Project

General

Profile

Bug #21184

Bonded provision and primary interface causes DHCP duplication

Added by Trey Dockendorf almost 5 years ago. Updated over 3 years ago.

Status:
New
Priority:
Normal
Assignee:
-
Category:
Network
Target version:
-
Difficulty:
Triaged:
No
Bugzilla link:
Pull request:
Fixed in Releases:
Found in Releases:

Description

I am adding a host that has a bond as the primary and provision interface. For record keeping I add the slave interfaces with just their interface name and MAC address defined (managed unchecked). When the host is created it seems Foreman is sending the DHCP proxy the same command twice [1]. The logs for the proxy show the omshell commands are duplicated [1] which causes an error in Foreman [2]. The only way to add this host is by modifying /var/lib/dhcpd/dhcpd.leases, deleting this new host's lines, then restarting dhcpd. Once that modification is made I'm able to add the host. Looking at the items added to DHCP it looks like both interfaces for the bond are added to DHCP despite the actual interfaces being unmanaged in Foreman. This operation is not something I've attempted (bonded host) since around 1.12, and it worked back then.

As a test I deleted the host and recreated but this time I did not add interfaces for the bond slave interfaces. I only added bond0 interface and the BMC interface, and receive no errors. Having the slave interfaces defined and each of their MAC addresses added to DHCP does make sense, but seems to cause some sort of duplication.

As yet another test I took the successful host without slaves defined and went back and added the non-managed slaves and get similar errors.

[1]:
, [2017-10-03T16:29:32.529539 ] INFO -- : 10.20.0.1 - - [03/Oct/2017:16:29:32 -0400] "GET /dhcp/10.16.0.0/ip/10.16.2.2 HTTP/1.1" 404 48 0.0008

D, [2017-10-03T16:29:32.570113 ] DEBUG -- : close: 10.20.0.1:39320
D, [2017-10-03T16:29:32.633139 ] DEBUG -- : accept: 10.20.0.1:39322
D, [2017-10-03T16:29:32.634593 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
D, [2017-10-03T16:29:32.635648 ] DEBUG -- : verifying remote client 10.20.0.1 against trusted_hosts ["foreman.<DOMAIN>"]
D, [2017-10-03T16:29:32.635952 ] DEBUG -- : Ignoring duplicates for macs: ["D0:94:66:0A:84:8D", "D0:94:66:0A:84:8E"]
D, [2017-10-03T16:29:32.641416 ] DEBUG -- : omshell: executed - set name = "ufm02.<DOMAIN>-01"
D, [2017-10-03T16:29:32.641507 ] DEBUG -- : nil
D, [2017-10-03T16:29:32.641564 ] DEBUG -- : omshell: executed - set ip-address = 10.20.2.2
D, [2017-10-03T16:29:32.641599 ] DEBUG -- : nil
D, [2017-10-03T16:29:32.641638 ] DEBUG -- : omshell: executed - set hardware-address = d0:94:66:0a:84:8d
D, [2017-10-03T16:29:32.641699 ] DEBUG -- : nil
D, [2017-10-03T16:29:32.641737 ] DEBUG -- : omshell: executed - set hardware-type = 1
D, [2017-10-03T16:29:32.641771 ] DEBUG -- : nil
D, [2017-10-03T16:29:32.641920 ] DEBUG -- : omshell: executed - set statements = "filename = \"pxelinux.0\"; next-server = c0:94:f7:1c; option host-name = \"ufm02.<DOMAIN>\";"
D, [2017-10-03T16:29:32.641968 ] DEBUG -- : nil
D, [2017-10-03T16:29:32.642031 ] DEBUG -- : omshell: executed - create
D, [2017-10-03T16:29:32.642074 ] DEBUG -- : nil
D, [2017-10-03T16:29:32.659846 ] DEBUG -- : caught :modify event on /var/lib/dhcpd/dhcpd.leases.
D, [2017-10-03T16:29:32.662395 ] DEBUG -- : Added a reservation: 10.20.2.2:d0:94:66:0a:84:8d:ufm02.<DOMAIN>-01
D, [2017-10-03T16:29:32.664551 ] DEBUG -- : Added DHCP reservation for ufm02.<DOMAIN>-01 (10.20.2.2 / d0:94:66:0a:84:8d)
I, [2017-10-03T16:29:32.664916 ] INFO -- : 10.20.0.1 - - [03/Oct/2017:16:29:32 -0400] "POST /dhcp/10.20.0.0 HTTP/1.1" 200 - 0.0297

D, [2017-10-03T16:29:32.665769 ] DEBUG -- : close: 10.20.0.1:39322
D, [2017-10-03T16:29:32.690018 ] DEBUG -- : accept: 10.20.0.1:39324
D, [2017-10-03T16:29:32.691299 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
D, [2017-10-03T16:29:32.692231 ] DEBUG -- : verifying remote client 10.20.0.1 against trusted_hosts ["foreman.<DOMAIN>"]
D, [2017-10-03T16:29:32.692588 ] DEBUG -- : Ignoring duplicates for macs: ["d0:94:66:0a:84:8d", "D0:94:66:0A:84:8E"]
D, [2017-10-03T16:29:32.697085 ] DEBUG -- : omshell: executed - set name = "ufm02.<DOMAIN>-02"
D, [2017-10-03T16:29:32.697180 ] DEBUG -- : nil
D, [2017-10-03T16:29:32.697261 ] DEBUG -- : omshell: executed - set ip-address = 10.20.2.2
D, [2017-10-03T16:29:32.697317 ] DEBUG -- : nil
D, [2017-10-03T16:29:32.697367 ] DEBUG -- : omshell: executed - set hardware-address = d0:94:66:0a:84:8d
D, [2017-10-03T16:29:32.697403 ] DEBUG -- : nil
D, [2017-10-03T16:29:32.697444 ] DEBUG -- : omshell: executed - set hardware-type = 1
D, [2017-10-03T16:29:32.697478 ] DEBUG -- : nil
D, [2017-10-03T16:29:32.697630 ] DEBUG -- : omshell: executed - set statements = "filename = \"pxelinux.0\"; next-server = c0:94:f7:1c; option host-name = \"ufm02.<DOMAIN>\";"
D, [2017-10-03T16:29:32.697680 ] DEBUG -- : nil
D, [2017-10-03T16:29:32.697720 ] DEBUG -- : omshell: executed - create
D, [2017-10-03T16:29:32.697751 ] DEBUG -- : nil
E, [2017-10-03T16:29:32.713313 ] ERROR -- : Omshell failed:

obj: <null>

, > obj: host
, > obj: host
, name = "ufm02.<DOMAIN>-02"
, > obj: host
, name = "ufm02.<DOMAIN>-02"
, ip-address = 0a:14:02:02
, > obj: host
, name = "ufm02.<DOMAIN>-02"
, ip-address = 0a:14:02:02
, hardware-address = d0:94:66:0a:84:8d
, > obj: host
, name = "ufm02.<DOMAIN>-02"
, ip-address = 0a:14:02:02
, hardware-address = d0:94:66:0a:84:8d
, hardware-type = 1
, > obj: host
, name = "ufm02.<DOMAIN>-02"
, ip-address = 0a:14:02:02
, hardware-address = d0:94:66:0a:84:8d
, hardware-type = 1
, statements = "filename = "pxelinux.0"; next-server = c0:94:f7:1c; option host-name = "ufm02.<DOMAIN>";"
, > can't open object: key conflict
, obj: host
, name = "ufm02.<DOMAIN>-02"
, ip-address = 0a:14:02:02
, hardware-address = d0:94:66:0a:84:8d
, hardware-type = 1
, statements = "filename = "pxelinux.0"; next-server = c0:94:f7:1c; option host-name = "ufm02.<DOMAIN>";"
, >
E, [2017-10-03T16:29:32.713575 ] ERROR -- : Hardware address conflict.
D, [2017-10-03T16:29:32.713617 ] DEBUG -- : Hardware address conflict. (Proxy::DHCP::Collision)
/usr/share/foreman-proxy/modules/dhcp_common/isc/omapi_provider.rb:95:in `report'
/usr/share/foreman-proxy/modules/dhcp_common/isc/omapi_provider.rb:80:in `om_disconnect'
/usr/share/foreman-proxy/modules/dhcp_common/isc/omapi_provider.rb:54:in `om_add_record'
/usr/share/foreman-proxy/modules/dhcp_common/isc/omapi_provider.rb:30:in `add_record'
/usr/share/foreman-proxy/modules/dhcp/dhcp_api.rb:96:in `block in <class:DhcpApi>'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1611:in `call'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1611:in `block in compile!'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:975:in `[]'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:975:in `block (3 levels) in route!'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:994:in `route_eval'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:975:in `block (2 levels) in route!'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1015:in `block in process_route'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1013:in `catch'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1013:in `process_route'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:973:in `block in route!'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:972:in `each'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:972:in `route!'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1085:in `block in dispatch!'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `block in invoke'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `catch'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `invoke'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1082:in `dispatch!'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:907:in `block in call!'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `block in invoke'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `catch'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `invoke'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:907:in `call!'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:895:in `call'
/usr/share/gems/gems/rack-1.6.4/lib/rack/methodoverride.rb:22:in `call'
/usr/share/gems/gems/rack-1.6.4/lib/rack/commonlogger.rb:33:in `call'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:219:in `call'
/usr/share/foreman-proxy/lib/proxy/log.rb:109:in `call'
/usr/share/foreman-proxy/lib/proxy/request_id_middleware.rb:9:in `call'
/usr/share/gems/gems/rack-protection-1.5.3/lib/rack/protection/xss_header.rb:18:in `call'
/usr/share/gems/gems/rack-protection-1.5.3/lib/rack/protection/path_traversal.rb:16:in `call'
/usr/share/gems/gems/rack-protection-1.5.3/lib/rack/protection/json_csrf.rb:18:in `call'
/usr/share/gems/gems/rack-protection-1.5.3/lib/rack/protection/base.rb:49:in `call'
/usr/share/gems/gems/rack-protection-1.5.3/lib/rack/protection/base.rb:49:in `call'
/usr/share/gems/gems/rack-protection-1.5.3/lib/rack/protection/frame_options.rb:31:in `call'
/usr/share/gems/gems/rack-1.6.4/lib/rack/nulllogger.rb:9:in `call'
/usr/share/gems/gems/rack-1.6.4/lib/rack/head.rb:13:in `call'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/show_exceptions.rb:25:in `call'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:182:in `call'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:2013:in `call'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1487:in `block in call'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1787:in `synchronize'
/usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1487:in `call'
/usr/share/gems/gems/rack-1.6.4/lib/rack/urlmap.rb:66:in `block in call'
/usr/share/gems/gems/rack-1.6.4/lib/rack/urlmap.rb:50:in `each'
/usr/share/gems/gems/rack-1.6.4/lib/rack/urlmap.rb:50:in `call'
/usr/share/gems/gems/rack-1.6.4/lib/rack/builder.rb:153:in `call'
/usr/share/gems/gems/rack-1.6.4/lib/rack/handler/webrick.rb:88:in `service'
/usr/share/ruby/webrick/httpserver.rb:138:in `service'
/usr/share/ruby/webrick/httpserver.rb:94:in `run'
/usr/share/ruby/webrick/server.rb:295:in `block in start_thread'
I, [2017-10-03T16:29:32.714071 ] INFO -- : 10.20.0.1 - - [03/Oct/2017:16:29:32 -0400] "POST /dhcp/10.20.0.0 HTTP/1.1" 409 26 0.0222

[2]:
Create DHCP Settings for ufm02.<DOMAIN> task failed with the following error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict) for proxy https://names1.&lt;DOMAIN&gt;:8443/dhcp


Related issues

Related to Foreman - Bug #25051: Creating an bond interface with slaves results in "Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict)"Duplicate

History

#1 Updated by Marek Hulán almost 5 years ago

  • Category set to Network

#2 Updated by Andreas Rogge almost 5 years ago

I'm seeing the same issue here.
It must have been working in older versions, as I'm trying to redeploy an existing host.

#3 Updated by Shane Thiessen almost 4 years ago

I am seeing this issue still in 1.18.1 when provisioning a bonded interface

D, [2018-08-29T07:34:41.857959 ] DEBUG -- : close: 10.100.0.107:51222
D, [2018-08-29T07:34:41.857959 ] DEBUG -- : accept: 10.100.0.107:51224
D, [2018-08-29T07:34:41.904834 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
E, [2018-08-29T07:34:41.904834 990e9026] ERROR -- : Record 10.10.20.41/255.255.255.0 conflicts with an existing record.
D, [2018-08-29T07:34:41.904834 990e9026] DEBUG -- : Record 10.10.20.41/255.255.255.0 conflicts with an existing record. (Proxy::DHCP::Collision)
c:/Smart-Proxy/modules/dhcp_native_ms/dhcp_native_ms_main.rb:50:in `rescue in create_reservation'
c:/Smart-Proxy/modules/dhcp_native_ms/dhcp_native_ms_main.rb:38:in `create_reservation'
c:/Smart-Proxy/modules/dhcp_native_ms/dhcp_native_ms_main.rb:33:in `add_record'
c:/Smart-Proxy/modules/dhcp/dhcp_api.rb:98:in `block in <class:DhcpApi>'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1634:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1634:in `block in compile!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:992:in `block (3 levels) in route!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1011:in `route_eval'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:992:in `block (2 levels) in route!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1039:in `block in process_route'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1037:in `catch'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1037:in `process_route'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:990:in `block in route!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:989:in `each'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:989:in `route!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1096:in `block in dispatch!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `block in invoke'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `catch'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `invoke'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1093:in `dispatch!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:924:in `block in call!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `block in invoke'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `catch'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `invoke'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:924:in `call!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:913:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/method_override.rb:22:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/common_logger.rb:33:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:231:in `call'
c:/Smart-Proxy/lib/proxy/log.rb:109:in `call'
c:/Smart-Proxy/lib/proxy/request_id_middleware.rb:9:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/xss_header.rb:18:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/path_traversal.rb:16:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/json_csrf.rb:26:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/base.rb:50:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/base.rb:50:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/frame_options.rb:31:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/null_logger.rb:9:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/head.rb:12:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/show_exceptions.rb:22:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:194:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1957:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1501:in `block in call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1728:in `synchronize'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1501:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/urlmap.rb:68:in `block in call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/urlmap.rb:53:in `each'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/urlmap.rb:53:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/builder.rb:153:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/handler/webrick.rb:86:in `service'
C:/Ruby24-x64/lib/ruby/2.4.0/webrick/httpserver.rb:140:in `service'
C:/Ruby24-x64/lib/ruby/2.4.0/webrick/httpserver.rb:96:in `run'
C:/Ruby24-x64/lib/ruby/2.4.0/webrick/server.rb:308:in `block in start_thread'
I, [2018-08-29T07:34:41.904834 990e9026] INFO -- : 10.100.0.107 - - [29/Aug/2018:07:34:41 -0500] "POST /dhcp/10.10.20.0 HTTP/1.1" 409 67 0.0000

#4 Updated by Lukas Zapletal almost 4 years ago

  • Related to Bug #25051: Creating an bond interface with slaves results in "Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict)" added

#5 Updated by Lukas Zapletal almost 4 years ago

  • Subject changed from bonded provision and primary interface causes DHCP duplication to Bonded provision and primary interface causes DHCP duplication
  • Found in Releases 1.18.1 added

Looks like 1.18 suffers from this as well.

#6 Updated by Anonymous almost 4 years ago

  • Found in Releases 1.18.2 added

#7 Updated by Shane Thiessen over 3 years ago

Output from 1.19

D, [2018-11-20T07:45:06.817871 ] DEBUG -- : accept: 10.100.0.107:35094
D, [2018-11-20T07:45:06.864750 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
I, [2018-11-20T07:45:06.864750 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:06 -0600] "GET /features HTTP/1.1" 200 21 0.0000

D, [2018-11-20T07:45:06.911629 ] DEBUG -- : close: 10.100.0.107:35094
D, [2018-11-20T07:45:08.318398 ] DEBUG -- : accept: 10.100.0.107:35100
D, [2018-11-20T07:45:08.365277 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
D, [2018-11-20T07:45:08.365277 0c121a6d] DEBUG -- : #<Proxy::DHCP::Reservation:0x00000000052fa530 @type="reservation", @name="waffles-f-1.test.com-01", @subnet=#<Proxy::DHCP::Subnet:0x00000000052fb390 @network="10.10.20.0", @netmask="255.255.255.0", @ipaddr=#<IPAddr: IPv4:10.10.20.0/255.255.255.0>, @options={}, @m=#<Monitor:0x00000000052fa6e8 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Thread::Mutex:0x00000000052fa5a8>>>, @ip="10.10.20.20", @mac="24:6e:96:1d:62:10", @options={:deleteable=>true, :hostname=>"waffles-f-1.test.com", 81=>0}>
I, [2018-11-20T07:45:08.365277 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:08 -0600] "GET /dhcp/10.10.20.0/mac/24:6e:96:1d:62:10 HTTP/1.1" 200 205 0.0000

D, [2018-11-20T07:45:08.412155 ] DEBUG -- : close: 10.100.0.107:35100
D, [2018-11-20T07:45:08.427782 ] DEBUG -- : accept: 10.100.0.107:35102
D, [2018-11-20T07:45:08.474660 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
D, [2018-11-20T07:45:08.474660 0c121a6d] DEBUG -- : #<Proxy::DHCP::Reservation:0x0000000005123ec8 @type="reservation", @name="waffles-f-1.test.com-01", @subnet=#<Proxy::DHCP::Subnet:0x0000000005128b30 @network="10.10.20.0", @netmask="255.255.255.0", @ipaddr=#<IPAddr: IPv4:10.10.20.0/255.255.255.0>, @options={}, @m=#<Monitor:0x0000000005128018 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Thread::Mutex:0x0000000005123f18>>>, @ip="10.10.20.20", @mac="24:6e:96:1d:62:10", @options={:deleteable=>true, :hostname=>"waffles-f-1.test.com", 81=>0}>
I, [2018-11-20T07:45:08.474660 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:08 -0600] "GET /dhcp/10.10.20.0/ip/10.10.20.20 HTTP/1.1" 200 207 0.0000

D, [2018-11-20T07:45:08.521539 ] DEBUG -- : close: 10.100.0.107:35102
D, [2018-11-20T07:45:08.537165 ] DEBUG -- : accept: 10.100.0.107:35104
D, [2018-11-20T07:45:08.584044 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
E, [2018-11-20T07:45:08.584044 0c121a6d] ERROR -- : No DHCP record for MAC 10.10.20.0/24:6e:96:1d:62:12 found
D, [2018-11-20T07:45:08.584044 0c121a6d] DEBUG -- : No DHCP record for MAC 10.10.20.0/24:6e:96:1d:62:12 found
I, [2018-11-20T07:45:08.584044 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:08 -0600] "GET /dhcp/10.10.20.0/mac/24:6e:96:1d:62:12 HTTP/1.1" 404 57 0.0000

D, [2018-11-20T07:45:08.630923 ] DEBUG -- : close: 10.100.0.107:35104
D, [2018-11-20T07:45:08.646549 ] DEBUG -- : accept: 10.100.0.107:35106
D, [2018-11-20T07:45:08.693428 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
D, [2018-11-20T07:45:08.693428 0c121a6d] DEBUG -- : #<Proxy::DHCP::Reservation:0x0000000004fa3800 @type="reservation", @name="waffles-f-1.test.com-01", @subnet=#<Proxy::DHCP::Subnet:0x0000000004fa8058 @network="10.10.20.0", @netmask="255.255.255.0", @ipaddr=#<IPAddr: IPv4:10.10.20.0/255.255.255.0>, @options={}, @m=#<Monitor:0x0000000004fa38a0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Thread::Mutex:0x0000000004fa3850>>>, @ip="10.10.20.20", @mac="24:6e:96:1d:62:10", @options={:deleteable=>true, :hostname=>"waffles-f-1.test.com", 81=>0}>
I, [2018-11-20T07:45:08.693428 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:08 -0600] "GET /dhcp/10.10.20.0/ip/10.10.20.20 HTTP/1.1" 200 207 0.0000

D, [2018-11-20T07:45:08.740306 ] DEBUG -- : close: 10.100.0.107:35106
D, [2018-11-20T07:45:08.755933 ] DEBUG -- : accept: 10.100.0.107:35108
D, [2018-11-20T07:45:08.802811 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
D, [2018-11-20T07:45:08.802811 0c121a6d] DEBUG -- : #<Proxy::DHCP::Reservation:0x0000000004e5b970 @type="reservation", @name="waffles-f-1.test.com-01", @subnet=#<Proxy::DHCP::Subnet:0x0000000004eac230 @network="10.10.20.0", @netmask="255.255.255.0", @ipaddr=#<IPAddr: IPv4:10.10.20.0/255.255.255.0>, @options={}, @m=#<Monitor:0x0000000004e5ba10 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Thread::Mutex:0x0000000004e5b9c0>>>, @ip="10.10.20.20", @mac="24:6e:96:1d:62:10", @options={:deleteable=>true, :hostname=>"waffles-f-1.test.com", 81=>0}>
I, [2018-11-20T07:45:08.802811 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:08 -0600] "GET /dhcp/10.10.20.0/mac/24:6e:96:1d:62:10 HTTP/1.1" 200 205 0.0000

D, [2018-11-20T07:45:08.849690 ] DEBUG -- : close: 10.100.0.107:35108
D, [2018-11-20T07:45:08.865316 ] DEBUG -- : accept: 10.100.0.107:35110
D, [2018-11-20T07:45:08.912195 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
E, [2018-11-20T07:45:08.912195 0c121a6d] ERROR -- : No DHCP record for MAC 10.10.20.0/24:6e:96:1d:62:12 found
D, [2018-11-20T07:45:08.912195 0c121a6d] DEBUG -- : No DHCP record for MAC 10.10.20.0/24:6e:96:1d:62:12 found
I, [2018-11-20T07:45:08.912195 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:08 -0600] "GET /dhcp/10.10.20.0/mac/24:6e:96:1d:62:12 HTTP/1.1" 404 57 0.0000

D, [2018-11-20T07:45:08.959074 ] DEBUG -- : close: 10.100.0.107:35110
D, [2018-11-20T07:45:09.115336 ] DEBUG -- : accept: 10.100.0.107:35114
D, [2018-11-20T07:45:09.177841 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
D, [2018-11-20T07:45:09.177841 0c121a6d] DEBUG -- : #<Proxy::DHCP::Reservation:0x0000000002c6b338 @type="reservation", @name="waffles-f-1-mgmt.test.com", @subnet=#<Proxy::DHCP::Subnet:0x0000000002c71a30 @network="10.10.21.0", @netmask="255.255.255.0", @ipaddr=#<IPAddr: IPv4:10.10.21.0/255.255.255.0>, @options={}, @m=#<Monitor:0x0000000002c6b590 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Thread::Mutex:0x0000000002c6b4a0>>>, @ip="10.10.21.20", @mac="24:6e:96:1d:62:15", @options={:deleteable=>true, :hostname=>"waffles-f-1-mgmt.test.com", :nextServer=>"10.10.0.101", :filename=>"pxelinux.0", 81=>0}>
I, [2018-11-20T07:45:09.177841 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:09 -0600] "GET /dhcp/10.10.21.0/mac/24:6e:96:1d:62:15 HTTP/1.1" 200 263 0.0000

D, [2018-11-20T07:45:09.224720 ] DEBUG -- : close: 10.100.0.107:35114
D, [2018-11-20T07:45:09.240346 ] DEBUG -- : accept: 10.100.0.107:35116
D, [2018-11-20T07:45:09.287225 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
D, [2018-11-20T07:45:09.287225 0c121a6d] DEBUG -- : #<Proxy::DHCP::Reservation:0x0000000001b74ac0 @type="reservation", @name="waffles-f-1-mgmt.test.com", @subnet=#<Proxy::DHCP::Subnet:0x0000000001b764b0 @network="10.10.21.0", @netmask="255.255.255.0", @ipaddr=#<IPAddr: IPv4:10.10.21.0/255.255.255.0>, @options={}, @m=#<Monitor:0x0000000001b74bd8 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Thread::Mutex:0x0000000001b74b10>>>, @ip="10.10.21.20", @mac="24:6e:96:1d:62:15", @options={:deleteable=>true, :hostname=>"waffles-f-1-mgmt.test.com", :nextServer=>"10.10.0.101", :filename=>"pxelinux.0", 81=>0}>
I, [2018-11-20T07:45:09.287225 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:09 -0600] "GET /dhcp/10.10.21.0/ip/10.10.21.20 HTTP/1.1" 200 265 0.0000

D, [2018-11-20T07:45:09.334104 ] DEBUG -- : close: 10.100.0.107:35116
D, [2018-11-20T07:45:09.349730 ] DEBUG -- : accept: 10.100.0.107:35118
D, [2018-11-20T07:45:09.396609 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
D, [2018-11-20T07:45:09.396609 0c121a6d] DEBUG -- : #<Proxy::DHCP::Reservation:0x0000000005303ce8 @type="reservation", @name="waffles-f-1-mgmt.test.com", @subnet=#<Proxy::DHCP::Subnet:0x00000000053089a0 @network="10.10.21.0", @netmask="255.255.255.0", @ipaddr=#<IPAddr: IPv4:10.10.21.0/255.255.255.0>, @options={}, @m=#<Monitor:0x0000000005309c60 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Thread::Mutex:0x0000000005303d60>>>, @ip="10.10.21.20", @mac="24:6e:96:1d:62:15", @options={:deleteable=>true, :hostname=>"waffles-f-1-mgmt.test.com", :nextServer=>"10.10.0.101", :filename=>"pxelinux.0", 81=>0}>
I, [2018-11-20T07:45:09.396609 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:09 -0600] "GET /dhcp/10.10.21.0/mac/24:6e:96:1d:62:15 HTTP/1.1" 200 263 0.0000

D, [2018-11-20T07:45:09.443488 ] DEBUG -- : close: 10.100.0.107:35118
D, [2018-11-20T07:45:09.505993 ] DEBUG -- : accept: 10.100.0.107:35120
D, [2018-11-20T07:45:09.552871 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
D, [2018-11-20T07:45:09.552871 0c121a6d] DEBUG -- : #<Proxy::DHCP::Reservation:0x00000000051386e8 @type="reservation", @name="waffles-f-1.test.com-01", @subnet=#<Proxy::DHCP::Subnet:0x0000000005139548 @network="10.10.20.0", @netmask="255.255.255.0", @ipaddr=#<IPAddr: IPv4:10.10.20.0/255.255.255.0>, @options={}, @m=#<Monitor:0x0000000005138800 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Thread::Mutex:0x0000000005138738>>>, @ip="10.10.20.20", @mac="24:6e:96:1d:62:10", @options={:deleteable=>true, :hostname=>"waffles-f-1.test.com", 81=>0}>
D, [2018-11-20T07:45:09.552871 0c121a6d] DEBUG -- : Deleting 'waffles-f-1.test.com-01 (10.10.20.20 / 24:6e:96:1d:62:10)'
I, [2018-11-20T07:45:09.552871 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:09 -0600] "DELETE /dhcp/10.10.20.0/mac/24:6e:96:1d:62:10 HTTP/1.1" 200 - 0.0000

D, [2018-11-20T07:45:09.568498 ] DEBUG -- : close: 10.100.0.107:35120
D, [2018-11-20T07:45:09.568498 ] DEBUG -- : accept: 10.100.0.107:35122
D, [2018-11-20T07:45:09.615376 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
I, [2018-11-20T07:45:09.615376 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:09 -0600] "DELETE /dhcp/10.10.20.0/mac/24:6e:96:1d:62:12 HTTP/1.1" 200 - 0.0000

D, [2018-11-20T07:45:09.631003 ] DEBUG -- : close: 10.100.0.107:35122
D, [2018-11-20T07:45:09.631003 ] DEBUG -- : accept: 10.100.0.107:35124
D, [2018-11-20T07:45:09.677881 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
I, [2018-11-20T07:45:09.677881 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:09 -0600] "POST /dhcp/10.10.20.0 HTTP/1.1" 200 - 0.0000

D, [2018-11-20T07:45:09.693508 ] DEBUG -- : close: 10.100.0.107:35124
D, [2018-11-20T07:45:09.693508 ] DEBUG -- : accept: 10.100.0.107:35126
D, [2018-11-20T07:45:09.740386 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
E, [2018-11-20T07:45:09.740386 0c121a6d] ERROR -- : Record 10.10.20.20/255.255.255.0 conflicts with an existing record.
D, [2018-11-20T07:45:09.740386 0c121a6d] DEBUG -- : Record 10.10.20.20/255.255.255.0 conflicts with an existing record. (Proxy::DHCP::Collision)
c:/Smart-Proxy/modules/dhcp_native_ms/dhcp_native_ms_main.rb:50:in `rescue in create_reservation'
c:/Smart-Proxy/modules/dhcp_native_ms/dhcp_native_ms_main.rb:38:in `create_reservation'
c:/Smart-Proxy/modules/dhcp_native_ms/dhcp_native_ms_main.rb:33:in `add_record'
c:/Smart-Proxy/modules/dhcp/dhcp_api.rb:98:in `block in <class:DhcpApi>'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1634:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1634:in `block in compile!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:992:in `block (3 levels) in route!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1011:in `route_eval'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:992:in `block (2 levels) in route!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1039:in `block in process_route'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1037:in `catch'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1037:in `process_route'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:990:in `block in route!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:989:in `each'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:989:in `route!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1096:in `block in dispatch!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `block in invoke'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `catch'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `invoke'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1093:in `dispatch!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:924:in `block in call!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `block in invoke'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `catch'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `invoke'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:924:in `call!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:913:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/method_override.rb:22:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/common_logger.rb:33:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:231:in `call'
c:/Smart-Proxy/lib/proxy/log.rb:109:in `call'
c:/Smart-Proxy/lib/proxy/request_id_middleware.rb:9:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/xss_header.rb:18:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/path_traversal.rb:16:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/json_csrf.rb:26:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/base.rb:50:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/base.rb:50:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/frame_options.rb:31:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/null_logger.rb:9:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/head.rb:12:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/show_exceptions.rb:22:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:194:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1957:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1501:in `block in call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1728:in `synchronize'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1501:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/urlmap.rb:68:in `block in call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/urlmap.rb:53:in `each'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/urlmap.rb:53:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/builder.rb:153:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/handler/webrick.rb:86:in `service'
C:/Ruby24-x64/lib/ruby/2.4.0/webrick/httpserver.rb:140:in `service'
C:/Ruby24-x64/lib/ruby/2.4.0/webrick/httpserver.rb:96:in `run'
C:/Ruby24-x64/lib/ruby/2.4.0/webrick/server.rb:308:in `block in start_thread'
I, [2018-11-20T07:45:09.740386 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:09 -0600] "POST /dhcp/10.10.20.0 HTTP/1.1" 409 67 0.0000

D, [2018-11-20T07:45:09.787265 ] DEBUG -- : close: 10.100.0.107:35126
D, [2018-11-20T07:45:09.802891 ] DEBUG -- : accept: 10.100.0.107:35128
D, [2018-11-20T07:45:09.849770 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
I, [2018-11-20T07:45:09.849770 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:09 -0600] "POST /dhcp/10.10.20.0 HTTP/1.1" 200 - 0.0000

D, [2018-11-20T07:45:09.865396 ] DEBUG -- : close: 10.100.0.107:35128
D, [2018-11-20T07:45:09.865396 ] DEBUG -- : accept: 10.100.0.107:35130
D, [2018-11-20T07:45:09.912275 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
E, [2018-11-20T07:45:09.912275 0c121a6d] ERROR -- : Record 10.10.20.20/255.255.255.0 conflicts with an existing record.
D, [2018-11-20T07:45:09.912275 0c121a6d] DEBUG -- : Record 10.10.20.20/255.255.255.0 conflicts with an existing record. (Proxy::DHCP::Collision)
c:/Smart-Proxy/modules/dhcp_native_ms/dhcp_native_ms_main.rb:50:in `rescue in create_reservation'
c:/Smart-Proxy/modules/dhcp_native_ms/dhcp_native_ms_main.rb:38:in `create_reservation'
c:/Smart-Proxy/modules/dhcp_native_ms/dhcp_native_ms_main.rb:33:in `add_record'
c:/Smart-Proxy/modules/dhcp/dhcp_api.rb:98:in `block in <class:DhcpApi>'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1634:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1634:in `block in compile!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:992:in `block (3 levels) in route!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1011:in `route_eval'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:992:in `block (2 levels) in route!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1039:in `block in process_route'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1037:in `catch'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1037:in `process_route'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:990:in `block in route!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:989:in `each'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:989:in `route!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1096:in `block in dispatch!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `block in invoke'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `catch'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `invoke'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1093:in `dispatch!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:924:in `block in call!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `block in invoke'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `catch'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1075:in `invoke'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:924:in `call!'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:913:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/method_override.rb:22:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/common_logger.rb:33:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:231:in `call'
c:/Smart-Proxy/lib/proxy/log.rb:109:in `call'
c:/Smart-Proxy/lib/proxy/request_id_middleware.rb:9:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/xss_header.rb:18:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/path_traversal.rb:16:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/json_csrf.rb:26:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/base.rb:50:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/base.rb:50:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-protection-2.0.1/lib/rack/protection/frame_options.rb:31:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/null_logger.rb:9:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/head.rb:12:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/show_exceptions.rb:22:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:194:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1957:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1501:in `block in call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1728:in `synchronize'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/sinatra-2.0.1/lib/sinatra/base.rb:1501:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/urlmap.rb:68:in `block in call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/urlmap.rb:53:in `each'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/urlmap.rb:53:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/builder.rb:153:in `call'
C:/Ruby24-x64/lib/ruby/gems/2.4.0/gems/rack-2.0.5/lib/rack/handler/webrick.rb:86:in `service'
C:/Ruby24-x64/lib/ruby/2.4.0/webrick/httpserver.rb:140:in `service'
C:/Ruby24-x64/lib/ruby/2.4.0/webrick/httpserver.rb:96:in `run'
C:/Ruby24-x64/lib/ruby/2.4.0/webrick/server.rb:308:in `block in start_thread'
I, [2018-11-20T07:45:09.912275 0c121a6d] INFO -- : 10.100.0.107 - - [20/Nov/2018:07:45:09 -0600] "POST /dhcp/10.10.20.0 HTTP/1.1" 409 67 0.0000

D, [2018-11-20T07:45:09.959154 ] DEBUG -- : close: 10.100.0.107:35130

Also available in: Atom PDF