"[sql] stop packet with zero session length" problem

[Brian Candler]

On 04/04/2017 06:25, Selahattin Cilek wrote:
> Sometimes, and for some reason that is unknown to me, when a user connects to a UAP NAS, he is immediately kicked out. We can see that in the accounting details log of the NAS:
>
> Tue Apr  4 08:02:36 2017
>      Acct-Session-Id = "58D911BB-00001F5D"
>      Acct-Status-Type = Start
>      Acct-Authentic = RADIUS
>      User-Name = "99481225842"
>      NAS-Identifier = "44d9e77a2de5"
>      NAS-Port = 0
>      Called-Station-Id = "46-D9-E7-7B-2D-E5:YEMEKHANE"
>      Calling-Station-Id = "28-ED-6A-30-55-5A"
>      NAS-Port-Type = Wireless-802.11
>      Connect-Info = "CONNECT 0Mbps 802.11b"
>      Class = 0x3939343831323235383432
>      NAS-IP-Address = 192.168.0.31
>      FreeRADIUS-Acct-Session-Start-Time = "Apr  4 2017 08:02:36 MSK"
>      Timestamp = 1491282156
>
> Tue Apr  4 08:02:36 2017
>      Acct-Session-Id = "58D911BB-00001F5D"
>      Acct-Status-Type = Stop
>      Acct-Authentic = RADIUS
>      User-Name = "99481225842"
>      NAS-Identifier = "44d9e77a2de5"
>      NAS-Port = 0
>      Called-Station-Id = "46-D9-E7-7B-2D-E5:YEMEKHANE"
>      Calling-Station-Id = "28-ED-6A-30-55-5A"
>      NAS-Port-Type = Wireless-802.11
>      Connect-Info = "CONNECT 0Mbps 802.11b"
>      Class = 0x3939343831323235383432
>      Acct-Session-Time = 0
>      Acct-Input-Packets = 11
>      Acct-Output-Packets = 12
>      Acct-Input-Octets = 1289
>      Acct-Output-Octets = 3415
>      Event-Timestamp = "Apr  4 2017 08:02:35 MSK"
>      Acct-Terminate-Cause = User-Request
>      NAS-IP-Address = 192.168.0.31
>      FreeRADIUS-Acct-Session-Start-Time = "Apr  4 2017 08:02:36 MSK"
>      Timestamp = 1491282156
>
>
> I believe this is ridiculous. How on earth could someone be connected to a WLAN for 0 seconds, right?

It's perfectly possible and reasonable. For example, say it were an 
authentication exchange which did not complete - it could be aborted 
either by the RADIUS server or the client. 11 or 12 packets sounds 
reasonable for that, and could certainly take less than 1 second.

The important thing is, *was* the user actually still on-line after this 
exchange? If they were not, then the RADIUS accounting Stop packet 
correctly reflects truth (that they were disconnected).  I would then 
expect to see the user try to re-auth, i.e. you'd see a new 
authentication exchange and new accounting Start packet a short time later.

> But because it refuses to accept the second packet, I end up with a suspended session.

What refuses the second packet? Your stored procedure, or FreeRADIUS?

If it's your stored procedure, then fix it.  If you think it's 
FreeRADIUS, then show the freeradius -X output where this occurs.

Regards,

Brian.

P.S. There definitely used to be some bugs in Unifi AP RADIUS accounting 
a few years ago - it got one pair of send/receive counters the wrong way 
round, and there was also a situation where the value was not 
initialized properly so it gave garbage.  But those problems came from a 
very old version of Hostapd, and I think they have picked up the fixes 
by now.