NetBSD Problem Report #55973

From martin@aprisoft.de  Thu Feb  4 09:53:00 2021
Return-Path: <martin@aprisoft.de>
Received: from mail.netbsd.org (mail.netbsd.org [199.233.217.200])
	(using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits))
	(Client CN "mail.NetBSD.org", Issuer "mail.NetBSD.org CA" (not verified))
	by mollari.NetBSD.org (Postfix) with ESMTPS id 4DFC61A9217
	for <gnats-bugs@gnats.NetBSD.org>; Thu,  4 Feb 2021 09:53:00 +0000 (UTC)
Message-Id: <20210204095250.559385CC7B9@emmas.aprisoft.de>
Date: Thu,  4 Feb 2021 10:52:50 +0100 (CET)
From: martin@NetBSD.org
Reply-To: martin@NetBSD.org
To: gnats-bugs@NetBSD.org
Subject: ntpd(8) does not notice all interface changes any more
X-Send-Pr-Version: 3.95

>Number:         55973
>Category:       bin
>Synopsis:       ntpd(8) does not notice all interface changes any more
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    bin-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Thu Feb 04 09:55:00 +0000 2021
>Last-Modified:  Thu Feb 18 15:15:01 +0000 2021
>Originator:     Martin Husemann
>Release:        NetBSD 9.99.79
>Organization:
The NetBSD Foundation, Inc.
>Environment:
System: NetBSD out-of-the-silent-planet.aprisoft.de 9.99.79 NetBSD 9.99.79 (GENERIC64) #187: Wed Feb 3 21:38:13 CET 2021 martin@seven-days-to-the-wolves.aprisoft.de:/work/src/sys/arch/evbarm/compile/GENERIC64 evbarm
Architecture: aarch64
Machine: evbarm
>Description:

This board has no RTC clock so usualy picks up / file system time at boot.
Due to other (unrelated) bugs it also has no network connectivity early at
boot. This means dhcpcd does not configure network before ntpd(8) starts,
but shortly after that netwok becomes available.

Nevertheless does ntpd stay in .INIT. state forever (actually only tested
for a few minutes):

 > ntpq -p
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
 emmas.aprisoft. .INIT.          16 u    -   64    0    0.000   +0.000   0.000


When I restart ntpd manually, it ~immediately establishes contact:

 > ntpq -p
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
 emmas.aprisoft. 44.66.217.167    3 u    2   64    1    0.114  +17976.   0.000


This used to work automatically w/o any manual intervention.

>How-To-Repeat:
s/a

>Fix:
n/a

>Audit-Trail:
From: Frank Kardel <kardel@kardel.name>
To: gnats-bugs@netbsd.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org,
 roy@NetBSD.org
Cc: 
Subject: Re: bin/55973: ntpd(8) does not notice all interface changes any more
Date: Thu, 4 Feb 2021 11:59:43 +0100

 seems like one of the last routing socket optimizations have gone

 unintendedly too far. Roy, could you please check?

 Frank


 On 02/04/21 10:55, martin@NetBSD.org wrote:
 >> Number:         55973
 >> Category:       bin
 >> Synopsis:       ntpd(8) does not notice all interface changes any more
 >> Confidential:   no
 >> Severity:       serious
 >> Priority:       medium
 >> Responsible:    bin-bug-people
 >> State:          open
 >> Class:          sw-bug
 >> Submitter-Id:   net
 >> Arrival-Date:   Thu Feb 04 09:55:00 +0000 2021
 >> Originator:     Martin Husemann
 >> Release:        NetBSD 9.99.79
 >> Organization:
 > The NetBSD Foundation, Inc.
 >> Environment:
 > System: NetBSD out-of-the-silent-planet.aprisoft.de 9.99.79 NetBSD 9.99.79 (GENERIC64) #187: Wed Feb 3 21:38:13 CET 2021 martin@seven-days-to-the-wolves.aprisoft.de:/work/src/sys/arch/evbarm/compile/GENERIC64 evbarm
 > Architecture: aarch64
 > Machine: evbarm
 >> Description:
 > This board has no RTC clock so usualy picks up / file system time at boot.
 > Due to other (unrelated) bugs it also has no network connectivity early at
 > boot. This means dhcpcd does not configure network before ntpd(8) starts,
 > but shortly after that netwok becomes available.
 >
 > Nevertheless does ntpd stay in .INIT. state forever (actually only tested
 > for a few minutes):
 >
 >   > ntpq -p
 >       remote           refid      st t when poll reach   delay   offset  jitter
 > ==============================================================================
 >   emmas.aprisoft. .INIT.          16 u    -   64    0    0.000   +0.000   0.000
 >
 >
 > When I restart ntpd manually, it ~immediately establishes contact:
 >
 >   > ntpq -p
 >       remote           refid      st t when poll reach   delay   offset  jitter
 > ==============================================================================
 >   emmas.aprisoft. 44.66.217.167    3 u    2   64    1    0.114  +17976.   0.000
 >
 >
 > This used to work automatically w/o any manual intervention.
 >
 >> How-To-Repeat:
 > s/a
 >
 >> Fix:
 > n/a
 >

From: Roy Marples <roy@marples.name>
To: Frank Kardel <kardel@kardel.name>, gnats-bugs@netbsd.org,
 gnats-admin@netbsd.org, netbsd-bugs@netbsd.org, roy@NetBSD.org
Cc: 
Subject: Re: bin/55973: ntpd(8) does not notice all interface changes any more
Date: Thu, 4 Feb 2021 16:54:21 +0000

 Hi Frank

 On 04/02/2021 10:59, Frank Kardel wrote:
 > seems like one of the last routing socket optimizations have gone
 > 
 > unintendedly too far. Roy, could you please check?

 So on my pinebook with ntpd dated Jan 1 this year (ie before my latest changes)
 I see the same / similar behaviour as on my dev machine with the latest code.

 I start ntpd without any interface other than lo0 on my pinebook and have netbsd 
 pool ntp servers setup.

 I hotplug urtwn0 and after the address as left the tentative state, ntpq -pn 
 shows remote's appear but in the .INIT. state.
 After 5 minutes waiting only one of these has left the .INIT. state and now has 
 a refid.

 I can restart ntpd a few times and eventually some or all leave the .INIT. state.

 I unplug urtwn0, ntpq reports no ids and plug it back in.
 ntpd sees the address leave tentative and voila ids come back.
 two have refids, one is in .INIT. and one is in .XFAC.

 I have no idea what this means, but I suggest things are working?

 Roy

From: Martin Husemann <martin@duskware.de>
To: Roy Marples <roy@marples.name>
Cc: Frank Kardel <kardel@kardel.name>, gnats-bugs@netbsd.org
Subject: Re: bin/55973: ntpd(8) does not notice all interface changes any more
Date: Thu, 4 Feb 2021 18:00:46 +0100

 On Thu, Feb 04, 2021 at 04:54:21PM +0000, Roy Marples wrote:
 > I start ntpd without any interface other than lo0 on my pinebook and have
 > netbsd pool ntp servers setup.

 In my case the network interface (awge0) is present at boot, but does
 not have carrier.

 Martin

From: Frank Kardel <kardel@kardel.name>
To: gnats-bugs@netbsd.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org,
 martin@NetBSD.org
Cc: 
Subject: Re: bin/55973: ntpd(8) does not notice all interface changes any more
Date: Thu, 4 Feb 2021 18:19:42 +0100

 Can you a "-D 4 -l /tmp/ntpd.log" to ntpd_flags so we can check what 
 happens in your case.

 Are your peers/servers configured with "iburst"?

 On 02/04/21 18:05, Martin Husemann wrote:
 > The following reply was made to PR bin/55973; it has been noted by GNATS.
 >
 > From: Martin Husemann <martin@duskware.de>
 > To: Roy Marples <roy@marples.name>
 > Cc: Frank Kardel <kardel@kardel.name>, gnats-bugs@netbsd.org
 > Subject: Re: bin/55973: ntpd(8) does not notice all interface changes any more
 > Date: Thu, 4 Feb 2021 18:00:46 +0100
 >
 >   On Thu, Feb 04, 2021 at 04:54:21PM +0000, Roy Marples wrote:
 >   > I start ntpd without any interface other than lo0 on my pinebook and have
 >   > netbsd pool ntp servers setup.
 >   
 >   In my case the network interface (awge0) is present at boot, but does
 >   not have carrier.
 >   
 >   Martin
 >   

From: Frank Kardel <kardel@kardel.name>
To: gnats-bugs@netbsd.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org,
 martin@NetBSD.org
Cc: 
Subject: Re: bin/55973: ntpd(8) does not notice all interface changes any more
Date: Thu, 4 Feb 2021 18:36:37 +0100

 Looks like it is behaving as expected.

 XFAC just means interfaces have changed in between - should recover at 
 next poll.

 INIT means that ntpd has not yet seen a reply packet (possibly not even 
 requested one

 up to now.

 Keep in mind the ntpd polls at its normal rate and needs at least 4 
 replys before considering

 tracking the time on a peer. So if interfaces come up after ntpd attempts to

 query peers we basically miss the first 64 second poll interval.

 A closer look is needed whether it is unfortunate timing.

 Frank


 On 02/04/21 17:55, Roy Marples wrote:
 > The following reply was made to PR bin/55973; it has been noted by GNATS.
 >
 > From: Roy Marples <roy@marples.name>
 > To: Frank Kardel <kardel@kardel.name>, gnats-bugs@netbsd.org,
 >   gnats-admin@netbsd.org, netbsd-bugs@netbsd.org, roy@NetBSD.org
 > Cc:
 > Subject: Re: bin/55973: ntpd(8) does not notice all interface changes any more
 > Date: Thu, 4 Feb 2021 16:54:21 +0000
 >
 >   Hi Frank
 >   
 >   On 04/02/2021 10:59, Frank Kardel wrote:
 >   > seems like one of the last routing socket optimizations have gone
 >   >
 >   > unintendedly too far. Roy, could you please check?
 >   
 >   So on my pinebook with ntpd dated Jan 1 this year (ie before my latest changes)
 >   I see the same / similar behaviour as on my dev machine with the latest code.
 >   
 >   I start ntpd without any interface other than lo0 on my pinebook and have netbsd
 >   pool ntp servers setup.
 >   
 >   I hotplug urtwn0 and after the address as left the tentative state, ntpq -pn
 >   shows remote's appear but in the .INIT. state.
 >   After 5 minutes waiting only one of these has left the .INIT. state and now has
 >   a refid.
 >   
 >   I can restart ntpd a few times and eventually some or all leave the .INIT. state.
 >   
 >   I unplug urtwn0, ntpq reports no ids and plug it back in.
 >   ntpd sees the address leave tentative and voila ids come back.
 >   two have refids, one is in .INIT. and one is in .XFAC.
 >   
 >   I have no idea what this means, but I suggest things are working?
 >   
 >   Roy
 >   

From: Martin Husemann <martin@duskware.de>
To: Frank Kardel <kardel@kardel.name>
Cc: gnats-bugs@netbsd.org
Subject: Re: bin/55973: ntpd(8) does not notice all interface changes any more
Date: Thu, 4 Feb 2021 20:01:56 +0100

 On Thu, Feb 04, 2021 at 06:19:42PM +0100, Frank Kardel wrote:
 > Can you a "-D 4 -l /tmp/ntpd.log" to ntpd_flags so we can check what happens
 > in your case.
 > 
 > Are your peers/servers configured with "iburst"?

 No iburst configured.
 The log option you gave fill the console with lots of output and wrote a
 tiny /tmp/ntpd.log. The console output shows that the awge0 interface is
 used and after waiting a lot longer there are signs of a connection to
 the server.

 I can make the (longish) console output available if you are interested,
 but maybe this is just normal behaviour (though I do see way faster first
 contatcts and even the typical initial jump from -g on other clients,
 usually takes less than 3 minutes to be more or less on the right time).

 Martin

From: Frank Kardel <kardel@netbsd.org>
To: Martin Husemann <martin@duskware.de>
Cc: gnats-bugs@netbsd.org
Subject: Re: bin/55973: ntpd(8) does not notice all interface changes any more
Date: Fri, 5 Feb 2021 08:29:43 +0100

 ok, iburst would improve startup.

 Sorry, I forgot that the debug output just send to stdout. I always trip 
 over that.

 For systems without RTC it should help to enable ntpdate at startup for

 the initial time setting. On systems with RTC starting with the

 options "-N -g" is usually advisible.

 Frank


 On 02/04/21 20:01, Martin Husemann wrote:
 > On Thu, Feb 04, 2021 at 06:19:42PM +0100, Frank Kardel wrote:
 >> Can you a "-D 4 -l /tmp/ntpd.log" to ntpd_flags so we can check what happens
 >> in your case.
 >>
 >> Are your peers/servers configured with "iburst"?
 > No iburst configured.
 > The log option you gave fill the console with lots of output and wrote a
 > tiny /tmp/ntpd.log. The console output shows that the awge0 interface is
 > used and after waiting a lot longer there are signs of a connection to
 > the server.
 >
 > I can make the (longish) console output available if you are interested,
 > but maybe this is just normal behaviour (though I do see way faster first
 > contatcts and even the typical initial jump from -g on other clients,
 > usually takes less than 3 minutes to be more or less on the right time).
 >
 > Martin

From: Martin Husemann <martin@duskware.de>
To: Frank Kardel <kardel@kardel.name>
Cc: gnats-bugs@netbsd.org
Subject: Re: bin/55973: ntpd(8) does not notice all interface changes any more
Date: Wed, 17 Feb 2021 12:04:00 +0100

 I am curious, is this still expected behaviour?

  > uptime; ping -o clock; ntpq -p
 12:01PM  up 19 mins, 1 user, load averages: 0.00, 0.00, 0.00
 PING emmas.aprisoft.de (192.168.111.42): 56 data bytes
 64 bytes from 192.168.111.42: icmp_seq=0 ttl=255 time=0.137420 ms

 ----emmas.aprisoft.de PING Statistics----
 1 packets transmitted, 1 packets received, 0.0% packet loss
 round-trip min/avg/max/stddev = 0.137420/0.137420/0.137420/0.000000 ms
      remote           refid      st t when poll reach   delay   offset  jitter
 ==============================================================================
  emmas.aprisoft. .INIT.          16 u    -  512    0    0.000   +0.000   0.000

 I am especially confused by the reach=0 field and the poll interval increasing.

 This does not sound like sane default behaviour.
 The machine uses:

 ntpd=YES ntpd_flags="-g"


 Martin

From: "Frank Kardel" <kardel@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc: 
Subject: PR/55973 CVS commit: src/external/bsd/ntp/dist/ntpd
Date: Thu, 18 Feb 2021 15:13:38 +0000

 Module Name:	src
 Committed By:	kardel
 Date:		Thu Feb 18 15:13:38 UTC 2021

 Modified Files:
 	src/external/bsd/ntp/dist/ntpd: ntp_timer.c

 Log Message:
 PR bin/55973:

 fix routing message triggered one shot interface update.


 To generate a diff of this commit:
 cvs rdiff -u -r1.9 -r1.10 src/external/bsd/ntp/dist/ntpd/ntp_timer.c

 Please note that diffs are not public domain; they are subject to the
 copyright notices on the relevant files.

Home	PR Database Search