Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Process hangs with file uploads larger than 127KB #2569

Open
ohaucke opened this issue Oct 14, 2024 · 5 comments
Open

Process hangs with file uploads larger than 127KB #2569

ohaucke opened this issue Oct 14, 2024 · 5 comments

Comments

@ohaucke
Copy link

ohaucke commented Oct 14, 2024

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?

  • What is the expected behavior?

HTTP POST request gets processed

  • What is the actual behavior?

HTTP POST request never reaches the application/redmine

  • How can we reproduce it?
Install 
# 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 
{
    "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
Copy link

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
Copy link

ernestohdmx commented Oct 22, 2024 •
edited
Loading

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
Copy link
Member

CamJN commented Oct 22, 2024

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

@ohaucke
Copy link
Author

ohaucke commented Oct 22, 2024

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
Copy link

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@ohaucke @CamJN @hostingseguro @ernestohdmx