Weird behaviour of sqlcounter / dailycounter

[Robert Senger]

Hi all,

tonight I've seen some weird behaviour during tests of sqlcounter
module. Please see the output below. 



The situation is that the station trying to connect is allowed a Max-
Daily-Session of 300 seconds. The counter is at 299, so sqlcounter
correctly sets Session-Timeout = 1, and the station is allowed access
for one second remaining...

However, this connection is terminated immediately by the Wifi AP
(running hostapd 2.due to Session-Timeout = 1. The counter never gets
increased, the station retries and is allowed access, and every 5
seconds or so this repeats and repeats and repeats... The logs get
flooded and there's useless load on the AP and freeradius. The station
(Linux machine with NetworkManager) stopped trying to connect after
half an hour or so...

This behaviour is reproduceable. Every time the station's Max-Daily-
Session value is reached and it get's kicked off by the AP, it get's
into this loop. The number of retries until the station finally is
giving up is significantly higher if more than one AP with the same
SSID is reachable (>30 minutes). This behaviour also occurs if the
"counter" module is used rather than the "sqlcounter" module. 

Freeradius version is 3.0.21, hostapd version is 2.10-8.

Did I configure something wrong, or what happens here? Thank you for
help!

Robert


freeradius -X output:

<...>
 
(3090) dailycounter: EXPAND %{User-Name}
(3090) dailycounter:    --> testtesttest
(3090) dailycounter: SQL-User-Name set to 'testtesttest' rlm_sql (sql): Reserved connection (297)
(3090) dailycounter: Executing select query: SELECT SUM(acctsessiontime - GREATEST((1685484000 - UNIX_TIMESTAMP(acctstarttime)), 0)) FROM radacct WHERE username = 'testtesttest' AND UNIX_TIMESTAMP(acctstarttime) + acctsessiontime > '1685484000'
rlm_sql (sql): Released connection (297)
(3090) dailycounter: EXPAND %{sql:SELECT SUM(acctsessiontime -GREATEST((1685484000 - UNIX_TIMESTAMP(acctstarttime)), 0)) FROM radacct WHERE username = '%{User-Name}' AND UNIX_TIMESTAMP(acctstarttime) + acctsessiontime > '1685484000'}
(3090) dailycounter:    --> 299
(3090) dailycounter: Allowing user, &control:Max-Daily-Session value (300) is greater than counter value (299)
(3090) dailycounter: Setting &reply:Session-Timeout value to 1
(3090)       [dailycounter] = ok
(3090)       [expiration] = noop

<...>

(2499) Login OK: [testtesttest] (from client pherkad_ipv6 port 1 cli A0-88-B4-B5-47-C0)
(2499) Sent Access-Accept Id 250 from [fd10:2842:f0d1:101::2]:1812 to [fd10:2842:f0d1:101:20d:b9ff:fe0d:c9c0]:56722 length 0
(2499)   MS-MPPE-Recv-Key = 0x5006b02549aab2d72a020f8a17a16052e8c967bf253791d93f8a904d72bc8ec8
(2499)   MS-MPPE-Send-Key = 0x98b138434cfd1cc09198086179c52dce065bde4d2634520098c6bf70e92aa0c2
(2499)   EAP-Message = 0x03a90004
(2499)   Message-Authenticator = 0x00000000000000000000000000000000
(2499)   User-Name = "testtesttest"
(2499)   Session-Timeout += 1
(2499)   Acct-Interim-Interval = 600

<...>





















-- 
Robert Senger