Hi Richard,
I'm sorry for my tardy response. I just returned from holiday.
On 2023-07-23 05:11, Richard Laager wrote:
> Some questions from upstream, with my commentary added...
>
>> How busy is this sustem? Is it just a simple client or also a server? If
>> server, how busy?
This is a server and participates in the NTP Pool project, so the NTPsec
process is fairly busy. From the logs the server is handling about 1.5
to 1.7 million NTP requests per hour.
>>
>> From the stack trace, the server side is trying to decode a NTS cookie. Is
>> this box setup as a NTS server? That needs a certificate and key so it takes
>> more than just upgrading from bullseye to bookworm.
>
> It's not, right? We previously established that this is using the stock
> ntp.conf?
>
No, it is not configured as an NTS server.
>> What are the chances that a valid NTP request with NTS arrived at this
>> system? ntpq -c ntsinfo will show counters.
>
I'd say the chances are fairly high that an invalid NTP request with NTS
has arrived. But the counters are all zero.
cyclone@karita:~$ ntpq -c ntsinfo
NTS client sends: 0
NTS client recvs good: 0
NTS client recvs w error: 0
NTS server recvs good: 0
NTS server recvs w error: 0
NTS server sends: 0
NTS make cookies: 0
NTS decode cookies: 0
NTS decode cookies old: 0
NTS decode cookies old2: 0
NTS decode cookies older: 0
NTS decode cookies too old: 0
NTS decode cookies error: 0
NTS KE client probes good: 0
NTS KE client probes bad: 0
NTS KE serves good: 0
NTS KE serves bad: 0
cyclone@karita:~$
> It would be good if you could check this. But if an NTS request is crashing
> ntpd, you might never see non-zero counters.
>
>> The log file from starting up might be helpful.
Here's the syslog entries from the most recent restart. I took the
liberty of scrubbing the high portions of the IP addresses.
2023-07-28T06:58:39.890236+00:00 karita ntpd[30320]: INIT: ntpd
ntpsec-1.2.2: Starting
2023-07-28T06:58:39.891073+00:00 karita ntpd[30320]: INIT: Command line:
/usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u
ntpsec:ntpsec
2023-07-28T06:58:39.891132+00:00 karita ntp-systemd-wrapper[30320]:
2023-07-28T06:58:39 ntpd[30320]: INIT: ntpd ntpsec-1.2.2: Starting
2023-07-28T06:58:39.892382+00:00 karita ntp-systemd-wrapper[30320]:
2023-07-28T06:58:39 ntpd[30320]: INIT: Command line: /usr/sbin/ntpd -p
/run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec
2023-07-28T06:58:39.892502+00:00 karita systemd[1]: Started
ntpsec.service - Network Time Service.
2023-07-28T06:58:39.894804+00:00 karita ntpd[30322]: INIT: precision =
0.060 usec (-24)
2023-07-28T06:58:39.895396+00:00 karita ntpd[30322]: INIT: successfully
locked into RAM
2023-07-28T06:58:39.899405+00:00 karita ntpd[30322]: CONFIG: readconfig:
parsing file: /etc/ntpsec/ntp.conf
2023-07-28T06:58:39.899544+00:00 karita ntpd[30322]: CONFIG: restrict
nopeer ignored
2023-07-28T06:58:39.900054+00:00 karita ntpd[30322]: CLOCK: leapsecond
file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature
2023-07-28T06:58:39.900121+00:00 karita ntpd[30322]: CLOCK: leapsecond
file ('/usr/share/zoneinfo/leap-seconds.list'): loaded,
expire=2023-12-28T00:00Z last=2017-01-01T00:00Z ofs=37
2023-07-28T06:58:39.900198+00:00 karita ntpd[30322]: INIT: Using
SO_TIMESTAMPNS(ns)
2023-07-28T06:58:39.900262+00:00 karita ntpd[30322]: IO: Listen and drop
on 0 v6wildcard [::]:123
2023-07-28T06:58:39.900367+00:00 karita ntpd[30322]: IO: Listen and drop
on 1 v4wildcard 0.0.0.0:123
2023-07-28T06:58:39.900518+00:00 karita ntpd[30322]: IO: Listen normally
on 2 lo 127.0.0.1:123
2023-07-28T06:58:39.900589+00:00 karita ntpd[30322]: IO: Listen normally
on 3 eth0 xxx.yyy.zzz.201:123
2023-07-28T06:58:39.900662+00:00 karita ntpd[30322]: IO: Listen normally
on 4 lo [::1]:123
2023-07-28T06:58:39.900913+00:00 karita ntpd[30322]: IO: Listen normally
on 5 eth0 [xxxx:yyyy:zzzz::5ce7]:123
2023-07-28T06:58:39.901000+00:00 karita ntpd[30322]: IO: Listen normally
on 6 eth0 [fe80::xxxx:yyyy:zzzz:dfe%2]:123
2023-07-28T06:58:39.901065+00:00 karita ntpd[30322]: IO: Listening on
routing socket on fd #23 for interface updates
2023-07-28T06:58:39.912520+00:00 karita ntpd[30322]: INIT: MRU 10922
entries, 13 hash bits, 65536 bytes
2023-07-28T06:58:39.912607+00:00 karita ntpd[30322]: INIT: Built with
OpenSSL 3.0.7 1 Nov 2022, 30000070
2023-07-28T06:58:39.912652+00:00 karita ntpd[30322]: INIT: Running with
OpenSSL 3.0.9 30 May 2023, 30000090
2023-07-28T06:58:39.912976+00:00 karita ntpd[30322]: NTSc: Using system
default root certificates.
2023-07-28T06:58:42.938515+00:00 karita ntpd[30322]: DNS: dns_probe:
0.debian.pool.ntp.org, cast_flags:8, flags:101
2023-07-28T06:58:42.957881+00:00 karita ntpd[30322]: DNS: dns_check:
processing 0.debian.pool.ntp.org, 8, 101
2023-07-28T06:58:42.957983+00:00 karita ntpd[30322]: DNS: Pool taking:
xxx.yyy.zzz.102
2023-07-28T06:58:42.958470+00:00 karita ntpd[30322]: DNS: Pool taking:
xxx.yyy.zzz.1
2023-07-28T06:58:42.958528+00:00 karita ntpd[30322]: DNS: Pool taking:
207.192.69.118
2023-07-28T06:58:42.958751+00:00 karita ntpd[30322]: DNS: Pool taking:
xxx.yyy.zzz.39
2023-07-28T06:58:42.959218+00:00 karita ntpd[30322]: DNS:
dns_take_status: 0.debian.pool.ntp.org=>good, 8
2023-07-28T06:58:43.936935+00:00 karita ntpd[30322]: DNS: dns_probe:
1.debian.pool.ntp.org, cast_flags:8, flags:101
2023-07-28T06:58:44.017455+00:00 karita ntpd[30322]: DNS: dns_check:
processing 1.debian.pool.ntp.org, 8, 101
2023-07-28T06:58:44.017588+00:00 karita ntpd[30322]: DNS: Pool taking:
xxx.yyy.zzz.36
2023-07-28T06:58:44.018108+00:00 karita ntpd[30322]: DNS: Pool taking:
xxx.yyy.zzz.97
2023-07-28T06:58:44.018161+00:00 karita ntpd[30322]: DNS: Pool taking:
xxx.yyy.zzz.245
2023-07-28T06:58:44.018476+00:00 karita ntpd[30322]: DNS: Pool taking:
xxx.yyy.zzz.244
2023-07-28T06:58:44.018556+00:00 karita ntpd[30322]: DNS:
dns_take_status: 1.debian.pool.ntp.org=>good, 8
2023-07-28T06:58:44.937671+00:00 karita ntpd[30322]: DNS: dns_probe:
2.debian.pool.ntp.org, cast_flags:8, flags:101
2023-07-28T06:58:44.959584+00:00 karita ntpd[30322]: DNS: dns_check:
processing 2.debian.pool.ntp.org, 8, 101
2023-07-28T06:58:44.959815+00:00 karita ntpd[30322]: DNS: Pool taking:
xxxx:yyyy:zzzz::53
2023-07-28T06:58:44.959947+00:00 karita ntpd[30322]: DNS: Pool taking:
xxxx:yyyy:zzzz::1000
Thank you,
Roy
