phusion / passenger

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

Unexpected error in mod_passenger: An error occurred while receiving HTTP upload data: Internal error (specific information not available) (20014) #2346

Open jaripog opened 3 years ago

jaripog commented 3 years ago

Issue report

Question 1: What is the problem? For a given post-call where the request body is approx ~8Kb, we are noticing 500 internal server errors and the Phusion passenger is getting crashed abruptly with the following error. This issue is very intermittent and it is failing ~ 5% of total requests being sent.

Note: the requests are not reaching the rails logs, the below error log is extracted from the apache by enabling PassengerLog

_[ 2021-03-22 11:32:23.7326 5432/7f23f07f8700 apache2/Hooks.cpp:732 ]: Unexpected error in mod_passenger: An error occurred while receiving HTTP upload data: Internal error (specific information not available) (20014)
  Backtrace:
     in 'boost::shared_ptr<Passenger::BufferedUpload> Hooks::receiveRequestBody(request_rec*)' (Hooks.cpp:1190)
     in 'int Hooks::handleRequest(request_rec*)' (Hooks.cpp:546)_

Log information

[ 2021-03-22 11:32:23.1871 5060/7fe030ca4700 EventedBufferedInput.h:146 ]: [EventedBufferedInput 0x7fe01400beb0 fd=22, state=LIVE, buffer(0)="", paused=0, socketPaused=0, nextTickInstalled=0, generation=2, error=0] onReadable
[ 2021-03-22 11:32:23.1871 5060/7fe030ca4700 EventedBufferedInput.h:172 ]: [EventedBufferedInput 0x7fe01400beb0 fd=22, state=LIVE, buffer(0)="", paused=0, socketPaused=0, nextTickInstalled=0, generation=2, error=0] end of stream
[ 2021-03-22 11:32:23.1871 5060/7fe030ca4700 agents/HelperAgent/RequestHandler.h:1223 ]: [Client 21] Event: onAppInputData
[ 2021-03-22 11:32:23.1871 5060/7fe030ca4700 agents/HelperAgent/RequestHandler.h:1313 ]: [Client 21] Event: onAppInputEof
[ 2021-03-22 11:32:23.1872 5060/7fe030ca4700 agents/HelperAgent/RequestHandler.h:1323 ]: [Client 21] Application sent EOF
[ 2021-03-22 11:32:23.1872 5060/7fe030ca4700 Pool2/Implementation.cpp:583 ]: Session closed for process (pid=9935, group=/home/platform/dev#default)
[ 2021-03-22 11:32:23.1872 5060/7fe030ca4700 agents/HelperAgent/RequestHandler.h:1406 ]: [Client 21] Event: onClientOutputPipeEnd
[ 2021-03-22 11:32:23.1872 5060/7fe030ca4700 agents/HelperAgent/RequestHandler.h:1411 ]: [Client 21] Client output pipe ended; disconnecting client
[ 2021-03-22 11:32:23.1872 5060/7fe030ca4700 agents/HelperAgent/RequestHandler.h:664 ]: [Client 21] Disconnected; new client count = 0
[ 2021-03-22 11:32:23.1873 5060/7fe030ca4700 EventedBufferedInput.h:353 ]: [EventedBufferedInput 0x7fe014009de0 fd=21, state=LIVE, buffer(0)="", paused=1, socketPaused=1, nextTickInstalled=0, generation=2, error=0] destroyed
[ 2021-03-22 11:32:23.1873 5060/7fe030ca4700 EventedBufferedInput.h:353 ]: [EventedBufferedInput 0x7fe01400beb0 fd=22, state=END_OF_STREAM, buffer(0)="", paused=1, socketPaused=1, nextTickInstalled=0, generation=2, error=0] destroyed
App 9881 stderr: [ 2021-03-22 11:32:23.1860 9935/0x00000000063184f8(Worker 1) request_handler/thread_handler.rb:153 ]: Request done.
[ 2021-03-22 11:32:23.7326 5432/7f23f07f8700 apache2/Hooks.cpp:732 ]: Unexpected error in mod_passenger: An error occurred while receiving HTTP upload data: Internal error (specific information not available) (20014)
  Backtrace:
     in 'boost::shared_ptr<Passenger::BufferedUpload> Hooks::receiveRequestBody(request_rec*)' (Hooks.cpp:1190)
     in 'int Hooks::handleRequest(request_rec*)' (Hooks.cpp:546)

Question 2: Passenger version and integration mode: Passenger - 4.0.59, mod_passenger with apache

Question 3: OS or Linux distro, platform (including version):

NAME="CentOS Linux"
VERSION="7 (Core)"
ID="centos"
ID_LIKE="rhel fedora"
VERSION_ID="7"
PRETTY_NAME="CentOS Linux 7 (Core)"
ANSI_COLOR="0;31"
CPE_NAME="cpe:/o:centos:centos:7"
HOME_URL="https://www.centos.org/"
BUG_REPORT_URL="https://bugs.centos.org/"

CENTOS_MANTISBT_PROJECT="CentOS-7"
CENTOS_MANTISBT_PROJECT_VERSION="7"
REDHAT_SUPPORT_PRODUCT="centos"
REDHAT_SUPPORT_PRODUCT_VERSION="7"

 x86_64

Question 4: Passenger installation method: [Y] RubyGems + Gemfile

Question 5: Your app's programming language (including any version managers) and framework (including versions):

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

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

  1. we have barracuda WAF as a proxy in front of the application

Note: we have enabled the tracing on passenger level and we did a ground-level analysis on this, for a payload with larger content it's trying to write to a temp file( buffering ). got the references from hooks.cpp and got to know it's failing in this particular method name called readRequestBodyFromApache, in this we are able to see when rv != APR_SUCCESS, passenger stops trying to read any data from the client and breaks without any tracepoint or readable information. screenshots have been attached for reference.

image

Please do let us know in case if you need more information on this.

Thanks in advance!!

jaripog commented 3 years ago

Kindly do let me know in case if anyone requires more information

CamJN commented 3 years ago

Can you reproduce this with Passenger 6? Passenger 4 is no longer supported and we have fixed some upload buffering bugs since that release.