Actions
Bug #12359
closed
100% cpu usage foreman-proxy after upgrade to 1.9
Added by Veaceslav Mindru over 8 years ago. Updated almost 7 years ago.
Status:
Resolved
Priority:
Normal
Assignee:
-
Category:
DHCP
Target version:
-
Description
after upgrade from 1.8 to 1.9 at some point the ruby process of foreman-proxy starts consuming high amounts of mem and is on 100% cpu usage. upgrade of foreman-proxy to 1.10 did not solve the issue.
Updated by Lukas Zapletal over 8 years ago
- Priority changed from High to Normal
Are you able to acquire stacktrace? Proxy does not provide signal trap, but if you modify launcher.rb with this code:
trap('TTIN') do
puts "Starting thread dump for current Ruby process"
puts "============================================="
puts ""
Thread.list.each do |thread|
puts "Thread TID-#{thread.object_id}"
puts thread.backtrace
puts ""
end
end
You can then send this signal and find the stracktraces in logs. Do this while CPU load is high tho.
Updated by Lukas Zapletal over 8 years ago
- Related to Feature #12370: Provide TTIN trap for stacktrace log output added
Updated by Dominic Cleal over 8 years ago
- Related to Bug #12392: 100% cpu usage on foreman-proxy DHCP calls added
Updated by Dominic Cleal over 8 years ago
https://github.com/theforeman/smart-proxy/compare/theforeman:1.9-stable...domcleal:1.9-stable-ttin.patch - equivalent patch for 1.9.
Updated by Alexandr Romanov over 8 years ago
This is the log form different foreman-proxy
Ubuntu 14.04
foreman-proxy 1.9.2-1
Starting thread dump for current Ruby process [54/424] ============================================= Thread TID-5466100 /usr/share/foreman-proxy/lib/smart_proxy.rb:151:in `block (2 levels) in launch' /usr/share/foreman-proxy/lib/smart_proxy.rb:149:in `each' /usr/share/foreman-proxy/lib/smart_proxy.rb:149:in `block in launch' /usr/share/foreman-proxy/lib/smart_proxy.rb:156:in `call' /usr/share/foreman-proxy/lib/smart_proxy.rb:156:in `join' /usr/share/foreman-proxy/lib/smart_proxy.rb:156:in `launch' /usr/share/foreman-proxy/bin/smart-proxy:6:in `<main>' Thread TID-20463920 /usr/lib/ruby/1.9.1/webrick/server.rb:98:in `block in start' /usr/lib/ruby/1.9.1/webrick/server.rb:22:in `start' /usr/lib/ruby/1.9.1/webrick/server.rb:89:in `start' /usr/lib/ruby/vendor_ruby/rack/handler/webrick.rb:14:in `run' /usr/lib/ruby/vendor_ruby/rack/server.rb:264:in `start' /usr/share/foreman-proxy/lib/smart_proxy.rb:137:in `block in launch' Thread TID-10371020 /usr/lib/ruby/1.9.1/webrick/utils.rb:184:in `block in initialize' Thread TID-20459720 [31/424] /usr/lib/ruby/1.9.1/ipaddr.rb:405:in `mask!' /usr/lib/ruby/1.9.1/ipaddr.rb:488:in `initialize' /usr/share/foreman-proxy/modules/dhcp/subnet.rb:32:in `new' /usr/share/foreman-proxy/modules/dhcp/subnet.rb:32:in `include?' /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:113:in `block in loadSubnetData' /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:98:in `scan' /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:98:in `loadSubnetData' /usr/share/foreman-proxy/modules/dhcp/subnet.rb:65:in `load' /usr/share/foreman-proxy/modules/dhcp/subnet.rb:75:in `records' /usr/share/foreman-proxy/modules/dhcp/server.rb:79:in `block in find_record' /usr/share/foreman-proxy/modules/dhcp/server.rb:78:in `each' /usr/share/foreman-proxy/modules/dhcp/server.rb:78:in `find_record' /usr/share/foreman-proxy/modules/dhcp/dhcp_api.rb:84:in `block in <class:DhcpApi>' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1541:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1541:in `block in compile!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:950:in `[]' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:950:in `block (3 levels) in route!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:966:in `route_eval' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:950:in `block (2 levels) in route!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:987:in `block in process_route' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:985:in `catch' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:985:in `process_route' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:948:in `block in route!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:947:in `each' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:947:in `route!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1059:in `block in dispatch!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `block in invoke' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `catch' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `invoke' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1056:in `dispatch!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:882:in `block in call!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `block in invoke' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `catch' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `invoke' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:882:in `call!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:870:in `call' /usr/lib/ruby/vendor_ruby/rack/methodoverride.rb:21:in `call' /usr/lib/ruby/vendor_ruby/rack/commonlogger.rb:33:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:212:in `call' /usr/share/foreman-proxy/lib/proxy/log.rb:35:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/xss_header.rb:18:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/path_traversal.rb:16:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/json_csrf.rb:18:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/base.rb:50:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/base.rb:50:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/frame_options.rb:31:in `call' /usr/lib/ruby/vendor_ruby/rack/nulllogger.rb:9:in `call' /usr/lib/ruby/vendor_ruby/rack/head.rb:11:in `call' /usr/lib/ruby/vendor_ruby/sinatra/showexceptions.rb:21:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:175:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1949:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1449:in `block in call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1726:in `synchronize' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1449:in `call' /usr/lib/ruby/vendor_ruby/rack/builder.rb:138:in `call' /usr/lib/ruby/vendor_ruby/rack/urlmap.rb:65:in `block in call' /usr/lib/ruby/vendor_ruby/rack/urlmap.rb:50:in `each' /usr/lib/ruby/vendor_ruby/rack/urlmap.rb:50:in `call' /usr/lib/ruby/vendor_ruby/rack/builder.rb:138:in `call' /usr/lib/ruby/vendor_ruby/rack/handler/webrick.rb:60:in `service' /usr/lib/ruby/1.9.1/webrick/httpserver.rb:138:in `service' /usr/lib/ruby/1.9.1/webrick/httpserver.rb:94:in `run' /usr/lib/ruby/1.9.1/webrick/server.rb:191:in `block in start_thread'
Updated by Alexandr Romanov over 8 years ago
And this is the log from the original installation (from which ticket was created).
Ubuntu 14.04
foreman-proxy 1.10.0~rc2-1
Starting thread dump for current Ruby process [108/564] ============================================= Thread TID-14067700 /usr/share/foreman-proxy/lib/launcher.rb:129:in `block (2 levels) in launch' /usr/share/foreman-proxy/lib/launcher.rb:127:in `each' /usr/share/foreman-proxy/lib/launcher.rb:127:in `block in launch' /usr/share/foreman-proxy/lib/launcher.rb:138:in `call' /usr/share/foreman-proxy/lib/launcher.rb:138:in `join' /usr/share/foreman-proxy/lib/launcher.rb:138:in `launch' /usr/share/foreman-proxy/bin/smart-proxy:6:in `<main>' Thread TID-27919840 /usr/lib/ruby/1.9.1/webrick/server.rb:98:in `block in start' /usr/lib/ruby/1.9.1/webrick/server.rb:22:in `start' /usr/lib/ruby/1.9.1/webrick/server.rb:89:in `start' /usr/lib/ruby/vendor_ruby/rack/handler/webrick.rb:14:in `run' /usr/lib/ruby/vendor_ruby/rack/server.rb:264:in `start' /usr/share/foreman-proxy/lib/launcher.rb:113:in `block in launch' Thread TID-24946400 /usr/lib/ruby/1.9.1/webrick/utils.rb:184:in `block in initialize' Thread TID-23493380 [85/564] /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:96:in `block (2 levels) in parse_config_and_leases_for_records' /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:95:in `each' /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:95:in `block in parse_config_and_leases_for_records' /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:90:in `scan' /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:90:in `parse_config_and_leases_for_records' /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:147:in `loadSubnetData' /usr/share/foreman-proxy/modules/dhcp/dhcp_api.rb:42:in `load_subnet_data' /usr/share/foreman-proxy/modules/dhcp/dhcp_api.rb:95:in `block in <class:DhcpApi>' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1541:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1541:in `block in compile!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:950:in `[]' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:950:in `block (3 levels) in route!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:966:in `route_eval' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:950:in `block (2 levels) in route!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:987:in `block in process_route' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:985:in `catch' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:985:in `process_route' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:948:in `block in route!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:947:in `each' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:947:in `route!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1059:in `block in dispatch!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `block in invoke' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `catch' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `invoke' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1056:in `dispatch!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:882:in `block in call!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `block in invoke' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `catch' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `invoke' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:882:in `call!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:870:in `call' /usr/lib/ruby/vendor_ruby/rack/methodoverride.rb:21:in `call' /usr/lib/ruby/vendor_ruby/rack/commonlogger.rb:33:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:212:in `call' /usr/share/foreman-proxy/lib/proxy/log.rb:58:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/xss_header.rb:18:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/path_traversal.rb:16:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/json_csrf.rb:18:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/base.rb:50:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/base.rb:50:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/frame_options.rb:31:in `call' /usr/lib/ruby/vendor_ruby/rack/nulllogger.rb:9:in `call' /usr/lib/ruby/vendor_ruby/rack/head.rb:11:in `call' /usr/lib/ruby/vendor_ruby/sinatra/showexceptions.rb:21:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:175:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1949:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1449:in `block in call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1726:in `synchronize' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1449:in `call' /usr/lib/ruby/vendor_ruby/rack/builder.rb:138:in `call' /usr/lib/ruby/vendor_ruby/rack/urlmap.rb:65:in `block in call' /usr/lib/ruby/vendor_ruby/rack/urlmap.rb:50:in `each' /usr/lib/ruby/vendor_ruby/rack/urlmap.rb:50:in `call' /usr/lib/ruby/vendor_ruby/rack/builder.rb:138:in `call' /usr/lib/ruby/vendor_ruby/rack/handler/webrick.rb:60:in `service' /usr/lib/ruby/1.9.1/webrick/httpserver.rb:138:in `service' /usr/lib/ruby/1.9.1/webrick/httpserver.rb:94:in `run' /usr/lib/ruby/1.9.1/webrick/server.rb:191:in `block in start_thread' Thread TID-70174802568480 [25/564] /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:208:in `parse_record_options' /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:96:in `block (2 levels) in parse_config_and_leases_for_records' /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:95:in `each' /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:95:in `block in parse_config_and_leases_for_records' /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:90:in `scan' /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:90:in `parse_config_and_leases_for_records' /usr/share/foreman-proxy/modules/dhcp/providers/server/isc.rb:147:in `loadSubnetData' /usr/share/foreman-proxy/modules/dhcp/dhcp_api.rb:42:in `load_subnet_data' /usr/share/foreman-proxy/modules/dhcp/dhcp_api.rb:95:in `block in <class:DhcpApi>' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1541:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1541:in `block in compile!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:950:in `[]' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:950:in `block (3 levels) in route!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:966:in `route_eval' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:950:in `block (2 levels) in route!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:987:in `block in process_route' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:985:in `catch' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:985:in `process_route' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:948:in `block in route!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:947:in `each' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:947:in `route!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1059:in `block in dispatch!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `block in invoke' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `catch' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `invoke' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1056:in `dispatch!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:882:in `block in call!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `block in invoke' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `catch' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1041:in `invoke' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:882:in `call!' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:870:in `call' /usr/lib/ruby/vendor_ruby/rack/methodoverride.rb:21:in `call' /usr/lib/ruby/vendor_ruby/rack/commonlogger.rb:33:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:212:in `call' /usr/share/foreman-proxy/lib/proxy/log.rb:58:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/xss_header.rb:18:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/path_traversal.rb:16:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/json_csrf.rb:18:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/base.rb:50:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/base.rb:50:in `call' /usr/lib/ruby/vendor_ruby/rack/protection/frame_options.rb:31:in `call' /usr/lib/ruby/vendor_ruby/rack/nulllogger.rb:9:in `call' /usr/lib/ruby/vendor_ruby/rack/head.rb:11:in `call' /usr/lib/ruby/vendor_ruby/sinatra/showexceptions.rb:21:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:175:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1949:in `call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1449:in `block in call' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1726:in `synchronize' /usr/lib/ruby/vendor_ruby/sinatra/base.rb:1449:in `call' /usr/lib/ruby/vendor_ruby/rack/builder.rb:138:in `call' /usr/lib/ruby/vendor_ruby/rack/urlmap.rb:65:in `block in call' /usr/lib/ruby/vendor_ruby/rack/urlmap.rb:50:in `each' /usr/lib/ruby/vendor_ruby/rack/urlmap.rb:50:in `call' /usr/lib/ruby/vendor_ruby/rack/builder.rb:138:in `call' /usr/lib/ruby/vendor_ruby/rack/handler/webrick.rb:60:in `service' /usr/lib/ruby/1.9.1/webrick/httpserver.rb:138:in `service' /usr/lib/ruby/1.9.1/webrick/httpserver.rb:94:in `run' /usr/lib/ruby/1.9.1/webrick/server.rb:191:in `block in start_thread'
Updated by Anonymous about 8 years ago
I opened a pull request (https://github.com/theforeman/smart-proxy/pull/409) that eliminates parsing of the dhcpd leases file on every request. The changes have been tested against a fairly low-load dhcpd server, and I would appreciate if you could run a test against a busy dhcpd server and report your findings in the main ticket: http://projects.theforeman.org/issues/2687.
Updated by Dominic Cleal almost 8 years ago
- Category set to DHCP
- Status changed from New to Feedback
The inotify-related changes from ticket #2687 have now been made in develop (nightly) for 1.13, which should drastically reduce the amount of re-parsing of config/lease files during smart proxy requests. I'm moving this ticket state to feedback as hopefully the next release will resolve this issue.
#12425 in 1.12 should also have reduced the number of calls being made to the DHCP smart proxy, thus reducing the load.
Updated by Anonymous almost 7 years ago
- Status changed from Feedback to Resolved
Actions