Tunnelblick disconnecting after 4-5mins (Sierra, 3.7.1 and 3.7.2beta3)

[jeff.j...@aeoncomputing.com]

Hello,

After updating Tunnelblick a couple months ago I've been seeing errors where Tunnelblick stops passing traffic, disconnects, tries reconnecting and eventually fails. Networking is goofed up as a result and it takes a reboot to clear.

The configuration had been working fine for a couple years. I don't know if a change in Sierra or a recent Tunnelblick update started this.

Any ideas are greatly appreciated!

===config===

client

remote publicgw.mydomain.tld 1194

dev tun

proto udp

resolv-retry infinite

nobind

persist-key

persist-tun

ca ca-cert.pem

cert client-englbert-cert.pem

key client-englebert-key.pem

ns-cert-type server

comp-lzo

verb 3

auth-user-pass

redirect-gateway def1

dhcp-option DNS 172.17.2.1

======tunnelblick log======

2017-07-06 15:30:54 OpenVPN 2.3.17 x86_64-apple-darwin [SSL (OpenSSL)] [LZO] [PKCS11] [MH] [IPv6] built on Jun 21 2017

2017-07-06 15:30:54 library versions: OpenSSL 1.0.2k  26 Jan 2017, LZO 2.09

2017-07-06 15:30:54 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:1337

2017-07-06 15:30:54 Need hold release from management interface, waiting...

*Tunnelblick: OS X 10.12.5; Tunnelblick 3.7.2beta03 (build 4840); prior version 3.7.1b (build 4813)

2017-07-06 15:30:54 *Tunnelblick: Attempting connection with MyCoVPN using shadow copy; Set nameserver = 769; monitoring connection

2017-07-06 15:30:54 *Tunnelblick: openvpnstart start MyCoVPN.tblk 1337 769 0 1 0 1065776 -ptADGNWradsgnw 2.3.17-openssl-1.0.2k

2017-07-06 15:30:55 *Tunnelblick: openvpnstart log:

     OpenVPN started successfully. Command used to start OpenVPN (one argument per displayed line):

          /Applications/Tunnelblick.app/Contents/Resources/openvpn/openvpn-2.3.17-openssl-1.0.2k/openvpn

          --daemon

          --log

          /Library/Application Support/Tunnelblick/Logs/-SUsers-Senglebert-SLibrary-SApplication Support-STunnelblick-SConfigurations-SMyCoVPN.tblk-SContents-SResources-Sconfig.ovpn.769_0_1_0_1065776.1337.openvpn.log

          --cd

          /Library/Application Support/Tunnelblick/Users/englebert/MyCoVPN.tblk/Contents/Resources

          --verb

          3

          --config

          /Library/Application Support/Tunnelblick/Users/englebert/MyCoVPN.tblk/Contents/Resources/config.ovpn

          --verb

          3

          --cd

          /Library/Application Support/Tunnelblick/Users/englebert/MyCoVPN.tblk/Contents/Resources

          --management

          127.0.0.1

          1337

          --management-query-passwords

          --management-hold

          --redirect-gateway

          def1

          --script-security

          2

          --up

          /Applications/Tunnelblick.app/Contents/Resources/client.up.tunnelblick.sh -9 -d -f -m -w -ptADGNWradsgnw

          --down

          /Applications/Tunnelblick.app/Contents/Resources/client.down.tunnelblick.sh -9 -d -f -m -w -ptADGNWradsgnw

2017-07-06 15:30:54 *Tunnelblick: openvpnstart starting OpenVPN

2017-07-06 15:30:55 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:1337

2017-07-06 15:30:55 *Tunnelblick: Established communication with OpenVPN

2017-07-06 15:30:55 *Tunnelblick: Obtained VPN username and password from the Keychain

2017-07-06 15:30:55 MANAGEMENT: CMD 'pid'

2017-07-06 15:30:55 MANAGEMENT: CMD 'state on'

2017-07-06 15:30:55 MANAGEMENT: CMD 'state'

2017-07-06 15:30:55 MANAGEMENT: CMD 'bytecount 1'

2017-07-06 15:30:55 MANAGEMENT: CMD 'hold release'

2017-07-06 15:30:55 MANAGEMENT: CMD 'username "Auth" "englebert"'

2017-07-06 15:30:55 MANAGEMENT: CMD 'password [...]'

2017-07-06 15:30:55 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts

2017-07-06 15:30:55 Socket Buffers: R=[196724->196724] S=[9216->9216]

2017-07-06 15:30:55 MANAGEMENT: >STATE:1499380255,RESOLVE,,,

2017-07-06 15:30:55 UDPv4 link local: [undef]

2017-07-06 15:30:55 UDPv4 link remote: [AF_INET]YY.YYY.YYY.YYY:1194

2017-07-06 15:30:55 MANAGEMENT: >STATE:1499380255,WAIT,,,

2017-07-06 15:30:55 MANAGEMENT: >STATE:1499380255,AUTH,,,

2017-07-06 15:30:55 TLS: Initial packet from [AF_INET]YY.YYY.YYY.YYY:1194, sid=7c2cf053 b7bb60ab

2017-07-06 15:30:55 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this

2017-07-06 15:30:55 VERIFY OK: depth=1, C=US, L=Somewhere, O=ClearOS, OU=Corporate, CN=ca.publicgw.mydomain.tld, emailAddress=secu...@publicgw.mydomain.tld, O=MyCo, ST=California

2017-07-06 15:30:55 VERIFY OK: nsCertType=SERVER

2017-07-06 15:30:55 VERIFY OK: depth=0, C=US, ST=California, L=Somewhere, O=ClearOS, O=MyCo, OU=Corporate, CN=publicgw.mydomain.tld, emailAddress=secu...@publicgw.mydomain.tld

2017-07-06 15:30:55 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key

2017-07-06 15:30:55 WARNING: INSECURE cipher with block size less than 128 bit (64 bit).  This allows attacks like SWEET32.  Mitigate by using a --cipher with a larger block size (e.g. AES-256-CBC).

2017-07-06 15:30:55 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication

2017-07-06 15:30:55 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key

2017-07-06 15:30:55 WARNING: INSECURE cipher with block size less than 128 bit (64 bit).  This allows attacks like SWEET32.  Mitigate by using a --cipher with a larger block size (e.g. AES-256-CBC).

2017-07-06 15:30:55 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication

2017-07-06 15:30:55 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-GCM-SHA384, 2048 bit RSA

2017-07-06 15:30:55 [publicgw.mydomain.tld] Peer Connection Initiated with [AF_INET]YY.YYY.YYY.YYY:1194

2017-07-06 15:30:56 MANAGEMENT: >STATE:1499380256,GET_CONFIG,,,

2017-07-06 15:30:57 SENT CONTROL [publicgw.mydomain.tld]: 'PUSH_REQUEST' (status=1)

2017-07-06 15:30:57 PUSH: Received control message: 'PUSH_REPLY,dhcp-option DNS 172.17.2.1,dhcp-option DOMAIN main.mydomain.tld,route 172.17.2.0 255.255.255.0,redirect-gateway def1,route 10.8.0.1,topology net30,ping 10,ping-restart 120,ifconfig 10.8.0.6 10.8.0.5'

2017-07-06 15:30:57 OPTIONS IMPORT: timers and/or timeouts modified

2017-07-06 15:30:57 OPTIONS IMPORT: --ifconfig/up options modified

2017-07-06 15:30:57 OPTIONS IMPORT: route options modified

2017-07-06 15:30:57 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified

2017-07-06 15:30:57 Opening utun (connect(AF_SYS_CONTROL)): Resource busy

2017-07-06 15:30:57 Opened utun device utun1

2017-07-06 15:30:57 do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0

2017-07-06 15:30:57 MANAGEMENT: >STATE:1499380257,ASSIGN_IP,,10.8.0.6,

2017-07-06 15:30:57 /sbin/ifconfig utun1 delete

                                        ifconfig: ioctl (SIOCDIFADDR): Can't assign requested address

2017-07-06 15:30:57 NOTE: Tried to delete pre-existing tun/tap instance -- No Problem if failure

2017-07-06 15:30:57 /sbin/ifconfig utun1 10.8.0.6 10.8.0.5 mtu 1500 netmask 255.255.255.255 up

2017-07-06 15:30:57 /Applications/Tunnelblick.app/Contents/Resources/client.up.tunnelblick.sh -9 -d -f -m -w -ptADGNWradsgnw utun1 1500 1542 10.8.0.6 10.8.0.5 init

                                        **********************************************

                                        Start of output from client.up.tunnelblick.sh

                                        Retrieved from OpenVPN: name server(s) [ 172.17.2.1 172.17.2.1 ], domain name [ main.mydomain.tld ], search domain(s) [  ], and SMB server(s) [  ]

                                        Not aggregating ServerAddresses because running on OS X 10.6 or higher

                                        Setting search domains to 'main.mydomain.tld' because running under OS X 10.6 or higher and the search domains were not set manually (or are allowed to be changed) and 'Prepend domain name to search domains' was not selected

                                        Saved the DNS and SMB configurations so they can be restored

                                        Changed DNS ServerAddresses setting from '192.168.2.1' to '172.17.2.1 172.17.2.1'

                                        Changed DNS SearchDomains setting from '' to 'main.mydomain.tld'

                                        Changed DNS DomainName setting from 'internal' to 'main.mydomain.tld'

                                        Did not change SMB NetBIOSName setting of ''

                                        Did not change SMB Workgroup setting of ''

                                        Did not change SMB WINSAddresses setting of ''

                                        DNS servers '172.17.2.1 172.17.2.1' will be used for DNS queries when the VPN is active

                                        NOTE: The DNS servers do not include any free public DNS servers known to Tunnelblick. This may cause DNS queries to fail or be intercepted or falsified even if they are directed through the VPN. Specify only known public DNS servers or DNS servers located on the VPN network to avoid such problems.

                                        Flushed the DNS cache via dscacheutil

                                        /usr/sbin/discoveryutil not present. Not flushing the DNS cache via discoveryutil

                                        Notified mDNSResponder that the DNS cache was flushed

                                        Setting up to monitor system configuration with process-network-changes

                                        End of output from client.up.tunnelblick.sh

                                        **********************************************

2017-07-06 15:31:01 *Tunnelblick: No 'connected.sh' script to execute

2017-07-06 15:31:01 /sbin/route add -net YY.YYY.YYY.YYY 192.168.2.1 255.255.255.255

                                        add net YY.YYY.YYY.YYY: gateway 192.168.2.1

2017-07-06 15:31:01 /sbin/route add -net 0.0.0.0 10.8.0.5 128.0.0.0

                                        add net 0.0.0.0: gateway 10.8.0.5

2017-07-06 15:31:01 /sbin/route add -net 128.0.0.0 10.8.0.5 128.0.0.0

                                        add net 128.0.0.0: gateway 10.8.0.5

2017-07-06 15:31:01 MANAGEMENT: >STATE:1499380261,ADD_ROUTES,,,

2017-07-06 15:31:01 /sbin/route add -net 172.17.2.0 10.8.0.5 255.255.255.0

                                        add net 172.17.2.0: gateway 10.8.0.5

2017-07-06 15:31:01 /sbin/route add -net 10.8.0.1 10.8.0.5 255.255.255.255

                                        add net 10.8.0.1: gateway 10.8.0.5

2017-07-06 15:31:01 Initialization Sequence Completed

2017-07-06 15:31:01 MANAGEMENT: >STATE:1499380261,CONNECTED,SUCCESS,10.8.0.6,YY.YYY.YYY.YYY

2017-07-06 15:31:06 *Tunnelblick process-network-changes: A system configuration change was ignored

2017-07-06 15:31:07 *Tunnelblick: This computer's apparent public IP address changed from XX.XX.XX.XX before connection to YY.YYY.YYY.YYY after connection

2017-07-06 15:36:03 [publicgw.mydomain.tld] Inactivity timeout (--ping-restart), restarting

2017-07-06 15:36:03 SIGUSR1[soft,ping-restart] received, process restarting

2017-07-06 15:36:03 MANAGEMENT: >STATE:1499379663,RECONNECTING,ping-restart,,

2017-07-06 15:36:03 *Tunnelblick: No 'reconnecting.sh' script to execute

2017-07-06 15:36:03 MANAGEMENT: CMD 'hold release'

2017-07-06 15:36:03 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts

2017-07-06 15:36:03 Socket Buffers: R=[196724->196724] S=[9216->9216]

2017-07-06 15:36:03 MANAGEMENT: >STATE:1499379663,RESOLVE,,,

2017-07-06 15:36:33 RESOLVE: Cannot resolve host address: publicgw.mydomain.tld: nodename nor servname provided, or not known

2017-07-06 15:36:33 MANAGEMENT: >STATE:1499379693,RESOLVE,,,

[Tunnelblick developer]

The connection is restarting:

2017-07-06 15:36:03 [publicgw.mydomain.tld] Inactivity timeout (--ping-restart), restarting

2017-07-06 15:36:03 SIGUSR1[soft,ping-restart] received, process restarting

I don't know why that is happening; if the VPN is behaving normally that shouldn't happen. It is not caused by Tunnelblick or OpenVPN or Sierra (although it could be caused by third-party software such as Little Snitch). The most likely causes are problems with a local router or ISP or changes on the VPN server or its network.

The reason that the OpenVPN restart fails:

2017-07-06 15:36:33 RESOLVE: Cannot resolve host address: publicgw.mydomain.tld: nodename nor servname provided, or not known

is that the VPN server's address cannot be resolved.

The VPN server's address cannot be resolved because OpenVPN is trying to use the DNS server that is located on the VPN (the 172.17.2.1  and172.17.2.1 DNS servers). That won't work, because the VPN is not working!

To restart properly, OpenVPN needs to restore the network and then reconnect. Remove the "persist-tun" from your configuration. That will force OpenVPN to restore the original network configuration before restarting.

2017-07-06 15:30:55 VERIFY OK: depth=1, C=US, L=Somewhere, O=ClearOS, OU=Corporate, CN=ca.publicgw.mydomain.tld, emailAddress=security@publicgw.mydomain.tld, O=MyCo, ST=California

2017-07-06 15:30:55 VERIFY OK: nsCertType=SERVER

2017-07-06 15:30:55 VERIFY OK: depth=0, C=US, ST=California, L=Somewhere, O=ClearOS, O=MyCo, OU=Corporate, CN=publicgw.mydomain.tld, emailAddress=security@publicgw.mydomain.tld

[jeff.j...@aeoncomputing.com]

I made the settings and DNS changes you suggested. Those errors have disappeared. However the VPN connection still dies around the same duration of time. 

I have a iOS device with a OpenVPN client and it works fine connecting to the same VPN server while on the same wireless LAN as the tunnelblick Macbook that drops the connection.

There is something about Tunnelblick or running on Sierra that has changed.

[Tunnelblick developer]

Please post the diagnostic info from a connect / (fail) /disconnect sequence now that you've fixed the other problem.

[elmar.s...@t-online.de]

I have a similar problem. 

Here is my bug report: 

*Tunnelblick: OS X 10.12.6; Tunnelblick 3.7.5beta01 (build 4910); prior version 3.7.4 (build 4900); Admin user

Console Log:

2017-11-05 11:20:49 Tunnelblick[5028] BUG in libdispatch client: kevent[EVFILT_MACHPORT] monitored resource vanished before the source cancel handler was invoked

2017-11-05 11:26:25 Tunnelblick[5028] Keychain item retrieved successfully for service = 'Tunnelblick-Auth- lte...@87.xxx.xx.6’ account = 'username'

2017-11-05 11:26:25 Tunnelblick[5028] Keychain item retrieved successfully for service = 'Tunnelblick-Auth- lte...@87.xxx.xx.6’ account = 'password'

And that happens all the time after 30 secs of operation.

Can anybody tell me what's wrong here?

Thank You

Elmar

[Tunnelblick developer]

@elmar - Please follow the instructions at Read Before You Post to get the info needed to diagnose problems and then post that info.