I keep getting these error messages in my new freeradius install...
freeradius-snapshot-20020205
rlm_sql_mysql with Mysql 3.23.47 + shared mysqlclient libs
This seems to happen ONLY on my ascend boxes, not on my new patton 2996
boxes.
I've disabled ASCEND_PORT_HACK (The boxes assign the IP addresses, plus at
least ONE of my boxes has 23+24 lines instead of 23+23, and one has 4 lines)
and also disabled CISCO_ACCOUNTING_HACK
I use sql for user accounting and authentication, and only use radutmp for
the Simultaneous-Use limiting.
I've noticed that often when this happens there is NO user logged into that
port according to radwho (radutmp) but the sql tables shows that there IS
someone logged in. (And a finger to that ascend box shows the same person
logged in as the sql tables show).
Any ideas?
It LOOKS like there are some strange Acct STOP records being sent that don't
have corresponding Start records, and freeradius is ignoring them, and the
ascend box just keeps sending them again and again....
[excerpt from -xx logs, a3 port 20113]
Thread 1 handling request 0, (1 handled so far)
NAS-IP-Address = 205.161.172.7
NAS-Port = 20113
Ascend-NAS-Port-Format = 1_2_2
NAS-Port-Type = Async
Acct-Status-Type = Stop
Acct-Delay-Time = 1
Acct-Session-Id = "14b1f251"
Ascend-Disconnect-Cause = Invalid-Incoming-User
Ascend-Connect-Progress = IPNCP-Opened
Ascend-Xmit-Rate = 46667
Ascend-Data-Rate = 24000
Ascend-PreSession-Time = 27
Ascend-Pre-Input-Octets = 1194
Ascend-Pre-Output-Octets = 315
Ascend-Pre-Input-Packets = 23
Ascend-Pre-Output-Packets = 18
Ascend-Modem-PortNo = 5
Ascend-Modem-SlotNo = 5
Called-Station-Id = "6092400"
modcall: entering group preacct
modcall[preacct]: module "suffix" returns ok
modcall[preacct]: module "files" returns noop
modcall[preacct]: module "preprocess" returns noop
modcall: group preacct returns ok
modcall: entering group accounting
radius_xlat: '/usr/local/var/log/radius/radacct/205.161.172.7/detail'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail
expand
s to /usr/local/var/log/radius/radacct/205.161.172.7/detail
modcall[accounting]: module "detail" returns ok
modcall[accounting]: module "unix" returns noop
radius_xlat: ''
modcall[accounting]: module "radutmp" returns ok
rlm_sql: Reserving sql socket id: 4
radius_xlat: ''
rlm_sql: Released sql socket id: 4
modcall[accounting]: module "sql" returns fail
modcall: group accounting returns fail
Finished request 0
Going to the next request
[...]
Thread 2 handling request 46, (10 handled so far)
User-Name = "amorris"
NAS-IP-Address = 205.161.172.7
NAS-Port = 20113
Ascend-NAS-Port-Format = 1_2_2
NAS-Port-Type = Async
Acct-Status-Type = Start
Acct-Delay-Time = 0
Acct-Session-Id = "14b1f252"
Acct-Authentic = RADIUS
Ascend-Modem-PortNo = 5
Ascend-Modem-SlotNo = 5
Called-Station-Id = "6092400"
Framed-Protocol = PPP
Framed-IP-Address = 205.161.172.139
rad_lowerpair: User-Name now 'amorris'
rad_rmspace_pair: User-Name now 'amorris'
modcall: entering group preacct
modcall[preacct]: module "suffix" returns ok
modcall[preacct]: module "files" returns noop
modcall[preacct]: module "preprocess" returns noop
modcall: group preacct returns ok
modcall: entering group accounting
radius_xlat: '/usr/local/var/log/radius/radacct/205.161.172.7/detail'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail
expand
s to /usr/local/var/log/radius/radacct/205.161.172.7/detail
modcall[accounting]: module "detail" returns ok
modcall[accounting]: module "unix" returns ok
radius_xlat: 'amorris'
modcall[accounting]: module "radutmp" returns ok
rlm_sql: Reserving sql socket id: 4
radius_xlat: 'amorris'
sql_escape in: 'amorris'
sql_escape out: 'amorris'
sql_set_user: escaped user --> 'amorris'
radius_xlat: 'INSERT into radacct (RadAcctId, AcctSessionId, AcctUniqueId,
User
Name, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime,
AcctStopTime,
AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_stop,
AcctInputOc
tets, AcctOutputOctets, CalledStationId, CallingStationId,
AcctTerminateCause, S
erviceType, FramedProtocol, FramedIPAddress, AcctStartDelay, AcctStopDelay)
valu
es('', '14b1f252', '', 'amorris', 'DEFAULT', '205.161.172.7', '20113',
'Async',
'2002-02-14 15:48:39', '0', '0', 'RADIUS', '', '', '0', '0', '6092400', '',
'',
'Framed-User', 'PPP', '205.161.172.139', '0', '0')'
rlm_sql: Released sql socket id: 4
modcall[accounting]: module "sql" returns ok
modcall: group accounting returns ok
Sending Accounting-Response of id 56 to 205.161.172.7:1028
Finished request 46
[...]
Thread 3 handling request 47, (10 handled so far)
NAS-IP-Address = 205.161.172.7
NAS-Port = 20113
Ascend-NAS-Port-Format = 1_2_2
NAS-Port-Type = Async
Acct-Status-Type = Stop
Acct-Delay-Time = 47
Acct-Session-Id = "14b1f251"
Ascend-Disconnect-Cause = Invalid-Incoming-User
Ascend-Connect-Progress = IPNCP-Opened
Ascend-Xmit-Rate = 46667
Ascend-Data-Rate = 24000
Ascend-PreSession-Time = 27
Ascend-Pre-Input-Octets = 1194
Ascend-Pre-Output-Octets = 315
Ascend-Pre-Input-Packets = 23
Ascend-Pre-Output-Packets = 18
Ascend-Modem-PortNo = 5
Ascend-Modem-SlotNo = 5
Called-Station-Id = "6092400"
modcall: entering group preacct
modcall[preacct]: module "suffix" returns ok
modcall[preacct]: module "files" returns noop
modcall[preacct]: module "preprocess" returns noop
modcall: group preacct returns ok
modcall: entering group accounting
radius_xlat: '/usr/local/var/log/radius/radacct/205.161.172.7/detail'
rlm_detail: /usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail
expand
s to /usr/local/var/log/radius/radacct/205.161.172.7/detail
modcall[accounting]: module "detail" returns ok
modcall[accounting]: module "unix" returns noop
radius_xlat: ''
Accounting: logout: entry for NAS a3 port 20113 has wrong ID
modcall[accounting]: module "radutmp" returns ok
rlm_sql: Reserving sql socket id: 4
radius_xlat: ''
rlm_sql: Released sql socket id: 4
modcall[accounting]: module "sql" returns fail
modcall: group accounting returns fail
Finished request 47
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
