[cisco-nas] 5400 authentication problem
Yannis Xydas
yxydas at teiath.gr
Fri Jan 23 01:19:13 EST 2004
In our Institution we have 2 dialup routers a Cisco 3640 and a new 5400.
The 3640 has one ISDN PRI line (E1 module) accepting only ISDN calls and
the 5400 has two ISDN PRI lines (up to 8 E1 controllers) and 240 modems.
Authentication is done by a radius server (FreeRadius in Linux) serving
both routers. Everything works fine except the double login detection
for the 5400 calls. Both routers have the same IOS version (12.2) and
are running the same aaa configuration. The double login detection is
done with SNMP (snmpget into the router MIB. If it returns 0 --> no
double login, if 1 --> double login ) and it works fine with the 3640
but not with the 5400.
Here it is the aaa configuration for both routers (3540:
195.130.102.130, 5400: 195.130.98.1)
--------------------------------------------------------------------------------------------------------
aaa new-model
aaa authentication login default local
aaa authentication enable default enable
aaa authentication ppp default group radius local
aaa authentication ppp dialin if-needed local
aaa authorization exec default if-authenticated local
aaa authorization network default group radius local
aaa accounting delay-start
aaa accounting network default start-stop group radius
aaa processes 6 (only in 3640, cannot find the same in 5400)
.......................................................................
ip radius source-interface Loopback0 (3640)
radius-server host 195.130.100.47 auth-port 1645 acct-port 1646 (3640)
radius-server key xxxxxxxxxx (3640)
radius-server retransmit 3 (3640)
......................................................................
ip radius source-interface Loopback0 (5400)
radius-server host 195.130.100.47 auth-port 1645 acct-port 1646 (5400)
radius-server timeout 10 (5400)
radius-server key xxxxxxxxxx (5400)
radius-server authorization permit missing Service-Type (5400)
------------------------------------------------------------------------------------------------------
Please find attached the "debug radius" for both routers and the radius
server (195.130.100.47) log.
Any idea or help is welcome...
Thanks
Yannis Xydas
NOC manager
Technological Institution of Athens
-------------- next part --------------
r3640#
r3640#sh log
Syslog logging: enabled (0 messages dropped, 26 messages rate-limited, 0 flushes
, 0 overruns)
Console logging: level debugging, 22001 messages logged
Monitor logging: level debugging, 0 messages logged
Buffer logging: level debugging, 22027 messages logged
Logging Exception size (4096 bytes)
Trap logging: level informational, 21427 message lines logged
Log Buffer (8192 bytes):
------------ First call (ISDN BRI one channel B allowed) ----------
Jan 22 08:50:31: RADIUS: Retransmit id 143
Jan 22 08:50:31: RADIUS: Received from id 143 195.130.100.47:1645, Access-Reject
, len 68
Jan 22 08:50:31: Attribute 18 48 0D0A596F
Jan 22 08:50:31: RADIUS: saved authorization data for user 616C1240 at 0
Jan 22 08:50:31: AAA/AUTHEN (4278416657): status = FAIL
Jan 22 08:50:31: AAA/MEMORY: free_user (0x616C1240) user='ixydas' ruser='NULL' p
ort='Serial2/0:14' rem_addr='2105319787/00' authen_type=PAP service=PPP priv=1
Jan 22 08:50:31: %ISDN-6-CONNECT: Interface Serial2/0:14 is now connected to 210
5319787
Jan 22 08:50:31: %ISDN-6-DISCONNECT: Interface Serial2/0:14 disconnected from 2
105319787 , call lasted 11 seconds
Jan 22 08:50:31: %LINK-3-UPDOWN: Interface Serial2/0:14, changed state to down
Jan 22 08:50:37: %ISDN-6-DISCONNECT: Interface Serial2/0:1 disconnected from 21
05319788 ixydas, call lasted 187 seconds
Jan 22 08:50:37: %LINK-3-UPDOWN: Interface Serial2/0:1, changed state to down
Jan 22 08:50:37: RADIUS: ustruct sharecount=3
Jan 22 08:50:37: Radius: radius_port_info() success=1 radius_nas_port=1
Jan 22 08:50:37: %LINK-3-UPDOWN: Interface Virtual-Access5, changed state to dow
n
Jan 22 08:50:37: RADIUS: Initial Transmit Serial2/0:1 id 144 195.130.100.47:1646
, Accounting-Request, len 144
Jan 22 08:50:37: Attribute 4 6 C3826682
Jan 22 08:50:37: Attribute 5 6 00004E21
Jan 22 08:50:37: Attribute 61 6 00000002
Jan 22 08:50:37: Attribute 1 8 69787964
Jan 22 08:50:37: Attribute 30 4 30301F0C
Jan 22 08:50:37: Attribute 31 12 32313035
Jan 22 08:50:37: Attribute 40 6 00000002
Jan 22 08:50:37: Attribute 45 6 00000001
Jan 22 08:50:37: Attribute 6 6 00000002
Jan 22 08:50:37: Attribute 44 10 30303030
Jan 22 08:50:37: Attribute 7 6 00000001
Jan 22 08:50:37: Attribute 8 6 C38266AA
Jan 22 08:50:37: Attribute 49 6 00000001
Jan 22 08:50:37: Attribute 42 6 00000F10
Jan 22 08:50:37: Attribute 43 6 00001BA3
Jan 22 08:50:37: Attribute 47 6 00000039
Jan 22 08:50:37: Attribute 48 6 00000095
Jan 22 08:50:37: Attribute 46 6 000000B8
Jan 22 08:50:37: Attribute 41 6 00000000
Jan 22 08:50:37: RADIUS: Received from id 144 195.130.100.47:1646, Accounting-re
sponse, len 20
Jan 22 08:50:37: AAA/MEMORY: free_user (0x616D9E04) user='ixydas' ruser='NULL' p
ort='Serial2/0:1' rem_addr='2105319788/00' authen_type=PAP service=PPP priv=1
Jan 22 08:50:38: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access5
, changed state to down
Jan 22 08:50:38: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial2/0:1, ch
anged state to down
Jan 22 08:51:21: %LINK-3-UPDOWN: Interface Serial2/0:25, changed state to up
Jan 22 08:51:25: AAA: parse name=Serial2/0:25 idb type=13 tty=-1
Jan 22 08:51:25: AAA: name=Serial2/0:25 flags=0x55 type=1 shelf=0 slot=2 adapter
=0 port=0 channel=25
Jan 22 08:51:25: AAA: parse name=<no string> idb type=-1 tty=-1
Jan 22 08:51:25: AAA/MEMORY: create_user (0x616D9E04) user='ixydas' ruser='NULL'
port='Serial2/0:25' rem_addr='2105319788/00' authen_type=PAP service=PPP priv=1
initial_task_id='0'
Jan 22 08:51:25: AAA/AUTHEN/START (2726464681): port='Serial2/0:25' list='' acti
on=LOGIN service=PPP
Jan 22 08:51:25: AAA/AUTHEN/START (2726464681): using "default" list
Jan 22 08:51:25: AAA/AUTHEN/START (2726464681): Method=radius (radius)
Jan 22 08:51:25: RADIUS: ustruct sharecount=1
Jan 22 08:51:25: Radius: radius_port_info() success=1 radius_nas_port=1
Jan 22 08:51:25: RADIUS: Initial Transmit Serial2/0:25 id 145 195.130.100.47:164
5, Access-Request, len 92
Jan 22 08:51:25: Attribute 4 6 C3826682
Jan 22 08:51:25: Attribute 5 6 00004E39
Jan 22 08:51:25: Attribute 61 6 00000002
Jan 22 08:51:25: Attribute 1 8 69787964
Jan 22 08:51:25: Attribute 30 4 30301F0C
Jan 22 08:51:25: Attribute 31 12 32313035
Jan 22 08:51:25: Attribute 2 18 1573269B
Jan 22 08:51:25: Attribute 6 6 00000002
Jan 22 08:51:25: Attribute 7 6 00000001
Jan 22 08:51:25: RADIUS: Received from id 145 195.130.100.47:1645, Access-Accept
, len 85
Jan 22 08:51:25: Attribute 62 6 00000001
Jan 22 08:51:25: Attribute 8 6 C38266AA
Jan 22 08:51:25: Attribute 9 6 FFFFFFC0
Jan 22 08:51:25: Attribute 7 6 00000001
Jan 22 08:51:25: Attribute 88 17 3235352E
Jan 22 08:51:25: Attribute 12 6 00000240
Jan 22 08:51:25: Attribute 6 6 00000002
Jan 22 08:51:25: Attribute 28 6 0000012C
Jan 22 08:51:25: Attribute 27 6 00003451
Jan 22 08:51:25: RADIUS: saved authorization data for user 616D9E04 at 6157A568
Jan 22 08:51:25: AAA/AUTHEN (2726464681): status = PASS
Jan 22 08:51:25: %LINK-3-UPDOWN: Interface Virtual-Access7, changed state to up
Jan 22 08:51:25: RADIUS: Authorize IP address 195.130.102.170
Jan 22 08:51:25: RADIUS: Framed-IP-Netmask 255.255.255.192
Jan 22 08:51:25: RADIUS: framed-route 195.130.102.128 255.255.255.192
Jan 22 08:51:26: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial2/0:25, c
hanged state to up
Jan 22 08:51:26: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access7
, changed state to up
Jan 22 08:51:28: RADIUS: ustruct sharecount=4
Jan 22 08:51:28: Radius: radius_port_info() success=1 radius_nas_port=1
Jan 22 08:51:28: RADIUS: Initial Transmit Serial2/0:25 id 146 195.130.100.47:164
6, Accounting-Request, len 108
Jan 22 08:51:28: Attribute 4 6 C3826682
Jan 22 08:51:28: Attribute 5 6 00004E39
Jan 22 08:51:28: Attribute 61 6 00000002
Jan 22 08:51:28: Attribute 1 8 69787964
Jan 22 08:51:28: Attribute 30 4 30301F0C
Jan 22 08:51:28: Attribute 31 12 32313035
Jan 22 08:51:28: Attribute 40 6 00000001
Jan 22 08:51:28: Attribute 45 6 00000001
Jan 22 08:51:28: Attribute 6 6 00000002
Jan 22 08:51:28: Attribute 44 10 30303030
Jan 22 08:51:28: Attribute 7 6 00000001
Jan 22 08:51:28: Attribute 8 6 C38266AA
Jan 22 08:51:28: Attribute 41 6 00000000
Jan 22 08:51:28: RADIUS: Received from id 146 195.130.100.47:1646, Accounting-re
sponse, len 20
--- Second call (ISDN BRI one channel B) ---> Double login detected (Login rejected)
Jan 22 08:51:59: %LINK-3-UPDOWN: Interface Serial2/0:5, changed state to up
Jan 22 08:51:59: %ISDN-6-CONNECT: Interface Serial2/0:25 is now connected to 210
5319788 ixydas
Jan 22 08:52:05: AAA: parse name=Serial2/0:5 idb type=13 tty=-1
Jan 22 08:52:05: AAA: name=Serial2/0:5 flags=0x55 type=1 shelf=0 slot=2 adapter=
0 port=0 channel=5
Jan 22 08:52:05: AAA: parse name=<no string> idb type=-1 tty=-1
Jan 22 08:52:05: AAA/MEMORY: create_user (0x6169B100) user='ixydas' ruser='NULL'
port='Serial2/0:5' rem_addr='2105319787/00' authen_type=PAP service=PPP priv=1
initial_task_id='0'
Jan 22 08:52:05: AAA/AUTHEN/START (381304722): port='Serial2/0:5' list='' action
=LOGIN service=PPP
Jan 22 08:52:05: AAA/AUTHEN/START (381304722): using "default" list
Jan 22 08:52:05: AAA/AUTHEN/START (381304722): Method=radius (radius)
Jan 22 08:52:05: RADIUS: ustruct sharecount=1
Jan 22 08:52:05: Radius: radius_port_info() success=1 radius_nas_port=1
Jan 22 08:52:05: RADIUS: Initial Transmit Serial2/0:5 id 147 195.130.100.47:1645
, Access-Request, len 92
Jan 22 08:52:05: Attribute 4 6 C3826682
Jan 22 08:52:05: Attribute 5 6 00004E25
Jan 22 08:52:05: Attribute 61 6 00000002
Jan 22 08:52:05: Attribute 1 8 69787964
Jan 22 08:52:05: Attribute 30 4 30301F0C
Jan 22 08:52:05: Attribute 31 12 32313035
Jan 22 08:52:05: Attribute 2 18 55A88D83
Jan 22 08:52:05: Attribute 6 6 00000002
Jan 22 08:52:05: Attribute 7 6 00000001
Jan 22 08:52:10: RADIUS: Retransmit id 147
Jan 22 08:52:10: RADIUS: Received from id 147 195.130.100.47:1645, Access-Reject
, len 68
Jan 22 08:52:10: Attribute 18 48 0D0A596F
Jan 22 08:52:10: RADIUS: saved authorization data for user 6169B100 at 0
Jan 22 08:52:10: AAA/AUTHEN (381304722): status = FAIL
Jan 22 08:52:10: AAA/MEMORY: free_user (0x6169B100) user='ixydas' ruser='NULL' p
ort='Serial2/0:5' rem_addr='2105319787/00' authen_type=PAP service=PPP priv=1
Jan 22 08:52:10: %ISDN-6-CONNECT: Interface Serial2/0:5 is now connected to 2105
319787
Jan 22 08:52:10: %ISDN-6-DISCONNECT: Interface Serial2/0:5 disconnected from 21
05319787 , call lasted 11 seconds
Jan 22 08:52:10: %LINK-3-UPDOWN: Interface Serial2/0:5, changed state to down
-------------- next part --------------
r5400#sh log
Syslog logging: enabled (0 messages dropped, 76 messages rate-limited, 0 flushes
, 0 overruns, xml disabled)
Console logging: level debugging, 22873 messages logged, xml disabled
Monitor logging: level debugging, 0 messages logged, xml disabled
Buffer logging: level debugging, 22948 messages logged, xml disabled
Logging Exception size (4096 bytes)
Count and timestamp logging messages: enabled
Trap logging: level informational, 22559 message lines logged
Log Buffer (16384 bytes):
----------- 1rst call (ISDN) --> Login OK -----------
Jan 22 07:50:51: RADIUS: AAA Unsupported [150] 9
Jan 22 07:50:51: RADIUS: 41 73 79 6E 63 33 2F [Asy
nc3/]
Jan 22 07:50:51: RADIUS(00000B1E): Storing nasport 441 in rad_db
Jan 22 07:50:51: RADIUS(00000B1E): Config NAS IP: 195.130.98.1
Jan 22 07:50:51: RADIUS/ENCODE(00000B1E): acct_session_id: 4476
Jan 22 07:50:51: RADIUS(00000B1E): sending
Jan 22 07:50:51: RADIUS(00000B1E): Send Access-Request to 195.130.100.47:1645 id
21668/234, len 93
Jan 22 07:50:51: RADIUS: authenticator CA 33 BC F4 F8 C0 43 A4 - 9D 57 7D AB 34
07 39 7B
Jan 22 07:50:51: RADIUS: Framed-Protocol [7] 6 PPP
[1]
Jan 22 07:50:51: RADIUS: User-Name [1] 8 "yxydas"
Jan 22 07:50:51: RADIUS: User-Password [2] 18 *
Jan 22 07:50:51: RADIUS: Calling-Station-Id [31] 12 "2105317340"
Jan 22 07:50:51: RADIUS: Called-Station-Id [30] 5 "000"
Jan 22 07:50:51: RADIUS: NAS-Port [5] 6 441
Jan 22 07:50:51: RADIUS: NAS-Port-Type [61] 6 Async
[0]
Jan 22 07:50:51: RADIUS: Service-Type [6] 6 Framed
[2]
Jan 22 07:50:51: RADIUS: NAS-IP-Address [4] 6 195.130.98.1
Jan 22 07:50:51: RADIUS: Received from id 21668/234 195.130.100.47:1645, Access-
Accept, len 79
Jan 22 07:50:51: RADIUS: authenticator F1 64 A7 FD FF D5 29 9E - 25 F5 FA 89 26
94 5F 5C
Jan 22 07:50:51: RADIUS: Port-Limit [62] 6 1
Jan 22 07:50:51: RADIUS: Port-Limit [62] 6 1
Jan 22 07:50:51: RADIUS: Framed-Protocol [7] 6 PPP
[1]
Jan 22 07:50:51: RADIUS: Unsupported [88] 17
Jan 22 07:50:51: RADIUS: 32 35 35 2E 32 35 35 2E 32 35 35 2E 32 35 34 [255
.255.255.254]
Jan 22 07:50:51: RADIUS: Framed-MTU [12] 6 576
Jan 22 07:50:51: RADIUS: Service-Type [6] 6 Framed
[2]
Jan 22 07:50:51: RADIUS: Idle-Timeout [28] 6 300
Jan 22 07:50:51: RADIUS: Session-Timeout [27] 6 13871
Jan 22 07:50:51: RADIUS(00000B1E): Received from id 21668/234
Jan 22 07:50:51: RADIUS: Unsupported [88] 17
Jan 22 07:50:51: RADIUS: 32 35 35 2E 32 35 35 2E 32 35 35 2E 32 35 34 [255
.255.255.254]
--------- 2nd call (PSTN) ---> Login OK (double login accepted !!!) ------
Jan 22 07:51:03: RADIUS(00000B1E): Using existing nas_port 441
Jan 22 07:51:03: RADIUS(00000B1E): Config NAS IP: 195.130.98.1
Jan 22 07:51:03: RADIUS(00000B1E): sending
Jan 22 07:51:03: RADIUS(00000B1E): Send Accounting-Request to 195.130.100.47:164
6 id 21668/235, len 152
Jan 22 07:51:03: RADIUS: authenticator 64 C6 8C 68 C4 FA A2 7A - 00 C4 3B 18 42
22 3D B6
Jan 22 07:51:03: RADIUS: Acct-Session-Id [44] 10 "0000117C"
Jan 22 07:51:03: RADIUS: Framed-Protocol [7] 6 PPP
[1]
Jan 22 07:51:03: RADIUS: Framed-IP-Address [8] 6 195.130.98.213
Jan 22 07:51:03: RADIUS: Acct-Authentic [45] 6 RADIUS
[1]
Jan 22 07:51:03: RADIUS: User-Name [1] 8 "yxydas"
Jan 22 07:51:03: RADIUS: Acct-Status-Type [40] 6 Start
[1]
Jan 22 07:51:03: RADIUS: Calling-Station-Id [31] 12 "2105317340"
Jan 22 07:51:03: RADIUS: Called-Station-Id [30] 5 "000"
Jan 22 07:51:03: RADIUS: NAS-Port [5] 6 441
Jan 22 07:51:03: RADIUS: NAS-Port-Type [61] 6 Async
[0]
Jan 22 07:51:03: RADIUS: Connect-Info [77] 43 "38667/28800 V90/V42bis/
LAPM (40000/28800)"
Jan 22 07:51:03: RADIUS: Service-Type [6] 6 Framed
[2]
Jan 22 07:51:03: RADIUS: NAS-IP-Address [4] 6 195.130.98.1
Jan 22 07:51:03: RADIUS: Acct-Delay-Time [41] 6 0
Jan 22 07:51:03: RADIUS: Received from id 21668/235 195.130.100.47:1646, Account
ing-response, len 20
Jan 22 07:51:03: RADIUS: authenticator 91 27 68 93 00 29 26 25 - 43 1A 39 2B C1
1D D8 7E
Jan 22 07:51:31: RADIUS: AAA Unsupported [150] 11
Jan 22 07:51:31: RADIUS: 53 65 72 69 61 6C 31 2F 30 [Ser
ial1/0]
Jan 22 07:51:31: RADIUS(00000B1F): Storing nasport 20006 in rad_db
Jan 22 07:51:31: RADIUS(00000B1F): Config NAS IP: 195.130.98.1
Jan 22 07:51:31: RADIUS/ENCODE(00000B1F): acct_session_id: 4477
Jan 22 07:51:31: RADIUS(00000B1F): sending
Jan 22 07:51:31: RADIUS(00000B1F): Send Access-Request to 195.130.100.47:1645 id
21668/236, len 93
Jan 22 07:51:31: RADIUS: authenticator 8B 8E A2 71 89 D9 17 12 - 7B 65 23 B1 08
74 0B E5
Jan 22 07:51:31: RADIUS: Framed-Protocol [7] 6 PPP
[1]
Jan 22 07:51:31: RADIUS: User-Name [1] 8 "yxydas"
Jan 22 07:51:31: RADIUS: User-Password [2] 18 *
Jan 22 07:51:31: RADIUS: NAS-Port [5] 6 20006
Jan 22 07:51:31: RADIUS: NAS-Port-Type [61] 6 ISDN
[2]
Jan 22 07:51:31: RADIUS: Calling-Station-Id [31] 12 "2105319787"
Jan 22 07:51:31: RADIUS: Called-Station-Id [30] 5 "000"
Jan 22 07:51:31: RADIUS: Service-Type [6] 6 Framed
[2]
Jan 22 07:51:31: RADIUS: NAS-IP-Address [4] 6 195.130.98.1
Jan 22 07:51:41: RADIUS: Retransmit to (195.130.100.47:1645,1646) for id 21668/2
36
Jan 22 07:51:41: RADIUS: Received from id 21668/236 195.130.100.47:1645, Access-
Accept, len 79
Jan 22 07:51:41: RADIUS: authenticator 4C F7 46 A0 59 D2 61 C6 - 09 BB E1 01 C8
CE B7 14
Jan 22 07:51:41: RADIUS: Port-Limit [62] 6 1
Jan 22 07:51:41: RADIUS: Port-Limit [62] 6 1
Jan 22 07:51:41: RADIUS: Framed-Protocol [7] 6 PPP
[1]
Jan 22 07:51:41: RADIUS: Unsupported [88] 17
Jan 22 07:51:41: RADIUS: 32 35 35 2E 32 35 35 2E 32 35 35 2E 32 35 34 [255
.255.255.254]
Jan 22 07:51:41: RADIUS: Framed-MTU [12] 6 576
Jan 22 07:51:41: RADIUS: Service-Type [6] 6 Framed
[2]
Jan 22 07:51:41: RADIUS: Idle-Timeout [28] 6 300
Jan 22 07:51:41: RADIUS: Session-Timeout [27] 6 13871
Jan 22 07:51:41: RADIUS(00000B1F): Received from id 21668/236
Jan 22 07:51:41: RADIUS: Unsupported [88] 17
Jan 22 07:51:41: RADIUS: 32 35 35 2E 32 35 35 2E 32 35 35 2E 32 35 34 [255
.255.255.254]
Jan 22 07:51:41: RADIUS(00000B1F): Using existing nas_port 20006
Jan 22 07:51:41: RADIUS(00000B1F): Config NAS IP: 195.130.98.1
Jan 22 07:51:41: RADIUS(00000B1F): sending
Jan 22 07:51:41: RADIUS(00000B1F): Send Accounting-Request to 195.130.100.47:164
6 id 21668/237, len 109
Jan 22 07:51:41: RADIUS: authenticator FF 27 AA DF 81 CF 74 BD - 40 B0 CC FF F7
5A 86 6A
Jan 22 07:51:41: RADIUS: Acct-Session-Id [44] 10 "0000117D"
Jan 22 07:51:41: RADIUS: Framed-Protocol [7] 6 PPP
[1]
Jan 22 07:51:41: RADIUS: Framed-IP-Address [8] 6 195.130.98.47
Jan 22 07:51:41: RADIUS: Acct-Authentic [45] 6 RADIUS
[1]
Jan 22 07:51:41: RADIUS: User-Name [1] 8 "yxydas"
Jan 22 07:51:41: RADIUS: Acct-Status-Type [40] 6 Start
[1]
Jan 22 07:51:41: RADIUS: NAS-Port [5] 6 20006
Jan 22 07:51:41: RADIUS: NAS-Port-Type [61] 6 ISDN
[2]
Jan 22 07:51:41: RADIUS: Calling-Station-Id [31] 12 "2105319787"
Jan 22 07:51:41: RADIUS: Called-Station-Id [30] 5 "000"
Jan 22 07:51:41: RADIUS: Service-Type [6] 6 Framed
[2]
Jan 22 07:51:41: RADIUS: NAS-IP-Address [4] 6 195.130.98.1
Jan 22 07:51:41: RADIUS: Acct-Delay-Time [41] 6 0
Jan 22 07:51:41: RADIUS: Received from id 21668/237 195.130.100.47:1646, Account
ing-response, len 20
Jan 22 07:51:41: RADIUS: authenticator D7 7E 5E 88 AE 3A 7B 16 - AF 72 D6 E6 4C
42 51 46
------------ stop PSTN call ---------------------
Jan 22 07:55:31: RADIUS(00000B1E): Using existing nas_port 441
Jan 22 07:55:31: RADIUS(00000B1E): Config NAS IP: 195.130.98.1
Jan 22 07:55:31: RADIUS(00000B1E): sending
Jan 22 07:55:31: RADIUS(00000B1E): Send Accounting-Request to 195.130.100.47:164
6 id 21668/238, len 188
Jan 22 07:55:31: RADIUS: authenticator 60 46 A0 10 82 73 A9 D9 - 1A 51 4A BD 5B
0A 81 0D
Jan 22 07:55:31: RADIUS: Acct-Session-Id [44] 10 "0000117C"
Jan 22 07:55:31: RADIUS: Framed-Protocol [7] 6 PPP
[1]
Jan 22 07:55:31: RADIUS: Framed-IP-Address [8] 6 195.130.98.213
Jan 22 07:55:31: RADIUS: Acct-Authentic [45] 6 RADIUS
[1]
Jan 22 07:55:31: RADIUS: Acct-Session-Time [46] 6 280
Jan 22 07:55:31: RADIUS: Acct-Input-Octets [42] 6 13658
Jan 22 07:55:31: RADIUS: Acct-Output-Octets [43] 6 234
Jan 22 07:55:31: RADIUS: Acct-Input-Packets [47] 6 324
Jan 22 07:55:31: RADIUS: Acct-Output-Packets [48] 6 12
Jan 22 07:55:31: RADIUS: Acct-Terminate-Cause[49] 6 idle-timeout
[4]
Jan 22 07:55:31: RADIUS: User-Name [1] 8 "yxydas"
Jan 22 07:55:31: RADIUS: Acct-Status-Type [40] 6 Stop
[2]
Jan 22 07:55:31: RADIUS: Calling-Station-Id [31] 12 "2105317340"
Jan 22 07:55:31: RADIUS: Called-Station-Id [30] 5 "000"
Jan 22 07:55:31: RADIUS: NAS-Port [5] 6 441
Jan 22 07:55:31: RADIUS: NAS-Port-Type [61] 6 Async
[0]
Jan 22 07:55:31: RADIUS: Connect-Info [77] 43 "33333/28800 V90/V42bis/
LAPM (40000/28800)"
Jan 22 07:55:31: RADIUS: Service-Type [6] 6 Framed
[2]
Jan 22 07:55:31: RADIUS: NAS-IP-Address [4] 6 195.130.98.1
Jan 22 07:55:31: RADIUS: Acct-Delay-Time [41] 6 0
Jan 22 07:55:31: RADIUS: Received from id 21668/238 195.130.100.47:1646, Account
ing-response, len 20
Jan 22 07:55:31: RADIUS: authenticator ED D2 94 96 BD C8 62 DD - F5 9E 25 75 B0
02 11 60
------stop ISDN call ----------------
Jan 22 07:56:24: RADIUS(00000B1F): Using existing nas_port 20006
Jan 22 07:56:24: RADIUS(00000B1F): Config NAS IP: 195.130.98.1
Jan 22 07:56:24: RADIUS(00000B1F): sending
Jan 22 07:56:24: RADIUS(00000B1F): Send Accounting-Request to 195.130.100.47:164
6 id 21668/239, len 145
Jan 22 07:56:24: RADIUS: authenticator 10 AB 95 1B 1E A5 32 79 - 3E 47 99 93 B7
8B DA FC
Jan 22 07:56:24: RADIUS: Acct-Session-Id [44] 10 "0000117D"
Jan 22 07:56:24: RADIUS: Framed-Protocol [7] 6 PPP
[1]
Jan 22 07:56:24: RADIUS: Framed-IP-Address [8] 6 195.130.98.47
Jan 22 07:56:24: RADIUS: Acct-Authentic [45] 6 RADIUS
[1]
Jan 22 07:56:24: RADIUS: Acct-Session-Time [46] 6 283
Jan 22 07:56:24: RADIUS: Acct-Input-Octets [42] 6 1240
Jan 22 07:56:24: RADIUS: Acct-Output-Octets [43] 6 552
Jan 22 07:56:24: RADIUS: Acct-Input-Packets [47] 6 35
Jan 22 07:56:24: RADIUS: Acct-Output-Packets [48] 6 33
Jan 22 07:56:24: RADIUS: Acct-Terminate-Cause[49] 6 user-request
[1]
Jan 22 07:56:24: RADIUS: User-Name [1] 8 "yxydas"
Jan 22 07:56:24: RADIUS: Acct-Status-Type [40] 6 Stop
[2]
Jan 22 07:56:24: RADIUS: NAS-Port [5] 6 20006
Jan 22 07:56:24: RADIUS: NAS-Port-Type [61] 6 ISDN
[2]
Jan 22 07:56:24: RADIUS: Calling-Station-Id [31] 12 "2105319787"
Jan 22 07:56:24: RADIUS: Called-Station-Id [30] 5 "000"
Jan 22 07:56:24: RADIUS: Service-Type [6] 6 Framed
[2]
Jan 22 07:56:24: RADIUS: NAS-IP-Address [4] 6 195.130.98.1
Jan 22 07:56:24: RADIUS: Acct-Delay-Time [41] 6 0
Jan 22 07:56:24: RADIUS: Received from id 21668/239 195.130.100.47:1646, Account
ing-response, len 20
Jan 22 07:56:24: RADIUS: authenticator 38 41 F6 9E 84 46 8D F8 - FD 18 39 55 33
6B 44 8B
r5400#
-------------- next part --------------
<<< Log from portieris.teiath.gr started january 22, 2004, 16:25:29 >>>
--- 5400: Double login detection fails and 2nd call (yxydas) is allowed -----
Thu Jan 22 07:38:58 2004 : Auth: Login OK: [tmisthos] (from client r3640 port 20
011 cli 2106811343)
Thu Jan 22 07:43:19 2004 checkrad cisco 195.130.98.1 20003 yxydas 00001179
snmpget: /usr/bin/snmpget -r 1 -t 5 195.130.98.1 public .iso.org.dod.internet.pr
ivate.enterprises.9.9.150.1.1.3.1.2.4473
Thu Jan 22 07:43:29 2004 : Error: Discarding new request from client r5400:21668
- ID: 232 due to live request 25885
Thu Jan 22 07:43:29 2004 : Error: Check-TS: timeout waiting for checkrad
Thu Jan 22 07:43:29 2004 : Auth: Login OK: [yxydas] (from client r5400 port 501
cli 2105317340)
user with session id 00001179 (4473):
snpwalk: /usr/bin/snmpwalk -r 1 -t 5 195.130.98.1 'public' .iso.org.dod.internet
.private.enterprises.9.10.19.1.3.1.1.3
Thu Jan 22 07:43:40 2004 : Returning 0 (login ok) : [yxydas] (from nas 195.130.9
8.1 port 20003 cli )
Thu Jan 22 07:50:51 2004 : Auth: Login OK: [yxydas] (from client r5400 port 441
cli 2105317340)
Thu Jan 22 07:51:31 2004 checkrad cisco 195.130.98.1 441 yxydas 0000117C
snmpget: /usr/bin/snmpget -r 1 -t 5 195.130.98.1 public .iso.org.dod.internet.pr
ivate.enterprises.9.2.9.2.1.18.441
Thu Jan 22 07:51:41 2004 : Error: Discarding new request from client r5400:21668
- ID: 236 due to live request 25891
Thu Jan 22 07:51:41 2004 : Error: Check-TS: timeout waiting for checkrad
Thu Jan 22 07:51:41 2004 : Auth: Login OK: [yxydas] (from client r5400 port 2000
6 cli 2105319787)
user at port S441:
snpwalk: /usr/bin/snmpwalk -r 1 -t 5 195.130.98.1 'public' .iso.org.dod.internet
.private.enterprises.9.10.19.1.3.1.1.3
Thu Jan 22 07:51:51 2004 : Returning 0 (login ok) : [yxydas] (from nas 195.130.9
8.1 port 441 cli )
Thu Jan 22 08:03:09 2004 : Auth: Login OK: [amoronis] (from client r3640 port 20
030 cli 2106139326)
Thu Jan 22 08:03:28 2004 : Auth: Login OK: [amoronis] (from client r3640 port 20
002 cli 2106139326)
Thu Jan 22 08:04:08 2004 : Auth: Login OK: [amoronis] (from client r3640 port 20
009 cli 2106139326)
Thu Jan 22 08:05:39 2004 : Auth: Login OK: [ixydas] (from client r3640 port 2000
8 cli 2105319787)
Thu Jan 22 08:07:28 2004 : Auth: Login OK: [kziakris] (from client r5400 port 65
5 cli 2109734812)
Thu Jan 22 08:07:59 2004 : Auth: Login OK: [ixydas] (from client r3640 port 2002
2 cli 2105319787)
Thu Jan 22 08:08:17 2004 : Auth: Login OK: [ixydas] (from client r3640 port 2000
3 cli 2105319787)
Thu Jan 22 08:18:15 2004 : Auth: Login OK: [asimkeri] (from client r5400 port 51
1 cli 2109423963)
Thu Jan 22 08:44:03 2004 : Auth: Login OK: [ixydas] (from client r3640 port 2000
7 cli 2105319788)
Thu Jan 22 08:45:13 2004 : Auth: Login OK: [ixydas] (from client r3640 port 2001
3 cli 2105319788)
Thu Jan 22 08:45:18 2004 : Auth: Login OK: [elfounda] (from client r5400 port 36
0 cli 2102580838)
Thu Jan 22 08:45:25 2004 : Auth: Login OK: [esifinis] (from client r5400 port 35
6 cli 2104675296)
----- 3400: Double login detection works and 2nd call (ixydas) is rejected ---
Thu Jan 22 08:45:37 2004 checkrad cisco 195.130.102.130 20013 ixydas 000007E3
snmpget: /usr/bin/snmpget -r 1 -t 5 195.130.102.130 public .iso.org.dod.internet
.private.enterprises.9.9.150.1.1.3.1.2.2019
user with session id 000007E3 (2019):
snpwalk: /usr/bin/snmpwalk -r 1 -t 5 195.130.102.130 'public' .iso.org.dod.inter
net.private.enterprises.9.10.19.1.3.1.1.3
Thu Jan 22 08:45:37 2004 : Returning 1 (Multiple-Logins) : [ixydas] (from nas 19
5.130.102.130 port 20013 cli )
Thu Jan 22 08:45:38 2004 : Auth: Multiple logins (max 1) : [ixydas] (from client
r3640 port 20021 cli 2105319787)
Thu Jan 22 08:46:52 2004 : Auth: Login incorrect: [ixydas] (from client r3640 po
rt 20023 cli 2105319787)
Thu Jan 22 08:47:32 2004 : Auth: Login OK: [ixydas] (from client r3640 port 2000
1 cli 2105319788)
Thu Jan 22 08:47:55 2004 checkrad cisco 195.130.102.130 20001 ixydas 000007E4
snmpget: /usr/bin/snmpget -r 1 -t 5 195.130.102.130 public .iso.org.dod.internet
.private.enterprises.9.9.150.1.1.3.1.2.2020
user with session id 000007E4 (2020):
snpwalk: /usr/bin/snmpwalk -r 1 -t 5 195.130.102.130 'public' .iso.org.dod.inter
net.private.enterprises.9.10.19.1.3.1.1.3
Thu Jan 22 08:47:56 2004 : Returning 1 (Multiple-Logins) : [ixydas] (from nas 19
5.130.102.130 port 20001 cli )
Thu Jan 22 08:47:57 2004 : Auth: Multiple logins (max 1) : [ixydas] (from client
r3640 port 20000 cli 2105319787)
Thu Jan 22 08:48:29 2004 : Auth: Login OK: [gkizasgr] (from client r5400 port 33
2 cli 2109591124)
Thu Jan 22 08:49:10 2004 checkrad cisco 195.130.102.130 20001 ixydas 000007E4
snmpget: /usr/bin/snmpget -r 1 -t 5 195.130.102.130 public .iso.org.dod.internet
.private.enterprises.9.9.150.1.1.3.1.2.2020
user with session id 000007E4 (2020):
snpwalk: /usr/bin/snmpwalk -r 1 -t 5 195.130.102.130 'public' .iso.org.dod.inter
net.private.enterprises.9.10.19.1.3.1.1.3
Thu Jan 22 08:49:11 2004 : Returning 1 (Multiple-Logins) : [ixydas] (from nas 19
5.130.102.130 port 20001 cli )
Thu Jan 22 08:49:12 2004 : Auth: Multiple logins (max 1) : [ixydas] (from client
r3640 port 20012 cli 2105319787)
Thu Jan 22 08:49:17 2004 : Auth: Login OK: [kmarian] (from client r5400 port 688
cli 2102135398)
Thu Jan 22 08:50:26 2004 checkrad cisco 195.130.102.130 20001 ixydas 000007E4
snmpget: /usr/bin/snmpget -r 1 -t 5 195.130.102.130 public .iso.org.dod.internet
.private.enterprises.9.9.150.1.1.3.1.2.2020
user with session id 000007E4 (2020):
snpwalk: /usr/bin/snmpwalk -r 1 -t 5 195.130.102.130 'public' .iso.org.dod.inter
net.private.enterprises.9.10.19.1.3.1.1.3
Thu Jan 22 08:50:26 2004 : Returning 1 (Multiple-Logins) : [ixydas] (from nas 19
5.130.102.130 port 20001 cli )
Thu Jan 22 08:50:27 2004 : Auth: Multiple logins (max 1) : [ixydas] (from client
r3640 port 20014 cli 2105319787)
Thu Jan 22 08:51:24 2004 : Auth: Login OK: [ixydas] (from client r3640 port 2002
5 cli 2105319788)
Thu Jan 22 08:52:05 2004 checkrad cisco 195.130.102.130 20025 ixydas 000007E5
snmpget: /usr/bin/snmpget -r 1 -t 5 195.130.102.130 public .iso.org.dod.internet
.private.enterprises.9.9.150.1.1.3.1.2.2021
user with session id 000007E5 (2021):
snpwalk: /usr/bin/snmpwalk -r 1 -t 5 195.130.102.130 'public' .iso.org.dod.inter
net.private.enterprises.9.10.19.1.3.1.1.3
Thu Jan 22 08:52:05 2004 : Returning 1 (Multiple-Logins) : [ixydas] (from nas 19
5.130.102.130 port 20025 cli )
Thu Jan 22 08:52:06 2004 : Auth: Multiple logins (max 1) : [ixydas] (from client
r3640 port 20005 cli 2105319787)
Thu Jan 22 08:52:39 2004 : Auth: Login OK: [alychoun] (from client r5400 port 51
9 cli 2105816898)
Thu Jan 22 08:53:24 2004 : Auth: Login OK: [vanag] (from client r5400 port 664)
Thu Jan 22 08:55:22 2004 : Auth: Login OK: [piklasgr] (from client r5400 port 48
7 cli 2107525238)
Thu Jan 22 08:55:46 2004 : Auth: Login OK: [gmaragaki] (from client r3640 port 2
0029 cli 2106800205)
<<< Log from portieris.teiath.gr ended January 22, 2004, 16:25:48 >>>
More information about the cisco-nas
mailing list