json encoding (Freeradius 3.0.13)
Fabrice Durand
fdurand at inverse.ca
Tue Nov 22 21:39:09 CET 2016
Hi All,
i am trying to implement cisco Device sensor
(http://www.cisco.com/c/en/us/td/docs/switches/lan/catalyst3750/software/release/15-0_1_se/device_sensor/guide/sensor_guide.html)
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 at inverse.ca :: +1.514.447.4918 (x135) :: www.inverse.ca
Inverse inc. :: Leaders behind SOGo (http://www.sogo.nu) and PacketFence (http://packetfence.org)
More information about the Freeradius-Users
mailing list