(attempt 2) Results of Updxlrator testing - working great

(attempt 2) Results of Updxlrator testing - working great

[Justin Luth]

[-- Attachment #1: Type: text/plain, Size: 7058 bytes --]

Updatexlrator testing - everything is working great!  (I compiled core 
118, installed it on my spare ipfire replacement box, and swapped it in 
yesterday morning.)  Here are some key excerpts from the debug log.

The Microsoft files are generally defined as "URL" based because it is 
not necessarily the name that is unique, but the url itself.

2018-01-11 08:26:58 [5878] [updxlrator] Running command 
/var/ipfire/updatexlrator/bin/download microsoft 
http://officecdn.microsoft.com/pr/39168D7E-077B-48E7-872C-B232C3E72675/Office/Data/v32.cab 
0 &
2018-01-11 08:27:04 [5878] [updxlrator] Running command 
/var/ipfire/updatexlrator/bin/download microsoft 
http://officecdn.microsoft.com/pr/492350f6-3a01-4f97-b9c0-c7c6ddf67d60/Office/Data/v32.cab 
0 &

But if the filename contains the 40-digit SHA1 value, then we know that 
the filename is unique, and so we can treat it like Linux files, where 
it can be considered as a mirror-able file and only saved once. The 
following logs highlight A.) Multiple requests for the same 2GB file. 
(20 in two seconds!!) B.) The redirect from URL to FILE based caching.  
C.) two download requests before the lock file could be created. 
(Imagine how many more would have started when the lock delayed until 
wget wrote the first data.)

2018-01-11 17:35:23 [5878] [updxlrator] Processing 
...kb4056891-x64_5...  (first time this URL was seen.  22 attempts in 
the following 6 seconds).
2018-01-11 17:35:23 [6040] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:24 [6040] [updxlrator] SHA1: microsoft 
033ed1d0-1709-957f-9fd1-34e24770fed4 not cached. Reprocessing as mirror 
http://7.au.download.windowsupdate.com/c/msdownload/update/software/secu/2018/01/windows10.0-kb4056891-x64_5_0a5255f85efca77e0abaa9c74f1581b5d3994c47.psf
2018-01-11 17:35:24 [5878] [updxlrator] SHA1: microsoft 
033ed1d0-1709-957f-9fd1-34e24770fed4 not cached. Reprocessing as mirror 
http://7.au.download.windowsupdate.com/c/msdownload/update/software/secu/2018/01/windows10.0-kb4056891-x64_5_0a5255f85efca77e0abaa9c74f1581b5d3994c47.psf
2018-01-11 17:35:24 [6040] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:24 [5878] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:25 [6040] [updxlrator] Running command 
/var/ipfire/updatexlrator/bin/download microsoft ...kb4056891-x64_5... 1 &
2018-01-11 17:35:25 [5878] [updxlrator] Running command 
/var/ipfire/updatexlrator/bin/download microsoft ...kb4056891-x64_5... 1 &
2018-01-11 17:35:28 [6025] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:28 [6040] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:28 [6123] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:28 [6131] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:28 [6065] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:28 [6112] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:28 [2384] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:28 [2397] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:28 [2471] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:28 [2481] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:29 [2519] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:29 [2520] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:29 [2491] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:29 [2533] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:29 [16847] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:29 [2643] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:29 [16923] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:29 [16854] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:29 [16952] [updxlrator] Processing ...kb4056891-x64_5...
2018-01-11 17:35:29 [16990] [updxlrator] Processing ...kb4056891-x64_5...


These logs show 3 different URLs that a single client 
(55.55.55.40/DESKTOP-5NNUJJJ.local) requested this 2GB file from.

2018-01-12 02:21:12 [6115] [updxlrator] SHA1: microsoft 
033ed1d0-1709-957f-9fd1-34e24770fed4 not cached. Reprocessing as mirror 
http://7.au.download.windowsupdate.com/c/msdownload/update/software/secu/2018/01/windows10.0-kb4056891-x64_5_0a5255f85efca77e0abaa9c74f1581b5d3994c47.psf
2018-01-12 04:13:44 [5878] [updxlrator] SHA1: microsoft 
b6e85197-9fcb-ffd1-0388-fd8adad6a4b1 not cached. Reprocessing as mirror 
http://000498-1.l.windowsupdate.com/llnhost_4.au.download.windowsupdate.com/c/msdownload/update/software/secu/2018/01/windows10.0-kb4056891-x64_5_0a5255f85efca77e0abaa9c74f1581b5d3994c47.psf
2018-01-12 04:14:11 [5878] [updxlrator] SHA1: microsoft 
e28b880b-1350-d70a-fd16-be58c4ce1e45 not cached. Reprocessing as mirror 
http://4.au.download.windowsupdate.com/c/msdownload/update/software/secu/2018/01/windows10.0-kb4056891-x64_5_0a5255f85efca77e0abaa9c74f1581b5d3994c47.psf

Oh, and some logs just to show the cache working in action - downloaded 
from one mirror, and fulfilled in a request from another mirror
...
2018-01-11 16:43:58 [6025] [updxlrator] Running command 
/var/ipfire/updatexlrator/bin/download microsoft 
http://7.au.download.windowsupdate.com/c/msdownload/update/software/secu/2018/01/windows10.0-kb4056891-x64_1_0a04efc071ff44c3262927fd2df414474e6a4c56.psf 
1 &
...
2018-01-12 03:22:03 [6025] [updxlrator] Processing URL 
http://000f31-1.l.windowsupdate.com/llnhost_4.au.download.windowsupdate.com/c/msdownload/update/software/secu/2018/01/windows10.0-kb4056891-x64_1_0a04efc071ff44c3262927fd2df414474e6a4c56.psf
2018-01-12 03:22:03 [6025] [updxlrator] UUID is 
da895428-94cf-268c-6545-56d4c1c1aca2
2018-01-12 03:22:04 [6025] [updxlrator] SHA1: microsoft 
da895428-94cf-268c-6545-56d4c1c1aca2 not cached. Reprocessing as mirror 
http://000f31-1.l.windowsupdate.com/llnhost_4.au.download.windowsupdate.com/c/msdownload/update/software/secu/2018/01/windows10.0-kb4056891-x64_1_0a04efc071ff44c3262927fd2df414474e6a4c56.psf
2018-01-12 03:22:04 [6025] [updxlrator] UUID is 
b52663ab-8332-5292-0157-b95d50a5c96f
2018-01-12 03:22:04 [6040] [updxlrator] File exists in cache and is up 
to date
2018-01-12 03:22:04 [6040] [updxlrator] Retrieving file from cache 
(UPDCACHE) for 55.55.55.40/DESKTOP-5NNUJJJ.local


So, yesterday's log nicely highlights the importance of these patches.
-it was super easy (especially on slow connections) to have MANY 
download attempts for the same file.  The download command now has 
improved logic to prevent simultaneous wget's. I confirmed that only one 
wget was running for each downloading file.
-clients can request these huge updates from anywhere. Even though you 
might have had the file cached from a previous request, if another 
client starts requesting from a different mirror, you would have 
downloaded that too.  The bandwidth (and disk) savings from this change 
in logic is going to be huge.