[SOLVED] OpenVPN: Client, Status Up, do not pass data

Started by rost, September 02, 2015, 01:55:24 PM

Previous topic - Next topic
Print
Go Down Pages1
User actions
September 02, 2015, 01:55:24 PM Last Edit: September 04, 2015, 06:18:20 PM by AdSchellevis
Help please understand what the problem is?
Configure OpenVPN: Client
When Tunnel Status Up, ping works the first few seconds and traceroute work the first few seconds then stop work. But Tunnel Status stay Up.
Code Select
1    <1 мс    <1 мс    <1 мс  gw [192.168.1.1]
  2    46 ms     *       46 ms  192.168.100.1
  3    48 ms    47 ms    47 ms  192.168.11.203

Code Select
192.168.1.0/24 link#1 U 409007999 1500 em0
192.168.1.1 link#1 UHS 0 16384 lo0
192.168.11.0/24 192.168.100.1 UGS 34 1500 ovpnc1
192.168.100.0/24 link#7 U 0 1500 ovpnc1
192.168.100.4 link#7 UHS 0 16384 lo0
September 02, 2015, 02:32:54 PM #1
Just to be sure, have you setup any firewall rules on the vpn interface?
September 02, 2015, 03:02:36 PM #2
Firewall: Rules  tab OpenVPN
IPv4 *   *   *   *   *   *   none        (any any any)
September 02, 2015, 03:20:57 PM #3
restart tunnel
5 sec ping ok then stop
Code Select
16:18:51.545298 IP 192.168.11.203 > 192.168.1.201: ICMP echo reply, id 4624, seq 10, length 64
16:18:52.475740 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 11, length 64
16:18:52.544891 IP 192.168.11.203 > 192.168.1.201: ICMP echo reply, id 4624, seq 11, length 64
16:18:53.477135 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 12, length 64
16:18:53.534857 IP 192.168.11.203 > 192.168.1.201: ICMP echo reply, id 4624, seq 12, length 64
16:18:54.477935 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 13, length 64
16:18:54.548026 IP 192.168.11.203 > 192.168.1.201: ICMP echo reply, id 4624, seq 13, length 64
16:18:55.479261 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 14, length 64
16:18:55.556716 IP 192.168.11.203 > 192.168.1.201: ICMP echo reply, id 4624, seq 14, length 64
16:18:56.480209 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 15, length 64
16:18:56.548472 IP 192.168.11.203 > 192.168.1.201: ICMP echo reply, id 4624, seq 15, length 64
16:18:57.482132 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 16, length 64
16:18:57.549698 IP 192.168.11.203 > 192.168.1.201: ICMP echo reply, id 4624, seq 16, length 64
16:18:58.483375 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 17, length 64
16:18:58.549833 IP 192.168.11.203 > 192.168.1.201: ICMP echo reply, id 4624, seq 17, length 64
16:18:59.485467 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 18, length 64
16:18:59.540277 IP 192.168.11.203 > 192.168.1.201: ICMP echo reply, id 4624, seq 18, length 64
16:19:00.486975 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 19, length 64
16:19:01.494607 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 20, length 64
16:19:02.502478 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 21, length 64
16:19:03.510620 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 22, length 64
16:19:04.518497 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 23, length 64
16:19:05.526296 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 24, length 64
16:19:06.534480 IP 192.168.1.201 > 192.168.11.203: ICMP echo request, id 4624, seq 25, length 64
September 02, 2015, 03:27:09 PM #4
maybe you can tail the log on your machine too see if something happens in those few seconds, starting with system.log:

Code Select

clog -f /var/log/system.log

September 02, 2015, 03:37:55 PM #5
Code Select
Sep  2 16:31:21 host kernel: ovpnc1: link state changed to DOWN
Sep  2 16:31:21 host devd: Executing '/usr/local/opnsense/service/configd_ctl.py interface linkup stop ovpnc1'
Sep  2 16:31:21 host configd.py: [1271be97-b1cf-40c3-945b-1945c5ed560a] Linkup stopping ovpnc1
Sep  2 16:31:21 host configd.py: [45e2bf8f-17c5-4a9e-a115-3157dfe8ebac] Reloading filter
Sep  2 16:31:22 host opnsense: /usr/local/etc/rc.linkup: Hotplug event detected for MSKVPN(opt1) but ignoring since interface is configured with static IP ( )
Sep  2 16:31:22 host configd.py: [2d801076-ca34-4802-88c3-b5420316182a] Reloading filter
Sep  2 16:31:46 host kernel: ovpnc1: link state changed to UP
Sep  2 16:31:46 host devd: Executing '/usr/local/opnsense/service/configd_ctl.py interface linkup start ovpnc1'
Sep  2 16:31:46 host configd.py: [60b2100d-1aa2-4bdb-b4f3-02168b1c18ed] Linkup starting ovpnc1
Sep  2 16:31:46 host configd.py: [5a6730c7-88ac-4f84-9ca4-8bea6d89ad2b] rc.newwanip starting ovpnc1
Sep  2 16:31:46 host opnsense: /usr/local/etc/rc.linkup: Hotplug event detected for MSKVPN(opt1) but ignoring since interface is configured with static IP ( )
Sep  2 16:31:46 host opnsense: /usr/local/etc/rc.newwanip: rc.newwanip: Informational is starting ovpnc1.
Sep  2 16:31:46 host opnsense: /usr/local/etc/rc.newwanip: rc.newwanip: on (IP address: 192.168.100.4) (interface: MSKVPN[opt1]) (real interface: ovpnc1).
Sep  2 16:31:46 host opnsense: /usr/local/etc/rc.newwanip: Creating rrd update script
Sep  2 16:31:48 host configd.py: [f2414d2f-a7be-4fa3-a57f-cc6670ea58e7] Reloading filter
then ping ok
ok
ok
ok
then stop but no new log in system.log
September 02, 2015, 03:42:29 PM #6
and "Enable authentication of TLS packets." always enabled when i try to edit OpenVPN: Client config
September 02, 2015, 03:48:52 PM #7
Maybe retry same test and tail the openvpn log?

Code Select

clog -f /var/log/openvpn.log


September 02, 2015, 03:49:16 PM #8
Code Select
Sep  2 16:43:55 host openvpn[24390]: TUN/TAP device /dev/tap1 opened
Sep  2 16:43:55 host openvpn[24390]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Sep  2 16:43:55 host openvpn[24390]: /sbin/ifconfig ovpnc1 192.168.100.4 netmask 255.255.255.0 mtu 1500 up
Sep  2 16:43:55 host openvpn[24390]: /usr/local/sbin/ovpn-linkup ovpnc1 1500 1574 192.168.100.4 255.255.255.0 init
Sep  2 16:43:58 host openvpn[24390]: /sbin/route add -net 192.168.11.0 192.168.100.1 255.255.255.0
Sep  2 16:43:58 host openvpn[24390]: Initialization Sequence Completed
Sep  2 16:43:58 host openvpn[24390]: UDPv4 WRITE [22] to [AF_INET]194.x.x.x:1194: P_ACK_V1 kid=0 [ 32 ]
Sep  2 16:43:58 host openvpn[24390]: UDPv4 READ [77] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=76
Sep  2 16:43:58 host openvpn[24390]: TUN WRITE [42]
Sep  2 16:43:58 host openvpn[24390]: UDPv4 READ [77] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=76
Sep  2 16:43:58 host openvpn[24390]: TUN WRITE [42]
Sep  2 16:43:58 host openvpn[24390]: UDPv4 READ [77] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=76
Sep  2 16:43:58 host openvpn[24390]: TUN WRITE [42]
Sep  2 16:43:58 host openvpn[24390]: UDPv4 READ [77] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=76
Sep  2 16:43:58 host openvpn[24390]: TUN WRITE [42]
Sep  2 16:43:58 host openvpn[24390]: UDPv4 READ [20] from [AF_INET]194.x.x.x:1194: P_CONTROL_V1 kid=0 [ ] pid=32 DATA len=6
Sep  2 16:43:58 host openvpn[24390]: UDPv4 WRITE [22] to [AF_INET]194.x.x.x:1194: P_ACK_V1 kid=0 [ 32 ]
Sep  2 16:43:58 host openvpn[24390]: TUN READ [42]
Sep  2 16:43:58 host openvpn[24390]: UDPv4 WRITE [77] to [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=76
Sep  2 16:43:58 host openvpn[24390]: UDPv4 READ [93] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=92
Sep  2 16:43:58 host openvpn[24390]: TUN WRITE [58]
Sep  2 16:43:59 host openvpn[24390]: UDPv4 READ [93] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=92
Sep  2 16:43:59 host openvpn[24390]: TUN WRITE [58]
Sep  2 16:44:03 host openvpn[24390]: UDPv4 READ [77] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=76
Sep  2 16:44:03 host openvpn[24390]: TUN WRITE [42]
Sep  2 16:44:03 host openvpn[24390]: TUN READ [42]
Sep  2 16:44:03 host openvpn[24390]: UDPv4 WRITE [77] to [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=76
Sep  2 16:44:10 host openvpn[24390]: UDPv4 READ [397] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=396
Sep  2 16:44:10 host openvpn[24390]: TUN WRITE [399]
Sep  2 16:44:11 host openvpn[24390]: UDPv4 READ [101] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=100
Sep  2 16:44:11 host openvpn[24390]: UDPv4 WRITE [53] to [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
Sep  2 16:44:11 host openvpn[24390]: TUN WRITE [66]
Sep  2 16:44:11 host openvpn[24390]: UDPv4 READ [397] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=396
Sep  2 16:44:11 host openvpn[24390]: TUN WRITE [399]
Sep  2 16:44:12 host openvpn[24390]: UDPv4 READ [397] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=396
Sep  2 16:44:12 host openvpn[24390]: TUN WRITE [399]
Sep  2 16:44:13 host openvpn[24390]: UDPv4 READ [101] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=100
Sep  2 16:44:13 host openvpn[24390]: TUN WRITE [65]
Sep  2 16:44:14 host openvpn[24390]: UDPv4 READ [101] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=100
Sep  2 16:44:14 host openvpn[24390]: TUN WRITE [66]
Sep  2 16:44:15 host openvpn[24390]: UDPv4 READ [397] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=396
Sep  2 16:44:15 host openvpn[24390]: TUN WRITE [399]
Sep  2 16:44:17 host openvpn[24390]: UDPv4 READ [189] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=188
Sep  2 16:44:17 host openvpn[24390]: TUN WRITE [154]
Sep  2 16:44:19 host openvpn[24390]: UDPv4 READ [93] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=92
Sep  2 16:44:19 host openvpn[24390]: UDPv4 WRITE [53] to [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
Sep  2 16:44:19 host openvpn[24390]: TUN WRITE [58]
Sep  2 16:44:19 host openvpn[24390]: UDPv4 READ [397] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=396
Sep  2 16:44:19 host openvpn[24390]: TUN WRITE [399]
Sep  2 16:44:19 host openvpn[24390]: UDPv4 READ [237] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=236
Sep  2 16:44:30 host openvpn[24390]: TUN WRITE [86]
Sep  2 16:44:30 host openvpn[24390]: UDPv4 READ [125] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=124
Sep  2 16:44:30 host openvpn[24390]: TUN WRITE [86]
Sep  2 16:44:30 host openvpn[24390]: UDPv4 READ [125] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=124
Sep  2 16:44:30 host openvpn[24390]: TUN WRITE [86]
Sep  2 16:44:30 host openvpn[24390]: UDPv4 READ [93] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=92
Sep  2 16:44:30 host openvpn[24390]: TUN WRITE [58]
Sep  2 16:44:30 host openvpn[24390]: UDPv4 READ [101] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=100
Sep  2 16:44:30 host openvpn[24390]: TUN WRITE [62]
Sep  2 16:44:30 host openvpn[24390]: UDPv4 READ [117] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=116
Sep  2 16:44:30 host openvpn[24390]: TUN WRITE [78]
Sep  2 16:44:30 host openvpn[24390]: UDPv4 READ [93] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=92
Sep  2 16:44:30 host openvpn[24390]: TUN WRITE [58]
Sep  2 16:44:30 host openvpn[24390]: UDPv4 READ [117] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=116
Sep  2 16:44:30 host openvpn[24390]: TUN WRITE [78]
Sep  2 16:44:30 host openvpn[24390]: UDPv4 READ [125] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=124
Sep  2 16:44:30 host openvpn[24390]: TUN WRITE [86]
Sep  2 16:44:30 host openvpn[24390]: UDPv4 READ [125] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=124
Sep  2 16:44:30 host openvpn[24390]: TUN WRITE [86]
Sep  2 16:44:30 host openvpn[24390]: UDPv4 READ [125] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=124
Sep  2 16:44:30 host openvpn[24390]: TUN WRITE [86]
Sep  2 16:44:31 host openvpn[24390]: UDPv4 READ [141] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=140
Sep  2 16:44:31 host openvpn[24390]: TUN WRITE [120]
Sep  2 16:44:31 host openvpn[24390]: UDPv4 READ [93] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=92
Sep  2 16:44:31 host openvpn[24390]: TUN WRITE [55]
Sep  2 16:44:31 host openvpn[24390]: UDPv4 READ [117] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=116
Sep  2 16:44:31 host openvpn[24390]: TUN WRITE [78]
Sep  2 16:44:36 host openvpn[24390]: UDPv4 WRITE [53] to [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
Sep  2 16:44:39 host openvpn[24390]: UDPv4 READ [53] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
Sep  2 16:44:44 host openvpn[24390]: UDPv4 WRITE [53] to [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
Sep  2 16:44:47 host openvpn[24390]: UDPv4 READ [53] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
Sep  2 16:44:52 host openvpn[24390]: UDPv4 WRITE [53] to [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
Sep  2 16:44:55 host openvpn[24390]: UDPv4 READ [53] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
Sep  2 16:45:00 host openvpn[24390]: UDPv4 WRITE [53] to [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
Sep  2 16:45:03 host openvpn[24390]: UDPv4 READ [53] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
Sep  2 16:45:08 host openvpn[24390]: UDPv4 WRITE [53] to [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
Sep  2 16:45:12 host openvpn[24390]: UDPv4 READ [53] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
Sep  2 16:45:16 host openvpn[24390]: UDPv4 WRITE [53] to [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
Sep  2 16:45:20 host openvpn[24390]: UDPv4 READ [53] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
September 02, 2015, 04:04:57 PM #9
Quoteand "Enable authentication of TLS packets." always enabled when i try to edit OpenVPN: Client config

that one seems to be a bug in the interface, if you save it when toggling off the config should be ok.

I've just pushed a patch for it:
https://github.com/opnsense/core/commit/574a301eabec6e87247c0dd4c6bd18711431790d


As for the log, the last one doesn't show any errors for as far as I see. This one in the syslog looks a bit suspicious:

... /usr/local/etc/rc.linkup: Hotplug event detected for MSKVPN(opt1) but ignoring since interface is config...






September 02, 2015, 04:18:42 PM #10 Last Edit: September 02, 2015, 04:22:31 PM by rost
Do i need Firewall: NAT: Outbound configure to "Manual Outbound NAT rule generation" ?
Finde in openvpn.log

Code Select
Sep  2 17:08:40 host openvpn[24390]: UDPv4 READ [53] from [AF_INET]194.x.x.x:1194: P_DATA_V1 kid=0 DATA len=52
Sep  2 17:08:41 host openvpn[24390]: MANAGEMENT: Client connected from /var/etc/openvpn/client1.sock
Sep  2 17:08:41 host openvpn[24390]: MANAGEMENT: CMD 'state 1'
Sep  2 17:08:41 host openvpn[24390]: MANAGEMENT: CMD 'status 2'
Sep  2 17:08:41 host openvpn[24390]: MANAGEMENT: Client disconnected
but tunnel still up
September 02, 2015, 04:20:11 PM #11
only if the nets don't route to each other and you need to translate your source address, probably not because the first pings function correctly.
September 03, 2015, 02:11:46 PM #12 Last Edit: September 03, 2015, 04:40:08 PM by rost
If i wait a long time without disconnecting the tunnel, the ping is working again for a while. And then again all stop.
September 04, 2015, 06:00:55 PM #13
[Solved]
found a mistake in server side
one ip address for two openvpn client!!!
September 04, 2015, 06:17:31 PM #14
Good to hear you found the configuration issue!
Thanks for reporting back.
Print
Go Up Pages1
User actions