Can't connect because of kext

[eri...@clearskydata.com]

I'm on Sierra so I shouldn't have the High Sierra security issue and I've compared my kextstat with everyone else's at my company yet I still can't seem to figure this issue out and the reason from the logs is this:

May 24 17:53:41 erivas-macbook Tunnelblick[1763]: Sparkle: ===== Tunnelblick =====

May 24 17:53:41 erivas-macbook Tunnelblick[1763]: Sparkle: Verified appcast signature

May 24 17:53:54 erivas-macbook com.apple.xpc.launchd[1] (com.apple.quicklook[1785]): Endpoint has been activated through legacy launch(3) APIs. Please switch to XPC or bootstrap_check_in(): com.apple.quicklook

May 24 17:53:57 erivas-macbook Tunnelblick[1763]: runTunnelblickd: no data available from tunnelblickd socket; sleeping 5.000000 seconds...

May 24 17:53:58 erivas-macbook tunnelblickd[1776]: Status = 247 from tunnelblick-helper command 'start production.tblk 60608 769 0 1 0 1065265 -ptADGNWradsgnw 2.4.6-openssl-1.0.2o'

May 24 17:54:02 erivas-macbook Tunnelblick[1763]: tunnelblickd status from start: 247

May 24 17:54:02 erivas-macbook logd[77]: kext query: did not find the uuid

May 24 17:54:02 erivas-macbook logd[77]: #DECODE failed to resolved UUID: [pc:0xff7f83ce2949 ns:0x04 type:0x00 flags:0x0008 main:D3314D98-5D40-3CD8-98A4-F1DD46C20E03 pid:0]

May 24 17:54:02 erivas-macbook logd[77]: kext query: did not find the uuid

May 24 17:54:02 erivas-macbook logd[77]: #DECODE failed to resolved UUID: [pc:0xff7f83ce2949 ns:0x04 type:0x00 flags:0x0008 main:D3314D98-5D40-3CD8-98A4-F1DD46C20E03 pid:0]

May 24 17:54:02 erivas-macbook logd[77]: kext query: did not find the uuid

May 24 17:54:02 erivas-macbook logd[77]: #DECODE failed to resolved UUID: [pc:0xff7f83ce2949 ns:0x04 type:0x00 flags:0x0008 main:D3314D98-5D40-3CD8-98A4-F1DD46C20E03 pid:0]

May 24 17:54:02 erivas-macbook logd[77]: kext query: did not find the uuid

May 24 17:54:02 erivas-macbook logd[77]: #DECODE failed to resolved UUID: [pc:0xff7f83ce2949 ns:0x04 type:0x00 flags:0x0008 main:D3314D98-5D40-3CD8-98A4-F1DD46C20E03 pid:0]

May 24 17:54:02 erivas-macbook logd[77]: kext query: did not find the uuid

May 24 17:54:02 erivas-macbook logd[77]: #DECODE failed to resolved UUID: [pc:0xff7f83ce2949 ns:0x04 type:0x00 flags:0x0008 main:D3314D98-5D40-3CD8-98A4-F1DD46C20E03 pid:0]

May 24 17:54:02 erivas-macbook logd[77]: kext query: did not find the uuid

May 24 17:54:02 erivas-macbook logd[77]: #DECODE failed to resolved UUID: [pc:0xff7f83cd9949 ns:0x04 type:0x00 flags:0x0008 main:D3314D98-5D40-3CD8-98A4-F1DD46C20E03 pid:0]

May 24 17:54:02 erivas-macbook logd[77]: kext query: did not find the uuid

May 24 17:54:02 erivas-macbook logd[77]: #DECODE failed to resolved UUID: [pc:0xff7f83cd9949 ns:0x04 type:0x00 flags:0x0008 main:D3314D98-5D40-3CD8-98A4-F1DD46C20E03 pid:0]

May 24 17:54:02 erivas-macbook logd[77]: kext query: did not find the uuid

May 24 17:54:02 erivas-macbook logd[77]: #DECODE failed to resolved UUID: [pc:0xff7f83cd9949 ns:0x04 type:0x00 flags:0x0008 main:D3314D98-5D40-3CD8-98A4-F1DD46C20E03 pid:0]

May 24 17:54:02 erivas-macbook logd[77]: kext query: did not find the uuid

May 24 17:54:02 erivas-macbook logd[77]: #DECODE failed to resolved UUID: [pc:0xff7f83cd9949 ns:0x04 type:0x00 flags:0x0008 main:D3314D98-5D40-3CD8-98A4-F1DD46C20E03 pid:0]

May 24 17:54:02 erivas-macbook logd[77]: kext query: did not find the uuid

May 24 17:54:02 erivas-macbook logd[77]: #DECODE failed to resolved UUID: [pc:0xff7f83cd9949 ns:0x04 type:0x00 flags:0x0008 main:D3314D98-5D40-3CD8-98A4-F1DD46C20E03 pid:0]

May 24 17:55:18 erivas-macbook Tunnelblick[1763]: runTunnelblickd: no data available from tunnelblickd socket; sleeping 5.000000 seconds...

May 24 17:55:19 erivas-macbook tunnelblickd[1802]: Status = 247 from tunnelblick-helper command 'start production.tblk 63427 769 0 1 0 1065265 -ptADGNWradsgnw 2.4.6-openssl-1.0.2o'

May 24 17:55:23 erivas-macbook Tunnelblick[1763]: tunnelblickd status from start: 247

Oddly enough, the connection works ONCE after a reboot and then fails subsequently from there. cat'ing kextstat before the first connection and after shows no significant changes.

Can anybody help me please? This is driving me insane.

[eri...@clearskydata.com]

Follow-up: it seems that the net.tunnelblick.tun kext is loaded the first time I try the connection, but subsequent ones fail. When I try kextload manually, I get the error /Applications/Tunnelblick.app/Contents/Resources/tun-signed.kext failed to load - (libkern/kext) kext (kmod) start/stop routine failed; check the system/kernel logs for errors or try kextutil(8). which then spits out all the error text from the original post in the system log.

[Tunnelblick developer]

It's not clear (since you didn't post the diagnostic info from Before You Post). but assuming you have a "dev-type tun" line in your configuration, remove it so Tunnelblick can use the system's built-in tun driver (utun).

If that doesn't, help, please post the diagnostic info.

[eri...@clearskydata.com]

Here's the diagnostic information:

*Tunnelblick: OS X 10.12.6; Tunnelblick 3.7.6beta04 (build 5050); prior version 3.7.5a (build 5011); Admin user

git commit 1417c1a1c5bd33c34277585f02de388622192e72

Configuration production

"Sanitized" condensed configuration file for /Users/erivas/Library/Application Support/Tunnelblick/Configurations/production.tblk:

[Lines that appear to be security-related have been omitted]

setenv FORWARD_COMPATIBLE 1

client

server-poll-timeout 4

nobind

remote 52.3.203.95 1194 udp

remote 52.3.203.95 1194 udp

remote 52.3.203.95 443 tcp

remote 52.3.203.95 1194 udp

remote 52.3.203.95 1194 udp

remote 52.3.203.95 1194 udp

remote 52.3.203.95 1194 udp

remote 52.3.203.95 1194 udp

dev tun

dev-type tun

ns-cert-type server

reneg-sec 604800

sndbuf 100000

rcvbuf 100000

auth-user-pass

comp-lzo no

verb 3

setenv PUSH_PEER_INFO

<ca>

[Security-related line(s) omitted]

</ca>

<cert>

[Security-related line(s) omitted]

</cert>

<key>

[Security-related line(s) omitted]

</key>

key-direction 1

<tls-auth>

[Security-related line(s) omitted]

</tls-auth>

[Lines that appear to be security-related have been omitted]

[Lines that appear to be security-related have been omitted]

[Lines that appear to be security-related have been omitted]

================================================================================

Non-Apple kexts that are loaded:

Index Refs Address            Size       Wired      Name (Version) UUID <Linked Against>

   15    0 0xffffff7f80a89000 0x8000     0x8000     com.sophos.driver.devctrl (9.7.4) 7CB58D78-DA57-3E8C-B2EC-EFA16E1AF05B <14 5 4 3 1>

  160    3 0xffffff7f83a6b000 0x63000    0x63000    org.virtualbox.kext.VBoxDrv (5.2.0) E1869433-3D2C-386E-92C5-AED4D37C58A5 <7 5 4 3 1>

  161    0 0xffffff7f83ace000 0x14000    0x14000    com.intel.kext.intelhaxm (6.0.1) 8FF2C637-0A5E-367E-B007-5B08655B1E8A <7 5 4 3 1>

  164    0 0xffffff7f83ae2000 0x8000     0x8000     org.virtualbox.kext.VBoxUSB (5.2.0) EA012F83-83D1-3425-BC8D-23EF33CBC2AD <163 160 42 7 5 4 3 1>

  165    0 0xffffff7f83aea000 0x5000     0x5000     org.virtualbox.kext.VBoxNetFlt (5.2.0) 5D36AD04-952F-37BA-8CD0-2B53394887C2 <160 7 5 4 3 1>

  166    0 0xffffff7f83aef000 0x6000     0x6000     org.virtualbox.kext.VBoxNetAdp (5.2.0) ED4AAFA9-EC34-38A6-B695-2853B5043084 <160 5 4 1>

  170    0 0xffffff7f80a18000 0x7000     0x7000     com.sophos.nke.swi (9.7.4) AFB9B66E-C67A-32D1-A8A8-654F475EECFC <4 1>

  173    0 0xffffff7f80aad000 0x8000     0x8000     com.sophos.kext.sfm (9.7.4) 47394905-E2D3-3643-804D-D278B1BF74FB <5 4 2 1>

  188    0 0xffffff7f83b04000 0x8000     0x8000     com.sophos.kext.oas (9.7.4) FE151087-F3B0-3F51-BD15-3313B8BCDDAB <5 4 2 1>

================================================================================

There are no unusual files in production.tblk

================================================================================

Configuration preferences:

-skipWarningThatMayNotConnectInFutureBecauseOfOpenVPNOptions = 1

-notOKToCheckThatIPAddressDidNotChangeAfterConnection = 1

-lastConnectionSucceeded = 0

================================================================================

Wildcard preferences:

-notOKToCheckThatIPAddressDidNotChangeAfterConnection = 1

================================================================================

Program preferences:

launchAtNextLogin = 1

notOKToCheckThatIPAddressDidNotChangeAfterConnection = 1

tunnelblickVersionHistory = (

    "3.7.6beta04 (build 5050)",

    "3.7.5a (build 5011)",

    "3.7.6beta04 (build 5050)",

    "3.7.5a (build 5011)",

    "3.7.4b (build 4921)",

    "3.7.1a (build 4812)",

    "3.7.1 (build 4811)"

)

statusDisplayNumber = 0

lastLaunchTime = 548892115.633582

lastLanguageAtLaunchWasRTL = 0

connectionWindowDisplayCriteria = showWhenConnecting

maxLogDisplaySize = 102400

lastConnectedDisplayName = production

keyboardShortcutIndex = 1

updateCheckAutomatically = 1

updateCheckBetas = 1

NSWindow Frame ConnectingWindow = 514 436 412 297 0 0 1440 877 

NSWindow Frame SUUpdateAlert = 410 364 620 392 0 0 1440 877 

detailsWindowFrameVersion = 5050

detailsWindowFrame = {{260, 307}, {920, 468}}

detailsWindowLeftFrame = {{0, 0}, {165, 350}}

detailsWindowViewIndex = 0

detailsWindowConfigurationsTabIdentifier = log

leftNavSelectedDisplayName = production

AdvancedWindowTabIdentifier = connectingAndDisconnecting

haveDealtWithOldTunTapPreferences = 1

haveDealtWithOldLoginItem = 1

haveDealtWithAfterDisconnect = 1

SUEnableAutomaticChecks = 1

SUScheduledCheckInterval = 86400

SUSendProfileInfo = 1

SULastCheckTime = 2018-05-24 22:01:55 +0000

SULastProfileSubmissionDate = 2018-05-24 15:10:12 +0000

SUHasLaunchedBefore = 1

WebKitDefaultFontSize = 16

WebKitStandardFont = Times

askedUserIfOKToCheckThatIPAddressDidNotChangeAfterConnection = 1

haveDealtWithSparkle1dot5b6 = 1

updateSendProfileInfo = 1

================================================================================

Tunnelblick Log:

*Tunnelblick: OS X 10.12.6; Tunnelblick 3.7.6beta04 (build 5050); prior version 3.7.5a (build 5011)

2018-05-25 11:27:46 *Tunnelblick: Attempting connection with production using shadow copy; Set nameserver = 769; monitoring connection

2018-05-25 11:27:46 *Tunnelblick: openvpnstart start production.tblk 53236 769 0 1 0 1065265 -ptADGNWradsgnw 2.4.6-openssl-1.0.2o

2018-05-25 11:27:56 *Tunnelblick: 

Could not start OpenVPN (openvpnstart returned with status #247)

Contents of the openvpnstart log:

*Tunnelblick: openvpnstart log:

     Loading tun-signed.kext

     stderr from kextload: /Applications/Tunnelblick.app/Contents/Resources/tun-signed.kext failed to load - (libkern/kext) kext (kmod) start/stop routine failed; check the system/kernel logs for errors or try kextutil(8).

     stderr from kextload: /Applications/Tunnelblick.app/Contents/Resources/tun-signed.kext failed to load - (libkern/kext) kext (kmod) start/stop routine failed; check the system/kernel logs for errors or try kextutil(8).

     stderr from kextload: /Applications/Tunnelblick.app/Contents/Resources/tun-signed.kext failed to load - (libkern/kext) kext (kmod) start/stop routine failed; check the system/kernel logs for errors or try kextutil(8).

     stderr from kextload: /Applications/Tunnelblick.app/Contents/Resources/tun-signed.kext failed to load - (libkern/kext) kext (kmod) start/stop routine failed; check the system/kernel logs for errors or try kextutil(8).

     stderr from kextload: /Applications/Tunnelblick.app/Contents/Resources/tun-signed.kext failed to load - (libkern/kext) kext (kmod) start/stop routine failed; check the system/kernel logs for errors or try kextutil(8).

     Unable to load net.tunnelblick.tun and/or net.tunnelblick.tap kexts in 5 tries. Status = 71

2018-05-25 11:27:46 *Tunnelblick: openvpnstart starting OpenVPN

================================================================================

"Sanitized" full configuration file

# Automatically generated OpenVPN client config file

# Generated on Thu May 24 18:25:55 2018 by ops-vpn01.aws.csdops.net

# Note: this config file contains inline private keys

#       and therefore should be kept confidential!

# Note: this configuration is user-locked to the username below

# OVPN_ACCESS_SERVER_USERNAME=erivas

# Define the profile name of this particular configuration file

# OVPN_ACCESS_SERVER_PROFILE=eri...@52.3.203.95

# OVPN_ACCESS_SERVER_CLI_PREF_ALLOW_WEB_IMPORT=True

# OVPN_ACCESS_SERVER_CLI_PREF_ENABLE_CONNECT=True

# OVPN_ACCESS_SERVER_CLI_PREF_ENABLE_XD_PROXY=True

# OVPN_ACCESS_SERVER_WSHOST=52.3.203.95:443

# OVPN_ACCESS_SERVER_WEB_CA_BUNDLE_START

# -----BEGIN CERTIFICATE-----

 [Lines that appear to be security-related have been omitted]

# -----END CERTIFICATE-----

# OVPN_ACCESS_SERVER_WEB_CA_BUNDLE_STOP

# OVPN_ACCESS_SERVER_IS_OPENVPN_WEB_CA=1

# OVPN_ACCESS_SERVER_ORGANIZATION=OpenVPN Technologies, Inc.

setenv FORWARD_COMPATIBLE 1

client

server-poll-timeout 4

nobind

remote 52.3.203.95 1194 udp

remote 52.3.203.95 1194 udp

remote 52.3.203.95 443 tcp

remote 52.3.203.95 1194 udp

remote 52.3.203.95 1194 udp

remote 52.3.203.95 1194 udp

remote 52.3.203.95 1194 udp

remote 52.3.203.95 1194 udp

dev tun

dev-type tun

ns-cert-type server

reneg-sec 604800

sndbuf 100000

rcvbuf 100000

auth-user-pass

# NOTE: LZO commands are pushed by the Access Server at connect time.

# NOTE: The below line doesn't disable LZO.

comp-lzo no

verb 3

setenv PUSH_PEER_INFO

<ca>

 [Security-related line(s) omitted]

</ca>

<cert>

 [Security-related line(s) omitted]

</cert>

<key>

 [Security-related line(s) omitted]

</key>

key-direction 1

<tls-auth>

 [Security-related line(s) omitted]

</tls-auth>

## -----BEGIN RSA SIGNATURE-----

 [Lines that appear to be security-related have been omitted]

## -----END RSA SIGNATURE-----

## -----BEGIN CERTIFICATE-----

 [Lines that appear to be security-related have been omitted]

## -----END CERTIFICATE-----

## -----BEGIN CERTIFICATE-----

 [Lines that appear to be security-related have been omitted]

## -----END CERTIFICATE-----

================================================================================

ifconfig output:

lo0: flags=8049<UP,LOOPBACK,RUNNING,MULTICAST> mtu 16384

options=1203<RXCSUM,TXCSUM,TXSTATUS,SW_TIMESTAMP>

inet 127.0.0.1 netmask 0xff000000 

inet6 ::1 prefixlen 128 

inet6 fe80::1%lo0 prefixlen 64 scopeid 0x1 

inet 127.94.0.1 netmask 0xff000000 

nd6 options=201<PERFORMNUD,DAD>

gif0: flags=8010<POINTOPOINT,MULTICAST> mtu 1280

stf0: flags=0<> mtu 1280

en0: flags=8863<UP,BROADCAST,SMART,RUNNING,SIMPLEX,MULTICAST> mtu 1500

ether 3c:15:c2:e7:2d:66 

inet6 fe80::1c5f:994b:cac8:fb49%en0 prefixlen 64 secured scopeid 0x4 

inet 10.2.1.185 netmask 0xffffff00 broadcast 10.2.1.255

nd6 options=201<PERFORMNUD,DAD>

media: autoselect

status: active

en1: flags=963<UP,BROADCAST,SMART,RUNNING,PROMISC,SIMPLEX> mtu 1500

options=60<TSO4,TSO6>

ether 72:00:04:46:2a:70 

media: autoselect <full-duplex>

status: inactive

en2: flags=963<UP,BROADCAST,SMART,RUNNING,PROMISC,SIMPLEX> mtu 1500

options=60<TSO4,TSO6>

ether 72:00:04:46:2a:71 

media: autoselect <full-duplex>

status: inactive

p2p0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> mtu 2304

ether 0e:15:c2:e7:2d:66 

media: autoselect

status: inactive

awdl0: flags=8943<UP,BROADCAST,RUNNING,PROMISC,SIMPLEX,MULTICAST> mtu 1484

ether 4e:77:e9:08:16:17 

inet6 fe80::4c77:e9ff:fe08:1617%awdl0 prefixlen 64 scopeid 0xa 

nd6 options=201<PERFORMNUD,DAD>

media: autoselect

status: active

bridge0: flags=8863<UP,BROADCAST,SMART,RUNNING,SIMPLEX,MULTICAST> mtu 1500

options=63<RXCSUM,TXCSUM,TSO4,TSO6>

ether 72:00:04:46:2a:70 

Configuration:

id 0:0:0:0:0:0 priority 0 hellotime 0 fwddelay 0

maxage 0 holdcnt 0 proto stp maxaddr 100 timeout 1200

root id 0:0:0:0:0:0 priority 0 ifcost 0 port 0

ipfilter disabled flags 0x2

member: en1 flags=3<LEARNING,DISCOVER>

        ifmaxaddr 0 port 5 priority 0 path cost 0

member: en2 flags=3<LEARNING,DISCOVER>

        ifmaxaddr 0 port 6 priority 0 path cost 0

nd6 options=201<PERFORMNUD,DAD>

media: <unknown type>

status: inactive

utun0: flags=8051<UP,POINTOPOINT,RUNNING,MULTICAST> mtu 2000

inet6 fe80::fcf0:4fb6:7305:b602%utun0 prefixlen 64 scopeid 0xe 

nd6 options=201<PERFORMNUD,DAD>

fw4: flags=8863<UP,BROADCAST,SMART,RUNNING,SIMPLEX,MULTICAST> mtu 4078

lladdr 00:0a:27:02:00:6a:c8:af 

nd6 options=201<PERFORMNUD,DAD>

media: autoselect <full-duplex>

status: inactive

fw0: flags=8863<UP,BROADCAST,SMART,RUNNING,SIMPLEX,MULTICAST> mtu 4078

lladdr 00:0a:27:02:00:5c:07:75 

nd6 options=201<PERFORMNUD,DAD>

media: autoselect <full-duplex>

status: inactive

en4: flags=8863<UP,BROADCAST,SMART,RUNNING,SIMPLEX,MULTICAST> mtu 1500

options=10b<RXCSUM,TXCSUM,VLAN_HWTAGGING,AV>

ether 0c:4d:e9:a0:f8:e7 

nd6 options=201<PERFORMNUD,DAD>

media: autoselect (none)

status: inactive

en10: flags=8863<UP,BROADCAST,SMART,RUNNING,SIMPLEX,MULTICAST> mtu 1500

options=10b<RXCSUM,TXCSUM,VLAN_HWTAGGING,AV>

ether 38:c9:86:30:4d:0a 

nd6 options=201<PERFORMNUD,DAD>

media: autoselect (none)

status: inactive

================================================================================

Console Log:

2018-05-25 11:27:51 Tunnelblick[502] runTunnelblickd: no data available from tunnelblickd socket; sleeping 5.000000 seconds...

2018-05-25 11:27:53 tunnelblickd[2077] Status = 247 from tunnelblick-helper command 'start production.tblk 53236 769 0 1 0 1065265 -ptADGNWradsgnw 2.4.6-openssl-1.0.2o'

2018-05-25 11:27:56 Tunnelblick[502] tunnelblickd status from start: 247

Additionally, this pop-up came up, although it seems odd to me I'm getting a deprecation warning using the same connection profile as everyone else.

On Thursday, May 24, 2018 at 6:01:33 PM UTC-4, Eddie Rivas wrote:

[Tunnelblick developer]

As I wrote earlier, remove the "dev-type tun" line, or comment it out by prefixing it with a semicolon character (";").

As to why you get the deprecated warning when nobody else at your organization does, perhaps they are not running a version of Tunnelblick that includes that warning. Or perhaps they are not using OpenVPN 2.4 (your version of Tunnelblick defaults to use it).

# OVPN_ACCESS_SERVER_PROFILE=eriv...@52.3.203.95

[eri...@clearskydata.com]

Getting rid of the dev-tun on the configuration worked, thank you so much! I'll have to go find out if I'm the only one with that in the configuration.

[eri...@clearskydata.com]

I looked around at others' VPN profiles and they also have the dev-type tun in their configurations. I don't know if this is out of the scope of support, but do you have an explanation as to why this didn't work for me and did for them, or how the dev-type tun disrupts the built in system tunnel? Alternatively, a resource on the matter would also help. And if not, it's okay, I would just like to make sure this isn't going to become an issue for us. I should say that I am in no way familiar with VPN tunneling or OpenSSL tunneling so if this would become obvious by doing a little research there, I will do that.

Thanks again!

[Tunnelblick developer]

The "dev-type tun" option forces OpenVPN to use a "tun" device driver instead of the built-into-macOS "utun" driver. Since macOS doesn't include a "tun" device driver, Tunnelblick must load its own, but Tunnelblick is unable to load its tun driver on your system. I suspect Sophos is interfering, but in your situation I don't think it's worth investigating.

In my opinion it is better to use the Apple-provided utun driver. Presumably Apple will keep it working on future versions of macOS, and if your colleagues update to a some future version of macOS that breaks Tunnelblick's "tun" kexts, they might not be able to connect unless they also update to a version of Tunnelblick that supports that new version of macOS.

[eri...@clearskydata.com]

Excellent, thanks so much again for the help. I'll be sure to discuss this with our sys admins and pass your message along.

Have a good one! :)