Wrong Vlan assignment by freeradius, threading issue?!

[Jan Zacharias]

Hi Folks,

I'm running into some very bad issue: when running freeradius in threaded mode
(default)
it's mixing up CONCURRENT requests resulting in a wrong vlan assignment.

Here are the logs of two clients (OSX and Ubuntu). The Ubuntu supplicant
(wpa-suppl.)
always fails the first login try, but this is normal.

This is with reauthentification interval of 10 seconds, so requests seem to
overlap:

Tue Sep  7 16:45:36 2010 : Auth: Login incorrect: [jan/<via Auth-Type = EAP>]
(from client swba1-00-test port 50037 cli 00-1C-25-A2-10-3C)
Tue Sep  7 16:45:38 2010 : Auth: Login OK: [jan/<via Auth-Type = mschap>] (from
client swba1-00-test port 0 via TLS tunnel)
Tue Sep  7 16:45:38 2010 : Auth: Login OK: [jan/<via Auth-Type = EAP>] (from
client swba1-00-test port 50037 cli 00-1C-25-A2-10-3C)
Tue Sep  7 16:45:39 2010 : Auth: Login OK: [jan/<via Auth-Type = mschap>] (from
client swba1-00-test port 0 via TLS tunnel)
Tue Sep  7 16:45:41 2010 : Auth: Login OK: [jan/<via Auth-Type = EAP>] (from
client swba1-00-test port 50039 cli 00-16-CB-AA-0F-CB)
Tue Sep  7 16:45:44 2010 : Error: Discarding duplicate request from client
swba1-00-test port 1645 - ID: 208 due to unfinished request 267
Tue Sep  7 16:45:53 2010 : Auth: Login incorrect: [jan/<via Auth-Type = EAP>]
(from client swba1-00-test port 50037 cli 00-1C-25-A2-10-3C)
Tue Sep  7 16:45:56 2010 : Auth: Login OK: [jan/<via Auth-Type = mschap>] (from
client swba1-00-test port 0 via TLS tunnel)
Tue Sep  7 16:45:56 2010 : Auth: Login OK: [jan/<via Auth-Type = EAP>] (from
client swba1-00-test port 50037 cli 00-1C-25-A2-10-3C)
Tue Sep  7 16:45:56 2010 : Auth: Login OK: [jan/<via Auth-Type = mschap>] (from
client swba1-00-test port 0 via TLS tunnel)
Tue Sep  7 16:45:59 2010 : Auth: Login OK: [jan/<via Auth-Type = EAP>] (from
client swba1-00-test port 50039 cli 00-16-CB-AA-0F-CB)
Tue Sep  7 16:46:01 2010 : Error: Discarding duplicate request from client
swba1-00-test port 1645 - ID: 232 due to unfinished request 291

Now let's check what Vlans got assigned (this is the vmps log, vmps gets only
this MAC via rad2vmps and looks up the vlan in a mysql db):

ALLOW: 00:16:cb:aa:0f:cb -> Management, switch swba1-00-test.sb.dfki.de
[172.16.0.24] port Gi0/39
ALLOW: 00:16:cb:aa:0f:cb -> Management, switch swba1-00-test.sb.dfki.de
[172.16.0.24] port Gi0/39
ALLOW: 00:16:cb:aa:0f:cb -> Management, switch swba1-00-test.sb.dfki.de
[172.16.0.24] port Gi0/39
ALLOW: 00:16:cb:aa:0f:cb -> Management, switch swba1-00-test.sb.dfki.de
[172.16.0.24] port Gi0/39

So freeradius takes the MAC of the OSX client and inserts it into the
request that is associated with the Ubuntu client - VERY BAD.

Now I only changed the reauthentification interval to 20 seconds, so the
requests do not overlap anymore for sure.

Tue Sep  7 16:46:50 2010 : Auth: Login incorrect: [jan/<via Auth-Type = EAP>]
(from client swba1-00-test port 50037 cli 00-1C-25-A2-10-3C)
Tue Sep  7 16:46:53 2010 : Auth: Login OK: [jan/<via Auth-Type = mschap>] (from
client swba1-00-test port 0 via TLS tunnel)
Tue Sep  7 16:46:53 2010 : Auth: Login OK: [jan/<via Auth-Type = EAP>] (from
client swba1-00-test port 50037 cli 00-1C-25-A2-10-3C)
Tue Sep  7 16:46:57 2010 : Auth: Login OK: [jan/<via Auth-Type = mschap>] (from
client swba1-00-test port 0 via TLS tunnel)
Tue Sep  7 16:46:57 2010 : Auth: Login OK: [jan/<via Auth-Type = EAP>] (from
client swba1-00-test port 50039 cli 00-16-CB-AA-0F-CB)
Tue Sep  7 16:47:17 2010 : Auth: Login incorrect: [jan/<via Auth-Type = EAP>]
(from client swba1-00-test port 50037 cli 00-1C-25-A2-10-3C)
Tue Sep  7 16:47:20 2010 : Auth: Login OK: [jan/<via Auth-Type = mschap>] (from
client swba1-00-test port 0 via TLS tunnel)
Tue Sep  7 16:47:20 2010 : Auth: Login OK: [jan/<via Auth-Type = EAP>] (from
client swba1-00-test port 50037 cli 00-1C-25-A2-10-3C)
Tue Sep  7 16:47:25 2010 : Auth: Login OK: [jan/<via Auth-Type = mschap>] (from
client swba1-00-test port 0 via TLS tunnel)
Tue Sep  7 16:47:25 2010 : Auth: Login OK: [jan/<via Auth-Type = EAP>] (from
client swba1-00-test port 50039 cli 00-16-CB-AA-0F-CB)

Vmps log:

ALLOW: 00:1c:25:a2:10:3c -> FBIB, switch swba1-00-test.sb.dfki.de [172.16.0.24]
port Gi0/37
ALLOW: 00:16:cb:aa:0f:cb -> Management, switch swba1-00-test.sb.dfki.de
[172.16.0.24] port Gi0/39
ALLOW: 00:1c:25:a2:10:3c -> FBIB, switch swba1-00-test.sb.dfki.de [172.16.0.24]
port Gi0/37
ALLOW: 00:16:cb:aa:0f:cb -> Management, switch swba1-00-test.sb.dfki.de
[172.16.0.24] port Gi0/39

The short reauthentification interval is just to simulate a few more clients for
stresstesting purposes.

Can anyone help? The operating system is FreeBSD 8.1-RELEASE i386 and always las
load averages of 0.00,  0.00,  0.00
Switch hardware is cisco WS-C3560G-48PS with firmware (12.2(53)SE2
C3560-IPSERVICESK9-M).

Best, Jan
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20100907/95128501/attachment.html>