logging anomalies

Using 0.8.1 on several FreeBSD machines. These are all proxies; all send
accounting info to a MySQL dB on a dedicated server.

We've noticed that sometimes an enduser will log in and two records will
be created with start times 5 seconds apart and stop times exactly the
same. It seems to be happening only on CVX NASs, when we find it.

The radius.log only shows one login, but both the detail log and the
radacct table in the radius dB show duplicate entries. All fields are the
same except RadAcctID and AcctStartTime. Both detail and radacct info are
included at the end of this email.

Questions:

1. How can duplicate entries be happening for the same session? The
AcctSessionIDs and AcctUnique IDs are identical.

2. Is the 5 second delay a clue? 

3. Are the CVXs contributing to this? If so, what would be done to correct
it?

4. Could dirty phone lines and/or bad transit cause the duplicate entries?

radacct log:

RadAcctId AcctSessionId AcctUniqueId UserName Realm NASIPAddress NASPortId
NASPortType AcctStartTime AcctStopTime AcctSessionTime AcctAuthentic
ConnectInfo_start ConnectInfo_stop AcctInputOctets AcctOutputOctets
CalledStationId CallingStationId AcctTerminateCause ServiceType
FramedProtocol FramedIPAddress AcctStartDelay AcctStopDelay 

3871925 00103CBE        ff3c4e93a446fa45        user@xxxxxxxxx
realm.net        111.111.111.111 17042707        Async   2003-06-11 1
8:57:46 2003-06-11 19:13:49     964     RADIUS                  8411
101641  npanxx1985      npanxx0891              Framed-User     PPP
        222.222.222.222    0       0

3871926 00103CBE        ff3c4e93a446fa45        user@xxxxxxxxx
realm.net        111.111.111.111 17042707        Async   2003-06-11 1
8:57:51 2003-06-11 19:13:49     964     RADIUS                  8411
101641  npanxx1985      npanxx0891              Framed-User     PPP
        222.222.222.222    5       0

>From the detail log:

Wed Jun 11 18:57:46 2003
        Acct-Status-Type = Start
        NAS-Identifier = "cvx02"
        Service-Type = Framed-User
        NAS-Port = 17042707
        NAS-Port-Type = Async
        Called-Station-Id = "npanxx1985"
        Calling-Station-Id = "npanxx0891"
        Acct-Delay-Time = 0
        Framed-IP-Address = 222.222.222.222
        User-Name = "user@xxxxxxxxx"
        Framed-Protocol = PPP
        Acct-Session-Id = "00103CBE"
        Acct-Authentic = RADIUS
        Acct-Link-Count = 1
        Login-IP-Host = 0.0.0.0
        Login-Service = PortMaster
        Login-TCP-Port = 0
        Ascend-Data-Rate = 28800
        X-Ascend-Xmit-Rate = 31200
        X-Ascend-PreSession-Time = 22
        Attr-172818442 = 0x562e3334
        Attr-172818444 = 0x562e3432
        Attr-172818445 = 0x562e3432626973
        Attr-103 = 0x3ee7df03
        NAS-IP-Address = 111.111.111.111
        Client-IP-Address = 333.333.333.333
        Stripped-User-Name = "user"
        Realm = "realm.net"
        Acct-Unique-Session-Id = "ff3c4e93a446fa45"
        Freeradius-Proxied-To = 444.444.444.444
        Timestamp = 1055383066

Wed Jun 11 18:57:51 2003
        Acct-Status-Type = Start
        NAS-Identifier = "cvx02"
        Service-Type = Framed-User
        NAS-Port = 17042707
        NAS-Port-Type = Async
        Called-Station-Id = "npanxx1985"
        Calling-Station-Id = "npanxx0891"
        Acct-Delay-Time = 5
        Framed-IP-Address = 222.222.222.222
        User-Name = "user@xxxxxxxxx"
        Framed-Protocol = PPP
        Acct-Session-Id = "00103CBE"
        Acct-Authentic = RADIUS
        Acct-Link-Count = 1
        Login-IP-Host = 0.0.0.0
        Login-Service = PortMaster
        Login-TCP-Port = 0
        Ascend-Data-Rate = 28800
        X-Ascend-Xmit-Rate = 31200
        X-Ascend-PreSession-Time = 22
        Attr-172818442 = 0x562e3334
        Attr-172818444 = 0x562e3432
        Attr-172818445 = 0x562e3432626973
        Attr-103 = 0x3ee7df03
        NAS-IP-Address = 111.111.111.111
        Client-IP-Address = 333.333.333.333
        Stripped-User-Name = "user"
        Realm = "realm.net"
        Acct-Unique-Session-Id = "ff3c4e93a446fa45"
        Freeradius-Proxied-To = 444.444.444.444
        Timestamp = 1055383071

Wed Jun 11 19:13:49 2003
        Acct-Status-Type = Stop
        NAS-Identifier = "cvx02"
        Service-Type = Framed-User
        NAS-Port = 17042707
        NAS-Port-Type = Async
        Called-Station-Id = "npanxx1985"
        Calling-Station-Id = "npanxx0891"
        Acct-Delay-Time = 0
        Framed-IP-Address = 222.222.222.222
        User-Name = "user@xxxxxxxxx"
        Framed-Protocol = PPP
        Acct-Input-Octets = 8411
        Acct-Output-Octets = 101641
        Acct-Session-Id = "00103CBE"
        Acct-Session-Time = 964
        Acct-Input-Packets = 321
        Acct-Output-Packets = 309
        Acct-Authentic = RADIUS
        Acct-Link-Count = 1
        Login-IP-Host = 0.0.0.0
        Login-Service = PortMaster
        Login-TCP-Port = 0
        X-Ascend-Disconnect-Cause = 100
        Ascend-Data-Rate = 28800
        X-Ascend-Xmit-Rate = 31200
        X-Ascend-PreSession-Time = 22
        Attr-172818443 = 0x562e3334
        Attr-172818446 = 0x000002a3
        Attr-172818447 = 0x00000000
        Attr-172818448 = 0x00000028
        Attr-172818449 = 0x00000001
        Attr-172818450 = 0x00000001
        Attr-172818451 = 0x00000000
        Attr-172818452 = 0x00000005
        Attr-172818454 = 0xffffffed
        Attr-103 = 0x3ee7e2c6
        NAS-IP-Address = 111.111.111.111
        Client-IP-Address = 333.333.333.333
        Stripped-User-Name = "user"
        Realm = "realm.net"
        Acct-Unique-Session-Id = "ff3c4e93a446fa45"
        Freeradius-Proxied-To = 444.444.444.444
        Timestamp = 1055384029


Wed Jun 11 19:13:49 2003
        Acct-Status-Type = Stop
        NAS-Identifier = "cvx02"
        Service-Type = Framed-User
        NAS-Port = 17042707
        NAS-Port-Type = Async
        Called-Station-Id = "npanxx1985"
        Calling-Station-Id = "npanxx0891"
        Acct-Delay-Time = 0
        Framed-IP-Address = 222.222.222.222
        User-Name = "user@xxxxxxxxx"
        Framed-Protocol = PPP
        Acct-Input-Octets = 8411
        Acct-Output-Octets = 101641
        Acct-Session-Id = "00103CBE"
        Acct-Session-Time = 964
        Acct-Input-Packets = 321
        Acct-Output-Packets = 309
        Acct-Authentic = RADIUS
        Acct-Link-Count = 1
        Login-IP-Host = 0.0.0.0
        Login-Service = PortMaster
        Login-TCP-Port = 0
        X-Ascend-Disconnect-Cause = 100
        Ascend-Data-Rate = 28800
        X-Ascend-Xmit-Rate = 31200
        X-Ascend-PreSession-Time = 22
        Attr-172818443 = 0x562e3334
        Attr-172818446 = 0x000002a3
        Attr-172818447 = 0x00000000
        Attr-172818448 = 0x00000028
        Attr-172818449 = 0x00000001
        Attr-172818450 = 0x00000001
        Attr-172818451 = 0x00000000
        Attr-172818452 = 0x00000005
        Attr-172818454 = 0xffffffed
        Attr-103 = 0x3ee7e2c6
        NAS-IP-Address = 111.111.111.111
        Client-IP-Address = 333.333.333.333
        Stripped-User-Name = "user"
        Realm = "realm.net"
        Acct-Unique-Session-Id = "ff3c4e93a446fa45"
        Freeradius-Proxied-To = 444.444.444.444
        Timestamp = 1055384029



- 
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html