intermittent auth issue (proxy: request is no longer in proxy hash)
Chris Knipe
savage at savage.za.org
Thu Jul 3 12:15:56 CEST 2014
Hi All,
I've manage to pull the below request (-Xxx) from a debug log. Very
intermittently, and randomly, my FR would receive a auth-accept from
an proxy server.
The accept packet received from the proxy server includes a
Configuration-Token attribute, which I then interpret and do stuff
with in the post_proxy section, using rlm_perl.
For some reason, the response received does not make it through
post_proxy. From what I can gather in the logs, FR complains:
Thu Jul 3 11:55:49 2014 : Debug: (216) proxy: request is no longer in
proxy hash
Thu Jul 3 11:55:49 2014 : Debug: (216) Found Auth-Type = Accept
Thu Jul 3 11:55:49 2014 : Debug: (216) Auth-Type = Accept, accepting the user
Thu Jul 3 11:55:49 2014 : Auth: (216) Login OK:
[user at proxy.realm/oozuL8poop] (from client CLIENT port 0 cli c.d.99.6)
And then of course, never passes the request off through rlm_perl.
Can anyone shed some light on this in terms of how to fix this? It is
imperative that that proxied response passes through rlm_perl - in my
specific case, I am not concerned about how long the authentication
process takes, but it is critically important that it passes through
rlm_perl so that various aspects of the session can be setup...
Full Debug Log:
Received Access-Request Id 85 from e.f.240.36:22947 to
e.f.136.224:1812 length 119
Called-Station-Id = 'a.b.8.42'
Calling-Station-Id = 'c.d.99.6'
NAS-IP-Address = e.f.240.36
NAS-Port-Type = Virtual
NAS-Port-Id = '16980'
Service-Type = Authenticate-Only
User-Name = 'user at proxy.realm'
User-Password = 'oozuL8poop'
Thu Jul 3 11:55:48 2014 : Debug: (216) # Executing section authorize
from file /etc/freeradius/radiusd.conf
Thu Jul 3 11:55:48 2014 : Debug: (216) authorize {
Thu Jul 3 11:55:48 2014 : Debug: (216) filter_username filter_username {
Thu Jul 3 11:55:48 2014 : Debug: (216) if (User-Name =~ / /)
Thu Jul 3 11:55:48 2014 : Debug:
Thu Jul 3 11:55:48 2014 : Debug: Parsed xlat tree:
Thu Jul 3 11:55:48 2014 : Debug: literal -->
Thu Jul 3 11:55:48 2014 : Debug: (216) EXPAND
Thu Jul 3 11:55:48 2014 : Debug: (216) -->
Thu Jul 3 11:55:48 2014 : Debug: (216) if (User-Name =~ / /) -> FALSE
Thu Jul 3 11:55:48 2014 : Debug: (216) if (User-Name =~ /@.*@/ )
Thu Jul 3 11:55:48 2014 : Debug: @.*@
Thu Jul 3 11:55:48 2014 : Debug: Parsed xlat tree:
Thu Jul 3 11:55:48 2014 : Debug: literal --> @.*@
Thu Jul 3 11:55:48 2014 : Debug: (216) EXPAND @.*@
Thu Jul 3 11:55:48 2014 : Debug: (216) --> @.*@
Thu Jul 3 11:55:48 2014 : Debug: (216) if (User-Name =~ /@.*@/ ) -> FALSE
Thu Jul 3 11:55:48 2014 : Debug: (216) if (User-Name =~ /\\.\\./ )
Thu Jul 3 11:55:48 2014 : Debug: \.\.
Thu Jul 3 11:55:48 2014 : Debug: Parsed xlat tree:
Thu Jul 3 11:55:48 2014 : Debug: literal --> \\\.
Thu Jul 3 11:55:48 2014 : Debug: (216) EXPAND \.\.
Thu Jul 3 11:55:48 2014 : Debug: (216) --> \\\.
Thu Jul 3 11:55:48 2014 : Debug: (216) if (User-Name =~ /\\.\\./
) -> FALSE
Thu Jul 3 11:55:48 2014 : Debug: (216) if (User-Name =~ /\\.$/)
Thu Jul 3 11:55:48 2014 : Debug: \.$
Thu Jul 3 11:55:48 2014 : Debug: Parsed xlat tree:
Thu Jul 3 11:55:48 2014 : Debug: literal --> \$$
Thu Jul 3 11:55:48 2014 : Debug: (216) EXPAND \.$
Thu Jul 3 11:55:48 2014 : Debug: (216) --> \$$
Thu Jul 3 11:55:48 2014 : Debug: (216) if (User-Name =~ /\\.$/) -> FALSE
Thu Jul 3 11:55:48 2014 : Debug: (216) if (User-Name =~ /@\\./)
Thu Jul 3 11:55:48 2014 : Debug: @\.
Thu Jul 3 11:55:48 2014 : Debug: Parsed xlat tree:
Thu Jul 3 11:55:48 2014 : Debug: literal --> @\.
Thu Jul 3 11:55:48 2014 : Debug: (216) EXPAND @\.
Thu Jul 3 11:55:48 2014 : Debug: (216) --> @\.
Thu Jul 3 11:55:48 2014 : Debug: (216) if (User-Name =~ /@\\./) -> FALSE
Thu Jul 3 11:55:48 2014 : Debug: (216) } # filter_username
filter_username = notfound
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
calling preprocess (rlm_preprocess) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
returned from preprocess (rlm_preprocess) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) [preprocess] = ok
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
calling auth_log (rlm_detail) for request 216
Thu Jul 3 11:55:48 2014 : Debug: /var/log/freeradius/%Y/%Y-%m/%Y-%m-%d-auth_log
Thu Jul 3 11:55:48 2014 : Debug: Parsed xlat tree:
Thu Jul 3 11:55:48 2014 : Debug: literal --> /var/log/freeradius/
Thu Jul 3 11:55:48 2014 : Debug: percent --> Y
Thu Jul 3 11:55:48 2014 : Debug: literal --> /
Thu Jul 3 11:55:48 2014 : Debug: percent --> Y
Thu Jul 3 11:55:48 2014 : Debug: literal --> -
Thu Jul 3 11:55:48 2014 : Debug: percent --> m
Thu Jul 3 11:55:48 2014 : Debug: literal --> /
Thu Jul 3 11:55:48 2014 : Debug: percent --> Y
Thu Jul 3 11:55:48 2014 : Debug: literal --> -
Thu Jul 3 11:55:48 2014 : Debug: percent --> m
Thu Jul 3 11:55:48 2014 : Debug: literal --> -
Thu Jul 3 11:55:48 2014 : Debug: percent --> d
Thu Jul 3 11:55:48 2014 : Debug: literal --> -auth_log
Thu Jul 3 11:55:48 2014 : Debug: (216) auth_log : EXPAND
/var/log/freeradius/%Y/%Y-%m/%Y-%m-%d-auth_log
Thu Jul 3 11:55:48 2014 : Debug: (216) auth_log : -->
/var/log/freeradius/2014/2014-07/2014-07-03-auth_log
Thu Jul 3 11:55:48 2014 : Debug: (216) auth_log :
/var/log/freeradius/%Y/%Y-%m/%Y-%m-%d-auth_log expands to
/var/log/freeradius/2014/2014-07/2014-07-03-auth_log
Thu Jul 3 11:55:48 2014 : Debug: %t
Thu Jul 3 11:55:48 2014 : Debug: Parsed xlat tree:
Thu Jul 3 11:55:48 2014 : Debug: percent --> t
Thu Jul 3 11:55:48 2014 : Debug: (216) auth_log : EXPAND %t
Thu Jul 3 11:55:48 2014 : Debug: (216) auth_log : --> Thu Jul 3
11:55:48 2014
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
returned from auth_log (rlm_detail) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) [auth_log] = ok
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
calling suffix (rlm_realm) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) suffix : Looking up realm
"proxy.realm" for User-Name = "user at proxy.realm"
Thu Jul 3 11:55:48 2014 : Debug: (216) suffix : Found realm "proxy.realm"
Thu Jul 3 11:55:48 2014 : Debug: (216) suffix : Adding Realm = "proxy.realm"
Thu Jul 3 11:55:48 2014 : Debug: (216) suffix : Proxying request from
user user at proxy.realm to realm proxy.realm
Thu Jul 3 11:55:48 2014 : Debug: (216) suffix : Preparing to proxy
authentication request to realm "proxy.realm"
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
returned from suffix (rlm_realm) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) [suffix] = updated
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
calling files (rlm_files) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
returned from files (rlm_files) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) [files] = noop
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
calling perl (rlm_perl) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : <-- Proxy-To-Realm = proxy.realm
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : <-- Called-Station-Id = a.b.8.42
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : <-- Calling-Station-Id
= c.d.99.6
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : <-- NAS-IP-Address = e.f.240.36
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : <-- NAS-Port-Type = Virtual
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : <-- NAS-Port-Id = 16980
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : <-- Service-Type =
Authenticate-Only
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : <-- User-Name = user at proxy.realm
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : <-- User-Password = oozuL8poop
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : <-- Realm = proxy.realm
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : <-- Proxy-To-Realm = proxy.realm
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : --> NAS-Port-Type = Virtual
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : --> Service-Type =
Authenticate-Only
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : --> Calling-Station-Id
= c.d.99.6
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : --> Called-Station-Id = a.b.8.42
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : --> User-Name = user at proxy.realm
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : --> User-Password = oozuL8poop
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : --> Realm = proxy.realm
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : --> NAS-IP-Address = e.f.240.36
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : --> NAS-Port-Id = 16980
Thu Jul 3 11:55:48 2014 : Debug: (216) perl : --> Proxy-To-Realm = proxy.realm
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
returned from perl (rlm_perl) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) [perl] = noop
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
calling logintime (rlm_logintime) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
returned from logintime (rlm_logintime) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) [logintime] = noop
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
calling pap (rlm_pap) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
returned from pap (rlm_pap) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) [pap] = noop
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
calling chap (rlm_chap) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[authorize]:
returned from chap (rlm_chap) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) [chap] = noop
Thu Jul 3 11:55:48 2014 : Debug: (216) } # authorize = updated
Thu Jul 3 11:55:48 2014 : Debug: (216) # Executing section pre-proxy
from file /etc/freeradius/radiusd.conf
Thu Jul 3 11:55:48 2014 : Debug: (216) pre-proxy {
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[pre-proxy]:
calling pre_proxy_log (rlm_detail) for request 216
Thu Jul 3 11:55:48 2014 : Debug:
/var/log/freeradius/%Y/%Y-%m/%Y-%m-%d-pre_proxy_log
Thu Jul 3 11:55:48 2014 : Debug: Parsed xlat tree:
Thu Jul 3 11:55:48 2014 : Debug: literal --> /var/log/freeradius/
Thu Jul 3 11:55:48 2014 : Debug: percent --> Y
Thu Jul 3 11:55:48 2014 : Debug: literal --> /
Thu Jul 3 11:55:48 2014 : Debug: percent --> Y
Thu Jul 3 11:55:48 2014 : Debug: literal --> -
Thu Jul 3 11:55:48 2014 : Debug: percent --> m
Thu Jul 3 11:55:48 2014 : Debug: literal --> /
Thu Jul 3 11:55:48 2014 : Debug: percent --> Y
Thu Jul 3 11:55:48 2014 : Debug: literal --> -
Thu Jul 3 11:55:48 2014 : Debug: percent --> m
Thu Jul 3 11:55:48 2014 : Debug: literal --> -
Thu Jul 3 11:55:48 2014 : Debug: percent --> d
Thu Jul 3 11:55:48 2014 : Debug: literal --> -pre_proxy_log
Thu Jul 3 11:55:48 2014 : Debug: (216) pre_proxy_log : EXPAND
/var/log/freeradius/%Y/%Y-%m/%Y-%m-%d-pre_proxy_log
Thu Jul 3 11:55:48 2014 : Debug: (216) pre_proxy_log : -->
/var/log/freeradius/2014/2014-07/2014-07-03-pre_proxy_log
Thu Jul 3 11:55:48 2014 : Debug: (216) pre_proxy_log :
/var/log/freeradius/%Y/%Y-%m/%Y-%m-%d-pre_proxy_log expands to
/var/log/freeradius/2014/2014-07/2014-07-03-pre_proxy_log
Thu Jul 3 11:55:48 2014 : Debug: %t
Thu Jul 3 11:55:48 2014 : Debug: Parsed xlat tree:
Thu Jul 3 11:55:48 2014 : Debug: percent --> t
Thu Jul 3 11:55:48 2014 : Debug: (216) pre_proxy_log : EXPAND %t
Thu Jul 3 11:55:48 2014 : Debug: (216) pre_proxy_log : --> Thu Jul
3 11:55:48 2014
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[pre-proxy]:
returned from pre_proxy_log (rlm_detail) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) [pre_proxy_log] = ok
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[pre-proxy]:
calling attr_filter.pre-proxy (rlm_attr_filter) for request 216
Thu Jul 3 11:55:48 2014 : Debug: %{Realm}
Thu Jul 3 11:55:48 2014 : Debug: Parsed xlat tree:
Thu Jul 3 11:55:48 2014 : Debug: attribute --> Realm
Thu Jul 3 11:55:48 2014 : Debug: {
Thu Jul 3 11:55:48 2014 : Debug: ref 2
Thu Jul 3 11:55:48 2014 : Debug: list 1
Thu Jul 3 11:55:48 2014 : Debug: tag -128
Thu Jul 3 11:55:48 2014 : Debug: }
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy : EXPAND %{Realm}
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy : -->
proxy.realm
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Matched entry DEFAULT at line 1
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
NAS-Port-Type = Virtual allowed by NAS-Port-Type == Virtual
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Attribute "NAS-Port-Type" allowed by 1 rules, disallowed by 0 rules
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Service-Type = Authenticate-Only allowed by Service-Type ==
Authenticate-Only
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Attribute "Service-Type" allowed by 1 rules, disallowed by 0 rules
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Calling-Station-Id = 'c.d.99.6' allowed by Calling-Station-Id =* ''
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Attribute "Calling-Station-Id" allowed by 1 rules, disallowed by 0
rules
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Called-Station-Id = 'a.b.8.42' allowed by Called-Station-Id ==
'a.b.8.42'
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Attribute "Called-Station-Id" allowed by 1 rules, disallowed by 0
rules
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
User-Name = 'user at proxy.realm' allowed by User-Name =* ''
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Attribute "User-Name" allowed by 1 rules, disallowed by 0 rules
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
User-Password = 'oozuL8poop' allowed by User-Password =* ''
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Attribute "User-Password" allowed by 1 rules, disallowed by 0 rules
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Attribute "Realm" allowed by 0 rules, disallowed by 0 rules
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Attribute "NAS-IP-Address" allowed by 0 rules, disallowed by 0 rules
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Attribute "NAS-Port-Id" allowed by 0 rules, disallowed by 0 rules
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Attribute "Message-Authenticator" allowed by 0 rules, disallowed by 0
rules
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Proxy-State = 0x3835 allowed by Proxy-State =* 0x
Thu Jul 3 11:55:48 2014 : Debug: (216) attr_filter.pre-proxy :
Attribute "Proxy-State" allowed by 1 rules, disallowed by 0 rules
Thu Jul 3 11:55:48 2014 : Debug: (216) modsingle[pre-proxy]:
returned from attr_filter.pre-proxy (rlm_attr_filter) for request 216
Thu Jul 3 11:55:48 2014 : Debug: (216) [attr_filter.pre-proxy] = updated
Thu Jul 3 11:55:48 2014 : Debug: (216) } # pre-proxy = updated
Thu Jul 3 11:55:48 2014 : Debug: (216) proxy: Trying to allocate ID (0/2)
Thu Jul 3 11:55:48 2014 : Debug: (216) proxy: request is now in proxy hash
Thu Jul 3 11:55:48 2014 : Debug: (216) proxy: allocating destination
127.0.0.1 port 18130 - Id 28
Thu Jul 3 11:55:48 2014 : Debug: (216) Proxying request to home
server 127.0.0.1 port 18130
Sending Access-Request Id 28 from 0.0.0.0:5245 to 127.0.0.1:18130
Acct-Authentic := RADIUS
Acct-Delay-Time := 0
NAS-IP-Address := 85.12.8.44
NAS-Port-Type = Virtual
Service-Type = Authenticate-Only
Calling-Station-Id = 'c.d.99.6'
Called-Station-Id = 'a.b.8.42'
User-Name = 'user at proxy.realm'
User-Password = 'oozuL8poop'
Proxy-State = 0x3835
Received Access-Accept Id 28 from 127.0.0.1:18130 to 127.0.0.1:5245 length 106
Configuration-Token = 'OK:100:15:V:26843545600'
Reply-Message = 'Welcome to the ...'
Service-Type = Authenticate-Only
Proxy-State = 0x3835
Default-TTL = 19
Thu Jul 3 11:55:49 2014 : Debug: (216) proxy: request is no longer in
proxy hash
Thu Jul 3 11:55:49 2014 : Debug: (216) Found Auth-Type = Accept
Thu Jul 3 11:55:49 2014 : Debug: (216) Auth-Type = Accept, accepting the user
Thu Jul 3 11:55:49 2014 : Auth: (216) Login OK:
[user at proxy.realm/oozuL8poop] (from client CLIENT port 0 cli c.d.99.6)
Thu Jul 3 11:55:49 2014 : Debug: (216) # Executing section post-auth
from file /etc/freeradius/radiusd.conf
Thu Jul 3 11:55:49 2014 : Debug: (216) post-auth {
Thu Jul 3 11:55:49 2014 : Debug: (216) modsingle[post-auth]:
calling reply_log (rlm_detail) for request 216
Thu Jul 3 11:55:49 2014 : Debug:
/var/log/freeradius/%Y/%Y-%m/%Y-%m-%d-reply_log
Thu Jul 3 11:55:49 2014 : Debug: Parsed xlat tree:
Thu Jul 3 11:55:49 2014 : Debug: literal --> /var/log/freeradius/
Thu Jul 3 11:55:49 2014 : Debug: percent --> Y
Thu Jul 3 11:55:49 2014 : Debug: literal --> /
Thu Jul 3 11:55:49 2014 : Debug: percent --> Y
Thu Jul 3 11:55:49 2014 : Debug: literal --> -
Thu Jul 3 11:55:49 2014 : Debug: percent --> m
Thu Jul 3 11:55:49 2014 : Debug: literal --> /
Thu Jul 3 11:55:49 2014 : Debug: percent --> Y
Thu Jul 3 11:55:49 2014 : Debug: literal --> -
Thu Jul 3 11:55:49 2014 : Debug: percent --> m
Thu Jul 3 11:55:49 2014 : Debug: literal --> -
Thu Jul 3 11:55:49 2014 : Debug: percent --> d
Thu Jul 3 11:55:49 2014 : Debug: literal --> -reply_log
Thu Jul 3 11:55:49 2014 : Debug: (216) reply_log : EXPAND
/var/log/freeradius/%Y/%Y-%m/%Y-%m-%d-reply_log
Thu Jul 3 11:55:49 2014 : Debug: (216) reply_log : -->
/var/log/freeradius/2014/2014-07/2014-07-03-reply_log
Thu Jul 3 11:55:49 2014 : Debug: (216) reply_log :
/var/log/freeradius/%Y/%Y-%m/%Y-%m-%d-reply_log expands to
/var/log/freeradius/2014/2014-07/2014-07-03-reply_log
Thu Jul 3 11:55:49 2014 : Debug: %t
Thu Jul 3 11:55:49 2014 : Debug: Parsed xlat tree:
Thu Jul 3 11:55:49 2014 : Debug: percent --> t
Thu Jul 3 11:55:49 2014 : Debug: (216) reply_log : EXPAND %t
Thu Jul 3 11:55:49 2014 : Debug: (216) reply_log : --> Thu Jul 3
11:55:48 2014
Thu Jul 3 11:55:49 2014 : Debug: (216) modsingle[post-auth]:
returned from reply_log (rlm_detail) for request 216
Thu Jul 3 11:55:49 2014 : Debug: (216) [reply_log] = ok
Thu Jul 3 11:55:49 2014 : Debug: (216) } # post-auth = ok
Sending Access-Accept Id 85 from e.f.136.224:1812 to e.f.240.36:22947
--
Regards,
Chris Knipe
More information about the Freeradius-Users
mailing list