bugGNU Wget - Bugs: bug #62869, if retry hits a 302 FOUND wget...

 
 

bug #62869: if retry hits a 302 FOUND wget forgets to send the Range header thus appending the whole file to what's downloaded alrdy

Submitter:  Emanuel Czirai <correabuscar>
Submitted:  Sat 06 Aug 2022 05:49:12 AM UTC
   
 
Category:  Program Logic Severity:  3 - Normal
Priority:  5 - Normal Status:  None
Privacy:  Public Assigned to:  None
Originator Name:  Open/Closed:  Open
Release:  trunk Operating System:  GNU/Linux
Reproducibility:  Every Time Fixed Release:  None
Planned Release:  None Regression:  None
Work Required:  None Patch Included:  Yes
* Mandatory Fields

Add a New Comment Rich Markup
   

Sat 22 Oct 2022 07:56:06 PM UTC, comment #4: 


comment #3:

> Hi, sorry for the late response. I accidentally deleted a couple of the files you uploaded instead of downloading them. Could you please re-upload your scripts and PoC? I'll take a look in the coming weeks to see what the issue is and resolve it


what?!? brah! :)) (just kiddin')

`tst` and `go` are missing, re-uploading as they were.


md5sum:
8253c07003be31ae11e7ae83e59ef818  ./a.py                                                                                                                         
a42eaa5474f3628156e1df447f60c5b7  ./go                                                                                                                           
41aecb3964bbfdcb3d58bb493eee3f05  ./gocurltest                                                                                                                   
7cade2df153b656b8876f39319eefc5b  ./tst                                                                                                                          
e1286619a8c0d88d1a86c0a5690c9ea3  ./wget_no_append_on302_uponretry.patch 


(file #53891, file #53892)

Emanuel Czirai <correabuscar>
Sat 22 Oct 2022 07:14:23 PM UTC, comment #3: 

Hi, sorry for the late response. I accidentally deleted a couple of the files you uploaded instead of downloading them. Could you please re-upload your scripts and PoC? I'll take a look in the coming weeks to see what the issue is and resolve it

Darshit Shah <darnir>
Group administrator
Sat 06 Aug 2022 08:27:29 PM UTC, comment #2: 

For what is worth, I've tried doing this with curl but because it doesn't have this feature to resume download on retry, it discards previously downloaded data and redownloads the whole thing, thus doesn't have the issue, but it doesn't have resume either which is unacceptable, thus I must keep using wget :)

eg.

> Throwing away 6 bytes


Attaching gocurltest bash script anyway.

(file #53540)

Emanuel Czirai <correabuscar>
Sat 06 Aug 2022 06:31:34 AM UTC, comment #1: 

Oh, I forgot to mention one important thing: this issue only happens with -O file arg (aka --output-document=file ), and doesn't happen with --continue


Here's output of ./go bug --debug

when bug is present:

$ ./go bug --debug
Bugged version on
/tmp ~/sandbox/python/server_for_wget
Setting --tries (tries) to 3
Setting --timeout (timeout) to 2
Setting --passive-ftp (passiveftp) to 1
Setting --output-document (outputdocument) to aha.txt
DEBUG output created by Wget 1.21.3 on linux-gnu.

Reading HSTS entries from /home/user/.wget-hsts
--2022-08-06 08:28:19--  http://127.0.2.9:8000/a.txt
Connecting to 127.0.2.9:8000... connected.
Created socket 4.
Releasing 0x00005e5530cfbea0 (new refcount 0).
Deleting unused 0x00005e5530cfbea0.

---request begin---
GET /a.txt HTTP/1.1
Host: 127.0.2.9:8000
User-Agent: Wget/1.21.3
Accept: /
Accept-Encoding: identity
Connection: Keep-Alive

---request end---
HTTP request sent, awaiting response... 127.0.0.1 - - [06/Aug/2022 08:28:19] "GET /a.txt HTTP/1.1" 302 -

---response begin---
HTTP/1.0 302 Found
Server: BaseHTTP/0.6 Python/3.10.6
Date: Sat, 06 Aug 2022 06:28:19 GMT
Location: http://127.0.3.12:8001/a.txt

---response end---
302 Found
Registered socket 4 for persistent reuse.
Location: http://127.0.3.12:8001/a.txt [following]
] done.
--2022-08-06 08:28:19--  http://127.0.3.12:8001/a.txt
Connecting to 127.0.3.12:8001... connected.
Created socket 5.
Releasing 0x00005e5530cfc350 (new refcount 0).
Deleting unused 0x00005e5530cfc350.

---request begin---
GET /a.txt HTTP/1.1
Host: 127.0.3.12:8001
User-Agent: Wget/1.21.3
Accept: /
Accept-Encoding: identity
Connection: Keep-Alive

---request end---
HTTP request sent, awaiting response... 127.0.0.1 - - [06/Aug/2022 08:28:19] "GET /a.txt HTTP/1.1" 200 -
[Server] Sending full file
Pretending to timeout

---response begin---
HTTP/1.0 200 OK
Server: BaseHTTP/0.6 Python/3.10.6
Date: Sat, 06 Aug 2022 06:28:19 GMT
Content-type: text/plain; charset=utf-8
Content-Length: 14

---response end---
200 OK
Disabling further reuse of socket 4.
Closed fd 4
Registered socket 5 for persistent reuse.
Length: 14 [text/plain]
Saving to: 'aha.txt'

aha.txt                                   42%[=================================>                                               ]       6  --.-KB/s    in 2.0s   

Disabling further reuse of socket 5.
Closed fd 5
2022-08-06 08:28:21 (3.00 B/s) - Read error at byte 6/14 (Connection timed out). Retrying.

--2022-08-06 08:28:22--  (try: 2)  http://127.0.3.12:8001/a.txt
Connecting to 127.0.3.12:8001... connected.
Created socket 4.
Releasing 0x00005e5530cfc8d0 (new refcount 0).
Deleting unused 0x00005e5530cfc8d0.

---request begin---
GET /a.txt HTTP/1.1
Host: 127.0.3.12:8001
Range: bytes=6-
User-Agent: Wget/1.21.3
Accept: /
Accept-Encoding: identity
Connection: Keep-Alive

---request end---
HTTP request sent, awaiting response... 127.0.0.1 - - [06/Aug/2022 08:28:22] "GET /a.txt HTTP/1.1" 302 -

---response begin---
HTTP/1.0 302 Found
Server: BaseHTTP/0.6 Python/3.10.6
Date: Sat, 06 Aug 2022 06:28:22 GMT
Location: http://127.0.2.9:8000/a.txt

---response end---
302 Found
Registered socket 4 for persistent reuse.
Location: http://127.0.2.9:8000/a.txt [following]
] done.
--2022-08-06 08:28:22--  http://127.0.2.9:8000/a.txt
Connecting to 127.0.2.9:8000... connected.
Created socket 5.
Releasing 0x00005e5530cfca50 (new refcount 0).
Deleting unused 0x00005e5530cfca50.

---request begin---
GET /a.txt HTTP/1.1
Host: 127.0.2.9:8000
User-Agent: Wget/1.21.3
Accept: /
Accept-Encoding: identity
Connection: Keep-Alive

---request end---
HTTP request sent, awaiting response... 127.0.0.1 - - [06/Aug/2022 08:28:22] "GET /a.txt HTTP/1.1" 200 -
[Server] Sending full file

---response begin---
HTTP/1.0 200 OK
Server: BaseHTTP/0.6 Python/3.10.6
Date: Sat, 06 Aug 2022 06:28:22 GMT
Content-type: text/plain; charset=utf-8
Content-Length: 14

---response end---
200 OK
Disabling further reuse of socket 4.
Closed fd 4
Registered socket 5 for persistent reuse.
Length: 14 [text/plain]
Saving to: 'aha.txt'

aha.txt                                  100%[================================================================================>]      14  --.-KB/s    in 0s     

2022-08-06 08:28:22 (3.34 MB/s) - 'aha.txt' saved [14/14]

Hello Hello World.
-rw-r--r-- 1 user user 20 Aug  6 08:28 aha.txt
Bug still present!

Emanuel Czirai <correabuscar>
Sat 06 Aug 2022 05:49:12 AM UTC, original submission:  

Hello.
I've encountered this append bug on Gentoo with wget-1.21.3-r1 while portage is downloading the file android-studio-2022.1.1.9-linux.tar.gz for Android Studio Canary (a 1G file, which on disk was 1.6G and thus corrupt due to this bug)

I've (not yet) attached file problem_on_real_url.log if you want to see wget output the second time I've reproduced the above which yielded a file that was 24 MiB larger. I haven't redacted anything(like my IP address). I haven't attached this yet, because only 4 files can be attached, if you really want to see this let me know, I will attach in the next comment, but only if you need to see it.

I couldn't reproduce it all the time because those google servers don't always yield a 302 FOUND after a timeout and they don't always timeout either.

So I've come up with a test that always reproduces this issue (unfortunately, I couldn't figure out how to make it a test case - test suite doesn't seem to have the needed functionality): A server that pretends to timeout in the middle of the transfer then when wget retries, it will give a 302 FOUND and redirect to another server and this is when wget forgets to send the Range header which specifies from where should the server continue sending the file, thus the server sends the full file from the beginning, and wget still acts as if the file is being sent from the continue point, thus appending the full file to whatever it already downloaded until the timeout(and the 302) occurred.

I've attached files:

a.py
go
tst
wget_no_append_on302_uponretry.patch


to run the test and check that the bug exists just first chmod a+x go tst then run(as normal user, always):

./go

or
to see wget --debug output:

./go --debug

or

./go bug --debug



The last line should be a red color: "Bug still present!"

To see how wget acts when the server doesn't do a 302 redirect after a timeout (ie. it never hits this bug) then run:

./go nobug --debug


This will always say as last line: "Bug is fixed."

To test both:

./tst


For this test script, if the bug is not fixed you get a yellow/brown last line:
"ok, bug test is fine ie. wget isn't fixed (but it should eventually be, hence why this is yellow)"

but if the bug is fixed, you get:
"Failed to reveal the bug, was the wget bug fixed?! (assume this is green if you know that wget got fixed)"



The test wants to wget the file with contents "Hello World.\r\n" but the server induces a timeout after "Hello " and this causes wget to retry, but the server then gives a 302 which wget follows and then wget doesn't send a Range header anymore causing the server to reply with 200 OK instead of 206 Partial Content, thus the final file contents are "Hello Hello World.\r\n" when the bug is present, thus showcasing the fact that the whole file(which is "Hello World.\r\n") just got appended to whatever it already downloaded(which is the first "Hello ")

Apply that attached patch to wget to see a proof of concept hacky fix which makes wget do send a Range header after the 302 happens by pretending that wget was ran with --start-pos=X arg, where X is the file offset it should've continued from. It's a hack, not the actual fix.


Emanuel Czirai <correabuscar>

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attach Files:
   
   
Comment:
   

Attached Files
file #53891:  tst added by correabuscar (2KiB - application/octet-stream - re-uploaded the original 'tst' & 'go' attached files)
file #53892:  go added by correabuscar (993B - application/octet-stream - re-uploaded the original 'tst' & 'go' attached files)
file #53540:  gocurltest added by correabuscar (2KiB - application/octet-stream)
file #53531:  a.py added by correabuscar (8KiB - text/x-python - test for the bug presence and hacky poc patch)
file #53534:  wget_no_append_on302_uponretry.patch added by correabuscar (1KiB - text/x-patch - test for the bug presence and hacky poc patch)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by darnir (Posted a comment)
  • -email is unavailable- added by correabuscar (Submitted the item)
  •  

    Follow 9 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2022-10-22 correabuscar Attached File- Added tst, #53891
        Attached File- Added go, #53892
    2022-10-22 darnir Attached File#53532 Removed
    2022-10-22 darnir Attached File#53533 Removed
    2022-08-06 correabuscar Attached File- Added gocurltest, #53540
    2022-08-06 correabuscar Attached File- Added a.py, #53531
        Attached File- Added tst, #53532
        Attached File- Added go, #53533
        Attached File- Added wget_no_append_on302_uponretry.patch, #53534

    Back to the top

    Powered by Savane 3.14-49f2.
    Corresponding source code