Bug #15597
closed
"undefined method `each' for nil:NilClass" from WEBrick
Description
Foreman makes a duplicate call to the Puppet CA Smart-Proxy trying to delete the autosign entry for a newly provisioned host.
Logs are below:
http://pastebin.com/5R8a7Ur3
Updated by Dominic Cleal over 8 years ago
- Status changed from New to Need more information
- Priority changed from Immediate to Normal
I think the second call to remove the autosign entry is a consequence of the orchestration rollback, because the first call failed, but should be entirely harmless. The smart proxy should return a 404 if the entry's already removed, which Foreman will ignore.
The problem in the log file appears to be the 500 error from your PuppetCA smart proxy when removing the entry. Its log files should show more information.
Updated by Chris Pisano over 8 years ago
Dominic Cleal wrote:
I think the second call to remove the autosign entry is a consequence of the orchestration rollback, because the first call failed, but should be entirely harmless. The smart proxy should return a 404 if the entry's already removed, which Foreman will ignore.
The problem in the log file appears to be the 500 error from your PuppetCA smart proxy when removing the entry. Its log files should show more information.
Dominic, here are the debug logs from the Smart-Proxy.
Updated by Dominic Cleal over 8 years ago
Those debug logs only show 404 and 200 responses, which is correct, but the Foreman log clearly shows a 500 error. Perhaps the grep is hiding the error messages or requests that are failing?
Updated by Chris Pisano over 8 years ago
Dominic Cleal wrote:
Those debug logs only show 404 and 200 responses, which is correct, but the Foreman log clearly shows a 500 error. Perhaps the grep is hiding the error messages or requests that are failing?
Here are more of the logs. I cat'ed the file and took everything from a few second before to a few seconds after. I also checked my other CA smart-proxy logs (load balanced active passive) to make sure nothing was in there and I didn't see any connections from Foreman to that host.
Updated by Dominic Cleal over 8 years ago
The error messages in the log file are certainly interesting, but I can't tell if they're the cause or harmless. I can though see that those messages shouldn't occur on EL7 (versus EL6, which I assume you're running).
The times don't quite correlate though, they're a few minute earlier when things appear to be OK on Foreman. Do you have anything logged on the smart proxy closer to 15:12:15 that matches this message on Foreman?
2016-07-06 15:12:15 [app] [W] Delete autosign entry for maaentlweb-p01.advisory.com task failed with the following error: ERF12-4681 [ProxyAPI::ProxyException]: Unable to delete PuppetCA autosign for 88f49662-57c6-426a-89e9-a77dc5f93410 ([RestClient::InternalServerError]: 500 Internal Server Error) for proxy https://puppetca.advisory.com:8443/puppet/ca
Updated by Chris Pisano over 8 years ago
Dominic Cleal wrote:
The error messages in the log file are certainly interesting, but I can't tell if they're the cause or harmless. I can though see that those messages shouldn't occur on EL7 (versus EL6, which I assume you're running).
The times don't quite correlate though, they're a few minute earlier when things appear to be OK on Foreman. Do you have anything logged on the smart proxy closer to 15:12:15 that matches this message on Foreman?
2016-07-06 15:12:15 [app] [W] Delete autosign entry for maaentlweb-p01.advisory.com task failed with the following error: ERF12-4681 [ProxyAPI::ProxyException]: Unable to delete PuppetCA autosign for 88f49662-57c6-426a-89e9-a77dc5f93410 ([RestClient::InternalServerError]: 500 Internal Server Error) for proxy https://puppetca.advisory.com:8443/puppet/ca
Dominic, here are the logs from that timeframe. Yes I am on EL6. . . soon to be EL7.
Updated by Dominic Cleal over 8 years ago
- Project changed from Foreman to Smart Proxy
- Subject changed from Foreman Sends Duplicate Request to Delete Autosign Entry to "undefined method `each' for nil:NilClass" from WEBrick
- Category changed from PuppetCA to Core
- Status changed from Need more information to New
Thanks, I think that shows the same stack trace is the likely cause of the 500:
D, [2016-07-06T15:12:13.761594 #30643] DEBUG -- : accept: 10.150.130.9:25457 D, [2016-07-06T15:12:13.763154 #30643] DEBUG -- : Rack::Handler::WEBrick is invoked. E, [2016-07-06T15:12:13.763314 #30643] ERROR -- : undefined method `each' for nil:NilClass (NoMethodError) /usr/lib/ruby/1.8/webrick/httprequest.rb:153:in `each' /usr/lib/ruby/1.8/webrick/httprequest.rb:210:in `orig_meta_vars' /usr/lib/ruby/1.8/webrick/https.rb:46:in `meta_vars' /usr/lib/ruby/gems/1.8/gems/rack-1.1.0/lib/rack/handler/webrick.rb:23:in `service' /usr/lib/ruby/1.8/webrick/httpserver.rb:104:in `service' /usr/lib/ruby/1.8/webrick/httpserver.rb:65:in `run' /usr/lib/ruby/1.8/webrick/server.rb:173:in `start_thread' /usr/lib/ruby/1.8/webrick/server.rb:162:in `start' /usr/lib/ruby/1.8/webrick/server.rb:162:in `start_thread' /usr/lib/ruby/1.8/webrick/server.rb:95:in `start' /usr/lib/ruby/1.8/webrick/server.rb:92:in `each' /usr/lib/ruby/1.8/webrick/server.rb:92:in `start' /usr/lib/ruby/1.8/webrick/server.rb:23:in `start' /usr/lib/ruby/1.8/webrick/server.rb:82:in `start' /usr/share/foreman-proxy/lib/launcher.rb:136:in `launch' /usr/share/foreman-proxy/lib/launcher.rb:136:in `initialize' /usr/share/foreman-proxy/lib/launcher.rb:136:in `new' /usr/share/foreman-proxy/lib/launcher.rb:136:in `launch' /usr/share/foreman-proxy/bin/smart-proxy:6 D, [2016-07-06T15:12:13.763712 #30643] DEBUG -- : close: 10.150.130.9:25457
I can't explain this any further than saying I can see this bit of code appears to be fixed in later Ruby versions. I don't know why it would have started to fail on EL6, or why it appears to only affect certain types of requests. Moving this to the smart proxy project for now.
Updated by Anonymous over 7 years ago
- Status changed from New to Resolved
most likely resolved by depending on newer Rubies now.