[Top][All Lists]
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: [Radiusplugin-users] username end with space can login succeed, but
|
From: |
Jacky.He |
|
Subject: |
Re: [Radiusplugin-users] username end with space can login succeed, but can't be accounted. |
|
Date: |
Sun, 19 Feb 2012 01:08:49 +0800 |
Ralf,
Thanks, I have modified the Freeradius's policy.conf file and put policy
filter name on the authorize section of site config file, it works.
Jacky
-----Original Message-----
From: Ralf Lübben [mailto:address@hidden
Sent: Saturday, February 18, 2012 11:57 PM
To: Jacky.He
Cc: address@hidden
Subject: Re: [Radiusplugin-users] username end with space can login succeed,
but can't be accounted.
Hi,
thanks, the log file helps.
I you search for "username=" in the log you will see, that for "AUTH-USER-
PASS-VERIFY" the username becomes "user009 ", so the "_" is replaced.
For "CLIENT-CONNECT" the "_" is not replaced. (I assume it was the same
connection in the log of user user009).
This behavior is due to OpenVPN so I can't change it. But I don't understand
why OpenVPN replaces the "_", even with the man page of OpenVPN it does not
become clear for me.
The second issue is that Freeradius (probably older versions) allow/trim
spaces from the username, see
http://freeradius.1045715.n5.nabble.com/nospace-user-not-working-as-expected
-
in-1-0-5-td2745378.html
I think this explains why your user can connect. The solution could be
rlm_policy as mentioned in the mailing list.
Regards,
Ralf
Am Samstag, 18. Februar 2012, 22:56:58 schrieb Jacky.He:
> Log bellow, hope it helpful.
>
> -----------------
> Sat Feb 18 09:48:16 2012 us=225455 TUN/TAP device tun9 opened
> Sat Feb 18 09:48:16 2012 us=225490 TUN/TAP TX queue length set to 100
> Sat Feb 18 09:48:16 2012 us=225530 /sbin/ip link set dev tun9 up mtu 1500
> Sat Feb 18 09:48:16 2012 us=228399 /sbin/ip addr add dev tun9 10.11.0.1/16
> broadcast 10.11.255.255
> Sat Feb 18 09:48:16 2012 us=231344 Data Channel MTU parms [ L:1558 D:1300
> EF:58 EB:135 ET:0 EL:0 AF:3/1 ]
> Sat Feb 18 09:48:16 2012 us=233246 UDPv4 link local (bound):
> 10x.1xx.xx.xx:443
> Sat Feb 18 09:48:16 2012 us=233354 UDPv4 link remote: [undef]
> Sat Feb 18 09:48:16 2012 us=233390 MULTI: multi_init called, r=256 v=256
> Sat Feb 18 09:48:16 2012 us=235093 IFCONFIG POOL: base=10.11.0.2
size=65532
> Sat Feb 18 09:48:16 2012 us=235193 Initialization Sequence Completed
> Sat Feb 18 09:48:26 2012 us=245374 MULTI: REAP range 0 -> 16
> Sat Feb 18 09:48:36 2012 us=255632 MULTI: REAP range 16 -> 32
> Sat Feb 18 09:48:37 2012 us=283508 MULTI: REAP range 32 -> 48
> Sat Feb 18 09:48:37 2012 us=283659 MULTI: multi_create_instance called
> Sat Feb 18 09:48:37 2012 us=283733 115.170.126.165:4329 Re-using SSL/TLS
> context
> Sat Feb 18 09:48:37 2012 us=283793 115.170.126.165:4329 LZO compression
> initialized
> Sat Feb 18 09:48:37 2012 us=283811 115.170.126.165:4329 MTU DYNAMIC mtu=0,
> flags=1, 0 -> 166
> Sat Feb 18 09:48:37 2012 us=283824 115.170.126.165:4329 PID packet_id_init
> seq_backtrack=64 time_backtrack=15
> Sat Feb 18 09:48:37 2012 us=284036 115.170.126.165:4329 PID packet_id_init
> seq_backtrack=64 time_backtrack=15
> Sat Feb 18 09:48:37 2012 us=284052 115.170.126.165:4329 PID packet_id_init
> seq_backtrack=64 time_backtrack=15
> Sat Feb 18 09:48:37 2012 us=284124 115.170.126.165:4329 PID packet_id_init
> seq_backtrack=64 time_backtrack=15
> Sat Feb 18 09:48:37 2012 us=284143 115.170.126.165:4329 Control Channel
MTU
> parms [ L:1562 D:166 EF:66 EB:0 ET:0 EL:0 ]
> Sat Feb 18 09:48:37 2012 us=284154 115.170.126.165:4329 MTU DYNAMIC
> mtu=1300, flags=2, 1562 -> 1300
> Sat Feb 18 09:48:37 2012 us=284229 115.170.126.165:4329 MTU DYNAMIC
> mtu=1300, flags=2, 1562 -> 1300
> Sat Feb 18 09:48:37 2012 us=284253 115.170.126.165:4329 Data Channel MTU
> parms [ L:1562 D:1300 EF:62 EB:135 ET:0 EL:0 AF:3/1 ]
> Sat Feb 18 09:48:37 2012 us=284266 115.170.126.165:4329 Fragmentation MTU
> parms [ L:1562 D:1300 EF:61 EB:135 ET:1 EL:0 AF:3/1 ]
> Sat Feb 18 09:48:37 2012 us=284399 115.170.126.165:4329 Local Options
> String: 'V4,dev-type tun,link-mtu 1562,tun-mtu 1500,proto
> UDPv4,comp-lzo,mtu-dynamic,keydir 0,cipher AES-128-CBC,auth SHA1,keysize
> 128,tls-auth,key-method 2,tls-server'
> Sat Feb 18 09:48:37 2012 us=284417 115.170.126.165:4329 Expected Remote
> Options String: 'V4,dev-type tun,link-mtu 1562,tun-mtu 1500,proto
> UDPv4,comp-lzo,mtu-dynamic,keydir 1,cipher AES-128-CBC,auth SHA1,keysize
> 128,tls-auth,key-method 2,tls-client'
> Sat Feb 18 09:48:37 2012 us=284439 115.170.126.165:4329 Local Options hash
> (VER=V4): '6a64613d'
> Sat Feb 18 09:48:37 2012 us=284454 115.170.126.165:4329 Expected Remote
> Options hash (VER=V4): '84ab6e17'
> Sat Feb 18 09:48:37 2012 us=284476 115.170.126.165:4329 SENT PING
> Sat Feb 18 09:48:37 2012 us=284519 115.170.126.165:4329 GET INST BY REAL:
> 115.170.126.165:4329 [created]
> Sat Feb 18 09:48:37 2012 us=284551 115.170.126.165:4329 UDPv4 READ [42]
from
> 115.170.126.165:4329: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 pid=[ #2 ] [ ]
> pid=0 DATA len=0
> Sat Feb 18 09:48:37 2012 us=284579 115.170.126.165:4329 TLS: Initial
packet
> from 115.170.126.165:4329, sid=38c92866 a748523b
> Sat Feb 18 09:48:37 2012 us=284640 115.170.126.165:4329 UDPv4 WRITE [54]
to
> 115.170.126.165:4329: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 pid=[ #1 ] [ 0
]
> pid=0 DATA len=0
> Sat Feb 18 09:48:37 2012 us=711162 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:37 2012 us=711229 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #3 ] [ 0 ]
> Sat Feb 18 09:48:37 2012 us=718639 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:37 2012 us=718681 115.170.126.165:4329 UDPv4 READ [142]
> from 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #4 ] [ ] pid=1 DATA
> len=100
> Sat Feb 18 09:48:37 2012 us=718762 115.170.126.165:4329 UDPv4 WRITE [50]
to
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #2 ] [ 1 ]
> Sat Feb 18 09:48:37 2012 us=718868 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:37 2012 us=718896 115.170.126.165:4329 UDPv4 READ [142]
> from 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #5 ] [ ] pid=2 DATA
> len=100
> Sat Feb 18 09:48:37 2012 us=719007 115.170.126.165:4329 UDPv4 WRITE [50]
to
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #3 ] [ 2 ]
> Sat Feb 18 09:48:37 2012 us=719086 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:37 2012 us=719125 115.170.126.165:4329 UDPv4 READ [52]
from
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #6 ] [ ] pid=3 DATA len=10
> Sat Feb 18 09:48:37 2012 us=729024 115.170.126.165:4329 UDPv4 WRITE [154]
> to 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #4 ] [ 3 ] pid=1 DATA
> len=100 Sat Feb 18 09:48:37 2012 us=729230 115.170.126.165:4329 UDPv4
WRITE
> [142] to 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #5 ] [ ] pid=2
DATA
> len=100 Sat Feb 18 09:48:37 2012 us=729350 115.170.126.165:4329 UDPv4
WRITE
> [142] to 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #6 ] [ ] pid=3
DATA
> len=100 Sat Feb 18 09:48:37 2012 us=729446 115.170.126.165:4329 UDPv4
WRITE
> [142] to 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #7 ] [ ] pid=4
DATA
> len=100 Sat Feb 18 09:48:37 2012 us=729496 115.170.126.165:4329 ACK output
> sequence broken: [5] 1 2 3 4
> Sat Feb 18 09:48:38 2012 us=162178 MULTI: REAP range 48 -> 64
> Sat Feb 18 09:48:38 2012 us=162343 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:38 2012 us=162373 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #7 ] [ 1 ]
> Sat Feb 18 09:48:38 2012 us=162466 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #8 ] [ ] pid=5 DATA len=100
> Sat Feb 18 09:48:38 2012 us=162531 115.170.126.165:4329 ACK output
sequence
> broken: [6] 5 2 3 4
> Sat Feb 18 09:48:38 2012 us=162560 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:38 2012 us=162577 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #8 ] [ 2 ]
> Sat Feb 18 09:48:38 2012 us=162621 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #9 ] [ ] pid=6 DATA len=100
> Sat Feb 18 09:48:38 2012 us=162665 115.170.126.165:4329 ACK output
sequence
> broken: [7] 5 6 3 4
> Sat Feb 18 09:48:38 2012 us=167266 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:38 2012 us=167314 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #9 ] [ 3 ]
> Sat Feb 18 09:48:38 2012 us=167400 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #10 ] [ ] pid=7 DATA
len=100
> Sat Feb 18 09:48:38 2012 us=167454 115.170.126.165:4329 ACK output
sequence
> broken: [8] 5 6 7 4
> Sat Feb 18 09:48:38 2012 us=167481 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:38 2012 us=167496 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #10 ] [ 4 ]
> Sat Feb 18 09:48:38 2012 us=167535 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #11 ] [ ] pid=8 DATA
len=100
> Sat Feb 18 09:48:38 2012 us=167572 115.170.126.165:4329 ACK output
sequence
> broken: [9] 5 6 7 8
> Sat Feb 18 09:48:38 2012 us=607904 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:38 2012 us=607947 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #11 ] [ 5 ]
> Sat Feb 18 09:48:38 2012 us=608024 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #12 ] [ ] pid=9 DATA
len=100
> Sat Feb 18 09:48:38 2012 us=608087 115.170.126.165:4329 ACK output
sequence
> broken: [10] 9 6 7 8
> Sat Feb 18 09:48:38 2012 us=608131 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:38 2012 us=608156 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #12 ] [ 6 ]
> Sat Feb 18 09:48:38 2012 us=608212 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #13 ] [ ] pid=10 DATA
> len=100 Sat Feb 18 09:48:38 2012 us=608264 115.170.126.165:4329 ACK output
> sequence broken: [11] 9 10 7 8
> Sat Feb 18 09:48:38 2012 us=615939 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:38 2012 us=615989 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #13 ] [ 7 ]
> Sat Feb 18 09:48:38 2012 us=616076 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #14 ] [ ] pid=11 DATA
> len=100 Sat Feb 18 09:48:38 2012 us=616141 115.170.126.165:4329 ACK output
> sequence broken: [12] 9 10 11 8
> Sat Feb 18 09:48:38 2012 us=616177 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:38 2012 us=616214 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #14 ] [ 8 ]
> Sat Feb 18 09:48:38 2012 us=616285 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #15 ] [ ] pid=12 DATA
> len=100 Sat Feb 18 09:48:38 2012 us=616353 115.170.126.165:4329 ACK output
> sequence broken: [13] 9 10 11 12
> Sat Feb 18 09:48:39 2012 us=62810 MULTI: REAP range 64 -> 80
> Sat Feb 18 09:48:39 2012 us=62949 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:39 2012 us=62979 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #15 ] [ 9 ]
> Sat Feb 18 09:48:39 2012 us=63068 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #16 ] [ ] pid=13 DATA
len=100
> Sat Feb 18 09:48:39 2012 us=63133 115.170.126.165:4329 ACK output sequence
> broken: [14] 13 10 11 12
> Sat Feb 18 09:48:39 2012 us=63173 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:39 2012 us=63200 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #16 ] [ 10 ]
> Sat Feb 18 09:48:39 2012 us=63261 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #17 ] [ ] pid=14 DATA
len=100
> Sat Feb 18 09:48:39 2012 us=63360 115.170.126.165:4329 ACK output sequence
> broken: [15] 13 14 11 12
> Sat Feb 18 09:48:39 2012 us=68919 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:39 2012 us=68968 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #17 ] [ 11 ]
> Sat Feb 18 09:48:39 2012 us=69055 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #18 ] [ ] pid=15 DATA
len=100
> Sat Feb 18 09:48:39 2012 us=69120 115.170.126.165:4329 ACK output sequence
> broken: [16] 13 14 15 12
> Sat Feb 18 09:48:39 2012 us=75178 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:39 2012 us=75222 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #18 ] [ 12 ]
> Sat Feb 18 09:48:39 2012 us=75301 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #19 ] [ ] pid=16 DATA
len=100
> Sat Feb 18 09:48:39 2012 us=75380 115.170.126.165:4329 ACK output sequence
> broken: [17] 13 14 15 16
> Sat Feb 18 09:48:39 2012 us=503066 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:39 2012 us=503117 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #19 ] [ 13 ]
> Sat Feb 18 09:48:39 2012 us=503190 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #20 ] [ ] pid=17 DATA
> len=100 Sat Feb 18 09:48:39 2012 us=503255 115.170.126.165:4329 ACK output
> sequence broken: [18] 17 14 15 16
> Sat Feb 18 09:48:39 2012 us=531981 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:39 2012 us=532026 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #20 ] [ 14 ]
> Sat Feb 18 09:48:39 2012 us=532091 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #21 ] [ ] pid=18 DATA
> len=100 Sat Feb 18 09:48:39 2012 us=532150 115.170.126.165:4329 ACK output
> sequence broken: [19] 17 18 15 16
> Sat Feb 18 09:48:39 2012 us=537523 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:39 2012 us=537571 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #21 ] [ 15 ]
> Sat Feb 18 09:48:39 2012 us=537641 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #22 ] [ ] pid=19 DATA
> len=100 Sat Feb 18 09:48:39 2012 us=537695 115.170.126.165:4329 ACK output
> sequence broken: [20] 17 18 19 16
> Sat Feb 18 09:48:39 2012 us=656224 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:39 2012 us=656266 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #22 ] [ 16 ]
> Sat Feb 18 09:48:39 2012 us=656369 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #23 ] [ ] pid=20 DATA
> len=100 Sat Feb 18 09:48:39 2012 us=656425 115.170.126.165:4329 ACK output
> sequence broken: [21] 17 18 19 20
> Sat Feb 18 09:48:39 2012 us=949945 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:39 2012 us=950029 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #23 ] [ 17 ]
> Sat Feb 18 09:48:39 2012 us=950174 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #24 ] [ ] pid=21 DATA
> len=100 Sat Feb 18 09:48:39 2012 us=950281 115.170.126.165:4329 ACK output
> sequence broken: [22] 21 18 19 20
> Sat Feb 18 09:48:39 2012 us=973921 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:39 2012 us=974001 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #24 ] [ 18 ]
> Sat Feb 18 09:48:39 2012 us=974140 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #25 ] [ ] pid=22 DATA
> len=100 Sat Feb 18 09:48:39 2012 us=974232 115.170.126.165:4329 ACK output
> sequence broken: [23] 21 22 19 20
> Sat Feb 18 09:48:39 2012 us=980127 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:39 2012 us=980189 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #25 ] [ 19 ]
> Sat Feb 18 09:48:39 2012 us=980280 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #26 ] [ ] pid=23 DATA
> len=100 Sat Feb 18 09:48:39 2012 us=980386 115.170.126.165:4329 ACK output
> sequence broken: [24] 21 22 23 20
> Sat Feb 18 09:48:40 2012 us=75020 MULTI: REAP range 80 -> 96
> Sat Feb 18 09:48:40 2012 us=75169 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:40 2012 us=75192 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #26 ] [ 20 ]
> Sat Feb 18 09:48:40 2012 us=75288 115.170.126.165:4329 UDPv4 WRITE [44] to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #27 ] [ ] pid=24 DATA len=2
> Sat Feb 18 09:48:40 2012 us=75366 115.170.126.165:4329 ACK output sequence
> broken: [25] 21 22 23 24
> Sat Feb 18 09:48:40 2012 us=376622 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:40 2012 us=376696 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #27 ] [ 21 ]
> Sat Feb 18 09:48:40 2012 us=390187 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:40 2012 us=390256 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #28 ] [ 22 ]
> Sat Feb 18 09:48:40 2012 us=416828 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:40 2012 us=416895 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #29 ] [ 23 ]
> Sat Feb 18 09:48:40 2012 us=530937 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:40 2012 us=531002 115.170.126.165:4329 UDPv4 READ [154]
> from 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #30 ] [ 24 ] pid=4
DATA
> len=100
> Sat Feb 18 09:48:40 2012 us=531098 115.170.126.165:4329 UDPv4 WRITE [50]
to
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #28 ] [ 4 ]
> Sat Feb 18 09:48:40 2012 us=531169 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:40 2012 us=531188 115.170.126.165:4329 UDPv4 READ [140]
> from 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #31 ] [ ] pid=5 DATA
> len=98
> Sat Feb 18 09:48:40 2012 us=536029 115.170.126.165:4329 UDPv4 WRITE [113]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #29 ] [ 5 ] pid=25 DATA
> len=59
> Sat Feb 18 09:48:40 2012 us=978563 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:40 2012 us=978626 115.170.126.165:4329 UDPv4 READ [154]
> from 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #32 ] [ 25 ] pid=6
DATA
> len=100
> Sat Feb 18 09:48:40 2012 us=978734 115.170.126.165:4329 UDPv4 WRITE [50]
to
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #30 ] [ 6 ]
> Sat Feb 18 09:48:40 2012 us=984188 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:40 2012 us=984222 115.170.126.165:4329 UDPv4 READ [142]
> from 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #33 ] [ ] pid=7 DATA
> len=100
> Sat Feb 18 09:48:40 2012 us=984272 115.170.126.165:4329 UDPv4 WRITE [50]
to
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #31 ] [ 7 ]
> Sat Feb 18 09:48:40 2012 us=990772 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:40 2012 us=990806 115.170.126.165:4329 UDPv4 READ [142]
> from 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #34 ] [ ] pid=8 DATA
> len=100
> Sat Feb 18 09:48:40 2012 us=990860 115.170.126.165:4329 UDPv4 WRITE [50]
to
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #32 ] [ 8 ]
> Sat Feb 18 09:48:40 2012 us=990930 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:40 2012 us=990963 115.170.126.165:4329 UDPv4 READ [120]
> from 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #35 ] [ ] pid=9 DATA
> len=78
> Sat Feb 18 09:48:40 2012 us=991131 115.170.126.165:4329 PLUGIN_CALL: PRE
> type=PLUGIN_AUTH_USER_PASS_VERIFY
> Sat Feb 18 09:48:40 2012 us=991146 115.170.126.165:4329 ARGV[0] =
> '/etc/openvpn/radiusplugin.so'
> Sat Feb 18 09:48:40 2012 us=991156 115.170.126.165:4329 ENVP[0] =
> 'auth_control_file=/tmp/openvpn_acf_2204867bb6d81a2313aeec4c9e057ea5.tmp'
> Sat Feb 18 09:48:40 2012 us=991165 115.170.126.165:4329 ENVP[1] =
> 'untrusted_port=4329'
> Sat Feb 18 09:48:40 2012 us=991174 115.170.126.165:4329 ENVP[2] =
> 'untrusted_ip=115.170.126.165'
> Sat Feb 18 09:48:40 2012 us=991183 115.170.126.165:4329 ENVP[4] =
> 'username=user009 '
> Sat Feb 18 09:48:40 2012 us=991192 115.170.126.165:4329 ENVP[5] =
> 'remote_port_1=443'
> Sat Feb 18 09:48:40 2012 us=991201 115.170.126.165:4329 ENVP[6] =
> 'local_port_1=443'
> Sat Feb 18 09:48:40 2012 us=991210 115.170.126.165:4329 ENVP[7] =
> 'local_1=10x.1xx.xx.xx'
> Sat Feb 18 09:48:40 2012 us=991219 115.170.126.165:4329 ENVP[8] =
> 'proto_1=udp'
> Sat Feb 18 09:48:40 2012 us=991228 115.170.126.165:4329 ENVP[9] =
> 'daemon_pid=2836'
> Sat Feb 18 09:48:40 2012 us=991236 115.170.126.165:4329 ENVP[10] =
> 'daemon_start_time=1329576496'
> Sat Feb 18 09:48:40 2012 us=991246 115.170.126.165:4329 ENVP[11] =
> 'daemon_log_redirect=1'
> Sat Feb 18 09:48:40 2012 us=991255 115.170.126.165:4329 ENVP[12] =
> 'daemon=1'
> Sat Feb 18 09:48:40 2012 us=991281 115.170.126.165:4329 ENVP[13] =
'verb=7'
> Sat Feb 18 09:48:40 2012 us=991292 115.170.126.165:4329 ENVP[14] =
> 'config=server_udp443.conf'
> Sat Feb 18 09:48:40 2012 us=991301 115.170.126.165:4329 ENVP[15] =
> 'ifconfig_local=10.11.0.1'
> Sat Feb 18 09:48:40 2012 us=991336 115.170.126.165:4329 ENVP[16] =
> 'ifconfig_netmask=255.255.0.0'
> Sat Feb 18 09:48:40 2012 us=991346 115.170.126.165:4329 ENVP[17] =
> 'ifconfig_broadcast=10.11.255.255'
> Sat Feb 18 09:48:40 2012 us=991355 115.170.126.165:4329 ENVP[18] =
> 'script_context=init'
> Sat Feb 18 09:48:40 2012 us=991364 115.170.126.165:4329 NOTE: --mute
> triggered...
> at Feb 18 09:48:40 2012 Sat Feb 18 09:48:40 2012 RADIUS-PLUGIN: FOREGROUND
> THREAD: Auth_user_pass_verify thread started.
> RADIUS-PLUGIN: FOREGROUND: OPENVPN_PLUGIN_AUTH_USER_PASS_VERIFY is called.
> Sat Feb 18 09:48:40 2012 RADIUS-PLUGIN: FOREGROUND THREAD: Waiting for new
> user.Sat Feb 18 09:48:40 2012 RADIUS-PLUGIN: FOREGROUND: Commonname set to
> Username
>
> Sat Feb 18 09:48:40 2012 RADIUS-PLUGIN: FOREGROUND: Key:
> 115.170.126.165:4329.
> Sat Feb 18 09:48:40 2012 RADIUS-PLUGIN: FOREGROUND THREAD: New user from
> OpenVPN!
> Sat Feb 18 09:48:40 2012 RADIUS-PLUGIN: FOREGROUND THREAD: New user.
> Sat Feb 18 09:48:40 2012 RADIUS-PLUGIN: FOREGROUND THREAD: New user:
> username: user009 , password: *****, newuser ip: 115.170.126.165, newuser
> port: 4329 .
> Sat Feb 18 09:48:40 2012 RADIUS-PLUGIN: BACKGROUND AUTH: New user auth:
> username: user009 , password: *****, calling station: 115.170.126.165,
> commonname: user009 .
> Sat Feb 18 09:48:40 2012 RADIUS-PLUGIN: radius_server().
> Sat Feb 18 09:48:40 2012 RADIUS-PLUGIN: Build password packet: password:
> *****, sharedSecret: *****.
> Sat Feb 18 09:48:40 2012 RADIUS-PLUGIN: Send packet to rad.server.com.
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: Get ACCESS_ACCEPT-Packet.
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: parse_response_packet().
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: BACKGROUND AUTH: routes: .
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: BACKGROUND AUTH: framed ip: .
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: BACKGROUND AUTH: Acct Interim
> Interval: 60.
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: Client config file was not
written,
> overwriteccfiles is false
> .Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: BACKGROUND AUTH: Auth succeeded
in
> radius_server().
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: FOREGROUND THREAD: Authentication
> succeeded!
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: FOREGROUND THREAD: Received routes
> for user: .
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: FOREGROUND THREAD: Received framed
> ip for user: .
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: FOREGROUND THREAD: Receive
> acctinteriminterval 60 sec from backgroundprocess.
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: FOREGROUND THREAD: Add user to
map.
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: FOREGROUND THREAD: Waiting for new
> user.
> Sat Feb 18 09:48:41 2012 us=344335 115.170.126.165:4329 3 variation(s) on
> previous 20 message(s) suppressed by --mute
> Sat Feb 18 09:48:41 2012 us=344369 115.170.126.165:4329 PLUGIN_CALL: POST
> /etc/openvpn/radiusplugin.so/PLUGIN_AUTH_USER_PASS_VERIFY status=0
> Sat Feb 18 09:48:41 2012 us=344488 115.170.126.165:4329 TLS:
> Username/Password authentication succeeded for username 'user009_' [CN
SET]
> Sat Feb 18 09:48:41 2012 us=344590 115.170.126.165:4329 Client pre_master:
> e566fa4a 31c6fe1f 1c949156 2b577827 e50e8422 8f977386 0252fbcb 72400070
> f606e9f0 e03207aa 0c2c79c9 e71a9076
> Sat Feb 18 09:48:41 2012 us=344620 115.170.126.165:4329 Client random1:
> 0ed9928e b04841f4 41dd2b83 cdaeb9fe 8e0a5b83 bee28e7f 671a4232 7d11b6aa
> Sat Feb 18 09:48:41 2012 us=344646 115.170.126.165:4329 Client random2:
> 8e7f5749 119ee55f 6dbac34d 68b3fbf6 0ef273b3 f4fe8ce8 847fa1b9 ef4552a2
> Sat Feb 18 09:48:41 2012 us=344679 115.170.126.165:4329 Server pre_master:
> 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> 00000000 00000000 00000000 00000000
> Sat Feb 18 09:48:41 2012 us=344706 115.170.126.165:4329 Server random1:
> 465f081c 73825a3d f0bc92c9 e59d0281 e5075fac 7dfa258f 65818f3f 5ab5e2c9
> Sat Feb 18 09:48:41 2012 us=344731 115.170.126.165:4329 Server random2:
> 0f67acf1 ee3289a9 669e107a 6dac259d c2761f1d 8b0dcb5b 99153fcb 9cc839df
> Sat Feb 18 09:48:41 2012 us=344757 115.170.126.165:4329 tls1_P_hash sec:
> e566fa4a 31c6fe1f 1c949156 2b577827 e50e8422 8f977386
> Sat Feb 18 09:48:41 2012 us=344802 115.170.126.165:4329 tls1_P_hash seed:
> 4f70656e 56504e20 6d617374 65722073 65637265 740ed992 8eb04841 f441dd2b
> 83cdaeb9 fe8e0a5b 83bee28e 7f671a42 327d11b6 aa465f08 1c73825a 3df0bc92
> c9e59d02 81e5075f ac7dfa25 8f65818f 3f5ab5e2 c9
> Sat Feb 18 09:48:41 2012 us=344853 115.170.126.165:4329 tls1_P_hash out:
> bc865580 728f4766 efed4b08 f67d32fb 54c4dc4d c17c5ab9 c31d5161 aabd553f
> ecd5a77c d25006ce ae9f06ae 4934c7b6
> Sat Feb 18 09:48:41 2012 us=344877 115.170.126.165:4329 tls1_P_hash sec:
> 0252fbcb 72400070 f606e9f0 e03207aa 0c2c79c9 e71a9076
> Sat Feb 18 09:48:41 2012 us=344939 115.170.126.165:4329 tls1_P_hash seed:
> 4f70656e 56504e20 6d617374 65722073 65637265 740ed992 8eb04841 f441dd2b
> 83cdaeb9 fe8e0a5b 83bee28e 7f671a42 327d11b6 aa465f08 1c73825a 3df0bc92
> c9e59d02 81e5075f ac7dfa25 8f65818f 3f5ab5e2 c9
> Sat Feb 18 09:48:41 2012 us=345001 115.170.126.165:4329 tls1_P_hash out:
> da048c39 7afde405 92c463a4 aefcebb4 ecab3fd7 fa8f07c3 8eed2498 728526ad
> af1a29db 0a877a40 0db29387 a6002176
> Sat Feb 18 09:48:41 2012 us=345037 115.170.126.165:4329 tls1_PRF out[48]:
> 6682d9b9 0872a363 7d2928ac 5881d94f b86fe39a 3bf35d7a 4df075f9 d8387392
> 43cf8ea7 d8d77c8e a32d9529 ef34e6c0
> Sat Feb 18 09:48:41 2012 us=345062 115.170.126.165:4329 tls1_P_hash sec:
> 6682d9b9 0872a363 7d2928ac 5881d94f b86fe39a 3bf35d7a
> Sat Feb 18 09:48:41 2012 us=345112 115.170.126.165:4329 tls1_P_hash seed:
> 4f70656e 56504e20 6b657920 65787061 6e73696f 6e8e7f57 49119ee5 5f6dbac3
> 4d68b3fb f60ef273 b3f4fe8c e8847fa1 b9ef4552 a20f67ac f1ee3289 a9669e10
> 7a6dac25 9dc2761f 1d8b0dcb 5b99153f cb9cc839 df38c928 66a74852 3b043916
> eeb2d459 90
> Sat Feb 18 09:48:41 2012 us=345263 115.170.126.165:4329 tls1_P_hash out:
> e4c39cee 083be89e 0d1701af 010f2f4e 477db1ce 9774fa67 a6a5e899 b9cbf3ca
> 5aef6012 94d62d51 f73884c5 6529f739 16c80be3 f3743b97 7e644245 6fa8572f
> 80d1ef99 d8578193 2e0c0c95 153e4254 a87bb31e 3419bedb 1ac3ffd7 a78a816c
> 6fe4f5c2 e11b76ca e5ea0fa2 8a5fdc72 c5a44fc6 5a220d45 0242c14d 2893ffe2
> 48b62152 31cd886c dbcae09b f118ea4f 11c87c9f 5d0330b0 07491dd3 c4508ed0
> ee290d4c aaa989fe defb9e4f 2dba02ed a32cd437 e6be5284 01a8c2a5 66c47ef2
> 767e89b3 afda624b 1f559dd9 d0eb30f7 d7ef8a03 a76d532a f5ecfb55 99b0117b
> 28e9b6bc d00c0e7d d61dc356 981acf40 1828323f 4acd8f23 d4d101b7 8487fd7a
> Sat Feb 18 09:48:41 2012 us=345302 115.170.126.165:4329 tls1_P_hash sec:
> 4df075f9 d8387392 43cf8ea7 d8d77c8e a32d9529 ef34e6c0
> Sat Feb 18 09:48:41 2012 us=345376 115.170.126.165:4329 tls1_P_hash seed:
> 4f70656e 56504e20 6b657920 65787061 6e73696f 6e8e7f57 49119ee5 5f6dbac3
> 4d68b3fb f60ef273 b3f4fe8c e8847fa1 b9ef4552 a20f67ac f1ee3289 a9669e10
> 7a6dac25 9dc2761f 1d8b0dcb 5b99153f cb9cc839 df38c928 66a74852 3b043916
> eeb2d459 90
> Sat Feb 18 09:48:41 2012 us=345533 115.170.126.165:4329 tls1_P_hash out:
> 9b16e898 becf3fb2 d0020a8e 1522e94e f18f5f35 edf8f90f cc243473 53b209b4
> 51deaa29 03ba92a7 6cb8b8bd 4ac5c30a fd75a54b fff63ef0 8659f60a 392fd315
> 0ab78440 ed1e1862 9ea6fa85 9a8518e5 59b74495 38b67bd0 7f70e688 a76e76d5
> b36f2559 42f169d8 6d00e272 adea3c95 1d85efe8 8045833d d3e9c37f eda16d53
> d511699b 50e779ba 47e86484 2d92a8bb 40b7b5e4 a0dfab81 ea64fe78 111940da
> 751a11f9 add3e494 d317b72a 03ffd7f9 8d6a1b5f a8afe41a e96e9a7c 0618514a
> fbf4194d f06602e2 287cb4f3 23e81c69 09a46f50 1b25466e 35ec20c0 efbf92a6
> 54c862bc bd58bc38 54347529 840e0e47 3f12795d 349fd33e 19c0da2d bf755694
> Sat Feb 18 09:48:41 2012 us=345666 115.170.126.165:4329 tls1_PRF out[256]:
> 7fd57476 b6f4d72c dd150b21 142dc600 b6f2eefb 7a8c0368 6a81dcea ea79fa7e
> 0b31ca3b 976cbff6 9b803c78 2fec3433 ebbdaea8 0c820567 f83db44f 5687843a
> 8a666bd9 354999f1 b0aaf610 8fbb5ab1 f1ccf78b 0cafc50b 65b3195f 00e4f7b9
> dc8bd09b a3ea1f12 88eaedd0 27b5e0e7 d821a02e da678e78 d1ab0232 c53292b1
> 9da748c9 612af1d6 9c22841f dc8a42f4 517fc97b fddc9b31 ed2de3ab d549ce0a
> 9b331cb5 077a6d6a 0dec2965 2e45d514 2e46cf68 4e11b69e e8c658d9 60dc2fb8
> 8d8a90fe 5fbc60a9 3729292a f3032c9e de4be553 bc481544 c000db95 760f83dd
> 7c21d400 6d54b245 8229b67f 1c14c107 273a4b62 7e525c1d cd11db9a 3bf2abee
> Sat Feb 18 09:48:41 2012 us=345692 115.170.126.165:4329 NOTE: --mute
> triggered...
> Sat Feb 18 09:48:41 2012 us=345735 115.170.126.165:4329 8 variation(s) on
> previous 20 message(s) suppressed by --mute
> Sat Feb 18 09:48:41 2012 us=345763 115.170.126.165:4329 Data Channel
> Encrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
> Sat Feb 18 09:48:41 2012 us=345797 115.170.126.165:4329 Data Channel
> Encrypt: CIPHER KEY: 9da748c9 612af1d6 9c22841f dc8a42f4
> Sat Feb 18 09:48:41 2012 us=345816 115.170.126.165:4329 Data Channel
> Encrypt: CIPHER block_size=16 iv_size=16
> Sat Feb 18 09:48:41 2012 us=345836 115.170.126.165:4329 Data Channel
> Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
> Sat Feb 18 09:48:41 2012 us=345858 115.170.126.165:4329 Data Channel
> Encrypt: HMAC KEY: 8d8a90fe 5fbc60a9 3729292a f3032c9e de4be553
> Sat Feb 18 09:48:41 2012 us=345873 115.170.126.165:4329 Data Channel
> Encrypt: HMAC size=20 block_size=64
> Sat Feb 18 09:48:41 2012 us=345893 115.170.126.165:4329 Data Channel
> Decrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
> Sat Feb 18 09:48:41 2012 us=345926 115.170.126.165:4329 Data Channel
> Decrypt: CIPHER KEY: 7fd57476 b6f4d72c dd150b21 142dc600
> Sat Feb 18 09:48:41 2012 us=345943 115.170.126.165:4329 Data Channel
> Decrypt: CIPHER block_size=16 iv_size=16
> Sat Feb 18 09:48:41 2012 us=345962 115.170.126.165:4329 Data Channel
> Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
> Sat Feb 18 09:48:41 2012 us=345984 115.170.126.165:4329 Data Channel
> Decrypt: HMAC KEY: 8a666bd9 354999f1 b0aaf610 8fbb5ab1 f1ccf78b
> Sat Feb 18 09:48:41 2012 us=345998 115.170.126.165:4329 Data Channel
> Decrypt: HMAC size=20 block_size=64
> Sat Feb 18 09:48:41 2012 us=346100 MULTI: REAP range 96 -> 112
> Sat Feb 18 09:48:41 2012 us=346211 115.170.126.165:4329 UDPv4 WRITE [154]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #33 ] [ 9 ] pid=26 DATA
> len=100
> Sat Feb 18 09:48:41 2012 us=346304 115.170.126.165:4329 UDPv4 WRITE [142]
to
> 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #34 ] [ ] pid=27 DATA
> len=100 Sat Feb 18 09:48:41 2012 us=346419 115.170.126.165:4329 UDPv4
WRITE
> [142] to 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #35 ] [ ] pid=28
> DATA len=100 Sat Feb 18 09:48:41 2012 us=346494 115.170.126.165:4329 UDPv4
> WRITE [56] to 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #36 ] [ ]
> pid=29 DATA len=14 Sat Feb 18 09:48:41 2012 us=346537 115.170.126.165:4329
> ACK output sequence broken: [30] 26 27 28 29
> Sat Feb 18 09:48:41 2012 us=777309 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:41 2012 us=777409 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #36 ] [ 26 ]
> Sat Feb 18 09:48:41 2012 us=777489 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:41 2012 us=777515 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #37 ] [ 27 ]
> Sat Feb 18 09:48:41 2012 us=804887 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:41 2012 us=804962 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #38 ] [ 28 ]
> Sat Feb 18 09:48:41 2012 us=805052 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:41 2012 us=805088 115.170.126.165:4329 UDPv4 READ [50]
from
> 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #39 ] [ 29 ]
> Sat Feb 18 09:48:41 2012 us=805120 115.170.126.165:4329 Control Channel:
> TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA
> Sat Feb 18 09:48:41 2012 us=805155 115.170.126.165:4329 [user009_] Peer
> Connection Initiated with 115.170.126.165:4329
> Sat Feb 18 09:48:41 2012 us=805341 user009_/115.170.126.165:4329
> PLUGIN_CALL: PRE type=PLUGIN_CLIENT_CONNECT
> Sat Feb 18 09:48:41 2012 us=805362 user009_/115.170.126.165:4329 ARGV[0] =
> '/etc/openvpn/radiusplugin.so'
> Sat Feb 18 09:48:41 2012 us=805377 user009_/115.170.126.165:4329 ARGV[1] =
> '/tmp/openvpn_cc_8659a7c6a31ef8b06db64fa1059e15dd.tmp'
> Sat Feb 18 09:48:41 2012 us=805391 user009_/115.170.126.165:4329 ENVP[0] =
> 'time_unix=1329576517'
> Sat Feb 18 09:48:41 2012 us=805405 user009_/115.170.126.165:4329 ENVP[1] =
> 'time_ascii=Sat Feb 18 09:48:37 2012'
> Sat Feb 18 09:48:41 2012 us=805422 user009_/115.170.126.165:4329 ENVP[2] =
> 'ifconfig_pool_netmask=255.255.0.0'
> Sat Feb 18 09:48:41 2012 us=805445 user009_/115.170.126.165:4329 ENVP[3] =
> 'ifconfig_pool_remote_ip=10.11.0.2'
> Sat Feb 18 09:48:41 2012 us=805466 user009_/115.170.126.165:4329 ENVP[4] =
> 'trusted_port=4329'
> Sat Feb 18 09:48:41 2012 us=805482 user009_/115.170.126.165:4329 ENVP[5] =
> 'trusted_ip=115.170.126.165'
> Sat Feb 18 09:48:41 2012 us=805496 user009_/115.170.126.165:4329 ENVP[6] =
> 'common_name=user009_'
> Sat Feb 18 09:48:41 2012 us=805510 user009_/115.170.126.165:4329 ENVP[7] =
> 'username=user009_'
> Sat Feb 18 09:48:41 2012 us=805524 user009_/115.170.126.165:4329 ENVP[8] =
> 'auth_control_file=/tmp/openvpn_acf_2204867bb6d81a2313aeec4c9e057ea5.tmp'
> Sat Feb 18 09:48:41 2012 us=805538 user009_/115.170.126.165:4329 ENVP[9] =
> 'untrusted_port=4329'
> Sat Feb 18 09:48:41 2012 us=805560 user009_/115.170.126.165:4329 ENVP[10]
=
> 'untrusted_ip=115.170.126.165'
> Sat Feb 18 09:48:41 2012 us=805582 user009_/115.170.126.165:4329 ENVP[11]
=
> 'remote_port_1=443'
> Sat Feb 18 09:48:41 2012 us=805604 user009_/115.170.126.165:4329 ENVP[12]
=
> 'local_port_1=443'
> Sat Feb 18 09:48:41 2012 us=805626 user009_/115.170.126.165:4329 ENVP[13]
=
> 'local_1=10x.1xx.xx.xx'
> Sat Feb 18 09:48:41 2012 us=805647 user009_/115.170.126.165:4329 ENVP[14]
=
> 'proto_1=udp'
> Sat Feb 18 09:48:41 2012 us=805669 user009_/115.170.126.165:4329 ENVP[15]
=
> 'daemon_pid=2836'
> Sat Feb 18 09:48:41 2012 us=805689 user009_/115.170.126.165:4329 ENVP[16]
=
> 'daemon_start_time=1329576496'
> Sat Feb 18 09:48:41 2012 us=805703 user009_/115.170.126.165:4329 NOTE:
> --mute triggered...
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: FOREGROUND:
> OPENVPN_PLUGIN_CLIENT_CONNECT is called.
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: FOREGROUND: Commonname set to
> Username
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: FOREGROUND: Key:
> 115.170.126.165:4329.
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: FOREGROUND: Set FramedIP to the IP
> (10.11.0.2) OpenVPN assigned to the user user009
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: FOREGROUND: Add user for
accounting:
> username: user009 , commonname: user009
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: BACKGROUND ACCT: Get a command.
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: BACKGROUND ACCT: New User.
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: BACKGROUND ACCT: New user acct:
> username: user009 , interval: 60, calling station: 115.170.126.165,
> commonname: user009 , framed ip: 10.11.0.2.
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: BACKGROUND-ACCT: Get
> ACCOUNTING_RESPONSE-Packet.
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: BACKGROUND ACCT: Start packet was
> send.
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: BACKGROUND ACCT: User was added to
> accounting scheduler.
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: BACKGROUND-ACCT: No routes for
> user.
> Sat Feb 18 09:48:41 2012 RADIUS-PLUGIN: FOREGROUND: Accounting succeeded!
> Sat Feb 18 09:48:41 2012 us=945433 user009_/115.170.126.165:4329 11
> variation(s) on previous 20 message(s) suppressed by --mute
> Sat Feb 18 09:48:41 2012 us=945453 user009_/115.170.126.165:4329
> PLUGIN_CALL: POST /etc/openvpn/radiusplugin.so/PLUGIN_CLIENT_CONNECT
> status=0
> Sat Feb 18 09:48:41 2012 us=945498 user009_/115.170.126.165:4329 TEST FILE
> '/tmp/openvpn_cc_8659a7c6a31ef8b06db64fa1059e15dd.tmp' [1]
> Sat Feb 18 09:48:41 2012 us=945528 user009_/115.170.126.165:4329 OPTIONS
> IMPORT: reading client specific options from:
> /tmp/openvpn_cc_8659a7c6a31ef8b06db64fa1059e15dd.tmp
> Sat Feb 18 09:48:41 2012 us=945668 user009_/115.170.126.165:4329 MULTI:
> Learn: 10.11.0.2 -> user009_/115.170.126.165:4329
> Sat Feb 18 09:48:41 2012 us=945709 user009_/115.170.126.165:4329 MULTI:
> primary virtual IP for user009_/115.170.126.165:4329: 10.11.0.2
> Sat Feb 18 09:48:43 2012 us=152091 MULTI: REAP range 112 -> 128
> Sat Feb 18 09:48:44 2012 us=10923 MULTI: REAP range 128 -> 144
> Sat Feb 18 09:48:44 2012 us=11053 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:44 2012 us=11086 user009_/115.170.126.165:4329 UDPv4 READ
> [132] from 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #40 ] [ ] pid=10
> DATA len=90
> Sat Feb 18 09:48:44 2012 us=11192 user009_/115.170.126.165:4329 PUSH:
> Received control message: 'PUSH_REQUEST'
> Sat Feb 18 09:48:44 2012 us=11235 user009_/115.170.126.165:4329 SENT
CONTROL
> [user009_]: 'PUSH_REPLY,route-metric 1,dhcp-option DOMAIN
> localhost,dhcp-option DNS 10.2.0.1,dhcp-option DNS 10.3.0.1,sndbuf
> 1000000,rcvbuf 1000000,show-net-up,explicit-exit-notify 2,route-gateway
> 10.11.0.1,topology subnet,ping 10,ping-restart 600,ifconfig 10.11.0.2
> 255.255.0.0' (status=1)
> Sat Feb 18 09:48:44 2012 us=11263 user009_/115.170.126.165:4329 UDPv4
WRITE
> [50] to 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #37 ] [ 10 ]
> Sat Feb 18 09:48:44 2012 us=11455 user009_/115.170.126.165:4329 UDPv4
WRITE
> [142] to 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #38 ] [ ] pid=30
> DATA len=100
> Sat Feb 18 09:48:44 2012 us=11507 user009_/115.170.126.165:4329 UDPv4
WRITE
> [142] to 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #39 ] [ ] pid=31
> DATA len=100
> Sat Feb 18 09:48:44 2012 us=11552 user009_/115.170.126.165:4329 UDPv4
WRITE
> [142] to 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #40 ] [ ] pid=32
> DATA len=100
> Sat Feb 18 09:48:44 2012 us=11599 user009_/115.170.126.165:4329 UDPv4
WRITE
> [72] to 115.170.126.165:4329: P_CONTROL_V1 kid=0 pid=[ #41 ] [ ] pid=33
DATA
> len=30
> Sat Feb 18 09:48:44 2012 us=11629 user009_/115.170.126.165:4329 ACK output
> sequence broken: [34] 30 31 32 33
> Sat Feb 18 09:48:44 2012 us=472497 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:44 2012 us=472554 user009_/115.170.126.165:4329 UDPv4
READ
> [50] from 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #41 ] [ 30 ]
> Sat Feb 18 09:48:44 2012 us=472630 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:44 2012 us=472647 user009_/115.170.126.165:4329 UDPv4
READ
> [50] from 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #42 ] [ 32 ]
> Sat Feb 18 09:48:44 2012 us=478303 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:44 2012 us=478388 user009_/115.170.126.165:4329 UDPv4
READ
> [50] from 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #43 ] [ 31 ]
> Sat Feb 18 09:48:44 2012 us=508113 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:44 2012 us=508179 user009_/115.170.126.165:4329 UDPv4
READ
> [50] from 115.170.126.165:4329: P_ACK_V1 kid=0 pid=[ #44 ] [ 33 ]
> Sat Feb 18 09:48:48 2012 us=717556 MULTI: REAP range 144 -> 160
> Sat Feb 18 09:48:50 2012 us=727113 MULTI: REAP range 160 -> 176
> Sat Feb 18 09:48:50 2012 us=727231 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:50 2012 us=727249 user009_/115.170.126.165:4329 UDPv4
READ
> [101] from 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
> Sat Feb 18 09:48:50 2012 us=727262 user009_/115.170.126.165:4329 TLS:
> tls_pre_decrypt, key_id=0, IP=115.170.126.165:4329
> Sat Feb 18 09:48:50 2012 us=727289 user009_/115.170.126.165:4329 FRAG_IN
> buf->len=53 type=FRAG_WHOLE flags=0x00000000
> Sat Feb 18 09:48:50 2012 us=727339 user009_/115.170.126.165:4329 GET INST
BY
> VIRT: 10.11.0.2 -> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:50 2012 us=727366 user009_/115.170.126.165:4329 MSS: 1348
> -> 1198
> Sat Feb 18 09:48:50 2012 us=727378 user009_/115.170.126.165:4329 TUN WRITE
> [52]
> Sat Feb 18 09:48:50 2012 us=837013 GET INST BY VIRT: 10.11.0.2 ->
> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:50 2012 us=837071 user009_/115.170.126.165:4329 TUN READ
> [52]
> Sat Feb 18 09:48:50 2012 us=837085 user009_/115.170.126.165:4329 MSS: 1460
> -> 1198
> Sat Feb 18 09:48:50 2012 us=837098 user009_/115.170.126.165:4329 FRAG_OUT
> len=53 type=0 seq_id=0 frag_id=0 frag_size=0 flags=0x00000000
> Sat Feb 18 09:48:50 2012 us=837109 user009_/115.170.126.165:4329 TLS:
> tls_pre_encrypt: key_id=0
> Sat Feb 18 09:48:50 2012 us=837163 user009_/115.170.126.165:4329 UDPv4
WRITE
> [101] to 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
> Sat Feb 18 09:48:50 2012 us=911887 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:50 2012 us=911953 user009_/115.170.126.165:4329 UDPv4
READ
> [165] from 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=164
> Sat Feb 18 09:48:50 2012 us=911970 user009_/115.170.126.165:4329 TLS:
> tls_pre_decrypt, key_id=0, IP=115.170.126.165:4329
> Sat Feb 18 09:48:50 2012 us=912006 user009_/115.170.126.165:4329 FRAG_IN
> buf->len=107 type=FRAG_WHOLE flags=0x00000000
> Sat Feb 18 09:48:50 2012 us=912026 user009_/115.170.126.165:4329 GET INST
BY
> VIRT: 10.11.0.2 -> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:50 2012 us=912050 user009_/115.170.126.165:4329 TUN WRITE
> [106]
> Sat Feb 18 09:48:51 2012 us=270087 MULTI: REAP range 176 -> 192
> Sat Feb 18 09:48:51 2012 us=270251 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:51 2012 us=270276 user009_/115.170.126.165:4329 UDPv4
READ
> [101] from 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
> Sat Feb 18 09:48:51 2012 us=270297 user009_/115.170.126.165:4329 TLS:
> tls_pre_decrypt, key_id=0, IP=115.170.126.165:4329
> Sat Feb 18 09:48:51 2012 us=270373 user009_/115.170.126.165:4329 FRAG_IN
> buf->len=41 type=FRAG_WHOLE flags=0x00000000
> Sat Feb 18 09:48:51 2012 us=270402 user009_/115.170.126.165:4329 GET INST
BY
> VIRT: 10.11.0.2 -> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:51 2012 us=270436 user009_/115.170.126.165:4329 TUN WRITE
> [40]
> Sat Feb 18 09:48:51 2012 us=311399 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:51 2012 us=311519 user009_/115.170.126.165:4329 UDPv4
READ
> [197] from 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=196
> Sat Feb 18 09:48:51 2012 us=311554 user009_/115.170.126.165:4329 TLS:
> tls_pre_decrypt, key_id=0, IP=115.170.126.165:4329
> Sat Feb 18 09:48:51 2012 us=311616 user009_/115.170.126.165:4329 FRAG_IN
> buf->len=150 type=FRAG_WHOLE flags=0x00000000
> Sat Feb 18 09:48:51 2012 us=311660 user009_/115.170.126.165:4329 GET INST
BY
> VIRT: 10.11.0.2 -> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:51 2012 us=311709 user009_/115.170.126.165:4329 TUN WRITE
> [149]
> Sat Feb 18 09:48:51 2012 us=421178 GET INST BY VIRT: 10.11.0.2 ->
> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:51 2012 us=421262 user009_/115.170.126.165:4329 TUN READ
> [40]
> Sat Feb 18 09:48:51 2012 us=421283 user009_/115.170.126.165:4329 FRAG_OUT
> len=41 type=0 seq_id=0 frag_id=0 frag_size=0 flags=0x00000000
> Sat Feb 18 09:48:51 2012 us=421299 user009_/115.170.126.165:4329 TLS:
> tls_pre_encrypt: key_id=0
> Sat Feb 18 09:48:51 2012 us=421373 user009_/115.170.126.165:4329 UDPv4
WRITE
> [101] to 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
> Sat Feb 18 09:48:51 2012 us=423314 GET INST BY VIRT: 10.11.0.2 ->
> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:51 2012 us=423348 user009_/115.170.126.165:4329 TUN READ
> [1238]
> Sat Feb 18 09:48:51 2012 us=423853 user009_/115.170.126.165:4329 FRAG_OUT
> len=1101 type=0 seq_id=0 frag_id=0 frag_size=0 flags=0x00000000
> Sat Feb 18 09:48:51 2012 us=423875 user009_/115.170.126.165:4329 TLS:
> tls_pre_encrypt: key_id=0
> Sat Feb 18 09:48:51 2012 us=423953 user009_/115.170.126.165:4329 UDPv4
WRITE
> [1157] to 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=1156
> Sat Feb 18 09:48:51 2012 us=424016 GET INST BY VIRT: 10.11.0.2 ->
> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:51 2012 us=424034 user009_/115.170.126.165:4329 TUN READ
> [1179]
> Sat Feb 18 09:48:51 2012 us=424081 user009_/115.170.126.165:4329 FRAG_OUT
> len=1104 type=0 seq_id=0 frag_id=0 frag_size=0 flags=0x00000000
> Sat Feb 18 09:48:51 2012 us=424105 user009_/115.170.126.165:4329 TLS:
> tls_pre_encrypt: key_id=0
> Sat Feb 18 09:48:51 2012 us=424178 user009_/115.170.126.165:4329 UDPv4
WRITE
> [1157] to 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=1156
> Sat Feb 18 09:48:51 2012 us=609566 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:51 2012 us=609604 user009_/115.170.126.165:4329 UDPv4
READ
> [101] from 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
> Sat Feb 18 09:48:51 2012 us=609619 user009_/115.170.126.165:4329 TLS:
> tls_pre_decrypt, key_id=0, IP=115.170.126.165:4329
> Sat Feb 18 09:48:51 2012 us=609644 user009_/115.170.126.165:4329 FRAG_IN
> buf->len=53 type=FRAG_WHOLE flags=0x00000000
> Sat Feb 18 09:48:51 2012 us=609674 user009_/115.170.126.165:4329 GET INST
BY
> VIRT: 10.11.0.2 -> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:51 2012 us=609704 user009_/115.170.126.165:4329 MSS: 1348
> -> 1198
> Sat Feb 18 09:48:51 2012 us=609726 user009_/115.170.126.165:4329 TUN WRITE
> [52]
> Sat Feb 18 09:48:51 2012 us=878133 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:51 2012 us=878181 user009_/115.170.126.165:4329 UDPv4
READ
> [101] from 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
> Sat Feb 18 09:48:51 2012 us=878201 user009_/115.170.126.165:4329 TLS:
> tls_pre_decrypt, key_id=0, IP=115.170.126.165:4329
> Sat Feb 18 09:48:51 2012 us=878225 user009_/115.170.126.165:4329 FRAG_IN
> buf->len=41 type=FRAG_WHOLE flags=0x00000000
> Sat Feb 18 09:48:51 2012 us=878243 user009_/115.170.126.165:4329 GET INST
BY
> VIRT: 10.11.0.2 -> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:51 2012 us=878264 user009_/115.170.126.165:4329 TUN WRITE
> [40]
> Sat Feb 18 09:48:51 2012 us=919433 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:51 2012 us=919495 user009_/115.170.126.165:4329 UDPv4
READ
> [405] from 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=404
> Sat Feb 18 09:48:51 2012 us=919517 user009_/115.170.126.165:4329 TLS:
> tls_pre_decrypt, key_id=0, IP=115.170.126.165:4329
> Sat Feb 18 09:48:51 2012 us=919565 user009_/115.170.126.165:4329 FRAG_IN
> buf->len=359 type=FRAG_WHOLE flags=0x00000000
> Sat Feb 18 09:48:51 2012 us=919600 user009_/115.170.126.165:4329 GET INST
BY
> VIRT: 10.11.0.2 -> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:51 2012 us=919638 user009_/115.170.126.165:4329 TUN WRITE
> [358]
> Sat Feb 18 09:48:52 2012 us=47100 MULTI: REAP range 192 -> 208
> Sat Feb 18 09:48:52 2012 us=47224 GET INST BY VIRT: 10.11.0.2 ->
> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:52 2012 us=47237 user009_/115.170.126.165:4329 TUN READ
> [91]
> Sat Feb 18 09:48:52 2012 us=47251 user009_/115.170.126.165:4329 FRAG_OUT
> len=92 type=0 seq_id=0 frag_id=0 frag_size=0 flags=0x00000000
> Sat Feb 18 09:48:52 2012 us=47283 user009_/115.170.126.165:4329 TLS:
> tls_pre_encrypt: key_id=0
> Sat Feb 18 09:48:52 2012 us=47340 user009_/115.170.126.165:4329 UDPv4
WRITE
> [149] to 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=148
> Sat Feb 18 09:48:52 2012 us=571872 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:52 2012 us=571932 user009_/115.170.126.165:4329 UDPv4
READ
> [389] from 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=388
> Sat Feb 18 09:48:52 2012 us=571949 user009_/115.170.126.165:4329 TLS:
> tls_pre_decrypt, key_id=0, IP=115.170.126.165:4329
> Sat Feb 18 09:48:52 2012 us=571984 user009_/115.170.126.165:4329 FRAG_IN
> buf->len=342 type=FRAG_WHOLE flags=0x00000000
> Sat Feb 18 09:48:52 2012 us=572004 user009_/115.170.126.165:4329 GET INST
BY
> VIRT: 10.11.0.2 -> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:52 2012 us=572028 user009_/115.170.126.165:4329 TUN WRITE
> [341]
> Sat Feb 18 09:48:52 2012 us=721069 GET INST BY VIRT: 10.11.0.2 ->
> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:52 2012 us=721111 user009_/115.170.126.165:4329 TUN READ
> [40]
> Sat Feb 18 09:48:52 2012 us=721133 user009_/115.170.126.165:4329 FRAG_OUT
> len=41 type=0 seq_id=0 frag_id=0 frag_size=0 flags=0x00000000
> Sat Feb 18 09:48:52 2012 us=721150 user009_/115.170.126.165:4329 TLS:
> tls_pre_encrypt: key_id=0
> Sat Feb 18 09:48:52 2012 us=721206 user009_/115.170.126.165:4329 UDPv4
WRITE
> [101] to 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
> Sat Feb 18 09:48:53 2012 us=245341 MULTI: REAP range 208 -> 224
> Sat Feb 18 09:48:53 2012 us=245579 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:53 2012 us=245607 user009_/115.170.126.165:4329 UDPv4
READ
> [501] from 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=500
> Sat Feb 18 09:48:53 2012 us=245627 user009_/115.170.126.165:4329 TLS:
> tls_pre_decrypt, key_id=0, IP=115.170.126.165:4329
> Sat Feb 18 09:48:53 2012 us=245671 user009_/115.170.126.165:4329 FRAG_IN
> buf->len=454 type=FRAG_WHOLE flags=0x00000000
> Sat Feb 18 09:48:53 2012 us=245702 user009_/115.170.126.165:4329 GET INST
BY
> VIRT: 10.11.0.2 -> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:53 2012 us=245749 user009_/115.170.126.165:4329 TUN WRITE
> [453]
> Sat Feb 18 09:48:53 2012 us=355148 GET INST BY VIRT: 10.11.0.2 ->
> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:53 2012 us=355189 user009_/115.170.126.165:4329 TUN READ
> [40]
> Sat Feb 18 09:48:53 2012 us=355210 user009_/115.170.126.165:4329 FRAG_OUT
> len=41 type=0 seq_id=0 frag_id=0 frag_size=0 flags=0x00000000
> Sat Feb 18 09:48:53 2012 us=355228 user009_/115.170.126.165:4329 TLS:
> tls_pre_encrypt: key_id=0
> Sat Feb 18 09:48:53 2012 us=355282 user009_/115.170.126.165:4329 UDPv4
WRITE
> [101] to 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
> Sat Feb 18 09:48:53 2012 us=620250 GET INST BY VIRT: 10.11.0.2 ->
> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:53 2012 us=620292 user009_/115.170.126.165:4329 TUN READ
> [541]
> Sat Feb 18 09:48:53 2012 us=620344 user009_/115.170.126.165:4329 FRAG_OUT
> len=542 type=0 seq_id=0 frag_id=0 frag_size=0 flags=0x00000000
> Sat Feb 18 09:48:53 2012 us=620358 user009_/115.170.126.165:4329 TLS:
> tls_pre_encrypt: key_id=0
> Sat Feb 18 09:48:53 2012 us=620406 user009_/115.170.126.165:4329 UDPv4
WRITE
> [597] to 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=596
> Sat Feb 18 09:48:53 2012 us=620468 GET INST BY VIRT: 10.11.0.2 ->
> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:53 2012 us=620490 user009_/115.170.126.165:4329 TUN READ
> [40]
> Sat Feb 18 09:48:53 2012 us=620502 user009_/115.170.126.165:4329 FRAG_OUT
> len=41 type=0 seq_id=0 frag_id=0 frag_size=0 flags=0x00000000
> Sat Feb 18 09:48:53 2012 us=620511 user009_/115.170.126.165:4329 TLS:
> tls_pre_encrypt: key_id=0
> Sat Feb 18 09:48:53 2012 us=620536 user009_/115.170.126.165:4329 UDPv4
WRITE
> [101] to 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
> Sat Feb 18 09:48:54 2012 us=76410 MULTI: REAP range 224 -> 240
> Sat Feb 18 09:48:54 2012 us=76630 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:54 2012 us=76702 user009_/115.170.126.165:4329 UDPv4 READ
> [101] from 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
> Sat Feb 18 09:48:54 2012 us=76734 user009_/115.170.126.165:4329 TLS:
> tls_pre_decrypt, key_id=0, IP=115.170.126.165:4329
> Sat Feb 18 09:48:54 2012 us=76783 user009_/115.170.126.165:4329 FRAG_IN
> buf->len=41 type=FRAG_WHOLE flags=0x00000000
> Sat Feb 18 09:48:54 2012 us=76828 user009_/115.170.126.165:4329 GET INST
BY
> VIRT: 10.11.0.2 -> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:54 2012 us=76875 user009_/115.170.126.165:4329 TUN WRITE
> [40]
> Sat Feb 18 09:48:54 2012 us=89383 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:54 2012 us=89432 user009_/115.170.126.165:4329 UDPv4 READ
> [101] from 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
> Sat Feb 18 09:48:54 2012 us=89455 user009_/115.170.126.165:4329 TLS:
> tls_pre_decrypt, key_id=0, IP=115.170.126.165:4329
> Sat Feb 18 09:48:54 2012 us=89488 user009_/115.170.126.165:4329 FRAG_IN
> buf->len=41 type=FRAG_WHOLE flags=0x00000000
> Sat Feb 18 09:48:54 2012 us=89518 user009_/115.170.126.165:4329 GET INST
BY
> VIRT: 10.11.0.2 -> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:54 2012 us=89549 user009_/115.170.126.165:4329 TUN WRITE
> [40]
> Sat Feb 18 09:48:54 2012 us=198923 GET INST BY VIRT: 10.11.0.2 ->
> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:54 2012 us=198963 user009_/115.170.126.165:4329 TUN READ
> [40]
> Sat Feb 18 09:48:54 2012 us=198983 user009_/115.170.126.165:4329 FRAG_OUT
> len=41 type=0 seq_id=0 frag_id=0 frag_size=0 flags=0x00000000
> Sat Feb 18 09:48:54 2012 us=198998 user009_/115.170.126.165:4329 TLS:
> tls_pre_encrypt: key_id=0
> Sat Feb 18 09:48:54 2012 us=199049 user009_/115.170.126.165:4329 UDPv4
WRITE
> [101] to 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
> Sat Feb 18 09:48:54 2012 us=616953 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:54 2012 us=616992 user009_/115.170.126.165:4329 UDPv4
READ
> [101] from 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
> Sat Feb 18 09:48:54 2012 us=617006 user009_/115.170.126.165:4329 TLS:
> tls_pre_decrypt, key_id=0, IP=115.170.126.165:4329
> Sat Feb 18 09:48:54 2012 us=617031 user009_/115.170.126.165:4329 FRAG_IN
> buf->len=53 type=FRAG_WHOLE flags=0x00000000
> Sat Feb 18 09:48:54 2012 us=617049 user009_/115.170.126.165:4329 GET INST
BY
> VIRT: 10.11.0.2 -> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:54 2012 us=617070 user009_/115.170.126.165:4329 MSS: 1348
> -> 1198
> Sat Feb 18 09:48:54 2012 us=617080 user009_/115.170.126.165:4329 TUN WRITE
> [52]
> Sat Feb 18 09:48:56 2012 us=951391 MULTI: REAP range 240 -> 256
> Sat Feb 18 09:48:56 2012 us=951568 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:56 2012 us=951596 user009_/115.170.126.165:4329 UDPv4
READ
> [165] from 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=164
> Sat Feb 18 09:48:56 2012 us=951617 user009_/115.170.126.165:4329 TLS:
> tls_pre_decrypt, key_id=0, IP=115.170.126.165:4329
> Sat Feb 18 09:48:56 2012 us=951661 user009_/115.170.126.165:4329 FRAG_IN
> buf->len=107 type=FRAG_WHOLE flags=0x00000000
> Sat Feb 18 09:48:56 2012 us=951691 user009_/115.170.126.165:4329 GET INST
BY
> VIRT: 10.11.0.2 -> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:56 2012 us=951724 user009_/115.170.126.165:4329 TUN WRITE
> [106]
> Sat Feb 18 09:48:58 2012 us=851745 MULTI: REAP range 0 -> 16
> Sat Feb 18 09:48:58 2012 us=851937 GET INST BY REAL: 115.170.126.165:4329
> [succeeded]
> Sat Feb 18 09:48:58 2012 us=851963 user009_/115.170.126.165:4329 UDPv4
READ
> [101] from 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
> Sat Feb 18 09:48:58 2012 us=851984 user009_/115.170.126.165:4329 TLS:
> tls_pre_decrypt, key_id=0, IP=115.170.126.165:4329
> Sat Feb 18 09:48:58 2012 us=852020 user009_/115.170.126.165:4329 FRAG_IN
> buf->len=53 type=FRAG_WHOLE flags=0x00000000
> Sat Feb 18 09:48:58 2012 us=852047 user009_/115.170.126.165:4329 GET INST
BY
> VIRT: 10.11.0.2 -> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:58 2012 us=852125 user009_/115.170.126.165:4329 MSS: 1348
> -> 1198
> Sat Feb 18 09:48:58 2012 us=852144 user009_/115.170.126.165:4329 TUN WRITE
> [52]
> Sat Feb 18 09:48:58 2012 us=965289 GET INST BY VIRT: 10.11.0.2 ->
> user009_/115.170.126.165:4329 via 10.11.0.2
> Sat Feb 18 09:48:58 2012 us=965367 user009_/115.170.126.165:4329 TUN READ
> [52]
> Sat Feb 18 09:48:58 2012 us=965386 user009_/115.170.126.165:4329 MSS: 1460
> -> 1198
> Sat Feb 18 09:48:58 2012 us=965405 user009_/115.170.126.165:4329 FRAG_OUT
> len=53 type=0 seq_id=0 frag_id=0 frag_size=0 flags=0x00000000
> Sat Feb 18 09:48:58 2012 us=965420 user009_/115.170.126.165:4329 TLS:
> tls_pre_encrypt: key_id=0
> Sat Feb 18 09:48:58 2012 us=965479 user009_/115.170.126.165:4329 UDPv4
WRITE
> [101] to 115.170.126.165:4329: P_DATA_V1 kid=0 DATA len=100
>
> -----------------
>
> -----Original Message-----
> From: Ralf Lübben [mailto:address@hidden
> Sent: Saturday, February 18, 2012 10:12 PM
> To: address@hidden
> Cc: Jacky.He
> Subject: Re: [Radiusplugin-users] username end with space can login
succeed,
> but can't be accounted.
>
> Hi,
>
> can you increase the verbosity level of OpenVPN to 7 or more, to find
where
> the
> rewrite happens.
>
> The log should show which parameters are passed to the plugin. Probably
> OpenVPN does some rewritting:
>
> "String Types and Remapping" in the man page.
>
> Ralf
>
> Am Samstag, 18. Februar 2012, 21:48:37 schrieb Jacky.He:
> > Hi,
> >
> >
> >
> > I have an OpenVPN 2.2 server with radiusplugin 2.1a Beta1 running in a
>
> Linux
>
> > server, with bellowing config:
> >
> > -----
> >
> > status openvpn-status.log 1
> >
> > plugin /etc/openvpn/radiusplugin.so /etc/openvpn/radiusplugin.cnf
> >
> > client-cert-not-required
> >
> > username-as-common-name
> >
> > -----
> >
> >
> >
> >
> >
> > Everything runs fine, I recently found some user login with an _ at the
>
> end
>
> > of username, like "jacky" can login as "jacky_" successfully, but user
> > traffic can't be accounted.
> >
> > OpenVPN logs like:
> >
> >
> >
> > TLS: Username/Password authentication succeeded for username 'jacky_'
> > [CN
> > SET]
> >
> > .
> >
> > RADIUS-PLUGIN: BACKGROUND ACCT: No accounting data was found for jacky
> > ,1xx.xx.xxx.xxx:57534
> >
> >
> >
> >
> >
> > I found if I add a space at the end of username in the password file of
> > openvpn client config, I can playback the problem: user can login with
> > end of _ , but can't be accounted.
> >
> > And I also check the username in my radius database, it doesn't contain
>
> any
>
> > _ or any space.
> >
> >
> >
> > How can I avoid this problem? What I want is:
> >
> > if user add a or more space at the end of username in the password file,
> > OpenVPN server will refuse the user to login.
> >
> >
> >
> > Please help, thanks.
> >
> >
> >
> > --
> >
> > Best Regards
> >
> > Jacky
>
> __________ Information from ESET NOD32 Antivirus, version of virus
signature
> database 6894 (20120218) __________
>
> The message was checked by ESET NOD32 Antivirus.
>
> http://www.eset.com
__________ Information from ESET NOD32 Antivirus, version of virus signature
database 6894 (20120218) __________
The message was checked by ESET NOD32 Antivirus.
http://www.eset.com