I have a production rails 6.0.3, ruby 2.6.3 application with nginx and passenger. The app ran fine for ages until recently, the server began getting it's CPU maxed out. I used htop to see what is happening and I see several processes that are "Passenger AppPreloader: /app-location (forking...)"
I ran passenger-status and got
/app-location (production):
App root: /app-location
Requests in queue: 3
* PID: 2241 Sessions: 1 Processed: 8652 Uptime: 1h 0m 43s
CPU: 26% Memory : 149M Last used: 1s ago
* PID: 2261 Sessions: 1 Processed: 8366 Uptime: 1h 0m 42s
CPU: 24% Memory : 128M Last used: 2s ago
* PID: 2281 Sessions: 1 Processed: 7771 Uptime: 1h 0m 41s
CPU: 22% Memory : 139M Last used: 1s ago
* PID: 2300 Sessions: 1 Processed: 7184 Uptime: 1h 0m 40s
CPU: 20% Memory : 128M Last used: 2s ago
* PID: 2319 Sessions: 1 Processed: 6466 Uptime: 1h 0m 39s
CPU: 19% Memory : 138M Last used: 0s ago
* PID: 2340 Sessions: 1 Processed: 6447 Uptime: 1h 0m 37s
CPU: 18% Memory : 129M Last used: 3s ago
* PID: 2359 Sessions: 1 Processed: 6015 Uptime: 1h 0m 34s
CPU: 17% Memory : 128M Last used: 2s ago
* PID: 2380 Sessions: 1 Processed: 5708 Uptime: 1h 0m 32s
CPU: 16% Memory : 127M Last used: 0s ago
Then ran passenger-status --show=server and got
Version : 6.0.7
Date : 2023-08-18 16:06:52 +0000
Instance: NTbICiN4 (nginx/1.14.0 Phusion_Passenger/6.0.7)
{
"thread1" : {
"active_client_count" : 5,
"active_clients" : {
"1-58219" : {
"connected_at" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -1.0689136981964111,
"timestamp" : 1692374811.062485
},
"connection_state" : "ACTIVE",
"current_request" : {
"app_response_http_state" : "PARSING_HEADERS",
"app_sink_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : false
},
"app_source_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : true
},
"flags" : {
"dechunk_response" : true,
"https" : true,
"request_body_buffering" : false
},
"host" : "www.hostname.com",
"http_major" : 1,
"http_minor" : 1,
"http_state" : "COMPLETE",
"last_data_receive_time" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -1.0689136981964111,
"timestamp" : 1692374811.062459
},
"last_data_send_time" : null,
"method" : "GET",
"path" : "/uri",
"refcount" : 1,
"request_body_already_read" : 0,
"request_body_fully_read" : true,
"request_body_type" : "NO_BODY",
"response_begun" : false,
"session" : {
"gupid" : "1ae645d-fY1k189UHN",
"pid" : 2241
},
"session_checkout_try" : 1,
"started_at" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -1.0689136981964111,
"timestamp" : 1692374811.062469
},
"state" : "WAITING_FOR_APP_OUTPUT",
"sticky_session" : false,
"want_keep_alive" : false
},
"lingering_request_count" : 0,
"name" : "1-58219",
"number" : 58219,
"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
},
"1-58225" : {
"connected_at" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.66239261627197266,
"timestamp" : 1692374811.468967
},
"connection_state" : "ACTIVE",
"current_request" : {
"app_response_http_state" : "PARSING_HEADERS",
"app_sink_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : false
},
"app_source_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : true
},
"flags" : {
"dechunk_response" : true,
"https" : true,
"request_body_buffering" : false
},
"host" : "www.hostname.com",
"http_major" : 1,
"http_minor" : 1,
"http_state" : "COMPLETE",
"last_data_receive_time" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.66239261627197266,
"timestamp" : 1692374811.468941
},
"last_data_send_time" : null,
"method" : "GET",
"path" : "/uri",
"refcount" : 1,
"request_body_already_read" : 0,
"request_body_fully_read" : true,
"request_body_type" : "NO_BODY",
"response_begun" : false,
"session" : {
"gupid" : "1ae645d-wHSs0mT5ZT",
"pid" : 2319
},
"session_checkout_try" : 1,
"started_at" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.66239261627197266,
"timestamp" : 1692374811.4689519
},
"state" : "WAITING_FOR_APP_OUTPUT",
"sticky_session" : false,
"want_keep_alive" : false
},
"lingering_request_count" : 0,
"name" : "1-58225",
"number" : 58225,
"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
},
"1-58226" : {
"connected_at" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.65522408485412598,
"timestamp" : 1692374811.4760959
},
"connection_state" : "ACTIVE",
"current_request" : {
"app_response_http_state" : "PARSING_HEADERS",
"app_sink_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : false
},
"app_source_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : true
},
"flags" : {
"dechunk_response" : true,
"https" : true,
"request_body_buffering" : false
},
"host" : "www.hostname.com",
"http_major" : 1,
"http_minor" : 1,
"http_state" : "COMPLETE",
"last_data_receive_time" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.65522408485412598,
"timestamp" : 1692374811.4760671
},
"last_data_send_time" : null,
"method" : "GET",
"path" : "/uri",
"refcount" : 1,
"request_body_already_read" : 0,
"request_body_fully_read" : true,
"request_body_type" : "NO_BODY",
"response_begun" : false,
"session" : {
"gupid" : "1ae645d-9aPZQq2rjB",
"pid" : 2380
},
"session_checkout_try" : 1,
"started_at" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.65522408485412598,
"timestamp" : 1692374811.4760759
},
"state" : "WAITING_FOR_APP_OUTPUT",
"sticky_session" : false,
"want_keep_alive" : false
},
"lingering_request_count" : 0,
"name" : "1-58226",
"number" : 58226,
"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
},
"1-58227" : {
"connected_at" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.51140403747558594,
"timestamp" : 1692374811.619869
},
"connection_state" : "ACTIVE",
"current_request" : {
"app_response_http_state" : "PARSING_HEADERS",
"app_sink_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : false
},
"app_source_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : true
},
"flags" : {
"dechunk_response" : true,
"https" : true,
"request_body_buffering" : false
},
"host" : "www.hostname.com",
"http_major" : 1,
"http_minor" : 1,
"http_state" : "COMPLETE",
"last_data_receive_time" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.51140403747558594,
"timestamp" : 1692374811.6198339
},
"last_data_send_time" : null,
"method" : "GET",
"path" : "/uri",
"refcount" : 1,
"request_body_already_read" : 0,
"request_body_fully_read" : true,
"request_body_type" : "NO_BODY",
"response_begun" : false,
"session" : {
"gupid" : "1ae645d-GzqZSvASHc",
"pid" : 2300
},
"session_checkout_try" : 1,
"started_at" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.51140403747558594,
"timestamp" : 1692374811.6198471
},
"state" : "WAITING_FOR_APP_OUTPUT",
"sticky_session" : false,
"want_keep_alive" : false
},
"lingering_request_count" : 0,
"name" : "1-58227",
"number" : 58227,
"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
},
"1-58237" : {
"connected_at" : {
"local" : "Fri Aug 18 16:06:52 2023",
"relative" : "0s ago",
"relative_timestamp" : -0.027449846267700195,
"timestamp" : 1692374812.10377
},
"connection_state" : "ACTIVE",
"current_request" : {
"app_sink_state" : {
"callback_in_progress" : false,
"initialized" : false,
"io_watcher_active" : false
},
"app_source_state" : {
"callback_in_progress" : true,
"initialized" : false,
"io_watcher_active" : false
},
"flags" : {
"dechunk_response" : true,
"https" : true,
"request_body_buffering" : false
},
"host" : "www.hostname.com",
"http_major" : 1,
"http_minor" : 1,
"http_state" : "COMPLETE",
"last_data_receive_time" : {
"local" : "Fri Aug 18 16:06:52 2023",
"relative" : "0s ago",
"relative_timestamp" : -0.027449846267700195,
"timestamp" : 1692374812.1037059
},
"last_data_send_time" : null,
"method" : "GET",
"path" : "/uri",
"refcount" : 2,
"request_body_already_read" : 0,
"request_body_fully_read" : true,
"request_body_type" : "NO_BODY",
"response_begun" : false,
"session_checkout_try" : 0,
"started_at" : {
"local" : "Fri Aug 18 16:06:52 2023",
"relative" : "0s ago",
"relative_timestamp" : -0.027449846267700195,
"timestamp" : 1692374812.1037469
},
"state" : "CHECKING_OUT_SESSION",
"sticky_session" : false,
"want_keep_alive" : false
},
"lingering_request_count" : 0,
"name" : "1-58237",
"number" : 58237,
"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" : 989.09000000000003
},
"1m" : {
"averaged_over" : "1 minute",
"per" : "minute",
"value" : 1233.3800000000001
}
},
"disconnected_client_count" : 0,
"disconnected_clients" : {},
"free_client_count" : 0,
"free_request_count" : 6,
"mbuf_pool" : {
"active_blocks" : 5,
"active_memory" : {
"bytes" : 20480,
"human_readable" : "20.0 KB"
},
"chunk_size" : 4096,
"free_blocks" : 60,
"offset" : 4048,
"spare_memory" : {
"bytes" : 245760,
"human_readable" : "240.0 KB"
}
},
"peak_active_client_count" : 11,
"pid" : 1003,
"request_begin_speed" : {
"1h" : {
"averaged_over" : "1 hour",
"per" : "minute",
"value" : 989.09000000000003
},
"1m" : {
"averaged_over" : "1 minute",
"per" : "minute",
"value" : 1233.3800000000001
}
},
"server_state" : "ACTIVE",
"total_bytes_consumed" : 139872386,
"total_clients_accepted" : 58237,
"total_requests_begun" : 58237,
"turbocaching" : {
"fetches" : 0,
"hit_ratio" : null,
"hits" : 0,
"store_success_ratio" : 0.0,
"store_successes" : 0,
"stores" : 0
}
},
"thread2" : {
"active_client_count" : 6,
"active_clients" : {
"2-58209" : {
"connected_at" : {
"local" : "Fri Aug 18 16:06:50 2023",
"relative" : "2s ago",
"relative_timestamp" : -1.711137056350708,
"timestamp" : 1692374810.4202621
},
"connection_state" : "ACTIVE",
"current_request" : {
"app_response_http_state" : "PARSING_HEADERS",
"app_sink_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : false
},
"app_source_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : true
},
"flags" : {
"dechunk_response" : true,
"https" : true,
"request_body_buffering" : false
},
"host" : "www.hostname.com",
"http_major" : 1,
"http_minor" : 1,
"http_state" : "COMPLETE",
"last_data_receive_time" : {
"local" : "Fri Aug 18 16:06:50 2023",
"relative" : "2s ago",
"relative_timestamp" : -1.711137056350708,
"timestamp" : 1692374810.420238
},
"last_data_send_time" : null,
"method" : "GET",
"path" : "/uri",
"refcount" : 1,
"request_body_already_read" : 0,
"request_body_fully_read" : true,
"request_body_type" : "NO_BODY",
"response_begun" : false,
"session" : {
"gupid" : "1ae645d-tEcEtQ3OxQ",
"pid" : 2281
},
"session_checkout_try" : 1,
"started_at" : {
"local" : "Fri Aug 18 16:06:50 2023",
"relative" : "2s ago",
"relative_timestamp" : -1.711137056350708,
"timestamp" : 1692374810.420249
},
"state" : "WAITING_FOR_APP_OUTPUT",
"sticky_session" : false,
"want_keep_alive" : false
},
"lingering_request_count" : 0,
"name" : "2-58209",
"number" : 58209,
"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
},
"2-58219" : {
"connected_at" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -1.0652401447296143,
"timestamp" : 1692374811.0661211
},
"connection_state" : "ACTIVE",
"current_request" : {
"app_response_http_state" : "PARSING_HEADERS",
"app_sink_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : false
},
"app_source_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : true
},
"flags" : {
"dechunk_response" : true,
"https" : true,
"request_body_buffering" : false
},
"host" : "www.hostname.com",
"http_major" : 1,
"http_minor" : 1,
"http_state" : "COMPLETE",
"last_data_receive_time" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -1.0652401447296143,
"timestamp" : 1692374811.0660989
},
"last_data_send_time" : null,
"method" : "GET",
"path" : "/uri",
"refcount" : 1,
"request_body_already_read" : 0,
"request_body_fully_read" : true,
"request_body_type" : "NO_BODY",
"response_begun" : false,
"session" : {
"gupid" : "1ae645d-m8VNsKoLer",
"pid" : 2340
},
"session_checkout_try" : 1,
"started_at" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -1.0652401447296143,
"timestamp" : 1692374811.0661099
},
"state" : "WAITING_FOR_APP_OUTPUT",
"sticky_session" : false,
"want_keep_alive" : false
},
"lingering_request_count" : 0,
"name" : "2-58219",
"number" : 58219,
"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
},
"2-58223" : {
"connected_at" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.76185989379882812,
"timestamp" : 1692374811.3694699
},
"connection_state" : "ACTIVE",
"current_request" : {
"app_response_http_state" : "PARSING_HEADERS",
"app_sink_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : false
},
"app_source_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : true
},
"flags" : {
"dechunk_response" : true,
"https" : true,
"request_body_buffering" : false
},
"host" : "www.hostname.com",
"http_major" : 1,
"http_minor" : 1,
"http_state" : "COMPLETE",
"last_data_receive_time" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.76185989379882812,
"timestamp" : 1692374811.369447
},
"last_data_send_time" : null,
"method" : "GET",
"path" : "/uri",
"refcount" : 1,
"request_body_already_read" : 0,
"request_body_fully_read" : true,
"request_body_type" : "NO_BODY",
"response_begun" : false,
"session" : {
"gupid" : "1ae645d-TSVuBVnnU7",
"pid" : 2359
},
"session_checkout_try" : 1,
"started_at" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.76185989379882812,
"timestamp" : 1692374811.369457
},
"state" : "WAITING_FOR_APP_OUTPUT",
"sticky_session" : false,
"want_keep_alive" : false
},
"lingering_request_count" : 0,
"name" : "2-58223",
"number" : 58223,
"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
},
"2-58224" : {
"connected_at" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.67304801940917969,
"timestamp" : 1692374811.4582491
},
"connection_state" : "ACTIVE",
"current_request" : {
"app_response_http_state" : "PARSING_HEADERS",
"app_sink_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : false
},
"app_source_state" : {
"callback_in_progress" : false,
"initialized" : true,
"io_watcher_active" : true
},
"flags" : {
"dechunk_response" : true,
"https" : true,
"request_body_buffering" : false
},
"host" : "www.hostname.com",
"http_major" : 1,
"http_minor" : 1,
"http_state" : "COMPLETE",
"last_data_receive_time" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.67304801940917969,
"timestamp" : 1692374811.458221
},
"last_data_send_time" : null,
"method" : "GET",
"path" : "/uri",
"refcount" : 1,
"request_body_already_read" : 0,
"request_body_fully_read" : true,
"request_body_type" : "NO_BODY",
"response_begun" : false,
"session" : {
"gupid" : "1ae645d-QZeDNIDYRj",
"pid" : 2261
},
"session_checkout_try" : 1,
"started_at" : {
"local" : "Fri Aug 18 16:06:51 2023",
"relative" : "1s ago",
"relative_timestamp" : -0.67304801940917969,
"timestamp" : 1692374811.458231
},
"state" : "WAITING_FOR_APP_OUTPUT",
"sticky_session" : false,
"want_keep_alive" : false
},
"lingering_request_count" : 0,
"name" : "2-58224",
"number" : 58224,
"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
},
...
...
},
"threads" : 2
}
Does anyone know of a lead to fix this issue? Thanks
