Not processing accounting packet
Tyller D
tyllerd at gmail.com
Wed May 1 10:10:28 CEST 2013
Hi All,
I'm having a problem that I can't find a solution to.
The process I'm using is as follows. User connects to landing page, landing
page sends access-request to server with users details. FreeRADIUS then
sends a COA to the NAS to change the state and apply attributes. However
when FreeRADIUS gets the accounting-start packet, it does nothing with it.
Can someone please tell me how I can log this normally in radacct table? In
my accounting section i have accounting { sql }
sql_xlat finished
rlm_sql (sql): Released sql socket id: 4
expand: %{sql:SELECT IFNULL((SELECT IF(ims.vouchers.`data`= 0,
0,IF((ims.vouchers.`data` -
(SUM(radius.radacct.acctinputoctets)+SUM(radius.radacct.acctoutputoctets)))
< 0,-1, ims.vouchers.`data` -
(SUM(radius.radacct.acctinputoctets)+SUM(radius.radacct.acctoutputoctets))))
AS voucherdata FROM radius.radacct,ims.vouchers WHERE
radius.radacct.username='%{request:User-Name}' AND radius.radacct.username
= ims.vouchers.voucher AND radius.radacct.acctterminatecause<>'Hotspot
Restart'),(SELECT ims.vouchers.`data` FROM ims.vouchers WHERE
ims.vouchers.voucher='%{request:User-Name}')) as voucherdata} -> 1048576
++[control] returns noop
sql_xlat
expand: %{User-Name} -> 10269783
sql_set_user escaped user --> '10269783'
expand: SELECT IFNULL((SELECT IF(ims.user_account.`data`= 0,
0,IF((ims.user_account.`data` -
(SUM(radius.radacct.acctinputoctets)+SUM(radius.radacct.acctoutputoctets)))
< 0,-1, ims.user_account.`data` -
(SUM(radius.radacct.acctinputoctets)+SUM(radius.radacct.acctoutputoctets))))
AS voucherdata FROM radius.radacct,ims.user_account WHERE
radius.radacct.username='%{request:User-Name}' AND radius.radacct.username
= ims.user_account.username AND radius.radacct.acctterminatecause<>'Hotspot
Restart'),(SELECT ims.user_account.`data` FROM ims.user_account WHERE
ims.user_account.username='%{request:User-Name}')) as voucherdata -> SELECT
IFNULL((SELECT IF(ims.user_account.`data`= 0, 0,IF((ims.user_account.`data`
-
(SUM(radius.radacct.acctinputoctets)+SUM(radius.radacct.acctoutputoctets)))
< 0,-1, ims.user_account.`data` -
(SUM(radius.radacct.acctinputoctets)+SUM(radius.radacct.acctoutputoctets))))
AS voucherdata FROM radius.radacct,ims.user_account WHERE
radius.radacct.username='10269783' AND radius.radacct.username =
rlm_sql (sql): Reserving sql socket id: 3
row[0] returned NULL
rlm_sql (sql): Released sql socket id: 3
expand: %{sql:SELECT IFNULL((SELECT IF(ims.user_account.`data`= 0,
0,IF((ims.user_account.`data` -
(SUM(radius.radacct.acctinputoctets)+SUM(radius.radacct.acctoutputoctets)))
< 0,-1, ims.user_account.`data` -
(SUM(radius.radacct.acctinputoctets)+SUM(radius.radacct.acctoutputoctets))))
AS voucherdata FROM radius.radacct,ims.user_account WHERE
radius.radacct.username='%{request:User-Name}' AND radius.radacct.username
= ims.user_account.username AND radius.radacct.acctterminatecause<>'Hotspot
Restart'),(SELECT ims.user_account.`data` FROM ims.user_account WHERE
ims.user_account.username='%{request:User-Name}')) as voucherdata} ->
++[control] returns noop
++? if (control:IMS-ActiveDirectory == 0)
? Evaluating (control:IMS-ActiveDirectory == 0) -> FALSE
++? if (control:IMS-ActiveDirectory == 0) -> FALSE
++? if (control:IMS-Timeout < 0)
? Evaluating (control:IMS-Timeout < 0) -> FALSE
++? if (control:IMS-Timeout < 0) -> FALSE
++? elsif (control:IMS-Timeout > 0)
? Evaluating (control:IMS-Timeout > 0) -> FALSE
++? elsif (control:IMS-Timeout > 0) -> FALSE
++? if (control:IMS-Data < 0)
? Evaluating (control:IMS-Data < 0) -> FALSE
++? if (control:IMS-Data < 0) -> FALSE
++? if (control:IMS-Data > 0)
? Evaluating (control:IMS-Data > 0) -> TRUE
++? if (control:IMS-Data > 0) -> TRUE
++- entering if (control:IMS-Data > 0) {...}
expand: %{control:IMS-Data} -> 1048576
+++[reply] returns noop
++- if (control:IMS-Data > 0) returns noop
++? if (control:IMS-UserData < 0)
? Evaluating (control:IMS-UserData < 0) -> FALSE
++? if (control:IMS-UserData < 0) -> FALSE
++? if (control:IMS-UserData > 0)
? Evaluating (control:IMS-UserData > 0) -> FALSE
++? if (control:IMS-UserData > 0) -> FALSE
++[reply] returns noop
} # server ims
Sending Access-Accept of id 79 to 127.0.0.1 port 51340
Trapeze-Qos-Profile = "MB100"
Mikrotik-Total-Limit = 1048576
Acct-Interim-Interval = 120
# Executing section pre-proxy from file /etc/freeradius/sites-enabled/ims
+- entering group pre-proxy {...}
[detail] expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d ->
/var/log/freeradius/radacct/127.0.0.1/detail-20130501
[detail] /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d
expands to /var/log/freeradius/radacct/127.0.0.1/detail-20130501
[detail] expand: %t -> Wed May 1 09:58:20 2013
++[detail] returns ok
Sending CoA-Request of id 91 to 172.16.255.35 port 3799
Calling-Station-Id = "04:54:53:85:ca:82"
NAS-IP-Address = 172.16.255.35
Trapeze-COA-Replace-Username = "10269783"
Filter-Id = "MB100"
Finished request 3.
Going to the next request
Waking up in 2.4 seconds.
rad_recv: CoA-ACK packet from host 172.16.255.35 port 3799, id=91, length=26
Event-Timestamp = "May 1 2013 09:58:34 SAST"
# Executing section post-proxy from file /etc/freeradius/sites-enabled/ims
+- entering group post-proxy {...}
[detail] expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d ->
/var/log/freeradius/radacct/127.0.0.1/detail-20130501
[detail] /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d
expands to /var/log/freeradius/radacct/127.0.0.1/detail-20130501
[detail] expand: %t -> Wed May 1 09:58:20 2013
++[detail] returns ok
server ims {
} # server ims
Finished request 3.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Accounting-Request packet from host 172.16.255.35 port 20000,
id=200, length=244
Acct-Status-Type = Start
Acct-Multi-Session-Id = "SESS-464-72c952-395089-4201e"
Acct-Session-Id = "SESS-464-72c952-395089-4201e"
User-Name = "10269783"
Event-Timestamp = "May 1 2013 09:58:34 SAST"
Trapeze-VLAN-Name = "DataA"
Calling-Station-Id = "04-54-53-85-CA-82"
NAS-Port-Id = "AP13/2"
Called-Station-Id = "AC-4B-C8-02-23-41:BTC HOTSPOT - FAIRGROUND"
Trapeze-Attr-19 = 0x69706164
Trapeze-Attr-21 = 0x696f73
NAS-Port = 464
Framed-IP-Address = 172.16.100.18
NAS-Port-Type = Wireless-802.11
NAS-IP-Address = 172.16.255.35
NAS-Identifier = "XON"
Acct-Delay-Time = 0
WARNING: Empty preacct section. Using default return values.
WARNING: Empty accounting section. Using default return values.
Finished request 4.
Cleaning up request 4 ID 200 with timestamp +47
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 3 ID 79 with timestamp +47
rad_recv: Accounting-Request packet from host 172.16.255.35 port 20000,
id=201, length=244
Acct-Status-Type = Start
Acct-Multi-Session-Id = "SESS-464-72c952-395089-4201e"
Acct-Session-Id = "SESS-464-72c952-395089-4201e"
User-Name = "10269783"
Event-Timestamp = "May 1 2013 09:58:34 SAST"
Trapeze-VLAN-Name = "DataA"
Calling-Station-Id = "04-54-53-85-CA-82"
NAS-Port-Id = "AP13/2"
Called-Station-Id = "AC-4B-C8-02-23-41:BTC HOTSPOT - FAIRGROUND"
Trapeze-Attr-19 = 0x69706164
Trapeze-Attr-21 = 0x696f73
NAS-Port = 464
Framed-IP-Address = 172.16.100.18
NAS-Port-Type = Wireless-802.11
NAS-IP-Address = 172.16.255.35
NAS-Identifier = "XON"
Acct-Delay-Time = 5
WARNING: Empty preacct section. Using default return values.
WARNING: Empty accounting section. Using default return values.
Finished request 5.
Cleaning up request 5 ID 201 with timestamp +52
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 172.16.255.35 port 20000,
id=202, length=244
Acct-Status-Type = Start
Acct-Multi-Session-Id = "SESS-464-72c952-395089-4201e"
Acct-Session-Id = "SESS-464-72c952-395089-4201e"
User-Name = "10269783"
Event-Timestamp = "May 1 2013 09:58:34 SAST"
Trapeze-VLAN-Name = "DataA"
Calling-Station-Id = "04-54-53-85-CA-82"
NAS-Port-Id = "AP13/2"
Called-Station-Id = "AC-4B-C8-02-23-41:BTC HOTSPOT - FAIRGROUND"
Trapeze-Attr-19 = 0x69706164
Trapeze-Attr-21 = 0x696f73
NAS-Port = 464
Framed-IP-Address = 172.16.100.18
NAS-Port-Type = Wireless-802.11
NAS-IP-Address = 172.16.255.35
NAS-Identifier = "XON"
Acct-Delay-Time = 10
WARNING: Empty preacct section. Using default return values.
WARNING: Empty accounting section. Using default return values.
Finished request 6.
Cleaning up request 6 ID 202 with timestamp +57
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 172.16.255.35 port 20000,
id=203, length=274
Acct-Status-Type = Stop
Acct-Multi-Session-Id = "SESS-464-72c952-395089-4201e"
Acct-Session-Id = "SESS-464-72c952-395089-4201e"
User-Name = "10269783"
Event-Timestamp = "May 1 2013 10:03:16 SAST"
Trapeze-VLAN-Name = "DataA"
Calling-Station-Id = "04-54-53-85-CA-82"
NAS-Port-Id = "AP13/2"
Called-Station-Id = "AC-4B-C8-02-23-41:BTC HOTSPOT - FAIRGROUND"
Trapeze-Attr-19 = 0x69706164
Trapeze-Attr-21 = 0x696f73
NAS-Port = 464
Framed-IP-Address = 172.16.100.18
NAS-Identifier = "XON"
Acct-Session-Time = 282
Acct-Output-Octets = 58993
Acct-Input-Octets = 35737
Acct-Output-Packets = 177
Acct-Input-Packets = 393
NAS-Port-Type = Wireless-802.11
NAS-IP-Address = 172.16.255.35
Acct-Delay-Time = 0
WARNING: Empty preacct section. Using default return values.
WARNING: Empty accounting section. Using default return values.
Finished request 7.
Cleaning up request 7 ID 203 with timestamp +329
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 172.16.255.35 port 20000,
id=204, length=274
Acct-Status-Type = Stop
Acct-Multi-Session-Id = "SESS-464-72c952-395089-4201e"
Acct-Session-Id = "SESS-464-72c952-395089-4201e"
User-Name = "10269783"
Event-Timestamp = "May 1 2013 10:03:16 SAST"
Trapeze-VLAN-Name = "DataA"
Calling-Station-Id = "04-54-53-85-CA-82"
NAS-Port-Id = "AP13/2"
Called-Station-Id = "AC-4B-C8-02-23-41:BTC HOTSPOT - FAIRGROUND"
Trapeze-Attr-19 = 0x69706164
Trapeze-Attr-21 = 0x696f73
NAS-Port = 464
Framed-IP-Address = 172.16.100.18
NAS-Identifier = "XON"
Acct-Session-Time = 282
Acct-Output-Octets = 58993
Acct-Input-Octets = 35737
Acct-Output-Packets = 177
Acct-Input-Packets = 393
NAS-Port-Type = Wireless-802.11
NAS-IP-Address = 172.16.255.35
Acct-Delay-Time = 5
WARNING: Empty preacct section. Using default return values.
WARNING: Empty accounting section. Using default return values.
Finished request 8.
Cleaning up request 8 ID 204 with timestamp +334
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 172.16.255.35 port 20000,
id=205, length=274
Acct-Status-Type = Stop
Acct-Multi-Session-Id = "SESS-464-72c952-395089-4201e"
Acct-Session-Id = "SESS-464-72c952-395089-4201e"
User-Name = "10269783"
Event-Timestamp = "May 1 2013 10:03:16 SAST"
Trapeze-VLAN-Name = "DataA"
Calling-Station-Id = "04-54-53-85-CA-82"
NAS-Port-Id = "AP13/2"
Called-Station-Id = "AC-4B-C8-02-23-41:BTC HOTSPOT - FAIRGROUND"
Trapeze-Attr-19 = 0x69706164
Trapeze-Attr-21 = 0x696f73
NAS-Port = 464
Framed-IP-Address = 172.16.100.18
NAS-Identifier = "XON"
Acct-Session-Time = 282
Acct-Output-Octets = 58993
Acct-Input-Octets = 35737
Acct-Output-Packets = 177
Acct-Input-Packets = 393
NAS-Port-Type = Wireless-802.11
NAS-IP-Address = 172.16.255.35
Acct-Delay-Time = 10
WARNING: Empty preacct section. Using default return values.
WARNING: Empty accounting section. Using default return values.
Finished request 9.
Cleaning up request 9 ID 205 with timestamp +339
Going to the next request
Ready to process requests.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20130501/3d694b99/attachment-0001.html>
More information about the Freeradius-Users
mailing list