bizarre VMPS behaviour - different mac's being displayed - same switch, same client, different version of Freeradius

Keith Olsen keith.r.olsen at gmail.com
Thu Jan 15 06:39:09 CET 2015


HI Arran, 

I had a quick look in the pcap in wireshark but could not see any obvious issues, I was looking for the erroneous mac addresses, but could not see where the parsing is going wrong. The correct mac  (00:25:bc:e1:5b:4a) is there.

I have attached the pcap and here is the output from radius -X for the transactions,

Ready to process requests
	VMPS-Packet-Type = VMPS-Join-Request
	VMPS-Error-Code = VMPS-No-Error
	VMPS-Sequence-Number = 145
	VMPS-Client-IP-Address = 192.168.30.11
	VMPS-Port-Name = 'Fa0/11'
	VMPS-VLAN-Name = '--NONE--'
	VMPS-Domain-Name = 'seccom.ab.ca'
	VMPS-Unknown = 0x00
	VMPS-MAC = f0:45:75:08:97:7f
(1) Received Access-Request packet from host 192.168.30.11 port 53489, id=145, length=81
(1) 	VMPS-Packet-Type = VMPS-Join-Request
(1) 	VMPS-Error-Code = VMPS-No-Error
(1) 	VMPS-Sequence-Number = 145
(1) 	VMPS-Client-IP-Address = 192.168.30.11
(1) 	VMPS-Port-Name = 'Fa0/11'
(1) 	VMPS-VLAN-Name = '--NONE--'
(1) 	VMPS-Domain-Name = 'seccom.ab.ca'
(1) 	VMPS-Unknown = 0x00
(1) 	VMPS-MAC = f0:45:75:08:97:7f
Doing VMPS
(1)   vmps {
(1)    if (!VMPS-Mac)
(1)    if (!VMPS-Mac)  -> FALSE
(1)   update reply {
(1) 	VMPS-Packet-Type = VMPS-Join-Response
(1) EXPAND %{VMPS-Mac}
(1)    --> f0:45:75:08:97:7f
(1) 	VMPS-Cookie = f0:45:75:08:97:7f
(1) 	VMPS-VLAN-Name = 'default'
(1) EXPAND %{User-Name}
(1)    -->
(1) SQL-User-Name set to ''
rlm_sql (sql): Reserved connection (4)
rlm_sql (sql): Executing query: 'SELECT vlan FROM mac2vlan WHERE mac='f0:45:75:08:97:7f''
(1) SQL query returned no results
rlm_sql (sql): Released connection (4)
rlm_sql (sql): Closing connection (0), from 1 unused connections
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 187 seconds
rlm_sql (sql): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): Closing connection (2): Hit idle_timeout, was idle for 187 seconds
rlm_sql (sql): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): Closing connection (1): Hit idle_timeout, was idle for 187 seconds
rlm_sql (sql): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
(1) EXPAND %{sql:SELECT vlan FROM mac2vlan WHERE mac='%{VMPS-Mac}'}
(1)    -->
(1) 	VMPS-VLAN-Name = ""
(1)   } # update reply = noop
(1)    if (VMPS-Packet-Type == VMPS-Reconfirm-Request)
(1)    if (VMPS-Packet-Type == VMPS-Reconfirm-Request) -> FALSE
(1)  linelog : EXPAND messages.%{%{Packet-Type}:-default}
(1)  linelog :    --> messages.Access-Request
(1)  linelog : EXPAND /var/log/radius/linelog
(1)  linelog :    --> /var/log/radius/linelog
(1)  linelog : EXPAND Requested access: %{User-Name}
(1)  linelog :    --> Requested access:
(1)   [linelog] = ok
(1)  } #  vmps = ok
Done VMPS
(1)   vmps {
(1)    if (!VMPS-Mac)
(1)    if (!VMPS-Mac)  -> FALSE
(1)   update reply {
(1) 	VMPS-Packet-Type = VMPS-Join-Response
(1) EXPAND %{VMPS-Mac}
(1)    --> f0:45:75:08:97:7f
(1) 	VMPS-Cookie = f0:45:75:08:97:7f
(1) 	VMPS-VLAN-Name = 'default'
(1) EXPAND %{User-Name}
(1)    -->
(1) SQL-User-Name set to ''
rlm_sql (sql): Reserved connection (4)
rlm_sql (sql): Executing query: 'SELECT vlan FROM mac2vlan WHERE mac='f0:45:75:08:97:7f''
(1) SQL query returned no results
rlm_sql (sql): Released connection (4)
(1) EXPAND %{sql:SELECT vlan FROM mac2vlan WHERE mac='%{VMPS-Mac}'}
(1)    -->
(1) 	VMPS-VLAN-Name = ""
(1)   } # update reply = noop
(1)    if (VMPS-Packet-Type == VMPS-Reconfirm-Request)
(1)    if (VMPS-Packet-Type == VMPS-Reconfirm-Request) -> FALSE
(1)  linelog : EXPAND messages.%{%{Packet-Type}:-default}
(1)  linelog :    --> messages.Access-Request
(1)  linelog : EXPAND /var/log/radius/linelog
(1)  linelog :    --> /var/log/radius/linelog
(1)  linelog : EXPAND Requested access: %{User-Name}
(1)  linelog :    --> Requested access:
(1)   [linelog] = ok
(1)  } #  vmps = ok
(1) Sending Access-Accept packet to host 192.168.30.11 port 53489, id=145, length=0
(1) 	VMPS-Packet-Type = VMPS-Join-Response
(1) 	VMPS-Cookie = f0:45:75:08:97:7f
(1) 	VMPS-VLAN-Name = 'default'
	VMPS-VLAN-Name = 'default'
	VMPS-Cookie = f0:45:75:08:97:7f
(1) Finished request
Waking up in 0.3 seconds.
Waking up in 4.6 seconds.
(1) Cleaning up request packet ID 145 with timestamp +187
Ready to process requests
	VMPS-Packet-Type = VMPS-Join-Request
	VMPS-Error-Code = VMPS-No-Error
	VMPS-Sequence-Number = 161
	VMPS-Client-IP-Address = 192.168.30.11
	VMPS-Port-Name = 'Fa0/19'
	VMPS-VLAN-Name = '--NONE--'
	VMPS-Domain-Name = 'seccom.ab.ca'
	VMPS-Unknown = 0x00
	VMPS-MAC = 20:4c:75:08:97:7f
(2) Received Access-Request packet from host 192.168.30.11 port 53489, id=161, length=81
(2) 	VMPS-Packet-Type = VMPS-Join-Request
(2) 	VMPS-Error-Code = VMPS-No-Error
(2) 	VMPS-Sequence-Number = 161
(2) 	VMPS-Client-IP-Address = 192.168.30.11
(2) 	VMPS-Port-Name = 'Fa0/19'
(2) 	VMPS-VLAN-Name = '--NONE--'
(2) 	VMPS-Domain-Name = 'seccom.ab.ca'
(2) 	VMPS-Unknown = 0x00
(2) 	VMPS-MAC = 20:4c:75:08:97:7f
Doing VMPS
(2)   vmps {
(2)    if (!VMPS-Mac)
(2)    if (!VMPS-Mac)  -> FALSE
(2)   update reply {
(2) 	VMPS-Packet-Type = VMPS-Join-Response
(2) EXPAND %{VMPS-Mac}
(2)    --> 20:4c:75:08:97:7f
(2) 	VMPS-Cookie = 20:4c:75:08:97:7f
(2) 	VMPS-VLAN-Name = 'default'
(2) EXPAND %{User-Name}
(2)    -->
(2) SQL-User-Name set to ''
rlm_sql (sql): Reserved connection (4)
rlm_sql (sql): Executing query: 'SELECT vlan FROM mac2vlan WHERE mac='20:4c:75:08:97:7f''
(2) SQL query returned no results
rlm_sql (sql): Released connection (4)
rlm_sql (sql): 0 of 1 connections in use.  Need more spares
rlm_sql (sql): Opening additional connection (5)
rlm_sql_mysql: Starting connect to MySQL server
(2) EXPAND %{sql:SELECT vlan FROM mac2vlan WHERE mac='%{VMPS-Mac}'}
(2)    -->
(2) 	VMPS-VLAN-Name = ""
(2)   } # update reply = noop
(2)    if (VMPS-Packet-Type == VMPS-Reconfirm-Request)
(2)    if (VMPS-Packet-Type == VMPS-Reconfirm-Request) -> FALSE
(2)  linelog : EXPAND messages.%{%{Packet-Type}:-default}
(2)  linelog :    --> messages.Access-Request
(2)  linelog : EXPAND /var/log/radius/linelog
(2)  linelog :    --> /var/log/radius/linelog
(2)  linelog : EXPAND Requested access: %{User-Name}
(2)  linelog :    --> Requested access:
(2)   [linelog] = ok
(2)  } #  vmps = ok
Done VMPS
(2)   vmps {
(2)    if (!VMPS-Mac)
(2)    if (!VMPS-Mac)  -> FALSE
(2)   update reply {
(2) 	VMPS-Packet-Type = VMPS-Join-Response
(2) EXPAND %{VMPS-Mac}
(2)    --> 20:4c:75:08:97:7f
(2) 	VMPS-Cookie = 20:4c:75:08:97:7f
(2) 	VMPS-VLAN-Name = 'default'
(2) EXPAND %{User-Name}
(2)    -->
(2) SQL-User-Name set to ''
rlm_sql (sql): Reserved connection (5)
rlm_sql (sql): Executing query: 'SELECT vlan FROM mac2vlan WHERE mac='20:4c:75:08:97:7f''
(2) SQL query returned no results
rlm_sql (sql): Released connection (5)
(2) EXPAND %{sql:SELECT vlan FROM mac2vlan WHERE mac='%{VMPS-Mac}'}
(2)    -->
(2) 	VMPS-VLAN-Name = ""
(2)   } # update reply = noop
(2)    if (VMPS-Packet-Type == VMPS-Reconfirm-Request)
(2)    if (VMPS-Packet-Type == VMPS-Reconfirm-Request) -> FALSE
(2)  linelog : EXPAND messages.%{%{Packet-Type}:-default}
(2)  linelog :    --> messages.Access-Request
(2)  linelog : EXPAND /var/log/radius/linelog
(2)  linelog :    --> /var/log/radius/linelog
(2)  linelog : EXPAND Requested access: %{User-Name}
(2)  linelog :    --> Requested access:
(2)   [linelog] = ok
(2)  } #  vmps = ok
(2) Sending Access-Accept packet to host 192.168.30.11 port 53489, id=161, length=0
(2) 	VMPS-Packet-Type = VMPS-Join-Response
(2) 	VMPS-Cookie = 20:4c:75:08:97:7f
(2) 	VMPS-VLAN-Name = 'default'
	VMPS-VLAN-Name = 'default'
	VMPS-Cookie = 20:4c:75:08:97:7f
(2) Finished request
Waking up in 0.3 seconds.
Waking up in 4.6 seconds.
(2) Cleaning up request packet ID 161 with timestamp +195
Ready to process requests
	VMPS-Packet-Type = VMPS-Join-Request
	VMPS-Error-Code = VMPS-No-Error
	VMPS-Sequence-Number = 177
	VMPS-Client-IP-Address = 192.168.30.11
	VMPS-Port-Name = 'Fa0/25'
	VMPS-VLAN-Name = '--NONE--'
	VMPS-Domain-Name = 'seccom.ab.ca'
	VMPS-Unknown = 0x00
	VMPS-MAC = 70:0f:72:08:97:7f
(3) Received Access-Request packet from host 192.168.30.11 port 53489, id=177, length=81
(3) 	VMPS-Packet-Type = VMPS-Join-Request
(3) 	VMPS-Error-Code = VMPS-No-Error
(3) 	VMPS-Sequence-Number = 177
(3) 	VMPS-Client-IP-Address = 192.168.30.11
(3) 	VMPS-Port-Name = 'Fa0/25'
(3) 	VMPS-VLAN-Name = '--NONE--'
(3) 	VMPS-Domain-Name = 'seccom.ab.ca'
(3) 	VMPS-Unknown = 0x00
(3) 	VMPS-MAC = 70:0f:72:08:97:7f
Doing VMPS
(3)   vmps {
(3)    if (!VMPS-Mac)
(3)    if (!VMPS-Mac)  -> FALSE
(3)   update reply {
(3) 	VMPS-Packet-Type = VMPS-Join-Response
(3) EXPAND %{VMPS-Mac}
(3)    --> 70:0f:72:08:97:7f
(3) 	VMPS-Cookie = 70:0f:72:08:97:7f
(3) 	VMPS-VLAN-Name = 'default'
(3) EXPAND %{User-Name}
(3)    -->
(3) SQL-User-Name set to ''
rlm_sql (sql): Reserved connection (5)
rlm_sql (sql): Executing query: 'SELECT vlan FROM mac2vlan WHERE mac='70:0f:72:08:97:7f''
(3) SQL query returned no results
rlm_sql (sql): Released connection (5)
rlm_sql (sql): 0 of 2 connections in use.  Need more spares
rlm_sql (sql): Opening additional connection (6)
rlm_sql_mysql: Starting connect to MySQL server
(3) EXPAND %{sql:SELECT vlan FROM mac2vlan WHERE mac='%{VMPS-Mac}'}
(3)    -->
(3) 	VMPS-VLAN-Name = ""
(3)   } # update reply = noop
(3)    if (VMPS-Packet-Type == VMPS-Reconfirm-Request)
(3)    if (VMPS-Packet-Type == VMPS-Reconfirm-Request) -> FALSE
(3)  linelog : EXPAND messages.%{%{Packet-Type}:-default}
(3)  linelog :    --> messages.Access-Request
(3)  linelog : EXPAND /var/log/radius/linelog
(3)  linelog :    --> /var/log/radius/linelog
(3)  linelog : EXPAND Requested access: %{User-Name}
(3)  linelog :    --> Requested access:
(3)   [linelog] = ok
(3)  } #  vmps = ok
Done VMPS
(3)   vmps {
(3)    if (!VMPS-Mac)
(3)    if (!VMPS-Mac)  -> FALSE
(3)   update reply {
(3) 	VMPS-Packet-Type = VMPS-Join-Response
(3) EXPAND %{VMPS-Mac}
(3)    --> 70:0f:72:08:97:7f
(3) 	VMPS-Cookie = 70:0f:72:08:97:7f
(3) 	VMPS-VLAN-Name = 'default'
(3) EXPAND %{User-Name}
(3)    -->
(3) SQL-User-Name set to ''
rlm_sql (sql): Reserved connection (6)
rlm_sql (sql): Executing query: 'SELECT vlan FROM mac2vlan WHERE mac='70:0f:72:08:97:7f''
(3) SQL query returned no results
rlm_sql (sql): Released connection (6)
(3) EXPAND %{sql:SELECT vlan FROM mac2vlan WHERE mac='%{VMPS-Mac}'}
(3)    -->
(3) 	VMPS-VLAN-Name = ""
(3)   } # update reply = noop
(3)    if (VMPS-Packet-Type == VMPS-Reconfirm-Request)
(3)    if (VMPS-Packet-Type == VMPS-Reconfirm-Request) -> FALSE
(3)  linelog : EXPAND messages.%{%{Packet-Type}:-default}
(3)  linelog :    --> messages.Access-Request
(3)  linelog : EXPAND /var/log/radius/linelog
(3)  linelog :    --> /var/log/radius/linelog
(3)  linelog : EXPAND Requested access: %{User-Name}
(3)  linelog :    --> Requested access:
(3)   [linelog] = ok
(3)  } #  vmps = ok
(3) Sending Access-Accept packet to host 192.168.30.11 port 53489, id=177, length=0
(3) 	VMPS-Packet-Type = VMPS-Join-Response
(3) 	VMPS-Cookie = 70:0f:72:08:97:7f
(3) 	VMPS-VLAN-Name = 'default'
	VMPS-VLAN-Name = 'default'
	VMPS-Cookie = 70:0f:72:08:97:7f
(3) Finished request
Waking up in 0.3 seconds.
Waking up in 4.6 seconds.
(3) Cleaning up request packet ID 177 with timestamp +203
Ready to process requests



-------------- next part --------------



On Jan 14, 2015, at 8:58 PM, Arran Cudbard-Bell <a.cudbardb at freeradius.org> wrote:

> 
>> On 15 Jan 2015, at 10:47, Keith Olsen <keith.r.olsen at gmail.com> wrote:
>> 
>> I just stood up Freeradius 3.0.4 on a Fedora system, and I have an older (2.1.12) one running on Ubuntu (doubt the OS makes any difference….)
>> 
>> On the 3x system, I am using mysql to provide the mac to vlan information, while on the 2x system it’s the mac2vlan flat file. 
> 
> Yeah, likely a parse issue. I don't think anyone's tested VMPS with v3.0.x, and we certainly have no internal tests.
> 
> PCAP would be useful so it can be replayed against the server locally.
> 
> -Arran
> 
> Arran Cudbard-Bell <a.cudbardb at freeradius.org>
> FreeRADIUS development team
> 
> FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
> 
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html



More information about the Freeradius-Users mailing list