(RADIATOR) USR Chassis and Radiator Problem

Tue Jun 27 08:09:47 CDT 2006

All;

I have recently installed Radiator onto a SuSE Open Enterprise Server 9 box.
This unit runs MySQL in concert with phpMyAdmin. All these products are what
control our authentication. The box was working great for approximately 3
weeks before my problem started happening. 

We have 2 3Com Total Control Chassis that provide the dial up (not that you
guys aren't familiar with these ;)

Here's the problem: Randomly the chassis' calls starts to not allow people
online. It seems happens in the early mornings (not sure if time has
anything to do with it) and late at night. The user connects on the chassis,
sends authentication to radiator, radiator logs the authentication as ok,
sends back the following, 20 times in 3 second intervals (specified by the
chassis'):

Tue Jun 27 03:24:45 2006: DEBUG: Packet dump:

*** Received from 10.10.10.39 port 1645 ....

Code:       Access-Request

Identifier: 28

Authentic:  <253>8<242><181>|<180>d<144>C<185>n<175>^<10>LB

Attributes:

        User-Name = "XXXXXXX"

        User-Password = m<177>N<249><140>_<241><205><204><151>Y<246><214>U
<201

        NAS-IP-Address = 10.10.10.39

        NAS-Identifier = "10.10.10.39"

        NAS-Port = 1794

        Acct-Session-Id = "117506115"

        USR-Interface-Index = 3050

        USR-Tunnel-Supports-Tags = 0

        Service-Type = Framed-User

        Framed-Protocol = PPP

        USR-Chassis-Call-Slot = 8

        USR-Chassis-Call-Span = 1

        USR-Chassis-Call-Channel = 2

        USR-Connect-Speed = NONE

        Calling-Station-Id = "XXXXXXX"

        Called-Station-Id = "XXXXXXX"

        NAS-Port-Type = Async

Tue Jun 27 03:24:45 2006: DEBUG: Handling request with Handler
'Realm=DEFAULT'

Tue Jun 27 03:24:45 2006: DEBUG: Rewrote user name to XXXXXX

Tue Jun 27 03:24:45 2006: DEBUG:  Deleting session for XXXXXX, 10.10.10.39,
1794

Tue Jun 27 03:24:45 2006: DEBUG: do query is: 'delete from RADONLINE where
NASI

Tue Jun 27 03:24:45 2006: DEBUG: Handling with Radius::AuthSQL

Tue Jun 27 03:24:45 2006: DEBUG: Handling with Radius::AuthSQL:

Tue Jun 27 03:24:45 2006: DEBUG: Query is: 'select ENCRYPTEDPASSWORD,
CHECKATTR

Tue Jun 27 03:24:45 2006: DEBUG: Radius::AuthSQL looks for match with XXXXX
[XXXXXX]

Tue Jun 27 03:24:45 2006: DEBUG: Expiration date converted to: 1155186000

Tue Jun 27 03:24:45 2006: DEBUG: Query is: 'select NASIDENTIFIER, NASPORT,
ACCT

Tue Jun 27 03:24:45 2006: DEBUG: Radius::AuthSQL ACCEPT: : XXXXXXX [XXXXXX]

Tue Jun 27 03:24:45 2006: DEBUG: AuthBy SQL result: ACCEPT,

Tue Jun 27 03:24:45 2006: DEBUG: Access accepted for XXXXXX

Tue Jun 27 03:24:45 2006: DEBUG: do query is: 'insert into RADAUTHLOG
(TIME_STA

Tue Jun 27 03:24:45 2006: DEBUG: Packet dump:

*** Sending to 10.10.10.39 port 1645 ....

Code:       Access-Accept

Identifier: 28

Authentic:  <253>8<242><181>|<180>d<144>C<185>n<175>^<10>LB

Attributes:

        Framed-IP-Address = 255.255.255.254

        Framed-Protocol = PPP

        Framed-MTU = 1500

        Framed-Compression = Van-Jacobson-TCP-IP

Then this pops up:

Tue Jun 27 03:25:24 2006: DEBUG: Packet dump:

*** Received from 10.10.10.39 port 1646 ....

Code:       Accounting-Request

Identifier: 184

Authentic:  `<215><7><196><145><252><144><214>P<144>]~<155><5>-$

Attributes:

        User-Name = "unauthenticated"

        NAS-IP-Address = 10.10.10.39

        Acct-Status-Type = Stop

        Acct-Session-Id = "117506115"

        Acct-Delay-Time = 0

        Service-Type = Framed-User

        NAS-Port-Type = Async

        NAS-Port = 1794

        USR-Interface-Index = 3050

        USR-Chassis-Call-Slot = 8

        USR-Chassis-Call-Span = 1

        USR-Chassis-Call-Channel = 2

        USR-Unauthenticated-Time = 65

        USR-Modem-Training-Time = 12

        Calling-Station-Id = "XXXXXXX"

        Called-Station-Id = "XXXXXXX"

        USR-Modulation-Type = v34

        USR-Simplified-MNP-Levels = ccittV42

        USR-Simplified-V42bis-Usage = ccittV42bis

        USR-Connect-Speed = 26400_BPS

        Framed-Protocol = PPP

        Framed-IP-Address = 0.0.0.0

        Acct-Session-Time = 77

        Acct-Terminate-Cause = User-Error

        USR-Disconnect-Reason = 27

        USR-Speed-of-Connection = 26400

        Acct-Input-Octets = 287

        Acct-Output-Octets = 193

        Acct-Input-Packets = 13

        Acct-Output-Packets = 7

        USR-Call-Arrived-Time = 330942478

        USR-Call-Lost-Time = 330942555

Tue Jun 27 03:25:24 2006: DEBUG: Handling request with Handler
'Realm=DEFAULT'

Tue Jun 27 03:25:24 2006: DEBUG: Rewrote user name to unauthenticated

Tue Jun 27 03:25:24 2006: DEBUG:  Deleting session for unauthenticated,
10.10.1

Tue Jun 27 03:25:24 2006: DEBUG: do query is: 'delete from RADONLINE where
NASI

Tue Jun 27 03:25:24 2006: DEBUG: Handling with Radius::AuthSQL

Tue Jun 27 03:25:24 2006: DEBUG: Handling accounting with Radius::AuthSQL

Tue Jun 27 03:25:24 2006: DEBUG: do query is: 'INSERT INTO ACCOUNTING
(ACCTSESS

Tue Jun 27 03:25:24 2006: DEBUG: AuthBy SQL result: ACCEPT,

Tue Jun 27 03:25:24 2006: DEBUG: Accounting accepted

Tue Jun 27 03:25:24 2006: DEBUG: Packet dump:

*** Sending to 10.10.10.39 port 1646 ....

Code:       Accounting-Response

Identifier: 184

Authentic:  `<215><7><196><145><252><144><214>P<144>]~<155><5>-$

Attributes:

This problem is occurring on both chassis so I don't suspect a problem with
them. One is programmed v.90 and the other with the current v.92 software. I
suspect a problem with the information that Radiator is returning.

Any help is MUCH appreciated. This is starting to upset some customers,
rightfully so.

Tom Greene

Byte Head Computer Solutions

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.open.com.au/pipermail/radiator/attachments/20060627/0d34b944/attachment.html>