File upload stuck/no response if file is larger than 127KB
Added by Oliver Haucke 2 months ago
Hey there,
i'm currently having issues uploading files to Redmine that are larger than 127KB.
$ freebsd-version 14.1-RELEASE-p5 $ pkg version -v | grep apache apache24-2.4.62 rubygem-passenger-apache-6.0.23
Environment: Redmine version 5.1.3.stable Ruby version 3.2.5-p208 (2024-07-26) [amd64-freebsd14] Rails version 6.1.7.8 Environment production Database adapter Mysql2 Mailer queue ActiveJob::QueueAdapters::AsyncAdapter Mailer delivery sendmail Redmine settings: Redmine theme Default SCM: Git 2.46.2 Filesystem Redmine plugins: no plugin installed
Last time, i uploaded a larger file (6MB) was 2024-09-12 14:30:19
.
After a bit of debugging, i figured out that if the file is 127KB or smaller, everything is fine but as soon as the file is 128KB or larger, i do not get any response from the server/the connection timed out.
What i can confirm via setting the LogLevel of apache to trace2 (and 5) + i ran tcpdump on the server:
The HTTP connection gets established and the data are received by the server
[Wed Oct 09 20:19:37.222886 2024] [socache_shmcb:debug] [pid 30309:tid 37622617604352] mod_socache_shmcb.c(545): AH00835: socache_shmcb_retrieve (0x5b -> subcache 27) [Wed Oct 09 20:19:37.222940 2024] [socache_shmcb:debug] [pid 30309:tid 37622617604352] mod_socache_shmcb.c(929): AH00851: shmcb_subcache_retrieve found no match [Wed Oct 09 20:19:37.222980 2024] [socache_shmcb:debug] [pid 30309:tid 37622617604352] mod_socache_shmcb.c(556): AH00836: leaving socache_shmcb_retrieve successfully [Wed Oct 09 20:19:37.222995 2024] [ssl:trace2] [pid 30309:tid 37622617604352] ssl_engine_kernel.c(2058): Inter-Process Session Cache: request=GET status=MISSED id=5b723ed47c62a36002***** (session renewal) [Wed Oct 09 20:19:37.230717 2024] [ssl:trace4] [pid 30309:tid 37622617604352] ssl_engine_io.c(2428): [client 1.2.3.4:41022] OpenSSL: write 3721/3721 bytes to BIO#2237b3826000 [mem: 2237b3842000] [Wed Oct 09 20:19:37.268149 2024] [ssl:trace4] [pid 30309:tid 37622617604352] ssl_engine_io.c(2428): [client 1.2.3.4:41022] OpenSSL: write 5/5 bytes to BIO#2237b38260a0 [mem: 2237b383ba03] ... [Wed Oct 09 20:19:37.268526 2024] [ssl:trace4] [pid 30309:tid 37622617604352] ssl_engine_io.c(2428): [client 1.2.3.4:41022] OpenSSL: write 40/40 bytes to BIO#2237b38260a0 [mem: 2237b383ba08] [Wed Oct 09 20:19:37.268608 2024] [ssl:trace4] [pid 30309:tid 37622617604352] ssl_engine_io.c(2428): [client 1.2.3.4:41022] OpenSSL: write 51/51 bytes to BIO#2237b3826000 [mem: 2237b3842000] [Wed Oct 09 20:19:37.268701 2024] [socache_shmcb:debug] [pid 30309:tid 37622617604352] mod_socache_shmcb.c(508): AH00831: socache_shmcb_store (0xe4 -> subcache 4) [Wed Oct 09 20:19:37.268720 2024] [socache_shmcb:debug] [pid 30309:tid 37622617604352] mod_socache_shmcb.c(860): AH00847: insert happened at idx=0, data=(0:32) [Wed Oct 09 20:19:37.268729 2024] [socache_shmcb:debug] [pid 30309:tid 37622617604352] mod_socache_shmcb.c(863): AH00848: finished insert, subcache: idx_pos/idx_used=0/1, data_pos/data_used=0/209 [Wed Oct 09 20:19:37.268751 2024] [socache_shmcb:debug] [pid 30309:tid 37622617604352] mod_socache_shmcb.c(530): AH00834: leaving socache_shmcb_store successfully [Wed Oct 09 20:19:37.268763 2024] [ssl:trace2] [pid 30309:tid 37622617604352] ssl_engine_kernel.c(2058): Inter-Process Session Cache: request=SET status=OK id=e4037a3268fde276***** timeout=300s (session caching) [Wed Oct 09 20:19:37.306475 2024] [ssl:trace4] [pid 30309:tid 37622617604352] ssl_engine_io.c(2428): [client 1.2.3.4:41022] OpenSSL: write 5/5 bytes to BIO#2237b38260a0 [mem: 2237b383ba03] [Wed Oct 09 20:19:37.306492 2024] [ssl:trace4] [pid 30309:tid 37622617604352] ssl_engine_io.c(2428): [client 1.2.3.4:41022] OpenSSL: write 1519/1519 bytes to BIO#2237b38260a0 [mem: 2237b383ba08] [Wed Oct 09 20:19:37.306549 2024] [ssl:debug] [pid 30309:tid 37622617604352] ssl_engine_kernel.c(415): [client 1.2.3.4:41022] AH02034: Initial (No.1) HTTPS request received for child 215 (server redmine.example.org:443), referer: https://redmine.example.org/issues/1101 [Wed Oct 09 20:19:37.306577 2024] [http:trace4] [pid 30309:tid 37622617604352] http_request.c(435): [client 1.2.3.4:41022] Headers received from client:, referer: https://redmine.example.org/issues/1101 [Wed Oct 09 20:19:37.306595 2024] [http:trace4] [pid 30309:tid 37622617604352] http_request.c(438): [client 1.2.3.4:41022] Accept: application/js, referer: https://redmine.example.org/issues/1101 [Wed Oct 09 20:19:37.306624 2024] [http:trace4] [pid 30309:tid 37622617604352] http_request.c(438): [client 1.2.3.4:41022] Accept-Encoding: gzip, deflate, br, zstd, referer: https://redmine.example.org/issues/1101 [Wed Oct 09 20:19:37.306641 2024] [http:trace4] [pid 30309:tid 37622617604352] http_request.c(438): [client 1.2.3.4:41022] Accept-Language: en-US,en;q=0.9,de-DE;q=0.8,de;q=0.7, referer: https://redmine.example.org/issues/1101 [Wed Oct 09 20:19:37.306656 2024] [http:trace4] [pid 30309:tid 37622617604352] http_request.c(438): [client 1.2.3.4:41022] Connection: keep-alive, referer: https://redmine.example.org/issues/1101 [Wed Oct 09 20:19:37.306686 2024] [http:trace4] [pid 30309:tid 37622617604352] http_request.c(438): [client 1.2.3.4:41022] Content-Length: 131072, referer: https://redmine.example.org/issues/1101 ... [Wed Oct 09 20:19:37.307045 2024] [http:trace4] [pid 30309:tid 37622617604352] http_request.c(438): [client 1.2.3.4:41022] sec-ch-ua-platform: \\"Windows\\", referer: https://redmine.example.org/issues/1101 [Wed Oct 09 20:19:37.307164 2024] [authz_core:debug] [pid 30309:tid 37622617604352] mod_authz_core.c(815): [client 1.2.3.4:41022] AH01626: authorization result of Require all granted: granted, referer: https://redmine.example.org/issues/1101 [Wed Oct 09 20:19:37.307182 2024] [authz_core:debug] [pid 30309:tid 37622617604352] mod_authz_core.c(815): [client 1.2.3.4:41022] AH01626: authorization result of <RequireAny>: granted, referer: https://redmine.example.org/issues/1101 [Wed Oct 09 20:19:37.307222 2024] [core:trace3] [pid 30309:tid 37622617604352] request.c(360): [client 1.2.3.4:41022] request authorized without authentication by access_checker_ex hook: /uploads.js, referer: https://redmine.example.org/issues/1101 [Wed Oct 09 20:19:37.307410 2024] [ssl:trace4] [pid 30309:tid 37622617604352] ssl_engine_io.c(2428): [client 1.2.3.4:41022] OpenSSL: write 5/5 bytes to BIO#2237b38260a0 [mem: 2237b3835f83] [Wed Oct 09 20:19:37.307443 2024] [ssl:trace4] [pid 30309:tid 37622617604352] ssl_engine_io.c(2428): [client 1.2.3.4:41022] OpenSSL: write 1435/16379 bytes to BIO#2237b38260a0 [mem: 2237b3835f88] [Wed Oct 09 20:19:37.307717 2024] [ssl:trace4] [pid 30309:tid 37622617604352] ssl_engine_io.c(2428): [client 1.2.3.4:41022] OpenSSL: write 1440/14944 bytes to BIO#2237b38260a0 [mem: 2237b3836523] [Wed Oct 09 20:19:37.308185 2024] [ssl:trace4] [pid 30309:tid 37622617604352] ssl_engine_io.c(2428): [client 1.2.3.4:41022] OpenSSL: write 1440/13504 bytes to BIO#2237b38260a0 [mem: 2237b3836ac3] [Wed Oct 09 20:19:37.308969 2024] [ssl:trace4] [pid 30309:tid 37622617604352] ssl_engine_io.c(2428): [client 1.2.3.4:41022] OpenSSL: write 1440/12064 bytes to BIO#2237b38260a0 [mem: 2237b3837063] ... [Wed Oct 09 20:19:38.076913 2024] [ssl:trace4] [pid 30309:tid 37622617604352] ssl_engine_io.c(2428): [client 1.2.3.4:41022] OpenSSL: write 5/5 bytes to BIO#2237b38260a0 [mem: 2237b3835f83] [Wed Oct 09 20:19:38.076949 2024] [ssl:trace4] [pid 30309:tid 37622617604352] ssl_engine_io.c(2428): [client 1.2.3.4:41022] OpenSSL: write 256/256 bytes to BIO#2237b38260a0 [mem: 2237b3835f88]
Next thing i checked was the passenger log (i increased the PassengerLogLevel
to 5/debug):
[ D 2024-10-09 20:28:26.0255 33442/Th Ser/Server.h:880 ]: [ServerThr.5] 1 new client(s) accepted; there are now 1 active client(s)
Looks like passenger also gets the request
Next thing i tested was config.log_level = :debug
in config/additional_environment.rb
but nothing related to the request got written in the log.
Just for my sanity (since i also have php available on the server), i tested the same request to a test script and there everything worked fine.
Any idea what could cause the issue or what i can test next to figure it out and solve it?
Regards
Replies (1)
RE: File upload stuck/no response if file is larger than 127KB - Added by Oliver Haucke 2 months ago
Many hours later: it looks like a problem with passenger.
If i run `bundle exec rails server -e production` everything works fine