PPP Per-User Timeouts
Available Languages
Contents
Introduction
This technical tip explains how to implement per-user timeouts on Cisco access servers. For per-user timeouts to work properly, you must run Cisco IOS version 11.3(8)T or later. If you run an earlier version of Cisco IOS, the timers might only work in certain basic configurations, such as async only with no virtual profiles.
This document covers the configuration of the network access server (NAS) and the authentication, authorization, and accounting (AAA) server. It also provides show and debug command output so you can confirm if your devices are working properly, and so you can debug any problems.
Prerequisites
Requirements
There are no specific requirements for this document.
Components Used
The information in this document is based on these software and hardware versions:
-
Cisco IOS version 11.3(8)T or later
The information in this document was created from the devices in a specific lab environment. All of the devices used in this document started with a cleared (default) configuration. If your network is live, make sure that you understand the potential impact of any command.
Conventions
For more information on document conventions, refer to Cisco Technical Tips Conventions.
Technical Details
Before discussing per-user timeouts, which bring in other variables like AAA configuration and RADIUS/TACACS+ servers, we will examine how to configure an access server for fixed-timeouts, that is timeouts that are applied on a global basis and are applied to everyone that dials in.
The key Cisco IOS commands are dialer idle-timeout and timeout absolute. Both of these are interface configuration commands. We will also discuss a third command, ppp timeout idle, which is used on vaccess interfaces.
dialer idle-timeout <x>
This command can be configured on any dialer-capable interface and controls how long the connection can be idle (in seconds) before it is terminated. Listed below are four points you should note about this command:
-
This command can only be applied to interfaces that are dialer-capable. By default all ISDN interfaces (BRI and PRI) are dialer-capable, so adding this command is not a problem. Async interfaces (including group-async interfaces) are not dialer-capable by default, you must make them so by entering the command dialer in-band. Only after entering the dialer in-band command on the async interface can you configure dialer idle-timeout. Note
Note: The vtemplate (and therefore vaccess interfaces) are not dialer-capable (they are point-to-point only) and thus cannot use this command.
-
On a dialer-capable interface (that is, ISDN or async with dialer in-band), the default is dialer idle-timeout 120 (seconds). This is generally too short in an ISP environment, so you should almost always increase this.
-
The dialer idle-timeout by default is only reset on outbound traffic (traffic toward the user) which matches the dialer-list (that is, it is considered interesting). It is possible to reset it for inbound interesting traffic as well by adding the either keyword at the end of the command (that is, dialer idle-timeout 600 either).
-
Traffic considered "interesting" is defined by the dialer-list <n> command, where <n> matches the number in your dialer-group <n> command statement.
timeout absolute <x> <y>
This command can be configured on any WAN interface, including async interfaces, ISDN interfaces, dialer interfaces, and vtemplate interfaces. It controls how long the connection can be up before it is terminated. Note that the syntax is <x> <y> where <x> is in minutes and <y> is in seconds.
ppp timeout idle <x>
This command can only be configured on vtemplate interfaces (and is even hidden in the parser), and controls how long the connection can be idle (in seconds) before it is terminated. Its function is very similar to that of the dialer idle-timeout command on dialer interfaces, only ppp timeout idle is for vtemplate/vaccess interfaces. Because it is used specifically on vtemplate/vaccess interfaces, this command is appropriate for virtual-profile configurations (where a vaccess interface is always created for a user), and virtual private dial-up network (VPDN) home gateways (where the projected interfaces is always terminated on a vaccess interface). Unlike the dialer idle-timeout command, there is no concept of interesting traffic, and thus all user traffic will reset the idle timer. Non-user traffic such as link control protocol (LCP) keepalives and Network Control Protocol (NCP) negotiation packets do not reset the timer.
Configure
In this section, you are presented with the information to configure the features described in this document.
Note: To find additional information on the commands used in this document, use the Command Lookup Tool (registered customers only) .
This document uses these configurations:
- Base Configuration (Virtual-Profiles Not Enabled)
- Global Timeouts
- Per-User Timeouts - AAA Server Configuration
- Per-User Timeouts - NAS Configuration
Base Configuration (Virtual-Profiles Not Enabled)
For learning purposes, we will assume a base configuration such as the one below. The virtual-profiles feature is not turned on.
| Base Configuration |
|---|
! version 11.3 service timestamps debug datetime msec service timestamps log datetime msec service password-encryption ! hostname access-3 ! aaa new-model aaa authentication login default tacacs+ local aaa authentication login console none aaa authentication login use-radius local radius aaa authentication enable default enable aaa authentication ppp default if-needed local tacacs+ aaa authentication ppp use-radius if-needed local radius aaa authentication arap default local aaa authorization exec default tacacs+ local aaa authorization exec console none aaa authorization exec use-radius local radius if-authenticated aaa authorization network default local tacacs+ if-authenticated aaa authorization network use-radius local radius if-authenticated aaa accounting exec default stop-only tacacs+ aaa accounting network default stop-only tacacs+ aaa accounting system default start-stop tacacs+ enable secret 5 $1$oMKx$kPcop1zxkpxa8fkxXBWp21 ! modem call-record terse modem buffer-size 250 no ip finger ! isdn switch-type primary-5ess clock timezone PST -8 clock summer-time PDT recurring ! controller T1 0 framing esf clock source line primary linecode b8zs pri-group timeslots 1-24 <output omitted> ! interface Loopback0 ip address 10.1.1.1 255.255.255.0 no ip directed-broadcast ! interface Ethernet0 ip address 172.16.1.1 255.255.255.0 no ip directed-broadcast ! interface Virtual-Template1 ip unnumbered Loopback0 no ip directed-broadcast no keepalive peer default ip address pool default ppp authentication chap pap use-radius ppp multilink ! interface Serial0:23 ip unnumbered Loopback0 no ip directed-broadcast encapsulation ppp no logging event link-status no keepalive dialer-group 1 autodetect encapsulation ppp v120 isdn switch-type primary-5ess isdn incoming-voice modem peer default ip address pool default no fair-queue no cdp enable ppp max-bad-auth 3 ppp authentication chap pap use-radius ppp multilink ! <output omitted> ! interface Group-Async1 ip unnumbered Loopback0 no ip directed-broadcast encapsulation ppp no logging event link-status async mode interactive peer default ip address pool default no fair-queue no cdp enable ppp max-bad-auth 3 ppp authentication chap pap use-radius ppp multilink group-range 1 96 hold-queue 10 in ! ip local pool default 10.1.1.2 10.1.1.200 ip classless ip route 0.0.0.0 0.0.0.0 172.16.1.254 ! no logging console dialer-list 1 protocol ip permit tacacs-server host 172.16.1.201 tacacs-server key cisco radius-server host 172.16.1.202 auth-port 1645 acct-port 1646 key cisco ! line con 0 exec-timeout 0 0 authorization exec console login authentication console transport input none line 1 96 autoselect during-login autoselect ppp modem Dialin escape-character BREAK authorization exec use-radius login authentication use-radius line aux 0 line vty 0 4 exec-timeout 60 0 ! end |
Global Timeouts
For the next example, we will impose a 30 minute (1800 seconds) idle timeout and three hour (180 minutes) absolute timeout for users. The delta configuration change that will enable global ppp timeouts will be as follows:
interface Serial0:23 dialer idle-timeout 1800 timeout absolute 180 ! <output omitted> ! interface Group=Async1 dialer in-band dialer idle-timeout 1800 dialer-group 1 timeout absolute 180
If you do not have a dialer-list 1, you will need to define one. The simplest would be dialer-list 1 protocol ip permit.
If you were using virtual profiles, your configuration can be easier because you can just put the timeout on the virtual-template interface, as shown below:
interface Virtual-Template1 ppp timeout idle 1800 timeout absolute 180
Per-User Timeouts - AAA Server Configuration
Now that we have worked on global timeouts, we will extend this knowledge to per-user timeouts. Your per-user timer values will be coming down during network authorization, so you must have the aaa authorization network command configured to whatever method you are using, which is RADIUS or TACACS+. Also note that per-user timers will always override any global values that are preconfigured on the NAS. The way the per-user timers work is that when the access server receives the timeout attributes during the network authorization phase, it will translate these attributes into a set of configuration commands which will be entered into the interface to which the user will be connected. These configuration commands that are entered into the interface by a background process are temporary; they are removed when the user disconnects.
Listed below are several sample user profiles on the server:
RADIUS profiles
timeout-absolute-ppp Password = "cisco"
Service-Type = Framed,
Framed-Protocol = PPP,
Framed-IP-Address = 255.255.255.254,
Session-Timeout = 600
timeout-idle-ppp Password = "cisco"
Service-Type = Framed,
Framed-Protocol = PPP
Framed-IP-Address = 255.255.255.254,
Idle-Timeout = 300
timeout-both-ppp Password = "cisco"
Service-Type = Framed,
Framed-Protocol = PPP,
Framed-IP-Address = 255.255.255.254,
Session-Timeout = 600,
Idle-Timeout = 300
Note: Your syntax may vary depending on how your dictionary is set up.
TACACS+ profiles
user = timeout-absolute-ppp {
chap = cleartext cisco
service = ppp protocol = lcp {
timeout = 10
}
service = ppp protocol = ip {
addr-pool = "default"
}
}
user = timeout-idle-ppp {
chap = cleartext cisco
service = ppp protocol = lcp {
idletime = 5
}
service = ppp protocol = ip {
addr-pool = "default"
}
}
user = timeout-both-ppp {
chap = cleartext cisco
service = ppp protocol = lcp {
timeout = 10
idletime = 5
}
service = ppp protocol = multilink { }
service = ppp protocol = ip {
addr-pool = "default"
}
}
Per-User Timeouts - NAS Configuration
If you are only doing async (no ISDN), and not using virtual profiles, as long as you have dialer in-band configured on the async (or group-async) interfaces, the per-user timers should work. The background process will insert the timers on the async interface, using the dialer idle-timeout and timeout absolute commands with the values passed in from RADIUS/TACACS+, and take them out when the user disconnects.
If you are only doing async (no ISDN), and are using virtual profiles, you do not need dialer in-band configured on the async (or group-async) interface. It should just work. The background process will insert the timers on the vaccess interface, using the ppp timeout idle and timeout absolute commands with the values passed in from RADIUS/TACACS+, and take them out when the user disconnects.
If you have ISDN users and you need to do per-user timers, you may need to use virtual profiles. The reason is because the background process we have previously discussed does not work for ISDN interfaces; that is, you cannot configure the B-channel to which the user is connected. The only thing you can configure is the D-channel which affects everyone. However if a user negotiates multilink on a session, the access-server will automatically create a virtual-access interface which acts as the bundle interface for the user. The background process does work on virtual-access interfaces, but it does not work on a non-multilink ISDN call where there is no virtual-access interface. So, if you will have single B-channel users who do not negotiate multilink and you want to install per-user timeouts for them, you must enable virtual-profiles. Enabling virtual profiles forces a creation of a vaccess interface for all users (not just the multilink users) and the background process can successfully insert the ppp timeout idle and timeout absolute commands. If you choose to not enable virtual profiles, async users and multilink ISDN users will be able to have per-user timeouts applied to them. But, non-multilink ISDN users cannot have per-user timeouts applied to them. Only the global timeouts statically configured on the interface (if any) will apply. If you try to apply per-user timeouts to a non-multilink ISDN user and don't have virtual-profiles turned on, the user connection will fail authorization because the access-server was unable to process the mandatory per-user timeout attributes.
Additionally, a feature has been added to Cisco IOS 11.3(8.1)T and later versions which allows per-user timeouts to be applied to non-multilink ISDN users. It essentially bypasses the background process configuration mode that is usually used and sets the timers directly onto the B-channel without using the command line interface.
To summarize this complicated setup, here are two rules you can follow:
-
If not using virtual profiles, configure dialer in-band on the async interfaces and run Cisco IOS 11.3(8.1)T or later. If you are running Cisco IOS 11.3(8)T, beware that non-multilink ISDN users cannot have per-user timeouts applied to them, otherwise they will fail to connect.
-
If using virtual profiles, Cisco IOS 11.3(8)T or later will work well.
Verify
There is currently no verification procedure available for this configuration.
Troubleshoot
This section provides information you can use to troubleshoot your configuration. For the purposes of debugging, six call output examples are included. To jump directly to a particular section, select one of the links below:
Certain show commands are supported by the Output Interpreter Tool (registered customers only) , which allows you to view an analysis of show command output.
Note: Before issuing debug commands, refer to Important Information on Debug Commands.
- Async Call with Virtual Profiles - Connection Does Not Idle Out
- Async Call with Virtual Profiles - Connection Idles Out
- Async Call without Virtual Profiles
- Multilink Single Channel ISDN Call without Virtual Profiles
- Non-Multilink Single Channel ISDN Call without Virtual Profiles
- Non-Multilink Single Channel ISDN Call with Virtual Profiles
Note: To see the same commands and output that are presented below, you must be running Cisco IOS version 11.3AA or version 12.0T.
Async Call with Virtual Profiles - Connection Does Not Idle Out
Below is an async call with virtual profiles. The profile installs a 90 second absolute timeout and a 60 second idle timeout. In this example, we will not let the connection idle out. See the comments in the output below for more details. Comments are highlighted and in italicized text.
!--- ISDN setup message comes in.
*Mar 4 19:21:47.772: ISDN Se0:23: RX <- SETUP pd = 8 callref = 0x09
*Mar 4 19:21:47.772: Bearer Capability i = 0x9090A2
*Mar 4 19:21:47.772: Channel ID i = 0xA98393
*Mar 4 19:21:47.772: Called Party Number i = 0xC1, '4085703932'
*Mar 4 19:21:47.776: ISDN Se0:23: TX -> CALL_PROC pd = 8 callref = 0x8009
*Mar 4 19:21:47.776: Channel ID i = 0xA98393
*Mar 4 19:21:47.776: ISDN Se0:23: TX -> ALERTING pd = 8 callref = 0x8009
!--- Modem is allocated.
*Mar 4 19:21:47.776: EVENT_FROM_ISDN::dchan_idb=0x6122CFCC, call_id=0x3D, ces=0x1
bchan=0x12, event=0x1, cause=0x0
*Mar 4 19:21:47.776: VDEV_ALLOCATE: slot 1 and port 28 is allocated.
*Mar 4 19:21:47.776: EVENT_FROM_ISDN:(003D): DEV_INCALL at slot 1 and port 28
*Mar 4 19:21:47.776: CSM_PROC_IDLE: CSM_EVENT_ISDN_CALL at slot 1, port 28
*Mar 4 19:21:47.776: Mica Modem(1/28): Configure(0x1 = 0x0)
*Mar 4 19:21:47.776: Mica Modem(1/28): Configure(0x23 = 0x0)
*Mar 4 19:21:47.776: Mica Modem(1/28): Call Setup
*Mar 4 19:21:47.932: Mica Modem(1/28): State Transition to Call Setup
!--- Modem goes offhook.
*Mar 4 19:21:47.932: Mica Modem(1/28): Went offhook
*Mar 4 19:21:47.932: CSM_PROC_IC1_RING: CSM_EVENT_MODEM_OFFHOOK at slot 1, port 28
*Mar 4 19:21:47.932: ISDN Se0:23: TX -> CONNECT pd = 8 callref = 0x8009
*Mar 4 19:21:47.996: ISDN Se0:23: RX <- CONNECT_ACK pd = 8 callref = 0x09
!--- DS0 is cut-through.
*Mar 4 19:21:47.996: EVENT_FROM_ISDN::dchan_idb=0x6122CFCC, call_id=0x3D, ces=0x1
bchan=0x12, event=0x4, cause=0x0
*Mar 4 19:21:47.996: EVENT_FROM_ISDN:(003D): DEV_CONNECTED at slot 1 and port 28
*Mar 4 19:21:47.996: CSM_PROC_IC4_WAIT_FOR_CARRIER: CSM_EVENT_ISDN_CONNECTED
at slot 1, port 28
!--- Modem training starts.
*Mar 4 19:21:47.996: Mica Modem(1/28): Link Initiate
*Mar 4 19:21:49.140: Mica Modem(1/28): State Transition to Connect
*Mar 4 19:21:54.276: Mica Modem(1/28): State Transition to Link
*Mar 4 19:22:05.828: Mica Modem(1/28): State Transition to Trainup
*Mar 4 19:22:09.028: Mica Modem(1/28): State Transition to EC Negotiating
*Mar 4 19:22:09.568: Mica Modem(1/28): State Transition to Steady State
!--- Modem training completes.
*Mar 4 19:22:10.128: AAA: parse NAME=tty53 idb TYPE=10 tty=53
*Mar 4 19:22:10.128: AAA: NAME=tty53 flags=0x11 TYPE=4 shelf=0 slot=0 adapter=0 port=53
channel=0
*Mar 4 19:22:10.128: AAA: parse NAME=Serial0:18 idb TYPE=12 tty=-1
*Mar 4 19:22:10.128: AAA: NAME=Serial0:18 flags=0x51 TYPE=1 shelf=0 slot=0 adapter=0
port=0 channel=18
!--- PPP begins negotiation.
*Mar 4 19:22:11.332: As53 LCP: Lower layer not up, Fast Starting
*Mar 4 19:22:11.332: As53 PPP: Treating connection as a dedicated line
*Mar 4 19:22:11.332: As53 AAA/AUTHOR/FSM: (0): LCP succeeds trivially
!--- LCP negotiation completes, authentication begins.
*Mar 4 19:22:13.556: As53 PPP: Phase is AUTHENTICATING, by this end
*Mar 4 19:22:13.556: As53 CHAP: O CHALLENGE id 1 len 26 from "STACK"
*Mar 4 19:22:16.016: As53 AUTH: Started process 0 pid 45
*Mar 4 19:22:16.016: As53 AAA/AUTHOR/PER-USER: Event LCP_DOWN
*Mar 4 19:22:16.208: As53 PPP: Phase is AUTHENTICATING, by this end
*Mar 4 19:22:16.208: As53 CHAP: O CHALLENGE id 2 len 26 from "STACK"
!--- CHAP response received from client.
*Mar 4 19:22:16.304: As53 CHAP: I RESPONSE id 2 len 30 from "timeout"
*Mar 4 19:22:16.304: AAA: parse NAME=Async53 idb TYPE=10 tty=53
*Mar 4 19:22:16.304: AAA: NAME=Async53 flags=0x11 TYPE=4 shelf=0 slot=0
adapter=0 port=53 channel=0
*Mar 4 19:22:16.304: AAA: parse NAME=Serial0:18 idb TYPE=12 tty=-1
*Mar 4 19:22:16.304: AAA: NAME=Serial0:18 flags=0x51 TYPE=1 shelf=0 slot=0
adapter=0 port=0 channel=18
!--- Send RADIUS query.
*Mar 4 19:22:16.304: RADIUS: ustruct sharecount=1
*Mar 4 19:22:16.304: RADIUS: Initial Transmit Async53 id 0 172.16.24.117:1645,
Access-Request, len 92
*Mar 4 19:22:16.304: Attribute 4 6 AC101874
*Mar 4 19:22:16.304: Attribute 5 6 00000035
*Mar 4 19:22:16.304: Attribute 61 6 00000000
*Mar 4 19:22:16.304: Attribute 1 11 74696D65
*Mar 4 19:22:16.304: Attribute 30 12 34303835
*Mar 4 19:22:16.304: Attribute 3 19 0283D0F9
*Mar 4 19:22:16.308: Attribute 6 6 00000002
*Mar 4 19:22:16.308: Attribute 7 6 00000001
!--- Received RADIUS response, note attribute 27 (Session-Timeout -> absolute timeout) !--- is 0x5A (90) and attribute 28 (Idle-Timeout) is 0x3C (60).
*Mar 4 19:22:16.316: RADIUS: Received from id 0 172.16.24.117:1645,
Access-Accept, len 50
*Mar 4 19:22:16.316: Attribute 6 6 00000002
*Mar 4 19:22:16.320: Attribute 7 6 00000001
*Mar 4 19:22:16.320: Attribute 8 6 FFFFFFFE
*Mar 4 19:22:16.320: Attribute 27 6 0000005A
*Mar 4 19:22:16.320: Attribute 28 6 0000003C
!--- Start LCP authorization.
*Mar 4 19:22:16.320: As53 AAA/AUTHOR/LCP: Authorize LCP
*Mar 4 19:22:16.320: AAA/AUTHOR/LCP As53 (3506139973): Port='Async53' list=''
service=NET
*Mar 4 19:22:16.320: AAA/AUTHOR/LCP: As53 (3506139973) send AV service=ppp
*Mar 4 19:22:16.320: AAA/AUTHOR/LCP: As53 (3506139973) send AV protocol=lcp
*Mar 4 19:22:16.320: AAA/AUTHOR/LCP (3506139973) found list "default"
*Mar 4 19:22:16.320: AAA/AUTHOR/LCP: As53 (3506139973) METHOD=RADIUS
*Mar 4 19:22:16.320: AAA/AUTHOR (3506139973): Post authorization status = PASS_REPL
!--- Gleaned per-user timeouts from user profile.
*Mar 4 19:22:16.320: As53 AAA/AUTHOR/LCP: Processing AV service=ppp
*Mar 4 19:22:16.320: As53 AAA/AUTHOR/LCP: Processing AV timeout=90
*Mar 4 19:22:16.320: As53 AAA/AUTHOR/LCP: Processing AV idletime=60
!--- Translate AAA attributes to interface configuration commands. !--- Since we are using virtual-profiles, we will use the "ppp timeout idle" !--- command instead of the "dialer in-band" command. Note that 90 second absolute timeout !--- translates to the command "timeout absolute 1 30" (1 minute and 30 seconds).
*Mar 4 19:22:16.320: AAA/AUTHOR/LCP As53: Per-user interface config created:
timeout absolute 1 30
ppp timeout idle 60
!--- PPP authentication succeeds.
*Mar 4 19:22:16.320: As53 CHAP: O SUCCESS id 2 len 4
*Mar 4 19:22:16.320: AAA/ACCT/NET/START User timeout, Port Async53, List ""
*Mar 4 19:22:16.320: AAA/ACCT/NET: Found list "default"
!--- Create new vaccess interface.
*Mar 4 19:22:16.416: VTEMPLATE: No unused vaccess, create new vaccess
*Mar 4 19:22:16.416: Vi1 VTEMPLATE: Set default settings with no ip address, encap ppp
*Mar 4 19:22:16.440: Vi1 VTEMPLATE: Hardware address 00e0.1e81.636c
*Mar 4 19:22:16.440: Vi1 VTEMPLATE: Has a new cloneblk vtemplate, now it has vtemplate
*Mar 4 19:22:16.440: Vi1 VTEMPLATE: ************* CLONE VACCESS1 *****************
*Mar 4 19:22:16.440: Vi1 VTEMPLATE: Clone from Virtual-Template1
interface Virtual-Access1
default ip address
no ip address
encap ppp
ip unnumbered Loopback0
ip access-group 199 in
ip helper-address 172.16.24.118
no ip directed-broadcast
ip accounting output-packets
ip nat inside
no keepalive
peer default ip address pool default
compress mppc
ppp callback accept
ppp authentication chap pap ms-chap
ppp multilink
multilink max-links 2
end
*Mar 4 19:22:16.504: Vi1 CCP: Re-Syncing history using legacy method
!--- Now add the per-user timeouts we constructed for this user.
*Mar 4 19:22:16.520: Vi1 VTEMPLATE: Has a new cloneblk AAA, now it has vtemplate/AAA
*Mar 4 19:22:16.520: Vi1 VTEMPLATE: ************* CLONE VACCESS1 *****************
*Mar 4 19:22:16.520: Vi1 VTEMPLATE: Clone from AAA
interface Virtual-Access1
timeout absolute 1 30
ppp timeout idle 60
end
!--- LCP layer is finished, negotiate the appropriate NCPs.
*Mar 4 19:22:16.532: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state to up
*Mar 4 19:22:16.536: Vi1 PPP: Treating connection as a dedicated line
*Mar 4 19:22:16.536: Vi1 AAA/AUTHOR/FSM: (0): LCP succeeds trivially
*Mar 4 19:22:16.536: Vi1 AAA/AUTHOR/FSM: (0): Can we start IPCP?
*Mar 4 19:22:16.536: AAA/AUTHOR/FSM Vi1 (1906691625): Port='Async53' list='' service=NET
*Mar 4 19:22:16.536: AAA/AUTHOR/FSM: Vi1 (1906691625) send AV service=ppp
*Mar 4 19:22:16.536: AAA/AUTHOR/FSM: Vi1 (1906691625) send AV protocol=ip
*Mar 4 19:22:16.536: AAA/AUTHOR/FSM (1906691625) found list "default"
*Mar 4 19:22:16.536: AAA/AUTHOR/FSM: Vi1 (1906691625) METHOD=RADIUS
*Mar 4 19:22:16.536: RADIUS: Using NAS default peer
*Mar 4 19:22:16.536: RADIUS: Authorize IP address 0.0.0.0
*Mar 4 19:22:16.536: AAA/AUTHOR (1906691625): Post authorization status = PASS_REPL
*Mar 4 19:22:16.536: Vi1 AAA/AUTHOR/FSM: We can start IPCP
*Mar 4 19:22:16.536: Vi1 AAA/AUTHOR/FSM: (0): Can we start CCP?
*Mar 4 19:22:16.536: AAA/AUTHOR/FSM Vi1 (282953275): Port='Async53' list='' service=NET
*Mar 4 19:22:16.536: AAA/AUTHOR/FSM: Vi1 (282953275) send AV service=ppp
*Mar 4 19:22:16.536: AAA/AUTHOR/FSM: Vi1 (282953275) send AV protocol=ccp
*Mar 4 19:22:16.536: AAA/AUTHOR/FSM (282953275) found list "default"
*Mar 4 19:22:16.536: AAA/AUTHOR/FSM: Vi1 (282953275) METHOD=RADIUS
*Mar 4 19:22:16.540: AAA/AUTHOR (282953275): Post authorization status = PASS_REPL
*Mar 4 19:22:16.540: Vi1 AAA/AUTHOR/FSM: We can start CCP
*Mar 4 19:22:16.540: Vi1 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 0.0.0.0
*Mar 4 19:22:16.540: Vi1 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:22:16.540: Vi1 AAA/AUTHOR/IPCP: Processing AV addr=0.0.0.0
*Mar 4 19:22:16.540: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:22:16.540: Vi1 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 0.0.0.0
*Mar 4 19:22:16.540: Vi1 AAA/AUTHOR/FSM: Check for unauthorized mandatory AV's
*Mar 4 19:22:16.540: Vi1 AAA/AUTHOR/FSM: Processing AV service=ppp
*Mar 4 19:22:16.540: Vi1 AAA/AUTHOR/FSM: Succeeded
*Mar 4 19:22:16.656: Vi1 AAA/AUTHOR/FSM: Check for unauthorized mandatory AV's
*Mar 4 19:22:16.656: Vi1 AAA/AUTHOR/FSM: Processing AV service=ppp
*Mar 4 19:22:16.656: Vi1 AAA/AUTHOR/FSM: Succeeded
*Mar 4 19:22:17.536: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to up
*Mar 4 19:22:19.516: Vi1 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 10.1.1.3
*Mar 4 19:22:19.516: Vi1 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:22:19.516: Vi1 AAA/AUTHOR/IPCP: Processing AV addr=0.0.0.0
*Mar 4 19:22:19.516: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:22:19.516: Vi1 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 10.1.1.3
*Mar 4 19:22:19.608: Vi1 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 10.1.1.3
*Mar 4 19:22:19.608: Vi1 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:22:19.608: Vi1 AAA/AUTHOR/IPCP: Processing AV addr=0.0.0.0
*Mar 4 19:22:19.608: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:22:19.612: Vi1 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 10.1.1.3
*Mar 4 19:22:19.704: Vi1 AAA/AUTHOR/IPCP: Start. Her address 10.1.1.3, we want 10.1.1.3
*Mar 4 19:22:19.704: AAA/AUTHOR/IPCP Vi1 (785695075): Port='Async53' list='' service=NET
*Mar 4 19:22:19.708: AAA/AUTHOR/IPCP: Vi1 (785695075) send AV service=ppp
*Mar 4 19:22:19.708: AAA/AUTHOR/IPCP: Vi1 (785695075) send AV protocol=ip
*Mar 4 19:22:19.708: AAA/AUTHOR/IPCP: Vi1 (785695075) send AV addr*10.1.1.3
*Mar 4 19:22:19.708: AAA/AUTHOR/IPCP (785695075) found list "default"
*Mar 4 19:22:19.708: AAA/AUTHOR/IPCP: Vi1 (785695075) METHOD=RADIUS
*Mar 4 19:22:19.708: RADIUS: Using NAS default peer
*Mar 4 19:22:19.708: RADIUS: Authorize IP address 10.1.1.3
*Mar 4 19:22:19.708: AAA/AUTHOR (785695075): Post authorization status = PASS_REPL
*Mar 4 19:22:19.708: Vi1 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:22:19.708: Vi1 AAA/AUTHOR/IPCP: Processing AV addr=10.1.1.3
*Mar 4 19:22:19.708: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:22:19.708: Vi1 AAA/AUTHOR/IPCP: Done. Her address 10.1.1.3, we want 10.1.1.3
*Mar 4 19:22:19.708: Vi1 AAA/AUTHOR/PER-USER: Event IP_UP
*Mar 4 19:22:19.708: Vi1 AAA/PER-USER: processing author params.
!--- PPP negotiation finished, user is connected.
!--- User is connected on line 53, async interface 53 and vaccess 1. The "show caller" !--- command shows active time and idle time for this user in Cisco IOS 11.3(8.1)AA or later.
access-3#show caller
Active Idle
Line User Service Time Time
tty 53 timeout Async 00:00:20 00:00:02
As53 timeout PPP 00:00:13 00:00:02
Vi1 timeout PPP VDP 00:00:13 00:00:11
!--- The "show caller timeout" command shows the installed absolute and idle timeout as well !--- as how much time before the user is disconnected by any timeouts. Note the timeouts !--- only show up on the vaccess interface.
access-3#show caller timeouts
Session Idle Disconnect
Line User Timeout Timeout User in
tty 53 timeout - - -
As53 timeout - - -
Vi1 timeout 00:01:30 00:01:00 00:00:43
!--- The "show caller user" command gives more detailed information about the user as well as !--- providing a breakdown of the active and idle time, absolute and idle timeout, !--- and time to disconnect for both idle and absolute timeout.
access-3#show caller user timeout
User: timeout, line tty 53, service Async
Active time 00:00:31, Idle time 00:00:12
Timeouts: Absolute Idle Idle
Session Exec
Limits: - - 00:10:00
Disconnect in: - - -
TTY: Line 53, running PPP on As53
Location: MICA V.90 modems
Line: Baud rate (TX/RX) is 115200/115200, no parity, 1 stopbits, 8 databits
Status: Ready, Active, No Exit Banner, Async Interface Active
HW PPP Support Active
Capabilities: No Flush-at-Activation, Hardware Flowcontrol In
Hardware Flowcontrol Out, Modem Callout, Modem RI is CD
Line usable as async interface, ARAP Permitted
Integrated Modem
Modem State: Ready
User: timeout, line As53, service PPP
Active time 00:00:23, Idle time 00:00:12
Timeouts: Absolute Idle
Limits: - -
Disconnect in: - -
PPP: LCP Open, multilink Closed, CHAP (<- AAA)
IP: Local 10.1.1.1
Counts: 35 packets input, 820 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
22 packets output, 517 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
User: timeout, line Vi1, service PPP VDP
Active time 00:00:24, Idle time 00:00:22
Timeouts: Absolute Idle
Limits: 00:01:30 00:01:00
Disconnect in: 00:01:05 00:00:37
PPP: LCP Open, multilink Closed, CHAP (<- none), IPCP, CCP
Idle timer 60 secs, idle 22 secs
IP: Local 10.1.1.1, remote 10.1.1.3
Access list (I/O) is 199/not set
Counts: 24 packets input, 542 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
19 packets output, 167 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
access-3#show caller timeout
Session Idle Disconnect
Line User Timeout Timeout User in
tty 53 timeout - - -
As53 timeout - - -
Vi1 timeout 00:01:30 00:01:00 00:00:35
access-3#show caller
Active Idle
Line User Service Time Time
tty 53 timeout Async 00:00:45 00:00:27
As53 timeout PPP 00:00:38 00:00:27
Vi1 timeout PPP VDP 00:00:38 00:00:36
!--- User has been idle for 36 seconds and will be disconnected in 24 seconds. Let's !--- ping the user to see what happens.
access-3#ping 10.1.1.3
Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 10.1.1.3, timeout is 2 seconds:
!!!!!
Success rate is 100 percent (5/5), round-trip min/avg/max = 92/108/132 ms
!--- Now the idle timer has been reset, so we won't disconnect the user for another !--- 58 seconds.
access-3#show caller timeout
Session Idle Disconnect
Line User Timeout Timeout User in
tty 53 timeout - - -
As53 timeout - - -
Vi1 timeout 00:01:30 00:01:00 00:00:58
!--- Ping again to reset the idle timer.
access-3#ping 10.1.1.3
Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 10.1.1.3, timeout is 2 seconds:
!!!!!
Success rate is 100 percent (5/5), round-trip min/avg/max = 96/98/108 ms
!--- But note, the disconnect timer did not go back to 1 minute. The reason is because the !--- absolute timer is going to start soon.
access-3#show caller timeout
Session Idle Disconnect
Line User Timeout Timeout User in
tty 53 timeout - - -
As53 timeout - - -
Vi1 timeout 00:01:30 00:01:00 00:00:24
access-3#show caller user timeout
User: timeout, line tty 53, service Async
Active time 00:01:23, Idle time 00:00:11
Timeouts: Absolute Idle Idle
Session Exec
Limits: - - 00:10:00
Disconnect in: - - -
TTY: Line 53, running PPP on As53
Location: MICA V.90 modems
Line: Baud rate (TX/RX) is 115200/115200, no parity, 1 stopbits, 8 databits
Status: Ready, Active, No Exit Banner, Async Interface Active
HW PPP Support Active
Capabilities: No Flush-at-Activation, Hardware Flowcontrol In
Hardware Flowcontrol Out, Modem Callout, Modem RI is CD
Line usable as async interface, ARAP Permitted
Integrated Modem
Modem State: Ready
User: timeout, line As53, service PPP
Active time 00:01:15, Idle time 00:00:11
Timeouts: Absolute Idle
Limits: - -
Disconnect in: - -
PPP: LCP Open, multilink Closed, CHAP (<- AAA)
IP: Local 10.1.1.1
Counts: 45 packets input, 1161 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
32 packets output, 897 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
User: timeout, line Vi1, service PPP VDP
Active time 00:01:16, Idle time 00:00:12
Timeouts: Absolute Idle
Limits: 00:01:30 00:01:00
Disconnect in: 00:00:13 00:00:47
PPP: LCP Open, multilink Closed, CHAP (<- none), IPCP, CCP
Idle timer 60 secs, idle 12 secs
IP: Local 10.1.1.1, remote 10.1.1.3
Access list (I/O) is 199/not set
Counts: 34 packets input, 883 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
39 packets output, 547 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
!--- User is disconnected.
*Mar 4 19:23:47.536: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state to down
*Mar 4 19:23:47.536: Vi1 VTEMPLATE: Free vaccess
*Mar 4 19:23:47.540: As53 AAA/ACCT: non-ISDN xmit 50000 recv 28800 hwidb 613307E0 ttynum 53
!--- Send accounting stop record, includes disc-cause 5 (session-timeout) and
!--- disc-cause-ext 1100 (session-timeout).
*Mar 4 19:23:47.540: AAA/ACCT/NET/STOP User timeout, Port Async53:
task_id=9 timezone=PST service=ppp protocol=ip addr=10.1.1.3 disc-cause=5
disc-cause-ext=1100
pre-bytes-in=184 pre-bytes-out=330 pre-paks-in=7 pre-paks-out=11 bytes_in=950
bytes_out=567 paks_in=37
paks_out=21 pre-session-time=5 elapsed_time=91 nas-rx-speed=28800 nas-tx-speed=50000
*Mar 4 19:23:47.540: Vi1 AAA/AUTHOR/PER-USER: Event IP_DOWN
*Mar 4 19:23:47.540: Vi1 AAA/AUTHOR/PER-USER: Event LCP_DOWN
!--- Modem hangs up.
*Mar 4 19:23:47.580: Mica Modem(1/28): State Transition to Terminating
*Mar 4 19:23:47.640: Mica Modem(1/28): State Transition to Idle
*Mar 4 19:23:47.640: Mica Modem(1/28): Went onhook
*Mar 4 19:23:47.640: CSM_PROC_IC5_OC6_CONNECTED: CSM_EVENT_MODEM_ONHOOK at slot 1, port 28
*Mar 4 19:23:47.640: VDEV_DEALLOCATE: slot 1 and port 28 is deallocated
*Mar 4 19:23:47.640: ISDN Se0:23: Event: Hangup call to call id 0x3D
!--- ISDN call is terminated.
*Mar 4 19:23:47.640: ISDN Se0:23: TX -> DISCONNECT pd = 8 callref = 0x8009
*Mar 4 19:23:47.640: Cause i = 0x8090 - Normal call clearing
*Mar 4 19:23:47.688: ISDN Se0:23: RX <- RELEASE pd = 8 callref = 0x09
*Mar 4 19:23:47.696: ISDN Se0:23: TX -> RELEASE_COMP pd = 8 callref = 0x8009
*Mar 4 19:23:47.744: TAC+: (866083896): received acct response status = SUCCESS
!--- Per-user timeouts are taken off the vaccess interface.
*Mar 4 19:23:48.140: VTEMPLATE: Clean up dirty vaccess queue, size 1
*Mar 4 19:23:48.140: Vi1 VTEMPLATE: Found a dirty vaccess clone with vtemplate/AAA
*Mar 4 19:23:48.140: Vi1 VTEMPLATE: ************ UNCLONE VACCESS1 **************
*Mar 4 19:23:48.140: Vi1 VTEMPLATE: Unclone to-be-freed command#2
interface Virtual-Access1
default ppp timeout idle 60
default timeout absolute 1 30
end
!--- vaccess interface is cleaned up.
*Mar 4 19:23:48.160: Vi1 VTEMPLATE: Set default settings with no ip address
*Mar 4 19:23:48.176: Vi1 VTEMPLATE: Remove cloneblk AAA with vtemplate/AAA
*Mar 4 19:23:48.180: Vi1 VTEMPLATE: ************ UNCLONE VACCESS1 **************
*Mar 4 19:23:48.180: Vi1 VTEMPLATE: Unclone to-be-freed command#15
interface Virtual-Access1
default multilink max-links 2
default ppp multilink
default ppp authentication chap pap ms-chap
default ppp callback accept
default compress mppc
default peer default ip address pool default
default keepalive
default ip nat inside
default ip accounting output-packets
default ip directed-broadcast
default ip helper-address 172.16.24.118
default ip access-group 199 in
default ip unnumbered Loopback0
default encap ppp
default ip address
end
*Mar 4 19:23:48.264: Vi1 VTEMPLATE: Set default settings with no ip address
*Mar 4 19:23:48.284: Vi1 VTEMPLATE: Remove cloneblk vtemplate with vtemplate/AAA
*Mar 4 19:23:48.284: Vi1 VTEMPLATE: Add vaccess to recycle queue, queue SIZE=1
!--- Here is the call record for the user. Note the disconnect reason is Session-Timeout !--- (absolute timeout).
*Mar 4 19:23:48.300: %CALLRECORD-3-MICA_TERSE_CALL_REC: DS0 slot/contr/chan=2/0/18,
slot/port=1/28, call_id=3D, userid=timeout, ip=10.1.1.3, calling=(n/a), called=4085703932,
std=K56Flx, prot=LAP-M, comp=V.42bis both, init-rx/tx b-rate=28800/50000, finl-rx/tx
b-rate=28800/50000, rbs=0, d-pad=6 dB, retr=0, sq=3, snr=32, rx/tx chars=1274/1477, bad=4,
rx/tx ec=45/61, bad=3, time=118, finl-state=Steady, disc(radius)=Session Timeout/Session Timeout,
disc(modem)=DF03 Tx (host to line) data flushing - OK/Requested by host/DTR dropped
*Mar 4 19:23:48.536: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to down
*Mar 4 19:23:49.536: As53 AAA/AUTHOR/PER-USER: Event LCP_DOWN
Async Call with Virtual Profiles - Connection Idles Out
Below is an async call with virtual profiles. It has the same username as the example above. The profile installs a 90 second absolute timeout and a 60 second idle timeout. In this example, we will let the connection idle out. There are no comments below, but important output has been highlighted.
*Mar 4 19:24:38.768: ISDN Se0:23: RX <- SETUP pd = 8 callref = 0x0A
*Mar 4 19:24:38.768: Bearer Capability i = 0x9090A2
*Mar 4 19:24:38.768: Channel ID i = 0xA98393
*Mar 4 19:24:38.768: Called Party Number i = 0xC1, '4085703932'
*Mar 4 19:24:38.772: ISDN Se0:23: TX -> CALL_PROC pd = 8 callref = 0x800A
*Mar 4 19:24:38.772: Channel ID i = 0xA98393
*Mar 4 19:24:38.772: ISDN Se0:23: TX -> ALERTING pd = 8 callref = 0x800A
*Mar 4 19:24:38.772: EVENT_FROM_ISDN::dchan_idb=0x6122CFCC, call_id=0x3E, ces=0x1
bchan=0x12, event=0x1, cause=0x0
*Mar 4 19:24:38.772: VDEV_ALLOCATE: slot 1 and port 29 is allocated.
*Mar 4 19:24:38.772: EVENT_FROM_ISDN:(003E): DEV_INCALL at slot 1 and port 29
*Mar 4 19:24:38.772: CSM_PROC_IDLE: CSM_EVENT_ISDN_CALL at slot 1, port 29
*Mar 4 19:24:38.772: Mica Modem(1/29): Configure(0x1 = 0x0)
*Mar 4 19:24:38.772: Mica Modem(1/29): Configure(0x23 = 0x0)
*Mar 4 19:24:38.772: Mica Modem(1/29): Call Setup
*Mar 4 19:24:38.908: Mica Modem(1/29): State Transition to Call Setup
*Mar 4 19:24:38.908: Mica Modem(1/29): Went offhook
*Mar 4 19:24:38.908: CSM_PROC_IC1_RING: CSM_EVENT_MODEM_OFFHOOK at slot 1, port 29
*Mar 4 19:24:38.912: ISDN Se0:23: TX -> CONNECT pd = 8 callref = 0x800A
*Mar 4 19:24:38.972: ISDN Se0:23: RX <- CONNECT_ACK pd = 8 callref = 0x0A
*Mar 4 19:24:38.976: EVENT_FROM_ISDN::dchan_idb=0x6122CFCC, call_id=0x3E, ces=0x1
bchan=0x12, event=0x4, cause=0x0
*Mar 4 19:24:38.976: EVENT_FROM_ISDN:(003E): DEV_CONNECTED at slot 1 and port 29
*Mar 4 19:24:38.976: CSM_PROC_IC4_WAIT_FOR_CARRIER: CSM_EVENT_ISDN_CONNECTED at
slot 1, port 29
*Mar 4 19:24:38.976: Mica Modem(1/29): Link Initiate
*Mar 4 19:24:40.060: Mica Modem(1/29): State Transition to Connect
*Mar 4 19:24:45.256: Mica Modem(1/29): State Transition to Link
*Mar 4 19:24:56.796: Mica Modem(1/29): State Transition to Trainup
*Mar 4 19:24:59.996: Mica Modem(1/29): State Transition to EC Negotiating
*Mar 4 19:25:00.532: Mica Modem(1/29): State Transition to Steady State
*Mar 4 19:25:01.340: AAA: parse NAME=tty54 idb TYPE=10 tty=54
*Mar 4 19:25:01.340: AAA: NAME=tty54 flags=0x11 TYPE=4 shelf=0 slot=0
adapter=0 port=54 channel=0
*Mar 4 19:25:01.340: AAA: parse NAME=Serial0:18 idb TYPE=12 tty=-1
*Mar 4 19:25:01.340: AAA: NAME=Serial0:18 flags=0x51 TYPE=1 shelf=0 slot=0
adapter=0 port=0 channel=18
*Mar 4 19:25:02.544: As54 LCP: Lower layer not up, Fast Starting
*Mar 4 19:25:02.544: As54 PPP: Treating connection as a dedicated line
*Mar 4 19:25:02.544: As54 AAA/AUTHOR/FSM: (0): LCP succeeds trivially
*Mar 4 19:25:04.744: As54 PPP: Phase is AUTHENTICATING, by this end
*Mar 4 19:25:04.744: As54 CHAP: O CHALLENGE id 1 len 26 from "STACK"
*Mar 4 19:25:06.628: As54 AAA/AUTHOR/PER-USER: Event LCP_DOWN
*Mar 4 19:25:06.820: As54 PPP: Phase is AUTHENTICATING, by this end
*Mar 4 19:25:06.820: As54 CHAP: O CHALLENGE id 2 len 26 from "STACK"
*Mar 4 19:25:06.916: As54 CHAP: I RESPONSE id 2 len 30 from "timeout"
*Mar 4 19:25:06.916: AAA: parse NAME=Async54 idb TYPE=10 tty=54
*Mar 4 19:25:06.916: AAA: NAME=Async54 flags=0x11 TYPE=4 shelf=0 slot=0
adapter=0 port=54 channel=0
*Mar 4 19:25:06.916: AAA: parse NAME=Serial0:18 idb TYPE=12 tty=-1
*Mar 4 19:25:06.916: AAA: NAME=Serial0:18 flags=0x51 TYPE=1 shelf=0 slot=0
adapter=0 port=0 channel=18
*Mar 4 19:25:06.916: RADIUS: ustruct sharecount=1
*Mar 4 19:25:06.916: RADIUS: Initial Transmit Async54 id 1 172.16.24.117:1645,
Access-Request, len 92
*Mar 4 19:25:06.916: Attribute 4 6 AC101874
*Mar 4 19:25:06.916: Attribute 5 6 00000036
*Mar 4 19:25:06.916: Attribute 61 6 00000000
*Mar 4 19:25:06.916: Attribute 1 11 74696D65
*Mar 4 19:25:06.916: Attribute 30 12 34303835
*Mar 4 19:25:06.916: Attribute 3 19 024525C7
*Mar 4 19:25:06.916: Attribute 6 6 00000002
*Mar 4 19:25:06.916: Attribute 7 6 00000001
*Mar 4 19:25:06.924: RADIUS: Received from id 1 172.16.24.117:1645,
Access-Accept, len 50
*Mar 4 19:25:06.924: Attribute 6 6 00000002
*Mar 4 19:25:06.924: Attribute 7 6 00000001
*Mar 4 19:25:06.924: Attribute 8 6 FFFFFFFE
*Mar 4 19:25:06.924: Attribute 27 6 0000005A
*Mar 4 19:25:06.928: Attribute 28 6 0000003C
*Mar 4 19:25:06.928: As54 AAA/AUTHOR/LCP: Authorize LCP
*Mar 4 19:25:06.928: AAA/AUTHOR/LCP As54 (2013841092): Port='Async54' list='' service=NET
*Mar 4 19:25:06.928: AAA/AUTHOR/LCP: As54 (2013841092) send AV service=ppp
*Mar 4 19:25:06.928: AAA/AUTHOR/LCP: As54 (2013841092) send AV protocol=lcp
*Mar 4 19:25:06.928: AAA/AUTHOR/LCP (2013841092) found list "default"
*Mar 4 19:25:06.928: AAA/AUTHOR/LCP: As54 (2013841092) METHOD=RADIUS
*Mar 4 19:25:06.928: AAA/AUTHOR (2013841092): Post authorization status = PASS_REPL
*Mar 4 19:25:06.928: As54 AAA/AUTHOR/LCP: Processing AV service=ppp
*Mar 4 19:25:06.928: As54 AAA/AUTHOR/LCP: Processing AV timeout=90
*Mar 4 19:25:06.928: As54 AAA/AUTHOR/LCP: Processing AV idletime=60
*Mar 4 19:25:06.928: AAA/AUTHOR/LCP As54: Per-user interface config created:
timeout absolute 1 30
ppp timeout idle 60
*Mar 4 19:25:06.928: As54 CHAP: O SUCCESS id 2 len 4
*Mar 4 19:25:06.928: AAA/ACCT/NET/START User timeout, Port Async54, List ""
*Mar 4 19:25:06.928: AAA/ACCT/NET: Found list "default"
*Mar 4 19:25:07.028: Vi1 VTEMPLATE: Reuse Vi1, recycle queue size 0
*Mar 4 19:25:07.028: Vi1 VTEMPLATE: Hardware address 00e0.1e81.636c
*Mar 4 19:25:07.028: Vi1 VTEMPLATE: Has a new cloneblk vtemplate, now it has vtemplate
*Mar 4 19:25:07.028: Vi1 VTEMPLATE: ************* CLONE VACCESS1 *****************
*Mar 4 19:25:07.028: Vi1 VTEMPLATE: Clone from Virtual-Template1
interface Virtual-Access1
default ip address
no ip address
encap ppp
ip unnumbered Loopback0
ip access-group 199 in
ip helper-address 172.16.24.118
no ip directed-broadcast
ip accounting output-packets
ip nat inside
no keepalive
peer default ip address pool default
compress mppc
ppp callback accept
ppp authentication chap pap ms-chap
ppp multilink
multilink max-links 2
end
*Mar 4 19:25:07.092: Vi1 CCP: Re-Syncing history using legacy method
*Mar 4 19:25:07.108: Vi1 VTEMPLATE: Has a new cloneblk AAA, now it has vtemplate/AAA
*Mar 4 19:25:07.108: Vi1 VTEMPLATE: ************* CLONE VACCESS1 *****************
*Mar 4 19:25:07.108: Vi1 VTEMPLATE: Clone from AAA
interface Virtual-Access1
timeout absolute 1 30
ppp timeout idle 60
end
*Mar 4 19:25:07.120: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state to up
*Mar 4 19:25:07.124: Vi1 PPP: Treating connection as a dedicated line
*Mar 4 19:25:07.124: Vi1 AAA/AUTHOR/FSM: (0): LCP succeeds trivially
*Mar 4 19:25:07.124: Vi1 AAA/AUTHOR/FSM: (0): Can we start IPCP?
*Mar 4 19:25:07.124: AAA/AUTHOR/FSM Vi1 (3979277251): Port='Async54' list='' service=NET
*Mar 4 19:25:07.124: AAA/AUTHOR/FSM: Vi1 (3979277251) send AV service=ppp
*Mar 4 19:25:07.124: AAA/AUTHOR/FSM: Vi1 (3979277251) send AV protocol=ip
*Mar 4 19:25:07.124: AAA/AUTHOR/FSM (3979277251) found list "default"
*Mar 4 19:25:07.124: AAA/AUTHOR/FSM: Vi1 (3979277251) METHOD=RADIUS
*Mar 4 19:25:07.124: RADIUS: Using NAS default peer
*Mar 4 19:25:07.124: RADIUS: Authorize IP address 0.0.0.0
*Mar 4 19:25:07.124: AAA/AUTHOR (3979277251): Post authorization status = PASS_REPL
*Mar 4 19:25:07.124: Vi1 AAA/AUTHOR/FSM: We can start IPCP
*Mar 4 19:25:07.124: Vi1 AAA/AUTHOR/FSM: (0): Can we start CCP?
*Mar 4 19:25:07.124: AAA/AUTHOR/FSM Vi1 (1524934880): Port='Async54' list='' service=NET
*Mar 4 19:25:07.124: AAA/AUTHOR/FSM: Vi1 (1524934880) send AV service=ppp
*Mar 4 19:25:07.124: AAA/AUTHOR/FSM: Vi1 (1524934880) send AV protocol=ccp
*Mar 4 19:25:07.128: AAA/AUTHOR/FSM (1524934880) found list "default"
*Mar 4 19:25:07.128: AAA/AUTHOR/FSM: Vi1 (1524934880) METHOD=RADIUS
*Mar 4 19:25:07.128: AAA/AUTHOR (1524934880): Post authorization status = PASS_REPL
*Mar 4 19:25:07.128: Vi1 AAA/AUTHOR/FSM: We can start CCP
*Mar 4 19:25:07.128: Vi1 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 0.0.0.0
*Mar 4 19:25:07.128: Vi1 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:25:07.128: Vi1 AAA/AUTHOR/IPCP: Processing AV addr=0.0.0.0
*Mar 4 19:25:07.128: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:25:07.128: Vi1 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 0.0.0.0
*Mar 4 19:25:07.128: Vi1 AAA/AUTHOR/FSM: Check for unauthorized mandatory AV's
*Mar 4 19:25:07.128: Vi1 AAA/AUTHOR/FSM: Processing AV service=ppp
*Mar 4 19:25:07.128: Vi1 AAA/AUTHOR/FSM: Succeeded
*Mar 4 19:25:07.236: Vi1 AAA/AUTHOR/FSM: Check for unauthorized mandatory AV's
*Mar 4 19:25:07.236: Vi1 AAA/AUTHOR/FSM: Processing AV service=ppp
*Mar 4 19:25:07.236: Vi1 AAA/AUTHOR/FSM: Succeeded
*Mar 4 19:25:08.120: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to up
*Mar 4 19:25:10.124: Vi1 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 10.1.1.3
*Mar 4 19:25:10.124: Vi1 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:25:10.124: Vi1 AAA/AUTHOR/IPCP: Processing AV addr=0.0.0.0
*Mar 4 19:25:10.124: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:25:10.124: Vi1 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 10.1.1.3
*Mar 4 19:25:10.220: Vi1 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 10.1.1.3
*Mar 4 19:25:10.220: Vi1 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:25:10.220: Vi1 AAA/AUTHOR/IPCP: Processing AV addr=0.0.0.0
*Mar 4 19:25:10.220: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:25:10.220: Vi1 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 10.1.1.3
*Mar 4 19:25:10.316: Vi1 AAA/AUTHOR/IPCP: Start. Her address 10.1.1.3, we want 10.1.1.3
*Mar 4 19:25:10.316: AAA/AUTHOR/IPCP Vi1 (2714455877): Port='Async54' list='' service=NET
*Mar 4 19:25:10.316: AAA/AUTHOR/IPCP: Vi1 (2714455877) send AV service=ppp
*Mar 4 19:25:10.316: AAA/AUTHOR/IPCP: Vi1 (2714455877) send AV protocol=ip
*Mar 4 19:25:10.316: AAA/AUTHOR/IPCP: Vi1 (2714455877) send AV addr*10.1.1.3
*Mar 4 19:25:10.316: AAA/AUTHOR/IPCP (2714455877) found list "default"
*Mar 4 19:25:10.316: AAA/AUTHOR/IPCP: Vi1 (2714455877) METHOD=RADIUS
*Mar 4 19:25:10.316: RADIUS: Using NAS default peer
*Mar 4 19:25:10.320: RADIUS: Authorize IP address 10.1.1.3
*Mar 4 19:25:10.320: AAA/AUTHOR (2714455877): Post authorization status = PASS_REPL
*Mar 4 19:25:10.320: Vi1 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:25:10.320: Vi1 AAA/AUTHOR/IPCP: Processing AV addr=10.1.1.3
*Mar 4 19:25:10.320: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:25:10.320: Vi1 AAA/AUTHOR/IPCP: Done. Her address 10.1.1.3, we want 10.1.1.3
*Mar 4 19:25:10.320: Vi1 AAA/AUTHOR/PER-USER: Event IP_UP
*Mar 4 19:25:10.320: Vi1 AAA/PER-USER: processing author params.
access-3#show caller
Active Idle
Line User Service Time Time
tty 54 timeout Async 00:00:17 00:00:01
As54 timeout PPP 00:00:10 00:00:01
Vi1 timeout PPP VDP 00:00:10 00:00:08
access-3#show caller
Active Idle
Line User Service Time Time
tty 54 timeout Async 00:00:27 00:00:11
As54 timeout PPP 00:00:20 00:00:11
Vi1 timeout PPP VDP 00:00:20 00:00:18
access-3#show caller user timeout
User: timeout, line tty 54, service Async
Active time 00:00:49, Idle time 00:00:34
Timeouts: Absolute Idle Idle
Session Exec
Limits: - - 00:10:00
Disconnect in: - - -
TTY: Line 54, running PPP on As54
Location: MICA V.90 modems
Line: Baud rate (TX/RX) is 115200/115200, no parity, 1 stopbits, 8 databits
Status: Ready, Active, No Exit Banner, Async Interface Active
HW PPP Support Active
Capabilities: No Flush-at-Activation, Hardware Flowcontrol In
Hardware Flowcontrol Out, Modem Callout, Modem RI is CD
Line usable as async interface, ARAP Permitted
Integrated Modem
Modem State: Ready
User: timeout, line As54, service PPP
Active time 00:00:43, Idle time 00:00:34
Timeouts: Absolute Idle
Limits: - -
Disconnect in: - -
PPP: LCP Open, multilink Closed, CHAP (<- AAA)
IP: Local 10.1.1.1
Counts: 35 packets input, 824 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
22 packets output, 517 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
User: timeout, line Vi1, service PPP VDP
Active time 00:00:43, Idle time 00:00:41
Timeouts: Absolute Idle
Limits: 00:01:30 00:01:00
Disconnect in: 00:00:45 00:00:18
PPP: LCP Open, multilink Closed, CHAP (<- none), IPCP, CCP
Idle timer 60 secs, idle 41 secs
IP: Local 10.1.1.1, remote 10.1.1.3
Access list (I/O) is 199/not set
Counts: 24 packets input, 546 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
19 packets output, 167 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
access-3#show caller timeouts
Session Idle Disconnect
Line User Timeout Timeout User in
tty 54 timeout - - -
As54 timeout - - -
Vi1 timeout 00:01:30 00:01:00 00:00:05
*Mar 4 19:26:10.320: Vi1 PPP: Idle timeout, dropping connection
*Mar 4 19:26:10.320: As54 AAA/ACCT: non-ISDN xmit 50000 recv 28800 hwidb 613360C8 ttynum 54
*Mar 4 19:26:10.320: AAA/ACCT/NET/STOP User timeout, Port Async54:
task_id=10 timezone=PST service=ppp protocol=ip addr=10.1.1.3 disc-cause=4
disc-cause-ext=1021 pre-bytes-in=184 pre-bytes-out=330 pre-paks-in=7 pre-paks-out=11
bytes_in=613 bytes_out=187 paks_in=27 paks_out=11 pre-session-time=4 elapsed_time=63
nas-rx-speed=28800 nas-tx-speed=50000
*Mar 4 19:26:10.320: Vi1 AAA/AUTHOR/PER-USER: Event IP_DOWN
*Mar 4 19:26:10.324: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state to down
*Mar 4 19:26:10.324: Vi1 VTEMPLATE: Free vaccess
*Mar 4 19:26:10.328: Vi1 AAA/AUTHOR/PER-USER: Event LCP_DOWN
*Mar 4 19:26:10.376: Mica Modem(1/29): State Transition to Terminating
*Mar 4 19:26:10.436: Mica Modem(1/29): State Transition to Idle
*Mar 4 19:26:10.436: Mica Modem(1/29): Went onhook
*Mar 4 19:26:10.436: CSM_PROC_IC5_OC6_CONNECTED: CSM_EVENT_MODEM_ONHOOK at slot 1,
port 29
*Mar 4 19:26:10.440: VDEV_DEALLOCATE: slot 1 and port 29 is deallocated
*Mar 4 19:26:10.440: ISDN Se0:23: Event: Hangup call to call id 0x3E
*Mar 4 19:26:10.440: ISDN Se0:23: TX -> DISCONNECT pd = 8 callref = 0x800A
*Mar 4 19:26:10.440: Cause i = 0x8090 - Normal call clearing
*Mar 4 19:26:10.488: ISDN Se0:23: RX <- RELEASE pd = 8 callref = 0x0A
*Mar 4 19:26:10.496: ISDN Se0:23: TX -> RELEASE_COMP pd = 8 callref = 0x800A
*Mar 4 19:26:10.528: TAC+: (2047544826): received acct response status = SUCCESS
*Mar 4 19:26:11.180: VTEMPLATE: Clean up dirty vaccess queue, size 1
*Mar 4 19:26:11.180: Vi1 VTEMPLATE: Found a dirty vaccess clone with vtemplate/AAA
*Mar 4 19:26:11.180: Vi1 VTEMPLATE: ************ UNCLONE VACCESS1 **************
*Mar 4 19:26:11.180: Vi1 VTEMPLATE: Unclone to-be-freed command#2
interface Virtual-Access1
default ppp timeout idle 60
default timeout absolute 1 30
end
*Mar 4 19:26:11.200: Vi1 VTEMPLATE: Set default settings with no ip address
*Mar 4 19:26:11.216: Vi1 VTEMPLATE: Remove cloneblk AAA with vtemplate/AAA
*Mar 4 19:26:11.216: Vi1 VTEMPLATE: ************ UNCLONE VACCESS1 **************
*Mar 4 19:26:11.216: Vi1 VTEMPLATE: Unclone to-be-freed command#15
interface Virtual-Access1
default multilink max-links 2
default ppp multilink
default ppp authentication chap pap ms-chap
default ppp callback accept
default compress mppc
default peer default ip address pool default
default keepalive
default ip nat inside
default ip accounting output-packets
default ip directed-broadcast
default ip helper-address 172.16.24.118
default ip access-group 199 in
default ip unnumbered Loopback0
default encap ppp
default ip address
end
*Mar 4 19:26:11.304: Vi1 VTEMPLATE: Set default settings with no ip address
*Mar 4 19:26:11.324: Vi1 VTEMPLATE: Remove cloneblk vtemplate with vtemplate/AAA
*Mar 4 19:26:11.324: Vi1 VTEMPLATE: Add vaccess to recycle queue, queue SIZE=1
*Mar 4 19:26:11.324: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to down
*Mar 4 19:26:11.460: Mica Modem(1/29): State Transition to Terminating
*Mar 4 19:26:11.520: Mica Modem(1/29): State Transition to Idle
*Mar 4 19:26:12.200: %CALLRECORD-3-MICA_TERSE_CALL_REC: DS0 slot/contr/chan=2/0/18,
slot/port=1/29, call_id=3E, userid=timeout, ip=10.1.1.3, calling=(n/a), called=4085703932,
std=K56Flx, prot=LAP-M, comp=V.42bis both, init-rx/tx b-rate=28800/50000, finl-rx/tx
b-rate=28800/50000, rbs=0, d-pad=6 dB, retr=0, sq=3, snr=34, rx/tx chars=918/1138, bad=5,
rx/tx ec=35/47, bad=0, time=90, finl-state=Steady, disc(radius)=Idle Timeout/Idle Timeout,
disc(modem)=DF03 Tx (host to line) data flushing - OK/Requested by host/DTR dropped
*Mar 4 19:26:12.320: As54 AAA/AUTHOR/PER-USER: Event LCP_DOWN
Async Call without Virtual Profiles
Below is an async call without virtual profiles enabled. Note that the dialer idle-timeout command is used instead of the ppp timeout idle command since we are not using virtual profiles and there is no vaccess interface. You will also see us create the per-user timeout command and, at the same time, the no version of the commands. The per-user timer commands are installed immediately, while the no version of the commands are enqueued to the interface to be processed when the user disconnects.
*Mar 4 19:30:28.420: ISDN Se0:23: RX <- SETUP pd = 8 callref = 0x06
*Mar 4 19:30:28.420: Bearer Capability i = 0x9090A2
*Mar 4 19:30:28.420: Channel ID i = 0xA98393
*Mar 4 19:30:28.420: Called Party Number i = 0xC1, '4085703932'
*Mar 4 19:30:28.420: ISDN Se0:23: TX -> CALL_PROC pd = 8 callref = 0x8006
*Mar 4 19:30:28.420: Channel ID i = 0xA98393
*Mar 4 19:30:28.424: ISDN Se0:23: TX -> ALERTING pd = 8 callref = 0x8006
*Mar 4 19:30:28.424: EVENT_FROM_ISDN::dchan_idb=0x6122CFCC, call_id=0x40, ces=0x1
bchan=0x12, event=0x1, cause=0x0
*Mar 4 19:30:28.424: VDEV_ALLOCATE: slot 1 and port 2 is allocated.
*Mar 4 19:30:28.424: EVENT_FROM_ISDN:(0040): DEV_INCALL at slot 1 and port 2
*Mar 4 19:30:28.424: CSM_PROC_IDLE: CSM_EVENT_ISDN_CALL at slot 1, port 2
*Mar 4 19:30:28.424: Mica Modem(1/2): Configure(0x1 = 0x0)
*Mar 4 19:30:28.424: Mica Modem(1/2): Configure(0x23 = 0x0)
*Mar 4 19:30:28.424: Mica Modem(1/2): Call Setup
*Mar 4 19:30:28.552: Mica Modem(1/2): State Transition to Call Setup
*Mar 4 19:30:28.552: Mica Modem(1/2): Went offhook
*Mar 4 19:30:28.552: CSM_PROC_IC1_RING: CSM_EVENT_MODEM_OFFHOOK at slot 1, port 2
*Mar 4 19:30:28.552: ISDN Se0:23: TX -> CONNECT pd = 8 callref = 0x8006
*Mar 4 19:30:28.604: ISDN Se0:23: RX <- CONNECT_ACK pd = 8 callref = 0x06
*Mar 4 19:30:28.604: EVENT_FROM_ISDN::dchan_idb=0x6122CFCC, call_id=0x40, ces=0x1
bchan=0x12, event=0x4, cause=0x0
*Mar 4 19:30:28.604: EVENT_FROM_ISDN:(0040): DEV_CONNECTED at slot 1 and port 2
*Mar 4 19:30:28.604: CSM_PROC_IC4_WAIT_FOR_CARRIER: CSM_EVENT_ISDN_CONNECTED
at slot 1, port 2
*Mar 4 19:30:28.604: Mica Modem(1/2): Link Initiate
*Mar 4 19:30:29.692: Mica Modem(1/2): State Transition to Connect
*Mar 4 19:30:34.888: Mica Modem(1/2): State Transition to Link
*Mar 4 19:30:46.408: Mica Modem(1/2): State Transition to Trainup
*Mar 4 19:30:49.612: Mica Modem(1/2): State Transition to EC Negotiating
*Mar 4 19:30:50.156: Mica Modem(1/2): State Transition to Steady State
*Mar 4 19:30:50.592: AAA: parse NAME=tty27 idb TYPE=10 tty=27
*Mar 4 19:30:50.592: AAA: NAME=tty27 flags=0x11 TYPE=4 shelf=0 slot=0
adapter=0 port=27 channel=0
*Mar 4 19:30:50.592: AAA: parse NAME=Serial0:18 idb TYPE=12 tty=-1
*Mar 4 19:30:50.592: AAA: NAME=Serial0:18 flags=0x51 TYPE=1 shelf=0 slot=0
adapter=0 port=0 channel=18
*Mar 4 19:30:51.792: As27 LCP: Lower layer not up, Fast Starting
*Mar 4 19:30:51.792: As27 PPP: Treating connection as a callin
*Mar 4 19:30:51.792: As27 AAA/AUTHOR/FSM: (0): LCP succeeds trivially
*Mar 4 19:30:57.468: As27 PPP: Phase is AUTHENTICATING, by this end
*Mar 4 19:30:57.468: As27 CHAP: O CHALLENGE id 1 len 26 from "STACK"
*Mar 4 19:30:57.564: As27 CHAP: I RESPONSE id 1 len 30 from "timeout"
*Mar 4 19:30:57.564: AAA: parse NAME=Async27 idb TYPE=10 tty=27
*Mar 4 19:30:57.564: AAA: NAME=Async27 flags=0x11 TYPE=4 shelf=0 slot=0
adapter=0 port=27 channel=0
*Mar 4 19:30:57.564: AAA: parse NAME=Serial0:18 idb TYPE=12 tty=-1
*Mar 4 19:30:57.564: AAA: NAME=Serial0:18 flags=0x51 TYPE=1 shelf=0 slot=0
adapter=0 port=0 channel=18
*Mar 4 19:30:57.564: RADIUS: ustruct sharecount=1
*Mar 4 19:30:57.564: RADIUS: Initial Transmit Async27 id 3 172.16.24.117:1645,
Access-Request, len 92
*Mar 4 19:30:57.564: Attribute 4 6 AC101874
*Mar 4 19:30:57.564: Attribute 5 6 0000001B
*Mar 4 19:30:57.564: Attribute 61 6 00000000
*Mar 4 19:30:57.564: Attribute 1 11 74696D65
*Mar 4 19:30:57.564: Attribute 30 12 34303835
*Mar 4 19:30:57.564: Attribute 3 19 01E5C3F6
*Mar 4 19:30:57.564: Attribute 6 6 00000002
*Mar 4 19:30:57.564: Attribute 7 6 00000001
*Mar 4 19:30:57.572: RADIUS: Received from id 3 172.16.24.117:1645,
Access-Accept, len 50
*Mar 4 19:30:57.572: Attribute 6 6 00000002
*Mar 4 19:30:57.572: Attribute 7 6 00000001
*Mar 4 19:30:57.572: Attribute 8 6 FFFFFFFE
*Mar 4 19:30:57.572: Attribute 27 6 0000005A
*Mar 4 19:30:57.572: Attribute 28 6 0000003C
*Mar 4 19:30:57.572: As27 AAA/AUTHOR/LCP: Authorize LCP
*Mar 4 19:30:57.572: AAA/AUTHOR/LCP As27 (1969884263): Port='Async27' list=''
service=NET
*Mar 4 19:30:57.572: AAA/AUTHOR/LCP: As27 (1969884263) send AV service=ppp
*Mar 4 19:30:57.572: AAA/AUTHOR/LCP: As27 (1969884263) send AV protocol=lcp
*Mar 4 19:30:57.572: AAA/AUTHOR/LCP (1969884263) found list "default"
*Mar 4 19:30:57.572: AAA/AUTHOR/LCP: As27 (1969884263) METHOD=RADIUS
*Mar 4 19:30:57.572: AAA/AUTHOR (1969884263): Post authorization status = PASS_REPL
*Mar 4 19:30:57.572: As27 AAA/AUTHOR/LCP: Processing AV service=ppp
*Mar 4 19:30:57.572: As27 AAA/AUTHOR/LCP: Processing AV timeout=90
*Mar 4 19:30:57.572: As27 AAA/AUTHOR: Parse 'interface Async27'
*Mar 4 19:30:57.576: As27 AAA/AUTHOR: Parse returned ok (0)
*Mar 4 19:30:57.576: As27 AAA/AUTHOR: Parse 'timeout absolute 1 30'
*Mar 4 19:30:57.580: As27 AAA/AUTHOR: Parse returned ok (0)
*Mar 4 19:30:57.580: As27 AAA/AUTHOR: enqueue peruser LCP txt=interface Async27
no timeout absolute
*Mar 4 19:30:57.580: As27 AAA/AUTHOR/LCP: Processing AV idletime=60
*Mar 4 19:30:57.580: As27 AAA/AUTHOR: Parse 'interface Async27'
*Mar 4 19:30:57.584: As27 AAA/AUTHOR: Parse returned ok (0)
*Mar 4 19:30:57.584: As27 AAA/AUTHOR: Parse 'dialer idle-timeout 60'
*Mar 4 19:30:57.588: As27 AAA/AUTHOR: Parse returned ok (0)
*Mar 4 19:30:57.588: As27 AAA/AUTHOR: enqueue peruser LCP txt=interface Async27
no dialer idle-timeout
*Mar 4 19:30:57.588: As27 CHAP: O SUCCESS id 1 len 4
*Mar 4 19:30:57.588: AAA/ACCT/NET/START User timeout, Port Async27, List ""
*Mar 4 19:30:57.588: AAA/ACCT/NET: Found list "default"
*Mar 4 19:30:57.692: As27 AAA/AUTHOR/FSM: (0): Can we start IPCP?
*Mar 4 19:30:57.692: AAA/AUTHOR/FSM As27 (2088523207): Port='Async27' list=''
service=NET
*Mar 4 19:30:57.692: AAA/AUTHOR/FSM: As27 (2088523207) send AV service=ppp
*Mar 4 19:30:57.692: AAA/AUTHOR/FSM: As27 (2088523207) send AV protocol=ip
*Mar 4 19:30:57.692: AAA/AUTHOR/FSM (2088523207) found list "default"
*Mar 4 19:30:57.692: AAA/AUTHOR/FSM: As27 (2088523207) METHOD=RADIUS
*Mar 4 19:30:57.692: RADIUS: Using NAS default peer
*Mar 4 19:30:57.692: RADIUS: Authorize IP address 10.1.1.6
*Mar 4 19:30:57.692: AAA/AUTHOR (2088523207): Post authorization status = PASS_REPL
*Mar 4 19:30:57.692: As27 AAA/AUTHOR/FSM: We can start IPCP
*Mar 4 19:30:57.784: As27 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 10.1.1.6
*Mar 4 19:30:57.788: As27 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:30:57.788: As27 AAA/AUTHOR/IPCP: Processing AV addr=10.1.1.6
*Mar 4 19:30:57.788: As27 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:30:57.788: As27 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 10.1.1.6
*Mar 4 19:31:00.792: As27 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 10.1.1.6
*Mar 4 19:31:00.792: As27 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:31:00.792: As27 AAA/AUTHOR/IPCP: Processing AV addr=10.1.1.6
*Mar 4 19:31:00.792: As27 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:31:00.792: As27 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 10.1.1.6
*Mar 4 19:31:00.884: As27 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 10.1.1.6
*Mar 4 19:31:00.884: As27 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:31:00.884: As27 AAA/AUTHOR/IPCP: Processing AV addr=10.1.1.6
*Mar 4 19:31:00.884: As27 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:31:00.888: As27 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 10.1.1.6
*Mar 4 19:31:00.984: As27 AAA/AUTHOR/IPCP: Start. Her address 10.1.1.6, we want 10.1.1.6
*Mar 4 19:31:00.984: As27 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:31:00.984: As27 AAA/AUTHOR/IPCP: Processing AV addr=10.1.1.6
*Mar 4 19:31:00.984: As27 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:31:00.984: As27 AAA/AUTHOR/IPCP: Done. Her address 10.1.1.6, we want 10.1.1.6
*Mar 4 19:31:00.984: As27 AAA/AUTHOR/PER-USER: Event IP_UP
*Mar 4 19:31:00.984: As27 AAA/PER-USER: processing author params.
access-3#show caller
Active Idle
Line User Service Time Time
tty 27 timeout Async 00:00:23 00:00:04
As27 timeout PPP 00:00:22 00:00:20
access-3#show caller user timeout
User: timeout, line tty 27, service Async
Active time 00:00:28, Idle time 00:00:08
Timeouts: Absolute Idle Idle
Session Exec
Limits: - - 00:10:00
Disconnect in: - - -
TTY: Line 27, running PPP on As27
Location: MICA V.90 modems
Line: Baud rate (TX/RX) is 115200/115200, no parity, 1 stopbits, 8 databits
Status: Ready, Active, No Exit Banner, Async Interface Active
HW PPP Support Active
Capabilities: No Flush-at-Activation, Hardware Flowcontrol In
Hardware Flowcontrol Out, Modem Callout, Modem RI is CD
Line usable as async interface, ARAP Permitted
Integrated Modem
Modem State: Ready
User: timeout, line As27, service PPP
Active time 00:00:27, Idle time 00:00:25
Timeouts: Absolute Idle
Limits: 00:01:30 00:01:00
Disconnect in: 00:01:09 00:00:34
PPP: LCP Open, multilink Closed, CHAP (<- AAA), IPCP
Dialer: Connected, inbound
Idle timer 60 secs, idle 25 secs
Type is IN-BAND ASYNC, group Async27
IP: Local 10.1.1.1, remote 10.1.1.6
Counts: 31 packets input, 1642 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
15 packets output, 347 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
access-3#show caller timeouts
Session Idle Disconnect
Line User Timeout Timeout User in
tty 27 timeout - - -
As27 timeout 00:01:30 00:01:00 00:00:22
access-3#show caller timeouts
Session Idle Disconnect
Line User Timeout Timeout User in
tty 27 timeout - - -
As27 timeout 00:01:30 00:01:00 00:00:07
access-3#
*Mar 4 19:31:53.824: Mica Modem(1/2): State Transition to Terminating
*Mar 4 19:31:53.884: Mica Modem(1/2): State Transition to Idle
*Mar 4 19:31:53.884: Mica Modem(1/2): Went onhook
*Mar 4 19:31:53.884: CSM_PROC_IC5_OC6_CONNECTED: CSM_EVENT_MODEM_ONHOOK at slot 1, port 2
*Mar 4 19:31:53.884: VDEV_DEALLOCATE: slot 1 and port 2 is deallocated
*Mar 4 19:31:53.888: ISDN Se0:23: Event: Hangup call to call id 0x40
*Mar 4 19:31:53.888: ISDN Se0:23: TX -> DISCONNECT pd = 8 callref = 0x8006
*Mar 4 19:31:53.888: Cause i = 0x8090 - Normal call clearing
*Mar 4 19:31:53.940: ISDN Se0:23: RX <- RELEASE pd = 8 callref = 0x06
*Mar 4 19:31:53.952: ISDN Se0:23: TX -> RELEASE_COMP pd = 8 callref = 0x8006
*Mar 4 19:31:55.792: As27 AAA/ACCT: non-ISDN xmit 50000 recv 28800 hwidb 611CEBC0 ttynum 27
*Mar 4 19:31:55.792: AAA/ACCT/NET/STOP User timeout, Port Async27:
task_id=12 timezone=PST service=ppp protocol=ip addr=10.1.1.6 disc-cause=4
disc-cause-ext=1021 pre-bytes-in=135 pre-bytes-out=176 pre-paks-in=5 pre-paks-out=6
bytes_in=1480 bytes_out=171 paks_in=25 paks_out=9 pre-session-time=6 elapsed_time=58
nas-rx-speed=28800 nas-tx-speed=50000
*Mar 4 19:31:55.792: As27 AAA/AUTHOR/PER-USER: Event IP_DOWN
*Mar 4 19:31:55.792: As27 AAA/AUTHOR/PER-USER: Event LCP_DOWN
*Mar 4 19:31:55.792: As27 AAA/AUTHOR: down_event: peruser LCP txt=interface Async27
no timeout absolute
*Mar 4 19:31:55.796: As27 AAA/AUTHOR: Parse 'interface Async27'
*Mar 4 19:31:55.800: As27 AAA/AUTHOR: Parse returned ok (0)
*Mar 4 19:31:55.800: As27 AAA/AUTHOR: Parse 'no timeout absolute'
*Mar 4 19:31:55.804: As27 AAA/AUTHOR: Parse returned ok (0)
*Mar 4 19:31:55.804: As27 AAA/AUTHOR: free peruser LCP txt=interface Async27
no timeout absolute
*Mar 4 19:31:55.804: As27 AAA/AUTHOR: down_event: peruser LCP txt=interface Async27
no dialer idle-timeout
*Mar 4 19:31:55.804: As27 AAA/AUTHOR: Parse 'interface Async27'
*Mar 4 19:31:55.808: As27 AAA/AUTHOR: Parse returned ok (0)
*Mar 4 19:31:55.808: As27 AAA/AUTHOR: Parse 'no dialer idle-timeout'
*Mar 4 19:31:55.812: As27 AAA/AUTHOR: Parse returned ok (0)
*Mar 4 19:31:55.812: As27 AAA/AUTHOR: free peruser LCP txt=interface Async27
no dialer idle-timeout
*Mar 4 19:31:56.016: TAC+: (3633056702): received acct response status = SUCCESS
*Mar 4 19:32:00.308: %CALLRECORD-3-MICA_TERSE_CALL_REC: DS0 slot/contr/chan=2/0/18,
slot/port=1/2, call_id=40, userid=timeout, ip=10.1.1.6, calling=(n/a), called=4085703932,
std=K56Flx, prot=LAP-M, comp=V.42bis both, init-rx/tx b-rate=28800/50000, finl-rx/tx
b-rate=28800/50000, rbs=0, d-pad=6 dB, retr=0, sq=3, snr=28, rx/tx chars=1727/995, bad=2,
rx/tx ec=31/36, bad=0, time=84, finl-state=Steady, disc(radius)=Idle Timeout/Idle Timeout,
disc(modem)=DF03 Tx (host to line) data flushing - OK/Requested by host/DTR dropped
Multilink Single Channel ISDN Call without Virtual Profiles
Below is a multilink ISDN call without virtual profiles enabled. Since a multilink call creates a vaccess interface, the timers can be installed easily.
*Mar 4 19:41:12.208: ISDN Se0:23: RX <- SETUP pd = 8 callref = 0x08
*Mar 4 19:41:12.212: Bearer Capability i = 0x8890
*Mar 4 19:41:12.212: Channel ID i = 0xA98393
*Mar 4 19:41:12.212: Calling Party Number i = '!', 0x80, '4085551200'
*Mar 4 19:41:12.212: Called Party Number i = 0xA1, '4085703930'
*Mar 4 19:41:12.212: ISDN Se0:23: TX -> CALL_PROC pd = 8 callref = 0x8008
*Mar 4 19:41:12.212: Channel ID i = 0xA98393
*Mar 4 19:41:12.224: ISDN Se0:23: TX -> CONNECT pd = 8 callref = 0x8008
*Mar 4 19:41:12.224: Channel ID i = 0xA98393
*Mar 4 19:41:12.296: ISDN Se0:23: RX <- CONNECT_ACK pd = 8 callref = 0x08
*Mar 4 19:41:12.536: Se0:18 PPP: Treating connection as a callin
*Mar 4 19:41:12.536: Se0:18 AAA/AUTHOR/FSM: (0): LCP succeeds trivially
*Mar 4 19:41:14.536: Se0:18 AAA/AUTHOR/FSM: (0): LCP succeeds trivially
*Mar 4 19:41:14.552: Se0:18 PPP: Phase is AUTHENTICATING, by this end
*Mar 4 19:41:14.552: Se0:18 CHAP: O CHALLENGE id 1 len 26 from "STACK"
*Mar 4 19:41:14.584: Se0:18 CHAP: I RESPONSE id 1 len 30 from "timeout"
*Mar 4 19:41:14.964: Se0:18 CHAP: I RESPONSE id 1 len 30 from "timeout"
*Mar 4 19:41:14.964: AAA: parse NAME=Serial0:18 idb TYPE=12 tty=-1
*Mar 4 19:41:14.964: AAA: NAME=Serial0:18 flags=0x51 TYPE=1 shelf=0 slot=0
adapter=0 port=0 channel=18
*Mar 4 19:41:14.964: AAA: parse NAME= idb TYPE=-1 tty=-1
*Mar 4 19:41:14.964: RADIUS: ustruct sharecount=1
*Mar 4 19:41:14.964: RADIUS: Initial Transmit Serial0:18 id 4 172.16.24.117:1645,
Access-Request, len 104
*Mar 4 19:41:14.964: Attribute 4 6 AC101874
*Mar 4 19:41:14.964: Attribute 5 6 00004E32
*Mar 4 19:41:14.964: Attribute 61 6 00000002
*Mar 4 19:41:14.964: Attribute 1 11 74696D65
*Mar 4 19:41:14.964: Attribute 30 12 34303835
*Mar 4 19:41:14.964: Attribute 31 12 34303835
*Mar 4 19:41:14.964: Attribute 3 19 012C4E14
*Mar 4 19:41:14.964: Attribute 6 6 00000002
*Mar 4 19:41:14.964: Attribute 7 6 00000001
*Mar 4 19:41:14.972: RADIUS: Received from id 4 172.16.24.117:1645, Access-Accept, len 50
*Mar 4 19:41:14.972: Attribute 6 6 00000002
*Mar 4 19:41:14.972: Attribute 7 6 00000001
*Mar 4 19:41:14.972: Attribute 8 6 FFFFFFFE
*Mar 4 19:41:14.972: Attribute 27 6 0000005A
*Mar 4 19:41:14.972: Attribute 28 6 0000003C
*Mar 4 19:41:14.976: Se0:18 AAA/AUTHOR/LCP: Authorize LCP
*Mar 4 19:41:14.976: AAA/AUTHOR/LCP Se0:18 (4039479425): Port='Serial0:18' list=''
service=NET
*Mar 4 19:41:14.976: AAA/AUTHOR/LCP: Se0:18 (4039479425) send AV service=ppp
*Mar 4 19:41:14.976: AAA/AUTHOR/LCP: Se0:18 (4039479425) send AV protocol=lcp
*Mar 4 19:41:14.976: AAA/AUTHOR/LCP (4039479425) found list "default"
*Mar 4 19:41:14.976: AAA/AUTHOR/LCP: Se0:18 (4039479425) METHOD=RADIUS
*Mar 4 19:41:14.976: AAA/AUTHOR (4039479425): Post authorization status = PASS_REPL
*Mar 4 19:41:14.976: Se0:18 AAA/AUTHOR/LCP: Processing AV service=ppp
*Mar 4 19:41:14.976: Se0:18 AAA/AUTHOR/LCP: Processing AV timeout=90
*Mar 4 19:41:14.976: Se0:18 AAA/AUTHOR/LCP: Processing AV idletime=60
*Mar 4 19:41:14.976: AAA/AUTHOR/LCP Se0:18: Per-user interface config created:
timeout absolute 1 30
ppp timeout idle 60
*Mar 4 19:41:14.976: Se0:18 CHAP: O SUCCESS id 1 len 4
*Mar 4 19:41:14.976: AAA/ACCT/NET/START User timeout, Port Serial0:18, List ""
*Mar 4 19:41:14.976: AAA/ACCT/NET: Found list "default"
*Mar 4 19:41:14.976: AAA/AUTHOR/MLP Se0:18 (1966034416): Port='Serial0:18' list=''
service=NET
*Mar 4 19:41:14.976: AAA/AUTHOR/MLP: Se0:18 (1966034416) send AV service=ppp
*Mar 4 19:41:14.976: AAA/AUTHOR/MLP: Se0:18 (1966034416) send AV protocol=multilink
*Mar 4 19:41:14.976: AAA/AUTHOR/MLP (1966034416) found list "default"
*Mar 4 19:41:14.976: AAA/AUTHOR/MLP: Se0:18 (1966034416) METHOD=RADIUS
*Mar 4 19:41:14.976: AAA/AUTHOR (1966034416): Post authorization status = PASS_REPL
*Mar 4 19:41:14.976: Vi1 VTEMPLATE: Reuse Vi1, recycle queue size 0
*Mar 4 19:41:14.980: Vi1 VTEMPLATE: Hardware address 00e0.1e81.636c
*Mar 4 19:41:14.980: Vi1 VTEMPLATE: Has a new cloneblk dialer, now it has dialer
*Mar 4 19:41:14.980: Vi1 VTEMPLATE: Has a new cloneblk AAA, now it has dialer/AAA
*Mar 4 19:41:14.980: Vi1 VTEMPLATE: ************* CLONE VACCESS1 *****************
*Mar 4 19:41:14.980: Vi1 VTEMPLATE: Clone from AAA
interface Virtual-Access1
timeout absolute 1 30
ppp timeout idle 60
end
*Mar 4 19:41:14.996: Vi1 PPP: Treating connection as a callin
*Mar 4 19:41:14.996: AAA/AUTHOR/MLP Vi1: Processing AV service=ppp
*Mar 4 19:41:15.000: Vi1 AAA/AUTHOR/FSM: (0): Can we start IPCP?
*Mar 4 19:41:15.000: AAA/AUTHOR/FSM Vi1 (921779905): Port='Serial0:18' list='' service=NET
*Mar 4 19:41:15.000: AAA/AUTHOR/FSM: Vi1 (921779905) send AV service=ppp
*Mar 4 19:41:15.000: AAA/AUTHOR/FSM: Vi1 (921779905) send AV protocol=ip
*Mar 4 19:41:15.000: AAA/AUTHOR/FSM (921779905) found list "default"
*Mar 4 19:41:15.000: AAA/AUTHOR/FSM: Vi1 (921779905) METHOD=RADIUS
*Mar 4 19:41:15.000: RADIUS: Using NAS default peer
*Mar 4 19:41:15.000: RADIUS: Authorize IP address 0.0.0.0
*Mar 4 19:41:15.000: AAA/AUTHOR (921779905): Post authorization status = PASS_REPL
*Mar 4 19:41:15.000: Vi1 AAA/AUTHOR/FSM: We can start IPCP
*Mar 4 19:41:15.000: Vi1 AAA/AUTHOR/FSM: (0): Can we start CDPCP?
*Mar 4 19:41:15.000: AAA/AUTHOR/FSM Vi1 (3065122210): Port='Serial0:18' list=''
service=NET
*Mar 4 19:41:15.000: AAA/AUTHOR/FSM: Vi1 (3065122210) send AV service=ppp
*Mar 4 19:41:15.000: AAA/AUTHOR/FSM: Vi1 (3065122210) send AV protocol=cdp
*Mar 4 19:41:15.000: AAA/AUTHOR/FSM (3065122210) found list "default"
*Mar 4 19:41:15.000: AAA/AUTHOR/FSM: Vi1 (3065122210) METHOD=RADIUS
*Mar 4 19:41:15.000: AAA/AUTHOR (3065122210): Post authorization status = PASS_REPL
*Mar 4 19:41:15.000: Vi1 AAA/AUTHOR/FSM: We can start CDPCP
access-3#show caller
Active Idle
Line User Service Time Time
Se0:18 timeout PPP 00:00:19 00:00:00
Vi1 timeout PPP Bundle 00:00:19 00:00:20
access-3#show caller user timeout
User: timeout, line Se0:18, service PPP
Active time 00:00:25, Idle time 00:00:00
Timeouts: Absolute Idle
Limits: - -
Disconnect in: - -
PPP: LCP Open, multilink Open, CHAP (<- AAA)
Dialer: Connected to 4085551200, inbound
Type is ISDN, group Serial0:23
IP: Local 10.1.1.1
Access list (I/O) is 199/not set
Bundle: Member of timeout/timeout, last input 00:00:00
Counts: 13 packets input, 279 bytes, 0 no buffer
11 input errors, 2 CRC, 3 frame, 0 overrun
23 packets output, 431 bytes, 0 underruns
0 output errors, 0 collisions, 40 interface resets
User: timeout, line Vi1, service PPP Bundle
Active time 00:00:25, Idle time 00:00:26
Timeouts: Absolute Idle
Limits: 00:01:30 00:01:00
Disconnect in: 00:01:04 00:00:33
PPP: LCP Open, multilink Open
Idle timer 60 secs, idle 26 secs
Dialer: Connected to 4085551200, inbound
Type is IN-BAND SYNC, group Serial0:23
IP: Local 10.1.1.1
Access list (I/O) is 199/not set
Bundle: First link of timeout/timeout, 1 link, last input 00:00:27
Counts: 0 packets input, 0 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
13 packets output, 236 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
access-3#show caller timeout
Session Idle Disconnect
Line User Timeout Timeout User in
Se0:18 timeout - - -
Vi1 timeout 00:01:30 00:01:00 00:00:30
access-3#
*Mar 4 19:42:14.996: Vi1 PPP: Idle timeout, dropping connection
*Mar 4 19:42:14.996: Vi1 VTEMPLATE: Free vaccess
*Mar 4 19:42:14.996: Se0:18 AAA/AUTHOR/PER-USER: Event LCP_DOWN
*Mar 4 19:42:15.000: Vi1 AAA/AUTHOR/PER-USER: Event LCP_DOWN
*Mar 4 19:42:15.004: Se0:18 AAA/ACCT: ISDN xmit 64000 recv 64000 hwidb 612048BC
*Mar 4 19:42:15.004: AAA/ACCT/NET/STOP User timeout, Port Serial0:18:
task_id=13 timezone=PST service=ppp mlp-links-max=1 mlp-links-current=1
mlp-sess-id=0 disc-cause=18 disc-cause-ext=1046 pre-bytes-in=125 pre-bytes-out=99
pre-paks-in=4 pre-paks-out=4 bytes_in=228 bytes_out=436 paks_in=15 paks_out=26
pre-session-time=3 elapsed_time=60 nas-rx-speed=64000 nas-tx-speed=64000
*Mar 4 19:42:15.008: ISDN Se0:23: TX -> DISCONNECT pd = 8 callref = 0x8008
*Mar 4 19:42:15.008: Cause i = 0x8090 - Normal call clearing
*Mar 4 19:42:15.060: ISDN Se0:23: RX <- RELEASE pd = 8 callref = 0x08
*Mar 4 19:42:15.072: ISDN Se0:23: TX -> RELEASE_COMP pd = 8 callref = 0x8008
*Mar 4 19:42:15.212: TAC+: (2571416724): received acct response status = SUCCESS
*Mar 4 19:42:15.500: VTEMPLATE: Clean up dirty vaccess queue, size 1
*Mar 4 19:42:15.500: Vi1 VTEMPLATE: Found a dirty vaccess clone with dialer/AAA
*Mar 4 19:42:15.500: Vi1 VTEMPLATE: ************ UNCLONE VACCESS1 **************
*Mar 4 19:42:15.500: Vi1 VTEMPLATE: Unclone to-be-freed command#2
interface Virtual-Access1
default ppp timeout idle 60
default timeout absolute 1 30
end
*Mar 4 19:42:15.516: Vi1 VTEMPLATE: Set default settings with no ip address
*Mar 4 19:42:15.536: Vi1 VTEMPLATE: Remove cloneblk AAA with dialer/AAA
*Mar 4 19:42:15.536: Vi1 VTEMPLATE: Remove cloneblk dialer with dialer/AAA
*Mar 4 19:42:15.536: Vi1 VTEMPLATE: Add vaccess to recycle queue, queue SIZE=1
Non-Multilink Single Channel ISDN Call without Virtual Profiles
Below is a non-multilink single channel ISDN call without virtual profiles enabled. In this example, we are running Cisco IOS 11.3(8.2)AA so these timers can be installed correctly. However, note that no configuration commands were created to cause this; the timers were set internally in the code.
*Mar 4 19:43:00.404: ISDN Se0:23: RX <- SETUP pd = 8 callref = 0x0E
*Mar 4 19:43:00.404: Bearer Capability i = 0x8890
*Mar 4 19:43:00.404: Channel ID i = 0xA98393
*Mar 4 19:43:00.404: Calling Party Number i = '!', 0x80, '4085551200'
*Mar 4 19:43:00.404: Called Party Number i = 0xA1, '4085703930'
*Mar 4 19:43:00.404: ISDN Se0:23: TX -> CALL_PROC pd = 8 callref = 0x800E
*Mar 4 19:43:00.408: Channel ID i = 0xA98393
*Mar 4 19:43:00.416: ISDN Se0:23: TX -> CONNECT pd = 8 callref = 0x800E
*Mar 4 19:43:00.416: Channel ID i = 0xA98393
*Mar 4 19:43:00.488: ISDN Se0:23: RX <- CONNECT_ACK pd = 8 callref = 0x0E
*Mar 4 19:43:00.720: Se0:18 PPP: Treating connection as a callin
*Mar 4 19:43:00.720: Se0:18 AAA/AUTHOR/FSM: (0): LCP succeeds trivially
*Mar 4 19:43:02.744: Se0:18 PPP: Phase is AUTHENTICATING, by this end
*Mar 4 19:43:02.744: Se0:18 CHAP: O CHALLENGE id 2 len 26 from "STACK"
*Mar 4 19:43:02.776: Se0:18 CHAP: I RESPONSE id 2 len 30 from "timeout"
*Mar 4 19:43:02.776: AAA: parse NAME=Serial0:18 idb TYPE=12 tty=-1
*Mar 4 19:43:02.776: AAA: NAME=Serial0:18 flags=0x51 TYPE=1 shelf=0 slot=0
adapter=0 port=0 channel=18
*Mar 4 19:43:02.776: AAA: parse NAME= idb TYPE=-1 tty=-1
*Mar 4 19:43:02.780: RADIUS: ustruct sharecount=1
*Mar 4 19:43:02.780: RADIUS: Initial Transmit Serial0:18 id 5 172.16.24.117:1645,
Access-Request, len 104
*Mar 4 19:43:02.780: Attribute 4 6 AC101874
*Mar 4 19:43:02.780: Attribute 5 6 00004E32
*Mar 4 19:43:02.780: Attribute 61 6 00000002
*Mar 4 19:43:02.780: Attribute 1 11 74696D65
*Mar 4 19:43:02.780: Attribute 30 12 34303835
*Mar 4 19:43:02.780: Attribute 31 12 34303835
*Mar 4 19:43:02.780: Attribute 3 19 02AE5572
*Mar 4 19:43:02.780: Attribute 6 6 00000002
*Mar 4 19:43:02.780: Attribute 7 6 00000001
*Mar 4 19:43:02.784: RADIUS: Received from id 5 172.16.24.117:1645, Access-Accept, len 50
*Mar 4 19:43:02.784: Attribute 6 6 00000002
*Mar 4 19:43:02.784: Attribute 7 6 00000001
*Mar 4 19:43:02.784: Attribute 8 6 FFFFFFFE
*Mar 4 19:43:02.784: Attribute 27 6 0000005A
*Mar 4 19:43:02.784: Attribute 28 6 0000003C
*Mar 4 19:43:02.788: Se0:18 AAA/AUTHOR/LCP: Authorize LCP
*Mar 4 19:43:02.788: AAA/AUTHOR/LCP Se0:18 (900316608): Port='Serial0:18' list=''
service=NET
*Mar 4 19:43:02.788: AAA/AUTHOR/LCP: Se0:18 (900316608) send AV service=ppp
*Mar 4 19:43:02.788: AAA/AUTHOR/LCP: Se0:18 (900316608) send AV protocol=lcp
*Mar 4 19:43:02.788: AAA/AUTHOR/LCP (900316608) found list "default"
*Mar 4 19:43:02.788: AAA/AUTHOR/LCP: Se0:18 (900316608) METHOD=RADIUS
*Mar 4 19:43:02.788: AAA/AUTHOR (900316608): Post authorization status = PASS_REPL
*Mar 4 19:43:02.788: Se0:18 AAA/AUTHOR/LCP: Processing AV service=ppp
*Mar 4 19:43:02.788: Se0:18 AAA/AUTHOR/LCP: Processing AV timeout=90
*Mar 4 19:43:02.788: Se0:18 AAA/AUTHOR/LCP: Processing AV idletime=60
*Mar 4 19:43:02.788: Se0:18 CHAP: O SUCCESS id 2 len 4
*Mar 4 19:43:02.788: AAA/ACCT/NET/START User timeout, Port Serial0:18, List ""
*Mar 4 19:43:02.788: AAA/ACCT/NET: Found list "default"
*Mar 4 19:43:02.788: Se0:18 AAA/AUTHOR/FSM: (0): Can we start IPCP?
*Mar 4 19:43:02.788: AAA/AUTHOR/FSM Se0:18 (3608739008): Port='Serial0:18' list=''
service=NET
*Mar 4 19:43:02.788: AAA/AUTHOR/FSM: Se0:18 (3608739008) send AV service=ppp
*Mar 4 19:43:02.788: AAA/AUTHOR/FSM: Se0:18 (3608739008) send AV protocol=ip
*Mar 4 19:43:02.788: AAA/AUTHOR/FSM (3608739008) found list "default"
*Mar 4 19:43:02.788: AAA/AUTHOR/FSM: Se0:18 (3608739008) METHOD=RADIUS
*Mar 4 19:43:02.788: RADIUS: Using NAS default peer
*Mar 4 19:43:02.788: RADIUS: Authorize IP address 0.0.0.0
*Mar 4 19:43:02.788: AAA/AUTHOR (3608739008): Post authorization status = PASS_REPL
*Mar 4 19:43:02.788: Se0:18 AAA/AUTHOR/FSM: We can start IPCP
*Mar 4 19:43:02.788: Se0:18 AAA/AUTHOR/FSM: (0): Can we start CDPCP?
*Mar 4 19:43:02.792: AAA/AUTHOR/FSM Se0:18 (3955392150): Port='Serial0:18' list=''
service=NET
*Mar 4 19:43:02.792: AAA/AUTHOR/FSM: Se0:18 (3955392150) send AV service=ppp
*Mar 4 19:43:02.792: AAA/AUTHOR/FSM: Se0:18 (3955392150) send AV protocol=cdp
*Mar 4 19:43:02.792: AAA/AUTHOR/FSM (3955392150) found list "default"
*Mar 4 19:43:02.792: AAA/AUTHOR/FSM: Se0:18 (3955392150) METHOD=RADIUS
*Mar 4 19:43:02.792: AAA/AUTHOR (3955392150): Post authorization status = PASS_REPL
*Mar 4 19:43:02.792: Se0:18 AAA/AUTHOR/FSM: We can start CDPCP
*Mar 4 19:43:02.804: Se0:18 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 0.0.0.0
*Mar 4 19:43:02.804: Se0:18 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:43:02.804: Se0:18 AAA/AUTHOR/IPCP: Processing AV addr=0.0.0.0
*Mar 4 19:43:02.804: Se0:18 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:43:02.804: Se0:18 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 0.0.0.0
*Mar 4 19:43:02.808: Se0:18 AAA/AUTHOR/FSM: Check for unauthorized mandatory AV's
*Mar 4 19:43:02.808: Se0:18 AAA/AUTHOR/FSM: Processing AV service=ppp
*Mar 4 19:43:02.808: Se0:18 AAA/AUTHOR/FSM: Succeeded
*Mar 4 19:43:02.816: Se0:18 AAA/AUTHOR/IPCP: Start. Her address 10.1.1.3, we want 10.1.1.3
*Mar 4 19:43:02.816: AAA/AUTHOR/IPCP Se0:18 (2267743837): Port='Serial0:18' list=''
service=NET
*Mar 4 19:43:02.816: AAA/AUTHOR/IPCP: Se0:18 (2267743837) send AV service=ppp
*Mar 4 19:43:02.816: AAA/AUTHOR/IPCP: Se0:18 (2267743837) send AV protocol=ip
*Mar 4 19:43:02.816: AAA/AUTHOR/IPCP: Se0:18 (2267743837) send AV addr*10.1.1.3
*Mar 4 19:43:02.816: AAA/AUTHOR/IPCP (2267743837) found list "default"
*Mar 4 19:43:02.816: AAA/AUTHOR/IPCP: Se0:18 (2267743837) METHOD=RADIUS
*Mar 4 19:43:02.816: RADIUS: Using NAS default peer
*Mar 4 19:43:02.816: RADIUS: Authorize IP address 10.1.1.3
*Mar 4 19:43:02.816: AAA/AUTHOR (2267743837): Post authorization status = PASS_REPL
*Mar 4 19:43:02.816: Se0:18 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:43:02.820: Se0:18 AAA/AUTHOR/IPCP: Processing AV addr=10.1.1.3
*Mar 4 19:43:02.820: Se0:18 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:43:02.820: Se0:18 AAA/AUTHOR/IPCP: Done. Her address 10.1.1.3,
we want 10.1.1.3
*Mar 4 19:43:02.824: Se0:18 AAA/AUTHOR/PER-USER: Event IP_UP
*Mar 4 19:43:02.824: Se0:18 AAA/PER-USER: processing author params.
access-3#show caller
Active Idle
Line User Service Time Time
Se0:18 timeout PPP 00:00:19 00:00:19
access-3#show caller timeout
Session Idle Disconnect
Line User Timeout Timeout User in
Se0:18 timeout 00:01:30 00:01:00 00:00:37
access-3#ping 10.1.1.3
Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 10.1.1.3, timeout is 2 seconds:
!!!!!
Success rate is 100 percent (5/5), round-trip min/avg/max = 32/33/36 ms
access-3#show caller timeout
Session Idle Disconnect
Line User Timeout Timeout User in
Se0:18 timeout 00:01:30 00:01:00 00:00:57
access-3#show caller user timeout
User: timeout, line Se0:18, service PPP
Active time 00:00:38, Idle time 00:00:10
Timeouts: Absolute Idle
Limits: 00:01:30 00:01:00
Disconnect in: 00:00:51 00:00:49
PPP: LCP Open, multilink Closed, CHAP (<- AAA), IPCP, CDPCP
Dialer: Connected to 4085551200, inbound
Idle timer 60 secs, idle 10 secs
Type is ISDN, group Serial0:23
IP: Local 10.1.1.1, remote 10.1.1.3
Access list (I/O) is 199/not set
Counts: 51 packets input, 2104 bytes, 0 no buffer
11 input errors, 2 CRC, 3 frame, 0 overrun
58 packets output, 2233 bytes, 0 underruns
0 output errors, 0 collisions, 45 interface resets
access-3#show caller user timeout
User: timeout, line Se0:18, service PPP
Active time 00:00:45, Idle time 00:00:17
Timeouts: Absolute Idle
Limits: 00:01:30 00:01:00
Disconnect in: 00:00:44 00:00:42
PPP: LCP Open, multilink Closed, CHAP (<- AAA), IPCP, CDPCP
Dialer: Connected to 4085551200, inbound
Idle timer 60 secs, idle 17 secs
Type is ISDN, group Serial0:23
IP: Local 10.1.1.1, remote 10.1.1.3
Access list (I/O) is 199/not set
Counts: 52 packets input, 2120 bytes, 0 no buffer
11 input errors, 2 CRC, 3 frame, 0 overrun
59 packets output, 2249 bytes, 0 underruns
0 output errors, 0 collisions, 45 interface resets
access-3#ping 10.1.1.3
Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 10.1.1.3, timeout is 2 seconds:
!!!!!
Success rate is 100 percent (5/5), round-trip min/avg/max = 32/34/40 ms
access-3#show caller user timeout
User: timeout, line Se0:18, service PPP
Active time 00:01:02, Idle time 00:00:04
Timeouts: Absolute Idle
Limits: 00:01:30 00:01:00
Disconnect in: 00:00:27 00:00:55
PPP: LCP Open, multilink Closed, CHAP (<- AAA), IPCP, CDPCP
Dialer: Connected to 4085551200, inbound
Idle timer 60 secs, idle 4 secs
Type is ISDN, group Serial0:23
IP: Local 10.1.1.1, remote 10.1.1.3
Access list (I/O) is 199/not set
Counts: 60 packets input, 2688 bytes, 0 no buffer
11 input errors, 2 CRC, 3 frame, 0 overrun
67 packets output, 2817 bytes, 0 underruns
0 output errors, 0 collisions, 45 interface resets
access-3#show caller timeout
Session Idle Disconnect
Line User Timeout Timeout User in
Se0:18 timeout 00:01:30 00:01:00 00:00:21
access-3#show caller timeout
Session Idle Disconnect
Line User Timeout Timeout User in
Se0:18 timeout 00:01:30 00:01:00 00:00:07
access-3#
*Mar 4 19:44:33.788: ISDN Se0:23: TX -> DISCONNECT pd = 8 callref = 0x800E
*Mar 4 19:44:33.788: Cause i = 0x8090 - Normal call clearing
*Mar 4 19:44:33.840: ISDN Se0:23: RX <- RELEASE pd = 8 callref = 0x0E
*Mar 4 19:44:33.852: Se0:18 AAA/ACCT: ISDN xmit 64000 recv 64000 hwidb 612048BC
*Mar 4 19:44:33.852: AAA/ACCT/NET/STOP User timeout, Port Serial0:18:
task_id=14 timezone=PST service=ppp protocol=ip addr=10.1.1.3 disc-cause=5
disc-cause-ext=1100 pre-bytes-in=101 pre-bytes-out=102 pre-paks-in=5 pre-paks-out=5
bytes_in=2258 bytes_out=2276 paks_in=38 paks_out=38 pre-session-time=2 elapsed_time=91
nas-rx-speed=64000 nas-tx-speed=64000
*Mar 4 19:44:33.852: ISDN Se0:23: TX -> RELEASE_COMP pd = 8 callref = 0x800E
*Mar 4 19:44:33.856: Se0:18 AAA/AUTHOR/PER-USER: Event IP_DOWN
*Mar 4 19:44:33.856: Se0:18 AAA/AUTHOR/PER-USER: Event LCP_DOWN
*Mar 4 19:44:34.060: TAC+: (3492368360): received acct response status = SUCCESS
Non-Multilink Single Channel ISDN Call with Virtual Profiles
Below is the same non-multilink single channel ISDN user but this time with virtual profiles enabled. Note that vaccess interface is created even though multilink is not negotiated and we create the configuration commands to install the timers.
*Mar 4 19:45:00.480: ISDN Se0:23: RX <- SETUP pd = 8 callref = 0x0C
*Mar 4 19:45:00.480: Bearer Capability i = 0x8890
*Mar 4 19:45:00.480: Channel ID i = 0xA98393
*Mar 4 19:45:00.480: Calling Party Number i = '!', 0x80, '4085551200'
*Mar 4 19:45:00.480: Called Party Number i = 0xA1, '4085703930'
*Mar 4 19:45:00.480: ISDN Se0:23: TX -> CALL_PROC pd = 8 callref = 0x800C
*Mar 4 19:45:00.480: Channel ID i = 0xA98393
*Mar 4 19:45:00.492: ISDN Se0:23: TX -> CONNECT pd = 8 callref = 0x800C
*Mar 4 19:45:00.492: Channel ID i = 0xA98393
*Mar 4 19:45:00.564: ISDN Se0:23: RX <- CONNECT_ACK pd = 8 callref = 0x0C
*Mar 4 19:45:00.804: Se0:18 PPP: Treating connection as a callin
*Mar 4 19:45:00.804: Se0:18 AAA/AUTHOR/FSM: (0): LCP succeeds trivially
*Mar 4 19:45:02.804: Se0:18 AAA/AUTHOR/FSM: (0): LCP succeeds trivially
*Mar 4 19:45:02.828: Se0:18 PPP: Phase is AUTHENTICATING, by this end
*Mar 4 19:45:02.828: Se0:18 CHAP: O CHALLENGE id 3 len 26 from "STACK"
*Mar 4 19:45:02.860: Se0:18 CHAP: I RESPONSE id 3 len 30 from "timeout"
*Mar 4 19:45:02.860: AAA: parse NAME=Serial0:18 idb TYPE=12 tty=-1
*Mar 4 19:45:02.860: AAA: NAME=Serial0:18 flags=0x51 TYPE=1 shelf=0 slot=0
adapter=0 port=0 channel=18
*Mar 4 19:45:02.860: AAA: parse NAME= idb TYPE=-1 tty=-1
*Mar 4 19:45:02.860: RADIUS: ustruct sharecount=1
*Mar 4 19:45:02.860: RADIUS: Initial Transmit Serial0:18 id 6 172.16.24.117:1645,
Access-Request, len 104
*Mar 4 19:45:02.860: Attribute 4 6 AC101874
*Mar 4 19:45:02.860: Attribute 5 6 00004E32
*Mar 4 19:45:02.860: Attribute 61 6 00000002
*Mar 4 19:45:02.864: Attribute 1 11 74696D65
*Mar 4 19:45:02.864: Attribute 30 12 34303835
*Mar 4 19:45:02.864: Attribute 31 12 34303835
*Mar 4 19:45:02.864: Attribute 3 19 03D4E134
*Mar 4 19:45:02.864: Attribute 6 6 00000002
*Mar 4 19:45:02.864: Attribute 7 6 00000001
*Mar 4 19:45:02.868: RADIUS: Received from id 6 172.16.24.117:1645, Access-Accept, len 50
*Mar 4 19:45:02.868: Attribute 6 6 00000002
*Mar 4 19:45:02.868: Attribute 7 6 00000001
*Mar 4 19:45:02.868: Attribute 8 6 FFFFFFFE
*Mar 4 19:45:02.868: Attribute 27 6 0000005A
*Mar 4 19:45:02.868: Attribute 28 6 0000003C
*Mar 4 19:45:02.868: Se0:18 AAA/AUTHOR/LCP: Authorize LCP
*Mar 4 19:45:02.868: AAA/AUTHOR/LCP Se0:18 (2825271150): Port='Serial0:18' list=''
service=NET
*Mar 4 19:45:02.868: AAA/AUTHOR/LCP: Se0:18 (2825271150) send AV service=ppp
*Mar 4 19:45:02.868: AAA/AUTHOR/LCP: Se0:18 (2825271150) send AV protocol=lcp
*Mar 4 19:45:02.868: AAA/AUTHOR/LCP (2825271150) found list "default"
*Mar 4 19:45:02.868: AAA/AUTHOR/LCP: Se0:18 (2825271150) METHOD=RADIUS
*Mar 4 19:45:02.872: AAA/AUTHOR (2825271150): Post authorization status = PASS_REPL
*Mar 4 19:45:02.872: Se0:18 AAA/AUTHOR/LCP: Processing AV service=ppp
*Mar 4 19:45:02.872: Se0:18 AAA/AUTHOR/LCP: Processing AV timeout=90
*Mar 4 19:45:02.872: Se0:18 AAA/AUTHOR/LCP: Processing AV idletime=60
*Mar 4 19:45:02.872: AAA/AUTHOR/LCP Se0:18: Per-user interface config created:
timeout absolute 1 30
ppp timeout idle 60
*Mar 4 19:45:02.872: Se0:18 CHAP: O SUCCESS id 3 len 4
*Mar 4 19:45:02.872: AAA/ACCT/NET/START User timeout, Port Serial0:18, List ""
*Mar 4 19:45:02.872: AAA/ACCT/NET: Found list "default"
*Mar 4 19:45:02.872: Vi1 VTEMPLATE: Reuse Vi1, recycle queue size 0
*Mar 4 19:45:02.872: Vi1 VTEMPLATE: Hardware address 00e0.1e81.636c
*Mar 4 19:45:02.872: Vi1 VTEMPLATE: Has a new cloneblk vtemplate, now it has vtemplate
*Mar 4 19:45:02.872: Vi1 VTEMPLATE: ************* CLONE VACCESS1 *****************
*Mar 4 19:45:02.872: Vi1 VTEMPLATE: Clone from Virtual-Template1
interface Virtual-Access1
default ip address
no ip address
encap ppp
ip unnumbered Loopback0
ip access-group 199 in
ip helper-address 172.16.24.118
no ip directed-broadcast
ip accounting output-packets
ip nat inside
no keepalive
peer default ip address pool default
compress mppc
ppp callback accept
ppp authentication chap pap ms-chap
ppp multilink
multilink max-links 2
end
enabling payload compression on this interface.
*Mar 4 19:45:02.952: Vi1 VTEMPLATE: Has a new cloneblk AAA, now it has vtemplate/AAA
*Mar 4 19:45:02.952: Vi1 VTEMPLATE: ************* CLONE VACCESS1 *****************
*Mar 4 19:45:02.952: Vi1 VTEMPLATE: Clone from AAA
interface Virtual-Access1
timeout absolute 1 30
ppp timeout idle 60
end
*Mar 4 19:45:02.976: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state to up
*Mar 4 19:45:02.976: Vi1 PPP: Treating connection as a dedicated line
*Mar 4 19:45:02.976: Vi1 AAA/AUTHOR/FSM: (0): LCP succeeds trivially
*Mar 4 19:45:02.980: Vi1 AAA/AUTHOR/FSM: (0): Can we start IPCP?
*Mar 4 19:45:02.980: AAA/AUTHOR/FSM Vi1 (2657898442): Port='Serial0:18' list='' service=NET
*Mar 4 19:45:02.980: AAA/AUTHOR/FSM: Vi1 (2657898442) send AV service=ppp
*Mar 4 19:45:02.980: AAA/AUTHOR/FSM: Vi1 (2657898442) send AV protocol=ip
*Mar 4 19:45:02.980: AAA/AUTHOR/FSM (2657898442) found list "default"
*Mar 4 19:45:02.980: AAA/AUTHOR/FSM: Vi1 (2657898442) METHOD=RADIUS
*Mar 4 19:45:02.980: RADIUS: Using NAS default peer
*Mar 4 19:45:02.980: RADIUS: Authorize IP address 0.0.0.0
*Mar 4 19:45:02.980: AAA/AUTHOR (2657898442): Post authorization status = PASS_REPL
*Mar 4 19:45:02.980: Vi1 AAA/AUTHOR/FSM: We can start IPCP
*Mar 4 19:45:02.980: Vi1 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 0.0.0.0
*Mar 4 19:45:02.980: Vi1 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:45:02.980: Vi1 AAA/AUTHOR/IPCP: Processing AV addr=0.0.0.0
*Mar 4 19:45:02.980: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:45:02.980: Vi1 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 0.0.0.0
*Mar 4 19:45:02.996: Vi1 AAA/AUTHOR/IPCP: Start. Her address 10.1.1.3, we want 10.1.1.3
*Mar 4 19:45:02.996: AAA/AUTHOR/IPCP Vi1 (1804338759): Port='Serial0:18' list=''
service=NET
*Mar 4 19:45:02.996: AAA/AUTHOR/IPCP: Vi1 (1804338759) send AV service=ppp
*Mar 4 19:45:02.996: AAA/AUTHOR/IPCP: Vi1 (1804338759) send AV protocol=ip
*Mar 4 19:45:02.996: AAA/AUTHOR/IPCP: Vi1 (1804338759) send AV addr*10.1.1.3
*Mar 4 19:45:02.996: AAA/AUTHOR/IPCP (1804338759) found list "default"
*Mar 4 19:45:02.996: AAA/AUTHOR/IPCP: Vi1 (1804338759) METHOD=RADIUS
*Mar 4 19:45:02.996: RADIUS: Using NAS default peer
*Mar 4 19:45:02.996: RADIUS: Authorize IP address 10.1.1.3
*Mar 4 19:45:02.996: AAA/AUTHOR (1804338759): Post authorization status = PASS_REPL
*Mar 4 19:45:02.996: Vi1 AAA/AUTHOR/IPCP: Processing AV service=ppp
*Mar 4 19:45:02.996: Vi1 AAA/AUTHOR/IPCP: Processing AV addr=10.1.1.3
*Mar 4 19:45:02.996: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
*Mar 4 19:45:02.996: Vi1 AAA/AUTHOR/IPCP: Done. Her address 10.1.1.3, we want 10.1.1.3
*Mar 4 19:45:03.004: Vi1 AAA/AUTHOR/PER-USER: Event IP_UP
*Mar 4 19:45:03.004: Vi1 AAA/PER-USER: processing author params.
*Mar 4 19:45:03.996: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to up
access-3#show caller
Active Idle
Line User Service Time Time
Se0:18 timeout PPP 00:00:11 00:00:10
Vi1 timeout PPP VDP 00:00:11 00:00:10
access-3#show caller timeout
User: timeout, line Se0:18, service PPP
Active time 00:00:15, Idle time 00:00:15
Timeouts: Absolute Idle
Limits: - -
Disconnect in: - -
PPP: LCP Open, multilink Closed, CHAP (<- AAA)
Dialer: Connected to 4085551200, inbound
Idle timer 60 secs, idle 15 secs
Type is ISDN, group Serial0:23
IP: Local 10.1.1.1
Access list (I/O) is 199/not set
Counts: 81 packets input, 3291 bytes, 0 no buffer
11 input errors, 2 CRC, 3 frame, 0 overrun
87 packets output, 3419 bytes, 0 underruns
0 output errors, 0 collisions, 47 interface resets
User: timeout, line Vi1, service PPP VDP
Active time 00:00:15, Idle time 00:00:15
Timeouts: Absolute Idle
Limits: 00:01:30 00:01:00
Disconnect in: 00:01:13 00:00:44
PPP: LCP Open, multilink Closed, CHAP (<- none), IPCP
Idle timer 60 secs, idle 15 secs
IP: Local 10.1.1.1, remote 10.1.1.3
Access list (I/O) is 199/not set
Counts: 7 packets input, 370 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
19 packets output, 404 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
access-3#show caller timeouts
Session Idle Disconnect
Line User Timeout Timeout User in
Se0:18 timeout - - -
Vi1 timeout 00:01:30 00:01:00 00:00:40
access-3#ping 10.1.1.3
Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 10.1.1.3, timeout is 2 seconds:
!!!!!
Success rate is 100 percent (5/5), round-trip min/avg/max = 32/33/36 ms
access-3#show caller timeouts
Session Idle Disconnect
Line User Timeout Timeout User in
Se0:18 timeout - - -
Vi1 timeout 00:01:30 00:01:00 00:00:58
access-3#show caller user timeout
User: timeout, line Se0:18, service PPP
Active time 00:00:34, Idle time 00:00:09
Timeouts: Absolute Idle
Limits: - -
Disconnect in: - -
PPP: LCP Open, multilink Closed, CHAP (<- AAA)
Dialer: Connected to 4085551200, inbound
Idle timer 60 secs, idle 9 secs
Type is ISDN, group Serial0:23
IP: Local 10.1.1.1
Access list (I/O) is 199/not set
Counts: 88 packets input, 3843 bytes, 0 no buffer
11 input errors, 2 CRC, 3 frame, 0 overrun
94 packets output, 3971 bytes, 0 underruns
0 output errors, 0 collisions, 47 interface resets
User: timeout, line Vi1, service PPP VDP
Active time 00:00:34, Idle time 00:00:09
Timeouts: Absolute Idle
Limits: 00:01:30 00:01:00
Disconnect in: 00:00:54 00:00:50
PPP: LCP Open, multilink Closed, CHAP (<- none), IPCP
Idle timer 60 secs, idle 9 secs
IP: Local 10.1.1.1, remote 10.1.1.3
Access list (I/O) is 199/not set
Counts: 14 packets input, 922 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
33 packets output, 956 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
access-3#show caller timeout
Session Idle Disconnect
Line User Timeout Timeout User in
Se0:18 timeout - - -
Vi1 timeout 00:01:30 00:01:00 00:00:42
access-3#show caller timeouts
Session Idle Disconnect
Line User Timeout Timeout User in
Se0:18 timeout - - -
Vi1 timeout 00:01:30 00:01:00 00:00:22
access-3#show caller
Active Idle
Line User Service Time Time
Se0:18 timeout PPP 00:01:22 00:00:57
Vi1 timeout PPP VDP 00:01:22 00:00:57
access-3#
*Mar 4 19:46:28.996: Vi1 PPP: Idle timeout, dropping connection
*Mar 4 19:46:28.996: Se0:18 AAA/ACCT: ISDN xmit 64000 recv 64000 hwidb 612048BC
*Mar 4 19:46:28.996: AAA/ACCT/NET/STOP User timeout, Port Serial0:18:
task_id=15 timezone=PST service=ppp protocol=ip addr=10.1.1.3 disc-cause=4
disc-cause-ext=1021 pre-bytes-in=101 pre-bytes-out=102 pre-paks-in=5 pre-paks-out=5
bytes_in=1024 bytes_out=1036 paks_in=21 paks_out=21 pre-session-time=2 elapsed_time=86
nas-rx-speed=64000 nas-tx-speed=64000
*Mar 4 19:46:29.000: ISDN Se0:23: TX -> DISCONNECT pd = 8 callref = 0x800C
*Mar 4 19:46:29.000: Cause i = 0x8090 - Normal call clearing
*Mar 4 19:46:29.000: Vi1 AAA/AUTHOR/PER-USER: Event IP_DOWN
*Mar 4 19:46:29.000: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state to down
*Mar 4 19:46:29.004: Vi1 VTEMPLATE: Free vaccess
*Mar 4 19:46:29.004: Vi1 AAA/AUTHOR/PER-USER: Event LCP_DOWN
*Mar 4 19:46:29.052: ISDN Se0:23: RX <- RELEASE pd = 8 callref = 0x0C
*Mar 4 19:46:29.064: ISDN Se0:23: TX -> RELEASE_COMP pd = 8 callref = 0x800C
*Mar 4 19:46:29.064: Se0:18 AAA/AUTHOR/PER-USER: Event LCP_DOWN
*Mar 4 19:46:29.208: TAC+: (3109010012): received acct response status = SUCCESS
*Mar 4 19:46:29.580: VTEMPLATE: Clean up dirty vaccess queue, size 1
*Mar 4 19:46:29.580: Vi1 VTEMPLATE: Found a dirty vaccess clone with vtemplate/AAA
*Mar 4 19:46:29.580: Vi1 VTEMPLATE: ************ UNCLONE VACCESS1 **************
*Mar 4 19:46:29.580: Vi1 VTEMPLATE: Unclone to-be-freed command#2
interface Virtual-Access1
default ppp timeout idle 60
default timeout absolute 1 30
end
*Mar 4 19:46:29.596: Vi1 VTEMPLATE: Set default settings with no ip address
*Mar 4 19:46:29.616: Vi1 VTEMPLATE: Remove cloneblk AAA with vtemplate/AAA
*Mar 4 19:46:29.616: Vi1 VTEMPLATE: ************ UNCLONE VACCESS1 **************
*Mar 4 19:46:29.616: Vi1 VTEMPLATE: Unclone to-be-freed command#15
interface Virtual-Access1
default multilink max-links 2
default ppp multilink
default ppp authentication chap pap ms-chap
default ppp callback accept
default compress mppc
default peer default ip address pool default
default keepalive
default ip nat inside
default ip accounting output-packets
default ip directed-broadcast
default ip helper-address 172.16.24.118
default ip access-group 199 in
default ip unnumbered Loopback0
default encap ppp
default ip address
end
*Mar 4 19:46:29.704: Vi1 VTEMPLATE: Set default settings with no ip address
*Mar 4 19:46:29.720: Vi1 VTEMPLATE: Remove cloneblk vtemplate with vtemplate/AAA
*Mar 4 19:46:29.720: Vi1 VTEMPLATE: Add vaccess to recycle queue, queue SIZE=1
*Mar 4 19:46:30.000: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to down
Related Information
Revision History
| Revision | Publish Date | Comments |
|---|---|---|
1.0 |
04-Feb-2010 |
Initial Release |
FeedbackContact Cisco
- Open a Support Case
- (Requires a Cisco Service Contract)