- Freeradius-Users - lists.freeradius.org

Two issues with FR 3.1
by Chris Howley 25 Nov '16

25 Nov '16

Hi, I've noticed a couple of issues with FR 3.1 and I'm hoping someone can help me resolve them. Thanks, Chris 1. No output written to file using radmin listen { type = "control" listen { socket = "/var/run/radiusd/control/radiusd.sock" gid = "radiusd" mode = "rw" peercred = yes } } [XXXXXXXXX ~]# radmin -f /var/run/radiusd/control/radiusd.sock radmin version 3.1.0-dead (git #4870102), built on Sep 9 2016 at 15:42:04 - FreeRADIUS Server administration tool. Copyright (C) 2008-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 v2. radmin> debug file /var/log/radius/tmp/bob.log ERROR: Cannot direct debug logs to absolute path. radmin> show debug file radmin> debug condition '(User-Name == "bob")' radmin> show debug condition &User-Name == "bob" radmin> 2. No User-Name attribute in Access-Accept when using EAP-TLS PEAP. (12,1) } # remove_reply_message_if_eap (noop) (12,1) } # post-auth (ok) (12,1) Sent Access-Accept Id 30 from 129.11.76.149:1812 to 10.12.80.79:32769 via em1 length 0 (12,1) MS-MPPE-Recv-Key = 0x0026c6259b41b7d2a79beed337a42a4a719e6604cbfa3ea381d44c795ce9c900 (12,1) MS-MPPE-Send-Key = 0x993c8b2ac3b792c214ccbe8362cd277dde3f560c3f2eff38f0860408bf6daf43 (12,1) EAP-Message = 0x030c0004 (12,1) Message-Authenticator = 0x00000000000000000000000000000000 (12,1) Finished request

2 1

Freeradius 3.0.11 SQL Accounting
by Albert K 24 Nov '16

24 Nov '16

Hi, I have set up have running setup with the following features 1) WPA-Enterprise with PEAP MSChapv2. 2) Authenticate with Microsoft AD via winbindd 3) Authorize with Microsoft AD via LDAP Now I want to enable MySQL logging, I followed the setup as per the wiki but I only get table radpostauth populated. What I want is to see table radacct populated. I am monitoring the output from radiusd -X but three is no error to indicate any problems. What else am I missing here? Thank you. https://wiki.freeradius.org/guide/SQL-HOWTO-for-freeradius-3.x-on-Debian-Ub…

2 1

DHCP NAT (and Relay) and Static Addressing based on Option82/Circuit ID
by Martin Edge 24 Nov '16

24 Nov '16

Hi, I'm working through setting up FreeRADIUS to behave as a DHCP Server so that it can read and respond to DHCP Packets (including Option 82 info). I'm making progress - however I am facing a few roadblocks that I would like some guidance on if possible. *Packets forwarded from an internal network which are translated out to us and carry a DHCP-Relay-IP-Address* DHCP Requests that are being sent to us include a Relay-IP-Address - and implicitly the DHCP module seems to use this as an authority and attempts to return the packet to the Relay IP, not the source of the packet. I was able to comment out in the source (3.0.12) - "modules/proto_dhcp/dhcpd.c" on line 497 (where it sets a new destination IP address) - and the packet was returned to the originator. Obviously this is not the way I should be doing this - so any suggestions are welcome. *DHCP IP Addressing from SQLIPool* I have the radippool (via dhcp_sqlippool) process able to extract an IP address based on the Circuit ID (Option 82) contained within the DHCP Packet. The challenge I have, is the IP addresses I am allocating (for the same provider, but we will also have multiple providers who use our system) - has different gateways based on the location of the service and the IP allocated. From what I can ascertain looking at the source code, the DHCP Pool functionality presently only deals with the returning of the Framed-IP-Address. Looking at "modules/rlm_sqlippool/rlm_sqlippool.c" (line 580) - there is an object called 'inst' with a property called framed_ip_address. This is used to build a 'vp' and adds it to the reply. How would one go about providing database driven gateway/dns settings? Is there a way? Or is the only option to add support for additional properties in the code for this? (I would need to isolate where the framed_ip_address is mapped to Framed-IP-Address to follow the similar behaviour. Hope you can help! Thanks Martin. Martin Edge Chief Technical Officer [Description: Description: Emersion Logo] Emersion saves you time and money, by providing an easy to use, secure and scalable billing, provisioning & operational support system delivered as a service in the cloud. Emersion Software Systems Pty Ltd Twitter: .......... @EmersionBilling ________________________________ This communication may contain CONFIDENTIAL or copyright information of Emersion Software Systems Pty Ltd (ABN 28 119 061 791). If you are not an intended recipient, you MUST NOT read, print, keep, forward, copy, use, save, retransmit or rely on this communication or any attachments, and any such action is unauthorised and prohibited. If you have received this communication in error, please reply to this e-mail to notify the sender of its incorrect delivery, and then delete both it and your reply. Emersion does not guarantee the integrity of any emails or any attached files. The views or opinions expressed are the author's own and may not reflect the views or opinions of Emersion. Thank you. ________________________________

4 6

Should I be worried about these error messages?
by Alex Sharaz 23 Nov '16

23 Nov '16

I'm seeing a fair number of error messages of the form Error: Couldn't open /var/cache/freeradius/tlscache/e60f73c400b6462028a381a46f584d59f25f392c59d217981221a60eba9b3345.vps for reading: No such file or directory on our 3.0.12 servers with eap caching enabled.Would you see this if the cache entry has expired or is it something else? Rgds Alex

2 1

json encoding (Freeradius 3.0.13)
by Fabrice Durand 23 Nov '16

23 Nov '16

Hi All, i am trying to implement cisco Device sensor (http://www.cisco.com/c/en/us/td/docs/switches/lan/catalyst3750/software/rel…) that allow to have endpoint data like DHCP, LLDP in the radius accounting packet. I am able to receive these specific attributes but when i want to send them to my api (PacketFence) through rlm_rest module , it looks that these attributes are not well encoded. You can see in the raddebug trace this attribute Cisco-AVPair = "dhcp-option=\0007\000\r\001\017\003\006,./\037!y\371\374+" received from the cisco switch which is encoded to that "dhcp-option=\u00007\u0000\r\u0001\u000F\u0003\u0006,.\/\u001F!y\uFFFFFFF9\uFFFFFFFC+" and i am not able to decode it. On my side i did some test with a perl json encoding code and the encoding string is suppose to be \\0007\\000\\r\\001\\017\\003\\006,.\/\\037!y\\371\\374+ Do i miss something in the Freeradius configuration in order to make it work ? Thanks, Regards Fabrice Here my raddebug trace: Tue Nov 22 15:19:40 2016 : Debug: (0) Received Accounting-Request Id 77 from 172.20.135.3:2940 to 172.20.135.1:1813 length 555 Tue Nov 22 15:19:40 2016 : Debug: (0) Cisco-AVPair = "dc-profile-name=HP-Device" Tue Nov 22 15:19:40 2016 : Debug: (0) Cisco-AVPair = "dc-device-name=MSFT 5.0" Tue Nov 22 15:19:40 2016 : Debug: (0) Cisco-AVPair = "dc-device-class-tag=HP-Device" Tue Nov 22 15:19:40 2016 : Debug: (0) Cisco-AVPair = "dc-certainty-metric=10" Tue Nov 22 15:19:40 2016 : Debug: (0) Cisco-AVPair = "dc-opaque=\000\000\000\002\000\000\000\000\000\000\000" Tue Nov 22 15:19:40 2016 : Debug: (0) Cisco-AVPair = "dc-protocol-map=9" Tue Nov 22 15:19:40 2016 : Debug: (0) Cisco-AVPair = "dhcp-option=\0007\000\r\001\017\003\006,./\037!y\371\374+" Tue Nov 22 15:19:40 2016 : Debug: (0) Cisco-AVPair = "dhcp-option=\000<\000\010MSFT 5.0" Tue Nov 22 15:19:40 2016 : Debug: (0) Cisco-AVPair = "dhcp-option=\000\014\000\tinverse-8" Tue Nov 22 15:19:40 2016 : Debug: (0) User-Name = "101f74b2f6a5" Tue Nov 22 15:19:40 2016 : Debug: (0) Cisco-AVPair = "audit-session-id=AC158904000001485B34CE42" Tue Nov 22 15:19:40 2016 : Debug: (0) Cisco-AVPair = "vlan-id=138" Tue Nov 22 15:19:40 2016 : Debug: (0) Cisco-AVPair = "method=mab" Tue Nov 22 15:19:40 2016 : Debug: (0) Called-Station-Id = "DC-A5-F4-34-55-08" Tue Nov 22 15:19:40 2016 : Debug: (0) Calling-Station-Id = "10-1F-74-B2-F6-A5" Tue Nov 22 15:19:40 2016 : Debug: (0) NAS-IP-Address = 172.20.135.77 Tue Nov 22 15:19:40 2016 : Debug: (0) NAS-Port-Id = "GigabitEthernet1/0/8" Tue Nov 22 15:19:40 2016 : Debug: (0) NAS-Port-Type = Ethernet Tue Nov 22 15:19:40 2016 : Debug: (0) NAS-Port = 50108 Tue Nov 22 15:19:40 2016 : Debug: (0) Acct-Session-Id = "000003B1" Tue Nov 22 15:19:40 2016 : Debug: (0) Acct-Terminate-Cause = Lost-Carrier Tue Nov 22 15:19:40 2016 : Debug: (0) Acct-Status-Type = Stop Tue Nov 22 15:19:40 2016 : Debug: (0) Event-Timestamp = "nov 22 2016 15:26:16 EST" Tue Nov 22 15:19:40 2016 : Debug: (0) Acct-Session-Time = 1133 Tue Nov 22 15:19:40 2016 : Debug: (0) Acct-Input-Octets = 97158148 Tue Nov 22 15:19:40 2016 : Debug: (0) Acct-Output-Octets = 166844207 Tue Nov 22 15:19:40 2016 : Debug: (0) Acct-Input-Packets = 744486 Tue Nov 22 15:19:40 2016 : Debug: (0) Acct-Output-Packets = 1682264 Tue Nov 22 15:19:40 2016 : Debug: (0) Acct-Delay-Time = 0 Tue Nov 22 15:19:40 2016 : Debug: (0) Proxy-State = 0x313339 Tue Nov 22 15:19:40 2016 : Debug: (0) # Executing section preacct from file raddb//sites-enabled/packetfence Tue Nov 22 15:19:40 2016 : Debug: (0) preacct { Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[preacct]: calling preprocess (rlm_preprocess) Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[preacct]: returned from preprocess (rlm_preprocess) Tue Nov 22 15:19:40 2016 : Debug: (0) [preprocess] = ok Tue Nov 22 15:19:40 2016 : Debug: (0) policy rewrite_called_station_id { Tue Nov 22 15:19:40 2016 : Debug: (0) if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { Tue Nov 22 15:19:40 2016 : Debug: (0) if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) -> TRUE Tue Nov 22 15:19:40 2016 : Debug: (0) if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { Tue Nov 22 15:19:40 2016 : Debug: (0) update request { Tue Nov 22 15:19:40 2016 : Debug: (0) &Called-Station-Id !* ANY Tue Nov 22 15:19:40 2016 : Debug: (0) EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} Tue Nov 22 15:19:40 2016 : Debug: (0) --> dc:a5:f4:34:55:08 Tue Nov 22 15:19:40 2016 : Debug: (0) &Called-Station-Id := dc:a5:f4:34:55:08 Tue Nov 22 15:19:40 2016 : Debug: (0) } # update request = noop Tue Nov 22 15:19:40 2016 : Debug: (0) if ("%{8}") { Tue Nov 22 15:19:40 2016 : Debug: (0) EXPAND %{8} Tue Nov 22 15:19:40 2016 : Debug: (0) --> Tue Nov 22 15:19:40 2016 : Debug: (0) if ("%{8}") -> FALSE Tue Nov 22 15:19:40 2016 : Debug: (0) elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) { Tue Nov 22 15:19:40 2016 : Debug: (0) elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE Tue Nov 22 15:19:40 2016 : Debug: (0) elsif (Aruba-Essid-Name) { Tue Nov 22 15:19:40 2016 : Debug: (0) elsif (Aruba-Essid-Name) -> FALSE Tue Nov 22 15:19:40 2016 : Debug: (0) elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) { Tue Nov 22 15:19:40 2016 : Debug: (0) EXPAND %{Cisco-AVPair} Tue Nov 22 15:19:40 2016 : Debug: (0) --> dc-profile-name=HP-Device Tue Nov 22 15:19:40 2016 : Debug: (0) elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[preacct]: calling updated (rlm_always) Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[preacct]: returned from updated (rlm_always) Tue Nov 22 15:19:40 2016 : Debug: (0) [updated] = updated Tue Nov 22 15:19:40 2016 : Debug: (0) } # if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) = updated Tue Nov 22 15:19:40 2016 : Debug: (0) ... skipping else: Preceding "if" was taken Tue Nov 22 15:19:40 2016 : Debug: (0) } # policy rewrite_called_station_id = updated Tue Nov 22 15:19:40 2016 : Debug: (0) policy acct_unique { Tue Nov 22 15:19:40 2016 : Debug: (0) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) { Tue Nov 22 15:19:40 2016 : Debug: (0) EXPAND %{string:Class} Tue Nov 22 15:19:40 2016 : Debug: (0) --> Tue Nov 22 15:19:40 2016 : Debug: (0) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE Tue Nov 22 15:19:40 2016 : Debug: (0) else { Tue Nov 22 15:19:40 2016 : Debug: (0) update request { Tue Nov 22 15:19:40 2016 : Debug: (0) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} Tue Nov 22 15:19:40 2016 : Debug: (0) --> ddbfe7a1d200b1fb1576b92057e0bcc6 Tue Nov 22 15:19:40 2016 : Debug: (0) &Acct-Unique-Session-Id := ddbfe7a1d200b1fb1576b92057e0bcc6 Tue Nov 22 15:19:40 2016 : Debug: (0) } # update request = noop Tue Nov 22 15:19:40 2016 : Debug: (0) } # else = noop Tue Nov 22 15:19:40 2016 : Debug: (0) } # policy acct_unique = noop Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[preacct]: calling suffix (rlm_realm) Tue Nov 22 15:19:40 2016 : Debug: (0) suffix: Checking for suffix after "@" Tue Nov 22 15:19:40 2016 : Debug: (0) suffix: No '@' in User-Name = "101f74b2f6a5", skipping NULL due to config. Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[preacct]: returned from suffix (rlm_realm) Tue Nov 22 15:19:40 2016 : Debug: (0) [suffix] = noop Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[preacct]: calling ntdomain (rlm_realm) Tue Nov 22 15:19:40 2016 : Debug: (0) ntdomain: Checking for prefix before "\" Tue Nov 22 15:19:40 2016 : Debug: (0) ntdomain: No '\' in User-Name = "101f74b2f6a5", looking up realm NULL Tue Nov 22 15:19:40 2016 : Debug: (0) ntdomain: Found realm "null" Tue Nov 22 15:19:40 2016 : Debug: (0) ntdomain: Adding Stripped-User-Name = "101f74b2f6a5" Tue Nov 22 15:19:40 2016 : Debug: (0) ntdomain: Adding Realm = "null" Tue Nov 22 15:19:40 2016 : Debug: (0) ntdomain: Accounting realm is LOCAL Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[preacct]: returned from ntdomain (rlm_realm) Tue Nov 22 15:19:40 2016 : Debug: (0) [ntdomain] = ok Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[preacct]: calling files (rlm_files) Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[preacct]: returned from files (rlm_files) Tue Nov 22 15:19:40 2016 : Debug: (0) [files] = noop Tue Nov 22 15:19:40 2016 : Debug: (0) } # preacct = updated Tue Nov 22 15:19:40 2016 : Debug: (0) # Executing section accounting from file raddb//sites-enabled/packetfence Tue Nov 22 15:19:40 2016 : Debug: (0) accounting { Tue Nov 22 15:19:40 2016 : Debug: (0) policy set_calling_station_id { Tue Nov 22 15:19:40 2016 : Debug: (0) if (&User-Name && (&User-Name =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { Tue Nov 22 15:19:40 2016 : Debug: (0) if (&User-Name && (&User-Name =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) -> TRUE Tue Nov 22 15:19:40 2016 : Debug: (0) if (&User-Name && (&User-Name =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { Tue Nov 22 15:19:40 2016 : Debug: (0) update request { Tue Nov 22 15:19:40 2016 : Debug: (0) EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} Tue Nov 22 15:19:40 2016 : Debug: (0) --> 10:1f:74:b2:f6:a5 Tue Nov 22 15:19:40 2016 : Debug: (0) &User-Name := 10:1f:74:b2:f6:a5 Tue Nov 22 15:19:40 2016 : Debug: (0) Overwriting value "101f74b2f6a5" with "10:1f:74:b2:f6:a5" Tue Nov 22 15:19:40 2016 : Debug: (0) EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} Tue Nov 22 15:19:40 2016 : Debug: (0) --> 10:1f:74:b2:f6:a5 Tue Nov 22 15:19:40 2016 : Debug: (0) &Calling-Station-Id = 10:1f:74:b2:f6:a5 Tue Nov 22 15:19:40 2016 : Debug: (0) Refusing to overwrite (use :=) Tue Nov 22 15:19:40 2016 : Debug: (0) } # update request = noop Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[accounting]: calling updated (rlm_always) Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[accounting]: returned from updated (rlm_always) Tue Nov 22 15:19:40 2016 : Debug: (0) [updated] = updated Tue Nov 22 15:19:40 2016 : Debug: (0) } # if (&User-Name && (&User-Name =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) = updated Tue Nov 22 15:19:40 2016 : Debug: (0) ... skipping else: Preceding "if" was taken Tue Nov 22 15:19:40 2016 : Debug: (0) } # policy set_calling_station_id = updated Tue Nov 22 15:19:40 2016 : Debug: (0) policy rewrite_calling_station_id { Tue Nov 22 15:19:40 2016 : Debug: (0) if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { Tue Nov 22 15:19:40 2016 : Debug: (0) if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) -> TRUE Tue Nov 22 15:19:40 2016 : Debug: (0) if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { Tue Nov 22 15:19:40 2016 : Debug: (0) update request { Tue Nov 22 15:19:40 2016 : Debug: (0) EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} Tue Nov 22 15:19:40 2016 : Debug: (0) --> 10:1f:74:b2:f6:a5 Tue Nov 22 15:19:40 2016 : Debug: (0) &Calling-Station-Id := 10:1f:74:b2:f6:a5 Tue Nov 22 15:19:40 2016 : Debug: (0) Overwriting value "10-1F-74-B2-F6-A5" with "10:1f:74:b2:f6:a5" Tue Nov 22 15:19:40 2016 : Debug: (0) } # update request = noop Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[accounting]: calling updated (rlm_always) Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[accounting]: returned from updated (rlm_always) Tue Nov 22 15:19:40 2016 : Debug: (0) [updated] = updated Tue Nov 22 15:19:40 2016 : Debug: (0) } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) = updated Tue Nov 22 15:19:40 2016 : Debug: (0) ... skipping else: Preceding "if" was taken Tue Nov 22 15:19:40 2016 : Debug: (0) } # policy rewrite_calling_station_id = updated Tue Nov 22 15:19:40 2016 : Debug: (0) policy rewrite_called_station_id { Tue Nov 22 15:19:40 2016 : Debug: (0) if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { Tue Nov 22 15:19:40 2016 : Debug: (0) if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) -> TRUE Tue Nov 22 15:19:40 2016 : Debug: (0) if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { Tue Nov 22 15:19:40 2016 : Debug: (0) update request { Tue Nov 22 15:19:40 2016 : Debug: (0) &Called-Station-Id !* ANY Tue Nov 22 15:19:40 2016 : Debug: (0) EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} Tue Nov 22 15:19:40 2016 : Debug: (0) --> dc:a5:f4:34:55:08 Tue Nov 22 15:19:40 2016 : Debug: (0) &Called-Station-Id := dc:a5:f4:34:55:08 Tue Nov 22 15:19:40 2016 : Debug: (0) } # update request = noop Tue Nov 22 15:19:40 2016 : Debug: (0) if ("%{8}") { Tue Nov 22 15:19:40 2016 : Debug: (0) EXPAND %{8} Tue Nov 22 15:19:40 2016 : Debug: (0) --> Tue Nov 22 15:19:40 2016 : Debug: (0) if ("%{8}") -> FALSE Tue Nov 22 15:19:40 2016 : Debug: (0) elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) { Tue Nov 22 15:19:40 2016 : Debug: (0) elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE Tue Nov 22 15:19:40 2016 : Debug: (0) elsif (Aruba-Essid-Name) { Tue Nov 22 15:19:40 2016 : Debug: (0) elsif (Aruba-Essid-Name) -> FALSE Tue Nov 22 15:19:40 2016 : Debug: (0) elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) { Tue Nov 22 15:19:40 2016 : Debug: (0) EXPAND %{Cisco-AVPair} Tue Nov 22 15:19:40 2016 : Debug: (0) --> dc-profile-name=HP-Device Tue Nov 22 15:19:40 2016 : Debug: (0) elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[accounting]: calling updated (rlm_always) Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[accounting]: returned from updated (rlm_always) Tue Nov 22 15:19:40 2016 : Debug: (0) [updated] = updated Tue Nov 22 15:19:40 2016 : Debug: (0) } # if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) = updated Tue Nov 22 15:19:40 2016 : Debug: (0) ... skipping else: Preceding "if" was taken Tue Nov 22 15:19:40 2016 : Debug: (0) } # policy rewrite_called_station_id = updated Tue Nov 22 15:19:40 2016 : Debug: (0) update { Tue Nov 22 15:19:40 2016 : Debug: (0) EXPAND %{Packet-Src-IP-Address} Tue Nov 22 15:19:40 2016 : Debug: (0) --> 172.20.135.3 Tue Nov 22 15:19:40 2016 : Debug: (0) &request:FreeRADIUS-Client-IP-Address := 172.20.135.3 Tue Nov 22 15:19:40 2016 : Debug: (0) &control:PacketFence-RPC-Server = 127.0.0.1 Tue Nov 22 15:19:40 2016 : Debug: (0) &control:PacketFence-RPC-Port = 7070 Tue Nov 22 15:19:40 2016 : Debug: (0) &control:PacketFence-RPC-User = packet Tue Nov 22 15:19:40 2016 : Debug: (0) &control:PacketFence-RPC-Pass = fence Tue Nov 22 15:19:40 2016 : Debug: (0) &control:PacketFence-RPC-Proto = http Tue Nov 22 15:19:40 2016 : Debug: (0) } # update = noop Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[accounting]: calling sql (rlm_sql) Tue Nov 22 15:19:40 2016 : Debug: %{tolower:type.%{Acct-Status-Type}.query} Tue Nov 22 15:19:40 2016 : Debug: Parsed xlat tree: Tue Nov 22 15:19:40 2016 : Debug: xlat --> tolower Tue Nov 22 15:19:40 2016 : Debug: { Tue Nov 22 15:19:40 2016 : Debug: literal --> type. Tue Nov 22 15:19:40 2016 : Debug: attribute --> Acct-Status-Type Tue Nov 22 15:19:40 2016 : Debug: literal --> .query Tue Nov 22 15:19:40 2016 : Debug: } Tue Nov 22 15:19:40 2016 : Debug: (0) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query} Tue Nov 22 15:19:40 2016 : Debug: (0) sql: --> type.stop.query Tue Nov 22 15:19:40 2016 : Debug: (0) sql: Using query template 'query' Tue Nov 22 15:19:40 2016 : Debug: rlm_sql (sql): Reserved connection (1) Tue Nov 22 15:19:40 2016 : Debug: %{User-Name} Tue Nov 22 15:19:40 2016 : Debug: Parsed xlat tree: Tue Nov 22 15:19:40 2016 : Debug: attribute --> User-Name Tue Nov 22 15:19:40 2016 : Debug: (0) sql: EXPAND %{User-Name} Tue Nov 22 15:19:40 2016 : Debug: (0) sql: --> 10:1f:74:b2:f6:a5 Tue Nov 22 15:19:40 2016 : Debug: (0) sql: SQL-User-Name set to '10:1f:74:b2:f6:a5' Tue Nov 22 15:19:40 2016 : Debug: CALL acct_stop ( FROM_UNIXTIME(%{integer:Event-Timestamp}), '%{Framed-IP-Address}', %{%{Acct-Session-Time}:-NULL}, '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Acct-Unique-Session-Id}', '%{Acct-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{%{NAS-Port-ID}:-%{NAS-Port}}', '%{NAS-Port-Type}', '%{Acct-Authentic}', '%{Connect-Info}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Acct-Terminate-Cause}', '%{Acct-Status-Type}') Tue Nov 22 15:19:40 2016 : Debug: Parsed xlat tree: Tue Nov 22 15:19:40 2016 : Debug: literal --> CALL acct_stop ( FROM_UNIXTIME( Tue Nov 22 15:19:40 2016 : Debug: xlat --> integer Tue Nov 22 15:19:40 2016 : Debug: { Tue Nov 22 15:19:40 2016 : Debug: literal --> Event-Timestamp Tue Nov 22 15:19:40 2016 : Debug: } Tue Nov 22 15:19:40 2016 : Debug: literal --> ), ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> Framed-IP-Address Tue Nov 22 15:19:40 2016 : Debug: literal --> ', Tue Nov 22 15:19:40 2016 : Debug: if { Tue Nov 22 15:19:40 2016 : Debug: attribute --> Acct-Session-Time Tue Nov 22 15:19:40 2016 : Debug: } Tue Nov 22 15:19:40 2016 : Debug: else { Tue Nov 22 15:19:40 2016 : Debug: literal --> NULL Tue Nov 22 15:19:40 2016 : Debug: } Tue Nov 22 15:19:40 2016 : Debug: literal --> , ' Tue Nov 22 15:19:40 2016 : Debug: if { Tue Nov 22 15:19:40 2016 : Debug: attribute --> Acct-Input-Gigawords Tue Nov 22 15:19:40 2016 : Debug: } Tue Nov 22 15:19:40 2016 : Debug: else { Tue Nov 22 15:19:40 2016 : Debug: literal --> 0 Tue Nov 22 15:19:40 2016 : Debug: } Tue Nov 22 15:19:40 2016 : Debug: literal --> ' << 32 | ' Tue Nov 22 15:19:40 2016 : Debug: if { Tue Nov 22 15:19:40 2016 : Debug: attribute --> Acct-Input-Octets Tue Nov 22 15:19:40 2016 : Debug: } Tue Nov 22 15:19:40 2016 : Debug: else { Tue Nov 22 15:19:40 2016 : Debug: literal --> 0 Tue Nov 22 15:19:40 2016 : Debug: } Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: if { Tue Nov 22 15:19:40 2016 : Debug: attribute --> Acct-Output-Gigawords Tue Nov 22 15:19:40 2016 : Debug: } Tue Nov 22 15:19:40 2016 : Debug: else { Tue Nov 22 15:19:40 2016 : Debug: literal --> 0 Tue Nov 22 15:19:40 2016 : Debug: } Tue Nov 22 15:19:40 2016 : Debug: literal --> ' << 32 | ' Tue Nov 22 15:19:40 2016 : Debug: if { Tue Nov 22 15:19:40 2016 : Debug: attribute --> Acct-Output-Octets Tue Nov 22 15:19:40 2016 : Debug: } Tue Nov 22 15:19:40 2016 : Debug: else { Tue Nov 22 15:19:40 2016 : Debug: literal --> 0 Tue Nov 22 15:19:40 2016 : Debug: } Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> Acct-Unique-Session-Id Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> Acct-Session-Id Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> SQL-User-Name Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> Realm Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> NAS-IP-Address Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: if { Tue Nov 22 15:19:40 2016 : Debug: attribute --> NAS-Port-Id Tue Nov 22 15:19:40 2016 : Debug: } Tue Nov 22 15:19:40 2016 : Debug: else { Tue Nov 22 15:19:40 2016 : Debug: attribute --> NAS-Port Tue Nov 22 15:19:40 2016 : Debug: } Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> NAS-Port-Type Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> Acct-Authentic Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> Connect-Info Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> Called-Station-Id Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> Calling-Station-Id Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> Service-Type Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> Framed-Protocol Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> Acct-Terminate-Cause Tue Nov 22 15:19:40 2016 : Debug: literal --> ', ' Tue Nov 22 15:19:40 2016 : Debug: attribute --> Acct-Status-Type Tue Nov 22 15:19:40 2016 : Debug: literal --> ') Tue Nov 22 15:19:40 2016 : Debug: (0) sql: EXPAND CALL acct_stop ( FROM_UNIXTIME(%{integer:Event-Timestamp}), '%{Framed-IP-Address}', %{%{Acct-Session-Time}:-NULL}, '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Acct-Unique-Session-Id}', '%{Acct-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{%{NAS-Port-ID}:-%{NAS-Port}}', '%{NAS-Port-Type}', '%{Acct-Authentic}', '%{Connect-Info}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Acct-Terminate-Cause}', '%{Acct-Status-Type}') Tue Nov 22 15:19:40 2016 : Debug: (0) sql: --> CALL acct_stop ( FROM_UNIXTIME(1479846376), '', 1133, '0' << 32 | '97158148', '0' << 32 | '166844207', 'ddbfe7a1d200b1fb1576b92057e0bcc6', '000003B1', '10:1f:74:b2:f6:a5', 'null', '172.20.135.77', 'GigabitEthernet1/0/8', 'Ethernet', '', '', 'dc:a5:f4:34:55:08', '10:1f:74:b2:f6:a5', '', '', 'Lost-Carrier', 'Stop') Tue Nov 22 15:19:40 2016 : Debug: (0) sql: Executing query: CALL acct_stop ( FROM_UNIXTIME(1479846376), '', 1133, '0' << 32 | '97158148', '0' << 32 | '166844207', 'ddbfe7a1d200b1fb1576b92057e0bcc6', '000003B1', '10:1f:74:b2:f6:a5', 'null', '172.20.135.77', 'GigabitEthernet1/0/8', 'Ethernet', '', '', 'dc:a5:f4:34:55:08', '10:1f:74:b2:f6:a5', '', '', 'Lost-Carrier', 'Stop') Tue Nov 22 15:19:40 2016 : Debug: (0) sql: SQL query returned: success Tue Nov 22 15:19:40 2016 : Debug: (0) sql: 1 record(s) updated Tue Nov 22 15:19:40 2016 : Debug: rlm_sql (sql): Released connection (1) Tue Nov 22 15:19:40 2016 : Info: rlm_sql (sql): Need 4 more connections to reach 10 spares Tue Nov 22 15:19:40 2016 : Info: rlm_sql (sql): Opening additional connection (6), 1 of 58 pending slots used Tue Nov 22 15:19:40 2016 : Debug: rlm_sql_mysql: Starting connect to MySQL server Tue Nov 22 15:19:40 2016 : Debug: rlm_sql_mysql: Connected to database 'pf' on 127.0.0.1 via TCP/IP, server version 5.5.50-MariaDB, protocol version 10 Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[accounting]: returned from sql (rlm_sql) Tue Nov 22 15:19:40 2016 : Debug: (0) [sql] = ok Tue Nov 22 15:19:40 2016 : Debug: (0) if (noop) { Tue Nov 22 15:19:40 2016 : Debug: (0) if (noop) -> FALSE Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[accounting]: calling attr_filter.accounting_response (rlm_attr_filter) Tue Nov 22 15:19:40 2016 : Debug: %{User-Name} Tue Nov 22 15:19:40 2016 : Debug: Parsed xlat tree: Tue Nov 22 15:19:40 2016 : Debug: attribute --> User-Name Tue Nov 22 15:19:40 2016 : Debug: (0) attr_filter.accounting_response: EXPAND %{User-Name} Tue Nov 22 15:19:40 2016 : Debug: (0) attr_filter.accounting_response: --> 10:1f:74:b2:f6:a5 Tue Nov 22 15:19:40 2016 : Debug: (0) attr_filter.accounting_response: Matched entry DEFAULT at line 12 Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[accounting]: returned from attr_filter.accounting_response (rlm_attr_filter) Tue Nov 22 15:19:40 2016 : Debug: (0) [attr_filter.accounting_response] = updated Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[accounting]: calling rest (rlm_rest) Tue Nov 22 15:19:40 2016 : Debug: rlm_rest (rest): Reserved connection (0) Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Expanding URI components Tue Nov 22 15:19:40 2016 : Debug: http://127.0.0.1:7070 Tue Nov 22 15:19:40 2016 : Debug: Parsed xlat tree: Tue Nov 22 15:19:40 2016 : Debug: literal --> http://127.0.0.1:7070 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: EXPAND http://127.0.0.1:7070 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: --> http://127.0.0.1:7070 Tue Nov 22 15:19:40 2016 : Debug: //radius/rest/accounting Tue Nov 22 15:19:40 2016 : Debug: Parsed xlat tree: Tue Nov 22 15:19:40 2016 : Debug: literal --> //radius/rest/accounting Tue Nov 22 15:19:40 2016 : Debug: (0) rest: EXPAND //radius/rest/accounting Tue Nov 22 15:19:40 2016 : Debug: (0) rest: --> //radius/rest/accounting Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Sending HTTP POST to "http://127.0.0.1:7070//radius/rest/accounting" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Adding custom headers: Tue Nov 22 15:19:40 2016 : Debug: (0) rest: X-FreeRADIUS-Section: accounting Tue Nov 22 15:19:40 2016 : Debug: (0) rest: X-FreeRADIUS-Server: packetfence Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Request body content-type will be "application/json" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "User-Name" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : string Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 17 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "10:1f:74:b2:f6:a5" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "NAS-IP-Address" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : ipaddr Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 13 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "172.20.135.77" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "NAS-Port" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : integer Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 5 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : 50108 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Called-Station-Id" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : string Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 17 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "dc:a5:f4:34:55:08" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Calling-Station-Id" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : string Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 17 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "10:1f:74:b2:f6:a5" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Proxy-State" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : octets Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 8 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "0x313339" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "NAS-Port-Type" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : integer Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 2 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : 15 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Acct-Status-Type" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : integer Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 1 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : 2 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Acct-Delay-Time" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : integer Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 1 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : 0 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Acct-Input-Octets" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : integer Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 8 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : 97158148 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Acct-Output-Octets" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : integer Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 9 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : 166844207 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Acct-Session-Id" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : string Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 8 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "000003B1" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Acct-Session-Time" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : integer Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 4 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : 1133 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Acct-Input-Packets" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : integer Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 6 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : 744486 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Acct-Output-Packets" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : integer Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 7 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : 1682264 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Acct-Terminate-Cause" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : integer Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 1 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : 2 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Event-Timestamp" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : date Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 24 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "nov 22 2016 15:26:16 EST" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "NAS-Port-Id" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : string Tue Nov 22 15:19:40 2016 : Debug: (0) rest: JSON Data: {"User-Name":{"type":"string","value":["10:1f:74:b2:f6:a5"]},"NAS-IP-Address":{"type":"ipaddr","value":["172.20.135.77"]},"NAS-Port":{"type":"integer","value":[50108]},"Called-Station-Id":{"type":"string","value":["dc:a5:f4:34:55:08"]},"Calling-Station-Id":{"type":"string","value":["10:1f:74:b2:f6:a5"]},"Proxy-State":{"type":"octets","value":["0x313339"]},"NAS-Port-Type":{"type":"integer","value":[15]},"Acct-Status-Type":{"type":"integer","value":[2]},"Acct-Delay-Time":{"type":"integer","value":[0]},"Acct-Input-Octets":{"type":"integer","value":[97158148]},"Acct-Output-Octets":{"type":"integer","value":[166844207]},"Acct-Session-Id":{"type":"string","value":["000003B1"]},"Acct-Session-Time":{"type":"integer","value":[1133]},"Acct-Input-Packets":{"type":"integer","value":[744486]},"Acct-Output-Packets":{"type":"integer","value":[1682264]},"Acct-Terminate-Cause":{"type":"integer","value":[2]},"Event-Timestamp":{"type":"date","value":["nov 22 2016 15:26:16 EST"]},"NAS-Port-Id":{"type":"string","value":[ Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Returning 1015 bytes of JSON data (buffer full or chunk exceeded) Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 22 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "GigabitEthernet1\/0\/8" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Cisco-AVPair" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : string Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 25 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "dc-profile-name=HP-Device" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 23 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "dc-device-name=MSFT 5.0" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 29 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "dc-device-class-tag=HP-Device" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 22 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "dc-certainty-metric=10" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 82 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "dc-opaque=\u0000\u0000\u0000\u0002\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 17 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "dc-protocol-map=9" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 84 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "dhcp-option=\u00007\u0000\r\u0001\u000F\u0003\u0006,.\/\u001F!y\uFFFFFFF9\uFFFFFFFC+" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 35 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "dhcp-option=\u0000<\u0000\bMSFT 5.0" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 37 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "dhcp-option=\u0000\f\u0000\tinverse-8" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 41 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "audit-session-id=AC158904000001485B34CE42" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 11 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "vlan-id=138" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 10 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "method=mab" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Stripped-User-Name" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : string Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 12 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "101f74b2f6a5" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Realm" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : string Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 4 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "null" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "Acct-Unique-Session-Id" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : string Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 32 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "ddbfe7a1d200b1fb1576b92057e0bcc6" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Encoding attribute "FreeRADIUS-Client-IP-Address" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : ipaddr Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 12 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "172.20.135.3" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: JSON Data: "GigabitEthernet1\/0\/8"]},"Cisco-AVPair":{"type":"string","value":["dc-profile-name=HP-Device","dc-device-name=MSFT 5.0","dc-device-class-tag=HP-Device","dc-certainty-metric=10","dc-opaque=\u0000\u0000\u0000\u0002\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000","dc-protocol-map=9","dhcp-option=\u00007\u0000\r\u0001\u000F\u0003\u0006,.\/\u001F!y\uFFFFFFF9\uFFFFFFFC+","dhcp-option=\u0000<\u0000\bMSFT 5.0","dhcp-option=\u0000\f\u0000\tinverse-8","audit-session-id=AC158904000001485B34CE42","vlan-id=138","method=mab"]},"Stripped-User-Name":{"type":"string","value":["101f74b2f6a5"]},"Realm":{"type":"string","value":["null"]},"Acct-Unique-Session-Id":{"type":"string","value":["ddbfe7a1d200b1fb1576b92057e0bcc6"]},"FreeRADIUS-Client-IP-Address":{"type":"ipaddr","value":["172.20.135.3"]}} Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Returning 791 bytes of JSON data Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Processing response header Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Status : 100 (Continue) Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Continuing... Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Processing response header Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Status : 200 (OK) Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : json (application/json) Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Parsing attribute "Reply-Message" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : string Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 13 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "Accounting ok" Tue Nov 22 15:19:40 2016 : Debug: Accounting ok Tue Nov 22 15:19:40 2016 : Debug: Parsed xlat tree: Tue Nov 22 15:19:40 2016 : Debug: literal --> Accounting ok Tue Nov 22 15:19:40 2016 : Debug: (0) rest: EXPAND Accounting ok Tue Nov 22 15:19:40 2016 : Debug: (0) rest: --> Accounting ok Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Reply-Message := "Accounting ok" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Parsing attribute "reply:PacketFence-Authorization-Status" Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Type : string Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Length : 5 Tue Nov 22 15:19:40 2016 : Debug: (0) rest: Value : "allow" Tue Nov 22 15:19:40 2016 : Debug: allow Tue Nov 22 15:19:40 2016 : Debug: Parsed xlat tree: Tue Nov 22 15:19:40 2016 : Debug: literal --> allow Tue Nov 22 15:19:40 2016 : Debug: (0) rest: EXPAND allow Tue Nov 22 15:19:40 2016 : Debug: (0) rest: --> allow Tue Nov 22 15:19:40 2016 : Debug: (0) rest: PacketFence-Authorization-Status := "allow" Tue Nov 22 15:19:40 2016 : Debug: rlm_rest (rest): Released connection (0) Tue Nov 22 15:19:40 2016 : Info: rlm_rest (rest): Need 5 more connections to reach 10 spares Tue Nov 22 15:19:40 2016 : Info: rlm_rest (rest): Opening additional connection (5), 1 of 59 pending slots used Tue Nov 22 15:19:40 2016 : Debug: rlm_rest (rest): Connecting to "http://127.0.0.1:7070/" Tue Nov 22 15:19:40 2016 : Debug: (0) modsingle[accounting]: returned from rest (rlm_rest) Tue Nov 22 15:19:40 2016 : Debug: (0) [rest] = updated Tue Nov 22 15:19:40 2016 : Debug: (0) } # accounting = updated Tue Nov 22 15:19:40 2016 : Debug: (0) Sent Accounting-Response Id 77 from 172.20.135.1:1813 to 172.20.135.3:2940 length 0 Tue Nov 22 15:19:40 2016 : Debug: (0) Reply-Message = "Accounting ok" Tue Nov 22 15:19:40 2016 : Debug: (0) PacketFence-Authorization-Status = "allow" Tue Nov 22 15:19:40 2016 : Debug: (0) Proxy-State = 0x313339 Tue Nov 22 15:19:40 2016 : Debug: (0) Finished request Tue Nov 22 15:19:40 2016 : Debug: (0) Cleaning up request packet ID 77 with timestamp +20 Tue Nov 22 15:19:40 2016 : Info: Ready to process requests -- Fabrice Durand fdurand(a)inverse.ca :: +1.514.447.4918 (x135) :: www.inverse.ca Inverse inc. :: Leaders behind SOGo (http://www.sogo.nu) and PacketFence (http://packetfence.org)

3 5

authentication-failed
by Ejaz 23 Nov '16

23 Nov '16

Hello, Please help As per the attached error it was not bringing the users data, when we cross checked our database with quries.conf which is below. We found on the oracle database table only a "username" as attached where as in queries.conf ""SQL-User-Name" Therefore, if replace in my quries.conf from ""SQL-User-Name" with "User-Name" that should work. I appreciate your Usual support. Here is the query.conf file. queries.conf allocate_begin = "commit" start_begin = "commit" alive_begin = "commit" stop_begin = "commit" on_begin = "commit" off_begin = "commit" allocate_find = "\ SELECT framedipaddress \ FROM ${ippool_table} \ WHERE pool_name = '%{control:Pool-Name}' \ AND expiry_time < current_timestamp \ AND rownum <= 1 \ ORDER BY \ (username <> '%{SQL-User-Name}'), \ (callingstationid <> '%{Calling-Station- Id}'), \ expiry_time \ FOR UPDATE" pool_check = "\ SELECT id \ FROM (\ SELECT id \ FROM ${ippool_table} \ WHERE pool_name='%{control:Pool-Name}'\ ) \ WHERE ROWNUM = 1" allocate_update = "\ UPDATE ${ippool_table} \ SET \ nasipaddress = '%{NAS-IP-Address}', \ pool_key = '${pool_key}', \ callingstationid = '%{Calling-Station-Id}', \ username = '%{SQL-User-Name}', \ expiry_time = current_timestamp + INTERVAL '${lease_duration}' second(1) \ WHERE framedipaddress = '%I'" allocate_clear = "\ UPDATE ${ippool_table} \ SET \ nasipaddress = '', \ pool_key = 0, \ callingstationid = '', \ expiry_time = current_timestamp - INTERVAL '1' second(1) \ WHERE pool_key = '${pool_key}'" start_update = "\ UPDATE ${ippool_table} \ SET \ expiry_time = current_timestamp + INTERVAL '${lease_duration}' second(1) \ WHERE nasipaddress = '%{NAS-IP-Address}' \ AND pool_key = '${pool_key}'" stop_clear = "\ UPDATE ${ippool_table} \ SET \ nasipaddress = '', \ pool_key = 0, \ callingstationid = '', \ expiry_time = current_timestamp - INTERVAL '1' second(1) \ WHERE nasipaddress = '%{Nas-IP-Address}' \ AND pool_key = '${pool_key}' \ AND username = '%{SQL-User-Name}' \ AND callingstationid = '%{Calling-Station-Id}'" alive_update = "\ UPDATE ${ippool_table} \ SET \ expiry_time = current_timestamp + INTERVAL '${lease_duration}' second(1) \ WHERE nasipaddress = '%{Nas-IP-Address}' \ AND pool_key = '${pool_key}' \ AND framedipaddress = '%{Framed-IP-Address}' \ AND username = '%{SQL-User-Name}' \ AND callingstationid = '%{Calling-Station-Id}'" on_clear = "\ UPDATE ${ippool_table} \ SET \ nasipaddress = '', \ pool_key = 0, \ callingstationid = '', \ expiry_time = current_timestamp - INTERVAL '1' second(1) \ WHERE nasipaddress = '%{Nas-IP-Address}'" off_clear = "\ UPDATE ${ippool_table} \ SET \ nasipaddress = '', \ pool_key = 0, \ callingstationid = '', \ expiry_time = current_timestamp - INTERVAL '1' second(1) \ WHERE nasipaddress = '%{Nas-IP-Address}'" Thanks, Mohammed Ejaz Asst. Operation Director of Systems. Cyberia SAUDI ARABIA P.O.Box: 301079, Riyadh 11372 Phone: (+966) 11 464 7114 Ext. 140 Mobile: (+966) 562311787 Fax: (+966) 11 465 4735 Website: http://www.cyberia.net.sa

4 6

EAP-MD5 Deprecation
by David Teston 23 Nov '16

23 Nov '16

Hi All, I've been using the apt repo package of FreeRadius (version 2.x) on Ubuntu 16.04. Recently, I switched to the GitHub repo version 3.1.x. I want to use "radtest -t eap-md5 ..." for testing which is supported in 2.x at /usr/bin/radtest, but 3.1.x uses a different radtest client (/usr/local/bin/radtest) which doesn't have support for eap-md5. Why is eap-md5 not there anymore? Does anyone know how to get this to work, short of copying the file? Additionally, all of my passwords are MD5 hashed. Thanks in advance, David -- David Teston PINES System Administrator dteston(a)georgialibraries.org

7 12

Status of pam_radius_auth
by Michael Weissenbacher 22 Nov '16

22 Nov '16

Dear List! I wanted to ask about the status of the pam_radius_auth Module found at http://freeradius.org/pam_radius_auth/ Does this have it's own mailing list? Bugtracker? It it currently unmaintained? The reason i am asking is because i found a few issues and would like to submit patches and/or find people who are willing to test them. Unfortunately it seems that the module didn't have much activity in recent years. Also, most distros (at least Debian, Ubuntu and Gentoo) still package the old version 1.3.17 and not 1.4.0. And please point me to the right place, in case it's not here :-) thanks, Michael

2 1

Building FR 4.0 on Ubuntu 16.04.1
by Alex Sharaz 21 Nov '16

21 Nov '16

Trying to build FR 4.0 on This flavour of Ubuntu and I get root@prodn2:/usr/local/src/freeradius-server-4.0.x# make scripts/boiler.mk:628: src/modules/rlm_lua/rlm_lua.mk: No such file or directory scripts/boiler.mk:628: src/modules/rlm_lua/libfreeradius-lua.mk: No such file or directory make: *** No rule to make target 'src/modules/rlm_lua/libfreeradius-lua.mk'. Stop. What do I need to install to get a bit further? A

3 6

missing is missing --is-lightweight?
by Peter Lambrechtsen 21 Nov '16

21 Nov '16

Noticed something pretty minor but thought I might point it out. When building on Debian on 3.0.x checking for rusers... /usr/bin/rusers /freeradius/freeradius-server/missing: Unknown `--is-lightweight' option Try `/freeradius/freeradius-server/missing --help' for more information configure: WARNING: 'missing' script is too old or missing checking for locate... /usr/bin/locate In the aclocal.m4 is pointing to the script. # Use eval to expand $SHELL if eval "$MISSING --is-lightweight"; then am_missing_run="$MISSING " else am_missing_run= AC_MSG_WARN(['missing' script is too old or missing]) fi Meh no biggie.. but if anyone was poking around aclocal or missing it might be worth sorting.

2 1