Hi, we are using FreeRADIUS VMPS server for a long time on Debian GNU/Linux. It works perfectly and my tiny modification to dist vmps site definition is line log. With FreeRADIUS 2.2.5 it worked fine. I did upgrade of first VMPS yesterday (Debian Stretch) and did a small mods to vmps for FreeRADIUS version 3.0.12. What I didn't know to do with is that vmps processing doubled or two-phase or something (every request is logged twice). Request sent from monitoring site using check_vmps nagios plugin with success: VMPS OK - Vlan: TPS, MAC Address: d4bed9681558, Status: ALLOW response is correct one packet (checked using tcpdump). The output of freeradius -X: FreeRADIUS Version 3.0.12 Copyright (C) 1999-2016 The FreeRADIUS server project and contributors There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE You may redistribute copies of FreeRADIUS under the terms of the GNU General Public License For more information about these matters, see the file named COPYRIGHT Starting - reading configuration files ... including dictionary file /usr/share/freeradius/dictionary including dictionary file /usr/share/freeradius/dictionary.dhcp including dictionary file /usr/share/freeradius/dictionary.vqp including dictionary file /etc/freeradius/3.0/dictionary including configuration file /etc/freeradius/3.0/radiusd.conf including configuration file /etc/freeradius/3.0/clients.conf including files in directory /etc/freeradius/3.0/mods-enabled/ including configuration file /etc/freeradius/3.0/mods-enabled/mac2vlan including configuration file /etc/freeradius/3.0/mods-enabled/linelog_vmps including files in directory /etc/freeradius/3.0/policy.d/ including configuration file /etc/freeradius/3.0/policy.d/control including configuration file /etc/freeradius/3.0/policy.d/canonicalization including configuration file /etc/freeradius/3.0/policy.d/eap including configuration file /etc/freeradius/3.0/policy.d/cui including configuration file /etc/freeradius/3.0/policy.d/dhcp including configuration file /etc/freeradius/3.0/policy.d/filter including configuration file /etc/freeradius/3.0/policy.d/accounting including configuration file /etc/freeradius/3.0/policy.d/abfab-tr including configuration file /etc/freeradius/3.0/policy.d/moonshot-targeted-ids including configuration file /etc/freeradius/3.0/policy.d/debug including configuration file /etc/freeradius/3.0/policy.d/operator-name including files in directory /etc/freeradius/3.0/sites-enabled/ including configuration file /etc/freeradius/3.0/sites-enabled/vmps main { security { user = "freerad" group = "freerad" allow_core_dumps = no } name = "freeradius" prefix = "/usr" localstatedir = "/var" logdir = "/var/log/freeradius" run_dir = "/var/run/freeradius" } main { name = "freeradius" prefix = "/usr" localstatedir = "/var" sbindir = "/usr/sbin" logdir = "/var/log/freeradius" run_dir = "/var/run/freeradius" libdir = "/usr/lib/freeradius" radacctdir = "/var/log/freeradius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 16384 pidfile = "/var/run/freeradius/freeradius.pid" checkrad = "/usr/sbin/checkrad" debug_level = 0 proxy_requests = no log { stripped_names = no auth = no auth_badpass = no auth_goodpass = no colourise = yes msg_denied = "You are already logged in - access denied" } resources { } security { max_attributes = 200 reject_delay = 1.000000 status_server = yes } } radiusd: #### Loading Realms and Home Servers #### radiusd: #### Loading Clients #### client localhost { ipaddr = 127.0.0.1 require_message_authenticator = no secret = <<< secret >>> nas_type = "other" proto = "*" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client localhost_ipv6 { ipv6addr = ::1 require_message_authenticator = no secret = <<< secret >>> limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } Debugger not attached radiusd: #### Instantiating modules #### modules { # Loaded module rlm_passwd # Loading module "mac2vlan" from file /etc/freeradius/3.0/mods-enabled/mac2vlan passwd mac2vlan { filename = "/etc/freeradius/3.0/mods-config/passwd/mac2vlan" format = "*VMPS-Mac:=VMPS-VLAN-Name" delimiter = "," ignore_nislike = yes ignore_empty = yes allow_multiple_keys = no hash_size = 100 } # Loaded module rlm_linelog # Loading module "linelog_vmps" from file /etc/freeradius/3.0/mods-enabled/linelog_vmps linelog linelog_vmps { filename = "/var/log/freeradius/vmps.log" escape_filenames = no syslog_severity = "info" permissions = 384 format = "%S %{VMPS-Client-IP-Address} %{VMPS-Port-Name} %{VMPS-Packet-Type} %{VMPS-Mac} -> %{reply:VMPS-VLAN-Name}" } instantiate { } # Instantiating module "mac2vlan" from file /etc/freeradius/3.0/mods-enabled/mac2vlan rlm_passwd: nfields: 2 keyfield 0(VMPS-Mac) listable: no # Instantiating module "linelog_vmps" from file /etc/freeradius/3.0/mods-enabled/linelog_vmps } # modules radiusd: #### Loading Virtual Servers #### server { # from file /etc/freeradius/3.0/radiusd.conf } # server server vmps { # from file /etc/freeradius/3.0/sites-enabled/vmps # Loading vmps {...} } # server vmps radiusd: #### Opening IP addresses and Ports #### listen { type = "vmps" ipaddr = 10.2.28.97 port = 1589 client cisco-switches { ipaddr = 192.168.0.0 netmask = 16 require_message_authenticator = no secret = <<< secret >>> limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client cisco-switches2 { ipaddr = 10.0.0.0 netmask = 11 require_message_authenticator = no secret = <<< secret >>> limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client monit { ipaddr = 192.168.30.80 netmask = 28 require_message_authenticator = no secret = <<< secret >>> limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client monit2 { ipaddr = 10.0.156.80 netmask = 29 require_message_authenticator = no secret = <<< secret >>> limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } } Listening on vmps address 10.2.28.97 port 1589 bound to server vmps Ready to process requests VMPS-Packet-Type = VMPS-Join-Request VMPS-Error-Code = VMPS-No-Error VMPS-Sequence-Number = 4660 VMPS-Client-IP-Address = 127.0.0.1 VMPS-Port-Name = "Fa0/1" VMPS-VLAN-Name = "" VMPS-Domain-Name = "" VMPS-Unknown = 0x00 VMPS-MAC = d4:be:d9:68:15:58 (0) Received Access-Request Id 4660 from 192.168.30.82:41160 to 10.2.28.97:1589 length 60 (0) VMPS-Packet-Type = VMPS-Join-Request (0) VMPS-Error-Code = VMPS-No-Error (0) VMPS-Sequence-Number = 4660 (0) VMPS-Client-IP-Address = 127.0.0.1 (0) VMPS-Port-Name = "Fa0/1" (0) VMPS-VLAN-Name = "" (0) VMPS-Domain-Name = "" (0) VMPS-Unknown = 0x00 (0) VMPS-MAC = d4:be:d9:68:15:58 Doing VMPS (0) vmps { (0) if (!&VMPS-Mac) { (0) if (!&VMPS-Mac) -> FALSE (0) mac2vlan: Added VMPS-VLAN-Name: 'TPS' to reply_items (0) [mac2vlan] = ok (0) update reply { (0) &VMPS-Packet-Type = VMPS-Join-Response (0) &VMPS-Cookie = &VMPS-Mac -> d4:be:d9:68:15:58 (0) &VMPS-VLAN-Name = "Guest" (0) } # update reply = noop (0) if (&VMPS-Packet-Type == VMPS-Reconfirm-Request){ (0) if (&VMPS-Packet-Type == VMPS-Reconfirm-Request) -> FALSE (0) linelog_vmps: EXPAND %S %{VMPS-Client-IP-Address} %{VMPS-Port-Name} %{VMPS-Packet-Type} %{VMPS-Mac} -> %{reply:VMPS-VLAN-Name} (0) linelog_vmps: --> 2017-06-28 17:21:53 127.0.0.1 Fa0/1 VMPS-Join-Request d4:be:d9:68:15:58 -> TPS (0) linelog_vmps: EXPAND /var/log/freeradius/vmps.log (0) linelog_vmps: --> /var/log/freeradius/vmps.log (0) [linelog_vmps] = ok (0) } # vmps = ok Done VMPS (0) vmps { (0) if (!&VMPS-Mac) { (0) if (!&VMPS-Mac) -> FALSE (0) mac2vlan: Added VMPS-VLAN-Name: 'TPS' to reply_items (0) [mac2vlan] = ok (0) update reply { (0) &VMPS-Packet-Type = VMPS-Join-Response (0) &VMPS-Cookie = &VMPS-Mac -> d4:be:d9:68:15:58 (0) &VMPS-VLAN-Name = "Guest" (0) } # update reply = noop (0) if (&VMPS-Packet-Type == VMPS-Reconfirm-Request){ (0) if (&VMPS-Packet-Type == VMPS-Reconfirm-Request) -> FALSE (0) linelog_vmps: EXPAND %S %{VMPS-Client-IP-Address} %{VMPS-Port-Name} %{VMPS-Packet-Type} %{VMPS-Mac} -> %{reply:VMPS-VLAN-Name} (0) linelog_vmps: --> 2017-06-28 17:21:53 127.0.0.1 Fa0/1 VMPS-Join-Request d4:be:d9:68:15:58 -> TPS (0) linelog_vmps: EXPAND /var/log/freeradius/vmps.log (0) linelog_vmps: --> /var/log/freeradius/vmps.log (0) [linelog_vmps] = ok (0) } # vmps = ok (0) Sent Access-Accept Id 4660 from 10.2.28.97:1589 to 192.168.30.82:41160 length 0 VMPS-VLAN-Name = "TPS" VMPS-Cookie = d4:be:d9:68:15:58 (0) Finished request (0) Cleaning up request packet ID 4660 with timestamp +3 Ready to process requests To distributed Debian configuration I did only * disabled proxy_requests in radiusd.conf * added to site-enabled vmps, removed default and inner-tunnel * removed all mods from mods-enabled and enable linelog-vmps and mac2vlan Any idea why there is second pass after 'Done VMPS'? Regards -- Zito