Hello David:

Ok, your log confirms what I have discovered.  We do indeed have a bug:

1. If you use replace-client-name = "always":

Upon renewal, we are incorrectly deciding the FQDN has changed and is blank, 
and are 
doing a remove only.  It does not matter whether the client sends the 
generated name in the renewals or not.


2.  If you use replace-client-name = "when-not-present":

We commit this same  basic mistake if the client omits the hostname on
renewals. If, however, they  send the generated hostname on renewals we
correctly assert they are equal and do not alter DNS.

In the config you originally sent, you were using "when-not-present",
however your most recent log file reports the value as being "always".
I also saw in the previous log that your client appeared to be sending
the generated name on renewals but this latest log does not show that.

If you can make your clients send the generated name they receive in 
the ack and change your replace-client-name policy to "when-not-present"
you can get around this.

If you don't mind, could you please open a bug ticket for us: 


http://kea.isc.org/newticket


You'll need to register if you haven't already.  This will ensure you're
emailed on any updates.


Thanks,

Thomas Markwalder

ISC Software Engineering



On 9/27/17 8:48 AM, David, Marcos wrote:
> Hi,
>
> Thank you for looking into this.
>
> Here is a full log of a request and the renew.
> I just took out some of the expired leases processing messages to keep the 
> logs shorter. The config is the same.
>
>
> 2017-09-27 12:18:32.054 DEBUG [kea-dhcp4.dhcp4/21] DHCP4_START_INFO pid: 21, 
> port: 67, verbose: yes
> 2017-09-27 12:18:32.054 INFO  [kea-dhcp4.dhcp4/21] DHCP4_STARTING Kea DHCPv4 
> server version 1.1.0 starting
> 2017-09-27 12:18:32.054 DEBUG [kea-dhcp4.dhcp4/21] DHCP4_OPEN_SOCKET opening 
> sockets on port 67
> 2017-09-27 12:18:32.054 DEBUG [kea-dhcp4.commands/21] COMMAND_REGISTERED 
> Command list-commands registered
> 2017-09-27 12:18:32.054 DEBUG [kea-dhcp4.commands/21] COMMAND_REGISTERED 
> Command shutdown registered
> 2017-09-27 12:18:32.054 DEBUG [kea-dhcp4.commands/21] COMMAND_REGISTERED 
> Command leases-reclaim registered
> 2017-09-27 12:18:32.054 DEBUG [kea-dhcp4.commands/21] COMMAND_REGISTERED 
> Command statistic-get registered
> 2017-09-27 12:18:32.054 DEBUG [kea-dhcp4.commands/21] COMMAND_REGISTERED 
> Command statistic-reset registered
> 2017-09-27 12:18:32.054 DEBUG [kea-dhcp4.commands/21] COMMAND_REGISTERED 
> Command statistic-remove registered
> 2017-09-27 12:18:32.054 DEBUG [kea-dhcp4.commands/21] COMMAND_REGISTERED 
> Command statistic-get-all registered
> 2017-09-27 12:18:32.054 DEBUG [kea-dhcp4.commands/21] COMMAND_REGISTERED 
> Command statistic-reset-all registered
> 2017-09-27 12:18:32.054 DEBUG [kea-dhcp4.commands/21] COMMAND_REGISTERED 
> Command statistic-remove-all registered
> 2017-09-27 12:18:32.054 INFO  [kea-dhcp-ddns.dhcpddns/19] DHCP_DDNS_STARTING 
> DHCP-DDNS starting, pid: 19, version: 1.1.0
> 2017-09-27 12:18:32.054 DEBUG [kea-dhcp-ddns.dhcpddns/19] DCTL_INIT_PROCESS 
> DhcpDdns initializing the application
> 2017-09-27 12:18:32.054 DEBUG [kea-dhcp-ddns.dhcpddns/19] DCTL_STANDALONE 
> DhcpDdns skipping message queue, running standalone
> 2017-09-27 12:18:32.055 DEBUG [kea-dhcp4.dhcp4/21] DHCP4_COMMAND_RECEIVED 
> received command config-reload, arguments: { "dhcp-ddns": { "enable-updates": 
> true, "generated-prefix": "pre", "qualifying-suffix": 
> "stagingdhcp.example.com.", "replace-client-name": "always" }, 
> "expired-leases-processing": { "flush-reclaimed-timer-wait-time": 25, 
> "hold-reclaimed-time": 360, "max-reclaim-leases": 100, "max-reclaim-time": 
> 250, "reclaim-timer-wait-time": 10, "unwarned-reclaim-cycles": 5 }, 
> "hosts-database": { "host": "0.0.0.0", "name": "keadb", "password": 
> "password", "type": "mysql", "user": "kea" }, "interfaces-config": { 
> "interfaces": [ "eth0" ] }, "lease-database": { "host": "0.0.0.0", "name": 
> "keadb", "password": "password", "type": "mysql", "user": "kea" }, 
> "option-data": [ { "code": 15, "csv-format": true, "data": 
> "stagingdhcp.example.com", "name": "domain-name", "space": "dhcp4" }, { 
> "code": 6, "csv-format": true, "data": "10.93.211.10,10.93.211.11", "name": 
> "domain-name-servers", "spac
 e": "dhcp4" }, { "code": 42, "csv-format": true, "data": 
"10.254.254.254,10.254.191.254,10.254.60.250,10.254.191.250", "name": 
"ntp-servers", "space": "dhcp4" }, { "code": 3, "csv-format": true, "data": 
"10.93.211.254", "name": "routers", "space": "dhcp4" } ], "subnet4": [ { "id": 
351, "pools": [ { "pool": "10.93.208.1-10.93.208.253" } ], "subnet": 
"10.93.208.0/22" } ], "valid-lifetime": 300 }
> 2017-09-27 12:18:32.055 DEBUG [kea-dhcp4.dhcp4/21] DHCP4_CONFIG_RECEIVED 
> received configuration { "dhcp-ddns": { "enable-updates": true, 
> "generated-prefix": "pre", "qualifying-suffix": "stagingdhcp.example.com.", 
> "replace-client-name": "always" }, "expired-leases-processing": { 
> "flush-reclaimed-timer-wait-time": 25, "hold-reclaimed-time": 360, 
> "max-reclaim-leases": 100, "max-reclaim-time": 250, 
> "reclaim-timer-wait-time": 10, "unwarned-reclaim-cycles": 5 }, 
> "hosts-database": { "host": "0.0.0.0", "name": "keadb", "password": 
> "password", "type": "mysql", "user": "kea" }, "interfaces-config": { 
> "interfaces": [ "eth0" ] }, "lease-database": { "host": "0.0.0.0", "name": 
> "keadb", "password": "password", "type": "mysql", "user": "kea" }, 
> "option-data": [ { "code": 15, "csv-format": true, "data": 
> "stagingdhcp.example.com", "name": "domain-name", "space": "dhcp4" }, { 
> "code": 6, "csv-format": true, "data": "10.93.211.10,10.93.211.11", "name": 
> "domain-name-servers", "space": "dhcp4" }, { "cod
 e": 42, "csv-format": true, "data": 
"10.254.254.254,10.254.191.254,10.254.60.250,10.254.191.250", "name": 
"ntp-servers", "space": "dhcp4" }, { "code": 3, "csv-format": true, "data": 
"10.93.211.254", "name": "routers", "space": "dhcp4" } ], "subnet4": [ { "id": 
351, "pools": [ { "pool": "10.93.208.1-10.93.208.253" } ], "subnet": 
"10.93.208.0/22" } ], "valid-lifetime": 300 }
> 2017-09-27 12:18:32.055 DEBUG [kea-dhcp-ddns.dhcpddns/19] DHCP_DDNS_CONFIGURE 
> configuration update received: { "dns-server-timeout": 500, "forward-ddns": { 
> "ddns-domains": [ { "dns-servers": [ { "ip-address": "10.93.211.12" } ], 
> "key-name": "tsig-dhcpupdate", "name": "stagingdhcp.example.com." } ] }, 
> "ip-address": "127.0.0.1", "port": 53001, "reverse-ddns": { "ddns-domains": [ 
> { "dns-servers": [ { "ip-address": "10.93.211.12" } ], "key-name": 
> "tsig-dhcpupdate", "name": "93.10.in-addr.arpa." } ] }, "tsig-keys": [ { 
> "algorithm": "HMAC-SHA256", "name": "tsig-dhcpupdate", "secret": "secret" } ] 
> }
> 2017-09-27 12:18:32.055 DEBUG [kea-dhcp-ddns.dhcpddns/19] DCTL_CONFIG_START 
> parsing new configuration: { "dns-server-timeout": 500, "forward-ddns": { 
> "ddns-domains": [ { "dns-servers": [ { "ip-address": "10.93.211.12" } ], 
> "key-name": "tsig-dhcpupdate", "name": "stagingdhcp.example.com." } ] }, 
> "ip-address": "127.0.0.1", "port": 53001, "reverse-ddns": { "ddns-domains": [ 
> { "dns-servers": [ { "ip-address": "10.93.211.12" } ], "key-name": 
> "tsig-dhcpupdate", "name": "93.10.in-addr.arpa." } ] }, "tsig-keys": [ { 
> "algorithm": "HMAC-SHA256", "name": "tsig-dhcpupdate", "secret": "secret" } ] 
> }
> 2017-09-27 12:18:32.055 INFO  [kea-dhcp-ddns.dhcpddns/19] 
> DCTL_CONFIG_COMPLETE server has completed configuration: listening on 
> 127.0.0.1, port 53001, using UDP
> 2017-09-27 12:18:32.055 DEBUG [kea-dhcp-ddns.dhcpddns/19] DCTL_RUN_PROCESS 
> DhcpDdns starting application event loop
> 2017-09-27 12:18:32.055 INFO  [kea-dhcp-ddns.dhcpddns/19] DHCP_DDNS_STARTED 
> Kea DHCP-DDNS server version 1.1.0 started
> 2017-09-27 12:18:32.055 DEBUG [kea-dhcp-ddns.dhcpddns/19] 
> DHCP_DDNS_QUEUE_MGR_RECONFIGURING application is reconfiguring the queue 
> manager
> 2017-09-27 12:18:32.055 DEBUG [kea-dhcp-ddns.dhcpddns/19] 
> DHCP_DDNS_QUEUE_MGR_STARTED application's queue manager has begun listening 
> for requests.
> 2017-09-27 12:18:32.056 DEBUG [kea-dhcp4.dhcp4/21] DHCP4_CONFIG_START DHCPv4 
> server is processing the following configuration: { "dhcp-ddns": { 
> "enable-updates": true, "generated-prefix": "pre", "qualifying-suffix": 
> "stagingdhcp.example.com.", "replace-client-name": "always" }, 
> "expired-leases-processing": { "flush-reclaimed-timer-wait-time": 25, 
> "hold-reclaimed-time": 360, "max-reclaim-leases": 100, "max-reclaim-time": 
> 250, "reclaim-timer-wait-time": 10, "unwarned-reclaim-cycles": 5 }, 
> "hosts-database": { "host": "0.0.0.0", "name": "keadb", "password": 
> "password", "type": "mysql", "user": "kea" }, "interfaces-config": { 
> "interfaces": [ "eth0" ] }, "lease-database": { "host": "0.0.0.0", "name": 
> "keadb", "password": "password", "type": "mysql", "user": "kea" }, 
> "option-data": [ { "code": 15, "csv-format": true, "data": 
> "stagingdhcp.example.com", "name": "domain-name", "space": "dhcp4" }, { 
> "code": 6, "csv-format": true, "data": "10.93.211.10,10.93.211.11", "name": 
> "domain-name-serve
 rs", "space": "dhcp4" }, { "code": 42, "csv-format": true, "data": 
"10.254.254.254,10.254.191.254,10.254.60.250,10.254.191.250", "name": 
"ntp-servers", "space": "dhcp4" }, { "code": 3, "csv-format": true, "data": 
"10.93.211.254", "name": "routers", "space": "dhcp4" } ], "subnet4": [ { "id": 
351, "pools": [ { "pool": "10.93.208.1-10.93.208.253" } ], "subnet": 
"10.93.208.0/22" } ], "valid-lifetime": 300 }
> 2017-09-27 12:18:32.056 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_TIMERMGR_UNREGISTER_ALL_TIMERS unregistering all timers
> 2017-09-27 12:18:32.056 DEBUG [kea-dhcp4.dhcp4/21] DHCP4_PARSER_CREATED 
> created parser for configuration element dhcp-ddns
> 2017-09-27 12:18:32.056 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_CFGMGR_CFG_DHCP_DDNS Setting DHCP-DDNS configuration to: DHCP_DDNS 
> updates enabled
> 2017-09-27 12:18:32.056 DEBUG [kea-dhcp4.dhcp4/21] DHCP4_PARSER_CREATED 
> created parser for configuration element expired-leases-processing
> 2017-09-27 12:18:32.056 DEBUG [kea-dhcp4.dhcp4/21] DHCP4_PARSER_CREATED 
> created parser for configuration element hosts-database
> 2017-09-27 12:18:32.056 DEBUG [kea-dhcp4.dhcp4/21] DHCP4_PARSER_CREATED 
> created parser for configuration element interfaces-config
> 2017-09-27 12:18:32.056 INFO  [kea-dhcp4.dhcpsrv/21] DHCPSRV_CFGMGR_ADD_IFACE 
> listening on interface eth0
> 2017-09-27 12:18:32.056 INFO  [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_CFGMGR_SOCKET_TYPE_DEFAULT "dhcp-socket-type" not specified , using 
> default socket type raw
> 2017-09-27 12:18:32.056 DEBUG [kea-dhcp4.dhcp4/21] DHCP4_PARSER_CREATED 
> created parser for configuration element lease-database
> 2017-09-27 12:18:32.056 DEBUG [kea-dhcp4.dhcp4/21] DHCP4_PARSER_CREATED 
> created parser for configuration element option-data
> 2017-09-27 12:18:32.056 DEBUG [kea-dhcp4.dhcp4/21] DHCP4_PARSER_CREATED 
> created parser for configuration element subnet4
> 2017-09-27 12:18:32.056 DEBUG [kea-dhcp4.dhcp4/21] DHCP4_PARSER_CREATED 
> created parser for configuration element valid-lifetime
> 2017-09-27 12:18:32.056 INFO  [kea-dhcp4.dhcp4/21] DHCP4_CONFIG_NEW_SUBNET a 
> new subnet has been added to configuration: 10.93.208.0/22 with params: 
> valid-lifetime=300
> 2017-09-27 12:18:32.056 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_CFGMGR_ADD_SUBNET4 adding subnet 10.93.208.0/22
> 2017-09-27 12:18:32.056 INFO  [kea-dhcp4.dhcp4/21] DHCP4_CONFIG_COMPLETE 
> DHCPv4 server has completed configuration: added IPv4 subnets: 1; DDNS: 
> enabled
> 2017-09-27 12:18:32.057 INFO  [kea-dhcp4.dhcpsrv/21] DHCPSRV_MYSQL_DB opening 
> MySQL lease database: host=0.0.0.0 name=keadb password=***** type=mysql 
> universe=4 user=kea
> 2017-09-27 12:18:32.074 INFO  [kea-dhcp4.dhcpsrv/21] DHCPSRV_MYSQL_HOST_DB 
> opening MySQL hosts database: host=0.0.0.0 name=keadb password=***** 
> type=mysql universe=4 user=kea
> 2017-09-27 12:18:32.085 INFO  [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_DHCP_DDNS_SENDER_STARTED NameChangeRequest sender has been started: 
> enable_updates: yes, server_ip: 127.0.0.1, server_port: 53001, sender_ip: 
> 0.0.0.0, sender_port: 0, max_queue_size: 1024, ncr_protocol: UDP, ncr_format: 
> JSON, always_include_fqdn: no, override_no_update: no, 
> override_client_update: no, replace_client_name: always, generated_prefix: 
> [pre], qualifying_suffix: [stagingdhcp.example.com.]
> 2017-09-27 12:18:32.093 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_TIMERMGR_REGISTER_TIMER registering timer: reclaim-expired-leases, 
> using interval: 10000 ms
> 2017-09-27 12:18:32.093 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_TIMERMGR_START_TIMER starting timer: reclaim-expired-leases
> 2017-09-27 12:18:32.093 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_TIMERMGR_REGISTER_TIMER registering timer: flush-reclaimed-leases, 
> using interval: 25000 ms
> 2017-09-27 12:18:32.093 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_TIMERMGR_START_TIMER starting timer: flush-reclaimed-leases
> 2017-09-27 12:18:32.093 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_TIMERMGR_START_THREAD starting thread for timers
> 2017-09-27 12:18:32.094 INFO  [kea-dhcp4.dhcp4/21] DHCP4_STARTED Kea DHCPv4 
> server version 1.1.0 started
> 2017-09-27 12:18:32.094 DEBUG [kea-dhcp4.packets/21] DHCP4_BUFFER_WAIT 
> waiting for next DHCPv4 packet with timeout 1000 ms
> 2017-09-27 12:18:42.093 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_TIMERMGR_RUN_TIMER_OPERATION running operation for timer: 
> reclaim-expired-leases
> 2017-09-27 12:18:42.093 DEBUG [kea-dhcp4.alloc-engine/21] 
> ALLOC_ENGINE_V4_LEASES_RECLAMATION_START starting reclamation of expired 
> leases (limit = 100 leases or 250 milliseconds)
> 2017-09-27 12:18:42.093 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_MYSQL_GET_EXPIRED4 obtaining maximum 101 of expired IPv4 leases
> 2017-09-27 12:18:42.095 DEBUG [kea-dhcp4.alloc-engine/21] 
> ALLOC_ENGINE_V4_LEASES_RECLAMATION_COMPLETE reclaimed 0 leases in 1.235 ms
> 2017-09-27 12:18:42.095 DEBUG [kea-dhcp4.alloc-engine/21] 
> ALLOC_ENGINE_V4_NO_MORE_EXPIRED_LEASES all expired leases have been reclaimed
> 2017-09-27 12:18:42.095 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_TIMERMGR_START_TIMER starting timer: reclaim-expired-leases
> ...
> 2017-09-27 12:19:02.098 DEBUG [kea-dhcp4.packets/21] 
> DHCP4_BUFFER_WAIT_INTERRUPTED interrupted wait for the next packet due to 
> timeout, signal or external socket callback (timeout value is 1000)
> 2017-09-27 12:19:02.098 DEBUG [kea-dhcp4.packets/21] DHCP4_BUFFER_WAIT 
> waiting for next DHCPv4 packet with timeout 1000 ms
> 2017-09-27 12:19:12.098 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_TIMERMGR_RUN_TIMER_OPERATION running operation for timer: 
> reclaim-expired-leases
> 2017-09-27 12:19:12.098 DEBUG [kea-dhcp4.alloc-engine/21] 
> ALLOC_ENGINE_V4_LEASES_RECLAMATION_START starting reclamation of expired 
> leases (limit = 100 leases or 250 milliseconds)
> 2017-09-27 12:19:12.098 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_MYSQL_GET_EXPIRED4 obtaining maximum 101 of expired IPv4 leases
> 2017-09-27 12:19:12.105 DEBUG [kea-dhcp4.alloc-engine/21] 
> ALLOC_ENGINE_V4_LEASES_RECLAMATION_COMPLETE reclaimed 0 leases in 7.229 ms
> 2017-09-27 12:19:12.105 DEBUG [kea-dhcp4.alloc-engine/21] 
> ALLOC_ENGINE_V4_NO_MORE_EXPIRED_LEASES all expired leases have been reclaimed
> 2017-09-27 12:19:12.105 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_TIMERMGR_START_TIMER starting timer: reclaim-expired-leases
> 2017-09-27 12:19:12.105 DEBUG [kea-dhcp4.packets/21] 
> DHCP4_BUFFER_WAIT_INTERRUPTED interrupted wait for the next packet due to 
> timeout, signal or external socket callback (timeout value is 1000)
> 2017-09-27 12:19:12.105 DEBUG [kea-dhcp4.packets/21] DHCP4_BUFFER_WAIT 
> waiting for next DHCPv4 packet with timeout 1000 ms
> 2017-09-27 12:19:21.825 DEBUG [kea-dhcp4.packets/21] DHCP4_BUFFER_RECEIVED 
> received buffer from 0.0.0.0:68 to 255.255.255.255:67 over interface eth0
> 2017-09-27 12:19:21.825 DEBUG [kea-dhcp4.options/21] DHCP4_BUFFER_UNPACK 
> parsing buffer received from 0.0.0.0 to 255.255.255.255 over interface eth0
> 2017-09-27 12:19:21.825 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_CFGMGR_SUBNET4_ADDR selected subnet 10.93.208.0/22 for packet 
> received by matching address 10.93.211.251
> 2017-09-27 12:19:21.825 DEBUG [kea-dhcp4.packets/21] DHCP4_SUBNET_SELECTED 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: the subnet with 
> ID 351 was selected for client assignments
> 2017-09-27 12:19:21.825 DEBUG [kea-dhcp4.packets/21] DHCP4_SUBNET_DATA 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: the selected 
> subnet details: 10.93.208.0/22
> 2017-09-27 12:19:21.825 DEBUG [kea-dhcp4.packets/21] DHCP4_PACKET_RECEIVED 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: DHCPDISCOVER 
> (type 1) received from 0.0.0.0 to 255.255.255.255 on interface eth0
> 2017-09-27 12:19:21.825 DEBUG [kea-dhcp4.packets/21] DHCP4_QUERY_DATA 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536, packet details: 
> local_address=255.255.255.255:67, remote_adress=0.0.0.0:68, 
> msg_type=DHCPDISCOVER (1), transid=0x9bf06536,
> options:
>   type=053, len=001: 1 (uint8)
>   type=055, len=018: 1(uint8) 28(uint8) 2(uint8) 121(uint8) 15(uint8) 
> 6(uint8) 12(uint8) 40(uint8) 41(uint8) 42(uint8) 26(uint8) 119(uint8) 
> 3(uint8) 121(uint8) 249(uint8) 33(uint8) 252(uint8) 42(uint8)
> 2017-09-27 12:19:21.825 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_CFGMGR_SUBNET4_ADDR selected subnet 10.93.208.0/22 for packet 
> received by matching address 10.93.211.251
> 2017-09-27 12:19:21.825 DEBUG [kea-dhcp4.packets/21] DHCP4_SUBNET_SELECTED 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: the subnet with 
> ID 351 was selected for client assignments
> 2017-09-27 12:19:21.825 DEBUG [kea-dhcp4.packets/21] DHCP4_SUBNET_DATA 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: the selected 
> subnet details: 10.93.208.0/22
> 2017-09-27 12:19:21.825 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv4 reservation for 
> subnet id 351, identified by hwaddr=005056A827E2
> 2017-09-27 12:19:21.825 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using 
> identifier: hwaddr=005056A827E2
> 2017-09-27 12:19:21.825 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier hwaddr=005056A827E2, 
> found 0 host(s)
> 2017-09-27 12:19:21.825 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet id 
> 351 and identifier hwaddr=005056A827E2
> 2017-09-27 12:19:21.831 DEBUG [kea-dhcp4.ddns/21] 
> DHCP4_CLIENT_HOSTNAME_PROCESS [hwtype=1 00:50:56:a8:27:e2], cid=[no info], 
> tid=0x9bf06536: processing client's Hostname option
> 2017-09-27 12:19:21.831 DEBUG [kea-dhcp4.ddns/21] DHCP4_GENERATE_FQDN 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: client did not 
> send a FQDN or hostname; FQDN will be be generated for the client
> 2017-09-27 12:19:21.831 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_MYSQL_GET_SUBID_HWADDR obtaining IPv4 lease for subnet ID 351 and 
> hardware address hwtype=1 00:50:56:a8:27:e2
> 2017-09-27 12:19:21.833 DEBUG [kea-dhcp4.alloc-engine/21] 
> ALLOC_ENGINE_V4_OFFER_NEW_LEASE allocation engine will try to offer new lease 
> to the client [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536
> 2017-09-27 12:19:21.833 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4 get one host with reservation for subnet 
> id 351 and IPv4 address 10.93.208.1
> 2017-09-27 12:19:21.833 DEBUG [kea-dhcp4.hosts/21] HOSTS_CFG_GET_ALL_ADDRESS4 
> get all hosts with reservations for IPv4 address 10.93.208.1
> 2017-09-27 12:19:21.833 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ALL_ADDRESS4_COUNT using address 10.93.208.1, found 0 host(s)
> 2017-09-27 12:19:21.833 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4_NULL host not found using subnet id 351 
> and address 10.93.208.1
> 2017-09-27 12:19:21.833 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_ADDRESS4 trying alternate source for host 
> using subnet id 351 and address 10.93.208.1
> 2017-09-27 12:19:21.835 DEBUG [kea-dhcp4.dhcpsrv/21] DHCPSRV_MYSQL_GET_ADDR4 
> obtaining IPv4 lease for address 10.93.208.1
> 2017-09-27 12:19:21.836 DEBUG [kea-dhcp4.dhcpsrv/21] DHCPSRV_MYSQL_GET_ADDR4 
> obtaining IPv4 lease for address 10.93.208.1
> 2017-09-27 12:19:21.837 INFO  [kea-dhcp4.leases/21] DHCP4_LEASE_ADVERT 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: lease 
> 10.93.208.1 will be advertised
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.ddns/21] 
> DHCP4_RESPONSE_HOSTNAME_GENERATE [hwtype=1 00:50:56:a8:27:e2], cid=[no info], 
> tid=0x9bf06536: server has generated hostname 
> pre-10-93-208-1.stagingdhcp.example.com for the client
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.options/21] DHCP4_PACKET_PACK 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: preparing 
> on-wire format of the packet to be sent
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.packets/21] DHCP4_PACKET_SEND 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: trying to send 
> packet DHCPOFFER (type 2) from 10.93.211.251:67 to 10.93.208.1:68 on 
> interface eth0
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.packets/21] DHCP4_RESPONSE_DATA 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: responding with 
> packet DHCPOFFER (type 2), packet details: local_address=10.93.211.251:67, 
> remote_adress=10.93.208.1:68, msg_type=DHCPOFFER (2), transid=0x9bf06536,
> options:
>   type=001, len=004: 4294966272 (uint32)
>   type=003, len=004: 10.93.211.254
>   type=006, len=008: 10.93.211.10 10.93.211.11
>   type=012, len=037: "pre-10-93-208-1.stagingdhcp.example.com" (string)
>   type=015, len=021: "stagingdhcp.example.com" (string)
>   type=042, len=016: 10.254.254.254 10.254.191.254 10.254.60.250 
> 10.254.191.250
>   type=051, len=004: 300 (uint32)
>   type=053, len=001: 2 (uint8)
>   type=054, len=004: 10.93.211.251
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.packets/21] DHCP4_BUFFER_WAIT 
> waiting for next DHCPv4 packet with timeout 1000 ms
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.packets/21] DHCP4_BUFFER_RECEIVED 
> received buffer from 0.0.0.0:68 to 255.255.255.255:67 over interface eth0
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.options/21] DHCP4_BUFFER_UNPACK 
> parsing buffer received from 0.0.0.0 to 255.255.255.255 over interface eth0
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_CFGMGR_SUBNET4_ADDR selected subnet 10.93.208.0/22 for packet 
> received by matching address 10.93.211.251
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.packets/21] DHCP4_SUBNET_SELECTED 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: the subnet with 
> ID 351 was selected for client assignments
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.packets/21] DHCP4_SUBNET_DATA 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: the selected 
> subnet details: 10.93.208.0/22
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.packets/21] DHCP4_PACKET_RECEIVED 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: DHCPREQUEST 
> (type 3) received from 0.0.0.0 to 255.255.255.255 on interface eth0
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.packets/21] DHCP4_QUERY_DATA 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536, packet details: 
> local_address=255.255.255.255:67, remote_adress=0.0.0.0:68, 
> msg_type=DHCPREQUEST (3), transid=0x9bf06536,
> options:
>   type=050, len=004: 10.93.208.1 (ipv4-address)
>   type=053, len=001: 3 (uint8)
>   type=054, len=004: 10.93.211.251 (ipv4-address)
>   type=055, len=018: 1(uint8) 28(uint8) 2(uint8) 121(uint8) 15(uint8) 
> 6(uint8) 12(uint8) 40(uint8) 41(uint8) 42(uint8) 26(uint8) 119(uint8) 
> 3(uint8) 121(uint8) 249(uint8) 33(uint8) 252(uint8) 42(uint8)
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_CFGMGR_SUBNET4_ADDR selected subnet 10.93.208.0/22 for packet 
> received by matching address 10.93.211.251
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.packets/21] DHCP4_SUBNET_SELECTED 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: the subnet with 
> ID 351 was selected for client assignments
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.packets/21] DHCP4_SUBNET_DATA 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: the selected 
> subnet details: 10.93.208.0/22
> 2017-09-27 12:19:21.837 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv4 reservation for 
> subnet id 351, identified by hwaddr=005056A827E2
> 2017-09-27 12:19:21.838 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using 
> identifier: hwaddr=005056A827E2
> 2017-09-27 12:19:21.838 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier hwaddr=005056A827E2, 
> found 0 host(s)
> 2017-09-27 12:19:21.838 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet id 
> 351 and identifier hwaddr=005056A827E2
> 2017-09-27 12:19:21.848 DEBUG [kea-dhcp4.ddns/21] 
> DHCP4_CLIENT_HOSTNAME_PROCESS [hwtype=1 00:50:56:a8:27:e2], cid=[no info], 
> tid=0x9bf06536: processing client's Hostname option
> 2017-09-27 12:19:21.848 DEBUG [kea-dhcp4.ddns/21] DHCP4_GENERATE_FQDN 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: client did not 
> send a FQDN or hostname; FQDN will be be generated for the client
> 2017-09-27 12:19:21.848 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_MYSQL_GET_SUBID_HWADDR obtaining IPv4 lease for subnet ID 351 and 
> hardware address hwtype=1 00:50:56:a8:27:e2
> 2017-09-27 12:19:21.849 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4 get one host with reservation for subnet 
> id 351 and IPv4 address 10.93.208.1
> 2017-09-27 12:19:21.849 DEBUG [kea-dhcp4.hosts/21] HOSTS_CFG_GET_ALL_ADDRESS4 
> get all hosts with reservations for IPv4 address 10.93.208.1
> 2017-09-27 12:19:21.849 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ALL_ADDRESS4_COUNT using address 10.93.208.1, found 0 host(s)
> 2017-09-27 12:19:21.849 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4_NULL host not found using subnet id 351 
> and address 10.93.208.1
> 2017-09-27 12:19:21.849 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_ADDRESS4 trying alternate source for host 
> using subnet id 351 and address 10.93.208.1
> 2017-09-27 12:19:21.851 DEBUG [kea-dhcp4.dhcpsrv/21] DHCPSRV_MYSQL_GET_ADDR4 
> obtaining IPv4 lease for address 10.93.208.1
> 2017-09-27 12:19:21.852 DEBUG [kea-dhcp4.alloc-engine/21] 
> ALLOC_ENGINE_V4_REQUEST_ALLOC_REQUESTED [hwtype=1 00:50:56:a8:27:e2], cid=[no 
> info], tid=0x9bf06536: trying to allocate requested address 10.93.208.1
> 2017-09-27 12:19:21.852 DEBUG [kea-dhcp4.dhcpsrv/21] DHCPSRV_MYSQL_GET_ADDR4 
> obtaining IPv4 lease for address 10.93.208.1
> 2017-09-27 12:19:21.853 DEBUG [kea-dhcp4.dhcpsrv/21] DHCPSRV_MYSQL_ADD_ADDR4 
> adding IPv4 lease with address 10.93.208.1
> 2017-09-27 12:19:21.866 INFO  [kea-dhcp4.leases/21] DHCP4_LEASE_ALLOC 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: lease 
> 10.93.208.1 has been allocated
> 2017-09-27 12:19:21.866 DEBUG [kea-dhcp4.ddns/21] 
> DHCP4_RESPONSE_HOSTNAME_GENERATE [hwtype=1 00:50:56:a8:27:e2], cid=[no info], 
> tid=0x9bf06536: server has generated hostname 
> pre-10-93-208-1.stagingdhcp.example.com for the client
> 2017-09-27 12:19:21.866 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_MYSQL_UPDATE_ADDR4 updating IPv4 lease for address 10.93.208.1
> 2017-09-27 12:19:21.878 DEBUG [kea-dhcp4.ddns/21] DHCP4_NCR_CREATE [hwtype=1 
> 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: DDNS updates enabled, 
> therefore sending name change requests
> 2017-09-27 12:19:21.879 DEBUG [kea-dhcp4.dhcpsrv/21] DHCPSRV_QUEUE_NCR 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info]: name change request to add DNS 
> entry queued: Type: 0 (CHG_ADD)
> Forward Change: yes
> Reverse Change: yes
> FQDN: [pre-10-93-208-1.stagingdhcp.example.com.]
> IP Address: [10.93.208.1]
> DHCID: 
> [000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62]
> Lease Expires On: 20170927122421
> Lease Length: 300
> 2017-09-27 12:19:21.879 DEBUG [kea-dhcp4.options/21] DHCP4_PACKET_PACK 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: preparing 
> on-wire format of the packet to be sent
> 2017-09-27 12:19:21.879 DEBUG [kea-dhcp4.packets/21] DHCP4_PACKET_SEND 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: trying to send 
> packet DHCPACK (type 5) from 10.93.211.251:67 to 10.93.208.1:68 on interface 
> eth0
> 2017-09-27 12:19:21.879 DEBUG [kea-dhcp4.packets/21] DHCP4_RESPONSE_DATA 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: responding with 
> packet DHCPACK (type 5), packet details: local_address=10.93.211.251:67, 
> remote_adress=10.93.208.1:68, msg_type=DHCPACK (5), transid=0x9bf06536,
> options:
>   type=001, len=004: 4294966272 (uint32)
>   type=003, len=004: 10.93.211.254
>   type=006, len=008: 10.93.211.10 10.93.211.11
>   type=012, len=037: "pre-10-93-208-1.stagingdhcp.example.com" (string)
>   type=015, len=021: "stagingdhcp.example.com" (string)
>   type=042, len=016: 10.254.254.254 10.254.191.254 10.254.60.250 
> 10.254.191.250
>   type=051, len=004: 300 (uint32)
>   type=053, len=001: 5 (uint8)
>   type=054, len=004: 10.93.211.251
> 2017-09-27 12:19:21.879 DEBUG [kea-dhcp4.packets/21] DHCP4_BUFFER_WAIT 
> waiting for next DHCPv4 packet with timeout 1000 ms
> 2017-09-27 12:19:21.879 DEBUG [kea-dhcp-ddns.dhcp-to-d2/19] 
> DHCP_DDNS_QUEUE_MGR_QUEUE_RECEIVE Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62: 
> received and queued a request.
> 2017-09-27 12:19:21.879 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_DHCP_DDNS_NCR_SENT NameChangeRequest sent to kea-dhcp-ddns: Type: 0 
> (CHG_ADD)
> Forward Change: yes
> Reverse Change: yes
> FQDN: [pre-10-93-208-1.stagingdhcp.example.com.]
> IP Address: [10.93.208.1]
> DHCID: 
> [000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62]
> Lease Expires On: 20170927122421
> Lease Length: 300
> 2017-09-27 12:19:21.879 DEBUG [kea-dhcp4.packets/21] 
> DHCP4_BUFFER_WAIT_INTERRUPTED interrupted wait for the next packet due to 
> timeout, signal or external socket callback (timeout value is 1000)
> 2017-09-27 12:19:21.879 DEBUG [kea-dhcp-ddns.d2-to-dns/19] 
> DHCP_DDNS_STARTING_TRANSACTION Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62:
> 2017-09-27 12:19:21.879 DEBUG [kea-dhcp4.packets/21] DHCP4_BUFFER_WAIT 
> waiting for next DHCPv4 packet with timeout 1000 ms
> 2017-09-27 12:19:21.879 DEBUG [kea-dhcp-ddns.d2-to-dns/19] 
> DHCP_DDNS_UPDATE_REQUEST_SENT Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62: 
> Foward Add to server: 10.93.211.12 port:53
> 2017-09-27 12:19:21.909 DEBUG [kea-dhcp-ddns.asiodns/19] 
> ASIODNS_FETCH_COMPLETED upstream fetch to 10.93.211.12(53) has now completed
> 2017-09-27 12:19:21.909 DEBUG [kea-dhcp-ddns.d2-to-dns/19] 
> DHCP_DDNS_UPDATE_RESPONSE_RECEIVED Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62: to 
> server: 10.93.211.12 port:53 status: SUCCESS, rcode: NOERROR
> 2017-09-27 12:19:21.909 DEBUG [kea-dhcp-ddns.d2-to-dns/19] 
> DHCP_DDNS_UPDATE_REQUEST_SENT Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62: 
> Reverse Replace to server: 10.93.211.12 port:53
> 2017-09-27 12:19:21.941 DEBUG [kea-dhcp-ddns.asiodns/19] 
> ASIODNS_FETCH_COMPLETED upstream fetch to 10.93.211.12(53) has now completed
> 2017-09-27 12:19:21.941 DEBUG [kea-dhcp-ddns.d2-to-dns/19] 
> DHCP_DDNS_UPDATE_RESPONSE_RECEIVED Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62: to 
> server: 10.93.211.12 port:53 status: SUCCESS, rcode: NOERROR
> 2017-09-27 12:19:21.941 INFO  [kea-dhcp-ddns.d2-to-dns/19] 
> DHCP_DDNS_ADD_SUCCEEDED DHCP_DDNS Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62: 
> successfully added the DNS mapping addition for this request: Type: 0 
> (CHG_ADD)
> Forward Change: yes
> Reverse Change: yes
> FQDN: [pre-10-93-208-1.stagingdhcp.example.com.]
> IP Address: [10.93.208.1]
> DHCID: 
> [000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62]
> Lease Expires On: 20170927122421
> Lease Length: 300
> 2017-09-27 12:19:22.095 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_TIMERMGR_RUN_TIMER_OPERATION running operation for timer: 
> flush-reclaimed-leases
> 2017-09-27 12:19:22.095 DEBUG [kea-dhcp4.alloc-engine/21] 
> ALLOC_ENGINE_V4_RECLAIMED_LEASES_DELETE begin deletion of reclaimed leases 
> expired more than 360 seconds ago
> 2017-09-27 12:19:22.095 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_MYSQL_DELETE_EXPIRED_RECLAIMED4 deleting reclaimed IPv4 leases that 
> expired more than 360 seconds ago
> 2017-09-27 12:19:22.096 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_MYSQL_DELETED_EXPIRED_RECLAIMED deleted 0 reclaimed leases from the 
> database
> 2017-09-27 12:19:22.097 DEBUG [kea-dhcp4.alloc-engine/21] 
> ALLOC_ENGINE_V4_RECLAIMED_LEASES_DELETE_COMPLETE successfully deleted 0 
> expired-reclaimed leases
> 2017-09-27 12:19:22.097 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_TIMERMGR_START_TIMER starting timer: flush-reclaimed-leases
> 2017-09-27 12:19:22.097 DEBUG [kea-dhcp4.packets/21] 
> DHCP4_BUFFER_WAIT_INTERRUPTED interrupted wait for the next packet due to 
> timeout, signal or external socket callback (timeout value is 1000)
> 2017-09-27 12:19:22.097 DEBUG [kea-dhcp4.packets/21] DHCP4_BUFFER_WAIT 
> waiting for next DHCPv4 packet with timeout 1000 ms
> 2017-09-27 12:19:22.106 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_TIMERMGR_RUN_TIMER_OPERATION running operation for timer: 
> reclaim-expired-leases
> 2017-09-27 12:19:22.106 DEBUG [kea-dhcp4.alloc-engine/21] 
> ALLOC_ENGINE_V4_LEASES_RECLAMATION_START starting reclamation of expired 
> leases (limit = 100 leases or 250 milliseconds)
> 2017-09-27 12:19:22.106 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_MYSQL_GET_EXPIRED4 obtaining maximum 101 of expired IPv4 leases
> ...
>
> 2017-09-27 12:21:27.104 DEBUG [kea-dhcp4.packets/21] 
> DHCP4_BUFFER_WAIT_INTERRUPTED interrupted wait for the next packet due to 
> timeout, signal or external socket callback (timeout value is 1000)
> 2017-09-27 12:21:27.104 DEBUG [kea-dhcp4.packets/21] DHCP4_BUFFER_WAIT 
> waiting for next DHCPv4 packet with timeout 1000 ms
> 2017-09-27 12:21:31.845 DEBUG [kea-dhcp4.packets/21] DHCP4_BUFFER_RECEIVED 
> received buffer from 10.93.208.1:68 to 10.93.211.251:67 over interface eth0
> 2017-09-27 12:21:31.845 DEBUG [kea-dhcp4.options/21] DHCP4_BUFFER_UNPACK 
> parsing buffer received from 10.93.208.1 to 10.93.211.251 over interface eth0
> 2017-09-27 12:21:31.846 DEBUG [kea-dhcp4.packets/21] DHCP4_PACKET_RECEIVED 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: DHCPREQUEST 
> (type 3) received from 10.93.208.1 to 10.93.211.251 on interface eth0
> 2017-09-27 12:21:31.846 DEBUG [kea-dhcp4.packets/21] DHCP4_QUERY_DATA 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536, packet details: 
> local_address=10.93.211.251:67, remote_adress=10.93.208.1:68, 
> msg_type=DHCPREQUEST (3), transid=0x9bf06536,
> options:
>   type=053, len=001: 3 (uint8)
>   type=055, len=018: 1(uint8) 28(uint8) 2(uint8) 121(uint8) 15(uint8) 
> 6(uint8) 12(uint8) 40(uint8) 41(uint8) 42(uint8) 26(uint8) 119(uint8) 
> 3(uint8) 121(uint8) 249(uint8) 33(uint8) 252(uint8) 42(uint8)
> 2017-09-27 12:21:31.846 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_CFGMGR_SUBNET4_ADDR selected subnet 10.93.208.0/22 for packet 
> received by matching address 10.93.208.1
> 2017-09-27 12:21:31.846 DEBUG [kea-dhcp4.packets/21] DHCP4_SUBNET_SELECTED 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: the subnet with 
> ID 351 was selected for client assignments
> 2017-09-27 12:21:31.846 DEBUG [kea-dhcp4.packets/21] DHCP4_SUBNET_DATA 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: the selected 
> subnet details: 10.93.208.0/22
> 2017-09-27 12:21:31.846 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv4 reservation for 
> subnet id 351, identified by hwaddr=005056A827E2
> 2017-09-27 12:21:31.846 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using 
> identifier: hwaddr=005056A827E2
> 2017-09-27 12:21:31.846 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier hwaddr=005056A827E2, 
> found 0 host(s)
> 2017-09-27 12:21:31.846 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet id 
> 351 and identifier hwaddr=005056A827E2
> 2017-09-27 12:21:31.847 DEBUG [kea-dhcp4.ddns/21] 
> DHCP4_CLIENT_HOSTNAME_PROCESS [hwtype=1 00:50:56:a8:27:e2], cid=[no info], 
> tid=0x9bf06536: processing client's Hostname option
> 2017-09-27 12:21:31.847 DEBUG [kea-dhcp4.ddns/21] DHCP4_GENERATE_FQDN 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: client did not 
> send a FQDN or hostname; FQDN will be be generated for the client
> 2017-09-27 12:21:31.847 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_MYSQL_GET_SUBID_HWADDR obtaining IPv4 lease for subnet ID 351 and 
> hardware address hwtype=1 00:50:56:a8:27:e2
> 2017-09-27 12:21:31.848 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4 get one host with reservation for subnet 
> id 351 and IPv4 address 10.93.208.1
> 2017-09-27 12:21:31.848 DEBUG [kea-dhcp4.hosts/21] HOSTS_CFG_GET_ALL_ADDRESS4 
> get all hosts with reservations for IPv4 address 10.93.208.1
> 2017-09-27 12:21:31.848 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ALL_ADDRESS4_COUNT using address 10.93.208.1, found 0 host(s)
> 2017-09-27 12:21:31.848 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4_NULL host not found using subnet id 351 
> and address 10.93.208.1
> 2017-09-27 12:21:31.848 DEBUG [kea-dhcp4.hosts/21] 
> HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_ADDRESS4 trying alternate source for host 
> using subnet id 351 and address 10.93.208.1
> 2017-09-27 12:21:31.849 DEBUG [kea-dhcp4.dhcpsrv/21] DHCPSRV_MYSQL_GET_ADDR4 
> obtaining IPv4 lease for address 10.93.208.1
> 2017-09-27 12:21:31.850 DEBUG [kea-dhcp4.alloc-engine/21] 
> ALLOC_ENGINE_V4_REQUEST_EXTEND_LEASE [hwtype=1 00:50:56:a8:27:e2], cid=[no 
> info], tid=0x9bf06536: extending lifetime of the lease for address 10.93.208.1
> 2017-09-27 12:21:31.850 DEBUG [kea-dhcp4.dhcpsrv/21] DHCPSRV_QUEUE_NCR 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info]: name change request to remove 
> DNS entry queued: Type: 1 (CHG_REMOVE)
> Forward Change: yes
> Reverse Change: yes
> FQDN: [pre-10-93-208-1.stagingdhcp.example.com.]
> IP Address: [10.93.208.1]
> DHCID: 
> [000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62]
> Lease Expires On: 20170927122421
> Lease Length: 300
> 2017-09-27 12:21:31.850 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_MYSQL_UPDATE_ADDR4 updating IPv4 lease for address 10.93.208.1
> 2017-09-27 12:21:31.850 DEBUG [kea-dhcp-ddns.dhcp-to-d2/19] 
> DHCP_DDNS_QUEUE_MGR_QUEUE_RECEIVE Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62: 
> received and queued a request.
> 2017-09-27 12:21:31.850 DEBUG [kea-dhcp-ddns.d2-to-dns/19] 
> DHCP_DDNS_STARTING_TRANSACTION Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62:
> 2017-09-27 12:21:31.850 DEBUG [kea-dhcp-ddns.d2-to-dns/19] 
> DHCP_DDNS_UPDATE_REQUEST_SENT Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62: 
> Forward A/AAAA Remove to server: 10.93.211.12 port:53
> 2017-09-27 12:21:31.860 INFO  [kea-dhcp4.leases/21] DHCP4_LEASE_ALLOC 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: lease 
> 10.93.208.1 has been allocated
> 2017-09-27 12:21:31.860 DEBUG [kea-dhcp4.ddns/21] 
> DHCP4_RESPONSE_HOSTNAME_GENERATE [hwtype=1 00:50:56:a8:27:e2], cid=[no info], 
> tid=0x9bf06536: server has generated hostname 
> pre-10-93-208-1.stagingdhcp.example.com for the client
> 2017-09-27 12:21:31.860 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_MYSQL_UPDATE_ADDR4 updating IPv4 lease for address 10.93.208.1
> 2017-09-27 12:21:31.870 DEBUG [kea-dhcp4.ddns/21] DHCP4_NCR_CREATE [hwtype=1 
> 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: DDNS updates enabled, 
> therefore sending name change requests
> 2017-09-27 12:21:31.870 DEBUG [kea-dhcp4.options/21] DHCP4_PACKET_PACK 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: preparing 
> on-wire format of the packet to be sent
> 2017-09-27 12:21:31.870 DEBUG [kea-dhcp4.packets/21] DHCP4_PACKET_SEND 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: trying to send 
> packet DHCPACK (type 5) from 10.93.211.251:67 to 10.93.208.1:68 on interface 
> eth0
> 2017-09-27 12:21:31.870 DEBUG [kea-dhcp4.packets/21] DHCP4_RESPONSE_DATA 
> [hwtype=1 00:50:56:a8:27:e2], cid=[no info], tid=0x9bf06536: responding with 
> packet DHCPACK (type 5), packet details: local_address=10.93.211.251:67, 
> remote_adress=10.93.208.1:68, msg_type=DHCPACK (5), transid=0x9bf06536,
> options:
>   type=001, len=004: 4294966272 (uint32)
>   type=003, len=004: 10.93.211.254
>   type=006, len=008: 10.93.211.10 10.93.211.11
>   type=012, len=037: "pre-10-93-208-1.stagingdhcp.example.com" (string)
>   type=015, len=021: "stagingdhcp.example.com" (string)
>   type=042, len=016: 10.254.254.254 10.254.191.254 10.254.60.250 
> 10.254.191.250
>   type=051, len=004: 300 (uint32)
>   type=053, len=001: 5 (uint8)
>   type=054, len=004: 10.93.211.251
> 2017-09-27 12:21:31.870 DEBUG [kea-dhcp4.packets/21] DHCP4_BUFFER_WAIT 
> waiting for next DHCPv4 packet with timeout 1000 ms
> 2017-09-27 12:21:31.870 DEBUG [kea-dhcp4.dhcpsrv/21] 
> DHCPSRV_DHCP_DDNS_NCR_SENT NameChangeRequest sent to kea-dhcp-ddns: Type: 1 
> (CHG_REMOVE)
> Forward Change: yes
> Reverse Change: yes
> FQDN: [pre-10-93-208-1.stagingdhcp.example.com.]
> IP Address: [10.93.208.1]
> DHCID: 
> [000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62]
> Lease Expires On: 20170927122421
> Lease Length: 300
> 2017-09-27 12:21:31.870 DEBUG [kea-dhcp4.packets/21] 
> DHCP4_BUFFER_WAIT_INTERRUPTED interrupted wait for the next packet due to 
> timeout, signal or external socket callback (timeout value is 1000)
> 2017-09-27 12:21:31.870 DEBUG [kea-dhcp4.packets/21] DHCP4_BUFFER_WAIT 
> waiting for next DHCPv4 packet with timeout 1000 ms
> 2017-09-27 12:21:31.883 DEBUG [kea-dhcp-ddns.asiodns/19] 
> ASIODNS_FETCH_COMPLETED upstream fetch to 10.93.211.12(53) has now completed
> 2017-09-27 12:21:31.884 DEBUG [kea-dhcp-ddns.d2-to-dns/19] 
> DHCP_DDNS_UPDATE_RESPONSE_RECEIVED Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62: to 
> server: 10.93.211.12 port:53 status: SUCCESS, rcode: NOERROR
> 2017-09-27 12:21:31.884 DEBUG [kea-dhcp-ddns.d2-to-dns/19] 
> DHCP_DDNS_UPDATE_REQUEST_SENT Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62: 
> Forward RR Remove to server: 10.93.211.12 port:53
> 2017-09-27 12:21:31.912 DEBUG [kea-dhcp-ddns.asiodns/19] 
> ASIODNS_FETCH_COMPLETED upstream fetch to 10.93.211.12(53) has now completed
> 2017-09-27 12:21:31.912 DEBUG [kea-dhcp-ddns.d2-to-dns/19] 
> DHCP_DDNS_UPDATE_RESPONSE_RECEIVED Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62: to 
> server: 10.93.211.12 port:53 status: SUCCESS, rcode: NOERROR
> 2017-09-27 12:21:31.912 DEBUG [kea-dhcp-ddns.d2-to-dns/19] 
> DHCP_DDNS_UPDATE_REQUEST_SENT Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62: 
> Reverse Remove to server: 10.93.211.12 port:53
> 2017-09-27 12:21:31.940 DEBUG [kea-dhcp-ddns.asiodns/19] 
> ASIODNS_FETCH_COMPLETED upstream fetch to 10.93.211.12(53) has now completed
> 2017-09-27 12:21:31.940 DEBUG [kea-dhcp-ddns.d2-to-dns/19] 
> DHCP_DDNS_UPDATE_RESPONSE_RECEIVED Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62: to 
> server: 10.93.211.12 port:53 status: SUCCESS, rcode: NOERROR
> 2017-09-27 12:21:31.940 INFO  [kea-dhcp-ddns.d2-to-dns/19] 
> DHCP_DDNS_REMOVE_SUCCEEDED DHCP_DDNS Request ID 
> 000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62: 
> successfully removed the DNS mapping addition for this request: Type: 1 
> (CHG_REMOVE)
> Forward Change: yes
> Reverse Change: yes
> FQDN: [pre-10-93-208-1.stagingdhcp.example.com.]
> IP Address: [10.93.208.1]
> DHCID: 
> [000001E61EC121FD8E9CA6B831936C799BA6B47E7D792702932E307CA8314DAD666E62]
> Lease Expires On: 20170927122421
> Lease Length: 300
>
> Kind regards,
> Marcos David
>
> On 27/09/2017, 12:31, "Kea-users on behalf of Thomas Markwalder" 
> <[email protected] on behalf of [email protected]> wrote:
>
>     Hello David:
>
>     We're looking into this for you.  Could you supply logging that shows
>     the original request as well?
>
>     Regards,
>
>     Thomas Markwalder
>     ISC Software Engineering
>
>
>
>     _______________________________________________
>     Kea-users mailing list
>     [email protected]
>     https://lists.isc.org/mailman/listinfo/kea-users
>
>
> Information in this email including any attachments may be privileged, 
> confidential and is intended exclusively for the addressee. The views 
> expressed may not be official policy, but the personal views of the 
> originator. If you have received it in error, please notify the sender by 
> return e-mail and delete it from your system. You should not reproduce, 
> distribute, store, retransmit, use or disclose its contents to anyone. Please 
> note we reserve the right to monitor all e-mail communication through our 
> internal and external networks. SKY and the SKY marks are trademarks of Sky 
> plc and Sky International AG and are used under licence.
>
> Sky UK Limited (Registration No. 2906991), Sky-In-Home Service Limited 
> (Registration No. 2067075) and Sky Subscribers Services Limited (Registration 
> No. 2340150) are direct or indirect subsidiaries of Sky plc (Registration No. 
> 2247735). All of the companies mentioned in this paragraph are incorporated 
> in England and Wales and share the same registered office at Grant Way, 
> Isleworth, Middlesex TW7 5QD.



_______________________________________________
Kea-users mailing list
[email protected]
https://lists.isc.org/mailman/listinfo/kea-users

Reply via email to