[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: |
Sat, 18 Feb 2012 22:56:58 +0800 |
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