{"action":"created","issue":{"url":"https://api.github.com/repos/phusion/passenger/issues/1432","labels_url":"https://api.github.com/repos/phusion/passenger/issues/1432/labels{/name}","comments_url":"https://api.github.com/repos/phusion/passenger/issues/1432/comments","events_url":"https://api.github.com/repos/phusion/passenger/issues/1432/events","html_url":"https://github.com/phusion/passenger/issues/1432","id":61158458,"number":1432,"title":"There should be a way to limit the request queuing time","user":{"login":"felixbuenemann","id":909587,"avatar_url":"https://avatars.githubusercontent.com/u/909587?v=3","gravatar_id":"","url":"https://api.github.com/users/felixbuenemann","html_url":"https://github.com/felixbuenemann","followers_url":"https://api.github.com/users/felixbuenemann/followers","following_url":"https://api.github.com/users/felixbuenemann/following{/other_user}","gists_url":"https://api.github.com/users/felixbuenemann/gists{/gist_id}","starred_url":"https://api.github.com/users/felixbuenemann/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/felixbuenemann/subscriptions","organizations_url":"https://api.github.com/users/felixbuenemann/orgs","repos_url":"https://api.github.com/users/felixbuenemann/repos","events_url":"https://api.github.com/users/felixbuenemann/events{/privacy}","received_events_url":"https://api.github.com/users/felixbuenemann/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/phusion/passenger/labels/Enhancement","name":"Enhancement","color":"c7def8"}],"state":"open","locked":false,"assignee":null,"milestone":{"url":"https://api.github.com/repos/phusion/passenger/milestones/22","html_url":"https://github.com/phusion/passenger/milestones/5.1.0","labels_url":"https://api.github.com/repos/phusion/passenger/milestones/22/labels","id":999040,"number":22,"title":"5.1.0","description":"","creator":{"login":"FooBarWidget","id":819,"avatar_url":"https://avatars.githubusercontent.com/u/819?v=3","gravatar_id":"","url":"https://api.github.com/users/FooBarWidget","html_url":"https://github.com/FooBarWidget","followers_url":"https://api.github.com/users/FooBarWidget/followers","following_url":"https://api.github.com/users/FooBarWidget/following{/other_user}","gists_url":"https://api.github.com/users/FooBarWidget/gists{/gist_id}","starred_url":"https://api.github.com/users/FooBarWidget/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/FooBarWidget/subscriptions","organizations_url":"https://api.github.com/users/FooBarWidget/orgs","repos_url":"https://api.github.com/users/FooBarWidget/repos","events_url":"https://api.github.com/users/FooBarWidget/events{/privacy}","received_events_url":"https://api.github.com/users/FooBarWidget/received_events","type":"User","site_admin":false},"open_issues":4,"closed_issues":0,"state":"open","created_at":"2015-02-27T16:33:31Z","updated_at":"2015-03-24T10:21:40Z","due_on":null,"closed_at":null},"comments":8,"created_at":"2015-03-13T17:50:39Z","updated_at":"2015-04-10T21:09:19Z","closed_at":null,"body":"Passenger 5.0.4 stays blocked for minutes after a request storm while the log fills up with:\r\n```\r\nDisconnecting client with error: client socket write error: Broken pipe (errno=32)\r\n```\r\nThis fact can easily be used for a denial of service:\r\n```\r\n# baseline response time (simulated slow endpoint)\r\ncurl -sw ' time_total: %{time_total}s\\n' localhost:3000\r\nYdxtDssIUc9zMl6UeGMncA== time_total: 10,007s\r\n\r\n# hit passenger with lots of request that time out\r\nwrk -c100 -d10s http://localhost:3000/\r\nRunning 10s test @ http://localhost:3000/\r\n  2 threads and 100 connections\r\n  1 requests in 10.02s, 286.00B read\r\n  Socket errors: connect 0, read 0, write 0, timeout 374\r\n\r\n# now try another request\r\ncurl -sw ' time_total: %{time_total}s\\n' localhost:3000\r\n7ypBhdFvn1Wpwo6Q6mtaOA== time_total: 992,797s\r\n```\r\n\r\nBy looking at the passenger log, it is evident that passenger is blocked processing all the requests made by clients that are no longer connected:\r\n```\r\npassenger start -e production --min-instances 1 --max-pool-size 1 --engine nginx\r\n=============== Phusion Passenger Standalone web server started ===============\r\nPID file: /home/felix/rack-hello/passenger.3000.pid\r\nLog file: /home/felix/rack-hello/passenger.3000.log\r\nEnvironment: production\r\nAccessible via: http://0.0.0.0:3000/\r\n\r\nYou can stop Phusion Passenger Standalone by pressing Ctrl-C.\r\nProblems? Check https://www.phusionpassenger.com/documentation/Users%20guide%20Standalone.html#troubleshooting\r\n===============================================================================\r\nApp 62016 stdout:\r\nApp 62032 stdout:\r\n[ 2015-03-13 10:10:16.8570 61985/7fa8b06c0700 Ser/Server.h:894 ]: [Client 1-1] Disconnecting client with error: client socket write error: Broken pipe (errno=32)\r\n[ 2015-03-13 10:11:24.1558 61985/7fa8b06c0700 Ser/Server.h:894 ]: [Client 1-5] Disconnecting client with error: client socket write error: Broken pipe (errno=32)\r\n[ 2015-03-13 10:11:34.1575 61985/7fa8b06c0700 Ser/Server.h:894 ]: [Client 1-6] Disconnecting client with error: client socket write error: Broken pipe (errno=32)\r\n[ 2015-03-13 10:11:44.1600 61985/7fa8b06c0700 Ser/Server.h:894 ]: [Client 1-7] Disconnecting client with error: client socket write error: Broken pipe (errno=32)\r\n…\r\n[ 2015-03-13 10:27:34.4088 61985/7fa8b06c0700 Ser/Server.h:894 ]: [Client 1-101] Disconnecting client with error: client socket write error: Broken pipe (errno=32)\r\n[ 2015-03-13 10:27:44.4121 61985/7fa8b06c0700 Ser/Server.h:894 ]: [Client 1-100] Disconnecting client with error: client socket write error: Broken pipe (errno=32)\r\n[ 2015-03-13 10:28:04.4202 61985/7fa8b06c0700 Ser/Server.h:894 ]: [Client 1-105] Disconnecting client with error: client socket write error: Broken pipe (errno=32)\r\n```\r\nThe problem here is that passenger detects client timeouts only after the processing of the app response is finished although the client might have disconnected before the request even left the request queue.\r\n\r\n------\r\n\r\nTodo list:\r\n\r\n- [ ] Implement request queuing timeout\r\n- [ ] Rename max_request_time to max_response_time\r\n- [ ] Documentation"},"comment":{"url":"https://api.github.com/repos/phusion/passenger/issues/comments/91691922","html_url":"https://github.com/phusion/passenger/issues/1432#issuecomment-91691922","issue_url":"https://api.github.com/repos/phusion/passenger/issues/1432","id":91691922,"user":{"login":"FooBarWidget","id":819,"avatar_url":"https://avatars.githubusercontent.com/u/819?v=3","gravatar_id":"","url":"https://api.github.com/users/FooBarWidget","html_url":"https://github.com/FooBarWidget","followers_url":"https://api.github.com/users/FooBarWidget/followers","following_url":"https://api.github.com/users/FooBarWidget/following{/other_user}","gists_url":"https://api.github.com/users/FooBarWidget/gists{/gist_id}","starred_url":"https://api.github.com/users/FooBarWidget/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/FooBarWidget/subscriptions","organizations_url":"https://api.github.com/users/FooBarWidget/orgs","repos_url":"https://api.github.com/users/FooBarWidget/repos","events_url":"https://api.github.com/users/FooBarWidget/events{/privacy}","received_events_url":"https://api.github.com/users/FooBarWidget/received_events","type":"User","site_admin":false},"created_at":"2015-04-10T21:09:18Z","updated_at":"2015-04-10T21:09:18Z","body":"We've recently had a discussion with an Enterprise customer about a similar problem. They are on Heroku, and whenever they deploy a new version, Heroku would spin up an instance, start Passenger and immediately direct traffic to that instance. This customer gets so much traffic, and spawning their app takes such a long time, that during the first minute or so their request queue would grow beyond the queue size.\r\n\r\nI suppose that, while the first process is being spawned, it is acceptable for the queue to grow over its configured size. But special casing this is not easy."}}