Bug #21214
closedfailure to find IP on /22 - undefined method `reopen' for nil:NilClass (NoMethodError)
Description
Have a subnet that is not returning IPs. Well, it was.. Now its not (just over night, no changes we know of). It is the only subnet we have that is /22 and Im not sure our IT set up the scope correctly
in ms-dhcp.
Here is what a good request looks like:
D, [2017-10-05T09:21:20.696265 #3096] DEBUG -- : accept: 100.90.131.25:57322 D, [2017-10-05T09:21:20.698264 #3096] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2017-10-05T09:21:20.698264 #3096] DEBUG -- : Loading subnets for 100.88.0.122 D, [2017-10-05T09:21:20.699262 #3096] DEBUG -- : executing: c:\windows\system32\cmd.exe /c c:\Windows\System32\netsh.exe -c dhcp server 100.88.0.122 show scope D, [2017-10-05T09:21:20.931275 #3096] DEBUG -- : Enumerated the scopes on 100.88.0.122 D, [2017-10-05T09:21:20.966281 #3096] DEBUG -- : Loading subnet data for 100.91.41.0/255.255.255.0 D, [2017-10-05T09:21:20.966281 #3096] DEBUG -- : executing: c:\windows\system32\cmd.exe /c c:\Windows\System32\netsh.exe -c dhcp server 100.88.0.122 scope 100.91.41.0 show client 1 D, [2017-10-05T09:21:21.077285 #3096] DEBUG -- : Enumerated hosts on 100.91.41.0 D, [2017-10-05T09:21:23.418402 #3096] DEBUG -- : executing: c:\windows\system32\cmd.exe /c c:\Windows\System32\netsh.exe -c dhcp server 100.88.0.122 scope 100.91.41.0 Show ReservedOptionValue 100.91.41.186 D, [2017-10-05T09:21:23.486406 #3096] DEBUG -- : Queried 100.91.41.186 options D, [2017-10-05T09:21:23.493416 #3096] DEBUG -- : trying to find an ip address, we got {:from=>nil, :to=>nil} D, [2017-10-05T09:21:23.505411 #3096] DEBUG -- : Searching for free IP - pinging 100.91.41.182 D, [2017-10-05T09:21:45.166508 #3096] DEBUG -- : Found free IP 100.91.41.182 out of a total of 151 free IPs I, [2017-10-05T09:21:45.168507 #3096] INFO -- : 100.90.131.25 - - [05/Oct/2017 09:21:45] "GET /dhcp/100.91.41.0/unused_ip HTTP/1.1" 200 22 24.4702 D, [2017-10-05T09:21:45.213512 #3096] DEBUG -- : close: 100.90.131.25:57322
and a bad request:
D, [2017-10-05T09:24:04.222593 #3096] DEBUG -- : accept: 100.90.131.25:57374 D, [2017-10-05T09:24:04.224589 #3096] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2017-10-05T09:24:04.225588 #3096] DEBUG -- : Loading subnets for 100.88.0.122 D, [2017-10-05T09:24:04.225588 #3096] DEBUG -- : executing: c:\windows\system32\cmd.exe /c c:\Windows\System32\netsh.exe -c dhcp server 100.88.0.122 show scope D, [2017-10-05T09:24:04.449598 #3096] DEBUG -- : Enumerated the scopes on 100.88.0.122 D, [2017-10-05T09:24:04.481605 #3096] DEBUG -- : Loading subnet data for 100.90.136.0/255.255.252.0 D, [2017-10-05T09:24:04.482612 #3096] DEBUG -- : executing: c:\windows\system32\cmd.exe /c c:\Windows\System32\netsh.exe -c dhcp server 100.88.0.122 scope 100.90.136.0 show client 1 D, [2017-10-05T09:24:04.555606 #3096] DEBUG -- : Enumerated hosts on 100.90.136.0 D, [2017-10-05T09:24:05.373643 #3096] DEBUG -- : trying to find an ip address, we got {:from=>"100.90.136.1", :to=>"100.90.139.254"} D, [2017-10-05T09:24:35.381173 #3096] DEBUG -- : execution expired E, [2017-10-05T09:24:35.382175 #3096] ERROR -- : undefined method `reopen' for nil:NilClass D, [2017-10-05T09:24:35.382175 #3096] DEBUG -- : undefined method `reopen' for nil:NilClass (NoMethodError) C:/foreman-proxy/smart-proxy-l3_4/modules/dhcp_common/subnet.rb:86:in `write_index_and_unlock' C:/foreman-proxy/smart-proxy-l3_4/modules/dhcp_common/subnet.rb:125:in `unused_ip' C:/foreman-proxy/smart-proxy-l3_4/modules/dhcp_common/server.rb:74:in `unused_ip' C:/foreman-proxy/smart-proxy-l3_4/modules/dhcp/dhcp_api.rb:59:in `block in <class:DhcpApi>' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1611:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1611:in `block in compile!' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:975:in `block (3 levels) in route!' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:994:in `route_eval' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:975:in `block (2 levels) in route!' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1015:in `block in process_route' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1013:in `catch' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1013:in `process_route' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:973:in `block in route!' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:972:in `each' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:972:in `route!' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1085:in `block in dispatch!' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `block in invoke' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `catch' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `invoke' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1082:in `dispatch!' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:907:in `block in call!' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `block in invoke' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `catch' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `invoke' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:907:in `call!' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:895:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-1.5.5/lib/rack/methodoverride.rb:21:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-1.5.5/lib/rack/commonlogger.rb:33:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:219:in `call' C:/foreman-proxy/smart-proxy-l3_4/lib/proxy/log.rb:63:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-protection-1.5.3/lib/rack/protection/xss_header.rb:18:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-protection-1.5.3/lib/rack/protection/path_traversal.rb:16:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-protection-1.5.3/lib/rack/protection/json_csrf.rb:18:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-protection-1.5.3/lib/rack/protection/base.rb:49:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-protection-1.5.3/lib/rack/protection/base.rb:49:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-protection-1.5.3/lib/rack/protection/frame_options.rb:31:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-1.5.5/lib/rack/nulllogger.rb:9:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-1.5.5/lib/rack/head.rb:11:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/show_exceptions.rb:25:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:182:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:2013:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1487:in `block in call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1787:in `synchronize' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/sinatra-1.4.8/lib/sinatra/base.rb:1487:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-1.5.5/lib/rack/builder.rb:138:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-1.5.5/lib/rack/urlmap.rb:65:in `block in call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-1.5.5/lib/rack/urlmap.rb:50:in `each' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-1.5.5/lib/rack/urlmap.rb:50:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-1.5.5/lib/rack/builder.rb:138:in `call' C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/rack-1.5.5/lib/rack/handler/webrick.rb:60:in `service' C:/Ruby23-x64/lib/ruby/2.3.0/webrick/httpserver.rb:140:in `service' C:/Ruby23-x64/lib/ruby/2.3.0/webrick/httpserver.rb:96:in `run' C:/Ruby23-x64/lib/ruby/2.3.0/webrick/server.rb:296:in `block in start_thread' I, [2017-10-05T09:24:35.383176 #3096] INFO -- : 100.90.131.25 - - [05/Oct/2017 09:24:35] "GET /dhcp/100.90.136.0/unused_ip?from=100.90.136.1&to=100.90.139.254 HTTP/1.1" 400 42 31.1576 D, [2017-10-05T09:24:35.428184 #3096] DEBUG -- : close: 100.90.131.25:57374
the difference starts at:
D, [2017-10-05T09:24:05.373643 #3096] DEBUG -- : trying to find an ip address, we got {:from=>"100.90.136.1", :to=>"100.90.139.254"}
which looks to be an issue while attempting to get information from IT DHCP. The only difference I see in this subnet is that it is a /22 and the rest are all /24. I tried other subnets, and they return IP's fine, so this looks to be a config issue with IT/Lab.
I am not totally familiar with DHCP settings, but on this scope in DHCP they have it set to:
============================================================= Start Address - End Address - Address Type ============================================================= 100.90.136.130 - 100.90.136.230 - DHCP ONLY No of IP Ranges : 1 in the Scope : 100.90.136.0.
Which doesn't really make sense since its IP range is 100.90.136.1 -> 100.90.139.254
Lastly, there are no other scopes beyond 100.90.136.0 - Does there need to be a scope for each octect/ip-range?
Any help would be appreciated.
Updated by Jeff Sparrow over 6 years ago
This was due to bad temp files. I zipped them up (removed them) and it worked again.
On us with the misfortune of using msft - temp