Modify

Opened 18 months ago

Last modified 12 months ago

#23146 new defect

openvpn and ntpd starting earlier than network

Reported by: risa2000 Owned by: developers
Priority: normal Milestone: Designated Driver (Trunk)
Component: base system Version: Trunk
Keywords: Cc:

Description

I was trying the recent r49395 to see if openvpn starts correctly (following recommendation from #20729) and noticed that now openvpn and ntpd starts even before the network is initialized.

I am including the full log in the attachment, here I just copy-paste some snippets.

First, both ntpd and openvpn starts at the same time, before any network interface is active. openvpn however creates correctly tun0 and ntpd binds to it.

Sat Aug 13 13:58:25 2016 daemon.notice ntpd[941]: ntpd 4.2.8p7@1.3265-o Fri Aug 12 23:43:33 UTC 2016 (1): Starting
Sat Aug 13 13:58:25 2016 daemon.info ntpd[941]: Command line: /sbin/ntpd -g -u ntp:ntp -p /var/run/ntpd.pid -n
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: OpenVPN 2.3.10 mips-openwrt-linux-gnu [SSL (PolarSSL)] [LZO] [EPOLL] [MH] [IPv6]
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: library versions: PolarSSL 1.3.16, LZO 2.09
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: Diffie-Hellman initialized with 1024 bit key
Sat Aug 13 13:58:25 2016 daemon.info procd: - init complete -
Sat Aug 13 13:58:25 2016 daemon.warn openvpn(risa_wrt_srv)[956]: WARNING: file '/etc/openvpn/risa-wrt.key' is group or others accessible
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: Socket Buffers: R=[163840->163840] S=[163840->163840]
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: TUN/TAP device tun0 opened
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: TUN/TAP TX queue length set to 100
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: /sbin/ip link set dev tun0 up mtu 1500
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: /sbin/ip addr add dev tun0 local 192.168.100.1 peer 192.168.100.2
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: /sbin/ip route add 192.168.4.0/24 via 192.168.100.2
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: /sbin/ip route add 192.168.100.0/24 via 192.168.100.2
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: UDPv4 link local (bound): [undef]
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: UDPv4 link remote: [undef]
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: MULTI: multi_init called, r=256 v=256
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: IFCONFIG POOL: base=192.168.100.4 size=62, ipv6=0
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: IFCONFIG POOL LIST
Sat Aug 13 13:58:25 2016 daemon.notice openvpn(risa_wrt_srv)[956]: Initialization Sequence Completed
Sat Aug 13 13:58:25 2016 daemon.info ntpd[941]: proto: precision = 3.286 usec (-18)
Sat Aug 13 13:58:25 2016 daemon.info ntpd[941]: Listen and drop on 0 v6wildcard [::]:123
Sat Aug 13 13:58:25 2016 daemon.info ntpd[941]: Listen and drop on 1 v4wildcard 0.0.0.0:123
Sat Aug 13 13:58:25 2016 daemon.info ntpd[941]: Listen normally on 2 tun0 192.168.100.1:123

Then all the other network interfaces are initialized by netifd, dnsmasq starts, etc (see the full log for the details) and during this time tun0 is lost, as is indicated by message from ntpd.

Sat Aug 13 13:58:30 2016 daemon.info ntpd[941]: Deleting interface #2 tun0, 192.168.100.1#123, interface stats: received=0, sent=0, dropped=0, active_time=5 secs

After that tun0 is never mentioned again in the list of active interfaces.

This means that after the sytem is fully initialized, tun0 is DOWN:

5: tun0: <POINTOPOINT,MULTICAST,NOARP> mtu 1500 qdisc fq_codel state DOWN group default qlen 100
    link/none

In the log there are also:
cat /etc/config/network
ls /etc/rc.d

I do not understand why ntpd and openvpn start so early if according to /etc/rc.d both should start after network and dnsmasq.

K10gpio_switch  K85odhcpd       K98boot         S10system       S20network      S50p910nd       S95done
K10openvpn      K89log          K99umount       S11sysctl       S35odhcpd       S60dnsmasq      S96led
K50dropbear     K90network      S00sysfixtime   S12log          S50cron         S65ntpd         S98gpio_switch
K65ntpd         K90sysfixtime   S10boot         S19firewall     S50dropbear     S90openvpn      S98sysntpd

Attachments (1)

openwrt-r49395-boot-ntpd-openwrt-race.log (21.6 KB) - added by risa2000 18 months ago.
ntpd and openvpn early start during the boot (tun0 created by openvpn is lost)

Download all attachments as: .zip

Change History (2)

Changed 18 months ago by risa2000

ntpd and openvpn early start during the boot (tun0 created by openvpn is lost)

comment:1 Changed 12 months ago by grumbler_eburg

tun0 created by openvpn and after this re-initialised by netifd.
To prevent this you should not define the interface "tun0" in the /etc/config/network.

It's possible netifd can't create the interface "tun0" and wait for it?

Add Comment

Modify Ticket

Action
as new .
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.