PostgreSQL accounting callingstationid field blank

[Stoycho Ganev]

Alan, thanks for the help. I understand it is a problem with the NAS not 
sending Calling-Station-Id in the Accounting-Request packet, but I was 
unable to make it do so.

I followed your advice and updated post-auth to include the following:

if(User-Name){
                 if("%{sql:UPDATE radacct set 
callingstationid='%{Calling-Station-Id}' WHERE UserName='%{User-Name}' 
and acctsessionid='%{Acct-Session-Id}' and AcctStopTime is NULL}"){
         }
}

It expands correctly, but affects 0 rows, because post-auth is executed 
before accounting and the row I'm trying to update in post-auth does not 
exist until it is INSERTed by accounting later (with an empty 
Calling-Station-Id field).

Could you help me with some further suggestions, please? Thanks!


--- DEBUG ---

......

Login OK: [cleaver] (from client mikrotik03 port 0 cli 
CC-FA-00-C6-4A-A6)
# Executing section post-auth from file 
/etc/freeradius/sites-enabled/default
+- entering group post-auth {...}
++? if (User-Name)
? Evaluating (User-Name) -> TRUE
++? if (User-Name) -> TRUE
++- entering if (User-Name) {...}
+++? if ("%{sql:UPDATE radacct set 
callingstationid='%{Calling-Station-Id}' WHERE UserName='%{User-Name}' 
and acctsessionid='%{Acct-Session-Id}' and AcctStopTime is NULL}")
sql_xlat
	expand: %{User-Name} -> cleaver
sql_set_user escaped user --> 'cleaver'
	expand: UPDATE radacct set callingstationid='%{Calling-Station-Id}' 
WHERE UserName='%{User-Name}' and acctsessionid='%{Acct-Session-Id}' and 
AcctStopTime is NULL -> UPDATE radacct set 
callingstationid='CC-FA-00-C6-4A-A6' WHERE UserName='cleaver' and 
acctsessionid='8200009a' and AcctStopTime is NULL
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 0
rlm_sql (sql): SQL query affected no rows
rlm_sql (sql): Released sql socket id: 4
	expand: %{sql:UPDATE radacct set 
callingstationid='%{Calling-Station-Id}' WHERE UserName='%{User-Name}' 
and acctsessionid='%{Acct-Session-Id}' and AcctStopTime is NULL} -> 0
? Evaluating ("%{sql:UPDATE radacct set 
callingstationid='%{Calling-Station-Id}' WHERE UserName='%{User-Name}' 
and acctsessionid='%{Acct-Session-Id}' and AcctStopTime is NULL}") -> 
FALSE
+++? if ("%{sql:UPDATE radacct set 
callingstationid='%{Calling-Station-Id}' WHERE UserName='%{User-Name}' 
and acctsessionid='%{Acct-Session-Id}' and AcctStopTime is NULL}") -> 
FALSE
++- if (User-Name) returns noop
Sending Access-Accept of id 38 to 192.168.13.4 port 41876
	Session-Timeout := 1800
	User-Name = "cleaver"
	MS-MPPE-Recv-Key = 
0x3475108df78cbe34afa52b064ab754e661ca85d1dccad4c48cdcf5bb9a621e88
	MS-MPPE-Send-Key = 
0xe528698a571c8a5e3406bc55f49d487c065ab6ecbd86c70a5f7bb0c8e639103b
	EAP-Message = 0x030c0004
	Message-Authenticator = 0x00000000000000000000000000000000
Finished request 12.
Going to the next request
Waking up in 4.6 seconds.
rad_recv: Accounting-Request packet from host 192.168.13.4 port 59174, 
id=39, length=153
	Service-Type = Framed-User
	NAS-Port-Id = "wlan1"
	NAS-Port-Type = Wireless-802.11
	User-Name = "cleaver"
	Acct-Session-Id = "8200009a"
	Acct-Multi-Session-Id = 
"D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-79"
	Acct-Authentic = RADIUS
	Acct-Status-Type = Start
	NAS-Identifier = "MikroTik"
	Acct-Delay-Time = 0
	NAS-IP-Address = 192.168.13.4
# Executing section preacct from file 
/etc/freeradius/sites-enabled/default
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port-Id = "wlan1",Client-IP-Address = 
192.168.13.4,NAS-IP-Address = 192.168.13.4,Acct-Session-Id = 
"8200009a",User-Name = "cleaver"'
[acct_unique] Acct-Unique-Session-ID = "af85b9caf30c3554".
++[acct_unique] returns ok
++[files] returns noop
# Executing section accounting from file 
/etc/freeradius/sites-enabled/default
+- entering group accounting {...}
[detail] 	expand: %{Packet-Src-IP-Address} -> 192.168.13.4
[detail] 	expand: 
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d 
-> /var/log/freeradius/radacct/192.168.13.4/detail-20140725
[detail] 
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d 
expands to /var/log/freeradius/radacct/192.168.13.4/detail-20140725
[detail] 	expand: %t -> Fri Jul 25 17:17:54 2014
++[detail] returns ok
[sql] 	expand: %{User-Name} -> cleaver
[sql] sql_set_user escaped user --> 'cleaver'
[sql] 	expand: %{NAS-Port} ->
[sql] 	... expanding second conditional
[sql] 	expand: %{Acct-Delay-Time} -> 0
[sql] 	expand: INSERT INTO radacct   (AcctSessionId, AcctUniqueId, 
UserName, Realm, NASIPAddress,    NASPortId, NASPortType, AcctStartTime, 
AcctAuthentic,   ConnectInfo_start, CalledStationId, CallingStationId, 
ServiceType,   FramedProtocol, FramedIPAddress, AcctStartDelay, 
XAscendSessionSvrKey)   VALUES('%{Acct-Session-Id}',   
'%{Acct-Unique-Session-Id}',   '%{SQL-User-Name}',   NULLIF('%{Realm}', 
''),   '%{NAS-IP-Address}',   %{%{NAS-Port}:-NULL},   
'%{NAS-Port-Type}',   ('%S'::timestamp - 
'%{%{Acct-Delay-Time}:-0}'::interval),   '%{Acct-Authentic}',   
'%{Connect-Info}',   '%{Called-Station-Id}',   '%{Calling-Station-Id}',  
  '%{Service-Type}',   '%{Framed-Protocol}',   
NULLIF('%{Framed-IP-Address}', '')::inet,   0,   
'%{X-Ascend-Session-Svr-Key}') -> INSERT INTO radacct   (AcctSessionId, 
AcctUniqueId, UserName, Realm, NASIPAddress,    NASPortId, NASPortType, 
AcctStartTime, AcctAuthentic,   ConnectInfo_start, CalledStationId, 
CallingStationId, ServiceType,   FramedProtocol, FramedIPAddress, 
AcctStartDelay,
rlm_sql (sql): Reserving sql socket id: 3
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 1
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok

......

--- DEBUG ---

On 25.07.2014 15:17, Alan DeKok wrote:

> Stoycho Ganev wrote:
> 
>> Everything works fine except that when accounting records are INSERTed 
>> in the radacct table, the callingstationid field is left blank instead 
>> of being populated with the MAC address of the calling station. This 
>> is rather strange, because the Calling-Station-Id is present in the 
>> Access-Request, and is the correct format (no wimax rubbish).
> 
> The point of the debug output is to READ IT. Honestly...
> 
> You're seeing a Calling-Station-Id in an Access-Request. That's nice.
> But you're not seeing the Calling-Station-Id in an Accounting-Request.
> And then blaming FreeRADIUS when the SQL insert doesn't contain the
> Calling-Station-Id.
> 
> Well... it doesn't exist in the accounting request. If you want it in
> the accounting request, go fix the NAS. The NAS is the one sending the
> packet. It's not sending Calling-Station-Id in the accounting packet.
> 
> Or, update the "post-auth" configuration to write the
> Calling-Station-Id to the accounting tables. From the debug log, all
> packets contain an Acct-Session-Id and Acct-Multi-Session-Id. So you
> can use those to track a unique session.
> 
> Alan DeKok.