VyprVPN - OpenVPN - external program exited with error status: 1

cpressland · Jun 18, 2012, 4:57 PM

Hey Guys,

I'm currently trying to setup VyprVPN to route my Usenet traffic to said VPN to prevent my ISP from throttling.

However, the SAB Server I have setup is unable to access the net after this, I've pulled some logs and can see:

Jun 18 16:56:06	openvpn[55078]: ERROR: FreeBSD route add command failed: external program exited with error status: 1

Which looks to me like a route isn't getting added correctly.

Log:

Jun 18 16:56:02	openvpn[54800]: pull = ENABLED
Jun 18 16:56:02	openvpn[54800]: auth_user_pass_file = '/cf/conf/vypr.pas'
Jun 18 16:56:02	openvpn[54800]: OpenVPN 2.2.0 amd64-portbld-freebsd8.1 [SSL] [LZO2] [eurephia] [MH] [PF_INET6] [IPv6 payload 20110424-2 (2.2RC2)] built on Aug 11 2011
Jun 18 16:56:02	openvpn[54800]: MANAGEMENT: unix domain socket listening on /var/etc/openvpn/client2.sock
Jun 18 16:56:02	openvpn[54800]: WARNING: file '/cf/conf/vypr.pas' is group or others accessible
Jun 18 16:56:02	openvpn[54800]: WARNING: Make sure you understand the semantics of --tls-remote before using it (see the man page).
Jun 18 16:56:02	openvpn[54800]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jun 18 16:56:02	openvpn[54800]: Initializing OpenSSL support for engine 'cryptodev'
Jun 18 16:56:02	openvpn[54800]: LZO compression initialized
Jun 18 16:56:02	openvpn[54800]: Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Jun 18 16:56:02	openvpn[54800]: Socket Buffers: R=[42080->65536] S=[57344->65536]
Jun 18 16:56:02	openvpn[54800]: Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Jun 18 16:56:02	openvpn[54800]: Local Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Jun 18 16:56:02	openvpn[54800]: Expected Remote Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Jun 18 16:56:02	openvpn[54800]: Local Options hash (VER=V4): '41690919'
Jun 18 16:56:02	openvpn[54800]: Expected Remote Options hash (VER=V4): '530fdded'
Jun 18 16:56:02	openvpn[55078]: UDPv4 link local (bound): [AF_INET]86.28.107.90:50011
Jun 18 16:56:02	openvpn[55078]: UDPv4 link remote: [AF_INET]138.199.67.149:1194
Jun 18 16:56:03	openvpn[55078]: TLS: Initial packet from [AF_INET]138.199.67.149:1194, sid=e235583f 9f6b7166
Jun 18 16:56:03	openvpn[55078]: WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Jun 18 16:56:03	openvpn[55078]: VERIFY OK: depth=1, /C=KY/ST=GrandCayman/L=GeorgeTown/O=GoldenFrog-Inc/CN=GoldenFrog-Inc_CA/emailAddress=admin@goldenfrog.com
Jun 18 16:56:03	openvpn[55078]: VERIFY X509NAME OK: /C=KY/ST=GrandCayman/L=GeorgeTown/O=GoldenFrog-Inc/CN=uk1.vpn.giganews.com/emailAddress=admin@goldenfrog.com
Jun 18 16:56:03	openvpn[55078]: VERIFY OK: depth=0, /C=KY/ST=GrandCayman/L=GeorgeTown/O=GoldenFrog-Inc/CN=uk1.vpn.giganews.com/emailAddress=admin@goldenfrog.com
Jun 18 16:56:03	openvpn[55078]: Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Jun 18 16:56:03	openvpn[55078]: Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Jun 18 16:56:03	openvpn[55078]: Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Jun 18 16:56:03	openvpn[55078]: Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Jun 18 16:56:03	openvpn[55078]: Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
Jun 18 16:56:03	openvpn[55078]: [uk1.vpn.giganews.com] Peer Connection Initiated with [AF_INET]138.199.67.149:1194
Jun 18 16:56:06	openvpn[55078]: SENT CONTROL [uk1.vpn.giganews.com]: 'PUSH_REQUEST' (status=1)
Jun 18 16:56:06	openvpn[55078]: PUSH: Received control message: 'PUSH_REPLY,redirect-gateway def1 bypass-dhcp,dhcp-option DNS 208.67.222.222,dhcp-option DNS 208.67.220.220,explicit-exit-notify 5,rcvbuf 262144,route-gateway 10.17.0.1,topology subnet,ping 10,ping-restart 60,ifconfig 10.17.0.50 255.255.0.0'
Jun 18 16:56:06	openvpn[55078]: OPTIONS IMPORT: timers and/or timeouts modified
Jun 18 16:56:06	openvpn[55078]: OPTIONS IMPORT: explicit notify parm(s) modified
Jun 18 16:56:06	openvpn[55078]: OPTIONS IMPORT: --sndbuf/--rcvbuf options modified
Jun 18 16:56:06	openvpn[55078]: Socket Buffers: R=[65536->262144] S=[65536->65536]
Jun 18 16:56:06	openvpn[55078]: OPTIONS IMPORT: --ifconfig/up options modified
Jun 18 16:56:06	openvpn[55078]: OPTIONS IMPORT: route options modified
Jun 18 16:56:06	openvpn[55078]: OPTIONS IMPORT: route-related options modified
Jun 18 16:56:06	openvpn[55078]: OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
Jun 18 16:56:06	openvpn[55078]: ROUTE default_gateway=86.28.104.1
Jun 18 16:56:06	openvpn[55078]: TUN/TAP device /dev/tun2 opened
Jun 18 16:56:06	openvpn[55078]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Jun 18 16:56:06	openvpn[55078]: /sbin/ifconfig ovpnc2 10.17.0.50 netmask 255.255.0.0 mtu 1500 up
Jun 18 16:56:06	openvpn[55078]: /sbin/route add -net 10.17.0.0 10.17.0.50 255.255.0.0
Jun 18 16:56:06	openvpn[55078]: ERROR: FreeBSD route add command failed: external program exited with error status: 1
Jun 18 16:56:06	openvpn[55078]: /usr/local/sbin/ovpn-linkup ovpnc2 1500 1542 10.17.0.50 255.255.0.0 init
Jun 18 16:56:06	openvpn[55078]: /sbin/route add -net 138.199.67.149 86.28.104.1 255.255.255.255
Jun 18 16:56:06	openvpn[55078]: /sbin/route add -net 0.0.0.0 10.17.0.1 128.0.0.0
Jun 18 16:56:06	openvpn[55078]: /sbin/route add -net 128.0.0.0 10.17.0.1 128.0.0.0
Jun 18 16:56:06	openvpn[55078]: Initialization Sequence Completed

Any ideas?

cpressland · Jun 18, 2012, 5:02 PM

Rule (currently disabled)

cpressland · Jun 18, 2012, 5:28 PM

ifconfig output:

em0: flags=8843 <up,broadcast,running,simplex,multicast>metric 0 mtu 1500
	options=9b <rxcsum,txcsum,vlan_mtu,vlan_hwtagging,vlan_hwcsum>ether 00:0c:29:9d:fd:db
	inet 10.0.1.1 netmask 0xffffff00 broadcast 10.0.1.255
	inet6 fe80::20c:29ff:fe9d:fddb%em0 prefixlen 64 scopeid 0x1 
	nd6 options=3 <performnud,accept_rtadv>media: Ethernet autoselect (1000baseT <full-duplex>)
	status: active
em1: flags=8843 <up,broadcast,running,simplex,multicast>metric 0 mtu 1500
	options=9b <rxcsum,txcsum,vlan_mtu,vlan_hwtagging,vlan_hwcsum>ether 00:0c:29:9d:fd:e5
	inet6 fe80::20c:29ff:fe9d:fde5%em1 prefixlen 64 scopeid 0x2 
	inet <snipped>netmask 0xfffffc00 broadcast 255.255.255.255
	nd6 options=3 <performnud,accept_rtadv>media: Ethernet autoselect (1000baseT <full-duplex>)
	status: active
plip0: flags=8810 <pointopoint,simplex,multicast>metric 0 mtu 1500
pflog0: flags=100 <promisc>metric 0 mtu 33664
pfsync0: flags=0<> metric 0 mtu 1460
	syncpeer: 224.0.0.240 maxupd: 128 syncok: 1
enc0: flags=0<> metric 0 mtu 1536
lo0: flags=8049 <up,loopback,running,multicast>metric 0 mtu 16384
	options=3 <rxcsum,txcsum>inet 127.0.0.1 netmask 0xff000000 
	inet6 ::1 prefixlen 128 
	inet6 fe80::1%lo0 prefixlen 64 scopeid 0x7 
	nd6 options=3 <performnud,accept_rtadv>ovpns1: flags=8051 <up,pointopoint,running,multicast>metric 0 mtu 1500
	options=80000 <linkstate>inet6 fe80::20c:29ff:fe9d:fddb%ovpns1 prefixlen 64 scopeid 0x8 
	inet 10.0.3.1 --> 10.0.3.2 netmask 0xffffffff 
	nd6 options=3 <performnud,accept_rtadv>Opened by PID 20739
ovpnc2: flags=8043 <up,broadcast,running,multicast>metric 0 mtu 1500
	options=80000 <linkstate>inet6 fe80::20c:29ff:fe9d:fddb%ovpnc2 prefixlen 64 scopeid 0x9 
	inet 10.17.0.50 netmask 0xffff0000 broadcast 10.17.255.255
	nd6 options=3 <performnud,accept_rtadv>Opened by PID 6924</performnud,accept_rtadv></linkstate></up,broadcast,running,multicast></performnud,accept_rtadv></linkstate></up,pointopoint,running,multicast></performnud,accept_rtadv></rxcsum,txcsum></up,loopback,running,multicast></promisc></pointopoint,simplex,multicast></full-duplex></performnud,accept_rtadv></snipped></rxcsum,txcsum,vlan_mtu,vlan_hwtagging,vlan_hwcsum></up,broadcast,running,simplex,multicast></full-duplex></performnud,accept_rtadv></rxcsum,txcsum,vlan_mtu,vlan_hwtagging,vlan_hwcsum></up,broadcast,running,simplex,multicast>

thermo · Jun 18, 2012, 10:04 PM

What is sab server?
Ignore the route add error as you need to enable manual outbound Nat.

cpressland · Jun 19, 2012, 12:45 PM

SAB Server = SabNZBd Server / Usenet Access

Manual Outbound NAT is enabled as follows:

I personally cannot see any issues there…

cpressland · Jun 19, 2012, 12:55 PM

How strange, I'm seeing this now…

openvpn[9870]: Authenticate/Decrypt packet error: packet HMAC authentication failed

cpressland · Jun 19, 2012, 1:16 PM

And:

Jun 19 13:12:50	openvpn[41217]: TUN/TAP device /dev/tun2 opened
Jun 19 13:12:50	openvpn[41217]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Jun 19 13:12:50	openvpn[41217]: /sbin/ifconfig ovpnc2 10.17.0.47 netmask 255.255.0.0 mtu 1500 up
Jun 19 13:12:50	openvpn[41217]: /sbin/route add -net 10.17.0.0 10.17.0.47 255.255.0.0
Jun 19 13:12:50	openvpn[41217]: ERROR: FreeBSD route add command failed: external program exited with error status: 1
Jun 19 13:12:50	openvpn[41217]: /usr/local/sbin/ovpn-linkup ovpnc2 1500 1542 10.17.0.47 255.255.0.0 init
Jun 19 13:12:50	openvpn[41217]: /sbin/route add -net 138.199.67.149 86.28.104.1 255.255.255.255
Jun 19 13:12:50	openvpn[41217]: /sbin/route add -net 0.0.0.0 10.17.0.1 128.0.0.0
Jun 19 13:12:50	openvpn[41217]: /sbin/route add -net 128.0.0.0 10.17.0.1 128.0.0.0
Jun 19 13:12:50	openvpn[41217]: Initialization Sequence Completed
Jun 19 13:13:57	openvpn[41217]: MANAGEMENT: Client connected from /var/etc/openvpn/client2.sock
Jun 19 13:13:57	openvpn[41217]: MANAGEMENT: CMD 'state 1'
Jun 19 13:13:57	openvpn[41217]: MANAGEMENT: CMD 'status 2'
Jun 19 13:13:57	openvpn[41217]: MANAGEMENT: Client disconnected
Jun 19 13:13:58	openvpn[41217]: MANAGEMENT: Client connected from /var/etc/openvpn/client2.sock
Jun 19 13:13:58	openvpn[41217]: MANAGEMENT: CMD 'state 1'
Jun 19 13:13:58	openvpn[41217]: MANAGEMENT: CMD 'status 2'
Jun 19 13:13:58	openvpn[41217]: MANAGEMENT: Client disconnected
Jun 19 13:13:59	openvpn[41217]: MANAGEMENT: Client connected from /var/etc/openvpn/client2.sock
Jun 19 13:13:59	openvpn[41217]: MANAGEMENT: CMD 'state 1'
Jun 19 13:13:59	openvpn[41217]: MANAGEMENT: CMD 'status 2'
Jun 19 13:13:59	openvpn[41217]: MANAGEMENT: Client disconnected
Jun 19 13:14:00	openvpn[41217]: MANAGEMENT: Client connected from /var/etc/openvpn/client2.sock
Jun 19 13:14:00	openvpn[41217]: MANAGEMENT: CMD 'state 1'
Jun 19 13:14:00	openvpn[41217]: MANAGEMENT: CMD 'status 2'
Jun 19 13:14:00	openvpn[41217]: MANAGEMENT: Client disconnected
Jun 19 13:14:01	openvpn[41217]: MANAGEMENT: Client connected from /var/etc/openvpn/client2.sock
Jun 19 13:14:01	openvpn[41217]: MANAGEMENT: CMD 'state 1'
Jun 19 13:14:01	openvpn[41217]: MANAGEMENT: CMD 'status 2'
Jun 19 13:14:01	openvpn[41217]: MANAGEMENT: Client disconnected
Jun 19 13:14:01	openvpn[41217]: MANAGEMENT: Client connected from /var/etc/openvpn/client2.sock
Jun 19 13:14:01	openvpn[41217]: MANAGEMENT: CMD 'state 1'
Jun 19 13:14:01	openvpn[41217]: MANAGEMENT: CMD 'status 2'
Jun 19 13:14:01	openvpn[41217]: MANAGEMENT: Client disconnected
Jun 19 13:14:14	openvpn[41217]: MANAGEMENT: Client connected from /var/etc/openvpn/client2.sock
Jun 19 13:14:14	openvpn[41217]: MANAGEMENT: CMD 'state 1'
Jun 19 13:14:14	openvpn[41217]: MANAGEMENT: CMD 'status 2'
Jun 19 13:14:14	openvpn[41217]: MANAGEMENT: Client disconnected
Jun 19 13:14:15	openvpn[41217]: MANAGEMENT: Client connected from /var/etc/openvpn/client2.sock
Jun 19 13:14:15	openvpn[41217]: MANAGEMENT: CMD 'state 1'
Jun 19 13:14:15	openvpn[41217]: MANAGEMENT: CMD 'status 2'
Jun 19 13:14:15	openvpn[41217]: MANAGEMENT: Client disconnected
Jun 19 13:14:16	openvpn[41217]: MANAGEMENT: Client connected from /var/etc/openvpn/client2.sock
Jun 19 13:14:16	openvpn[41217]: MANAGEMENT: CMD 'state 1'
Jun 19 13:14:16	openvpn[41217]: MANAGEMENT: CMD 'status 2'
Jun 19 13:14:16	openvpn[41217]: MANAGEMENT: Client disconnected
Jun 19 13:19:41	openvpn[41217]: MANAGEMENT: Client connected from /var/etc/openvpn/client2.sock
Jun 19 13:19:41	openvpn[41217]: MANAGEMENT: CMD 'state 1'
Jun 19 13:19:41	openvpn[41217]: MANAGEMENT: CMD 'status 2'
Jun 19 13:19:41	openvpn[41217]: MANAGEMENT: Client disconnected

I might just run OpenVPN on this specific server for the mean time