Re: [Radiusplugin-devel] openvpn radius plugin act problem

[Ralf Lübben]

Hi,

do you mean some accounting information is missing when the server sends 
accounting information?

The accounting information should contain the RADIUS attributes 
Acct_Input_Octets, Acct-Output-Octets, Acct_Input_Gigawords, 
Acct_Output_Gigawords.

Can you check e.g. with Wireshark if if the accounting packets are on the wire 
and if the attributes are included and what value they have?

>From your log file I see that the plugin reads the accounting values at the 
disconnect.

Regards
Ralf

Am Dienstag, 15. Oktober 2013, 13:27:48 schrieb mohammad Naimi:
> To Whom may Concern
> We've installed the latest version of Radius Plug-in and Open-VPN  on
> AMD-64 bit Ubuntu 12.04 . Radius authenticates privileged users but
> accounting is not working properly.I've provided my radiusclient.cnf and
> Openvpn.log at verbes 5. The problem is that, the radius plug-in sends
> inbound traffic of user correctly, but doesn't send outbound traffic of
> user.
> radiusclient.cnf
> # The NAS identifier which is sent to the RADIUS server
> NAS-Identifier=OpenVpn
> 
> # The service type which is sent to the RADIUS server
> Service-Type=5
> 
> # The framed protocol which is sent to the RADIUS server
> Framed-Protocol=1
> 
> # The NAS port type which is sent to the RADIUS server
> NAS-Port-Type=5
> 
> # The NAS IP address which is sent to the RADIUS server
> NAS-IP-Address=X.X.X.X
> 
> # Path to the OpenVPN configfile. The plugin searches there for
> # client-config-dir PATH   (searches for the path)
> # status FILE                (searches for the file, version must be 1)
> # client-cert-not-required (if the option is used or not)
> # username-as-common-name  (if the option is used or not)
> 
> OpenVPNConfig=/etc/openvpn/server.conf
> overwriteccfiles=true
> 
> server
> {
>     # The UDP port for radius accounting.
>     acctport=1813
>     # The UDP port for radius authentication.
>     authport=1812
>     # The name or ip address of the radius server.
>     name=Y.Y.Y.Y
>     # How many times should the plugin send the if there is no response?
>     retry=1
>     # How long should the plugin wait for a response?
>     wait=1
>     # The shared secret.
>     sharedsecret=110
> }
> 
> openvpn log:
> 
> ##############Connecting##########################
> 
> Tue Oct 15 08:13:33 2013 us=937401 Initialization Sequence Completed
> Tue Oct 15 08:14:07 2013 us=683752 MULTI: multi_create_instance called
> Tue Oct 15 08:14:07 2013 us=683966 Re-using SSL/TLS context
> Tue Oct 15 08:14:07 2013 us=684061 LZO compression initialized
> Tue Oct 15 08:14:07 2013 us=684417 Control Channel MTU parms [ L:1544 D:140
> EF:40 EB:0 ET:0 EL:0 ]
> Tue Oct 15 08:14:07 2013 us=684489 Data Channel MTU parms [ L:1544 D:1450
> EF:44 EB:135 ET:0 EL:0 AF:3/1 ]
> Tue Oct 15 08:14:07 2013 us=684620 Local Options String: 'V4,dev-type
> tun,link-mtu 1544,tun-mtu 1500,proto TCPv4_SERVER,comp-lzo,cipher
> BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
> Tue Oct 15 08:14:07 2013 us=684649 Expected Remote Options String:
> 'V4,dev-type tun,link-mtu 1544,tun-mtu 1500,proto
> TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method
> 2,tls-client'
> Tue Oct 15 08:14:07 2013 us=684691 Local Options hash (VER=V4): 'c0103fa8'
> Tue Oct 15 08:14:07 2013 us=684721 Expected Remote Options hash (VER=V4):
> '69109d17'
> Tue Oct 15 08:14:07 2013 us=684785 TCP connection established with [AF_INET]
> 217.218.83.90:46884
> Tue Oct 15 08:14:07 2013 us=684816 TCPv4_SERVER link local: [undef]
> Tue Oct 15 08:14:07 2013 us=684838 TCPv4_SERVER link remote: [AF_INET]
> 217.218.83.90:46884
> RTue Oct 15 08:14:08 2013 us=376620 217.218.83.90:46884 TLS: Initial packet
> from [AF_INET]217.218.83.90:46884, sid=18d63202 d10a7d6b
> WRRWRWRWWWWRWRWWWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRRRRWRWWWRRWRWRWRTue
> Oct 15 08:14:16 2013 RADIUS-PLUGIN: FOREGROUND:
> OPENVPN_PLUGIN_AUTH_USER_PASS_VERIFY is called.
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: FOREGROUND: Commonname set to
> Username
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: FOREGROUND: Key: 217.218.83.90:46884
> .
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: FOREGROUND THREAD:
> Auth_user_pass_verify thread started.
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: FOREGROUND THREAD: New user from
> OpenVPN!
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: FOREGROUND THREAD: New user.
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: FOREGROUND THREAD: New user:
> username: ali, password: *****, newuser ip: 217.218.83.90, newuser port:
> 46884 .
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: BACKGROUND  AUTH: New user auth:
> username: ali, password: *****, calling station: 217.218.83.90, commonname:
> ali.
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: radius_server().
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: Build password packet:  password:
> *****, sharedSecret: *****.
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: Send packet to 65.60.45.43.
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: Get ACCESS_ACCEPT-Packet.
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: parse_response_packet().
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: BACKGROUND AUTH: routes: .
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: BACKGROUND AUTH: framed ip: .
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: No attributes Acct Interim Interval
> or bad length.
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: BACKGROUND AUTH: Acct Interim
> Interval: 0.
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: Client config file was not written,
> overwriteccfiles is false
> .Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: BACKGROUND  AUTH: Auth succeeded
> in radius_server().
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: FOREGROUND THREAD: Authentication
> succeeded!
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: FOREGROUND THREAD: Received routes
> for user: .
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: FOREGROUND THREAD: Received framed
> ip for user: .
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: FOREGROUND THREAD: Receive
> acctinteriminterval 0 sec from backgroundprocess.
> Tue Oct 15 08:14:16 2013 RADIUS-PLUGIN: FOREGROUND THREAD: Add user to map.
> Tue Oct 15 08:14:16 2013 us=330263 217.218.83.90:46884 PLUGIN_CALL: POST
> /usr/lib/openvpn/radiusplugin.so/PLUGIN_AUTH_USER_PASS_VERIFY status=0
> Tue Oct 15 08:14:16 2013 us=330377 217.218.83.90:46884 TLS:
> Username/Password authentication succeeded for username 'ali' [CN SET]
> Tue Oct 15 08:14:16 2013 us=330602 217.218.83.90:46884 Data Channel
> Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
> Tue Oct 15 08:14:16 2013 us=330657 217.218.83.90:46884 Data Channel
> Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
> Tue Oct 15 08:14:16 2013 us=330750 217.218.83.90:46884 Data Channel
> Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
> Tue Oct 15 08:14:16 2013 us=330799 217.218.83.90:46884 Data Channel
> Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
> WWWTue Oct 15 08:14:16 2013 RADIUS-PLUGIN: FOREGROUND THREAD: Waiting for
> new user.
> RRTue Oct 15 08:14:17 2013 us=291241 217.218.83.90:46884 Control Channel:
> TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA
> Tue Oct 15 08:14:17 2013 us=291378 217.218.83.90:46884 [ali] Peer
> Connection Initiated with [AF_INET]217.218.83.90:46884
> Tue Oct 15 08:14:17 2013 us=291549 ali/217.218.83.90:46884 MULTI_sva: pool
> returned IPv4=10.8.0.6, IPv6=1866:cda6:ea7f::
> Tue Oct 15 08:14:17 2013 RADIUS-PLUGIN: FOREGROUND:
> OPENVPN_PLUGIN_CLIENT_CONNECT is called.
> Tue Oct 15 08:14:17 2013 RADIUS-PLUGIN: FOREGROUND: Key: 217.218.83.90:46884
> .
> Tue Oct 15 08:14:17 2013 RADIUS-PLUGIN: FOREGROUND: Set FramedIP to the IP
> (10.8.0.6) OpenVPN assigned to the user ali
> Tue Oct 15 08:14:17 2013 RADIUS-PLUGIN: FOREGROUND: Add user for
> accounting: username: ali, commonname: ali
> Tue Oct 15 08:14:17 2013 RADIUS-PLUGIN: BACKGROUND ACCT: Get a command.
> Tue Oct 15 08:14:17 2013 RADIUS-PLUGIN: BACKGROUND ACCT: New User.
> Tue Oct 15 08:14:17 2013 RADIUS-PLUGIN: BACKGROUND ACCT: New user acct:
> username: ali, interval: 0, calling station: 217.218.83.90, commonname:
> ali, framed ip: 10.8.0.6.
> Tue Oct 15 08:14:17 2013 RADIUS-PLUGIN: BACKGROUND-ACCT:  Get
> ACCOUNTING_RESPONSE-Packet.
> Tue Oct 15 08:14:17 2013 RADIUS-PLUGIN: BACKGROUND ACCT: Start packet was
> send.
> Tue Oct 15 08:14:17 2013 RADIUS-PLUGIN: BACKGROUND ACCT: User was added to
> accounting scheduler.
> Tue Oct 15 08:14:17 2013 RADIUS-PLUGIN: BACKGROUND-ACCT:  No routes for
> user.
> Tue Oct 15 08:14:17 2013 RADIUS-PLUGIN: FOREGROUND: Accouting succeeded!
> Tue Oct 15 08:14:17 2013 us=347244 ali/217.218.83.90:46884 PLUGIN_CALL:
> POST /usr/lib/openvpn/radiusplugin.so/PLUGIN_CLIENT_CONNECT status=0
> Tue Oct 15 08:14:17 2013 us=347300 ali/217.218.83.90:46884 OPTIONS IMPORT:
> reading client specific options from:
> /tmp/openvpn_cc_ab368797998a138d5203f1ff7bf3aeb8.tmp
>   % Total    % Received % Xferd  Average Speed   Time    Time     Time
> Current
>                                  Dload  Upload   Total   Spent    Left
> Speed
> 100    65    0    65    0     0    103      0 --:--:-- --:--:-- --:--:--
> 115
> iptables: No chain/target/match by that name.
> iptables: No chain/target/match by that name.
> iptables: No chain/target/match by that name.
> Tue Oct 15 08:14:18 2013 us=2443 ali/217.218.83.90:46884 OPTIONS IMPORT:
> reading client specific options from:
> /tmp/openvpn_cc_d0e95a873a6504d619de7f542cb32c73.tmp
> Tue Oct 15 08:14:18 2013 us=2632 ali/217.218.83.90:46884 MULTI: Learn:
> 10.8.0.6 -> ali/217.218.83.90:46884
> Tue Oct 15 08:14:18 2013 us=2696 ali/217.218.83.90:46884 MULTI: primary
> virtual IP for ali/217.218.83.90:46884: 10.8.0.6
> rWRTue Oct 15 08:14:19 2013 us=112898 ali/217.218.83.90:46884 PUSH:
> Received control message: 'PUSH_REQUEST'
> Tue Oct 15 08:14:19 2013 us=113017
> ali/217.218.83.90:46884send_push_reply(): safe_cap=960
> Tue Oct 15 08:14:19 2013 us=113105 ali/217.218.83.90:46884 SENT CONTROL
> [ali]: 'PUSH_REPLY,redirect-gateway def1,dhcp-option DNS
> 8.8.8.8,dhcp-option DNS 4.2.2.4,route 10.8.0.1,topology net30,ping
> 5,ping-restart 30,ifconfig 10.8.0.6 10.8.0.5' (status=1)
> WWWWRRRwRwRwrWrWRwRwRwRwRwRwrWrWrWrWrWWrWRwRwRTue Oct 15 08:14:29 2013
> us=313820 ali/217.218.83.90:46884 MULTI: bad source address from client
> [192.168.12.113], packet dropped
> RTue Oct 15 08:14:29 2013 us=314002 ali/217.218.83.90:46884 MULTI: bad
> source address from client [192.168.12.113], packet dropped
> RwRwRwRwRwRwRwRwRwRwrWrWrWrWrWrWrWRwRwrWRwRwRwRwRwRwRwRwRwRwrWrWrWrWRwRwRwRw
> RwrWrWrWRwRwRwRwRwRwrWrWrWrWrWRwrWrWrWrWRwRwRwRwRwRwRwRwRwRwrWrWrWrWrWRwRwRw
> rWrWRwrWrWrWRwRwRwRwRwRwRwRwRwRwRwRwrWrWrWRwRwRwRwrWrWrWRwRwrWrWrWrWRwRwRwRw
> RwRwRwrWRwrWrWRwRwRwrWRwRwRwRwrWrWrWrWRwrWrWRwRTue Oct 15 08:14:35 2013
> us=456960 ali/217.218.83.90:46884 MULTI: bad source address from client
> [192.168.12.113], packet dropped
> RwRTue Oct 15 08:14:35 2013 us=769325 ali/217.218.83.90:46884 MULTI: bad
> source address from client [192.168.12.113], packet dropped
> RwRwrWrWRwrWRwRwRwrWRwRwrWRwrWRwrWrWRwRwRwWRRwRwWRwrWRTue Oct 15 08:14:56
> 2013 us=152153 ali/217.218.83.90:46884 MULTI: bad source address from
> client [192.168.12.113], packet dropped
> RTue Oct 15 08:14:57 2013 us=48167 ali/217.218.83.90:46884 MULTI: bad
> source address from client [192.168.12.113], packet dropped
> WRWRrWRwWRRwWrWRwRwRwrWRwRwrWRwRwrWRwrWrWRRwRwRwrWRwRwrWrWrWrWrWrWRwRwRwRwRT
> ue Oct 15 08:15:37 2013 us=626862 ali/217.218.83.90:46884 MULTI: bad source
> address from client [192.168.12.113], packet dropped
> RTue Oct 15 08:15:39 2013 us=543636 ali/217.218.83.90:46884 MULTI: bad
> source address from client [192.168.12.113], packet dropped
> 
> 
> 
> ######After disconnecting from user#########################
> 
>  Oct 15 08:27:38 2013 us=700943 ali/217.218.83.90:46884 Connection reset,
> restarting [0]
> Tue Oct 15 08:27:38 2013 us=701114
> ali/217.218.83.90:46884SIGUSR1[soft,connection-reset] received,
> client-instance restarting
> Tue Oct 15 08:27:38 2013
> 
> RADIUS-PLUGIN: FOREGROUND: OPENVPN_PLUGIN_CLIENT_DISCONNECT is called.
> Tue Oct 15 08:27:38 2013 RADIUS-PLUGIN: FOREGROUND: Delete user for
> accounting: commonname: 217.218.83.90:46884
> Tue Oct 15 08:27:38 2013 RADIUS-PLUGIN: BACKGROUND ACCT: Get a command.
> Tue Oct 15 08:27:38 2013 RADIUS-PLUGIN: BACKGROUND-ACCT: Delete user from
> accounting.
> Tue Oct 15 08:27:38 2013 RADIUS-PLUGIN: BACKGROUND ACCT: Stop acct:
> username: ali, calling station: 217.218.83.90, commonname: ali.
> Tue Oct 15 08:27:38 2013 RADIUS-PLUGIN: BACKGROUND-ACCT:  No routes for
> user in AccessAcceptPacket.
> Tue Oct 15 08:27:38 2013 RADIUS-PLUGIN: BACKGROUND ACCT: Scheduler: Read
> Statusfile.
> Tue Oct 15 08:27:38 2013 RADIUS-PLUGIN: BACKGROUND-ACCT: Got accouting data
> from file, CN: ali in: 773786 out: 3028504.
> Tue Oct 15 08:27:38 2013 RADIUS-PLUGIN: BACKGROUND-ACCT:  Get
> ACCOUNTING_RESPONSE-Packet.
> Tue Oct 15 08:27:38 2013 RADIUS-PLUGIN: BACKGROUND-ACCT: Stop packet was
> sent. CN: ali.
> Tue Oct 15 08:27:38 2013 RADIUS-PLUGIN: BACKGROUND ACCT: User with key:
> 217.218.83.90:46884 was deleted from accouting.
> Tue Oct 15 08:27:38 2013 RADIUS-PLUGIN: FOREGROUND: Accouting for user with
> key217.218.83.90:46884 stopped!
> Tue Oct 15 08:27:38 2013 us=757264 PLUGIN_CALL: POST /usr/lib/openvpn/
> radiusplugin.so/PLUGIN_CLIENT_DISCONNECT status=0
> iptables: No chain/target/match by that name.
> iptables: No chain/target/match by that name.
> Tue Oct 15 08:27:38 2013 us=766578 TCP/UDP: Closing socket