Re: [Radiusplugin-users] PLUGIN_CLIENT_CONNECT failed

[Eike Lohmann]

Hi Ralf, hi List,

here the ovpnlog with verbose 7.
I have obfuscated IP and Keyvalues and hope that 'mute' didn't captured the
interesting lines, otherwise I have to capture again.

Thanks for the help.



Am 31.01.2012 16:38, schrieb Ralf Lübben:
> Hi,
>
> can you increase the verbosity level  to 7 in OpenVPN config and post the 
> output again?
>
> Probably it shows why CLIENT_CONNECT fails.
>
> Regards,
> Ralf
>
> Am Dienstag, 31. Januar 2012, 13:52:20 schrieb Eike Lohmann:
>> Hi Ralf, hi List,
>>
>> sometimes a client failed to connect and stop reconnecting and I can't find
>> the reason for this behavior.
>> If I look into my Radius, the client got authenticated and accounting START
>> was created.
>>
>> Any Ideas? I have 2 radius servers (http://www.open.com.au/radiator/) and
>> this happens only with one of them.
>>
>> My openvpnlog:
>>
>> Jan 31 00:15:41 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492 Re-using
>> SSL/TLS context
>> Jan 31 00:15:41 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492 LZO
>> compression initialized
>> Jan 31 00:15:41 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492 Control
>> Channel MTU parms [ L:1546 D:138 EF:38 EB:0 ET:0 EL:0 ]
>> Jan 31 00:15:41 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492 Data
>> Channel MTU parms [ L:1546 D:1300 EF:46 EB:135 ET:0 EL:0 AF:3/1 ]
>> Jan 31 00:15:41 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492
>> Fragmentation MTU parms [ L:1546 D:1300 EF:45 EB:135 ET:1 EL:0 AF:3/1 ]
>> Jan 31 00:15:41 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492 Local
>> Options hash (VER=V4): '8e7959c7'
>> Jan 31 00:15:41 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492 Expected
>> Remote Options hash (VER=V4): 'c086e1aa'
>> Jan 31 00:15:41 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492 TLS:
>> Initial packet from [AF_INET]178.14.xx.xxx:51492, sid=81322596 0617b1b6
>> Jan 31 00:15:45 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492
>> PLUGIN_CALL: POST /etc/openvpn/radiusplugin.so/PLUGIN_AUTH_USER_PASS_VERIFY
>> status=0 Jan 31 00:15:45 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492
>> TLS: Username/Password authentication succeeded for username 'user1234' [CN
>> SET] Jan 31 00:15:45 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492 Data
>> Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
>> Jan 31 00:15:45 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492 Data
>> Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
>> Jan 31 00:15:45 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492 Data
>> Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
>> Jan 31 00:15:45 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492 Data
>> Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
>> Jan 31 00:15:45 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492 Control
>> Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA
>> Jan 31 00:15:45 ovpn-server ovpn-ovpnd[1002]: 178.14.xx.xxx:51492 [user1234]
>> Peer Connection Initiated with [AF_INET]178.14.xx.xxx:51492
>> Jan 31 00:15:45 ovpn-server ovpn-ovpnd[1002]: user1234/178.14.xx.xxx:51492
>> OPTIONS IMPORT: reading client specific options from:
>> /etc/openvpn/ccd/user1234 Jan 31 00:15:56 ovpn-server ovpn-ovpnd[1002]:
>> user1234/178.14.xx.xxx:51492 PLUGIN_CALL: POST
>> /etc/openvpn/radiusplugin.so/PLUGIN_CLIENT_CONNECT status=1 Jan 31 00:15:56
>> ovpn-server ovpn-ovpnd[1002]: user1234/178.14.xx.xxx:51492 PLUGIN_CALL:
>> plugin function PLUGIN_CLIENT_CONNECT failed with status 1:
>> /etc/openvpn/radiusplugin.so
>> Jan 31 00:15:56 ovpn-server ovpn-ovpnd[1002]: user1234/178.14.xx.xxx:51492
>> WARNING: client-connect plugin call failed
>> Jan 31 00:15:56 ovpn-server ovpn-ovpnd[1002]: user1234/178.14.xx.xxx:51492
>> PUSH: Received control message: 'PUSH_REQUEST'
>> Jan 31 00:15:56 ovpn-server ovpn-ovpnd[1002]: user1234/178.14.xx.xxx:51492
>> Delayed exit in 5 seconds
>> Jan 31 00:15:56 ovpn-server ovpn-ovpnd[1002]: user1234/178.14.xx.xxx:51492
>> SENT CONTROL [user1234]: 'AUTH_FAILED' (status=1)
>> Jan 31 00:15:56 ovpn-server ovpn-ovpnd[1002]: user1234/178.14.xx.xxx:51492
>> PUSH: Received control message: 'PUSH_REQUEST'
>> Jan 31 00:15:56 ovpn-server ovpn-ovpnd[1002]: user1234/178.14.xx.xxx:51492
>> Delayed exit in 5 seconds
>> Jan 31 00:15:56 ovpn-server ovpn-ovpnd[1002]: user1234/178.14.xx.xxx:51492
>> SENT CONTROL [user1234]: 'AUTH_FAILED' (status=1)
>> Jan 31 00:16:01 ovpn-server ovpn-ovpnd[1002]: user1234/178.14.xx.xxx:51492
>> SIGTERM[soft,delayed-exit] received, client-instance exiting
>>
>>
>> A question maybe to the wrong List, but this client has disconnected at
>> 18:58 on 30.1. and the server is "Re-using" the SSL/TLS context for this
>> client. OK, reneg-sec = 86400 but I thought ping-*, keepalive or
>> explicit-exit-notify will destroy this context.
>>
>> Regards, Eike
>>
>>
>>
>>
>> _______________________________________________
>> Radiusplugin-users mailing list
>> address@hidden
>> https://lists.nongnu.org/mailman/listinfo/radiusplugin-users

problem.log
Description: Text Data