Hi everyone,
i did a fresh installation of IPFire 2.25 (x86_64) on my Hyper-V Server 2016 (Gen1 VM).
The system took 8 minutes to boot after the line “Setting up Pakfire Package Manager…”
I didn’t find much information in the logfiles. I think it has something to do with either the unbound service or the openvpn net2net connection. Maybe the problem only occurs on the x64 architecture beacuse I’m currently running the same version at x86 on the same server and there is no such problem.
I marked the 8 minutes interruption with ------------------------------
Jun 21 02:07:04 ipfire dhcpcd[5358]: red0: releasing lease of xxx.xxx.xxx.xxx
Jun 21 02:07:04 ipfire dhcpcd[6202]: ps_inet_recvmsgpsp: Network is unreachable
Jun 21 02:07:04 ipfire dhcpcd[5358]: red0: deleting route to xxx.xxx.xxx.0/24
Jun 21 02:07:04 ipfire dhcpcd[5358]: red0: deleting default route via xxx.xxx.xxx.1
Jun 21 02:07:04 ipfire dhcpcd.exe[6659]: red0 has been brought down (STOP)
Jun 21 02:07:04 ipfire openvpnserver[6061]: event_wait : Interrupted system call (code=4)
Jun 21 02:07:04 ipfire openvpnserver[6061]: /sbin/ip route del 10.46.19.0/24
Jun 21 02:07:04 ipfire N2N[6118]: event_wait : Interrupted system call (code=4)
Jun 21 02:07:04 ipfire N2N[6118]: /sbin/ip route del 192.168.20.0/24
Jun 21 02:07:04 ipfire openvpnserver[6061]: ERROR: Linux route delete command failed: external program exited with error status: 2
Jun 21 02:07:04 ipfire openvpnserver[6061]: /sbin/ip route del 10.46.18.0/24
Jun 21 02:07:04 ipfire N2N[6118]: ERROR: Linux route delete command failed: external program exited with error status: 2
Jun 21 02:07:04 ipfire N2N[6118]: Closing TUN/TAP interface
Jun 21 02:07:04 ipfire N2N[6118]: /sbin/ip addr del dev tun1 local 10.34.27.1 peer 10.34.27.2
Jun 21 02:07:04 ipfire openvpnserver[6061]: ERROR: Linux route delete command failed: external program exited with error status: 2
Jun 21 02:07:04 ipfire openvpnserver[6061]: Closing TUN/TAP interface
Jun 21 02:07:04 ipfire openvpnserver[6061]: /sbin/ip addr del dev tun0 local 10.46.18.1 peer 10.46.18.2
Jun 21 02:07:04 ipfire N2N[6118]: Linux ip addr del failed: external program exited with error status: 2
Jun 21 02:07:05 ipfire openvpnserver[6061]: Linux ip addr del failed: external program exited with error status: 2
Jun 21 02:07:05 ipfire N2N[6118]: SIGTERM[hard,] received, process exiting
Jun 21 02:07:05 ipfire openvpnserver[6061]: SIGTERM[hard,] received, process exiting
Jun 21 02:07:05 ipfire dhcpcd[5358]: dhcpcd exited
Jun 21 02:07:05 ipfire unbound: [5113:0] info: service stopped (unbound 1.10.1).
Jun 21 02:07:05 ipfire unbound: [5113:0] info: server stats for thread 0: 10 queries, 1 answers from cache, 9 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Jun 21 02:07:05 ipfire unbound: [5113:0] info: server stats for thread 0: requestlist max 1 avg 0.222222 exceeded 0 jostled 0
Jun 21 02:07:05 ipfire unbound: [5113:0] info: average recursion processing time 0.148931 sec
Jun 21 02:07:05 ipfire unbound: [5113:0] info: histogram of recursion processing times
Jun 21 02:07:05 ipfire unbound: [5113:0] info: [25%]=0.04096 median[50%]=0.090112 [75%]=0.126976
Jun 21 02:07:05 ipfire unbound: [5113:0] info: lower(secs) upper(secs) recursions
Jun 21 02:07:05 ipfire unbound: [5113:0] info: 0.016384 0.032768 2
Jun 21 02:07:05 ipfire unbound: [5113:0] info: 0.032768 0.065536 1
Jun 21 02:07:05 ipfire unbound: [5113:0] info: 0.065536 0.131072 4
Jun 21 02:07:05 ipfire unbound: [5113:0] info: 0.262144 0.524288 2
Jun 21 02:07:07 ipfire acpid: exiting
Jun 21 02:07:08 ipfire kernel: Kernel logging (proc) stopped.
Jun 21 02:07:08 ipfire kernel: Kernel log daemon terminating.
Jun 21 02:07:09 ipfire exiting on signal 15
------------------------------
Jun 21 02:15:31 ipfire syslogd 1.5.1: restart (remote reception).
Jun 21 02:15:31 ipfire unbound: [1634:0] notice: init module 0: validator
Jun 21 02:15:31 ipfire unbound: [1634:0] notice: init module 1: iterator
Jun 21 02:15:31 ipfire unbound: [1634:0] info: start of service (unbound 1.10.1).
Jun 21 02:15:31 ipfire acpid: starting up with netlink and the input layer
Jun 21 02:15:31 ipfire acpid: 1 rule loaded
Jun 21 02:15:31 ipfire acpid: waiting for events: event logging is off
Jun 21 02:15:32 ipfire dhcpcd[1795]: dhcpcd-9.0.2 starting
Jun 21 02:15:32 ipfire kernel: 8021q: 802.1Q VLAN Support v1.8
Jun 21 02:15:32 ipfire dhcpcd[1818]: DUID 00:01:00:01:26:81:63:24:xx:xx:xx....
Jun 21 02:15:32 ipfire dhcpcd[1818]: red0: IAID 5d:xx:......
Jun 21 02:15:32 ipfire dhcpcd[1818]: red0: adding address fe80::xxx
Jun 21 02:15:32 ipfire dhcpcd[1818]: ipv6_addaddr1: Permission denied
Jun 21 02:15:32 ipfire unbound: [1634:0] error: SERVFAIL <ns11.whois.co.kr. A IN>: all the configured stub or forward servers failed, at zone .
Jun 21 02:15:33 ipfire dhcpcd[1818]: red0: soliciting a DHCP lease
Jun 21 02:15:33 ipfire dhcpcd[1818]: red0: offered xxx.xxx.xxx.xxx from 10.34.113.1
Jun 21 02:15:33 ipfire dhcpcd[1818]: red0: probing address xxx.xxx.xxx.xxx/24
Jun 21 02:15:33 ipfire dhcpcd[1818]: red0: soliciting an IPv6 router
Jun 21 02:15:37 ipfire dhcpcd[1818]: red0: leased xxx.xxx.xxx.xxx for 3600 seconds
Jun 21 02:15:37 ipfire dhcpcd[1818]: red0: adding route to xxx.xxx.xxx.0/24
Jun 21 02:15:37 ipfire dhcpcd[1818]: red0: adding default route via xxx.xxx.xxx.1
Jun 21 02:15:38 ipfire dhcpcd.exe[1851]: red0 has been (re)configured with IP=xxx.xxx.xxx.xxx
Jun 21 02:15:38 ipfire unbound: [1634:0] info: generate keytag query _ta-4a5c-4f66. NULL IN
Jun 21 02:15:38 ipfire unbound: [1634:0] info: service stopped (unbound 1.10.1).
Jun 21 02:15:38 ipfire unbound: [1634:0] info: server stats for thread 0: 2 queries, 0 answers from cache, 2 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Jun 21 02:15:38 ipfire unbound: [1634:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
Jun 21 02:15:38 ipfire unbound: [1634:0] info: average recursion processing time 0.036877 sec
Jun 21 02:15:38 ipfire unbound: [1634:0] info: histogram of recursion processing times
Jun 21 02:15:38 ipfire unbound: [1634:0] info: [25%]=0 median[50%]=0 [75%]=0
Jun 21 02:15:38 ipfire unbound: [1634:0] info: lower(secs) upper(secs) recursions
Jun 21 02:15:38 ipfire unbound: [1634:0] info: 0.000000 0.000001 1
Jun 21 02:15:38 ipfire unbound: [1634:0] info: 0.065536 0.131072 1
Jun 21 02:15:38 ipfire unbound: [1634:0] notice: Restart of unbound 1.10.1.
Jun 21 02:15:38 ipfire unbound: [1634:0] notice: init module 0: validator
Jun 21 02:15:38 ipfire unbound: [1634:0] notice: init module 1: iterator
Jun 21 02:15:38 ipfire unbound: [1634:0] info: start of service (unbound 1.10.1).
Jun 21 02:15:38 ipfire unbound: [1634:0] info: generate keytag query _ta-4a5c-4f66. NULL IN
Jun 21 02:15:45 ipfire kernel: tun: Universal TUN/TAP device driver, 1.6
Jun 21 02:15:45 ipfire openvpnserver[2314]: OpenVPN 2.4.9 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Jun 4 2020
Jun 21 02:15:45 ipfire openvpnserver[2314]: library versions: OpenSSL 1.1.1g 21 Apr 2020, LZO 2.09
Jun 21 02:15:45 ipfire openvpnserver[2315]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jun 21 02:15:45 ipfire openvpnserver[2315]: Diffie-Hellman initialized with 2048 bit key
Jun 21 02:15:45 ipfire openvpnserver[2315]: CRL: loaded 1 CRLs from file /var/ipfire/ovpn/crls/cacrl.pem
Jun 21 02:15:45 ipfire openvpnserver[2315]: Outgoing Control Channel Authentication: Using 256 bit message hash 'SHA256' for HMAC authentication
Jun 21 02:15:45 ipfire openvpnserver[2315]: Incoming Control Channel Authentication: Using 256 bit message hash 'SHA256' for HMAC authentication
Jun 21 02:15:45 ipfire openvpnserver[2315]: ROUTE_GATEWAY xxx.xxx.xxx.1/255.255.255.0 IFACE=red0 HWADDR=00:xx:.....
Jun 21 02:15:45 ipfire openvpnserver[2315]: TUN/TAP device tun0 opened
Jun 21 02:15:45 ipfire openvpnserver[2315]: TUN/TAP TX queue length set to 100
Jun 21 02:15:45 ipfire openvpnserver[2315]: /sbin/ip link set dev tun0 up mtu 1500
Jun 21 02:15:45 ipfire openvpnserver[2315]: /sbin/ip addr add dev tun0 local 10.46.18.1 peer 10.46.18.2
Jun 21 02:15:45 ipfire openvpnserver[2315]: /sbin/ip route add 10.46.19.0/24 via 10.46.18.2
Jun 21 02:15:45 ipfire openvpnserver[2315]: /sbin/ip route add 10.46.18.0/24 via 10.46.18.2
Jun 21 02:15:45 ipfire openvpnserver[2315]: Could not determine IPv4/IPv6 protocol. Using AF_INET
Jun 21 02:15:45 ipfire openvpnserver[2315]: Socket Buffers: R=[212992->212992] S=[212992->212992]
Jun 21 02:15:45 ipfire openvpnserver[2315]: UDPv4 link local (bound): [AF_INET][undef]:1149
Jun 21 02:15:45 ipfire openvpnserver[2315]: UDPv4 link remote: [AF_UNSPEC]
Jun 21 02:15:45 ipfire openvpnserver[2315]: GID set to nobody
Jun 21 02:15:45 ipfire openvpnserver[2315]: UID set to nobody
Jun 21 02:15:45 ipfire openvpnserver[2315]: MULTI: multi_init called, r=256 v=256
Jun 21 02:15:45 ipfire openvpnserver[2315]: IFCONFIG POOL: base=10.46.18.4 size=62, ipv6=0
Jun 21 02:15:45 ipfire openvpnserver[2315]: IFCONFIG POOL LIST
Jun 21 02:15:45 ipfire openvpnserver[2315]: Initialization Sequence Completed
Jun 21 02:15:45 ipfire root: Could not find a bridged zone for tun0
Jun 21 02:15:45 ipfire vnstatd[1583]: Interface "tun0" enabled.
Jun 21 02:15:45 ipfire codel: Codel AQM has been enabled on 'tun0'.
Has anyone had the same problem or can reproduce it?
Thanks in advance
Sincerely
Thomas