OPNsense Forum

Archive => 17.1 Legacy Series => Topic started by: gothbert on April 02, 2017, 08:36:27 am

Title: OpenVPN: interrupted system call
Post by: gothbert on April 02, 2017, 08:36:27 am
Hi,

a previously working installation of OpenVPN on 17.1.3 stopped working after upgrade to 17.1.4. After successful initiation of the VPN tunnel, I get an interrupted system call error in the log:

Code: [Select]
...
Apr  2 01:24:40 opnsense openvpn[21132]: Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Apr  2 01:24:40 opnsense openvpn[21132]: Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-GCM-SHA384, 4096 bit RSA
Apr  2 01:24:40 opnsense openvpn[21132]: [<server FQDN>] Peer Connection Initiated with [AF_INET]<server IP address>:1194
Apr  2 01:24:41 opnsense openvpn[21132]: event_wait : Interrupted system call (code=4)
Apr  2 01:24:41 opnsense openvpn[21132]: TCP/UDP: Closing socket
Apr  2 01:24:41 opnsense openvpn[21132]: SIGTERM[hard,] received, process exiting
...

Reverting openvpn to 17.1.2 seems to have solved the problem.

Anything I can do to help track down the cause of the issue?

Kind regards,
Boris
Title: Re: OpenVPN: interrupted system call
Post by: gothbert on April 02, 2017, 12:11:20 pm
I installed OPNSense from scratch and remained on 17.1.1. The issue exists there as well.

The issue appears on my new physical machine with SuperMicro X11SBA-LN4F mainboard. There is also another issue with ntp running amok (questioning time server until rate limit kicks in).

I had to go back to OPNSense on a virtual machine. There openvpn and ntp run fine.

What can I do? Any help is appreciated.
Title: Re: OpenVPN: interrupted system call
Post by: gothbert on April 03, 2017, 12:14:21 pm
After another day of investigations, I found out that the issue is related to IPv6.

If and only if WAN has a global IPv6 address, OpenVPN fails.

The server log (verbosity 6) gives:

Code: [Select]
Apr  2 21:49:21 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 PUSH: Received control message: 'PUSH_REQUEST'
Apr  2 21:49:21 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 send_push_reply(): safe_cap=940
Apr  2 21:49:21 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 SENT CONTROL [opnsense]: 'PUSH_REPLY,route-gateway 192.168.38.1,topology subnet,ping 10,ping-restart 60,ifconfig 192.168.38.254 255.255.255.0' (status=1)
Apr  2 21:49:21 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 UDPv4 WRITE [50] to [AF_INET]xxx.xxx.28.18:30875: P_ACK_V1 kid=0 pid=[ #10 ] [ 6 ]
Apr  2 21:49:21 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 UDPv4 WRITE [187] to [AF_INET]xxx.xxx.28.18:30875: P_CONTROL_V1 kid=0 pid=[ #11 ] [ ] pid=7 DATA len=145
Apr  2 21:49:22 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 UDPv4 READ [50] from [AF_INET]xxx.xxx.28.18:30875: P_ACK_V1 kid=0 pid=[ #13 ] [ 7 ]
Apr  2 21:49:22 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 UDPv4 READ [133] from [AF_INET]xxx.xxx.28.18:30875: P_DATA_V1 kid=0 DATA len=132
Apr  2 21:49:22 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 MULTI: bad source address from client [::], packet dropped
Apr  2 21:49:22 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 UDPv4 READ [133] from [AF_INET]xxx.xxx.28.18:30875: P_DATA_V1 kid=0 DATA len=132
Apr  2 21:49:22 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 MULTI: bad source address from client [::], packet dropped
Apr  2 21:49:22 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 UDPv4 READ [117] from [AF_INET]xxx.xxx.28.18:30875: P_DATA_V1 kid=0 DATA len=116
Apr  2 21:49:22 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 MULTI: bad source address from client [::], packet dropped
Apr  2 21:49:24 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 UDPv4 READ [149] from [AF_INET]xxx.xxx.28.18:30875: P_DATA_V1 kid=0 DATA len=148
Apr  2 21:49:31 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 UDPv4 WRITE [69] to [AF_INET]xxx.xxx.28.18:30875: P_DATA_V1 kid=0 DATA len=68
Apr  2 21:49:35 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 UDPv4 READ [69] from [AF_INET]xxx.xxx.28.18:30875: P_DATA_V1 kid=0 DATA len=68
Apr  2 21:49:41 s1 openvpn-server[10536]: opnsense/xxx.xxx.28.18:30875 UDPv4 WRITE [69] to [AF_INET]xxx.xxx.28.18:30875: P_DATA_V1 kid=0 DATA len=68

Reading the OpenVPN forums, in principle, the dropped package from [::] should not be an issue, although I would like to understand why these packets are there in the first place.

On my new physical OPNSense OpenVPN client, OpenVPN connectivity breaks after 5 such messages on the server side. The identically configured virtual OPNSense OpenVPN client only produces 3 or 4 such messages and stays connected.

Searching the WWW, I found a few reports related to the message, and only one report of a user who also could track down the issue to having an IPv6 address on his internet-facing NIC.