lagg0 UP after ntpd and other services

[TheRickster]

Hi,

I've been using FreeNAS -> TrueNAS with a lagg0 interface using lacp to a HP 2824 switch for several years now.

Today I upgraded to TrueNAS-13.0-U3.1 and noticed in the logs an error with ntpd/wsdd

If you look at the log below, you will see that kernel brings up interfaces em0/em1, but does not bring up interface lagg0 until after ntpd and other services have started causing those services to fail.

Is this the expected behaviour or should lagg0 be brought UP earlier in the boot sequence

Cheers
Rick


Jan 18 13:56:56 nas CPU: Intel(R) Xeon(R) CPU E3-1270 V2 @ 3.50GHz (3492.07-MHz K8-class CPU)
Jan 18 13:56:56 nas Origin="GenuineIntel" Id=0x306a9 Family=0x6 Model=0x3a Stepping=9
Jan 18 13:56:56 nas Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
Jan 18 13:56:56 nas Features2=0x7fbae3ff<SSE3,PCLMULQDQ,DTES64,MON,DS_CPL,VMX,SMX,EST,TM2,SSSE3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,POPCNT,TSCDLT,AESNI,XSAVE,OSXSAVE,AVX,F16C,RDRAND>
Jan 18 13:56:56 nas AMD Features=0x28100800<SYSCALL,NX,RDTSCP,LM>
Jan 18 13:56:56 nas AMD Features2=0x1<LAHF>
Jan 18 13:56:56 nas Structured Extended Features=0x281<FSGSBASE,SMEP,ERMS>
Jan 18 13:56:56 nas Structured Extended Features3=0x9c000400<MD_CLEAR,IBPB,STIBP,L1DFL,SSBD>
Jan 18 13:56:56 nas XSAVE Features=0x1<XSAVEOPT>
Jan 18 13:56:56 nas VT-x: PAT,HLT,MTF,PAUSE,EPT,UG,VPID
Jan 18 13:56:56 nas TSC: P-state invariant, performance statistics
Jan 18 13:56:56 nas kernel: em0: link state changed to DOWN
Jan 18 13:56:56 nas kernel: em1: link state changed to DOWN
Jan 18 13:56:56 nas kernel: em0: link state changed to UP
Jan 18 13:56:56 nas kernel: em1: link state changed to UP
Jan 18 13:56:56 nas hwpmc: SOFT/16/64/0x67<INT,USR,SYS,REA,WRI> TSC/1/64/0x20<REA> IAP/4/48/0x3ff<INT,USR,SYS,EDG,THR,REA,WRI,INV,QUA,PRC> IAF/3/48/0x67<INT,USR,SYS,REA,WRI>
Jan 18 13:56:56 nas 1 2023-01-18T13:56:56.710019+11:00 nas.domain.com ntpd 1438 - - ntpd 4.2.8p15-a (1): Starting
Jan 18 13:56:56 nas 1 2023-01-18T13:56:56.710146+11:00 nas.domain.com ntpd 1438 - - Command line: /usr/sbin/ntpd -p /var/db/ntp/ntpd.pid -c /etc/ntp.conf -f /var/db/ntp/ntpd.drift -g
Jan 18 13:56:56 nas 1 2023-01-18T13:56:56.710151+11:00 nas.domain.com ntpd 1438 - - ----------------------------------------------------
Jan 18 13:56:56 nas 1 2023-01-18T13:56:56.710155+11:00 nas.domain.com ntpd 1438 - - ntp-4 is maintained by Network Time Foundation,
Jan 18 13:56:56 nas 1 2023-01-18T13:56:56.710159+11:00 nas.domain.com ntpd 1438 - - Inc. (NTF), a non-profit 501(c)(3) public-benefit
Jan 18 13:56:56 nas 1 2023-01-18T13:56:56.710163+11:00 nas.domain.com ntpd 1438 - - corporation. Support and training for ntp-4 are
Jan 18 13:56:56 nas 1 2023-01-18T13:56:56.710168+11:00 nas.domain.com ntpd 1438 - - available at https://www.nwtime.org/support
Jan 18 13:56:56 nas 1 2023-01-18T13:56:56.710171+11:00 nas.domain.com ntpd 1438 - - ----------------------------------------------------
Jan 18 13:56:56 nas nfsd: can't register svc name
Jan 18 13:56:56 nas kernel: NLM: local NSM state is 0
Jan 18 13:56:56 nas Security policy loaded: MAC/ntpd (mac_ntpd)
Jan 18 13:57:18 nas 1 2023-01-18T13:57:18.752055+11:00 nas.domain.com ntpd 1439 - - restrict: ignoring line 11, address/host '0.au.pool.ntp.org' unusable.
Jan 18 13:57:18 nas 1 2023-01-18T13:57:18.752323+11:00 nas.domain.com ntpd 1439 - - restrict: ignoring line 12, address/host '1.au.pool.ntp.org' unusable.
Jan 18 13:57:18 nas 1 2023-01-18T13:57:18.752579+11:00 nas.domain.com ntpd 1439 - - restrict: ignoring line 13, address/host '2.au.pool.ntp.org' unusable.
Jan 18 13:57:18 nas 1 2023-01-18T13:57:18.752839+11:00 nas.domain.com ntpd 1439 - - restrict: ignoring line 14, address/host '3.au.pool.ntp.org' unusable.
Jan 18 13:57:20 nas 1 2023-01-18T13:57:20.484466+11:00 nas.domain.com daemon 1549 - - _secure_path: /nonexistent/.login_conf is not owned by uid 65534
Jan 18 13:57:20 nas 1 2023-01-18T13:57:20.597281+11:00 nas.domain.com daemon 1539 - - 2023-01-18 13:57:20,597:wsdd WARNING(pid 1540): no interface given, using all interfaces
Jan 18 13:57:21 nas 1 2023-01-18T13:57:21.944428+11:00 nas.domain.com daemon 1539 - - 2023-01-18 13:57:21,944:wsdd ERROR(pid 1540): error while sending packet on lagg0: [Errno 50] Network is down
Jan 18 13:57:22 nas 1 2023-01-18T13:57:22.130431+11:00 nas.domain.com daemon 1539 - - 2023-01-18 13:57:22,130:wsdd ERROR(pid 1540): error while sending packet on lagg0: [Errno 50] Network is down
Jan 18 13:57:22 nas 1 2023-01-18T13:57:22.492898+11:00 nas.domain.com daemon 1539 - - 2023-01-18 13:57:22,492:wsdd ERROR(pid 1540): error while sending packet on lagg0: [Errno 50] Network is down
Jan 18 13:57:22 nas 1 2023-01-18T13:57:22.993646+11:00 nas.domain.com daemon 1539 - - 2023-01-18 13:57:22,993:wsdd ERROR(pid 1540): error while sending packet on lagg0: [Errno 50] Network is down
Jan 18 13:57:23 nas 1 2023-01-18T13:57:23.100435+11:00 nas.domain.com avahi-daemon 1490 - - XML_ParseBuffer() failed at line 1: no element found.
Jan 18 13:57:23 nas 1 2023-01-18T13:57:23.100456+11:00 nas.domain.com avahi-daemon 1490 - - Failed to load service group file /usr/local/etc/avahi/services/SSH.service, removing service.
Jan 18 13:57:24 nas syslog-ng[1841]: syslog-ng starting up; version='3.35.1'
Jan 18 13:57:24 nas kernel: pid 1353 (syslog-ng), jid 0, uid 0: exited on signal 6 (core dumped)
Jan 18 13:57:24 nas kernel: bridge0: Ethernet address: 58:9c:fc:00:14:07
Jan 18 13:57:25 nas kernel: em0: promiscuous mode enabled
Jan 18 13:57:25 nas kernel: em1: promiscuous mode enabled
Jan 18 13:57:25 nas kernel: lagg0: promiscuous mode enabled
Jan 18 13:57:25 nas kernel: em0: link state changed to DOWN
Jan 18 13:57:25 nas kernel: em1: link state changed to DOWN
Jan 18 13:57:25 nas kernel: bridge0: link state changed to UP
Jan 18 13:57:25 nas kernel: epair0a: Ethernet address: 1c:0a
Jan 18 13:57:25 nas kernel: epair0b: Ethernet address: 1c:0b
Jan 18 13:57:25 nas kernel: epair0a: link state changed to UP
Jan 18 13:57:25 nas kernel: epair0b: link state changed to UP
Jan 18 13:57:25 nas kernel: epair0a: changing name to 'vnet0.1'
Jan 18 13:57:26 nas 1 2023-01-18T13:57:26.854012+11:00 nas.domain.com daemon 1913 - - 2023-01-18 13:57:26,853:wsdd WARNING(pid 1914): no interface given, using all interfaces
Jan 18 13:57:28 nas kernel: vnet0.1: promiscuous mode enabled
Jan 18 13:57:30 nas kernel: lo0: link state changed to UP
Jan 18 13:57:30 nas kernel: em0: link state changed to UP
Jan 18 13:57:30 nas kernel: em1: link state changed to UP
Jan 18 13:57:41 nas kernel: lagg0: link state changed to UP
Jan 18 13:57:48 nas nfsrv_cache_session: no session IPaddr=192.168.0.200
Jan 18 13:58:10 nas nfsrv_cache_session[1841]: Last message 'no session IPaddr=20' repeated 1 times, suppressed by syslog-ng on nas.domain.com
Jan 18 13:58:10 nas Deprecated code (to be removed in FreeBSD 14): Asymmetric crypto features via /dev/crypto

 

[sretalla]

Is this the expected behaviour or should lagg0 be brought UP earlier in the boot sequence

I think this may be one of the cases for the use of the netwait option...

You can find it under Network | Global Configuration

 

[TheRickster]

Thanks,
That fixed the problem.
lagg0 now comes UP before ntpd

Code:

Jan 19 11:19:09 nas kernel: em0: link state changed to DOWN
Jan 19 11:19:09 nas kernel: em1: link state changed to DOWN
Jan 19 11:19:09 nas kernel: em0: link state changed to UP
Jan 19 11:19:09 nas kernel: em1: link state changed to UP
Jan 19 11:19:09 nas hwpmc: SOFT/16/64/0x67<INT,USR,SYS,REA,WRI> TSC/1/64/0x20<REA> IAP/4/48/0x3ff<INT,USR,SYS,EDG,THR,REA,WRI,INV,QUA,PRC> IAF/3/48/0x67<INT,USR,SYS,REA,WRI>
Jan 19 11:19:09 nas kernel: lagg0: link state changed to UP
Jan 19 11:19:09 nas 1 2023-01-19T11:19:09.290891+11:00 nas.ccoz.com ntpd 1604 - - ntpd 4.2.8p15-a (1): Starting