(RADIATOR) Having some DBissues when using radmin/radiator and OTP

Hugh Irvine hugh at open.com.au
Sun Mar 18 18:07:30 CST 2007


Hello Haakan -

Thanks for the additional information.

Unfortunately I can't see what the problem might be, but Radiator  
seems to have a problem when doing an accounting insert into the  
RADUSAGE table.

I do notice however that you are using the "dictionary.cisco" - I  
suggest you use the "dictionary" file in the main distribution  
directory instead as it is a compendium of all of the dictionaries  
that we have, including Cisco. This will get rid of the "ERR:  
Attribute number 66 is not defined in your dictionary" error messages  
(and others like it).

I suggest you install DBI-Shell and try running the accounting  
queries shown in the logs by hand so you can see what happens.

BTW - the log messages are truncated in what you sent me, which makes  
it difficult to see what is happening.

regards

Hugh



On 19 Mar 2007, at 00:02, Haakan Olofsson wrote:

> At 00:11 18.03.2007, Hugh Irvine wrote:
>
>
>> I will need to see a copy of your configuration file, so could you
>> please send me a copy (no secrets)?
>>
>> And what does the database log show when the error happens?
>
> Hello Hugh
>
> Well all logs from radiator and mysql are in the text that  
> follows , including the running radiator config.
> You'll find mysql logs in the bottom of this mail
>
> Config file
>
> afasdf# cat /etc/radiator/radmin.cfg
> Foreground
> LogStdout
> AuthPort        1645
> AcctPort        1646
> LogFile         %L/logfile2
> LogDir          /var/log/radius
> DbDir           /etc/radiator
> DictionaryFile %D/dictionary.cisco
> PreClientHook file:"%D/alterNASPort"
>
> SnmpgetProg /usr/local/bin/snmpget
> SnmpwalkProg /usr/local/bin/snmpwalk
>
> Trace 4
>
> # You will probably want to change this to suit your site.
> # You should list all the clients you have, and their secrets
> # If you are using the Radmin Clients table, you wil probably
> # want to disable this.
>
>
> <Client DEFAULT>
>         Secret SETECASTRONOMY
>         DupInterval 0
>         NasType Cisco
> </Client>
>
> # Handle everyone with RADMIN, then OTP
> <Realm DEFAULT>
>                 # Ensure we first check the username validity with  
> Radmin
>                 # and then check the password with OTP afterwards
>                 AuthByPolicy ContinueWhileAccept
>
>                 # Check username validity etc with RAdmin:
>                 <AuthBy RADMIN>
>
>                         # Change DBSource, DBUsername, DBAuth for  
> your database
>                         # See the reference manual. You will also  
> have to
>                         # change the one in <SessionDatabse SQL> below
>                         # so its the same
>                         DBSource        dbi:mysql:radmin:localhost
>                         DBUsername      radius
>                         DBAuth          SETECASTRONOMY
>
>                         # Never look up the DEFAULT user
>                         NoDefault
>
>                         # AuthBy OTP below will check the password
>                         NoCheckPassword
>
>                         # Here we set up a custom select query that  
> gets the FULLNAME
>                         # column, where we are storing the users  
> SMS number
>                         AuthSelect select PASS_WORD, STATICADDRESS,  
> TIMELEFT, MAXLOGINS, SERVICENAME, BADLOGINS, VALIDFROM, VALIDTO,  
> TELEPHONENUMBER, FULLNAME  from RADUSERS where USERNAME=%0
>
>                         # Here we add the users SMS number from the  
> FULLNAME column
>                         # to the incoming request
>                         # so AuthBy OTP will get it below
>                         AuthColumnDef 0, SMS-Number, request
>
>                         # You can add to or change these if you  
> want, but you
>                         # will probably want to change the database  
> schema first
>                         AccountingTable RADUSAGE
>                         AcctColumnDef USERNAME,User-Name
>                         AcctColumnDef PASS_WORD,Password
>                         AcctColumnDef TELEPHONENUMBER,TelephoneNumber
>                         AcctColumnDef TIME_STAMP,Timestamp,integer
>                         AcctColumnDef ACCTSTATUSTYPE,Acct-Status- 
> Type,integer
>                         AcctColumnDef ACCTDELAYTIME,Acct-Delay- 
> Time,integer
>                         AcctColumnDef ACCTINPUTOCTETS,Acct-Input- 
> Octets,integer
>                         AcctColumnDef ACCTOUTPUTOCTETS,Acct-Output- 
> Octets,integer
>                         AcctColumnDef ACCTSESSIONID,Acct-Session-Id
>                         AcctColumnDef ACCTSESSIONTIME,Acct-Session- 
> Time,integer
>                         AcctColumnDef ACCTTERMINATECAUSE,Acct- 
> Terminate-Cause,integer
>                         AcctColumnDef FRAMEDIPADDRESS,Framed-IP- 
> Address
>                         AcctColumnDef NASIDENTIFIER,NAS-IP-Address
>                         AcctColumnDef NASIDENTIFIER,NAS-Identifier
>                         AcctColumnDef NASPORT,NAS-Port,integer
>                         AcctColumnDef DNIS,Called-Station-Id
>                         AcctColumnDef CALLINGSTATIONID,Calling- 
> Station-Id
>
>                         # This updates the time and octets left
>                         # for this user
>                         AcctSQLStatement update RADUSERS set  
> TIMELEFT=TIMELEFT-0%{Acct-Session-Time},  
> OCTETSINLEFT=OCTETSINLEFT-0%{Acct-Input-Octets},  
> OCTETSOUTLEFT=OCTETSOUTLEFT-0%{Acct-Output-Octets} where USERNAME='%n'
>
>                 </AuthBy>
>
>                 # If the username is valid etc then we get to here  
> and issue or check
>                 # the One-Time-Pasword
>
>                 <AuthBy OTP>
>                         # This hook generates a new random password  
> and sends it
>                         # to the users SMS number (which we got  
> from the FULLNAME column
>                         # in the Radmin database above),
>                         # You can configure 'test' to 1 to prevent  
> sending
>
>                         ChallengeHook sub {\
>                                 use Radius::SMS::Tele2SMS;\
>                                 my ($self, $user, $p, $context) = @_;\
>                                 $context->{otp_password} = $self- 
> >generate_password();\
>                                 my $errormsg = $self->sms_tele2(\
>                                 debug => '-',\
>                                 username => 'tele2',\
>                                 password => 'CGcer32',\
>                                 mclass => '1',\
>                                 to => $p->get_attr('SMS-Number'),\
>                                 text => "Password: $context-> 
> {otp_password}",\
>                                 test => 1);\
>                                 return (defined $errormsg) ?  
> undef : 'Wait for your password via SMS';\
>                         }
>
>                 #        ChallengeHook sub {my ($self, $user, $p,  
> $context) = @_;\
>                 #        $context->{otp_password} = $self- 
> >generate_password();\
>
>                         #system('/bin/echo', "in sample  
> ChallengeHook for", $user, "password is", $context->{otp_password});\
>                         #return "Your OTP password has been printed  
> by Radiator on STDOUT";}
>                 </AuthBy>
>
>                 # This clause logs all authentication successes and  
> failures to the RADAUTHLOG table
>                 # Suitable for use with RAdmin version 1.6 or later
>
>                 <AuthLog SQL>
>                         # This database spec usually should be  
> exactly the same
>                         # as in <AuthBy RADMIN> above
>
>                         DBSource        dbi:mysql:radmin:localhost
>                         DBUsername      radius
>                         DBAuth          SETECASTRONOMY
>
>                         LogSuccess
>                         SuccessQuery insert into RADAUTHLOG  
> (TIME_STAMP, USERNAME, TYPE) values (%t, '%n', 1)
>                         LogFailure
>                         FailureQuery insert into RADAUTHLOG  
> (TIME_STAMP, USERNAME, TYPE, REASON) values (%t, '%n', 0, %1)
>                 </AuthLog>
> </Realm>
>
> <SessionDatabase SQL>
>         # This database spec usually should be exactly the same
>         # as in <AuthBy RADMIN> above
>                 DBSource        dbi:mysql:radmin:localhost
>                 DBUsername      radius
>                 DBAuth          SETECASTRONOMY
> </SessionDatabase>
>
>
> ---------------------------------------------------------------------- 
> ---------------------------------------------------------------------- 
> ----------------------------------------
>
>
> Logs from radiator
>
> afasdf# radiusd -config_file /etc/radiator/radmin.cfg
> Sat Mar 17 19:10:36 2007: DEBUG: Finished reading configuration  
> file '/etc/radiator/radmin.cfg'
> This Radiator license will expire on 2007-05-30
> This Radiator license will stop operating after 1000 requests
> To purchase an unlimited full source version of Radiator, see
> http://www.open.com.au/ordering.html
> To extend your license period, contact admin at open.com.au
>
> Sat Mar 17 19:10:36 2007: DEBUG: Reading dictionary file '/etc/ 
> radiator/dictionary.cisco'
> Sat Mar 17 19:10:36 2007: DEBUG: Creating authentication port  
> 0.0.0.0:1645
> Sat Mar 17 19:10:36 2007: DEBUG: Creating accounting port 0.0.0.0:1646
> Sat Mar 17 19:10:36 2007: NOTICE: Server started: Radiator 3.16 on  
> some.radius.server (LOCKED)
> Sat Mar 17 19:10:45 2007: ERR: Attribute number 66 is not defined  
> in your dictionary
> Sat Mar 17 19:10:45 2007: DEBUG: Packet dump:
> *** Received from 10.0.202.2 port 1695 ....
> Code:       Accounting-Request
> Identifier: 14
> Authentic:  XC<10><162><3<5><217><129><209><14><234>{L<159><174>
> Attributes:
>         User-Name = "olofson"
>         NAS-Port = 1955
>         Service-Type = Framed
>         Framed-Protocol = PPP
>         Framed-IP-Address = 10.0.202.65
>         Class = "juniks"
>         Calling-Station-Id = "192.168.254.88"
>         Acct-Status-Type = Stop
>         Acct-Input-Octets = 2728
>         Acct-Output-Octets = 0
>         Acct-Session-Id = "FB00041C"
>         Acct-Session-Time = 249
>         Acct-Input-Packets = 26
>         Acct-Output-Packets = 0
>         Acct-Terminate-Cause = User-Request
>         Acct-Authentic = RADIUS
>         Acct-Delay-Time = 0
>         NAS-IP-Address = 10.0.202.2
>         NAS-Port-Type = Virtual
>
> Sat Mar 17 19:10:45 2007: DEBUG: Handling request with Handler  
> 'Realm=DEFAULT'
> Sat Mar 17 19:10:45 2007: DEBUG:  Deleting session for olofson,  
> 10.0.202.2, 1955
> Sat Mar 17 19:10:45 2007: DEBUG: do query is: 'delete from  
> RADONLINE where NASIDENTIFIER='10.0.202.2' and NASPORT=01955':
> Sat Mar 17 19:10:45 2007: DEBUG: Handling with Radius::AuthRADMIN
> Sat Mar 17 19:10:45 2007: DEBUG: Handling accounting with  
> Radius::AuthRADMIN
> Sat Mar 17 19:10:45 2007: DEBUG: do query is: 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTINPUTOCTETS,ACCTOUTPUTOCTETS,ACCTSESSIONID,ACCTSESS 
> IONTIME,ACCTSTATUSTYPE,ACCTTERMINATECAUSE,CALLINGSTATIONID,FRAMEDIPADD 
> RESS,NASIDENTIFIER,NASPOR
> Sat Mar 17 19:10:45 2007: ERR: do failed for 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTINPUTOCTETS,ACCTOUTPUTOCTETS,ACCTSESSIONID,ACCTSESS 
> IONTIME,ACCTSTATUSTYPE,ACCTTERMINATECAUSE,CALLINGSTATIONID,FRAMEDIPADD 
> RESS,NASIDENTIFIER,NASPO
> Sat Mar 17 19:10:45 2007: ERR: do failed for 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTINPUTOCTETS,ACCTOUTPUTOCTETS,ACCTSESSIONID,ACCTSESS 
> IONTIME,ACCTSTATUSTYPE,ACCTTERMINATECAUSE,CALLINGSTATIONID,FRAMEDIPADD 
> RESS,NASIDENTIFIER,NASPO
> Sat Mar 17 19:10:45 2007: DEBUG: AuthBy RADMIN result: IGNORE,  
> Database failure
> Sat Mar 17 19:10:46 2007: ERR: Attribute number 66 is not defined  
> in your dictionary
> Sat Mar 17 19:10:46 2007: DEBUG: Packet dump:
> *** Received from 10.0.202.2 port 1695 ....
> Code:       Accounting-Request
> Identifier: 14
> Authentic:  XC<10><162><3<5><217><129><209><14><234>{L<159><174>
> Attributes:
>         User-Name = "olofson"
>         NAS-Port = 1955
>         Service-Type = Framed
>         Framed-Protocol = PPP
>         Framed-IP-Address = 10.0.202.65
>         Class = "juniks"
>         Calling-Station-Id = "192.168.254.88"
>         Acct-Status-Type = Stop
>         Acct-Input-Octets = 2728
>         Acct-Output-Octets = 0
>         Acct-Session-Id = "FB00041C"
>         Acct-Session-Time = 249
>         Acct-Input-Packets = 26
>         Acct-Output-Packets = 0
>         Acct-Terminate-Cause = User-Request
>         Acct-Authentic = RADIUS
>         Acct-Delay-Time = 0
>         NAS-IP-Address = 10.0.202.2
>         NAS-Port-Type = Virtual
>
> Sat Mar 17 19:10:46 2007: DEBUG: Handling request with Handler  
> 'Realm=DEFAULT'
> Sat Mar 17 19:10:46 2007: DEBUG:  Deleting session for olofson,  
> 10.0.202.2, 1955
> Sat Mar 17 19:10:46 2007: DEBUG: do query is: 'delete from  
> RADONLINE where NASIDENTIFIER='10.0.202.2' and NASPORT=01955':
> Sat Mar 17 19:10:46 2007: DEBUG: Handling with Radius::AuthRADMIN
> Sat Mar 17 19:10:46 2007: DEBUG: Handling accounting with  
> Radius::AuthRADMIN
> Sat Mar 17 19:10:46 2007: DEBUG: do query is: 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTINPUTOCTETS,ACCTOUTPUTOCTETS,ACCTSESSIONID,ACCTSESS 
> IONTIME,ACCTSTATUSTYPE,ACCTTERMINATECAUSE,CALLINGSTATIONID,FRAMEDIPADD 
> RESS,NASIDENTIFIER,NASPOR
> Sat Mar 17 19:10:46 2007: ERR: do failed for 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTINPUTOCTETS,ACCTOUTPUTOCTETS,ACCTSESSIONID,ACCTSESS 
> IONTIME,ACCTSTATUSTYPE,ACCTTERMINATECAUSE,CALLINGSTATIONID,FRAMEDIPADD 
> RESS,NASIDENTIFIER,NASPO
> Sat Mar 17 19:10:46 2007: ERR: do failed for 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTINPUTOCTETS,ACCTOUTPUTOCTETS,ACCTSESSIONID,ACCTSESS 
> IONTIME,ACCTSTATUSTYPE,ACCTTERMINATECAUSE,CALLINGSTATIONID,FRAMEDIPADD 
> RESS,NASIDENTIFIER,NASPO
> Sat Mar 17 19:10:46 2007: DEBUG: AuthBy RADMIN result: IGNORE,  
> Database failure
> Sat Mar 17 19:10:47 2007: ERR: Attribute number 66 is not defined  
> in your dictionary
> Sat Mar 17 19:10:47 2007: DEBUG: Packet dump:
> *** Received from 10.0.202.2 port 1695 ....
> Code:       Accounting-Request
> Identifier: 14
> Authentic:  XC<10><162><3<5><217><129><209><14><234>{L<159><174>
> Attributes:
>         User-Name = "olofson"
>         NAS-Port = 1955
>         Service-Type = Framed
>         Framed-Protocol = PPP
>         Framed-IP-Address = 10.0.202.65
>         Class = "juniks"
>         Calling-Station-Id = "192.168.254.88"
>         Acct-Status-Type = Stop
>         Acct-Input-Octets = 2728
>         Acct-Output-Octets = 0
>         Acct-Session-Id = "FB00041C"
>         Acct-Session-Time = 249
>         Acct-Input-Packets = 26
>         Acct-Output-Packets = 0
>         Acct-Terminate-Cause = User-Request
>         Acct-Authentic = RADIUS
>         Acct-Delay-Time = 0
>         NAS-IP-Address = 10.0.202.2
>         NAS-Port-Type = Virtual
>
> Sat Mar 17 19:10:47 2007: DEBUG: Handling request with Handler  
> 'Realm=DEFAULT'
> Sat Mar 17 19:10:47 2007: DEBUG:  Deleting session for olofson,  
> 10.0.202.2, 1955
> Sat Mar 17 19:10:47 2007: DEBUG: do query is: 'delete from  
> RADONLINE where NASIDENTIFIER='10.0.202.2' and NASPORT=01955':
> Sat Mar 17 19:10:47 2007: DEBUG: Handling with Radius::AuthRADMIN
> Sat Mar 17 19:10:47 2007: DEBUG: Handling accounting with  
> Radius::AuthRADMIN
> Sat Mar 17 19:10:47 2007: DEBUG: do query is: 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTINPUTOCTETS,ACCTOUTPUTOCTETS,ACCTSESSIONID,ACCTSESS 
> IONTIME,ACCTSTATUSTYPE,ACCTTERMINATECAUSE,CALLINGSTATIONID,FRAMEDIPADD 
> RESS,NASIDENTIFIER,NASPOR
> Sat Mar 17 19:10:47 2007: ERR: do failed for 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTINPUTOCTETS,ACCTOUTPUTOCTETS,ACCTSESSIONID,ACCTSESS 
> IONTIME,ACCTSTATUSTYPE,ACCTTERMINATECAUSE,CALLINGSTATIONID,FRAMEDIPADD 
> RESS,NASIDENTIFIER,NASPO
> Sat Mar 17 19:10:47 2007: ERR: do failed for 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTINPUTOCTETS,ACCTOUTPUTOCTETS,ACCTSESSIONID,ACCTSESS 
> IONTIME,ACCTSTATUSTYPE,ACCTTERMINATECAUSE,CALLINGSTATIONID,FRAMEDIPADD 
> RESS,NASIDENTIFIER,NASPO
> Sat Mar 17 19:10:47 2007: DEBUG: AuthBy RADMIN result: IGNORE,  
> Database failure
> Sat Mar 17 19:10:50 2007: ERR: Attribute number 66 is not defined  
> in your dictionary
> Sat Mar 17 19:10:50 2007: DEBUG: Packet dump:
> *** Received from 10.0.202.2 port 1666 ....
> Code:       Access-Request
> Identifier: 76
> Authentic:  <196><204>9<245><230>6U<10>[<217>K<214><148><187>}<196>
> Attributes:
>         User-Name = "olofson"
>         User-Password =  
> "<140><0>8Mf<137><163><200><207>z<209><198>E<17>y<147>"
>         NAS-Port = 1956
>         Service-Type = Framed
>         Framed-Protocol = PPP
>         Called-Station-Id = "192.168.1.2"
>         Calling-Station-Id = "192.168.254.88"
>         NAS-IP-Address = 10.0.202.2
>         NAS-Port-Type = Virtual
>
> Sat Mar 17 19:10:50 2007: DEBUG: Handling request with Handler  
> 'Realm=DEFAULT'
> Sat Mar 17 19:10:50 2007: DEBUG:  Deleting session for olofson,  
> 10.0.202.2, 1956
> Sat Mar 17 19:10:50 2007: DEBUG: do query is: 'delete from  
> RADONLINE where NASIDENTIFIER='10.0.202.2' and NASPORT=01956':
> Sat Mar 17 19:10:50 2007: DEBUG: Handling with Radius::AuthRADMIN
> Sat Mar 17 19:10:50 2007: DEBUG: Handling with Radius::AuthRADMIN:
> Sat Mar 17 19:10:50 2007: ERR: Attribute number 79 is not defined  
> in your dictionary
> Sat Mar 17 19:10:50 2007: DEBUG: Query is: 'select PASS_WORD,  
> STATICADDRESS, TIMELEFT, MAXLOGINS, SERVICENAME, BADLOGINS,  
> VALIDFROM, VALIDTO, TELEPHONENUMBER, FULLNAME  from RADUSERS where  
> USERNAME='olofson'':
> Sat Mar 17 19:10:50 2007: DEBUG: Query is: 'select ATTR_ID,  
> VENDOR_ID, IVALUE, SVALUE, ITEM_TYPE from RADCONFIG where  
> NAME='olofson' order by ITEM_TYPE':
> Sat Mar 17 19:10:50 2007: DEBUG: Radius::AuthRADMIN looks for match  
> with olofson [olofson]
> Sat Mar 17 19:10:50 2007: DEBUG: Query is: 'select NASIDENTIFIER,  
> NASPORT, ACCTSESSIONID, FRAMEDIPADDRESS from RADONLINE where  
> USERNAME='olofson'':
> Sat Mar 17 19:10:50 2007: DEBUG: ValidFrom date converted to:  
> 1173707880
> Sat Mar 17 19:10:50 2007: DEBUG: Expiration date converted to:  
> 1205280000
> Sat Mar 17 19:10:50 2007: DEBUG: do query is: 'update RADUSERS set  
> BADLOGINS=0 where USERNAME='olofson'':
> Sat Mar 17 19:10:50 2007: DEBUG: AuthBy RADMIN result: ACCEPT,
> Sat Mar 17 19:10:50 2007: DEBUG: Handling with Radius::AuthOTP:
> Sat Mar 17 19:10:50 2007: DEBUG: Radius::AuthOTP looks for match  
> with olofson [olofson]
> Sat Mar 17 19:10:50 2007: DEBUG: TELE2 SMSsender requesting http:// 
> 10.0.200.96:13013/cgi-bin/sendsms? 
> username=yourusername&password=yourpassword&mclass=1&to=4741319106&tex 
> t=Password: kiducej85&test=1
> Sat Mar 17 19:10:51 2007: ERR: Tele2 SMSsender generated a bad  
> request: 500 Can't connect to 10.0.200.96:13013 (connect: Invalid  
> argument)
> Sat Mar 17 19:10:51 2007: DEBUG: Radius::AuthOTP REJECT: OTP  
> challenge failed. Is OTP set up properly?: olofson [olofson]
> Sat Mar 17 19:10:51 2007: DEBUG: AuthBy OTP result: REJECT, OTP  
> challenge failed. Is OTP set up properly?
> Sat Mar 17 19:10:51 2007: INFO: Access rejected for olofson: OTP  
> challenge failed. Is OTP set up properly?
> Sat Mar 17 19:10:51 2007: DEBUG: do query is: 'insert into  
> RADAUTHLOG (TIME_STAMP, USERNAME, TYPE, REASON) values (1174158651,  
> 'olofson', 0, 'OTP challenge failed. Is OTP set up properly?')':
> Sat Mar 17 19:10:51 2007: DEBUG: Packet dump:
> *** Sending to 10.0.202.2 port 1666 ....
> Code:       Access-Reject
> Identifier: 76
> Authentic:  <196><204>9<245><230>6U<10>[<217>K<214><148><187>}<196>
> Attributes:
>         Reply-Message = "Request Denied"
>
> Sat Mar 17 19:11:03 2007: ERR: Attribute number 66 is not defined  
> in your dictionary
> Sat Mar 17 19:11:03 2007: DEBUG: Packet dump:
> *** Received from 10.0.202.2 port 1666 ....
> Code:       Access-Request
> Identifier: 77
> Authentic:  <186><144><228><249><201><27>E 
> {<129>N<205><31><177><28><179><18>
> Attributes:
>         User-Name = "olofson"
>         User-Password = "<7>D<180>y<173>s<154>`x3s<146><206><4><255>&"
>         NAS-Port = 1956
>         Service-Type = Framed
>         Framed-Protocol = PPP
>         Called-Station-Id = "192.168.1.2"
>         Calling-Station-Id = "192.168.254.88"
>         NAS-IP-Address = 10.0.202.2
>         NAS-Port-Type = Virtual
>
> Sat Mar 17 19:11:03 2007: DEBUG: Handling request with Handler  
> 'Realm=DEFAULT'
> Sat Mar 17 19:11:03 2007: DEBUG:  Deleting session for olofson,  
> 10.0.202.2, 1956
> Sat Mar 17 19:11:03 2007: DEBUG: do query is: 'delete from  
> RADONLINE where NASIDENTIFIER='10.0.202.2' and NASPORT=01956':
> Sat Mar 17 19:11:03 2007: DEBUG: Handling with Radius::AuthRADMIN
> Sat Mar 17 19:11:03 2007: DEBUG: Handling with Radius::AuthRADMIN:
> Sat Mar 17 19:11:03 2007: ERR: Attribute number 79 is not defined  
> in your dictionary
> Sat Mar 17 19:11:03 2007: DEBUG: Query is: 'select PASS_WORD,  
> STATICADDRESS, TIMELEFT, MAXLOGINS, SERVICENAME, BADLOGINS,  
> VALIDFROM, VALIDTO, TELEPHONENUMBER, FULLNAME  from RADUSERS where  
> USERNAME='olofson'':
> Sat Mar 17 19:11:03 2007: DEBUG: Query is: 'select ATTR_ID,  
> VENDOR_ID, IVALUE, SVALUE, ITEM_TYPE from RADCONFIG where  
> NAME='olofson' order by ITEM_TYPE':
> Sat Mar 17 19:11:03 2007: DEBUG: Radius::AuthRADMIN looks for match  
> with olofson [olofson]
> Sat Mar 17 19:11:03 2007: DEBUG: Query is: 'select NASIDENTIFIER,  
> NASPORT, ACCTSESSIONID, FRAMEDIPADDRESS from RADONLINE where  
> USERNAME='olofson'':
> Sat Mar 17 19:11:03 2007: DEBUG: ValidFrom date converted to:  
> 1173707880
> Sat Mar 17 19:11:03 2007: DEBUG: Expiration date converted to:  
> 1205280000
> Sat Mar 17 19:11:03 2007: DEBUG: do query is: 'update RADUSERS set  
> BADLOGINS=0 where USERNAME='olofson'':
> Sat Mar 17 19:11:03 2007: DEBUG: AuthBy RADMIN result: ACCEPT,
> Sat Mar 17 19:11:03 2007: DEBUG: Handling with Radius::AuthOTP:
> Sat Mar 17 19:11:03 2007: DEBUG: Radius::AuthOTP looks for match  
> with olofson [olofson]
> Sat Mar 17 19:11:03 2007: DEBUG: Radius::AuthOTP ACCEPT: blaj:  
> olofson [olofson]
> Sat Mar 17 19:11:03 2007: DEBUG: AuthBy OTP result: ACCEPT, blaj
> Sat Mar 17 19:11:03 2007: DEBUG: Access accepted for olofson
> Sat Mar 17 19:11:03 2007: DEBUG: do query is: 'insert into  
> RADAUTHLOG (TIME_STAMP, USERNAME, TYPE) values (1174158663,  
> 'olofson', 1)':
> Sat Mar 17 19:11:03 2007: DEBUG: Packet dump:
> *** Sending to 10.0.202.2 port 1666 ....
> Code:       Access-Accept
> Identifier: 77
> Authentic:  <186><144><228><249><201><27>E 
> {<129>N<205><31><177><28><179><18>
> Attributes:
>
> Sat Mar 17 19:11:04 2007: ERR: Attribute number 66 is not defined  
> in your dictionary
> Sat Mar 17 19:11:04 2007: DEBUG: Packet dump:
> *** Received from 10.0.202.2 port 1696 ....
> Code:       Accounting-Request
> Identifier: 15
> Authentic:  <179>>W 
> {<222><165><189><234><184><248><241>`<193><237><21><169>
> Attributes:
>         User-Name = "olofson"
>         NAS-Port = 1956
>         Service-Type = Framed
>         Framed-Protocol = PPP
>         Framed-IP-Address = 10.0.202.65
>         Class = "juniks"
>         Calling-Station-Id = "192.168.254.88"
>         Acct-Status-Type = Start
>         Acct-Session-Id = "FB00041D"
>         Acct-Authentic = RADIUS
>         Acct-Delay-Time = 0
>         NAS-IP-Address = 10.0.202.2
>         NAS-Port-Type = Virtual
>
> Sat Mar 17 19:11:04 2007: DEBUG: Handling request with Handler  
> 'Realm=DEFAULT'
> Sat Mar 17 19:11:04 2007: DEBUG:  Adding session for olofson,  
> 10.0.202.2, 1956
> Sat Mar 17 19:11:04 2007: DEBUG: do query is: 'delete from  
> RADONLINE where NASIDENTIFIER='10.0.202.2' and NASPORT=01956':
> Sat Mar 17 19:11:04 2007: DEBUG: do query is: 'insert into  
> RADONLINE (USERNAME, NASIDENTIFIER, NASPORT, ACCTSESSIONID,  
> TIME_STAMP, FRAMEDIPADDRESS, NASPORTTYPE, SERVICETYPE) values  
> ('olofson', '10.0.202.2', 1956, 'FB00041D', 1174158664,  
> '10.0.202.65', 'Virtual', 'Framed')':
> Sat Mar 17 19:11:04 2007: DEBUG: Handling with Radius::AuthRADMIN
> Sat Mar 17 19:11:04 2007: DEBUG: Handling accounting with  
> Radius::AuthRADMIN
> Sat Mar 17 19:11:04 2007: DEBUG: do query is: 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values  
> (0,'FB00041D',1,'192.168.254.88','10.0.
> Sat Mar 17 19:11:04 2007: ERR: do failed for 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values  
> (0,'FB00041D',1,'192.168.254.88','10.0
> Sat Mar 17 19:11:04 2007: ERR: do failed for 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values  
> (0,'FB00041D',1,'192.168.254.88','10.0
> Sat Mar 17 19:11:04 2007: DEBUG: AuthBy RADMIN result: IGNORE,  
> Database failure
> Sat Mar 17 19:11:05 2007: ERR: Attribute number 66 is not defined  
> in your dictionary
> Sat Mar 17 19:11:05 2007: DEBUG: Packet dump:
> *** Received from 10.0.202.2 port 1696 ....
> Code:       Accounting-Request
> Identifier: 15
> Authentic:  <179>>W 
> {<222><165><189><234><184><248><241>`<193><237><21><169>
> Attributes:
>         User-Name = "olofson"
>         NAS-Port = 1956
>         Service-Type = Framed
>         Framed-Protocol = PPP
>         Framed-IP-Address = 10.0.202.65
>         Class = "juniks"
>         Calling-Station-Id = "192.168.254.88"
>         Acct-Status-Type = Start
>         Acct-Session-Id = "FB00041D"
>         Acct-Authentic = RADIUS
>         Acct-Delay-Time = 0
>         NAS-IP-Address = 10.0.202.2
>         NAS-Port-Type = Virtual
>
> Sat Mar 17 19:11:05 2007: DEBUG: Handling request with Handler  
> 'Realm=DEFAULT'
> Sat Mar 17 19:11:05 2007: DEBUG:  Adding session for olofson,  
> 10.0.202.2, 1956
> Sat Mar 17 19:11:05 2007: DEBUG: do query is: 'delete from  
> RADONLINE where NASIDENTIFIER='10.0.202.2' and NASPORT=01956':
> Sat Mar 17 19:11:05 2007: DEBUG: do query is: 'insert into  
> RADONLINE (USERNAME, NASIDENTIFIER, NASPORT, ACCTSESSIONID,  
> TIME_STAMP, FRAMEDIPADDRESS, NASPORTTYPE, SERVICETYPE) values  
> ('olofson', '10.0.202.2', 1956, 'FB00041D', 1174158665,  
> '10.0.202.65', 'Virtual', 'Framed')':
> Sat Mar 17 19:11:05 2007: DEBUG: Handling with Radius::AuthRADMIN
> Sat Mar 17 19:11:05 2007: DEBUG: Handling accounting with  
> Radius::AuthRADMIN
> Sat Mar 17 19:11:05 2007: DEBUG: do query is: 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values  
> (0,'FB00041D',1,'192.168.254.88','10.0.
> Sat Mar 17 19:11:05 2007: ERR: do failed for 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values  
> (0,'FB00041D',1,'192.168.254.88','10.0
> Sat Mar 17 19:11:05 2007: ERR: do failed for 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values  
> (0,'FB00041D',1,'192.168.254.88','10.0
> Sat Mar 17 19:11:05 2007: DEBUG: AuthBy RADMIN result: IGNORE,  
> Database failure
> Sat Mar 17 19:11:06 2007: ERR: Attribute number 66 is not defined  
> in your dictionary
> Sat Mar 17 19:11:06 2007: DEBUG: Packet dump:
> *** Received from 10.0.202.2 port 1696 ....
> Code:       Accounting-Request
> Identifier: 15
> Authentic:  <179>>W 
> {<222><165><189><234><184><248><241>`<193><237><21><169>
> Attributes:
>         User-Name = "olofson"
>         NAS-Port = 1956
>         Service-Type = Framed
>         Framed-Protocol = PPP
>         Framed-IP-Address = 10.0.202.65
>         Class = "juniks"
>         Calling-Station-Id = "192.168.254.88"
>         Acct-Status-Type = Start
>         Acct-Session-Id = "FB00041D"
>         Acct-Authentic = RADIUS
>         Acct-Delay-Time = 0
>         NAS-IP-Address = 10.0.202.2
>         NAS-Port-Type = Virtual
>
> Sat Mar 17 19:11:06 2007: DEBUG: Handling request with Handler  
> 'Realm=DEFAULT'
> Sat Mar 17 19:11:06 2007: DEBUG:  Adding session for olofson,  
> 10.0.202.2, 1956
> Sat Mar 17 19:11:06 2007: DEBUG: do query is: 'delete from  
> RADONLINE where NASIDENTIFIER='10.0.202.2' and NASPORT=01956':
> Sat Mar 17 19:11:06 2007: DEBUG: do query is: 'insert into  
> RADONLINE (USERNAME, NASIDENTIFIER, NASPORT, ACCTSESSIONID,  
> TIME_STAMP, FRAMEDIPADDRESS, NASPORTTYPE, SERVICETYPE) values  
> ('olofson', '10.0.202.2', 1956, 'FB00041D', 1174158666,  
> '10.0.202.65', 'Virtual', 'Framed')':
> Sat Mar 17 19:11:06 2007: DEBUG: Handling with Radius::AuthRADMIN
> Sat Mar 17 19:11:06 2007: DEBUG: Handling accounting with  
> Radius::AuthRADMIN
> Sat Mar 17 19:11:06 2007: DEBUG: do query is: 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values  
> (0,'FB00041D',1,'192.168.254.88','10.0.
> Sat Mar 17 19:11:06 2007: ERR: do failed for 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values  
> (0,'FB00041D',1,'192.168.254.88','10.0
> Sat Mar 17 19:11:06 2007: ERR: do failed for 'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values  
> (0,'FB00041D',1,'192.168.254.88','10.0
> Sat Mar 17 19:11:06 2007: DEBUG: AuthBy RADMIN result: IGNORE,  
> Database failure
> ^C
>
> ---------------------------------------------------------------------- 
> ---------------------------------------------------------------------- 
> ----------------------------------------
>
> Logs from mysqlqueries
>
>
> 070317 19:11:05     957 Connect     radius at localhost on radmin
>                     957 Query       delete from RADONLINE where  
> NASIDENTIFIER='10.0.202.2' and NASPORT=01956
>                     957 Query       insert into RADONLINE  
> (USERNAME, NASIDENTIFIER, NASPORT, ACCTSESSIONID, TIME_STAMP,  
> FRAMEDIPADDRESS, NASPORTTYPE, SERVICETYPE) values ('olofson',  
> '10.0.202.2', 1956, 'FB00041D', 1174158665, '10.0.202.65',  
> 'Virtual', 'Framed')
>                     957 Query       insert into RADMESSAGES  
> (TIME_STAMP, TYPE, MESSAGE) values (1174158665, 4, 'Handling with  
> Radius::AuthRADMIN')
>                     957 Query       insert into RADMESSAGES  
> (TIME_STAMP, TYPE, MESSAGE) values (1174158665, 4, 'Handling  
> accounting with Radius::AuthRADMIN')
>                     957 Query       insert into RADMESSAGES  
> (TIME_STAMP, TYPE, MESSAGE) values (1174158665, 4, 'do query is:  
> \'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values (0, 
> \'FB00041D\',1,\'192.168.254.88\',\'10.0.')
>                     957 Query       insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values  
> (0,'FB00041D',1,'192.168.254.88','10.0.202.65','10.0.202.2', 
> 1956,1174158665,'olofson')
>                     957 Query       insert into RADMESSAGES  
> (TIME_STAMP, TYPE, MESSAGE) values (1174158665, 0, 'do failed for  
> \'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values (0, 
> \'FB00041D\',1,\'192.168.254.88\',\'10.0')
>                     957 Quit
>                     958 Connect     radius at localhost on radmin
>                     958 Query       insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values  
> (0,'FB00041D',1,'192.168.254.88','10.0.202.65','10.0.202.2', 
> 1956,1174158665,'olofson')
>                     958 Query       insert into RADMESSAGES  
> (TIME_STAMP, TYPE, MESSAGE) values (1174158665, 0, 'do failed for  
> \'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values (0, 
> \'FB00041D\',1,\'192.168.254.88\',\'10.0')
>                     958 Quit
>
>
> 070317 19:11:06     959 Connect     radius at localhost on radmin
>                     959 Query       delete from RADONLINE where  
> NASIDENTIFIER='10.0.202.2' and NASPORT=01956
>                     959 Query       insert into RADONLINE  
> (USERNAME, NASIDENTIFIER, NASPORT, ACCTSESSIONID, TIME_STAMP,  
> FRAMEDIPADDRESS, NASPORTTYPE, SERVICETYPE) values ('olofson',  
> '10.0.202.2', 1956, 'FB00041D', 1174158666, '10.0.202.65',  
> 'Virtual', 'Framed')
>                     959 Query       insert into RADMESSAGES  
> (TIME_STAMP, TYPE, MESSAGE) values (1174158666, 4, 'Handling with  
> Radius::AuthRADMIN')
>                     959 Query       insert into RADMESSAGES  
> (TIME_STAMP, TYPE, MESSAGE) values (1174158666, 4, 'Handling  
> accounting with Radius::AuthRADMIN')
>                     959 Query       insert into RADMESSAGES  
> (TIME_STAMP, TYPE, MESSAGE) values (1174158666, 4, 'do query is:  
> \'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values (0, 
> \'FB00041D\',1,\'192.168.254.88\',\'10.0.')
>                     959 Query       insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values  
> (0,'FB00041D',1,'192.168.254.88','10.0.202.65','10.0.202.2', 
> 1956,1174158666,'olofson')
>                     959 Query       insert into RADMESSAGES  
> (TIME_STAMP, TYPE, MESSAGE) values (1174158666, 0, 'do failed for  
> \'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values (0, 
> \'FB00041D\',1,\'192.168.254.88\',\'10.0')
>                     959 Quit
>                     960 Connect     radius at localhost on radmin
>                     960 Query       insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values  
> (0,'FB00041D',1,'192.168.254.88','10.0.202.65','10.0.202.2', 
> 1956,1174158666,'olofson')
>                     960 Query       insert into RADMESSAGES  
> (TIME_STAMP, TYPE, MESSAGE) values (1174158666, 0, 'do failed for  
> \'insert into RADUSAGE  
> (ACCTDELAYTIME,ACCTSESSIONID,ACCTSTATUSTYPE,CALLINGSTATIONID,FRAMEDIPA 
> DDRESS,NASIDENTIFIER,NASPORT,TIME_STAMP,USERNAME) values (0, 
> \'FB00041D\',1,\'192.168.254.88\',\'10.0')
>                     960 Quit
>
>
>
>
>
>
>
>
> ---------------------------------------------------------------------- 
> ---------------------------------------------------------------------- 
> ----------------------------------------



NB:

Have you read the reference manual ("doc/ref.html")?
Have you searched the mailing list archive (www.open.com.au/archives/ 
radiator)?
Have you had a quick look on Google (www.google.com)?
Have you included a copy of your configuration file (no secrets),
together with a trace 4 debug showing what is happening?

-- 
Radiator: the most portable, flexible and configurable RADIUS server
anywhere. Available on *NIX, *BSD, Windows, MacOS X.
Includes support for reliable RADIUS transport (RadSec),
and DIAMETER translation agent.
-
Nets: internetwork inventory and management - graphical, extensible,
flexible with hardware, software, platform and database independence.
-
CATool: Private Certificate Authority for Unix and Unix-like systems.


--
Archive at http://www.open.com.au/archives/radiator/
Announcements on radiator-announce at open.com.au
To unsubscribe, email 'majordomo at open.com.au' with
'unsubscribe radiator' in the body of the message.


More information about the radiator mailing list