FreeRADIUS 3.0.12 VMPS and logging twice?
Václav Ovsík
vaclav.ovsik at i.cz
Wed Jun 28 17:49:09 CEST 2017
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
More information about the Freeradius-Users
mailing list