Bigger uploads broken after v163

[nvedv (NV Norddeutsche Vermoegen)]

Hello!
After upgrading from build 163 to 164 a corporate upload-site (on the internet) we’re using isn’t working as expected anymore. Smaller uploads (< 1,2MB) are still working but bigger ones (> 2MB) are stalling during upload of some kB of data. Circumventing the ipfire-proxy the upload-site works without any problems.
Problem exists still in actual build 170 - i hoped to get this solveda fter 164, 165, … - that’s why i was waiting until now with my report.
I can’t find anything inside the logs neither in this forum. Don’t know what exactly killed the upload of some more data.
Any hints where to start finding the bug?

Ove

[bonnietwin (Adolf Belka)]

Hallo @nvedv

Welcome to the IPFire community.

So you only experience the problem when you have the web proxy activated and the download is going via it.

I would expect something to show up in the logs.

There is the web proxy system logs on the Logs - System Logs - choose Web Proxy in the drop down box. This will only show anything if the Web Proxy was stopped and restarted for some reason.

In the Logs - Proxy Logs you should have all the accesses via the Proxy. If the download started but then stopped for some reason you should still see an entry in that log. It might be worth un-checking the filter in that log page to be sure you are seeing everything.

I just tried a ~380MB download via the web proxy with CU170 and it completed very quickly with no problems. I found two entries for that operation in my logs.

[nvedv (NV Norddeutsche Vermoegen)]

Hello Adolf,
the problem is during uploading through the proxy to a webside - not while downloading stuff from the internet.
Inside the System-Logs → WebProxy there is no entry shown - like expected. In Log - Proxy Logs i see:

Every 2 secs a new entry but the upload is stalled:

Ove

[bonnietwin (Adolf Belka)]

Yes, I misunderstood about the upload vs download.

Is it possible to look at the logs for the corporate site to see if they give any more info as to why the upload starts but then stops after a very small amount.

The web proxy is continuing to try and send stuff to the site so it is not getting back a simple failure message as that would stop the proxy sending anything further.

You mention that it worked with CU163 which would have had version 4.16

Squid was updated to version 5.2 for CU164 and to 5.4.1 for CU165, 5.5 for CU168 and 5.6 for CU169 and version 5.7 is in CU171 that is currently in Testing phase.

I will have a look through the squid change logs and see if I see anything flagged up like this or if a bug has been raised with Squid.

I don’t know how many users of IPFire will do uploads. Most probably use it for caching downloads, however maybe someone else on the forum is also using it for uploads and can comment if they also see the same problem.

[bonnietwin (Adolf Belka)]

I looked through the changelogs and couldn’t see anything obvious but that could also just be my lack of knowledge.

I looked through the squid bugs and the only thing I found was related to FTP uploads.

https://bugs.squid-cache.org/show_bug.cgi?id=5213

Looking at the upload site url it looks like you are using http and not ftp so not sure that bug has any linkage to your situation.

@mfischer do you have any ideas of where to look to understand what is happening here?

[mfischer (Matthias Fischer)]

Hi,

I never came in this situation, so at first glance I have no idea.

Reading through the squid bug report: they “use squid as a FTP proxy, and c-icap [which we don’t use] *to check file body”.

The working solution in this case seemed to be to set “force_request_body_continuation”. Hm. But how?

I searched the squid documentation how to do this and found:
=> squid : force_request_body_continuation configuration directive

This setting “…controls how Squid handles data upload requests from HTTP and FTP agents that require a “Please Continue” control message response to actually send the request body to Squid. It is mostly useful in adaptation environments.”

Default value is Deny, unless rules exist in squid.conf.

Further infos:
TYPE: acl_access
LOC: Config.accessList.forceRequestBodyContinuation
DEFAULT: none

And that’s it. I found no further information yet how to implement this. No example, nothing.

Searching the squid source code for forceRequestBodyContinuation I only found some code fragments in /src/FtpServer.cc and /src/Http1Server.cc. Seems to be related.

Sorry, but does anyone else have an idea?

[nvedv (NV Norddeutsche Vermoegen)]

Log from the corporate webside look like this:

213.39.0.0 - - [11/Oct/2022:00:23:08 +0200] "GET /cgi-bin/upload_status.cgi?uid=624045512897&ajax2=1&num=1&rnd=0.18095509317141656 HTTP/1.1" 200 101 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=624045512897&files=:mshtml.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
213.39.0.0 - - [11/Oct/2022:00:23:09 +0200] "GET /cgi-bin/upload_status.cgi?uid=624045512897&ajax2=1&num=1&rnd=0.9517802171889715 HTTP/1.1" 200 101 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=624045512897&files=:mshtml.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
213.39.0.0 - - [11/Oct/2022:00:23:10 +0200] "GET /cgi-bin/upload_status.cgi?uid=624045512897&ajax2=1&num=1&rnd=0.8730969440510572 HTTP/1.1" 200 101 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=624045512897&files=:mshtml.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
213.39.0.0 - - [11/Oct/2022:00:23:11 +0200] "GET /cgi-bin/upload_status.cgi?uid=624045512897&ajax2=1&num=1&rnd=0.6376972866212429 HTTP/1.1" 200 101 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=624045512897&files=:mshtml.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
213.39.0.0 - - [11/Oct/2022:00:23:13 +0200] "GET /cgi-bin/upload_status.cgi?uid=624045512897&ajax2=1&num=1&rnd=0.024727640018423536 HTTP/1.1" 200 101 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=624045512897&files=:mshtml.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
213.39.0.0 - - [11/Oct/2022:00:23:14 +0200] "GET /cgi-bin/upload_status.cgi?uid=624045512897&ajax2=1&num=1&rnd=0.7024161921680394 HTTP/1.1" 200 101 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=624045512897&files=:mshtml.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"

Ove

[nvedv (NV Norddeutsche Vermoegen)]

adding
force_request_body_continuation allow all

to squid.conf doesn’t make any difference…

Ove

[nvedv (NV Norddeutsche Vermoegen)]

Logs from the corporate webside:
working with ipFire 163:

90.187.0.0 - - [11/Oct/2022:14:37:34 +0200] "GET /cgi-bin/upload_status.cgi?uid=994516206050&files=:HologramWorld.dll&ok=1 HTTP/1.1" 200 8714 "http://bigfiles.norddeutsche.de/cgi-bin/index.cgi" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
90.187.0.0 - - [11/Oct/2022:14:37:35 +0200] "GET /cgi-bin/upload_status.cgi?uid=994516206050&ajax2=1&num=0&rnd=0.6818834507709215 HTTP/1.1" 200 192 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=994516206050&files=:HologramWorld.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
90.187.0.0 - - [11/Oct/2022:14:37:36 +0200] "GET /cgi-bin/upload_status.cgi?uid=994516206050&ajax2=1&num=1&rnd=0.8701163896839017 HTTP/1.1" 200 106 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=994516206050&files=:HologramWorld.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
90.187.0.0 - - [11/Oct/2022:14:37:37 +0200] "GET /cgi-bin/upload_status.cgi?uid=994516206050&ajax2=1&num=1&rnd=0.09900145670698324 HTTP/1.1" 200 337 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=994516206050&files=:HologramWorld.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
90.187.0.0 - - [11/Oct/2022:14:37:38 +0200] "GET /cgi-bin/upload_status.cgi?uid=994516206050&ajax2=1&num=5&rnd=0.05716607406400098 HTTP/1.1" 200 81 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=994516206050&files=:HologramWorld.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
90.187.0.0 - - [11/Oct/2022:14:37:34 +0200] "POST /cgi-bin/upload.cgi?upload_id=994516206050&js_on=1 HTTP/1.1" 200 756 "http://bigfiles.norddeutsche.de/cgi-bin/index.cgi" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
90.187.0.0 - - [11/Oct/2022:14:37:39 +0200] "POST /htdocs/ HTTP/1.1" 200 2817 "http://bigfiles.norddeutsche.de/cgi-bin/upload.cgi?upload_id=994516206050&js_on=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"

not working with ipFire 170:

213.39.0.0 - - [11/Oct/2022:14:40:10 +0200] "GET /cgi-bin/upload_status.cgi?uid=856605759457&files=:HologramWorld.dll&ok=1 HTTP/1.1" 200 8714 "http://bigfiles.norddeutsche.de/cgi-bin/index.cgi" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
213.39.0.0 - - [11/Oct/2022:14:40:10 +0200] "GET /cgi-bin/upload_status.cgi?uid=856605759457&ajax2=1&num=0&rnd=0.5472851275937265 HTTP/1.1" 200 188 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=856605759457&files=:HologramWorld.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
213.39.0.0 - - [11/Oct/2022:14:40:11 +0200] "GET /cgi-bin/upload_status.cgi?uid=856605759457&ajax2=1&num=1&rnd=0.8416383476302727 HTTP/1.1" 200 101 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=856605759457&files=:HologramWorld.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
213.39.0.0 - - [11/Oct/2022:14:40:13 +0200] "GET /cgi-bin/upload_status.cgi?uid=856605759457&ajax2=1&num=1&rnd=0.1635611591345163 HTTP/1.1" 200 101 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=856605759457&files=:HologramWorld.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
213.39.0.0 - - [11/Oct/2022:14:40:14 +0200] "GET /cgi-bin/upload_status.cgi?uid=856605759457&ajax2=1&num=1&rnd=0.19797108137024444 HTTP/1.1" 200 101 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=856605759457&files=:HologramWorld.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
213.39.0.0 - - [11/Oct/2022:14:40:15 +0200] "GET /cgi-bin/upload_status.cgi?uid=856605759457&ajax2=1&num=1&rnd=0.1711796748631731 HTTP/1.1" 200 101 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=856605759457&files=:HologramWorld.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
213.39.0.0 - - [11/Oct/2022:14:40:16 +0200] "GET /cgi-bin/upload_status.cgi?uid=856605759457&ajax2=1&num=1&rnd=0.5133785726804836 HTTP/1.1" 200 101 "http://bigfiles.norddeutsche.de/cgi-bin/upload_status.cgi?uid=856605759457&files=:HologramWorld.dll&ok=1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
...

Ove

[mfischer (Matthias Fischer)]

Hm.

On Core 163 its ‘squid 4.16’. With Core 164 we switched to 5.4.1, Core 170 runs with 5.6.

On my productive machine (Core 170), I’m running 5.7 right now - no problems. But I don’t use it for uploads they way you do.

From v4 to v5 they must have changed something thats affecting your uploads.

But sorry, I have no idea.

Next thing I would do is to keep my squid.conf handy and ask on the squid-users mailing list

Prior to asking there, you need to register here.

HTH,
Matthias

[jon]

@mfischer

From v4 to v5 they must have changed something thats affecting your uploads.

When IPFire moved from squid v4 to v5 I experienced squid issues also. I had one web site that caused me big problems.

See my first post here:

Need help with network issue - Maybe squid related?

I subscribe to a streaming service that is experiencing an issue. I disabled the URL filter, the Intrusion Prevention System, the QoS while trying to figure this out. This has been happening since March 2022. I’ve been going back and forth with the vendor and they are pointing the “blame” finger back to me (actually my network). I’ve dug through the various logs and I don’t see anything noteworthy. But I did see LOTS of these errors in the squid access log starting on Mar 12: 1647144914.34…

As short term temporary test, try disabling the proxy. Maybe the uploads will change and start working.

This is a wild guess on my part... If by some miracle it starts working, you may need to do this:

Squid bypass - The IPFire Wiki