Freeradius 3.16 and mysql - duplicated entries in radpostauth
Marcin Marszałkowski
m.marszal at wp.pl
Mon Aug 19 04:40:07 CEST 2019
So far, I’ve come up with post-auth section rule (in my network only eap and md5 are used, pap is for radtest):
# sql
# sql input only for PAP and MD5
Post-Auth-Type MD5 {
sql
}
Post-Auth-Type PAP {
sql
}
I’ll be testing it and revert back with results...
Martin
> Wiadomość napisana przez Marcin Marszałkowski <m.marszal at wp.pl> w dniu 18.08.2019, o godz. 15:47:
>
>
>
>
> Thanks Alan B.!
> I’ve tested your advice - disabling sql in default server post-auth section, and it works. But won’t it affect MD5 protocol (MAC based auth.)? If so, can I apply some conditional rule in default post-auth, i.e.:
> Auth-Type MD5 {
> sql
> }
>
> And any word on:
>>>
>>> On top of that I have a problems with accounting, it seems like NAS doesn’t like Gigawords - quite often reports 4GB up and down. More often it happens when session is longer than shorter. Is there any any fix available on Freeradius side? Ubiquiti claims https://help.ubnt.com/hc/en-us/articles/115005255907-UniFi-Hotspot-RADIUS-Attributes their APs should be working with this attribute. NAS it is Unifi AP AC Pro.
>
>
> Simply NAS reports false bandwidth usage despite Ubiquiti claims it should work. I tried enabling and disabling „acct_counters64” but it doesn’t change anything.
> I’ve seen this:
> For Cisco <https://wiki.freeradius.org/vendor/Cisco> IOS, this usually achieved by entering
>
> aaa accounting gigawords
> but it seems like I can’t use it on Unifi NAS/AP. Any suggestions?
>
> Regards
> Martin
>
>
>> Wiadomość napisana przez Alan Buxey <alan.buxey at gmail.com> w dniu 18.08.2019, o godz. 13:39:
>>
>> hi,
>>
>> in your debug, step 10 is in the inner-tunnel - calling post-auth
>> section there... update SQL... step 11 is in the default (outer)
>> post-auth section - updating SQL there.
>> if you only want one entry, make sure you only call the post-auth with
>> SQL update in the inner (where username is real etc) and dont do it in
>> outer.
>>
>> for PEAP its usually 10 to 11 parts to the conversation (phase 1,
>> setup etc) then phase 2 - auth in the TLS tunnel) - a quick google
>> brings me a suitable example resource
>> such as https://sites.google.com/site/amitsciscozone/home/switching/peap---protected-eap-protocol
>>
>> alan
>>
>> On Sun, 18 Aug 2019 at 08:36, Marcin Marszałkowski <m.marszal at wp.pl> wrote:
>>>
>>> Hi,
>>>
>>> I’m newbie to Freeradius and have been pulling my hair out…
>>> Installed Freeradius 3.16 with mysql and Daloradius. Autheticating and authorizing work (I think so).
>>> But I might have something misconfigured - radpostauth table is full of duplicated/always double entries with the same timestamp. And it happens only for EAP auth., PAP (radtest) and MD5 (MAC based auth.) are not affected. Does it may affect accounting?
>>>
>>> Following is request debug where double input to radpostauth is visible:
>>> ————————————————
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Received Access-Request Id 248 from 172.16.0.5:48453 to 172.16.0.12:1812 length 242
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) User-Name = "Robert"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) NAS-Identifier = "feec3a9aeda5"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Called-Station-Id = "FE-EC-3A-9A-ED-A5:Guest"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) NAS-Port-Type = Wireless-802.11
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Service-Type = Framed-User
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Calling-Station-Id = "04-DB-56-F0-C3-36"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Connect-Info = "CONNECT 0Mbps 802.11b"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Acct-Session-Id = "D9B312EA0EEDF1F6"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Mobility-Domain-Id = 1826
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) WLAN-Pairwise-Cipher = 1027076
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) WLAN-Group-Cipher = 1027076
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) WLAN-AKM-Suite = 1027075
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Framed-MTU = 1400
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) EAP-Message = 0x021b00251900170303001a7ee7eda10323b3262a8342edbba1f2cff9ae93b8127cc51c3b47
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) State = 0x7d7976aa75626f6ce06082b82288935b
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Message-Authenticator = 0xdcedbfc0f49a2c315fa3a073561ea26c
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) session-state: No cached attributes
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) authorize {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) policy filter_username {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name) -> TRUE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ / /) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ / /) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /@[^@]*@/ ) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /@[^@]*@/ ) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.\./ ) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.\./ ) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.$/) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.$/) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /@\./) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /@\./) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # if (&User-Name) = notfound
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # policy filter_username = notfound
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) policy filter_password {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Password && (&User-Password != "%{string:User-Password}")) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # policy filter_password = notfound
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling preprocess (rlm_preprocess)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from preprocess (rlm_preprocess)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [preprocess] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) update request {
>>> Sat Aug 17 18:23:36 2019 : Debug: %{User-Name}
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) EXPAND %{User-Name}
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) --> Robert
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) SQL-User-Name set to 'Robert'
>>> Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Reserved connection (6)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Executing select query: select groupname from radhuntgroup where nasipaddress="172.16.0.5"
>>> Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Released connection (6)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) EXPAND %{sql:select groupname from radhuntgroup where nasipaddress="%{NAS-IP-Address}"}
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) --> WiFi
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Huntgroup-Name := WiFi
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # update request = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling mschap (rlm_mschap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from mschap (rlm_mschap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [mschap] = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling suffix (rlm_realm)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) suffix: Checking for suffix after "@"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) suffix: No '@' in User-Name = "Robert", looking up realm NULL
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) suffix: No such realm "NULL"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from suffix (rlm_realm)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [suffix] = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling eap (rlm_eap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Peer sent EAP Response (code 2) ID 27 length 37
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Continuing tunnel setup
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from eap (rlm_eap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [eap] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # authorize = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Found Auth-Type = eap
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) authenticate {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authenticate]: calling eap (rlm_eap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Expiring EAP session with state 0xba6ef1b9bb75eb14
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Finished EAP session with state 0x7d7976aa75626f6c
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Previous EAP request found for state 0x7d7976aa75626f6c, released from the list
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Peer sent packet with method EAP PEAP (25)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Calling submodule eap_peap to process data
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Continuing EAP-TLS
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Peer sent flags ---
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: [eaptls verify] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Done initial handshake
>>> Sat Aug 17 18:23:36 2019 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: [eaptls process] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Session established. Decoding tunneled attributes
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: PEAP state phase2
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: EAP method MSCHAPv2 (26)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Got tunneled request
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: EAP-Message = 0x021b00061a03
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Setting User-Name to Robert
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Sending tunneled request to inner-tunnel
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: EAP-Message = 0x021b00061a03
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: User-Name = "Robert"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: State = 0xba6ef1b9bb75eb14f919ef4d049db6e4
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Virtual server inner-tunnel received request
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) EAP-Message = 0x021b00061a03
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) FreeRADIUS-Proxied-To = 127.0.0.1
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) User-Name = "Robert"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) State = 0xba6ef1b9bb75eb14f919ef4d049db6e4
>>> Sat Aug 17 18:23:36 2019 : WARNING: (10) Outer and inner identities are the same. User privacy is compromised.
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) server inner-tunnel {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) session-state: No cached attributes
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/inner-tunnel
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) authorize {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) policy filter_username {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name) -> TRUE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ / /) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ / /) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /@[^@]*@/ ) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /@[^@]*@/ ) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.\./ ) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.\./ ) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.$/) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.$/) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /@\./) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /@\./) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # if (&User-Name) = notfound
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # policy filter_username = notfound
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling mschap (rlm_mschap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from mschap (rlm_mschap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [mschap] = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling suffix (rlm_realm)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) suffix: Checking for suffix after "@"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) suffix: No '@' in User-Name = "Robert", looking up realm NULL
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) suffix: No such realm "NULL"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from suffix (rlm_realm)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [suffix] = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) update control {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) &Proxy-To-Realm := LOCAL
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # update control = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling eap (rlm_eap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Peer sent EAP Response (code 2) ID 27 length 6
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: No EAP Start, assuming it's an on-going EAP conversation
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from eap (rlm_eap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [eap] = updated
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling sql (rlm_sql)
>>> Sat Aug 17 18:23:36 2019 : Debug: %{User-Name}
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND %{User-Name}
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> Robert
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: SQL-User-Name set to 'Robert'
>>> Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Reserved connection (8)
>>> Sat Aug 17 18:23:36 2019 : Debug: SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY '
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-User-Name
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY 'Robert' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY 'Robert' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: User found in radcheck table
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Conditional check items matched, merging assignment check items
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Cleartext-Password := "Atina2011!"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: FROM 1 TO 2 MAX 3
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Cleartext-Password
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Cleartext-Password FROM 0 TO 2
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: TO in 2 out 2
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: to[0] = Proxy-To-Realm
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: to[1] = Auth-Type
>>> Sat Aug 17 18:23:36 2019 : Debug: SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY '
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-User-Name
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY 'Robert' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY 'Robert' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ... falling-through to group processing
>>> Sat Aug 17 18:23:36 2019 : Debug: SELECT groupname FROM radusergroup WHERE username = BINARY '%{SQL-User-Name}' ORDER BY priority
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> SELECT groupname FROM radusergroup WHERE username = BINARY '
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-User-Name
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ' ORDER BY priority
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = BINARY '%{SQL-User-Name}' ORDER BY priority
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> SELECT groupname FROM radusergroup WHERE username = BINARY 'Robert' ORDER BY priority
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = BINARY 'Robert' ORDER BY priority
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: User found in the group table
>>> Sat Aug 17 18:23:36 2019 : Debug: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-Group
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'Dzieci' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'Dzieci' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Group "Dzieci": Conditional check items matched
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Group "Dzieci": Merging assignment check items
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Simultaneous-Use := 2
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Max-Daily-Session := 10800
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Login-Time := "Wk1200-2330,Sa0800-2330,Su0800-2300"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: FROM 3 TO 3 MAX 6
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Simultaneous-Use
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Simultaneous-Use FROM 0 TO 3
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Max-Daily-Session
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Max-Daily-Session FROM 1 TO 3
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Login-Time
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Login-Time FROM 2 TO 3
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: TO in 3 out 3
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: to[0] = Proxy-To-Realm
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: to[1] = Auth-Type
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: to[2] = Cleartext-Password
>>> Sat Aug 17 18:23:36 2019 : Debug: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-Group
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'Dzieci' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'Dzieci' ORDER BY id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Group "Dzieci": Merging reply items
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Tunnel-Private-Group-Id := "11"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Tunnel-Type := VLAN
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Tunnel-Medium-Type := IEEE-802
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Fall-Through = Yes
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Session-Timeout := 3600
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Acct-Interim-Interval := 300
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Idle-Timeout := 450
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Termination-Action := RADIUS-Request
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: FROM 8 TO 0 MAX 8
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Tunnel-Private-Group-Id
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Tunnel-Private-Group-Id FROM 0 TO 0
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Tunnel-Type
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Tunnel-Type FROM 1 TO 0
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Tunnel-Medium-Type
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Tunnel-Medium-Type FROM 2 TO 0
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Fall-Through
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Fall-Through FROM 3 TO 0
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Session-Timeout
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Session-Timeout FROM 4 TO 0
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Acct-Interim-Interval
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Acct-Interim-Interval FROM 5 TO 0
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Idle-Timeout
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Idle-Timeout FROM 6 TO 0
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Termination-Action
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Termination-Action FROM 7 TO 0
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: TO in 0 out 0
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ... falling-through to profile processing
>>> Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Released connection (8)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from sql (rlm_sql)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [sql] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling dailycounter (rlm_sqlcounter)
>>> Sat Aug 17 18:23:36 2019 : Debug: sqlcounter_expand: 'SELECT SUM(acctsessiontime) FROM radacct WHERE username = '%{User-Name}' AND acctstarttime BETWEEN FROM_UNIXTIME('1565992800') AND FROM_UNIXTIME('1566079200')'
>>> Sat Aug 17 18:23:36 2019 : Debug: %{sql:SELECT SUM(acctsessiontime) FROM radacct WHERE username = '%{User-Name}' AND acctstarttime BETWEEN FROM_UNIXTIME('1565992800') AND FROM_UNIXTIME('1566079200')}
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: xlat --> sql
>>> Sat Aug 17 18:23:36 2019 : Debug: {
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> SELECT SUM(acctsessiontime) FROM radacct WHERE username = '
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ' AND acctstarttime BETWEEN FROM_UNIXTIME('1565992800') AND FROM_UNIXTIME('1566079200')
>>> Sat Aug 17 18:23:36 2019 : Debug: }
>>> Sat Aug 17 18:23:36 2019 : Debug: %{User-Name}
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: EXPAND %{User-Name}
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: --> Robert
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: SQL-User-Name set to 'Robert'
>>> Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Reserved connection (7)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: Executing select query: SELECT SUM(acctsessiontime) FROM radacct WHERE username = 'Robert' AND acctstarttime BETWEEN FROM_UNIXTIME('1565992800') AND FROM_UNIXTIME('1566079200')
>>> Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Released connection (7)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: EXPAND %{sql:SELECT SUM(acctsessiontime) FROM radacct WHERE username = '%{User-Name}' AND acctstarttime BETWEEN FROM_UNIXTIME('1565992800') AND FROM_UNIXTIME('1566079200')}
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: --> 9927
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: Allowing user, &control:Max-Daily-Session value (10800) is greater than counter value (9927)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: Setting &reply:Session-Timeout value to 873
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from dailycounter (rlm_sqlcounter)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [dailycounter] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling expiration (rlm_expiration)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from expiration (rlm_expiration)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [expiration] = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling logintime (rlm_logintime)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) logintime: Checking Login-Time
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) logintime: Login within allowed time-slot, 18480 seconds left in this session
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) logintime: reply:Session-Timeout set to 18480
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from logintime (rlm_logintime)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [logintime] = updated
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling pap (rlm_pap)
>>> Sat Aug 17 18:23:36 2019 : WARNING: (10) pap: Auth-Type already set. Not setting to PAP
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from pap (rlm_pap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [pap] = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # authorize = updated
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Found Auth-Type = eap
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) # Executing group from file /etc/freeradius/3.0/sites-enabled/inner-tunnel
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) authenticate {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authenticate]: calling eap (rlm_eap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Expiring EAP session with state 0xba6ef1b9bb75eb14
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Finished EAP session with state 0xba6ef1b9bb75eb14
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Previous EAP request found for state 0xba6ef1b9bb75eb14, released from the list
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Peer sent packet with method EAP MSCHAPv2 (26)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Calling submodule eap_mschapv2 to process data
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Sending EAP Success (code 3) ID 27 length 4
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Freeing handler
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authenticate]: returned from eap (rlm_eap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [eap] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # authenticate = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) # Executing section session from file /etc/freeradius/3.0/sites-enabled/inner-tunnel
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) session {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[session]: calling sql (rlm_sql)
>>> Sat Aug 17 18:23:36 2019 : Debug: %{User-Name}
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND %{User-Name}
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> Robert
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: SQL-User-Name set to 'Robert'
>>> Sat Aug 17 18:23:36 2019 : Debug: SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> SELECT COUNT(*) FROM radacct WHERE username = '
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-User-Name
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ' AND acctstoptime IS NULL
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> SELECT COUNT(*) FROM radacct WHERE username = 'Robert' AND acctstoptime IS NULL
>>> Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Reserved connection (6)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Executing select query: SELECT COUNT(*) FROM radacct WHERE username = 'Robert' AND acctstoptime IS NULL
>>> Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Released connection (6)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[session]: returned from sql (rlm_sql)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [sql] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # session = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) # Executing section post-auth from file /etc/freeradius/3.0/sites-enabled/inner-tunnel
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) post-auth {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) update reply {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) User-Name := &request:User-Name -> 'Robert'
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Overwriting value "Robert" with "Robert"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # update reply = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[post-auth]: calling sql (rlm_sql)
>>> Sat Aug 17 18:23:36 2019 : Debug: .query
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> .query
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND .query
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> .query
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Using query template 'query'
>>> Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Reserved connection (8)
>>> Sat Aug 17 18:23:36 2019 : Debug: %{User-Name}
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND %{User-Name}
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> Robert
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: SQL-User-Name set to 'Robert'
>>> Sat Aug 17 18:23:36 2019 : Debug: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-User-Name
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ', '
>>> Sat Aug 17 18:23:36 2019 : Debug: XLAT-IF {
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Password
>>> Sat Aug 17 18:23:36 2019 : Debug: }
>>> Sat Aug 17 18:23:36 2019 : Debug: XLAT-ELSE {
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> CHAP-Password
>>> Sat Aug 17 18:23:36 2019 : Debug: }
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ', '
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> Packet-Type
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ', '
>>> Sat Aug 17 18:23:36 2019 : Debug: percent --> S
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ')
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'Robert', '', 'Access-Accept', '2019-08-17 18:23:36')
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'Robert', '', 'Access-Accept', '2019-08-17 18:23:36')
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: SQL query returned: success
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) sql: 1 record(s) updated
>>> Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Released connection (8)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[post-auth]: returned from sql (rlm_sql)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [sql] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (1) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (1) -> TRUE
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) if (1) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) update reply {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Message-Authenticator !* ANY
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) EAP-Message !* ANY
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Proxy-State !* ANY
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) MS-MPPE-Encryption-Types !* ANY
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) MS-MPPE-Encryption-Policy !* ANY
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) MS-MPPE-Send-Key !* ANY
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) MS-MPPE-Recv-Key !* ANY
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # update reply = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) update {
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Tunnel-Private-Group-Id += &reply:Tunnel-Private-Group-Id[*] -> '11'
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Tunnel-Type += &reply:Tunnel-Type[*] -> VLAN
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Tunnel-Medium-Type += &reply:Tunnel-Medium-Type[*] -> IEEE-802
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Fall-Through += &reply:Fall-Through[*] -> Yes
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Session-Timeout += &reply:Session-Timeout[*] -> 873
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Acct-Interim-Interval += &reply:Acct-Interim-Interval[*] -> 300
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Idle-Timeout += &reply:Idle-Timeout[*] -> 450
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Termination-Action += &reply:Termination-Action[*] -> RADIUS-Request
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::User-Name += &reply:User-Name[*] -> 'Robert'
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # update = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # if (1) = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # post-auth = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # server inner-tunnel
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Virtual server sending reply
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Tunnel-Private-Group-Id = "11"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Tunnel-Type = VLAN
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Tunnel-Medium-Type = IEEE-802
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Fall-Through = Yes
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Session-Timeout = 873
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Acct-Interim-Interval = 300
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Idle-Timeout = 450
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Termination-Action = RADIUS-Request
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) User-Name := "Robert"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Got tunneled reply code 2
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Tunnel-Private-Group-Id = "11"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Tunnel-Type = VLAN
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Tunnel-Medium-Type = IEEE-802
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Fall-Through = Yes
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Session-Timeout = 873
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Acct-Interim-Interval = 300
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Idle-Timeout = 450
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Termination-Action = RADIUS-Request
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: User-Name := "Robert"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Got tunneled reply RADIUS code 2
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Tunnel-Private-Group-Id = "11"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Tunnel-Type = VLAN
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Tunnel-Medium-Type = IEEE-802
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Fall-Through = Yes
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Session-Timeout = 873
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Acct-Interim-Interval = 300
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Idle-Timeout = 450
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Termination-Action = RADIUS-Request
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: User-Name := "Robert"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Tunneled authentication was successful
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: SUCCESS
>>> Sat Aug 17 18:23:36 2019 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Saving tunneled attributes for later
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Sending EAP Request (code 1) ID 28 length 46
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) eap: EAP session adding &reply:State = 0x7d7976aa74656f6c
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authenticate]: returned from eap (rlm_eap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) [eap] = handled
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) } # authenticate = handled
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Using Post-Auth-Type Challenge
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Post-Auth-Type sub-section not found. Ignoring.
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) session-state: Saving cached attributes
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Tunnel-Private-Group-Id += "11"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Tunnel-Type += VLAN
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Tunnel-Medium-Type += IEEE-802
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Session-Timeout += 873
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Acct-Interim-Interval += 300
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Idle-Timeout += 450
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Termination-Action += RADIUS-Request
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) User-Name += "Robert"
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Sent Access-Challenge Id 248 from 172.16.0.12:1812 to 172.16.0.5:48453 length 0
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) EAP-Message = 0x011c002e19001703030023b6cc9859d9e1d9fbccb915ae16456ad2c329aa053517b0282f4ff9fdf0e8bc45841a94
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Message-Authenticator = 0x00000000000000000000000000000000
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) State = 0x7d7976aa74656f6ce06082b82288935b
>>> Sat Aug 17 18:23:36 2019 : Debug: (10) Finished request
>>> Sat Aug 17 18:23:36 2019 : Debug: Waking up in 2.7 seconds.
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Received Access-Request Id 249 from 172.16.0.5:48453 to 172.16.0.12:1812 length 251
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) User-Name = "Robert"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) NAS-Identifier = "feec3a9aeda5"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Called-Station-Id = "FE-EC-3A-9A-ED-A5:Guest"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) NAS-Port-Type = Wireless-802.11
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Service-Type = Framed-User
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Calling-Station-Id = "04-DB-56-F0-C3-36"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Connect-Info = "CONNECT 0Mbps 802.11b"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Acct-Session-Id = "D9B312EA0EEDF1F6"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Mobility-Domain-Id = 1826
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) WLAN-Pairwise-Cipher = 1027076
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) WLAN-Group-Cipher = 1027076
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) WLAN-AKM-Suite = 1027075
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Framed-MTU = 1400
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) EAP-Message = 0x021c002e190017030300237ee7eda10323b327ee4332f9f48ce3978ef4ac3929fc08c00d246f066c893b4a182b1d
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) State = 0x7d7976aa74656f6ce06082b82288935b
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Message-Authenticator = 0xd6f3c9ee16eb98c8d0217d85c9804c2e
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Restoring &session-state
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:Tunnel-Private-Group-Id += "11"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:Tunnel-Type += VLAN
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:Tunnel-Medium-Type += IEEE-802
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:Session-Timeout += 873
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:Acct-Interim-Interval += 300
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:Idle-Timeout += 450
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:Termination-Action += RADIUS-Request
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:User-Name += "Robert"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) authorize {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) policy filter_username {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name) -> TRUE
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ / /) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ / /) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /@[^@]*@/ ) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /@[^@]*@/ ) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /\.\./ ) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /\.\./ ) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /\.$/) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /\.$/) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /@\./) {
>>> Sat Aug 17 18:23:36 2019 : Debug: No matches
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /@\./) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # if (&User-Name) = notfound
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # policy filter_username = notfound
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) policy filter_password {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Password && (&User-Password != "%{string:User-Password}")) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # policy filter_password = notfound
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: calling preprocess (rlm_preprocess)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: returned from preprocess (rlm_preprocess)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) [preprocess] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) update request {
>>> Sat Aug 17 18:23:36 2019 : Debug: %{User-Name}
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) EXPAND %{User-Name}
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) --> Robert
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) SQL-User-Name set to 'Robert'
>>> Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Reserved connection (7)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Executing select query: select groupname from radhuntgroup where nasipaddress="172.16.0.5"
>>> Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Released connection (7)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) EXPAND %{sql:select groupname from radhuntgroup where nasipaddress="%{NAS-IP-Address}"}
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) --> WiFi
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Huntgroup-Name := WiFi
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # update request = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: calling mschap (rlm_mschap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: returned from mschap (rlm_mschap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) [mschap] = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: calling suffix (rlm_realm)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) suffix: Checking for suffix after "@"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) suffix: No '@' in User-Name = "Robert", looking up realm NULL
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) suffix: No such realm "NULL"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: returned from suffix (rlm_realm)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) [suffix] = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: calling eap (rlm_eap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Peer sent EAP Response (code 2) ID 28 length 46
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Continuing tunnel setup
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: returned from eap (rlm_eap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) [eap] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # authorize = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Found Auth-Type = eap
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) authenticate {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authenticate]: calling eap (rlm_eap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Expiring EAP session with state 0x7d7976aa74656f6c
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Finished EAP session with state 0x7d7976aa74656f6c
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Previous EAP request found for state 0x7d7976aa74656f6c, released from the list
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Peer sent packet with method EAP PEAP (25)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Calling submodule eap_peap to process data
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Continuing EAP-TLS
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Peer sent flags ---
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: [eaptls verify] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Done initial handshake
>>> Sat Aug 17 18:23:36 2019 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: [eaptls process] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Session established. Decoding tunneled attributes
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: PEAP state send tlv success
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Received EAP-TLV response
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Success
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Using saved attributes from the original Access-Accept
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Tunnel-Private-Group-Id = "11"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Tunnel-Type = VLAN
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Tunnel-Medium-Type = IEEE-802
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Fall-Through = Yes
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Session-Timeout = 873
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Acct-Interim-Interval = 300
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Idle-Timeout = 450
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Termination-Action = RADIUS-Request
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: User-Name := "Robert"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Sending EAP Success (code 3) ID 28 length 4
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Freeing handler
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authenticate]: returned from eap (rlm_eap)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) [eap] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # authenticate = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) # Executing section post-auth from file /etc/freeradius/3.0/sites-enabled/default
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) post-auth {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (!&reply:State) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (!&reply:State) -> TRUE
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (!&reply:State) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) update reply {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) EXPAND 0x%{randstr:16h}
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) --> 0x8ce7b66eb9b9d607320857ccac1d3c220f
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) State := 0x8ce7b66eb9b9d607320857ccac1d3c220f
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # update reply = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # if (!&reply:State) = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) update {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::Tunnel-Private-Group-Id += &session-state:Tunnel-Private-Group-Id[*] -> '11'
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::Tunnel-Type += &session-state:Tunnel-Type[*] -> VLAN
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::Tunnel-Medium-Type += &session-state:Tunnel-Medium-Type[*] -> IEEE-802
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::Session-Timeout += &session-state:Session-Timeout[*] -> 873
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::Acct-Interim-Interval += &session-state:Acct-Interim-Interval[*] -> 300
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::Idle-Timeout += &session-state:Idle-Timeout[*] -> 450
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::Termination-Action += &session-state:Termination-Action[*] -> RADIUS-Request
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::User-Name += &session-state:User-Name[*] -> 'Robert'
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # update = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[post-auth]: calling sql (rlm_sql)
>>> Sat Aug 17 18:23:36 2019 : Debug: .query
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> .query
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) sql: EXPAND .query
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) sql: --> .query
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) sql: Using query template 'query'
>>> Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Reserved connection (6)
>>> Sat Aug 17 18:23:36 2019 : Debug: %{User-Name}
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) sql: EXPAND %{User-Name}
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) sql: --> Robert
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) sql: SQL-User-Name set to 'Robert'
>>> Sat Aug 17 18:23:36 2019 : Debug: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')
>>> Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree:
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-User-Name
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ', '
>>> Sat Aug 17 18:23:36 2019 : Debug: XLAT-IF {
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Password
>>> Sat Aug 17 18:23:36 2019 : Debug: }
>>> Sat Aug 17 18:23:36 2019 : Debug: XLAT-ELSE {
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> CHAP-Password
>>> Sat Aug 17 18:23:36 2019 : Debug: }
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ', '
>>> Sat Aug 17 18:23:36 2019 : Debug: attribute --> Packet-Type
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ', '
>>> Sat Aug 17 18:23:36 2019 : Debug: percent --> S
>>> Sat Aug 17 18:23:36 2019 : Debug: literal --> ')
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'Robert', '', 'Access-Accept', '2019-08-17 18:23:36')
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'Robert', '', 'Access-Accept', '2019-08-17 18:23:36')
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) sql: SQL query returned: success
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) sql: 1 record(s) updated
>>> Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Released connection (6)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[post-auth]: returned from sql (rlm_sql)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) [sql] = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[post-auth]: calling exec (rlm_exec)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[post-auth]: returned from exec (rlm_exec)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) [exec] = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) policy insert_acct_class {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) update reply {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) EXPAND ai:%{md5:%t,%I,%{Packet-Src-Port},%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}},%{NAS-IP-Address},%{Calling-Station-ID},%{User-Name}}
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) --> ai:acc29570a803c6c1a2268e867f1ed360
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) &Class = 0x61693a6163633239353730613830336336633161323236386538363766316564333630
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # update reply = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # policy insert_acct_class = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&reply:EAP-Session-Id) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&reply:EAP-Session-Id) -> TRUE
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&reply:EAP-Session-Id) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) update reply {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) EAP-Key-Name := &reply:EAP-Session-Id -> 0x195d582a086518d8626f3c8c8eb4ed1ae02b0e4d222b2363d0d6bb66028aebd9db3ec9aff3e280360a837f90ade646df976f66d4b2d287de285083a6df4935b8d7
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # update reply = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # if (&reply:EAP-Session-Id) = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) policy remove_reply_message_if_eap {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&reply:EAP-Message && &reply:Reply-Message) {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) else {
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[post-auth]: calling noop (rlm_always)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[post-auth]: returned from noop (rlm_always)
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) [noop] = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # else = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # policy remove_reply_message_if_eap = noop
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) } # post-auth = ok
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Sent Access-Accept Id 249 from 172.16.0.12:1812 to 172.16.0.5:48453 length 0
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Tunnel-Private-Group-Id = "11"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Tunnel-Type = VLAN
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Tunnel-Medium-Type = IEEE-802
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Session-Timeout = 873
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Acct-Interim-Interval = 300
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Idle-Timeout = 450
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Termination-Action = RADIUS-Request
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) User-Name := "Robert"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) MS-MPPE-Recv-Key = 0x452f2e97de2dbf05277fd62b8844b590145d436fb68df569f785b973c302e8c2
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) MS-MPPE-Send-Key = 0x4512fafa8219e461fbc3822b8f22ed4bde669628ef7a05918a3192c173cbfbaf
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) EAP-Message = 0x031c0004
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Message-Authenticator = 0x00000000000000000000000000000000
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) State := 0x8ce7b66eb9b9d607320857ccac1d3c220f
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Tunnel-Private-Group-Id += "11"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Tunnel-Type += VLAN
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Tunnel-Medium-Type += IEEE-802
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Session-Timeout += 873
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Acct-Interim-Interval += 300
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Idle-Timeout += 450
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Termination-Action += RADIUS-Request
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) User-Name += "Robert"
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Class = 0x61693a6163633239353730613830336336633161323236386538363766316564333630
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) EAP-Key-Name := 0x195d582a086518d8626f3c8c8eb4ed1ae02b0e4d222b2363d0d6bb66028aebd9db3ec9aff3e280360a837f90ade646df976f66d4b2d287de285083a6df4935b8d7
>>> Sat Aug 17 18:23:36 2019 : Debug: (11) Finished request
>>>
>>> ————————————————
>>>
>>>
>>>
>>> Server configuration:
>>> —————————————
>>> Sat Aug 17 18:20:38 2019 : Info: Starting - reading configuration files ...
>>> Sat Aug 17 18:20:38 2019 : Debug: including dictionary file /usr/share/freeradius/dictionary
>>> Sat Aug 17 18:20:38 2019 : Debug: including dictionary file /usr/share/freeradius/dictionary.dhcp
>>> Sat Aug 17 18:20:38 2019 : Debug: including dictionary file /usr/share/freeradius/dictionary.vqp
>>> Sat Aug 17 18:20:38 2019 : Debug: including dictionary file /etc/freeradius/3.0/dictionary
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/radiusd.conf
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/proxy.conf
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/clients.conf
>>> Sat Aug 17 18:20:38 2019 : Debug: including files in directory /etc/freeradius/3.0/mods-enabled/
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/attr_filter
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/cache_eap
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/chap
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/detail
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/detail.log
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/digest
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/dynamic_clients
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/eap
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/echo
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/exec
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/expiration
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/expr
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/files
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/linelog
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/logintime
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/mschap
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/ntlm_auth
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/pap
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/passwd
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/preprocess
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/radutmp
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/realm
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/replicate
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/soh
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/sradutmp
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/unix
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/unpack
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/utf8
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/sql
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-config/sql/main/mysql/queries.conf
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/sqlcounter
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-config/sql/counter/mysql/dailycounter.conf
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-config/sql/counter/mysql/monthlycounter.conf
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-config/sql/counter/mysql/noresetcounter.conf
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-config/sql/counter/mysql/expire_on_login.conf
>>> Sat Aug 17 18:20:38 2019 : Debug: including files in directory /etc/freeradius/3.0/policy.d/
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/abfab-tr
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/accounting
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/canonicalization
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/control
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/cui
>>> Sat Aug 17 18:20:38 2019 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE
>>> Sat Aug 17 18:20:38 2019 : Debug: OPTIMIZING (no == yes) --> FALSE
>>> Sat Aug 17 18:20:38 2019 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE
>>> Sat Aug 17 18:20:38 2019 : Debug: OPTIMIZING (no == yes) --> FALSE
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/debug
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/dhcp
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/eap
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/filter
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/moonshot-targeted-ids
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/operator-name
>>> Sat Aug 17 18:20:38 2019 : Debug: including files in directory /etc/freeradius/3.0/sites-enabled/
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/sites-enabled/default
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/sites-enabled/inner-tunnel
>>> Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/sites-enabled/status
>>> Sat Aug 17 18:20:38 2019 : Debug: main {
>>> Sat Aug 17 18:20:38 2019 : Debug: security {
>>> Sat Aug 17 18:20:38 2019 : Debug: user = "freerad"
>>> Sat Aug 17 18:20:38 2019 : Debug: group = "freerad"
>>> Sat Aug 17 18:20:38 2019 : Debug: allow_core_dumps = no
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[424]: The item 'max_attributes' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[442]: The item 'reject_delay' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[462]: The item 'status_server' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: name = "freeradius"
>>> Sat Aug 17 18:20:38 2019 : Debug: prefix = "/usr"
>>> Sat Aug 17 18:20:38 2019 : Debug: localstatedir = "/var"
>>> Sat Aug 17 18:20:38 2019 : Debug: logdir = "/var/log/freeradius"
>>> Sat Aug 17 18:20:38 2019 : Debug: run_dir = "/var/run/freeradius"
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[55]: The item 'sysconfdir' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[108]: The item 'libdir' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[119]: The item 'pidfile' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[194]: The item 'max_request_time' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[213]: The item 'cleanup_delay' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[250]: The item 'hostname_lookups' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[334]: The item 'checkrad' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[483]: The item 'proxy_requests' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: main {
>>> Sat Aug 17 18:20:38 2019 : Debug: name = "freeradius"
>>> Sat Aug 17 18:20:38 2019 : Debug: prefix = "/usr"
>>> Sat Aug 17 18:20:38 2019 : Debug: localstatedir = "/var"
>>> Sat Aug 17 18:20:38 2019 : Debug: sbindir = "/usr/sbin"
>>> Sat Aug 17 18:20:38 2019 : Debug: logdir = "/var/log/freeradius"
>>> Sat Aug 17 18:20:38 2019 : Debug: run_dir = "/var/run/freeradius"
>>> Sat Aug 17 18:20:38 2019 : Debug: libdir = "/usr/lib/freeradius"
>>> Sat Aug 17 18:20:38 2019 : Debug: radacctdir = "/var/log/freeradius/radacct"
>>> Sat Aug 17 18:20:38 2019 : Debug: hostname_lookups = no
>>> Sat Aug 17 18:20:38 2019 : Debug: max_request_time = 15
>>> Sat Aug 17 18:20:38 2019 : Debug: cleanup_delay = 3
>>> Sat Aug 17 18:20:38 2019 : Debug: max_requests = 16384
>>> Sat Aug 17 18:20:38 2019 : Debug: pidfile = "/var/run/freeradius/freeradius.pid"
>>> Sat Aug 17 18:20:38 2019 : Debug: checkrad = "/usr/sbin/checkrad"
>>> Sat Aug 17 18:20:38 2019 : Debug: debug_level = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: proxy_requests = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: log {
>>> Sat Aug 17 18:20:38 2019 : Debug: stripped_names = no
>>> Sat Aug 17 18:20:38 2019 : Debug: auth = no
>>> Sat Aug 17 18:20:38 2019 : Debug: auth_badpass = no
>>> Sat Aug 17 18:20:38 2019 : Debug: auth_goodpass = no
>>> Sat Aug 17 18:20:38 2019 : Debug: colourise = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: msg_denied = "You are already logged in - access denied"
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[268]: The item 'destination' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[285]: The item 'file' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[293]: The item 'syslog_facility' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: resources {
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: security {
>>> Sat Aug 17 18:20:38 2019 : Debug: max_attributes = 200
>>> Sat Aug 17 18:20:38 2019 : Debug: reject_delay = 1.000000
>>> Sat Aug 17 18:20:38 2019 : Debug: status_server = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[55]: The item 'sysconfdir' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configuration
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: radiusd: #### Loading Realms and Home Servers ####
>>> Sat Aug 17 18:20:38 2019 : Debug: proxy server {
>>> Sat Aug 17 18:20:38 2019 : Debug: retry_delay = 5
>>> Sat Aug 17 18:20:38 2019 : Debug: retry_count = 3
>>> Sat Aug 17 18:20:38 2019 : Debug: default_fallback = no
>>> Sat Aug 17 18:20:38 2019 : Debug: dead_time = 120
>>> Sat Aug 17 18:20:38 2019 : Debug: wake_all_if_all_dead = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: home_server localhost {
>>> Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 127.0.0.1
>>> Sat Aug 17 18:20:38 2019 : Debug: port = 1812
>>> Sat Aug 17 18:20:38 2019 : Debug: type = "auth"
>>> Sat Aug 17 18:20:38 2019 : Debug: secret = "testing123"
>>> Sat Aug 17 18:20:38 2019 : Debug: response_window = 20.000000
>>> Sat Aug 17 18:20:38 2019 : Debug: response_timeouts = 1
>>> Sat Aug 17 18:20:38 2019 : Debug: max_outstanding = 65536
>>> Sat Aug 17 18:20:38 2019 : Debug: zombie_period = 40
>>> Sat Aug 17 18:20:38 2019 : Debug: status_check = "status-server"
>>> Sat Aug 17 18:20:38 2019 : Debug: ping_interval = 30
>>> Sat Aug 17 18:20:38 2019 : Debug: check_interval = 30
>>> Sat Aug 17 18:20:38 2019 : Debug: check_timeout = 4
>>> Sat Aug 17 18:20:38 2019 : Debug: num_answers_to_alive = 3
>>> Sat Aug 17 18:20:38 2019 : Debug: revive_interval = 120
>>> Sat Aug 17 18:20:38 2019 : Debug: limit {
>>> Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16
>>> Sat Aug 17 18:20:38 2019 : Debug: max_requests = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: coa {
>>> Sat Aug 17 18:20:38 2019 : Debug: irt = 2
>>> Sat Aug 17 18:20:38 2019 : Debug: mrt = 16
>>> Sat Aug 17 18:20:38 2019 : Debug: mrc = 5
>>> Sat Aug 17 18:20:38 2019 : Debug: mrd = 30
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Warning: WARNING: Ignoring "response_window = 20.000000", forcing to "response_window = 15.000000"
>>> Sat Aug 17 18:20:38 2019 : Debug: home_server_pool my_auth_failover {
>>> Sat Aug 17 18:20:38 2019 : Debug: type = fail-over
>>> Sat Aug 17 18:20:38 2019 : Debug: home_server = localhost
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: realm example.com {
>>> Sat Aug 17 18:20:38 2019 : Debug: auth_pool = my_auth_failover
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: realm LOCAL {
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: radiusd: #### Loading Clients ####
>>> Sat Aug 17 18:20:38 2019 : Debug: client localhost {
>>> Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 127.0.0.1
>>> Sat Aug 17 18:20:38 2019 : Debug: require_message_authenticator = no
>>> Sat Aug 17 18:20:38 2019 : Debug: secret = "testing123"
>>> Sat Aug 17 18:20:38 2019 : Debug: nas_type = "other"
>>> Sat Aug 17 18:20:38 2019 : Debug: proto = "*"
>>> Sat Aug 17 18:20:38 2019 : Debug: limit {
>>> Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16
>>> Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 30
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Adding client 127.0.0.1/32 (127.0.0.1) to prefix tree 32
>>> Sat Aug 17 18:20:38 2019 : Debug: client localhost_ipv6 {
>>> Sat Aug 17 18:20:38 2019 : Debug: ipv6addr = ::1
>>> Sat Aug 17 18:20:38 2019 : Debug: require_message_authenticator = no
>>> Sat Aug 17 18:20:38 2019 : Debug: secret = "testing123"
>>> Sat Aug 17 18:20:38 2019 : Debug: limit {
>>> Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16
>>> Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 30
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Adding client ::1/128 (::1) to prefix tree 128
>>> Sat Aug 17 18:20:38 2019 : Info: Debug state unknown (cap_sys_ptrace capability not set)
>>> Sat Aug 17 18:20:38 2019 : Debug: # Creating Auth-Type = mschap
>>> Sat Aug 17 18:20:38 2019 : Debug: # Creating Auth-Type = eap
>>> Sat Aug 17 18:20:38 2019 : Debug: # Creating Auth-Type = PAP
>>> Sat Aug 17 18:20:38 2019 : Debug: # Creating Auth-Type = MS-CHAP
>>> Sat Aug 17 18:20:38 2019 : Debug: # Creating Autz-Type = radius-status
>>> Sat Aug 17 18:20:38 2019 : Debug: # Creating Acct-Type = radius-status
>>> Sat Aug 17 18:20:38 2019 : Debug: radiusd: #### Instantiating modules ####
>>> Sat Aug 17 18:20:38 2019 : Debug: modules {
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_always with path: /usr/lib/freeradius/rlm_always.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_always, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_always
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "reject" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: always reject {
>>> Sat Aug 17 18:20:38 2019 : Debug: rcode = "reject"
>>> Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: mpp = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "fail" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: always fail {
>>> Sat Aug 17 18:20:38 2019 : Debug: rcode = "fail"
>>> Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: mpp = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "ok" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: always ok {
>>> Sat Aug 17 18:20:38 2019 : Debug: rcode = "ok"
>>> Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: mpp = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "handled" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: always handled {
>>> Sat Aug 17 18:20:38 2019 : Debug: rcode = "handled"
>>> Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: mpp = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "invalid" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: always invalid {
>>> Sat Aug 17 18:20:38 2019 : Debug: rcode = "invalid"
>>> Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: mpp = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "userlock" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: always userlock {
>>> Sat Aug 17 18:20:38 2019 : Debug: rcode = "userlock"
>>> Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: mpp = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "notfound" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: always notfound {
>>> Sat Aug 17 18:20:38 2019 : Debug: rcode = "notfound"
>>> Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: mpp = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "noop" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: always noop {
>>> Sat Aug 17 18:20:38 2019 : Debug: rcode = "noop"
>>> Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: mpp = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "updated" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: always updated {
>>> Sat Aug 17 18:20:38 2019 : Debug: rcode = "updated"
>>> Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: mpp = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_attr_filter with path: /usr/lib/freeradius/rlm_attr_filter.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_attr_filter, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_attr_filter
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "attr_filter.post-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter
>>> Sat Aug 17 18:20:38 2019 : Debug: attr_filter attr_filter.post-proxy {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/post-proxy"
>>> Sat Aug 17 18:20:38 2019 : Debug: key = "%{Realm}"
>>> Sat Aug 17 18:20:38 2019 : Debug: relaxed = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "attr_filter.pre-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter
>>> Sat Aug 17 18:20:38 2019 : Debug: attr_filter attr_filter.pre-proxy {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/pre-proxy"
>>> Sat Aug 17 18:20:38 2019 : Debug: key = "%{Realm}"
>>> Sat Aug 17 18:20:38 2019 : Debug: relaxed = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "attr_filter.access_reject" from file /etc/freeradius/3.0/mods-enabled/attr_filter
>>> Sat Aug 17 18:20:38 2019 : Debug: attr_filter attr_filter.access_reject {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/access_reject"
>>> Sat Aug 17 18:20:38 2019 : Debug: key = "%{User-Name}"
>>> Sat Aug 17 18:20:38 2019 : Debug: relaxed = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "attr_filter.access_challenge" from file /etc/freeradius/3.0/mods-enabled/attr_filter
>>> Sat Aug 17 18:20:38 2019 : Debug: attr_filter attr_filter.access_challenge {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/access_challenge"
>>> Sat Aug 17 18:20:38 2019 : Debug: key = "%{User-Name}"
>>> Sat Aug 17 18:20:38 2019 : Debug: relaxed = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "attr_filter.accounting_response" from file /etc/freeradius/3.0/mods-enabled/attr_filter
>>> Sat Aug 17 18:20:38 2019 : Debug: attr_filter attr_filter.accounting_response {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/accounting_response"
>>> Sat Aug 17 18:20:38 2019 : Debug: key = "%{User-Name}"
>>> Sat Aug 17 18:20:38 2019 : Debug: relaxed = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_cache with path: /usr/lib/freeradius/rlm_cache.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_cache, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_cache
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "cache_eap" from file /etc/freeradius/3.0/mods-enabled/cache_eap
>>> Sat Aug 17 18:20:38 2019 : Debug: cache cache_eap {
>>> Sat Aug 17 18:20:38 2019 : Debug: driver = "rlm_cache_rbtree"
>>> Sat Aug 17 18:20:38 2019 : Debug: key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}"
>>> Sat Aug 17 18:20:38 2019 : Debug: ttl = 15
>>> Sat Aug 17 18:20:38 2019 : Debug: max_entries = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: epoch = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: add_stats = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_chap with path: /usr/lib/freeradius/rlm_chap.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_chap, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_chap
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "chap" from file /etc/freeradius/3.0/mods-enabled/chap
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_detail with path: /usr/lib/freeradius/rlm_detail.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_detail, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_detail
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "detail" from file /etc/freeradius/3.0/mods-enabled/detail
>>> Sat Aug 17 18:20:38 2019 : Debug: detail {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
>>> Sat Aug 17 18:20:38 2019 : Debug: header = "%t"
>>> Sat Aug 17 18:20:38 2019 : Debug: permissions = 384
>>> Sat Aug 17 18:20:38 2019 : Debug: locking = no
>>> Sat Aug 17 18:20:38 2019 : Debug: escape_filenames = no
>>> Sat Aug 17 18:20:38 2019 : Debug: log_packet_header = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "auth_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
>>> Sat Aug 17 18:20:38 2019 : Debug: detail auth_log {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d"
>>> Sat Aug 17 18:20:38 2019 : Debug: header = "%t"
>>> Sat Aug 17 18:20:38 2019 : Debug: permissions = 384
>>> Sat Aug 17 18:20:38 2019 : Debug: locking = no
>>> Sat Aug 17 18:20:38 2019 : Debug: escape_filenames = no
>>> Sat Aug 17 18:20:38 2019 : Debug: log_packet_header = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "reply_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
>>> Sat Aug 17 18:20:38 2019 : Debug: detail reply_log {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d"
>>> Sat Aug 17 18:20:38 2019 : Debug: header = "%t"
>>> Sat Aug 17 18:20:38 2019 : Debug: permissions = 384
>>> Sat Aug 17 18:20:38 2019 : Debug: locking = no
>>> Sat Aug 17 18:20:38 2019 : Debug: escape_filenames = no
>>> Sat Aug 17 18:20:38 2019 : Debug: log_packet_header = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "pre_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
>>> Sat Aug 17 18:20:38 2019 : Debug: detail pre_proxy_log {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d"
>>> Sat Aug 17 18:20:38 2019 : Debug: header = "%t"
>>> Sat Aug 17 18:20:38 2019 : Debug: permissions = 384
>>> Sat Aug 17 18:20:38 2019 : Debug: locking = no
>>> Sat Aug 17 18:20:38 2019 : Debug: escape_filenames = no
>>> Sat Aug 17 18:20:38 2019 : Debug: log_packet_header = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "post_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
>>> Sat Aug 17 18:20:38 2019 : Debug: detail post_proxy_log {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d"
>>> Sat Aug 17 18:20:38 2019 : Debug: header = "%t"
>>> Sat Aug 17 18:20:38 2019 : Debug: permissions = 384
>>> Sat Aug 17 18:20:38 2019 : Debug: locking = no
>>> Sat Aug 17 18:20:38 2019 : Debug: escape_filenames = no
>>> Sat Aug 17 18:20:38 2019 : Debug: log_packet_header = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_digest with path: /usr/lib/freeradius/rlm_digest.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_digest, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_digest
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "digest" from file /etc/freeradius/3.0/mods-enabled/digest
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_dynamic_clients with path: /usr/lib/freeradius/rlm_dynamic_clients.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_dynamic_clients, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_dynamic_clients
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "dynamic_clients" from file /etc/freeradius/3.0/mods-enabled/dynamic_clients
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_eap with path: /usr/lib/freeradius/rlm_eap.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_eap, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_eap
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "eap" from file /etc/freeradius/3.0/mods-enabled/eap
>>> Sat Aug 17 18:20:38 2019 : Debug: eap {
>>> Sat Aug 17 18:20:38 2019 : Debug: default_eap_type = "peap"
>>> Sat Aug 17 18:20:38 2019 : Debug: timer_expire = 60
>>> Sat Aug 17 18:20:38 2019 : Debug: ignore_unknown_eap_types = no
>>> Sat Aug 17 18:20:38 2019 : Debug: cisco_accounting_username_bug = no
>>> Sat Aug 17 18:20:38 2019 : Debug: max_sessions = 16384
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_exec with path: /usr/lib/freeradius/rlm_exec.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_exec, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_exec
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "echo" from file /etc/freeradius/3.0/mods-enabled/echo
>>> Sat Aug 17 18:20:38 2019 : Debug: exec echo {
>>> Sat Aug 17 18:20:38 2019 : Debug: wait = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: program = "/bin/echo %{User-Name}"
>>> Sat Aug 17 18:20:38 2019 : Debug: input_pairs = "request"
>>> Sat Aug 17 18:20:38 2019 : Debug: output_pairs = "reply"
>>> Sat Aug 17 18:20:38 2019 : Debug: shell_escape = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "exec" from file /etc/freeradius/3.0/mods-enabled/exec
>>> Sat Aug 17 18:20:38 2019 : Debug: exec {
>>> Sat Aug 17 18:20:38 2019 : Debug: wait = no
>>> Sat Aug 17 18:20:38 2019 : Debug: input_pairs = "request"
>>> Sat Aug 17 18:20:38 2019 : Debug: shell_escape = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: timeout = 10
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_expiration with path: /usr/lib/freeradius/rlm_expiration.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_expiration, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_expiration
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "expiration" from file /etc/freeradius/3.0/mods-enabled/expiration
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_expr with path: /usr/lib/freeradius/rlm_expr.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_expr, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_expr
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "expr" from file /etc/freeradius/3.0/mods-enabled/expr
>>> Sat Aug 17 18:20:38 2019 : Debug: expr {
>>> Sat Aug 17 18:20:38 2019 : Debug: safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_files with path: /usr/lib/freeradius/rlm_files.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_files, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_files
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "files" from file /etc/freeradius/3.0/mods-enabled/files
>>> Sat Aug 17 18:20:38 2019 : Debug: files {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/files/authorize"
>>> Sat Aug 17 18:20:38 2019 : Debug: acctusersfile = "/etc/freeradius/3.0/mods-config/files/accounting"
>>> Sat Aug 17 18:20:38 2019 : Debug: preproxy_usersfile = "/etc/freeradius/3.0/mods-config/files/pre-proxy"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_linelog with path: /usr/lib/freeradius/rlm_linelog.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_linelog, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_linelog
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "linelog" from file /etc/freeradius/3.0/mods-enabled/linelog
>>> Sat Aug 17 18:20:38 2019 : Debug: linelog {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/linelog"
>>> Sat Aug 17 18:20:38 2019 : Debug: escape_filenames = no
>>> Sat Aug 17 18:20:38 2019 : Debug: syslog_severity = "info"
>>> Sat Aug 17 18:20:38 2019 : Debug: permissions = 384
>>> Sat Aug 17 18:20:38 2019 : Debug: format = "This is a log message for %{User-Name}"
>>> Sat Aug 17 18:20:38 2019 : Debug: reference = "messages.%{%{reply:Packet-Type}:-default}"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "log_accounting" from file /etc/freeradius/3.0/mods-enabled/linelog
>>> Sat Aug 17 18:20:38 2019 : Debug: linelog log_accounting {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/linelog-accounting"
>>> Sat Aug 17 18:20:38 2019 : Debug: escape_filenames = no
>>> Sat Aug 17 18:20:38 2019 : Debug: syslog_severity = "info"
>>> Sat Aug 17 18:20:38 2019 : Debug: permissions = 384
>>> Sat Aug 17 18:20:38 2019 : Debug: format = ""
>>> Sat Aug 17 18:20:38 2019 : Debug: reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_logintime with path: /usr/lib/freeradius/rlm_logintime.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_logintime, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_logintime
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "logintime" from file /etc/freeradius/3.0/mods-enabled/logintime
>>> Sat Aug 17 18:20:38 2019 : Debug: logintime {
>>> Sat Aug 17 18:20:38 2019 : Debug: minimum_timeout = 60
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_mschap with path: /usr/lib/freeradius/rlm_mschap.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_mschap, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_mschap
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "mschap" from file /etc/freeradius/3.0/mods-enabled/mschap
>>> Sat Aug 17 18:20:38 2019 : Debug: mschap {
>>> Sat Aug 17 18:20:38 2019 : Debug: use_mppe = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: require_encryption = no
>>> Sat Aug 17 18:20:38 2019 : Debug: require_strong = no
>>> Sat Aug 17 18:20:38 2019 : Debug: with_ntdomain_hack = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: passchange {
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: allow_retry = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: winbind_retry_with_normalised_username = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "ntlm_auth" from file /etc/freeradius/3.0/mods-enabled/ntlm_auth
>>> Sat Aug 17 18:20:38 2019 : Debug: exec ntlm_auth {
>>> Sat Aug 17 18:20:38 2019 : Debug: wait = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}"
>>> Sat Aug 17 18:20:38 2019 : Debug: shell_escape = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_pap with path: /usr/lib/freeradius/rlm_pap.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_pap, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_pap
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "pap" from file /etc/freeradius/3.0/mods-enabled/pap
>>> Sat Aug 17 18:20:38 2019 : Debug: pap {
>>> Sat Aug 17 18:20:38 2019 : Debug: normalise = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_passwd with path: /usr/lib/freeradius/rlm_passwd.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_passwd, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_passwd
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "etc_passwd" from file /etc/freeradius/3.0/mods-enabled/passwd
>>> Sat Aug 17 18:20:38 2019 : Debug: passwd etc_passwd {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/etc/passwd"
>>> Sat Aug 17 18:20:38 2019 : Debug: format = "*User-Name:Crypt-Password:"
>>> Sat Aug 17 18:20:38 2019 : Debug: delimiter = ":"
>>> Sat Aug 17 18:20:38 2019 : Debug: ignore_nislike = no
>>> Sat Aug 17 18:20:38 2019 : Debug: ignore_empty = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: allow_multiple_keys = no
>>> Sat Aug 17 18:20:38 2019 : Debug: hash_size = 100
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_preprocess with path: /usr/lib/freeradius/rlm_preprocess.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_preprocess, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_preprocess
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "preprocess" from file /etc/freeradius/3.0/mods-enabled/preprocess
>>> Sat Aug 17 18:20:38 2019 : Debug: preprocess {
>>> Sat Aug 17 18:20:38 2019 : Debug: huntgroups = "/etc/freeradius/3.0/mods-config/preprocess/huntgroups"
>>> Sat Aug 17 18:20:38 2019 : Debug: hints = "/etc/freeradius/3.0/mods-config/preprocess/hints"
>>> Sat Aug 17 18:20:38 2019 : Debug: with_ascend_hack = no
>>> Sat Aug 17 18:20:38 2019 : Debug: ascend_channels_per_line = 23
>>> Sat Aug 17 18:20:38 2019 : Debug: with_ntdomain_hack = no
>>> Sat Aug 17 18:20:38 2019 : Debug: with_specialix_jetstream_hack = no
>>> Sat Aug 17 18:20:38 2019 : Debug: with_cisco_vsa_hack = no
>>> Sat Aug 17 18:20:38 2019 : Debug: with_alvarion_vsa_hack = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_radutmp with path: /usr/lib/freeradius/rlm_radutmp.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_radutmp, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_radutmp
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "radutmp" from file /etc/freeradius/3.0/mods-enabled/radutmp
>>> Sat Aug 17 18:20:38 2019 : Debug: radutmp {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/radutmp"
>>> Sat Aug 17 18:20:38 2019 : Debug: username = "%{User-Name}"
>>> Sat Aug 17 18:20:38 2019 : Debug: case_sensitive = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: check_with_nas = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: permissions = 384
>>> Sat Aug 17 18:20:38 2019 : Debug: caller_id = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_realm with path: /usr/lib/freeradius/rlm_realm.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_realm, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_realm
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "IPASS" from file /etc/freeradius/3.0/mods-enabled/realm
>>> Sat Aug 17 18:20:38 2019 : Debug: realm IPASS {
>>> Sat Aug 17 18:20:38 2019 : Debug: format = "prefix"
>>> Sat Aug 17 18:20:38 2019 : Debug: delimiter = "/"
>>> Sat Aug 17 18:20:38 2019 : Debug: ignore_default = no
>>> Sat Aug 17 18:20:38 2019 : Debug: ignore_null = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "suffix" from file /etc/freeradius/3.0/mods-enabled/realm
>>> Sat Aug 17 18:20:38 2019 : Debug: realm suffix {
>>> Sat Aug 17 18:20:38 2019 : Debug: format = "suffix"
>>> Sat Aug 17 18:20:38 2019 : Debug: delimiter = "@"
>>> Sat Aug 17 18:20:38 2019 : Debug: ignore_default = no
>>> Sat Aug 17 18:20:38 2019 : Debug: ignore_null = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "realmpercent" from file /etc/freeradius/3.0/mods-enabled/realm
>>> Sat Aug 17 18:20:38 2019 : Debug: realm realmpercent {
>>> Sat Aug 17 18:20:38 2019 : Debug: format = "suffix"
>>> Sat Aug 17 18:20:38 2019 : Debug: delimiter = "%"
>>> Sat Aug 17 18:20:38 2019 : Debug: ignore_default = no
>>> Sat Aug 17 18:20:38 2019 : Debug: ignore_null = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "ntdomain" from file /etc/freeradius/3.0/mods-enabled/realm
>>> Sat Aug 17 18:20:38 2019 : Debug: realm ntdomain {
>>> Sat Aug 17 18:20:38 2019 : Debug: format = "prefix"
>>> Sat Aug 17 18:20:38 2019 : Debug: delimiter = "\\"
>>> Sat Aug 17 18:20:38 2019 : Debug: ignore_default = no
>>> Sat Aug 17 18:20:38 2019 : Debug: ignore_null = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_replicate with path: /usr/lib/freeradius/rlm_replicate.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_replicate, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_replicate
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "replicate" from file /etc/freeradius/3.0/mods-enabled/replicate
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_soh with path: /usr/lib/freeradius/rlm_soh.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_soh, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_soh
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "soh" from file /etc/freeradius/3.0/mods-enabled/soh
>>> Sat Aug 17 18:20:38 2019 : Debug: soh {
>>> Sat Aug 17 18:20:38 2019 : Debug: dhcp = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "sradutmp" from file /etc/freeradius/3.0/mods-enabled/sradutmp
>>> Sat Aug 17 18:20:38 2019 : Debug: radutmp sradutmp {
>>> Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/sradutmp"
>>> Sat Aug 17 18:20:38 2019 : Debug: username = "%{User-Name}"
>>> Sat Aug 17 18:20:38 2019 : Debug: case_sensitive = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: check_with_nas = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: permissions = 420
>>> Sat Aug 17 18:20:38 2019 : Debug: caller_id = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_unix with path: /usr/lib/freeradius/rlm_unix.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_unix, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_unix
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "unix" from file /etc/freeradius/3.0/mods-enabled/unix
>>> Sat Aug 17 18:20:38 2019 : Debug: unix {
>>> Sat Aug 17 18:20:38 2019 : Debug: radwtmp = "/var/log/freeradius/radwtmp"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Creating attribute Unix-Group
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_unpack with path: /usr/lib/freeradius/rlm_unpack.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_unpack, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_unpack
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "unpack" from file /etc/freeradius/3.0/mods-enabled/unpack
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_utf8 with path: /usr/lib/freeradius/rlm_utf8.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_utf8, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_utf8
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "utf8" from file /etc/freeradius/3.0/mods-enabled/utf8
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_sql with path: /usr/lib/freeradius/rlm_sql.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_sql, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_sql
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "sql" from file /etc/freeradius/3.0/mods-enabled/sql
>>> Sat Aug 17 18:20:38 2019 : Debug: sql {
>>> Sat Aug 17 18:20:38 2019 : Debug: driver = "rlm_sql_mysql"
>>> Sat Aug 17 18:20:38 2019 : Debug: server = "localhost"
>>> Sat Aug 17 18:20:38 2019 : Debug: port = 3306
>>> Sat Aug 17 18:20:38 2019 : Debug: login = "root"
>>> Sat Aug 17 18:20:38 2019 : Debug: password = "XXXX"
>>> Sat Aug 17 18:20:38 2019 : Debug: radius_db = "radius"
>>> Sat Aug 17 18:20:38 2019 : Debug: read_groups = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: read_profiles = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: read_clients = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: delete_stale_sessions = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: sql_user_name = "%{User-Name}"
>>> Sat Aug 17 18:20:38 2019 : Debug: default_user_profile = ""
>>> Sat Aug 17 18:20:38 2019 : Debug: client_query = "SELECT id, nasname, shortname, type, secret, server FROM nas"
>>> Sat Aug 17 18:20:38 2019 : Debug: authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id"
>>> Sat Aug 17 18:20:38 2019 : Debug: authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id"
>>> Sat Aug 17 18:20:38 2019 : Debug: authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id"
>>> Sat Aug 17 18:20:38 2019 : Debug: authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id"
>>> Sat Aug 17 18:20:38 2019 : Debug: group_membership_query = "SELECT groupname FROM radusergroup WHERE username = BINARY '%{SQL-User-Name}' ORDER BY priority"
>>> Sat Aug 17 18:20:38 2019 : Debug: simul_count_query = "SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL"
>>> Sat Aug 17 18:20:38 2019 : Debug: simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL"
>>> Sat Aug 17 18:20:38 2019 : Debug: safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
>>> Sat Aug 17 18:20:38 2019 : Debug: query_timeout = 5
>>> Sat Aug 17 18:20:38 2019 : Debug: accounting {
>>> Sat Aug 17 18:20:38 2019 : Debug: reference = "%{tolower:type.%{Acct-Status-Type}.query}"
>>> Sat Aug 17 18:20:38 2019 : Debug: type {
>>> Sat Aug 17 18:20:38 2019 : Debug: accounting-on {
>>> Sat Aug 17 18:20:38 2019 : Debug: query = "UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = '%{integer:Event-Timestamp}' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= FROM_UNIXTIME(%{integer:Event-Timestamp})"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: accounting-off {
>>> Sat Aug 17 18:20:38 2019 : Debug: query = "UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = '%{integer:Event-Timestamp}' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= FROM_UNIXTIME(%{integer:Event-Timestamp})"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: start {
>>> Sat Aug 17 18:20:38 2019 : Debug: query = "INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctupdatetime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop,acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{%{NAS-Port-ID}:-%{NAS-Port}}', '%{NAS-Port-Type}', FROM_UNIXTIME(%{integer:Event-Timestamp}), FROM_UNIXTIME(%{integer:Event-Timestamp}), NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}')"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: interim-update {
>>> Sat Aug 17 18:20:38 2019 : Debug: query = "UPDATE radacct SET acctupdatetime = (@acctupdatetime_old:=acctupdatetime), acctupdatetime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctinterval = %{integer:Event-Timestamp} - UNIX_TIMESTAMP(@acctupdatetime_old), framedipaddress = '%{Framed-IP-Address}', acctsessiontime = %{%{Acct-Session-Time}:-NULL}, acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: stop {
>>> Sat Aug 17 18:20:38 2019 : Debug: query = "UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = %{%{Acct-Session-Time}:-NULL}, acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', connectinfo_stop = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: post-auth {
>>> Sat Aug 17 18:20:38 2019 : Debug: reference = ".query"
>>> Sat Aug 17 18:20:38 2019 : Debug: query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_sql_mysql with path: /usr/lib/freeradius/rlm_sql_mysql.so
>>> Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
>>> Sat Aug 17 18:20:38 2019 : Debug: Creating attribute SQL-Group
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_sqlcounter with path: /usr/lib/freeradius/rlm_sqlcounter.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_sqlcounter, checking if it's valid
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_sqlcounter
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "dailycounter" from file /etc/freeradius/3.0/mods-enabled/sqlcounter
>>> Sat Aug 17 18:20:38 2019 : Debug: sqlcounter dailycounter {
>>> Sat Aug 17 18:20:38 2019 : Debug: sql_module_instance = "sql"
>>> Sat Aug 17 18:20:38 2019 : Debug: key = "User-Name"
>>> Sat Aug 17 18:20:38 2019 : Debug: query = "SELECT SUM(acctsessiontime) FROM radacct WHERE username = '%{User-Name}' AND acctstarttime BETWEEN FROM_UNIXTIME('%%b') AND FROM_UNIXTIME('%%e')"
>>> Sat Aug 17 18:20:38 2019 : Debug: reset = "daily"
>>> Sat Aug 17 18:20:38 2019 : Debug: counter_name = "Daily-Session-Time"
>>> Sat Aug 17 18:20:38 2019 : Debug: check_name = "Max-Daily-Session"
>>> Sat Aug 17 18:20:38 2019 : Debug: reply_name = "Session-Timeout"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "monthlycounter" from file /etc/freeradius/3.0/mods-enabled/sqlcounter
>>> Sat Aug 17 18:20:38 2019 : Debug: sqlcounter monthlycounter {
>>> Sat Aug 17 18:20:38 2019 : Debug: sql_module_instance = "sql"
>>> Sat Aug 17 18:20:38 2019 : Debug: key = "User-Name"
>>> Sat Aug 17 18:20:38 2019 : Debug: query = "SELECT SUM(acctsessiontime - GREATEST((%%b - UNIX_TIMESTAMP(acctstarttime)), 0)) FROM radacct WHERE username='%{User-Name}' AND UNIX_TIMESTAMP(acctstarttime) + acctsessiontime > '%%b'"
>>> Sat Aug 17 18:20:38 2019 : Debug: reset = "monthly"
>>> Sat Aug 17 18:20:38 2019 : Debug: counter_name = "Monthly-Session-Time"
>>> Sat Aug 17 18:20:38 2019 : Debug: check_name = "Max-Monthly-Session"
>>> Sat Aug 17 18:20:38 2019 : Debug: reply_name = "Session-Timeout"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "noresetcounter" from file /etc/freeradius/3.0/mods-enabled/sqlcounter
>>> Sat Aug 17 18:20:38 2019 : Debug: sqlcounter noresetcounter {
>>> Sat Aug 17 18:20:38 2019 : Debug: sql_module_instance = "sql"
>>> Sat Aug 17 18:20:38 2019 : Debug: key = "User-Name"
>>> Sat Aug 17 18:20:38 2019 : Debug: query = "SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='%{User-Name}'"
>>> Sat Aug 17 18:20:38 2019 : Debug: reset = "never"
>>> Sat Aug 17 18:20:38 2019 : Debug: counter_name = "Max-All-Session-Time"
>>> Sat Aug 17 18:20:38 2019 : Debug: check_name = "Max-All-Session"
>>> Sat Aug 17 18:20:38 2019 : Debug: reply_name = "Session-Timeout"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Loading module "expire_on_login" from file /etc/freeradius/3.0/mods-enabled/sqlcounter
>>> Sat Aug 17 18:20:38 2019 : Debug: sqlcounter expire_on_login {
>>> Sat Aug 17 18:20:38 2019 : Debug: sql_module_instance = "sql"
>>> Sat Aug 17 18:20:38 2019 : Debug: key = "User-Name"
>>> Sat Aug 17 18:20:38 2019 : Debug: query = "SELECT IFNULL( MAX(TIME_TO_SEC(TIMEDIFF(NOW(), acctstarttime))),0) FROM radacct WHERE UserName='%{User-Name}' ORDER BY acctstarttime LIMIT 1;"
>>> Sat Aug 17 18:20:38 2019 : Debug: reset = "never"
>>> Sat Aug 17 18:20:38 2019 : Debug: counter_name = "Expire-After-Initial-Login"
>>> Sat Aug 17 18:20:38 2019 : Debug: check_name = "Expire-After"
>>> Sat Aug 17 18:20:38 2019 : Debug: reply_name = "Session-Timeout"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: instantiate {
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "dailycounter" from file /etc/freeradius/3.0/mods-enabled/sqlcounter
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sqlcounter: Current Time: 1566058838 [2019-08-17 18:20:38], Prev reset 1565992800 [2019-08-17 00:00:00]
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "reject" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "fail" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "ok" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "handled" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "invalid" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "userlock" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "notfound" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "noop" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "updated" from file /etc/freeradius/3.0/mods-enabled/always
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "attr_filter.post-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter
>>> Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/post-proxy
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "attr_filter.pre-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter
>>> Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/pre-proxy
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "attr_filter.access_reject" from file /etc/freeradius/3.0/mods-enabled/attr_filter
>>> Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/access_reject
>>> Sat Aug 17 18:20:38 2019 : Warning: [/etc/freeradius/3.0/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT".
>>> Sat Aug 17 18:20:38 2019 : Warning: [/etc/freeradius/3.0/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay-USec" found in filter list for realm "DEFAULT".
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "attr_filter.access_challenge" from file /etc/freeradius/3.0/mods-enabled/attr_filter
>>> Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/access_challenge
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/3.0/mods-enabled/attr_filter
>>> Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/accounting_response
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "cache_eap" from file /etc/freeradius/3.0/mods-enabled/cache_eap
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_cache_rbtree with path: /usr/lib/freeradius/rlm_cache_rbtree.so
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "detail" from file /etc/freeradius/3.0/mods-enabled/detail
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "auth_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "reply_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "pre_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "post_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "eap" from file /etc/freeradius/3.0/mods-enabled/eap
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_eap_tls with path: /usr/lib/freeradius/rlm_eap_tls.so
>>> Sat Aug 17 18:20:38 2019 : Debug: # Linked to sub-module rlm_eap_tls
>>> Sat Aug 17 18:20:38 2019 : Debug: tls {
>>> Sat Aug 17 18:20:38 2019 : Debug: tls = "tls-common"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: tls-config tls-common {
>>> Sat Aug 17 18:20:38 2019 : Debug: verify_depth = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: ca_path = "/etc/freeradius/3.0/certs"
>>> Sat Aug 17 18:20:38 2019 : Debug: pem_file_type = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: private_key_file = "/etc/ssl/private/server.key"
>>> Sat Aug 17 18:20:38 2019 : Debug: certificate_file = "/etc/ssl/private/server.pem"
>>> Sat Aug 17 18:20:38 2019 : Debug: ca_file = "/etc/ssl/certs/ca-certificates.crt"
>>> Sat Aug 17 18:20:38 2019 : Debug: private_key_password = "whatever"
>>> Sat Aug 17 18:20:38 2019 : Debug: dh_file = "/etc/freeradius/3.0/certs/dh"
>>> Sat Aug 17 18:20:38 2019 : Debug: fragment_size = 1024
>>> Sat Aug 17 18:20:38 2019 : Debug: include_length = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: auto_chain = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: check_crl = no
>>> Sat Aug 17 18:20:38 2019 : Debug: check_all_crl = no
>>> Sat Aug 17 18:20:38 2019 : Debug: cipher_list = "DEFAULT"
>>> Sat Aug 17 18:20:38 2019 : Debug: cipher_server_preference = no
>>> Sat Aug 17 18:20:38 2019 : Debug: ecdh_curve = "prime256v1"
>>> Sat Aug 17 18:20:38 2019 : Debug: tls_max_version = ""
>>> Sat Aug 17 18:20:38 2019 : Debug: tls_min_version = "1.0"
>>> Sat Aug 17 18:20:38 2019 : Debug: cache {
>>> Sat Aug 17 18:20:38 2019 : Debug: enable = no
>>> Sat Aug 17 18:20:38 2019 : Debug: lifetime = 24
>>> Sat Aug 17 18:20:38 2019 : Debug: max_entries = 255
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: verify {
>>> Sat Aug 17 18:20:38 2019 : Debug: skip_if_ocsp_ok = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: ocsp {
>>> Sat Aug 17 18:20:38 2019 : Debug: enable = no
>>> Sat Aug 17 18:20:38 2019 : Debug: override_cert_url = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: url = "http://127.0.0.1/ocsp/"
>>> Sat Aug 17 18:20:38 2019 : Debug: use_nonce = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: timeout = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: softfail = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_eap_ttls with path: /usr/lib/freeradius/rlm_eap_ttls.so
>>> Sat Aug 17 18:20:38 2019 : Debug: # Linked to sub-module rlm_eap_ttls
>>> Sat Aug 17 18:20:38 2019 : Debug: ttls {
>>> Sat Aug 17 18:20:38 2019 : Debug: tls = "tls-common"
>>> Sat Aug 17 18:20:38 2019 : Debug: default_eap_type = "md5"
>>> Sat Aug 17 18:20:38 2019 : Debug: copy_request_to_tunnel = no
>>> Sat Aug 17 18:20:38 2019 : Debug: use_tunneled_reply = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: virtual_server = "inner-tunnel"
>>> Sat Aug 17 18:20:38 2019 : Debug: include_length = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: require_client_cert = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: tls: Using cached TLS configuration from previous invocation
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_eap_peap with path: /usr/lib/freeradius/rlm_eap_peap.so
>>> Sat Aug 17 18:20:38 2019 : Debug: # Linked to sub-module rlm_eap_peap
>>> Sat Aug 17 18:20:38 2019 : Debug: peap {
>>> Sat Aug 17 18:20:38 2019 : Debug: tls = "tls-common"
>>> Sat Aug 17 18:20:38 2019 : Debug: default_eap_type = "mschapv2"
>>> Sat Aug 17 18:20:38 2019 : Debug: copy_request_to_tunnel = no
>>> Sat Aug 17 18:20:38 2019 : Debug: use_tunneled_reply = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: proxy_tunneled_request_as_eap = yes
>>> Sat Aug 17 18:20:38 2019 : Debug: virtual_server = "inner-tunnel"
>>> Sat Aug 17 18:20:38 2019 : Debug: soh = no
>>> Sat Aug 17 18:20:38 2019 : Debug: require_client_cert = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: tls: Using cached TLS configuration from previous invocation
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_eap_mschapv2 with path: /usr/lib/freeradius/rlm_eap_mschapv2.so
>>> Sat Aug 17 18:20:38 2019 : Debug: # Linked to sub-module rlm_eap_mschapv2
>>> Sat Aug 17 18:20:38 2019 : Debug: mschapv2 {
>>> Sat Aug 17 18:20:38 2019 : Debug: with_ntdomain_hack = no
>>> Sat Aug 17 18:20:38 2019 : Debug: send_error = no
>>> Sat Aug 17 18:20:38 2019 : Debug: identity = "daloradius.marszalkowscy.pl"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "expiration" from file /etc/freeradius/3.0/mods-enabled/expiration
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "files" from file /etc/freeradius/3.0/mods-enabled/files
>>> Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/files/authorize
>>> Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/files/accounting
>>> Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/files/pre-proxy
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "linelog" from file /etc/freeradius/3.0/mods-enabled/linelog
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "log_accounting" from file /etc/freeradius/3.0/mods-enabled/linelog
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "logintime" from file /etc/freeradius/3.0/mods-enabled/logintime
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "mschap" from file /etc/freeradius/3.0/mods-enabled/mschap
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_mschap (mschap): using internal authentication
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "pap" from file /etc/freeradius/3.0/mods-enabled/pap
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "etc_passwd" from file /etc/freeradius/3.0/mods-enabled/passwd
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "preprocess" from file /etc/freeradius/3.0/mods-enabled/preprocess
>>> Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/preprocess/huntgroups
>>> Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/preprocess/hints
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "IPASS" from file /etc/freeradius/3.0/mods-enabled/realm
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "suffix" from file /etc/freeradius/3.0/mods-enabled/realm
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "realmpercent" from file /etc/freeradius/3.0/mods-enabled/realm
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "ntdomain" from file /etc/freeradius/3.0/mods-enabled/realm
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "sql" from file /etc/freeradius/3.0/mods-enabled/sql
>>> Sat Aug 17 18:20:38 2019 : Info: rlm_sql_mysql: libmysql version: 5.7.27
>>> Sat Aug 17 18:20:38 2019 : Debug: mysql {
>>> Sat Aug 17 18:20:38 2019 : Debug: tls {
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: warnings = "auto"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Attempting to connect to database "radius"
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Using local pool section
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): No pool reference found for config item "sql.pool"
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Initialising connection pool
>>> Sat Aug 17 18:20:38 2019 : Debug: pool {
>>> Sat Aug 17 18:20:38 2019 : Debug: start = 5
>>> Sat Aug 17 18:20:38 2019 : Debug: min = 3
>>> Sat Aug 17 18:20:38 2019 : Debug: max = 32
>>> Sat Aug 17 18:20:38 2019 : Debug: spare = 10
>>> Sat Aug 17 18:20:38 2019 : Debug: uses = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: cleanup_interval = 30
>>> Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 60
>>> Sat Aug 17 18:20:38 2019 : Debug: retry_delay = 30
>>> Sat Aug 17 18:20:38 2019 : Debug: spread = no
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Opening additional connection (0), 1 of 32 pending slots used
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Starting connect to MySQL server
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.27-0ubuntu0.18.04.1, protocol version 10
>>> Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Opening additional connection (1), 1 of 31 pending slots used
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Starting connect to MySQL server
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.27-0ubuntu0.18.04.1, protocol version 10
>>> Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Opening additional connection (2), 1 of 30 pending slots used
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Starting connect to MySQL server
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.27-0ubuntu0.18.04.1, protocol version 10
>>> Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Opening additional connection (3), 1 of 29 pending slots used
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Starting connect to MySQL server
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.27-0ubuntu0.18.04.1, protocol version 10
>>> Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Opening additional connection (4), 1 of 28 pending slots used
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Starting connect to MySQL server
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.27-0ubuntu0.18.04.1, protocol version 10
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Adding pool reference 0x556e9959ea80 to config item "sql.pool"
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Processing generate_sql_clients
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret, server FROM nas
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Reserved connection (0)
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Executing select query: SELECT id, nasname, shortname, type, secret, server FROM nas
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Adding client 172.16.0.1 (USG) to global clients list
>>> Sat Aug 17 18:20:38 2019 : Debug: Adding client 172.16.0.1/32 (172.16.0.1) to prefix tree 32
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (172.16.0.1): Client "USG" (sql) added
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Adding client 172.16.0.2 (USW-16) to global clients list
>>> Sat Aug 17 18:20:38 2019 : Debug: Adding client 172.16.0.2/32 (172.16.0.2) to prefix tree 32
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (172.16.0.2): Client "USW-16" (sql) added
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Adding client 172.16.0.3 (USW-8) to global clients list
>>> Sat Aug 17 18:20:38 2019 : Debug: Adding client 172.16.0.3/32 (172.16.0.3) to prefix tree 32
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (172.16.0.3): Client "USW-8" (sql) added
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Adding client 172.16.0.4 (Pietro) to global clients list
>>> Sat Aug 17 18:20:38 2019 : Debug: Adding client 172.16.0.4/32 (172.16.0.4) to prefix tree 32
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (172.16.0.4): Client "Pietro" (sql) added
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Adding client 172.16.0.5 (Parter) to global clients list
>>> Sat Aug 17 18:20:38 2019 : Debug: Adding client 172.16.0.5/32 (172.16.0.5) to prefix tree 32
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (172.16.0.5): Client "Parter" (sql) added
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Released connection (0)
>>> Sat Aug 17 18:20:38 2019 : Info: Need 5 more connections to reach 10 spares
>>> Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Opening additional connection (5), 1 of 27 pending slots used
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Starting connect to MySQL server
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.27-0ubuntu0.18.04.1, protocol version 10
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "monthlycounter" from file /etc/freeradius/3.0/mods-enabled/sqlcounter
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sqlcounter: Current Time: 1566058838 [2019-08-17 18:20:38], Prev reset 1564610400 [2019-08-01 00:00:00]
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "noresetcounter" from file /etc/freeradius/3.0/mods-enabled/sqlcounter
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sqlcounter: Current Time: 1566058838 [2019-08-17 18:20:38], Prev reset 0 [2019-08-17 18:00:00]
>>> Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "expire_on_login" from file /etc/freeradius/3.0/mods-enabled/sqlcounter
>>> Sat Aug 17 18:20:38 2019 : Debug: rlm_sqlcounter: Current Time: 1566058838 [2019-08-17 18:20:38], Prev reset 0 [2019-08-17 18:00:00]
>>> Sat Aug 17 18:20:38 2019 : Debug: } # modules
>>> Sat Aug 17 18:20:38 2019 : Debug: radiusd: #### Loading Virtual Servers ####
>>> Sat Aug 17 18:20:38 2019 : Debug: server { # from file /etc/freeradius/3.0/radiusd.conf
>>> Sat Aug 17 18:20:38 2019 : Debug: } # server
>>> Sat Aug 17 18:20:38 2019 : Debug: server DOM { # from file /etc/freeradius/3.0/sites-enabled/default
>>> Sat Aug 17 18:20:38 2019 : Debug: authenticate {
>>> Sat Aug 17 18:20:38 2019 : Debug: group {
>>> Sat Aug 17 18:20:38 2019 : Debug: pap
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: group {
>>> Sat Aug 17 18:20:38 2019 : Debug: mschap
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: mschap
>>> Sat Aug 17 18:20:38 2019 : Debug: eap
>>> Sat Aug 17 18:20:38 2019 : Debug: } # authenticate
>>> Sat Aug 17 18:20:38 2019 : Debug: authorize {
>>> Sat Aug 17 18:20:38 2019 : Debug: policy filter_username {
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name) {
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ / /) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains whitespace'
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: reject
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /@[^@]*@/) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Multiple @ in User-Name'
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: reject
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /\.\./) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains multiple ..s'
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: reject
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /@/ && !&User-Name =~ /@(.+)\.(.+)$/) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm does not have at least one dot separator'
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: reject
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /\.$/) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm ends with a dot'
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: reject
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /@\./) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm begins with a dot'
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: reject
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: policy filter_password {
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Password && !&User-Password == "%{string:User-Password}") {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Tmp-String-0 := "%{string:User-Password}"
>>> Sat Aug 17 18:20:38 2019 : Debug: &User-Password := "%{string:Tmp-String-0}"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: preprocess
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/default[309]: Please change attribute reference to '&Huntgroup-Name := ...'
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Huntgroup-Name := "%{sql:select groupname from radhuntgroup where nasipaddress=\"%{NAS-IP-Address}\"}"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: mschap
>>> Sat Aug 17 18:20:38 2019 : Debug: suffix
>>> Sat Aug 17 18:20:38 2019 : Debug: eap
>>> Sat Aug 17 18:20:38 2019 : Debug: sql
>>> Sat Aug 17 18:20:38 2019 : Debug: dailycounter
>>> Sat Aug 17 18:20:38 2019 : Debug: expiration
>>> Sat Aug 17 18:20:38 2019 : Debug: logintime
>>> Sat Aug 17 18:20:38 2019 : Debug: pap
>>> Sat Aug 17 18:20:38 2019 : Debug: group {
>>> Sat Aug 17 18:20:38 2019 : Debug: sql
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: } # authorize
>>> Sat Aug 17 18:20:38 2019 : Debug: preacct {
>>> Sat Aug 17 18:20:38 2019 : Debug: preprocess
>>> Sat Aug 17 18:20:38 2019 : Debug: policy acct_counters64.preacct {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Acct-Input-Octets64 = "%{expr:(&Acct-Input-Gigawords << 32) | &Acct-Input-Octets}"
>>> Sat Aug 17 18:20:38 2019 : Debug: &Acct-Output-Octets64 = "%{expr:(&Acct-Output-Gigawords << 32) | &Acct-Output-Octets}"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &FreeRADIUS-Acct-Session-Start-Time = "%{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}}"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: policy acct_unique {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Tmp-String-9 := "ai:"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: if ("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/ && "%{string:&Class}" =~ /^ai:([0-9a-f]{32})/) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Acct-Unique-Session-Id := "%{md5:%{1},%{Acct-Session-ID}}"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: else {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Acct-Unique-Session-Id := "%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: suffix
>>> Sat Aug 17 18:20:38 2019 : Debug: } # preacct
>>> Sat Aug 17 18:20:38 2019 : Debug: accounting {
>>> Sat Aug 17 18:20:38 2019 : Debug: detail
>>> Sat Aug 17 18:20:38 2019 : Debug: sql
>>> Sat Aug 17 18:20:38 2019 : Debug: exec
>>> Sat Aug 17 18:20:38 2019 : Debug: attr_filter.accounting_response
>>> Sat Aug 17 18:20:38 2019 : Debug: group {
>>> Sat Aug 17 18:20:38 2019 : Debug: sql
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: } # accounting
>>> Sat Aug 17 18:20:38 2019 : Debug: session {
>>> Sat Aug 17 18:20:38 2019 : Debug: sql
>>> Sat Aug 17 18:20:38 2019 : Debug: } # session
>>> Sat Aug 17 18:20:38 2019 : Debug: post-proxy {
>>> Sat Aug 17 18:20:38 2019 : Debug: eap
>>> Sat Aug 17 18:20:38 2019 : Debug: } # post-proxy
>>> Sat Aug 17 18:20:38 2019 : Debug: post-auth {
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/default[706]: Please change attribute reference to '&State := ...'
>>> Sat Aug 17 18:20:38 2019 : Debug: if (!&reply:State) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &reply:State := "0x%{randstr:16h}"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &reply:[*] += &session-state:[*]
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: sql
>>> Sat Aug 17 18:20:38 2019 : Debug: exec
>>> Sat Aug 17 18:20:38 2019 : Debug: policy insert_acct_class {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &reply:Class = "ai:%{md5:%t,%I,%{Packet-Src-Port},%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}},%{NAS-IP-Address},%{Calling-Station-ID},%{User-Name}}"
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/default[822]: Please change attribute reference to '&EAP-Key-Name := ...'
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&reply:EAP-Session-Id) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &reply:EAP-Key-Name := &reply:EAP-Session-Id
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: policy remove_reply_message_if_eap {
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&reply:EAP-Message && &reply:Reply-Message) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &reply:Reply-Message !* ANY
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: else {
>>> Sat Aug 17 18:20:38 2019 : Debug: noop
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: group {
>>> Sat Aug 17 18:20:38 2019 : Debug: sql
>>> Sat Aug 17 18:20:38 2019 : Debug: attr_filter.access_reject
>>> Sat Aug 17 18:20:38 2019 : Debug: eap
>>> Sat Aug 17 18:20:38 2019 : Debug: policy remove_reply_message_if_eap {
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&reply:EAP-Message && &reply:Reply-Message) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &reply:Reply-Message !* ANY
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: else {
>>> Sat Aug 17 18:20:38 2019 : Debug: noop
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: } # post-auth
>>> Sat Aug 17 18:20:38 2019 : Debug: } # server DOM
>>> Sat Aug 17 18:20:38 2019 : Debug: server inner-tunnel { # from file /etc/freeradius/3.0/sites-enabled/inner-tunnel
>>> Sat Aug 17 18:20:38 2019 : Debug: authenticate {
>>> Sat Aug 17 18:20:38 2019 : Debug: group {
>>> Sat Aug 17 18:20:38 2019 : Debug: pap
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: group {
>>> Sat Aug 17 18:20:38 2019 : Debug: mschap
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: mschap
>>> Sat Aug 17 18:20:38 2019 : Debug: eap
>>> Sat Aug 17 18:20:38 2019 : Debug: } # authenticate
>>> Sat Aug 17 18:20:38 2019 : Debug: authorize {
>>> Sat Aug 17 18:20:38 2019 : Debug: policy filter_username {
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name) {
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ / /) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains whitespace'
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: reject
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /@[^@]*@/) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Multiple @ in User-Name'
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: reject
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /\.\./) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains multiple ..s'
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: reject
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /@/ && !&User-Name =~ /@(.+)\.(.+)$/) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm does not have at least one dot separator'
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: reject
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /\.$/) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm ends with a dot'
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: reject
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /@\./) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm begins with a dot'
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: reject
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: mschap
>>> Sat Aug 17 18:20:38 2019 : Debug: suffix
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &control:Proxy-To-Realm := LOCAL
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: eap
>>> Sat Aug 17 18:20:38 2019 : Debug: sql
>>> Sat Aug 17 18:20:38 2019 : Debug: dailycounter
>>> Sat Aug 17 18:20:38 2019 : Debug: expiration
>>> Sat Aug 17 18:20:38 2019 : Debug: logintime
>>> Sat Aug 17 18:20:38 2019 : Debug: pap
>>> Sat Aug 17 18:20:38 2019 : Debug: } # authorize
>>> Sat Aug 17 18:20:38 2019 : Debug: session {
>>> Sat Aug 17 18:20:38 2019 : Debug: sql
>>> Sat Aug 17 18:20:38 2019 : Debug: } # session
>>> Sat Aug 17 18:20:38 2019 : Debug: post-proxy {
>>> Sat Aug 17 18:20:38 2019 : Debug: eap
>>> Sat Aug 17 18:20:38 2019 : Debug: } # post-proxy
>>> Sat Aug 17 18:20:38 2019 : Debug: post-auth {
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[289]: Please change attribute reference to '&User-Name := ...'
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &reply:User-Name := &User-Name
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: sql
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[343]: Please change attribute reference to '&Message-Authenticator !* ...'
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[344]: Please change attribute reference to '&EAP-Message !* ...'
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[345]: Please change attribute reference to '&Proxy-State !* ...'
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[346]: Please change attribute reference to '&MS-MPPE-Encryption-Types !* ...'
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[347]: Please change attribute reference to '&MS-MPPE-Encryption-Policy !* ...'
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[348]: Please change attribute reference to '&MS-MPPE-Send-Key !* ...'
>>> Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[349]: Please change attribute reference to '&MS-MPPE-Recv-Key !* ...'
>>> Sat Aug 17 18:20:38 2019 : Debug: if (true) {
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &reply:Message-Authenticator !* ANY
>>> Sat Aug 17 18:20:38 2019 : Debug: &reply:EAP-Message !* ANY
>>> Sat Aug 17 18:20:38 2019 : Debug: &reply:Proxy-State !* ANY
>>> Sat Aug 17 18:20:38 2019 : Debug: &reply:MS-MPPE-Encryption-Types !* ANY
>>> Sat Aug 17 18:20:38 2019 : Debug: &reply:MS-MPPE-Encryption-Policy !* ANY
>>> Sat Aug 17 18:20:38 2019 : Debug: &reply:MS-MPPE-Send-Key !* ANY
>>> Sat Aug 17 18:20:38 2019 : Debug: &reply:MS-MPPE-Recv-Key !* ANY
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &outer.session-state:[*] += &reply:[*]
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: group {
>>> Sat Aug 17 18:20:38 2019 : Debug: sql
>>> Sat Aug 17 18:20:38 2019 : Debug: attr_filter.access_reject
>>> Sat Aug 17 18:20:38 2019 : Debug: update {
>>> Sat Aug 17 18:20:38 2019 : Debug: &outer.session-state:Module-Failure-Message := &Module-Failure-Message
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: } # post-auth
>>> Sat Aug 17 18:20:38 2019 : Debug: } # server inner-tunnel
>>> Sat Aug 17 18:20:38 2019 : Debug: server radius-status { # from file /etc/freeradius/3.0/sites-enabled/status
>>> Sat Aug 17 18:20:38 2019 : Debug: authorize {
>>> Sat Aug 17 18:20:38 2019 : Debug: ok
>>> Sat Aug 17 18:20:38 2019 : Debug: group {
>>> Sat Aug 17 18:20:38 2019 : Debug: ok
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: } # authorize
>>> Sat Aug 17 18:20:38 2019 : Debug: accounting {
>>> Sat Aug 17 18:20:38 2019 : Debug: ok
>>> Sat Aug 17 18:20:38 2019 : Debug: group {
>>> Sat Aug 17 18:20:38 2019 : Debug: ok
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: } # accounting
>>> Sat Aug 17 18:20:38 2019 : Debug: } # server radius-status
>>> Sat Aug 17 18:20:38 2019 : Debug: Created signal pipe. Read end FD 13, write end FD 14
>>> Sat Aug 17 18:20:38 2019 : Debug: radiusd: #### Opening IP addresses and Ports ####
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading proto_auth with path: /usr/lib/freeradius/proto_auth.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading proto_auth failed: /usr/lib/freeradius/proto_auth.so: cannot open shared object file: No such file or directory - No such file or directory
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading library using linker search path(s)
>>> Sat Aug 17 18:20:38 2019 : Debug: Defaults : /lib:/usr/lib
>>> Sat Aug 17 18:20:38 2019 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory
>>> Sat Aug 17 18:20:38 2019 : Debug: listen {
>>> Sat Aug 17 18:20:38 2019 : Debug: type = "auth"
>>> Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 172.16.0.12
>>> Sat Aug 17 18:20:38 2019 : Debug: port = 1812
>>> Sat Aug 17 18:20:38 2019 : Debug: limit {
>>> Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16
>>> Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 30
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading proto_acct with path: /usr/lib/freeradius/proto_acct.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading proto_acct failed: /usr/lib/freeradius/proto_acct.so: cannot open shared object file: No such file or directory - No such file or directory
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading library using linker search path(s)
>>> Sat Aug 17 18:20:38 2019 : Debug: Defaults : /lib:/usr/lib
>>> Sat Aug 17 18:20:38 2019 : Debug: Failed with error: proto_acct.so: cannot open shared object file: No such file or directory
>>> Sat Aug 17 18:20:38 2019 : Debug: listen {
>>> Sat Aug 17 18:20:38 2019 : Debug: type = "acct"
>>> Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 172.16.0.12
>>> Sat Aug 17 18:20:38 2019 : Debug: port = 1813
>>> Sat Aug 17 18:20:38 2019 : Debug: limit {
>>> Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16
>>> Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 30
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading proto_auth with path: /usr/lib/freeradius/proto_auth.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading proto_auth failed: /usr/lib/freeradius/proto_auth.so: cannot open shared object file: No such file or directory - No such file or directory
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading library using linker search path(s)
>>> Sat Aug 17 18:20:38 2019 : Debug: Defaults : /lib:/usr/lib
>>> Sat Aug 17 18:20:38 2019 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory
>>> Sat Aug 17 18:20:38 2019 : Debug: listen {
>>> Sat Aug 17 18:20:38 2019 : Debug: type = "auth"
>>> Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 127.0.0.1
>>> Sat Aug 17 18:20:38 2019 : Debug: port = 18120
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading proto_status with path: /usr/lib/freeradius/proto_status.so
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading proto_status failed: /usr/lib/freeradius/proto_status.so: cannot open shared object file: No such file or directory - No such file or directory
>>> Sat Aug 17 18:20:38 2019 : Debug: Loading library using linker search path(s)
>>> Sat Aug 17 18:20:38 2019 : Debug: Defaults : /lib:/usr/lib
>>> Sat Aug 17 18:20:38 2019 : Debug: Failed with error: proto_status.so: cannot open shared object file: No such file or directory
>>> Sat Aug 17 18:20:38 2019 : Debug: listen {
>>> Sat Aug 17 18:20:38 2019 : Debug: type = "status"
>>> Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 127.0.0.1
>>> Sat Aug 17 18:20:38 2019 : Debug: port = 18121
>>> Sat Aug 17 18:20:38 2019 : Debug: client admin {
>>> Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 127.0.0.1
>>> Sat Aug 17 18:20:38 2019 : Debug: require_message_authenticator = no
>>> Sat Aug 17 18:20:38 2019 : Debug: secret = "Ametyst3"
>>> Sat Aug 17 18:20:38 2019 : Debug: limit {
>>> Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16
>>> Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 30
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Adding client 127.0.0.1/32 (127.0.0.1) to prefix tree 32
>>> Sat Aug 17 18:20:38 2019 : Debug: client router {
>>> Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 172.16.0.1
>>> Sat Aug 17 18:20:38 2019 : Debug: require_message_authenticator = no
>>> Sat Aug 17 18:20:38 2019 : Debug: secret = "Ametyst3"
>>> Sat Aug 17 18:20:38 2019 : Debug: limit {
>>> Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16
>>> Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 30
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Adding client 172.16.0.1/32 (172.16.0.1) to prefix tree 32
>>> Sat Aug 17 18:20:38 2019 : Debug: client switch {
>>> Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 172.16.0.2
>>> Sat Aug 17 18:20:38 2019 : Debug: require_message_authenticator = no
>>> Sat Aug 17 18:20:38 2019 : Debug: secret = "Ametyst3"
>>> Sat Aug 17 18:20:38 2019 : Debug: limit {
>>> Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16
>>> Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0
>>> Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 30
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Adding client 172.16.0.2/32 (172.16.0.2) to prefix tree 32
>>> Sat Aug 17 18:20:38 2019 : Debug: }
>>> Sat Aug 17 18:20:38 2019 : Debug: Listening on auth address 172.16.0.12 port 1812 bound to server DOM
>>> Sat Aug 17 18:20:38 2019 : Debug: Listening on acct address 172.16.0.12 port 1813 bound to server DOM
>>> Sat Aug 17 18:20:38 2019 : Debug: Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel
>>> Sat Aug 17 18:20:38 2019 : Debug: Listening on status address 127.0.0.1 port 18121 bound to server radius-status
>>> Sat Aug 17 18:20:38 2019 : Debug: Opened new proxy socket 'proxy address * port 44003'
>>> Sat Aug 17 18:20:38 2019 : Debug: Listening on proxy address * port 44003
>>> Sat Aug 17 18:20:38 2019 : Info: Ready to process requests
>>>
>>> —————————————
>>>
>>>
>>>
>>> On top of that I have a problems with accounting, it seems like NAS doesn’t like Gigawords - quite often reports 4GB up and down. More often it happens when session is longer than shorter. Is there any any fix available on Freeradius side? Ubiquiti claims https://help.ubnt.com/hc/en-us/articles/115005255907-UniFi-Hotspot-RADIUS-Attributes their APs should be working with this attribute. NAS it is Unifi AP AC Pro.
>>>
>>> So, where do I need to troubleshoot, Freeradius or NAS? While looking at tcpdump on port 1812 I can see lengthy negotiation: multiple access requests and access challenges (12 times) followed finally by access accept... I don't know how many requests and challenges should be there.
>>> Thanks in advance!
>>>
>>> -
>>> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
>>
>> -
>> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
More information about the Freeradius-Users
mailing list