[Kea-users] Duplicate logging
jim at wrightthisway.com
jim at wrightthisway.com
Mon Aug 10 15:31:37 UTC 2026
Hey Darren, it looks to me like the thread ID does match? 0xf90b62 for
both.
I've done a packet capture for that server, it also acts as an NTP
server and those packets appear normal and not duplicated. Looking at
the DHCP packets, I'm only seeing ONE Discover packets going to the
server, but then see two replies. So the DHCP server is handling this
twice.
Time Source Destination Protocol Length Info
2.008807 100.67.122.254 100.67.10.20 DHCP 337 DHCP
Discover - Transaction ID 0xbaef852c
2.009683 100.67.10.20 100.67.122.254 DHCP 363 DHCP Offer
- Transaction ID 0xbaef852c
2.010090 100.67.10.20 100.67.122.254 DHCP 363 DHCP Offer
- Transaction ID 0xbaef852c
And with only one Kea process running, I'm really stumped as to what's
going on here.
On 2026-08-10 03:41, Darren Ankney wrote:
> Hi Jim,
>
> Adding the thread ID (and inspection of the log configuration)
> indicates that these are not duplicated log messages:
>
> 2026-08-09 11:55:20.510 INFO [kea-dhcp4.dhcp4/312252.139861619762880]
> DHCP4_QUERY_LABEL received query: [hwtype=1 b4:45:06:eb:25:69],
> cid=[01:b4:45:06:eb:25:69], tid=0xf908b62
>
> 2026-08-09 11:55:20.510 INFO [kea-dhcp4.dhcp4/312252.139861628155584]
> DHCP4_QUERY_LABEL received query: [hwtype=1 b4:45:06:eb:25:69],
> cid=[01:b4:45:06:eb:25:69], tid=0xf908b62
>
> Note that the thread ID between the two messages above do not match.
> These are most likely duplicated packets.
>
> Thank you,
> Darren Ankney
>
> On Sun, Aug 9, 2026 at 12:04 PM <jim at wrightthisway.com> wrote:
>>
>> Hi Darren, you are correct that the [%c/%i.%t] pattern wasn't part of
>> my
>> logging, I went back to my earliest config file and didn't see it
>> listed, not sure if the RHEL package had that changed or not by
>> default,
>> but I did just now add that to my pattern.
>>
>> "loggers": [
>> {
>> "name": "kea-dhcp4",
>> "output-options": [
>> {
>> "output": "kea-dhcp4.log",
>> "pattern": "%D{%Y-%m-%d %H:%M:%S.%q} %-5p [%c/%i.%t]
>> %m\n",
>> "maxsize": 150000000,
>> "maxver": 8
>> }
>> ],
>>
>> "severity": "INFO"
>> },
>>
>> Here is the updated logging I'm seeing:
>> 2026-08-09 11:55:20.510 INFO [kea-dhcp4.dhcp4/312252.139861619762880]
>> DHCP4_QUERY_LABEL received query: [hwtype=1 b4:45:06:eb:25:69],
>> cid=[01:b4:45:06:eb:25:69], tid=0xf908b62
>> 2026-08-09 11:55:20.510 INFO [kea-dhcp4.dhcp4/312252.139861628155584]
>> DHCP4_QUERY_LABEL received query: [hwtype=1 b4:45:06:eb:25:69],
>> cid=[01:b4:45:06:eb:25:69], tid=0xf908b62
>> 2026-08-09 11:55:20.510 INFO
>> [kea-dhcp4.packets/312252.139861619762880]
>> DHCP4_PACKET_RECEIVED [hwtype=1 b4:45:06:eb:25:69],
>> cid=[01:b4:45:06:eb:25:69], tid=0xf908b627: DHCPINF.254 to
>> 100.67.10.20
>> on interface eno16895np0
>> 2026-08-09 11:55:20.510 INFO
>> [kea-dhcp4.packets/312252.139861628155584]
>> DHCP4_PACKET_RECEIVED [hwtype=1 b4:45:06:eb:25:69],
>> cid=[01:b4:45:06:eb:25:69], tid=0xf908b627: DHCPINF.254 to
>> 100.67.10.20
>> on interface eno16895np0
>> 2026-08-09 11:55:20.510 INFO
>> [kea-dhcp4.packets/312252.139861628155584]
>> DHCP4_PACKET_SEND [hwtype=1 b4:45:06:eb:25:69],
>> cid=[01:b4:45:06:eb:25:69], tid=0xf908b627: trying to s.67.10.20:67 to
>> 100.67.98.232:68 on interface eno16895np0
>> 2026-08-09 11:55:20.510 INFO
>> [kea-dhcp4.packets/312252.139861619762880]
>> DHCP4_PACKET_SEND [hwtype=1 b4:45:06:eb:25:69],
>> cid=[01:b4:45:06:eb:25:69], tid=0xf908b627: trying to s.67.10.20:67 to
>> 100.67.98.232:68 on interface eno16895np0
>>
>> As far as I can tell I only have one Kea process running on this
>> server.
>> [root at 100671020-2 kea]# ps aux | grep kea
>> kea 312252 0.0 0.1 1832636 24524 ? Ssl 11:55 0:00
>> /usr/sbin/kea-dhcp4 -c /etc/kea/kea-dhcp4.conf
>> root 312828 0.0 0.0 227704 2260 pts/1 S+ 12:01 0:00
>> grep
>> --color=auto kea
>>
>>
>> Again, this happened suddenly with no changes to the system at that
>> time. My next step is to get a packet dump from what's reaching this
>> server to see if somehow packets being sent are duplicated for some
>> reason, that will be for Monday though.
>>
>>
>> On 2026-08-08 05:01, Darren Ankney wrote:
>> > Hi,
>> >
>> > It won't be possible to help you with this without at least the
>> > loggers section of your configuration. It also looks like you may
>> > have changed the logging pattern and did not include this part:
>> > "[%c/%i.%t]" which would have shown which logger was producing the
>> > log, the process id (to rule out the possibility of multiple Kea
>> > servers running), and finally the thread id (which would have been the
>> > final piece proving that it was the same log duplicated).
>> > Additionally, these values are often helpful when you are trying to
>> > trace what happened with a particular packet as they can move to
>> > different threads when parked during certain hook callouts and the
>> > like. It is often helpful to organize the logs by thread id when
>> > looking deeply at some behavior.
>> >
>> > Please attach a copy of your "loggers" configuration to progress
>> > troubleshooting.
>> >
>> > Thank you,
>> > Darren Ankney
>> >
>> > On Fri, Aug 7, 2026 at 4:10 PM Jim <jim at wrightthisway.com> wrote:
>> >>
>> >> I don’t check my logs often but was making an update to my config and
>> >> something odd caught my eye, I’m getting a number of lines duplicated.
>> >> My config hasn’t changed for months until today, and this started
>> >> happening back in July 28, it looks like Kea reloaded itself and
>> >> that’s when the dupes began.
>> >>
>> >> I checked the logs and all I see is Version 3.0.3 listed both before
>> >> and after that, so I don’t think the actual software release changed,
>> >> yum shows my version as 3.0.3-1.el10_2.
>> >>
>> >> Sample log lines that are dupes:
>> >>
>> >> 2026-08-07 16:01:09.625 INFO DHCP4_QUERY_LABEL received query:
>> >> [hwtype=1 0c:29:ef:e2:05:80], cid=[no info], tid=0xd14ec51b
>> >>
>> >> 2026-08-07 16:01:09.625 INFO DHCP4_QUERY_LABEL received query:
>> >> [hwtype=1 0c:29:ef:e2:05:80], cid=[no info], tid=0xd14ec51b
>> >>
>> >> 2026-08-07 16:01:09.625 INFO DHCP4_PACKET_RECEIVED [hwtype=1
>> >> 0c:29:ef:e2:05:80], cid=[no info], tid=0xd14ec51b: DHCPDISCOVER (type
>> >> 1) received from 100.67.122.254 to 100.67.10.20 on interface
>> >> eno16895np0
>> >>
>> >> 2026-08-07 16:01:09.625 INFO DHCP4_PACKET_RECEIVED [hwtype=1
>> >> 0c:29:ef:e2:05:80], cid=[no info], tid=0xd14ec51b: DHCPDISCOVER (type
>> >> 1) received from 100.67.122.254 to 100.67.10.20 on interface
>> >> eno16895np0
>> >>
>> >> 2026-08-07 16:01:09.626 INFO DHCP4_PACKET_SEND [hwtype=1
>> >> 0c:29:ef:e2:05:80], cid=[no info], tid=0xd14ec51b: trying to send
>> >> packet DHCPOFFER (type 2) from 100.67.10.20:67 to 100.67.122.254:67 on
>> >> interface eno16895np0
>> >>
>> >> 2026-08-07 16:01:09.626 INFO DHCP4_PACKET_SEND [hwtype=1
>> >> 0c:29:ef:e2:05:80], cid=[no info], tid=0xd14ec51b: trying to send
>> >> packet DHCPOFFER (type 2) from 100.67.10.20:67 to 100.67.122.254:67 on
>> >> interface eno16895np0
>> >>
>> >> --
>> >> ISC funds the development of this software with paid support
>> >> subscriptions. Contact us at https://www.isc.org/contact/ for more
>> >> information.
>> >>
>> >> To unsubscribe visit https://lists.isc.org/mailman/listinfo/kea-users.
>> >> Kea-users at lists.isc.org
More information about the Kea-users
mailing list