Bug 224126

Note: this DOES NOT appear to be related to Bug 213448.

This morning I found the following in my daily run output (periodic daily) on my stable/11 box:

===
...

Security check:
    (output mailed separately)
usage: fetch [-146AadFlMmnPpqRrsUv] [-B bytes] [--bind-address=host]
       [--ca-cert=file] [--ca-path=dir] [--cert=file] [--crl=file]
       [-i file] [--key=file] [-N file] [--no-passive] [--no-proxy=list]
       [--no-sslv3] [--no-tlsv1] [--no-verify-hostname] [--no-verify-peer]
       [-o file] [--referer=URL] [-S bytes] [-T seconds]
       [--user-agent=agent-string] [-w seconds] URL ...
       fetch [-146AadFlMmnPpqRrsUv] [-B bytes] [--bind-address=host]
       [--ca-cert=file] [--ca-path=dir] [--cert=file] [--crl=file]
       [-i file] [--key=file] [-N file] [--no-passive] [--no-proxy=list]
       [--no-sslv3] [--no-tlsv1] [--no-verify-hostname] [--no-verify-peer]
       [-o file] [--referer=URL] [-S bytes] [-T seconds]
       [--user-agent=agent-string] [-w seconds] -h host -f file [-c dir]

Checking userland and kernel versions:
Userland and kernel are in sync.
...
===

Digging through old cron mails, this problem began November 28th (November 27th had no problem).  The system has not been rebuilt (world, mergemaster, etc. -- system is running stable/11 r325712) or rebooted since November 24th.

I modified rc.conf to contain ntp_leapfile_fetch_verbose="yes" and then ran service ntpd onefetch to achieve the following output:

===
root@mambo:~ # service ntpd onefetch
ntp_src_leapfile version is 3676924800
ntp_db_leapfile version is 3676924800
not replacing /var/db/ntpd.leap-seconds.list with /etc/ntp/leap-seconds
Within ntp leapfile expiry limit, initiating fetch
fetching https://www.ietf.org/timezones/data/leap-seconds.list
usage: fetch [-146AadFlMmnPpqRrsUv] [-B bytes] [--bind-address=host]
       [--ca-cert=file] [--ca-path=dir] [--cert=file] [--crl=file]
       [-i file] [--key=file] [-N file] [--no-passive] [--no-proxy=list]
       [--no-sslv3] [--no-tlsv1] [--no-verify-hostname] [--no-verify-peer]
       [-o file] [--referer=URL] [-S bytes] [-T seconds]
       [--user-agent=agent-string] [-w seconds] URL ...
       fetch [-146AadFlMmnPpqRrsUv] [-B bytes] [--bind-address=host]
       [--ca-cert=file] [--ca-path=dir] [--cert=file] [--crl=file]
       [-i file] [--key=file] [-N file] [--no-passive] [--no-proxy=list]
       [--no-sslv3] [--no-tlsv1] [--no-verify-hostname] [--no-verify-peer]
       [-o file] [--referer=URL] [-S bytes] [-T seconds]
       [--user-agent=agent-string] [-w seconds] -h host -f file [-c dir]

{very VERY long stall here}
===

pstree output showed the following:

===
 | \-+= 71172 root sshd: jdc [priv] (sshd)
 |   \-+- 71174 jdc sshd: jdc@pts/1 (sshd)
 |     \-+= 71175 jdc -bash (bash)
 |       \-+= 71176 root sudo su -
 |         \-+- 71177 root su -
 |           \-+= 71178 root -su (csh)
 |             \-+= 71181 root /bin/sh /etc/rc.d/ntpd onefetch
 |               \-+- 71200 root /bin/sh /etc/rc.d/ntpd onefetch
 |                 \--- 71201 root awk $1 == "#$" { print $2 }
===

I then ^C'd the service ntpd onefetch and re-ran it under truss -af and found the following:

===
root@mambo:~ # truss -af service ntpd onefetch
...
71342: wait4(-1,{ EXITED,val=0 },0x0,0x0)        = 71358 (0x116be)
Within ntp leapfile expiry limit, initiating fetch
71342: write(1,"Within ntp leapfile expiry limit"...,51) = 51 (0x33)
fetching https://www.ietf.org/timezones/data/leap-seconds.list
71342: write(1,"fetching https://www.ietf.org/ti"...,63) = 63 (0x3f)
71342: stat("/sbin/fetch",0x7fffffffdbe8)        ERR#2 'No such file or directory'
71342: stat("/bin/fetch",0x7fffffffdbe8)         ERR#2 'No such file or directory'
71342: stat("/usr/sbin/fetch",0x7fffffffdbe8)    ERR#2 'No such file or directory'
71342: stat("/usr/bin/fetch",{ mode=-r-xr-xr-x ,inode=81231,size=36400,blksize=32768 }) = 0 (0x0)
71360: <new process>
71342: vfork()                                   = 71360 (0x116c0)
71360: execve("/usr/bin/fetch",[ "fetch", "-mq", "-o", "https://www.ietf.org/timezones/data/leap-seconds.list" ],0x801418790) = 0 (0x0)
71360: mmap(0x0,32768,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34366189568 (0x800627000)
...
usage: fetch [-146AadFlMmnPpqRrsUv] [-B bytes] [--bind-address=host]
       [--ca-cert=file] [--ca-path=dir] [--cert=file] [--crl=file]
       [-i file] [--key=file] [-N file] [--no-passive] [--no-proxy=list]
       [--no-sslv3] [--no-tlsv1] [--no-verify-hostname] [--no-verify-peer]
       [-o file] [--referer=URL] [-S bytes] [-T seconds]
       [--user-agent=agent-string] [-w seconds] URL ...
       fetch [-146AadFlMmnPpqRrsUv] [-B bytes] [--bind-address=host]
       [--ca-cert=file] [--ca-path=dir] [--cert=file] [--crl=file]
       [-i file] [--key=file] [-N file] [--no-passive] [--no-proxy=list]
       [--no-sslv3] [--no-tlsv1] [--no-verify-hostname] [--no-verify-peer]
       [-o file] [--referer=URL] [-S bytes] [-T seconds]
       [--user-agent=agent-string] [-w seconds] -h host -f file [-c dir]
71360: write(2,"usage: fetch [-146AadFlMmnPpqRrs"...,811) = 811 (0x32b)
...
===

Look closely at the execve() call arguments: there output file argument is missing, which is why fetch is spewing usage syntax:

71360: execve("/usr/bin/fetch",[ "fetch", "-mq", "-o", "https://www.ietf.org/timezones/data/leap-seconds.list" ],0x801418790) = 0 (0x0)

This call essentially correlates with ntpd_fetch_leapfile() in /etc/rc.d/ntpd:

===
...
        if ntpd_needfetch_leapfile ; then
                for url in $ntp_leapfile_sources ; do
                        $verbose fetching $url
                        fetch $ntp_leapfile_fetch_opts -o $ntp_tmp_leapfile $url && break
                done
...
===

This means that $ntp_tmp_leapfile is somehow empty/undefined when the fetch is being attempted -- and that's the bug.

The long delay is an after-effect of get_ntp_leapfile_ver()'s use of awk.  AFAICT it's sitting around waiting for data it never gets because of the failed fetch.

ntp-related stuff in my rc.conf and periodic.conf:

rc.conf
=========
ntpd_enable="yes"
ntpd_config="/conf/ME/ntp.conf"
ntpd_sync_on_start="yes"
ntpd_flags="-4 -p /var/run/ntpd.pid -f /var/db/ntpd.drift"
ntp_leapfile_fetch_verbose="yes"

periodic.conf
===============
daily_ntpd_avoid_congestion="no"

ntp-related files and both file and leap second timestamps:

root@mambo:~ # ls -lT /etc/ntp/leap-seconds /var/db/ntpd.leap-seconds.list
-rw-r--r--  1 root  wheel  10408 Nov  9 08:37:13 2017 /etc/ntp/leap-seconds
-rw-r--r--  1 root  wheel  10408 Nov  9 08:37:13 2017 /var/db/ntpd.leap-seconds.list

root@mambo:~ # grep '^#\$' /etc/ntp/leap-seconds /var/db/ntpd.leap-seconds.list
/etc/ntp/leap-seconds:#$         3676924800
/var/db/ntpd.leap-seconds.list:#$        3676924800

/etc/rc.d/ntpd is:

# $FreeBSD: stable/11/etc/rc.d/ntpd 325256 2017-11-01 01:03:44Z cy $

/etc/periodic/daily/480.leapfile-ntpd is:

# $FreeBSD: stable/11/etc/periodic/daily/480.leapfile-ntpd 325256 2017-11-01 01:03:44Z cy $