disconnect within 10-15 minutes when idle

Nadir Aliyev nadir at ultel.net
Sat Apr 10 14:53:42 CEST 2010 

Hello, dear all!
When user is idle session will disconnected within 10-15 minutes, but when
user is not idle session is not disconnected.
Disconnects not associated with keep alive or physical connection. 

Logs from radacct-detail file:

Sat Apr 10 14:34:58 2010
        Acct-Session-Id = "009B0031"
        Cisco-AVPair = "client-mac-address=0024.018a.a919"
        Framed-Protocol = PPP
        Framed-IP-Address = XXX.XXX.XXX.XXX
        User-Name = "Johny"
        Acct-Authentic = RADIUS
        Cisco-AVPair = "connect-progress=LAN Ses Up"
        Cisco-AVPair = "nas-tx-speed=1000000000"
        Cisco-AVPair = "nas-rx-speed=1000000000"
        Acct-Session-Time = 339
        Acct-Input-Octets = 4268
        Acct-Output-Octets = 3708
        Acct-Input-Packets = 88
        Acct-Output-Packets = 88
        Acct-Terminate-Cause = User-Request
        Cisco-AVPair = "disc-cause-ext=Call Disconnect"
        Acct-Status-Type = Stop
        NAS-Port-Type = Ethernet
        NAS-Port = 10158129
        NAS-Port-Id = "0/0/2/420"
        Service-Type = Framed-User
        NAS-IP-Address = XXX.XXX.XXX.XXX
        X-Ascend-Session-Svr-Key = "1162517C"
        Acct-Delay-Time = 0
        Acct-Unique-Session-Id = "40095579394b8fd0"
        Timestamp = 1270892098
        Request-Authenticator = Verified


Cisco debug:
Client interface: Vi81
Client mac: 0024.018a.a919
Client IP: 123.123.123.123


1972329: Apr 10 17:04:56.270 AZST:  Service tag: NULL Tag
1972330: Apr 10 17:04:56.270 AZST: PPPoE 0: O PADO, R:0012.4408.081b
L:001d.6a06.25b3 420 Gi0/0.420
1972331: Apr 10 17:04:56.270 AZST:  Service tag: NULL Tag
1972332: Apr 10 17:04:56.982 AZST: [893]PPPoE 891: AAA get dynamic attrs
1972333: Apr 10 17:04:56.982 AZST: [893]PPPoE 891: AAA get dynamic attrs
1972334: Apr 10 17:04:56.982 AZST: [481]PPPoE 481: AAA get dynamic attrs
1972335: Apr 10 17:04:56.982 AZST: [481]PPPoE 481: AAA get dynamic attrs
1972336: Apr 10 17:04:56.982 AZST: [798]PPPoE 796: AAA get dynamic attrs
1972337: Apr 10 17:04:56.982 AZST: [798]PPPoE 796: AAA get dynamic attrs
1972338: Apr 10 17:04:57.002 AZST: PPPoE 981: I PADT  R:0026.5a50.e1c3
L:0012.4408.081b 420 Gi0/0.420
1972339: Apr 10 17:04:57.526 AZST: PPPoE 350: I PADT  R:0019.cbc7.b3c3
L:0012.4408.081b 420 Gi0/0.420
1972340: Apr 10 17:04:57.526 AZST: [350]PPPoE 350: Destroying
R:0019.cbc7.b3c3 L:0012.4408.081b 420 Gi0/0.420
1972341: Apr 10 17:04:57.526 AZST: PPPoE: Returning Vaccess Virtual-Access34
1972342: Apr 10 17:04:57.526 AZST: Vi34 PPP: Block vaccess from being freed
[0x19]
1972343: Apr 10 17:04:57.526 AZST: [350]PPPoE 350: AAA get dynamic attrs
1972347: Apr 10 17:04:57.526 AZST: [350]PPPoE 350: AAA account stopped
1972348: Apr 10 17:04:57.526 AZST: Vi34 PPP: Sending Acct Event[Down]
id[303]
1972349: Apr 10 17:04:57.526 AZST: Vi34 IPCP: State is Closed
1972350: Apr 10 17:04:57.526 AZST: Vi34 PPP: Unlocked by [0x1] Still Locked
by [0x18]
1972351: Apr 10 17:04:57.526 AZST: Vi34 PPP: Unlocked by [0x10] Still Locked
by [0x8]
1972352: Apr 10 17:04:57.526 AZST: Vi34 PPP: Phase is TERMINATING
1972353: Apr 10 17:04:57.526 AZST: Vi34 LCP: State is Closed
1972354: Apr 10 17:04:57.526 AZST: Vi34 PPP: Phase is DOWN
1972355: Apr 10 17:04:57.526 AZST: Vi34 PPP: Unlocked by [0x8] Still Locked
by [0x0]
1972356: Apr 10 17:04:57.526 AZST: Vi34 PPP: Free previously blocked vaccess
1972357: Apr 10 17:04:57.534 AZST: [972]PPPoE 970: AAA get dynamic attrs
1972358: Apr 10 17:04:57.534 AZST: [972]PPPoE 970: AAA get dynamic attrs
1972359: Apr 10 17:04:57.534 AZST: [554]PPPoE 554: AAA get dynamic attrs
1972360: Apr 10 17:04:57.534 AZST: [554]PPPoE 554: AAA get dynamic attrs
1972362: Apr 10 17:04:57.534 AZST: %LINK-3-UPDOWN: Interface
Virtual-Access34, changed state to down
1972363: Apr 10 17:04:57.534 AZST: PPPoE 350: I PADT  R:0019.cbc7.b3c3
L:0012.4408.081b 420 Gi0/0.420
1972364: Apr 10 17:04:57.534 AZST: PPPoE 800: I PADT  R:0024.018a.a919
L:0012.4408.081b 420 Gi0/0.420
1972365: Apr 10 17:04:57.534 AZST: [802]PPPoE 800: Destroying
R:0024.018a.a919 L:0012.4408.081b 420 Gi0/0.420
1972366: Apr 10 17:04:57.534 AZST: PPPoE: Returning Vaccess Virtual-Access81
1972367: Apr 10 17:04:57.534 AZST: Vi81 PPP: Block vaccess from being freed
[0x19]
1972368: Apr 10 17:04:57.538 AZST: [802]PPPoE 800: AAA get dynamic attrs
1972369: Apr 10 17:04:57.538 AZST: [802]PPPoE 800: AAA get dynamic attrs
1972370: Apr 10 17:04:57.538 AZST: [802]PPPoE 800: AAA get dynamic attrs
1972371: Apr 10 17:04:57.538 AZST: [802]PPPoE 800: AAA get dynamic attrs
1972372: Apr 10 17:04:57.538 AZST: [802]PPPoE 800: AAA account stopped
1972373: Apr 10 17:04:57.538 AZST: PPPoE 800: I PADT  R:0024.018a.a919
L:0012.4408.081b 420 Gi0/0.420
1972374: Apr 10 17:04:57.538 AZST: PPPoE 350: I PADT  R:0004.e2fa.a927
L:0012.4408.081b 420 Gi0/0.420
1972375: Apr 10 17:04:57.538 AZST: PPPoE 800: I PADT  R:0024.018a.a919
L:0012.4408.081b 420 Gi0/0.420
1972376: Apr 10 17:04:57.538 AZST: PPPoE 350: I PADT  R:0023.088b.be7f
L:0012.4408.081b 420 Gi0/0.420
1972377: Apr 10 17:04:57.538 AZST: PPPoE 350: I PADT  R:0016.b6fa.cbc5
L:0012.4408.081b 420 Gi0/0.420
1972378: Apr 10 17:04:57.538 AZST: PPPoE 800: I PADT  R:0023.088b.be7f
L:0012.4408.081b 420 Gi0/0.420
1972379: Apr 10 17:04:57.538 AZST: PPPoE 800: I PADT  R:0016.b6fa.cbc5
L:0012.4408.081b 420 Gi0/0.420
1972380: Apr 10 17:04:57.538 AZST: PPPoE 350: I PADT  R:0019.cbc7.b3c3
L:0012.4408.081b 420 Gi0/0.420
1972381: Apr 10 17:04:57.538 AZST: PPPoE 800: I PADT  R:0024.018a.a919
L:0012.4408.081b 420 Gi0/0.420
1972382: Apr 10 17:04:57.538 AZST: PPPoE 0: I PADI  R:001d.6a06.25b3
L:ffff.ffff.ffff 420 Gi0/0.420
1972383: Apr 10 17:04:57.538 AZST:  Service tag: NULL Tag
1972384: Apr 10 17:04:57.538 AZST: PPPoE 0: O PADO, R:0012.4408.081b
L:001d.6a06.25b3 420 Gi0/0.420
1972385: Apr 10 17:04:57.538 AZST:  Service tag: NULL Tag
1972386: Apr 10 17:04:57.538 AZST: PPPoE 350: I PADT  R:0019.cbc7.b3c3
L:0012.4408.081b 420 Gi0/0.420
1972387: Apr 10 17:04:57.538 AZST: PPPoE 981: I PADT  R:0026.5a50.e1c3
L:0012.4408.081b 420 Gi0/0.420
1972388: Apr 10 17:04:57.538 AZST: PPPoE 0: I PADI  R:0026.5a50.e1c3
L:ffff.ffff.ffff 420 Gi0/0.420
1972390: Apr 10 17:04:57.538 AZST: PPPoE 0: O PADO, R:0012.4408.081b
L:0026.5a50.e1c3 420 Gi0/0.420
1972392: Apr 10 17:04:57.538 AZST: Vi81 PPP: Sending Acct Event[Down]
id[4C7]
1972393: Apr 10 17:04:57.538 AZST: Vi81 IPCP: State is Closed
1972394: Apr 10 17:04:57.538 AZST: Vi81 PPP: Unlocked by [0x1] Still Locked
by [0x18]
1972395: Apr 10 17:04:57.538 AZST: Vi81 PPP: Unlocked by [0x10] Still Locked
by [0x8]
1972396: Apr 10 17:04:57.538 AZST: Vi81 PPP: Phase is TERMINATING
1972397: Apr 10 17:04:57.538 AZST: Vi81 LCP: State is Closed
1972398: Apr 10 17:04:57.538 AZST: Vi81 PPP: Phase is DOWN
1972399: Apr 10 17:04:57.538 AZST: Vi81 PPP: Unlocked by [0x8] Still Locked
by [0x0]
1972400: Apr 10 17:04:57.538 AZST: Vi81 PPP: Free previously blocked vaccess
1972401: Apr 10 17:04:57.538 AZST: %LINK-3-UPDOWN: Interface
Virtual-Access81, changed state to down
Router-Core#terminal no monitor
1972402: Apr 10 17:04:57.538 AZST: Vi81 IPCP: Remove route to
123.123.123.123

More information about the Freeradius-Users mailing list