Re: [Radiusplugin-users] PLUGIN_CLIENT

radiusplugin-users
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: [Radiusplugin-users] PLUGIN_CLIENT_CONNECT failed

From:	Ralf Lübben
Subject:	Re: [Radiusplugin-users] PLUGIN_CLIENT_CONNECT failed
Date:	Wed, 08 Feb 2012 18:59:20 +0100
User-agent:	KMail/4.7.3 (Linux/3.0.0-15-generic-pae; KDE/4.7.4; i686; ; )
Hi,

still the plugin debugging information is missing. This could indicate why the 
connect fails.

If you use an old version the verbosity level must be set to 7 .

So your OpenVPN configuration file should contain

verb 7
log /var/log/openvpn.log 

The plugin writes debugging information to stderr, as described in the man 
page of OpenVPN this is forwarded to the configured log file. 

Can you check your settings? If you use syslog the debugging will probably be 
redirected to /dev/null .

Ralf




Am Mittwoch, 8. Februar 2012, 09:17:44 schrieb Eike Lohmann:
> Good Morning,
> 
> with verb 5 i got this information only, authentication is ok, but
> accounting fails or?
> 
> Thanks, Eike
> 
> Feb  7 00:56:05 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378 Re-using
> SSL/TLS context
> Feb  7 00:56:05 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378 LZO
> compression initialized
> Feb  7 00:56:05 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378 Control
> Channel MTU parms [ L:1546 D:138 EF:38 EB:0 ET:0 EL:0 ]
> Feb  7 00:56:05 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378 Data
> Channel MTU parms [ L:1546 D:1300 EF:46 EB:135 ET:0 EL:0 AF:3/1 ]
> Feb  7 00:56:05 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378
> Fragmentation MTU parms [ L:1546 D:1300 EF:45 EB:135 ET:1 EL:0 AF:3/1 ]
> Feb  7 00:56:05 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378 Local
> Options String: 'V4,dev-type tun,link-mtu 1546,tun-mtu 1500,proto
> UDPv4,comp-lzo,mtu-dynamic,cipher BF-CBC,auth SHA1,keysize 128,key-method
> 2,tls-server'
> Feb  7 00:56:05 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378 Expected
> Remote Options String: 'V4,dev-type tun,link-mtu 1546,tun-mtu 1500,proto
> UDPv4,comp-lzo,mtu-dynamic,cipher BF-CBC,auth SHA1,keysize 128,key-method
> 2,tls-client'
> Feb  7 00:56:05 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378 Local
> Options hash (VER=V4): '8e7959c7'
> Feb  7 00:56:05 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378 Expected
> Remote Options hash (VER=V4): 'c086e1aa'
> Feb  7 00:56:05 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378 TLS:
> Initial packet from [AF_INET]87.106.xxx.xxx:60378, sid=b7748434 01d2d4b4
> Feb  7 00:56:20 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378
> PLUGIN_CALL: POST /etc/openvpn/radiusplugin.so/PLUGIN_AUTH_USER_PASS_VERIFY
> status=0 Feb  7 00:56:20 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378
> TLS: Username/Password authentication succeeded for username 'user1234' [CN
> SET] Feb  7 00:56:20 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378
> Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
> Feb  7 00:56:20 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378 Data
> Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
> Feb  7 00:56:20 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378 Data
> Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
> Feb  7 00:56:20 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378 Data
> Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
> Feb  7 00:56:20 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378 Control
> Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA
> Feb  7 00:56:20 ovpn-server ovpn-ovpnd[1193]: 87.106.xxx.xxx:60378
> [user1234] Peer Connection Initiated with [AF_INET]87.106.xxx.xxx:60378
> Feb  7 00:56:20 ovpn-server ovpn-ovpnd[1193]: user1234/87.106.xxx.xxx:60378
> OPTIONS IMPORT: reading client specific options from:
> /etc/openvpn/ccd/user1234 Feb  7 00:56:36 ovpn-server ovpn-ovpnd[1193]:
> user1234/87.106.xxx.xxx:60378 PLUGIN_CALL: POST
> /etc/openvpn/radiusplugin.so/PLUGIN_CLIENT_CONNECT status=1 Feb  7 00:56:36
> ovpn-server ovpn-ovpnd[1193]: user1234/87.106.xxx.xxx:60378 PLUGIN_CALL:
> plugin function PLUGIN_CLIENT_CONNECT failed with status 1:
> /etc/openvpn/radiusplugin.so
> Feb  7 00:56:36 ovpn-server ovpn-ovpnd[1193]: user1234/87.106.xxx.xxx:60378
> WARNING: client-connect plugin call failed
> Feb  7 00:56:36 ovpn-server ovpn-ovpnd[1193]: user1234/87.106.xxx.xxx:60378
> PUSH: Received control message: 'PUSH_REQUEST'
> Feb  7 00:56:36 ovpn-server ovpn-ovpnd[1193]: user1234/87.106.xxx.xxx:60378
> Delayed exit in 5 seconds
> Feb  7 00:56:36 ovpn-server ovpn-ovpnd[1193]: user1234/87.106.xxx.xxx:60378
> SENT CONTROL [user1234]: 'AUTH_FAILED' (status=1)
> Feb  7 00:56:36 ovpn-server ovpn-ovpnd[1193]: user1234/87.106.xxx.xxx:60378
> PUSH: Received control message: 'PUSH_REQUEST'
> Feb  7 00:56:36 ovpn-server ovpn-ovpnd[1193]: user1234/87.106.xxx.xxx:60378
> Delayed exit in 5 seconds
> Feb  7 00:56:36 ovpn-server ovpn-ovpnd[1193]: user1234/87.106.xxx.xxx:60378
> SENT CONTROL [user1234]: 'AUTH_FAILED' (status=1)
> Feb  7 00:56:36 ovpn-server ovpn-ovpnd[1193]: user1234/87.106.xxx.xxx:60378
> PUSH: Received control message: 'PUSH_REQUEST'
> Feb  7 00:56:36 ovpn-server ovpn-ovpnd[1193]: user1234/87.106.xxx.xxx:60378
> Delayed exit in 5 seconds
> Feb  7 00:56:36 ovpn-server ovpn-ovpnd[1193]: user1234/87.106.xxx.xxx:60378
> SENT CONTROL [user1234]: 'AUTH_FAILED' (status=1)
> Feb  7 00:56:42 ovpn-server ovpn-ovpnd[1193]: user1234/87.106.xxx.xxx:60378
> SIGTERM[soft,delayed-exit] received, client-instance exiting
> 
> Am 04.02.2012 14:40, schrieb Ralf Lübben:
> > Hi,
> > 
> > the plugin output is missing.
> > 
> > Usally the plugin writes logging information to the OpenVPN log file, if
> > the verb option is greater or equal 5. This information is missing in
> > the log files. The information starts with "RADIUS-PLUGIN: ...".
> > 
> > Can you try to create files with the logging information of the plugin.
> > (I don't know why it is missing in your file.)
> > 
> > 
> > Ralf
> > 
> > Am Freitag, 3. Februar 2012, 10:28:59 schrieb 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
[Prev in Thread]
Current Thread
[Next in Thread]
Re: [Radiusplugin-users] PLUGIN_CLIENT_CONNECT failed, Eike Lohmann, 2012/02/03
- Re: [Radiusplugin-users] PLUGIN_CLIENT_CONNECT failed, Ralf Lübben, 2012/02/04
  - Re: [Radiusplugin-users] PLUGIN_CLIENT_CONNECT failed, Eike Lohmann, 2012/02/08
    - Re: [Radiusplugin-users] PLUGIN_CLIENT_CONNECT failed, Ralf Lübben <=
    - Re: [Radiusplugin-users] PLUGIN_CLIENT_CONNECT failed, Eike Lohmann, 2012/02/29
Prev by Date: Re: [Radiusplugin-users] PLUGIN_CLIENT_CONNECT failed
Next by Date: [Radiusplugin-users] username end with space can login succeed, but can't be accounted.
Previous by thread: Re: [Radiusplugin-users] PLUGIN_CLIENT_CONNECT failed
Next by thread: Re: [Radiusplugin-users] PLUGIN_CLIENT_CONNECT failed
Index(es):
- Date
- Thread