[Fli4l_dev] FFL-506 Tarball vom 29.8 und OpenVPN Problem

B. Sprenger b.sprenger at sprenger-ffm.de
So Sep 21 16:26:11 CEST 2014


Hallo Christoph,

Am 21.09.2014 um 11:51 schrieb Christoph Schulz:

> Wir brauchen die OpenVPN-Logs auf _beiden_ Seiten der Verbindung. Es gibt in
> der WebGUI dafür einen Eintrag "Supportinformationen" für jeden OpenVPN-
> Tunnel. Und ja, es handelt sich um ein recht spezifisches Problem, weil es
> nicht bei jedem auftritt. Wir haben bislang nur die Meldung von insgesamt
> zwei Leuten, bei denen OpenVPN seitdem Probleme macht.

Heisst das, es wird nur von 2 Leuten eingesetzt? :-))

So, hier das Log von Router 1 (Verbindung mit Router 2)
Versionen: Router 1: r31641, Router2: r31787
(Hier funktioniert alles tadellos und schnell)

21.09.2014	11:13:43	NOTE: the current --script-security setting may 
allow this configuration to call user-defined scripts
21.09.2014	11:13:43	Static Encrypt: Cipher 'AES-256-CBC' initialized 
with 256 bit key
21.09.2014	11:13:43	Static Encrypt: Using 160 bit message hash 'SHA1' 
for HMAC authentication
21.09.2014	11:13:43	Static Decrypt: Cipher 'AES-256-CBC' initialized 
with 256 bit key
21.09.2014	11:13:43	Static Decrypt: Using 160 bit message hash 'SHA1' 
for HMAC authentication
21.09.2014	11:13:43	TUN/TAP device tun0 opened
21.09.2014	11:13:43	do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
21.09.2014	11:13:43	/sbin/ip link set dev tun0 up mtu 1500
21.09.2014	11:13:43	/sbin/ip addr add dev tun0 local 192.168.200.194 
peer 192.168.200.203
21.09.2014	11:13:43	/usr/bin/openvpn_fwrules-helper-up tun0 1500 1565 
192.168.200.194 192.168.200.203 init
21.09.2014	11:13:43	UDPv4 link local (bound): [undef]
21.09.2014	11:13:43	UDPv4 link remote: [AF_INET]87.155.81.119:10002
21.09.2014	11:13:43	SIGUSR1[hard,] received, process restarting
21.09.2014	11:13:45	NOTE: the current --script-security setting may 
allow this configuration to call user-defined scripts
21.09.2014	11:13:45	Re-using pre-shared static key
21.09.2014	11:13:45	Preserving previous TUN/TAP instance: tun0
21.09.2014	11:13:45	UDPv4 link local (bound): [undef]
21.09.2014	11:13:45	UDPv4 link remote: [AF_INET]87.155.81.119:10002
21.09.2014	11:13:48	Peer Connection Initiated with 
[AF_INET]87.155.81.119:10002
21.09.2014	11:13:49	Initialization Sequence Completed

Die Gegenseite schenk' ich mir jetzt (sieht im Prinzip gleich aus).


Der interessante Teil kommt dann (vielleicht) jetzt:

Log von Router 1 (Verbindung mit Router 2)
Versionen: Router 1: r32991, Router2: r31787
(Hier dauert der Verbindungsaufbau ziemlich lange)

21.09.2014	16:13:16	OpenVPN 2.3.4 i586-buildroot-linux-uclibc [SSL 
(OpenSSL)] [LZO] [EPOLL] [MH] [IPv6]
21.09.2014	16:13:16	library versions: OpenSSL 1.0.1i 6 Aug 2014, LZO 2.08
21.09.2014	16:13:16	mlockall call succeeded
21.09.2014	16:13:27	mlockall call succeeded
21.09.2014	16:13:27	NOTE: the current --script-security setting may 
allow this configuration to call user-defined scripts
21.09.2014	16:13:27	Static Encrypt: Cipher 'AES-256-CBC' initialized 
with 256 bit key
21.09.2014	16:13:27	Static Encrypt: Using 160 bit message hash 'SHA1' 
for HMAC authentication
21.09.2014	16:13:27	Static Decrypt: Cipher 'AES-256-CBC' initialized 
with 256 bit key
21.09.2014	16:13:27	Static Decrypt: Using 160 bit message hash 'SHA1' 
for HMAC authentication
21.09.2014	16:13:27	TUN/TAP device tun0 opened
21.09.2014	16:13:27	do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
21.09.2014	16:13:27	/sbin/ip link set dev tun0 up mtu 1500
21.09.2014	16:13:27	/sbin/ip addr add dev tun0 local 192.168.200.194 
peer 192.168.200.203
21.09.2014	16:13:27	/usr/bin/openvpn_fwrules-helper-up tun0 1500 1565 
192.168.200.194 192.168.200.203 init
21.09.2014	16:13:28	UDPv4 link local (bound): [AF_INET]169.254.23.42:10003
21.09.2014	16:13:28	UDPv4 link remote: [AF_INET]87.155.81.119:10002
21.09.2014	16:13:28	SIGUSR1[hard,] received, process restarting
21.09.2014	16:13:30	NOTE: the current --script-security setting may 
allow this configuration to call user-defined scripts
21.09.2014	16:13:30	Re-using pre-shared static key
21.09.2014	16:13:30	Preserving previous TUN/TAP instance: tun0
21.09.2014	16:13:30	UDPv4 link local (bound): [AF_INET]169.254.23.42:10003
21.09.2014	16:13:30	UDPv4 link remote: [AF_INET]127.0.0.1:65500
21.09.2014	16:15:24	Peer Connection Initiated with 
[AF_INET]87.155.81.119:10002
21.09.2014	16:15:24	Initialization Sequence Completed




Da passiert zwischendrin für rund 2 Minuten gar nix (16:30:30)

Und hier die Gegenstelle.
Hier sieht es so aus, als ob die Gegenstelle die Trennung gar nicht 
bemerkt hat, der Inactivity timeout kommt erst um 16:15:22, die 
Verbindung wurde aber mit dem Reboot viel früher (so gegen 16:10) 
unterbrochen.


21.09.2014	11:13:44	Peer Connection Initiated with 
[AF_INET]79.255.3.191:10003
21.09.2014	16:15:22	Inactivity timeout (--ping-restart), restarting
21.09.2014	16:15:22	SIGUSR1[soft,ping-restart] received, process restarting
21.09.2014	16:15:24	NOTE: the current --script-security setting may 
allow this configuration to call user-defined scripts
21.09.2014	16:15:24	Re-using pre-shared static key
21.09.2014	16:15:24	Preserving previous TUN/TAP instance: tun0
21.09.2014	16:15:24	UDPv4 link local (bound): [undef]
21.09.2014	16:15:24	UDPv4 link remote: [AF_INET]79.255.58.2:10003
21.09.2014	16:15:24	Peer Connection Initiated with 
[AF_INET]79.255.58.2:10003
21.09.2014	16:15:25	Initialization Sequence Completed



Helfen die Informationen weiter?
Für mich sieht das alles ganz normal aus, bis auf
"UDPv4 link remote: [AF_INET]127.0.0.1:65500" bei Router 1, da müsste 
doch eine "echte" IP-Adresse drin stehen?
Soll ich nochmal ein Log erstellen mit Version r32991 auf beiden Seiten?

LG
Boris


Mehr Informationen über die Mailingliste Fli4l_dev