запускаем radiusd -XКогда приходит пакет от NAS с промежуточным обновлением, видим, что запрос выполняется:
rad_recv: Accounting-Request packet from host 192.168.99.1:1646, id=211, length=278
Acct-Session-Id = "000023CA"
Cisco-AVPair = "client-mac-address=0014.2a41.3dd1"
Framed-Protocol = PPP
Framed-IP-Address = 192.168.222.222
User-Name = "gsv123"
Cisco-AVPair = "connect-progress=LAN Ses Up"
Cisco-AVPair = "nas-tx-speed=950000"
Cisco-AVPair = "nas-rx-speed=950000"
Acct-Session-Time = 63
Acct-Input-Octets = 1523
Acct-Output-Octets = 290
Acct-Input-Packets = 26
Acct-Output-Packets = 19
Acct-Authentic = RADIUS
Acct-Status-Type = Interim-Update
NAS-Port-Type = Virtual
Cisco-NAS-Port = "0/0/1/33"
NAS-Port = 0
NAS-Port-Id = "0/0/1/33"
Service-Type = Framed-User
NAS-IP-Address = 192.168.99.1
Acct-Delay-Time = 15
Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 0
modcall[preacct]: module "preprocess" returns noop for request 0
rlm_acct_unique: Hashing 'NAS-Port = 0,Client-IP-Address = 192.168.99.1,NAS-IP-Address = 192.168.99.1,Acct-Session-Id = "000023CA",User-Name = "gsv123"'
rlm_acct_unique: Acct-Unique-Session-ID = "42cd7dcfe62ebb17".
modcall[preacct]: module "acct_unique" returns ok for request 0
rlm_realm: No '@' in User-Name = "gsv123", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[preacct]: module "suffix" returns noop for request 0
modcall: leaving group preacct (returns ok) for request 0
Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 0
radius_xlat: '/var/log/radacct/192.168.99.1/detail-20070814'
rlm_detail: /var/log/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radacct/192.168.99.1/detail-20070814
modcall[accounting]: module "detail" returns ok for request 0
modcall[accounting]: module "unix" returns noop for request 0
radius_xlat: '/var/log/radutmp'
radius_xlat: 'gsv123'
modcall[accounting]: module "radutmp" returns ok for request 0
radius_xlat: 'gsv123'
rlm_sql (sql): sql_set_user escaped user --> 'gsv123'
radius_xlat: 'UPDATE radacct SET FramedIPAddress = '192.168.222.222', AcctSessionTime = '63', AcctInputOctets = '1523', AcctOutputOctets = '290' WHERE AcctSessionId = '000023CA' AND UserName = 'gsv123' AND NASIPAddress= '192.168.99.1''
radius_xlat: '/var/log/radacct/sqltrace.sql'
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql_mysql: query: UPDATE radacct SET FramedIPAddress = '192.168.222.222', AcctSessionTime = '63', AcctInputOctets = '1523', AcctOutputOctets = '290' WHERE AcctSessionId = '000023CA' AND UserName = 'gsv123' AND NASIPAddress= '192.168.99.1'
rlm_sql (sql): Released sql socket id: 4
modcall[accounting]: module "sql" returns ok for request 0
modcall: leaving group accounting (returns ok) for request 0
Sending Accounting-Response of id 211 to 192.168.99.1 port 1646
Finished request 0
Going to the next request
когда приходит пакет stop, видим:
Cleaning up request 0 ID 252 with timestamp 46c1a480
Nothing to do. Sleeping until we see a request.
rad_recv: Accounting-Request packet from host 192.168.99.1:1646, id=254, length=323
Acct-Session-Id = "000023CA"
Cisco-AVPair = "client-mac-address=0014.2a41.3dd1"
Framed-Protocol = PPP
Framed-IP-Address = 192.168.222.222
User-Name = "gsv123"
Acct-Authentic = RADIUS
Cisco-AVPair = "connect-progress=LAN Ses Up"
Cisco-AVPair = "nas-tx-speed=950000"
Cisco-AVPair = "nas-rx-speed=950000"
Acct-Session-Time = 194
Acct-Input-Octets = 2069
Acct-Output-Octets = 646
Acct-Input-Packets = 53
Acct-Output-Packets = 45
Acct-Terminate-Cause = User-Request
Cisco-AVPair = "disc-cause-ext=PPP Receive Term"
Acct-Status-Type = Stop
NAS-Port-Type = Virtual
Cisco-NAS-Port = "0/0/1/33"
NAS-Port = 0
NAS-Port-Id = "0/0/1/33"
Service-Type = Framed-User
NAS-IP-Address = 192.168.99.1
Acct-Delay-Time = 0
Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 1
modcall[preacct]: module "preprocess" returns noop for request 1
rlm_acct_unique: Hashing 'NAS-Port = 0,Client-IP-Address = 192.168.99.1,NAS-IP-Address = 192.168.99.1,Acct-Session-Id = "000023CA",User-Name = "gsv123"'
rlm_acct_unique: Acct-Unique-Session-ID = "42cd7dcfe62ebb17".
modcall[preacct]: module "acct_unique" returns ok for request 1
rlm_realm: No '@' in User-Name = "gsv123", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[preacct]: module "suffix" returns noop for request 1
modcall: leaving group preacct (returns ok) for request 1
Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 1
radius_xlat: '/var/log/radacct/192.168.99.1/detail-20070814'
rlm_detail: /var/log/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radacct/192.168.99.1/detail-20070814
modcall[accounting]: module "detail" returns ok for request 1
modcall[accounting]: module "unix" returns fail for request 1
modcall: leaving group accounting (returns fail) for request 1
Finished request 1
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Accounting-Request packet from host 192.168.99.1:1646, id=2, length=323
Acct-Session-Id = "000023CA"
Cisco-AVPair = "client-mac-address=0014.2a41.3dd1"
Framed-Protocol = PPP
Framed-IP-Address = 192.168.222.222
User-Name = "gsv123"
Acct-Authentic = RADIUS
Cisco-AVPair = "connect-progress=LAN Ses Up"
Cisco-AVPair = "nas-tx-speed=950000"
Cisco-AVPair = "nas-rx-speed=950000"
Acct-Session-Time = 194
Acct-Input-Octets = 2069
Acct-Output-Octets = 646
Acct-Input-Packets = 53
Acct-Output-Packets = 45
Acct-Terminate-Cause = User-Request
Cisco-AVPair = "disc-cause-ext=PPP Receive Term"
Acct-Status-Type = Stop
NAS-Port-Type = Virtual
Cisco-NAS-Port = "0/0/1/33"
NAS-Port = 0
NAS-Port-Id = "0/0/1/33"
Service-Type = Framed-User
NAS-IP-Address = 192.168.99.1
Acct-Delay-Time = 5
Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 2
modcall[preacct]: module "preprocess" returns noop for request 2
rlm_acct_unique: Hashing 'NAS-Port = 0,Client-IP-Address = 192.168.99.1,NAS-IP-Address = 192.168.99.1,Acct-Session-Id = "000023CA",User-Name = "gsv123"'
rlm_acct_unique: Acct-Unique-Session-ID = "42cd7dcfe62ebb17".
modcall[preacct]: module "acct_unique" returns ok for request 2
rlm_realm: No '@' in User-Name = "gsv123", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[preacct]: module "suffix" returns noop for request 2
modcall: leaving group preacct (returns ok) for request 2
Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 2
radius_xlat: '/var/log/radacct/192.168.99.1/detail-20070814'
rlm_detail: /var/log/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radacct/192.168.99.1/detail-20070814
modcall[accounting]: module "detail" returns ok for request 2
modcall[accounting]: module "unix" returns fail for request 2
modcall: leaving group accounting (returns fail) for request 2
Finished request 2
Going to the next request
--- Walking the entire request list ---
Cleaning up request 1 ID 254 with timestamp 46c1a486
Waking up in 6 seconds...
т.е. даже нет попытки выполнить какой-то sql запрос...
А может быть радиус не понимает, что пришел stop пакет?
Есть какие-то соображения?