search

phusion / passenger

A fast and robust web server and application server for Ruby, Python and Node.js
https://www.phusionpassenger.com/
MIT License
5k stars 547 forks source link

Process hangs with file uploads larger than 127KB #2569

Open ohaucke opened 1 week ago

ohaucke commented 1 week ago

Issue report

Please try with the newest version of Passenger to avoid issues that have already been fixed

# pkg version -v | grep pass
rubygem-passenger-apache-6.0.23    =   up-to-date with remote

Question 1: What is the problem?

HTTP POST request gets processed

HTTP POST request never reaches the application/redmine

# pkg install apache24 redmine51 rubygem-passenger-apache mysql80-server
# nano -wc httpd.conf
// ...
LoadModule passenger_module /usr/local/lib/ruby/gems/3.2/gems/passenger/buildout/apache2/mod_passenger.so

<IfModule passenger_module>
  PassengerRoot /usr/local/lib/ruby/gems/3.2/gems/passenger
  PassengerRuby /usr/local/bin/ruby32
  PassengerMinInstances 1
  PassengerDefaultUser www
</IfModule>

<VirtualHost *:80>
  ServerName redmine.example.org
  DocumentRoot "/usr/local/www/redmine/public"
  RailsEnv production

  <Directory "/usr/local/www/redmine/public">
    AllowOverride All
    Options -MultiViews
    Require all granted
  </Directory>
</VirtualHost>

Install/Configure redmine: https://www.redmine.org/projects/redmine/wiki/RedmineInstall

Upload a file with 127KB or less to an issue : everything is fine Upload a file with 128KB or more to an issue : the HTTP POST request never reaches redmine and is stuck

Question 2: Passenger version and integration mode: Your answer: open source 6.0.23 apache

Question 3: OS or Linux distro, platform (including version): Your answer: FreeBSD 14.1-RELEASE-p5 amd64

Question 4: Passenger installation method:

Your answer: [ ] RubyGems + Gemfile [ ] RubyGems, no Gemfile [ ] Phusion APT repo [ ] Phusion YUM repo [ ] OS X Homebrew [ ] source tarball [X] Other, please specify:

Through the FreeBSD pkg system (https://www.freshports.org/www/rubygem-passenger)

Question 5: Your app's programming language (including any version managers) and framework (including versions): Your answer: Ruby 3.2.5,1, Rails 6.1.7.8

Question 6: Are you using a PaaS and/or containerization? If so which one? Your answer: No

Question 7: Anything else about your setup that we should know?

Your answer: When i run redmine via bundle exec rails server -e production everything works fine.

I uploaded two files and then ran passenger-status --show=requests. I trimmed the json a bit, since they all contained the same value as thread1 except for total_bytes_consumed

passenger-status --show=requests ```json { "thread1": { "active_client_count": 0, "active_clients": {}, "client_accept_speed": { "1h": { "averaged_over": "1 hour", "per": "minute", "value": 0.04 }, "1m": { "averaged_over": "1 minute", "per": "minute", "value": 0.0 } }, "disconnected_client_count": 0, "disconnected_clients": {}, "free_client_count": 0, "free_request_count": 1, "mbuf_pool": { "active_blocks": 0, "active_memory": { "bytes": 0, "human_readable": "0 bytes" }, "chunk_size": 4096, "free_blocks": 8, "offset": 4048, "spare_memory": { "bytes": 32768, "human_readable": "32.0 KB" } }, "peak_active_client_count": 1, "pid": 79465, "request_begin_speed": { "1h": { "averaged_over": "1 hour", "per": "minute", "value": 0.04 }, "1m": { "averaged_over": "1 minute", "per": "minute", "value": 0.0 } }, "server_state": "ACTIVE", "total_bytes_consumed": 1972, "total_clients_accepted": 1, "total_requests_begun": 1, "turbocaching": { "fetches": 0, "hit_ratio": null, "hits": 0, "store_success_ratio": null, "store_successes": 0, "stores": 0 } }, "thread2": { ... }, "thread3": { "active_client_count": 1, "active_clients": { "3-1": { "connected_at": { "local": "Mon Oct 14 16:35:24 2024", "relative": "2m 33s ago", "relative_timestamp": -152.5795509815216, "timestamp": 1728916524.187203 }, "connection_state": "ACTIVE", "current_request": { "app_sink_state": { "callback_in_progress": true, "end_acked": true, "ended": true, "initialized": false, "io_watcher_active": false }, "app_source_state": { "callback_in_progress": true, "end_acked": true, "ended": true, "initialized": false, "io_watcher_active": false }, "body_bytes_buffered": { "bytes": 131072, "human_readable": "128.0 KB" }, "content_length": 131072, "flags": { "dechunk_response": true, "https": true, "request_body_buffering": true }, "host": "redmine.example.org", "http_major": 1, "http_minor": 1, "http_state": "PARSING_BODY", "last_data_receive_time": { "local": "Mon Oct 14 16:35:24 2024", "relative": "2m 33s ago", "relative_timestamp": -152.48152327537538, "timestamp": 1728916524.285207 }, "last_data_send_time": null, "method": "POST", "path": "/uploads.js?attachment_id=1&filename=128KB.txt&content_type=text%2Fplain", "refcount": 1, "request_body_already_read": 131072, "request_body_fully_read": true, "request_body_type": "CONTENT_LENGTH", "response_begun": false, "session_checkout_try": 0, "started_at": { "local": "Mon Oct 14 16:35:24 2024", "relative": "2m 33s ago", "relative_timestamp": -152.5795509815216, "timestamp": 1728916524.187193 }, "state": "BUFFERING_REQUEST_BODY", "sticky_session": false, "want_keep_alive": false }, "lingering_request_count": 0, "name": "3-1", "number": 1, "output_channel_state": { "bytes_buffered": { "bytes": 0, "human_readable": "0 bytes" }, "callback_in_progress": false, "mode": "IN_MEMORY_MODE", "nbuffers": 0, "reader_state": "RS_INACTIVE" }, "refcount": 2, "requests_begun": 1 } }, "client_accept_speed": { "1h": { "averaged_over": "1 hour", "per": "minute", "value": 0.04 }, "1m": { "averaged_over": "1 minute", "per": "minute", "value": 0.0 } }, "disconnected_client_count": 0, "disconnected_clients": {}, "free_client_count": 0, "free_request_count": 0, "mbuf_pool": { "active_blocks": 33, "active_memory": { "bytes": 135168, "human_readable": "132.0 KB" }, "chunk_size": 4096, "free_blocks": 0, "offset": 4048, "spare_memory": { "bytes": 0, "human_readable": "0 bytes" } }, "peak_active_client_count": 1, "pid": 79465, "request_begin_speed": { "1h": { "averaged_over": "1 hour", "per": "minute", "value": 0.04 }, "1m": { "averaged_over": "1 minute", "per": "minute", "value": 0.0 } }, "server_state": "ACTIVE", "total_bytes_consumed": 133006, "total_clients_accepted": 1, "total_requests_begun": 1, "turbocaching": { "fetches": 0, "hit_ratio": null, "hits": 0, "store_success_ratio": null, "store_successes": 0, "stores": 0 } }, "thread4": { "active_client_count": 1, "active_clients": { "4-1": { "connected_at": { "local": "Mon Oct 14 16:36:39 2024", "relative": "1m 18s ago", "relative_timestamp": -77.58430409431458, "timestamp": 1728916599.182446 }, "connection_state": "ACTIVE", "current_request": { "app_sink_state": { "callback_in_progress": true, "end_acked": true, "ended": true, "initialized": false, "io_watcher_active": false }, "app_source_state": { "callback_in_progress": true, "end_acked": true, "ended": true, "initialized": false, "io_watcher_active": false }, "body_bytes_buffered": { "bytes": 131638, "human_readable": "128.6 KB" }, "content_length": 1336208, "flags": { "dechunk_response": true, "https": true, "request_body_buffering": true }, "host": "redmine.example.org", "http_major": 1, "http_minor": 1, "http_state": "PARSING_BODY", "last_data_receive_time": { "local": "Mon Oct 14 16:36:39 2024", "relative": "1m 18s ago", "relative_timestamp": -77.47915410995484, "timestamp": 1728916599.287567 }, "last_data_send_time": null, "method": "POST", "path": "/uploads.js?attachment_id=2&filename=1_27MB.png&content_type=image%2Fpng", "refcount": 1, "request_body_already_read": 131638, "request_body_fully_read": false, "request_body_type": "CONTENT_LENGTH", "response_begun": false, "session_checkout_try": 0, "started_at": { "local": "Mon Oct 14 16:36:39 2024", "relative": "1m 18s ago", "relative_timestamp": -77.58430409431458, "timestamp": 1728916599.182432 }, "state": "BUFFERING_REQUEST_BODY", "sticky_session": false, "want_keep_alive": false }, "lingering_request_count": 0, "name": "4-1", "number": 1, "output_channel_state": { "bytes_buffered": { "bytes": 0, "human_readable": "0 bytes" }, "callback_in_progress": false, "mode": "IN_MEMORY_MODE", "nbuffers": 0, "reader_state": "RS_INACTIVE" }, "refcount": 2, "requests_begun": 1 } }, "client_accept_speed": { "1h": { "averaged_over": "1 hour", "per": "minute", "value": 0.05 }, "1m": { "averaged_over": "1 minute", "per": "minute", "value": 0.06 } }, "disconnected_client_count": 0, "disconnected_clients": {}, "free_client_count": 0, "free_request_count": 0, "mbuf_pool": { "active_blocks": 33, "active_memory": { "bytes": 135168, "human_readable": "132.0 KB" }, "chunk_size": 4096, "free_blocks": 0, "offset": 4048, "spare_memory": { "bytes": 0, "human_readable": "0 bytes" } }, "peak_active_client_count": 1, "pid": 79465, "request_begin_speed": { "1h": { "averaged_over": "1 hour", "per": "minute", "value": 0.05 }, "1m": { "averaged_over": "1 minute", "per": "minute", "value": 0.06 } }, "server_state": "ACTIVE", "total_bytes_consumed": 133584, "total_clients_accepted": 1, "total_requests_begun": 1, "turbocaching": { "fetches": 0, "hit_ratio": null, "hits": 0, "store_success_ratio": null, "store_successes": 0, "stores": 0 } }, "thread5": { ... }, "thread6": { ... }, "thread7": { ... }, "thread8": { ... }, "threads": 8 } ```
apache log with PassengerLogLevel = 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) ``` Nothing more
hostingseguro commented 1 week ago

I add to this, the same thing is happening with all cPanel servers running Phusion Passenger along with CloudLinux. After much research we realized that the culprit is the new version==6.0.23 which is causing these problems.

ernestohdmx commented 6 days ago

In a server with OS ""CloudLinux 8.1" and running cPanel we fix the issue adding the following values to the /etc/apache2/conf.d/passenger.conf file between the ifModule directives:

PassengerMaxRequestQueueSize 1000
PassengerBufferUpload off
PassengerMaxPoolSize 20
PassengerMinInstances 5
PassengerStartTimeout 60

After that, restart Apache and re-check:

systemctl restart httpd

If the issue persists, update and remount CageFS for the user in question:

cagefsctl --force-update && cagefsctl -m <user>
CamJN commented 6 days ago

Cagefs needs to be configured to allow passenger to buffer to disk, that's probably your issue.

ohaucke commented 5 days ago

I don't have Cagefs but PassengerBufferUpload off helped for now. Question is why and what caused that?

I have PassengerDefaultUser www configured and that user can write in /tmp

ernestohdmx commented 5 days ago

Cagefs needs to be configured to allow passenger to buffer to disk, that's probably your issue.

In our particular case, everything seems to indicate a conflict triggered by recent CloudLinux updates, something that has affected the functioning of Passenger.