hi all
i try to configure packetfence act as eduroam server.
i have problem, all my local user or realm can't connect from other
university.
after debugging i realize all radius request from other university access
point is rejected, i see this log in freeradius.
ERROR: rest:
{"control:PacketFence-Authorization-Status":"allow","Reply-Message":"Switch
is not managed by
PacketFence","control:PacketFence-Request-Time":1529567567}
after that i try to add some access point to packetfence switch
configuration, and then i can connect.
do i need add all access point in eduroam federation? or i miss
configuration in eduroam integration with packetfence.
attach my radius-eduroam log file.
thanks.
(513) Thu Jun 21 14:52:47 2018: Debug: Received Access-Request Id 168 from
203.100.23.60:42290 to 203.100.59.39:11812 length 196
(513) Thu Jun 21 14:52:47 2018: Debug: User-Name = "[email protected]"
(513) Thu Jun 21 14:52:47 2018: Debug: Calling-Station-Id =
"0C-98-38-62-CA-8F"
(513) Thu Jun 21 14:52:47 2018: Debug: Called-Station-Id =
"84:b8:02:04:63:a0:eduroam"
(513) Thu Jun 21 14:52:47 2018: Debug: NAS-IP-Address = 192.168.127.8
(513) Thu Jun 21 14:52:47 2018: Debug: NAS-Identifier = "WLC-RU-4"
(513) Thu Jun 21 14:52:47 2018: Debug: EAP-Message =
0x020900251900170303001a000000000000000321e7fa5b22f28787957574744ebb600e4320
(513) Thu Jun 21 14:52:47 2018: Debug: State =
0xf4599259f3508bde1444eca174e1fcad
(513) Thu Jun 21 14:52:47 2018: Debug: Message-Authenticator =
0xa75a12467b9e02ca40faab9c8152101e
(513) Thu Jun 21 14:52:47 2018: Debug: Operator-Name = "1ru.nl"
(513) Thu Jun 21 14:52:47 2018: Debug: Proxy-State = 0x3238
(513) Thu Jun 21 14:52:47 2018: Debug: Proxy-State = 0x3533
(513) Thu Jun 21 14:52:47 2018: Debug: session-state: No cached attributes
(513) Thu Jun 21 14:52:47 2018: Debug: # Executing section authorize from file
/usr/local/pf/raddb/sites-enabled/eduroam
(513) Thu Jun 21 14:52:47 2018: Debug: authorize {
(513) Thu Jun 21 14:52:47 2018: Debug: update {
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND %{Packet-Src-IP-Address}
(513) Thu Jun 21 14:52:47 2018: Debug: --> 203.100.23.60
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND %l
(513) Thu Jun 21 14:52:47 2018: Debug: --> 1529567567
(513) Thu Jun 21 14:52:47 2018: Debug: } # update = noop
(513) Thu Jun 21 14:52:47 2018: Debug: policy rewrite_calling_station_id {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&Calling-Station-Id &&
(&Calling-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))
{
(513) Thu Jun 21 14:52:47 2018: Debug: if (&Calling-Station-Id &&
(&Calling-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))
-> TRUE
(513) Thu Jun 21 14:52:47 2018: Debug: if (&Calling-Station-Id &&
(&Calling-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))
{
(513) Thu Jun 21 14:52:47 2018: Debug: update request {
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(513) Thu Jun 21 14:52:47 2018: Debug: --> 0c:98:38:62:ca:8f
(513) Thu Jun 21 14:52:47 2018: Debug: } # update request = noop
(513) Thu Jun 21 14:52:47 2018: Debug: [updated] = updated
(513) Thu Jun 21 14:52:47 2018: Debug: } # if (&Calling-Station-Id &&
(&Calling-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))
= updated
(513) Thu Jun 21 14:52:47 2018: Debug: ... skipping else: Preceding "if"
was taken
(513) Thu Jun 21 14:52:47 2018: Debug: } # policy
rewrite_calling_station_id = updated
(513) Thu Jun 21 14:52:47 2018: Debug: policy rewrite_called_station_id {
(513) Thu Jun 21 14:52:47 2018: Debug: if ((&Called-Station-Id) &&
(&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
{
(513) Thu Jun 21 14:52:47 2018: Debug: if ((&Called-Station-Id) &&
(&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
-> TRUE
(513) Thu Jun 21 14:52:47 2018: Debug: if ((&Called-Station-Id) &&
(&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
{
(513) Thu Jun 21 14:52:47 2018: Debug: update request {
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(513) Thu Jun 21 14:52:47 2018: Debug: --> 84:b8:02:04:63:a0
(513) Thu Jun 21 14:52:47 2018: Debug: } # update request = noop
(513) Thu Jun 21 14:52:47 2018: Debug: if ("%{8}") {
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND %{8}
(513) Thu Jun 21 14:52:47 2018: Debug: --> eduroam
(513) Thu Jun 21 14:52:47 2018: Debug: if ("%{8}") -> TRUE
(513) Thu Jun 21 14:52:47 2018: Debug: if ("%{8}") {
(513) Thu Jun 21 14:52:47 2018: Debug: update request {
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND
%{Called-Station-Id}:%{8}
(513) Thu Jun 21 14:52:47 2018: Debug: -->
84:b8:02:04:63:a0:eduroam
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND %{8}
(513) Thu Jun 21 14:52:47 2018: Debug: --> eduroam
(513) Thu Jun 21 14:52:47 2018: Debug: } # update request = noop
(513) Thu Jun 21 14:52:47 2018: Debug: } # if ("%{8}") = noop
(513) Thu Jun 21 14:52:47 2018: Debug: ... skipping elsif: Preceding
"if" was taken
(513) Thu Jun 21 14:52:47 2018: Debug: ... skipping elsif: Preceding
"if" was taken
(513) Thu Jun 21 14:52:47 2018: Debug: ... skipping elsif: Preceding
"if" was taken
(513) Thu Jun 21 14:52:47 2018: Debug: [updated] = updated
(513) Thu Jun 21 14:52:47 2018: Debug: } # if ((&Called-Station-Id) &&
(&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
= updated
(513) Thu Jun 21 14:52:47 2018: Debug: ... skipping else: Preceding "if"
was taken
(513) Thu Jun 21 14:52:47 2018: Debug: } # policy rewrite_called_station_id
= updated
(513) Thu Jun 21 14:52:47 2018: Debug: policy filter_username {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name) -> TRUE
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ / /) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ / /) -> FALSE
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /@[^@]*@/ )
-> FALSE
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /\.\./ ) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /\.\./ ) ->
FALSE
(513) Thu Jun 21 14:52:47 2018: Debug: if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/)) {
(513) Thu Jun 21 14:52:47 2018: Debug: if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /\.$/) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /\.$/) ->
FALSE
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /@\./) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /@\./) ->
FALSE
(513) Thu Jun 21 14:52:47 2018: Debug: } # if (&User-Name) = updated
(513) Thu Jun 21 14:52:47 2018: Debug: } # policy filter_username = updated
(513) Thu Jun 21 14:52:47 2018: Debug: policy filter_password {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Password &&
(&User-Password != "%{string:User-Password}")) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Password &&
(&User-Password != "%{string:User-Password}")) -> FALSE
(513) Thu Jun 21 14:52:47 2018: Debug: } # policy filter_password = updated
(513) Thu Jun 21 14:52:47 2018: Debug: [preprocess] = ok
(513) Thu Jun 21 14:52:47 2018: Debug: suffix: Checking for suffix after "@"
(513) Thu Jun 21 14:52:47 2018: Debug: suffix: Looking up realm
"myuniversity.edu" for User-Name = "[email protected]"
(513) Thu Jun 21 14:52:47 2018: Debug: suffix: Found realm "myuniversity.edu"
(513) Thu Jun 21 14:52:47 2018: Debug: suffix: Adding Stripped-User-Name =
"prama"
(513) Thu Jun 21 14:52:47 2018: Debug: suffix: Adding Realm = "myuniversity.edu"
(513) Thu Jun 21 14:52:47 2018: Debug: suffix: Authentication realm is LOCAL
(513) Thu Jun 21 14:52:47 2018: Debug: [suffix] = ok
(513) Thu Jun 21 14:52:47 2018: Debug: ntdomain: Request already has
destination realm set. Ignoring
(513) Thu Jun 21 14:52:47 2018: Debug: [ntdomain] = noop
(513) Thu Jun 21 14:52:47 2018: Debug: if (User-Name =~ /@/) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (User-Name =~ /@/) -> TRUE
(513) Thu Jun 21 14:52:47 2018: Debug: if (User-Name =~ /@/) {
(513) Thu Jun 21 14:52:47 2018: Debug: if ( Realm == "myuniversity.edu" )
{
(513) Thu Jun 21 14:52:47 2018: Debug: if ( Realm == "myuniversity.edu" )
-> TRUE
(513) Thu Jun 21 14:52:47 2018: Debug: if ( Realm == "myuniversity.edu" )
{
(513) Thu Jun 21 14:52:47 2018: Debug: update control {
(513) Thu Jun 21 14:52:47 2018: Debug: } # update control = noop
(513) Thu Jun 21 14:52:47 2018: Debug: } # if ( Realm ==
"myuniversity.edu" ) = noop
(513) Thu Jun 21 14:52:47 2018: Debug: ... skipping else: Preceding "if"
was taken
(513) Thu Jun 21 14:52:47 2018: Debug: } # if (User-Name =~ /@/) = noop
(513) Thu Jun 21 14:52:47 2018: Debug: ... skipping else: Preceding "if"
was taken
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Peer sent EAP Response (code 2) ID
9 length 37
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Continuing tunnel setup
(513) Thu Jun 21 14:52:47 2018: Debug: [eap] = ok
(513) Thu Jun 21 14:52:47 2018: Debug: } # authorize = ok
(513) Thu Jun 21 14:52:47 2018: WARNING: You set Proxy-To-Realm = default, but
it is a LOCAL realm! Cancelling proxy request.
(513) Thu Jun 21 14:52:47 2018: Debug: Found Auth-Type = eap
(513) Thu Jun 21 14:52:47 2018: Debug: # Executing group from file
/usr/local/pf/raddb/sites-enabled/eduroam
(513) Thu Jun 21 14:52:47 2018: Debug: authenticate {
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Expiring EAP session with state
0xca7f480ecb765230
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Finished EAP session with state
0xf4599259f3508bde
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Previous EAP request found for
state 0xf4599259f3508bde, released from the list
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Peer sent packet with method EAP
PEAP (25)
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Calling submodule eap_peap to
process data
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: Continuing EAP-TLS
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: [eaptls verify] = ok
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: Done initial handshake
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: [eaptls process] = ok
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: Session established. Decoding
tunneled attributes
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: PEAP state phase2
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: EAP method MSCHAPv2 (26)
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: Got tunneled request
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: EAP-Message = 0x020900061a03
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: Setting User-Name to
[email protected]
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: Sending tunneled request to
packetfence-tunnel
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: EAP-Message = 0x020900061a03
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: FreeRADIUS-Proxied-To =
127.0.0.1
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: User-Name =
"[email protected]"
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: State =
0xca7f480ecb7652303a9e8566b6e8026d
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: Calling-Station-Id :=
"0c:98:38:62:ca:8f"
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: NAS-IP-Address =
192.168.127.8
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: NAS-Identifier = "WLC-RU-4"
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: Operator-Name = "1ru.nl"
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: Called-Station-Id :=
"84:b8:02:04:63:a0:eduroam"
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: Event-Timestamp = "Jun 21
2018 14:52:47 WIB"
(513) Thu Jun 21 14:52:47 2018: Debug: Virtual server packetfence-tunnel
received request
(513) Thu Jun 21 14:52:47 2018: Debug: EAP-Message = 0x020900061a03
(513) Thu Jun 21 14:52:47 2018: Debug: FreeRADIUS-Proxied-To = 127.0.0.1
(513) Thu Jun 21 14:52:47 2018: Debug: User-Name = "[email protected]"
(513) Thu Jun 21 14:52:47 2018: Debug: State =
0xca7f480ecb7652303a9e8566b6e8026d
(513) Thu Jun 21 14:52:47 2018: Debug: Calling-Station-Id :=
"0c:98:38:62:ca:8f"
(513) Thu Jun 21 14:52:47 2018: Debug: NAS-IP-Address = 192.168.127.8
(513) Thu Jun 21 14:52:47 2018: Debug: NAS-Identifier = "WLC-RU-4"
(513) Thu Jun 21 14:52:47 2018: Debug: Operator-Name = "1ru.nl"
(513) Thu Jun 21 14:52:47 2018: Debug: Called-Station-Id :=
"84:b8:02:04:63:a0:eduroam"
(513) Thu Jun 21 14:52:47 2018: Debug: Event-Timestamp = "Jun 21 2018
14:52:47 WIB"
(513) Thu Jun 21 14:52:47 2018: WARNING: Outer and inner identities are the
same. User privacy is compromised.
(513) Thu Jun 21 14:52:47 2018: Debug: server packetfence-tunnel {
(513) Thu Jun 21 14:52:47 2018: Debug: session-state: No cached attributes
(513) Thu Jun 21 14:52:47 2018: Debug: # Executing section authorize from
file /usr/local/pf/raddb/sites-enabled/packetfence-tunnel
(513) Thu Jun 21 14:52:47 2018: Debug: authorize {
(513) Thu Jun 21 14:52:47 2018: Debug: if ( outer.EAP-Type == TTLS) {
(513) Thu Jun 21 14:52:47 2018: Debug: if ( outer.EAP-Type == TTLS) ->
FALSE
(513) Thu Jun 21 14:52:47 2018: Debug: policy filter_username {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name) -> TRUE
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ / /) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ / /) ->
FALSE
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /@[^@]*@/ )
-> FALSE
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /\.\./ ) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /\.\./ ) ->
FALSE
(513) Thu Jun 21 14:52:47 2018: Debug: if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/)) {
(513) Thu Jun 21 14:52:47 2018: Debug: if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /\.$/) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /\.$/) ->
FALSE
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /@\./) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name =~ /@\./) ->
FALSE
(513) Thu Jun 21 14:52:47 2018: Debug: } # if (&User-Name) = notfound
(513) Thu Jun 21 14:52:47 2018: Debug: } # policy filter_username =
notfound
(513) Thu Jun 21 14:52:47 2018: Debug: [mschap] = noop
(513) Thu Jun 21 14:52:47 2018: Debug: suffix: Checking for suffix after "@"
(513) Thu Jun 21 14:52:47 2018: Debug: suffix: Looking up realm
"myuniversity.edu" for User-Name = "[email protected]"
(513) Thu Jun 21 14:52:47 2018: Debug: suffix: Found realm "myuniversity.edu"
(513) Thu Jun 21 14:52:47 2018: Debug: suffix: Adding Stripped-User-Name =
"prama"
(513) Thu Jun 21 14:52:47 2018: Debug: suffix: Adding Realm = "myuniversity.edu"
(513) Thu Jun 21 14:52:47 2018: Debug: suffix: Authentication realm is LOCAL
(513) Thu Jun 21 14:52:47 2018: Debug: [suffix] = ok
(513) Thu Jun 21 14:52:47 2018: Debug: ntdomain: Request already has
destination realm set. Ignoring
(513) Thu Jun 21 14:52:47 2018: Debug: [ntdomain] = noop
(513) Thu Jun 21 14:52:47 2018: Debug: update control {
(513) Thu Jun 21 14:52:47 2018: Debug: } # update control = noop
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Peer sent EAP Response (code 2) ID
9 length 6
(513) Thu Jun 21 14:52:47 2018: Debug: eap: No EAP Start, assuming it's an
on-going EAP conversation
(513) Thu Jun 21 14:52:47 2018: Debug: [eap] = updated
(513) Thu Jun 21 14:52:47 2018: Debug: policy rewrite_called_station_id {
(513) Thu Jun 21 14:52:47 2018: Debug: if ((&Called-Station-Id) &&
(&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
{
(513) Thu Jun 21 14:52:47 2018: Debug: if ((&Called-Station-Id) &&
(&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
-> TRUE
(513) Thu Jun 21 14:52:47 2018: Debug: if ((&Called-Station-Id) &&
(&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
{
(513) Thu Jun 21 14:52:47 2018: Debug: update request {
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(513) Thu Jun 21 14:52:47 2018: Debug: --> 84:b8:02:04:63:a0
(513) Thu Jun 21 14:52:47 2018: Debug: } # update request = noop
(513) Thu Jun 21 14:52:47 2018: Debug: if ("%{8}") {
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND %{8}
(513) Thu Jun 21 14:52:47 2018: Debug: --> eduroam
(513) Thu Jun 21 14:52:47 2018: Debug: if ("%{8}") -> TRUE
(513) Thu Jun 21 14:52:47 2018: Debug: if ("%{8}") {
(513) Thu Jun 21 14:52:47 2018: Debug: update request {
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND
%{Called-Station-Id}:%{8}
(513) Thu Jun 21 14:52:47 2018: Debug: -->
84:b8:02:04:63:a0:eduroam
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND %{8}
(513) Thu Jun 21 14:52:47 2018: Debug: --> eduroam
(513) Thu Jun 21 14:52:47 2018: Debug: } # update request = noop
(513) Thu Jun 21 14:52:47 2018: Debug: } # if ("%{8}") = noop
(513) Thu Jun 21 14:52:47 2018: Debug: ... skipping elsif: Preceding
"if" was taken
(513) Thu Jun 21 14:52:47 2018: Debug: ... skipping elsif: Preceding
"if" was taken
(513) Thu Jun 21 14:52:47 2018: Debug: ... skipping elsif: Preceding
"if" was taken
(513) Thu Jun 21 14:52:47 2018: Debug: [updated] = updated
(513) Thu Jun 21 14:52:47 2018: Debug: } # if ((&Called-Station-Id) &&
(&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
= updated
(513) Thu Jun 21 14:52:47 2018: Debug: ... skipping else: Preceding
"if" was taken
(513) Thu Jun 21 14:52:47 2018: Debug: } # policy
rewrite_called_station_id = updated
(513) Thu Jun 21 14:52:47 2018: Debug: ldap: EXPAND
(&(uid=%{%{Stripped-User-Name}:-%{User-Name}})(!(universityStatus=Blocked))(universityProxyStatus=TRUE)(&(|(!(universityStatus=Alumni))(&(universityStatus=Alumni)(|(universityStatus=Dosen)(universityStatus=Karyawan)(universityStatus=Peneliti))))))
(513) Thu Jun 21 14:52:47 2018: Debug: ldap: -->
(&(uid=prama)(!(universityStatus=Blocked))(universityProxyStatus=TRUE)(&(|(!(universityStatus=Alumni))(&(universityStatus=Alumni)(|(universityStatus=Dosen)(universityStatus=Karyawan)(universityStatus=Peneliti))))))
(513) Thu Jun 21 14:52:47 2018: Debug: ldap: Performing search in
"ou=people,dc=university,dc=ac,dc=id" with filter
"(&(uid=prama)(!(universityStatus=Blocked))(universityProxyStatus=TRUE)(&(|(!(universityStatus=Alumni))(&(universityStatus=Alumni)(|(universityStatus=Dosen)(universityStatus=Karyawan)(universityStatus=Peneliti))))))",
scope "sub"
(513) Thu Jun 21 14:52:47 2018: Debug: ldap: Waiting for search result...
(513) Thu Jun 21 14:52:47 2018: Debug: ldap: User object found at DN
"uid=prama,ou=people,dc=university,dc=ac,dc=id"
(513) Thu Jun 21 14:52:47 2018: Debug: ldap: Processing user attributes
(513) Thu Jun 21 14:52:47 2018: Debug: [ldap] = updated
(513) Thu Jun 21 14:52:47 2018: Debug: if (updated) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (updated) -> TRUE
(513) Thu Jun 21 14:52:47 2018: Debug: if (updated) {
(513) Thu Jun 21 14:52:47 2018: Debug: update control {
(513) Thu Jun 21 14:52:47 2018: Debug: } # update control = noop
(513) Thu Jun 21 14:52:47 2018: Debug: } # if (updated) = noop
(513) Thu Jun 21 14:52:47 2018: Debug: pap: Converted:
&control:Password-With-Header -> &control:SSHA1-Password
(513) Thu Jun 21 14:52:47 2018: Debug: pap: Removing
&control:Password-With-Header
(513) Thu Jun 21 14:52:47 2018: Debug: pap: No {...} in Password-With-Header,
re-writing to Cleartext-Password
(513) Thu Jun 21 14:52:47 2018: Debug: pap: Removing
&control:Password-With-Header
(513) Thu Jun 21 14:52:47 2018: Debug: pap: Normalizing SSHA1-Password from
base64 encoding, 32 bytes -> 24 bytes
(513) Thu Jun 21 14:52:47 2018: WARNING: pap: Auth-Type already set. Not
setting to PAP
(513) Thu Jun 21 14:52:47 2018: Debug: [pap] = noop
(513) Thu Jun 21 14:52:47 2018: Debug: } # authorize = updated
(513) Thu Jun 21 14:52:47 2018: WARNING: You set Proxy-To-Realm = local, but
it is a LOCAL realm! Cancelling proxy request.
(513) Thu Jun 21 14:52:47 2018: Debug: Found Auth-Type = eap
(513) Thu Jun 21 14:52:47 2018: Debug: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence-tunnel
(513) Thu Jun 21 14:52:47 2018: Debug: authenticate {
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Expiring EAP session with state
0xca7f480ecb765230
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Finished EAP session with state
0xca7f480ecb765230
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Previous EAP request found for
state 0xca7f480ecb765230, released from the list
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Peer sent packet with method EAP
MSCHAPv2 (26)
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Calling submodule eap_mschapv2 to
process data
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Sending EAP Success (code 3) ID 9
length 4
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Freeing handler
(513) Thu Jun 21 14:52:47 2018: Debug: [eap] = ok
(513) Thu Jun 21 14:52:47 2018: Debug: } # authenticate = ok
(513) Thu Jun 21 14:52:47 2018: Debug: # Executing section post-auth from
file /usr/local/pf/raddb/sites-enabled/packetfence-tunnel
(513) Thu Jun 21 14:52:47 2018: Debug: post-auth {
(513) Thu Jun 21 14:52:47 2018: Debug: policy packetfence-set-tenant-id {
(513) Thu Jun 21 14:52:47 2018: Debug: if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND
%{%{control:PacketFence-Tenant-Id}:-0}
(513) Thu Jun 21 14:52:47 2018: Debug: --> 0
(513) Thu Jun 21 14:52:47 2018: Debug: if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE
(513) Thu Jun 21 14:52:47 2018: Debug: if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
(513) Thu Jun 21 14:52:47 2018: Debug: update control {
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND %{User-Name}
(513) Thu Jun 21 14:52:47 2018: Debug: --> [email protected]
(513) Thu Jun 21 14:52:47 2018: Debug: SQL-User-Name set to
'[email protected]'
(513) Thu Jun 21 14:52:47 2018: Debug: Executing select query:
SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname =
'203.100.23.60'), 0)
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND %{sql: SELECT
IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname =
'%{Packet-Src-IP-Address}'), 0)}
(513) Thu Jun 21 14:52:47 2018: Debug: --> 0
(513) Thu Jun 21 14:52:47 2018: Debug: } # update control = noop
(513) Thu Jun 21 14:52:47 2018: Debug: } # if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop
(513) Thu Jun 21 14:52:47 2018: Debug: if (
&control:PacketFence-Tenant-Id == 0 ) {
(513) Thu Jun 21 14:52:47 2018: Debug: if (
&control:PacketFence-Tenant-Id == 0 ) -> TRUE
(513) Thu Jun 21 14:52:47 2018: Debug: if (
&control:PacketFence-Tenant-Id == 0 ) {
(513) Thu Jun 21 14:52:47 2018: Debug: update control {
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND %{User-Name}
(513) Thu Jun 21 14:52:47 2018: Debug: --> [email protected]
(513) Thu Jun 21 14:52:47 2018: Debug: SQL-User-Name set to
'[email protected]'
(513) Thu Jun 21 14:52:47 2018: Debug: Executing select query:
SELECT IFNULL((SELECT tenant_id from radius_nas WHERE start_ip <=
INET_ATON('203.100.23.60') and INET_ATON('203.100.23.60') <= end_ip order by
range_length limit 1), 1)
(513) Thu Jun 21 14:52:47 2018: Debug: EXPAND %{sql: SELECT
IFNULL((SELECT tenant_id from radius_nas WHERE start_ip <=
INET_ATON('%{Packet-Src-IP-Address}') and INET_ATON('%{Packet-Src-IP-Address}')
<= end_ip order by range_length limit 1), 1)}
(513) Thu Jun 21 14:52:47 2018: Debug: --> 1
(513) Thu Jun 21 14:52:47 2018: Debug: } # update control = noop
(513) Thu Jun 21 14:52:47 2018: Debug: } # if (
&control:PacketFence-Tenant-Id == 0 ) = noop
(513) Thu Jun 21 14:52:47 2018: Debug: } # policy
packetfence-set-tenant-id = noop
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Expanding URI components
(513) Thu Jun 21 14:52:47 2018: Debug: rest: EXPAND http://127.0.0.1:7070
(513) Thu Jun 21 14:52:47 2018: Debug: rest: --> http://127.0.0.1:7070
(513) Thu Jun 21 14:52:47 2018: Debug: rest: EXPAND //radius/rest/authorize
(513) Thu Jun 21 14:52:47 2018: Debug: rest: --> //radius/rest/authorize
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Sending HTTP POST to
"http://127.0.0.1:7070//radius/rest/authorize";
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute "User-Name"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute "NAS-IP-Address"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute "State"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute
"Called-Station-Id"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute
"Calling-Station-Id"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute "NAS-Identifier"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute
"Event-Timestamp"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute "EAP-Message"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute "Operator-Name"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute
"FreeRADIUS-Proxied-To"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute "EAP-Type"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute
"Stripped-User-Name"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute "Realm"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute "SQL-User-Name"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Encoding attribute
"Called-Station-SSID"
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Processing response header
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Status : 401 (Unauthorized)
(513) Thu Jun 21 14:52:47 2018: Debug: rest: Type : json (application/json)
(513) Thu Jun 21 14:52:47 2018: ERROR: rest: Server returned:
(513) Thu Jun 21 14:52:47 2018: ERROR: rest: Server returned:
(513) Thu Jun 21 14:52:47 2018: ERROR: rest:
{"control:PacketFence-Authorization-Status":"allow","Reply-Message":"Switch is
not managed by PacketFence","control:PacketFence-Request-Time":1529567567}
(513) Thu Jun 21 14:52:47 2018: Debug: [rest] = invalid
(513) Thu Jun 21 14:52:47 2018: Debug: } # post-auth = invalid
(513) Thu Jun 21 14:52:47 2018: Debug: Using Post-Auth-Type Reject
(513) Thu Jun 21 14:52:47 2018: Debug: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence-tunnel
(513) Thu Jun 21 14:52:47 2018: Debug: Post-Auth-Type REJECT {
(513) Thu Jun 21 14:52:47 2018: Debug: update {
(513) Thu Jun 21 14:52:47 2018: Debug: } # update = noop
(513) Thu Jun 21 14:52:47 2018: Debug: policy
packetfence-audit-log-reject {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name != "dummy") {
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name != "dummy") ->
TRUE
(513) Thu Jun 21 14:52:47 2018: Debug: if (&User-Name != "dummy") {
(513) Thu Jun 21 14:52:47 2018: Debug: policy request-timing {
(513) Thu Jun 21 14:52:47 2018: Debug: if
(control:PacketFence-Request-Time != 0) {
(513) Thu Jun 21 14:52:47 2018: ERROR: Failed retrieving values
required to evaluate condition
(513) Thu Jun 21 14:52:47 2018: Debug: } # policy request-timing =
noop
(513) Thu Jun 21 14:52:47 2018: Debug: sql_reject: EXPAND type.reject.query
(513) Thu Jun 21 14:52:47 2018: Debug: sql_reject: --> type.reject.query
(513) Thu Jun 21 14:52:47 2018: Debug: sql_reject: Using query template 'query'
(513) Thu Jun 21 14:52:47 2018: Debug: sql_reject: EXPAND %{User-Name}
(513) Thu Jun 21 14:52:47 2018: Debug: sql_reject: --> [email protected]
(513) Thu Jun 21 14:52:47 2018: Debug: sql_reject: SQL-User-Name set to
'[email protected]'
(513) Thu Jun 21 14:52:47 2018: Debug: sql_reject: EXPAND INSERT INTO
radius_audit_log ( mac, ip, computer_name, user_name,
stripped_user_name, realm, event_type, switch_id,
switch_mac, switch_ip_address, radius_source_ip_address,
called_station_id, calling_station_id, nas_port_type, ssid,
nas_port_id, ifindex, nas_port, connection_type,
nas_ip_address, nas_identifier, auth_status, reason, auth_type,
eap_type, role, node_status, profile, source,
auto_reg, is_phone, pf_domain, uuid, radius_request,
radius_reply, request_time, tenant_id) VALUES (
'%{request:Calling-Station-Id}', '%{request:Framed-IP-Address}',
'%{%{control:PacketFence-Computer-Name}:-N/A}', '%{request:User-Name}',
'%{request:Stripped-User-Name}', '%{request:Realm}',
'Radius-Access-Request',
'%{%{control:PacketFence-Switch-Id}:-N/A}',
'%{%{control:PacketFence-Switch-Mac}:-N/A}',
'%{%{control:PacketFence-Switch-Ip-Address}:-N/A}',
'%{Packet-Src-IP-Address}', '%{request:Called-Station-Id}',
'%{request:Calling-Station-Id}', '%{request:NAS-Port-Type}',
'%{request:Called-Station-SSID}', '%{request:NAS-Port-Id}',
'%{%{control:PacketFence-IfIndex}:-N/A}', '%{request:NAS-Port}',
'%{%{control:PacketFence-Connection-Type}:-N/A}',
'%{request:NAS-IP-Address}', '%{request:NAS-Identifier}', 'Reject',
'%{request:Module-Failure-Message}', '%{control:Auth-Type}',
'%{request:EAP-Type}', '%{%{control:PacketFence-Role}:-N/A}',
'%{%{control:PacketFence-Status}:-N/A}',
'%{%{control:PacketFence-Profile}:-N/A}',
'%{%{control:PacketFence-Source}:-N/A}',
'%{%{control:PacketFence-AutoReg}:-0}', '%{%{control:PacketFence-IsPhone}:-0}',
'%{request:PacketFence-Domain}', '',
'%{pairs:&request:[*]}','%{pairs:&reply:[*]}',
'%{%{control:PacketFence-Request-Time}:-N/A}',
'%{control:PacketFence-Tenant-Id}')
(513) Thu Jun 21 14:52:47 2018: Debug: sql_reject: --> INSERT INTO
radius_audit_log ( mac, ip, computer_name, user_name,
stripped_user_name, realm, event_type, switch_id,
switch_mac, switch_ip_address, radius_source_ip_address,
called_station_id, calling_station_id, nas_port_type, ssid,
nas_port_id, ifindex, nas_port, connection_type,
nas_ip_address, nas_identifier, auth_status, reason, auth_type,
eap_type, role, node_status, profile, source,
auto_reg, is_phone, pf_domain, uuid, radius_request,
radius_reply, request_time, tenant_id) VALUES (
'0c:98:38:62:ca:8f', '', 'N/A', '[email protected]',
'prama', 'myuniversity.edu', 'Radius-Access-Request', 'N/A',
'N/A', 'N/A', '203.100.23.60', '84:b8:02:04:63:a0:eduroam',
'0c:98:38:62:ca:8f', '', 'eduroam', '', 'N/A',
'', 'N/A', '192.168.127.8', 'WLC-RU-4', 'Reject',
'rest: Server returned:', 'eap', 'MSCHAPv2', 'N/A', 'N/A',
'N/A', 'N/A', '0', '0', '', '', 'User-Name =3D
[email protected]=22=2C NAS-IP-Address =3D 192.168.127.8=2C State =3D
0xca7f480ecb7652303a9e8566b6e8026d=2C Called-Station-Id =3D
=2284:b8:02:04:63:a0:eduroam=22=2C Calling-Station-Id =3D
=220c:98:38:62:ca:8f=22=2C NAS-Identifier =3D =22WLC-RU-4=22=2C Event-Timestamp
=3D =22Jun 21 2018 14:52:47 WIB=22=2C EAP-Message =3D 0x020900061a03=2C
Operator-Name =3D =221ru.nl=22=2C FreeRADIUS-Proxied-To =3D 127.0.0.1=2C
EAP-Type =3D MSCHAPv2=2C Stripped-User-Name =3D =22prama=22=2C Realm =3D
=22myuniversity.edu=22=2C Called-Station-SSID =3D =22eduroam=22=2C
Module-Failure-Message =3D =22rest: Server returned:=22=2C
Module-Failure-Message =3D =22rest:
=7B=5C=22control:PacketFence-Authorization-Status=5C=22:=5C=22allow=5C=22=2C=5C=22Reply-Message=5C=22:=5C=22Switch
is not managed by
PacketFence=5C=22=2C=5C=22control:PacketFence-Request-Time=5C=22:1529567567=7D=22=2C
User-Password =3D =22=2A=2A=2A=2A=2A=2A=22=2C Module-Failure-Message =3D
=22Failed retrieving values required to evaluate condition=22=2C SQL-User-Name
=3D [email protected]=22','MS-MPPE-Encryption-Policy =3D
Encryption-Required=2C MS-MPPE-Encryption-Types =3D 4=2C MS-MPPE-Send-Key =3D
0x056c7c42a8d963e4777ec62dc6a0268d=2C MS-MPPE-Recv-Key =3D
0x91a0bfdbe32c0526a7ea7945617f8011=2C EAP-Message =3D 0x03090004=2C
Message-Authenticator =3D 0x00000000000000000000000000000000=2C
Stripped-User-Name =3D =22prama=22', 'N/A', '1')
(513) Thu Jun 21 14:52:47 2018: Debug: sql_reject: Executing query: INSERT INTO
radius_audit_log ( mac, ip, computer_name, user_name,
stripped_user_name, realm, event_type, switch_id,
switch_mac, switch_ip_address, radius_source_ip_address,
called_station_id, calling_station_id, nas_port_type, ssid,
nas_port_id, ifindex, nas_port, connection_type,
nas_ip_address, nas_identifier, auth_status, reason, auth_type,
eap_type, role, node_status, profile, source,
auto_reg, is_phone, pf_domain, uuid, radius_request,
radius_reply, request_time, tenant_id) VALUES (
'0c:98:38:62:ca:8f', '', 'N/A', '[email protected]',
'prama', 'myuniversity.edu', 'Radius-Access-Request', 'N/A',
'N/A', 'N/A', '203.100.23.60', '84:b8:02:04:63:a0:eduroam',
'0c:98:38:62:ca:8f', '', 'eduroam', '', 'N/A',
'', 'N/A', '192.168.127.8', 'WLC-RU-4', 'Reject',
'rest: Server returned:', 'eap', 'MSCHAPv2', 'N/A', 'N/A',
'N/A', 'N/A', '0', '0', '', '', 'User-Name =3D
[email protected]=22=2C NAS-IP-Address =3D 192.168.127.8=2C State =3D
0xca7f480ecb7652303a9e8566b6e8026d=2C Called-Station-Id =3D
=2284:b8:02:04:63:a0:eduroam=22=2C Calling-Station-Id =3D
=220c:98:38:62:ca:8f=22=2C NAS-Identifier =3D =22WLC-RU-4=22=2C Event-Timestamp
=3D =22Jun 21 2018 14:52:47 WIB=22=2C EAP-Message =3D 0x020900061a03=2C
Operator-Name =3D =221ru.nl=22=2C FreeRADIUS-Proxied-To =3D 127.0.0.1=2C
EAP-Type =3D MSCHAPv2=2C Stripped-User-Name =3D =22prama=22=2C Realm =3D
=22myuniversity.edu=22=2C Called-Station-SSID =3D =22eduroam=22=2C
Module-Failure-Message =3D =22rest: Server returned:=22=2C
Module-Failure-Message =3D =22rest:
=7B=5C=22control:PacketFence-Authorization-Status=5C=22:=5C=22allow=5C=22=2C=5C=22Reply-Message=5C=22:=5C=22Switch
is not managed by
PacketFence=5C=22=2C=5C=22control:PacketFence-Request-Time=5C=22:1529567567=7D=22=2C
User-Password =3D =22=2A=2A=2A=2A=2A=2A=22=2C Module-Failure-Message =3D
=22Failed retrieving values required to evaluate condition=22=2C SQL-User-Name
=3D [email protected]=22','MS-MPPE-Encryption-Policy =3D
Encryption-Required=2C MS-MPPE-Encryption-Types =3D 4=2C MS-MPPE-Send-Key =3D
0x056c7c42a8d963e4777ec62dc6a0268d=2C MS-MPPE-Recv-Key =3D
0x91a0bfdbe32c0526a7ea7945617f8011=2C EAP-Message =3D 0x03090004=2C
Message-Authenticator =3D 0x00000000000000000000000000000000=2C
Stripped-User-Name =3D =22prama=22', 'N/A', '1')
(513) Thu Jun 21 14:52:47 2018: Debug: sql_reject: SQL query returned: success
(513) Thu Jun 21 14:52:47 2018: Debug: sql_reject: 1 record(s) updated
(513) Thu Jun 21 14:52:47 2018: Debug: [sql_reject] = ok
(513) Thu Jun 21 14:52:47 2018: Debug: } # if (&User-Name != "dummy")
= ok
(513) Thu Jun 21 14:52:47 2018: Debug: } # policy
packetfence-audit-log-reject = ok
(513) Thu Jun 21 14:52:47 2018: Debug: attr_filter.access_reject: EXPAND
%{User-Name}
(513) Thu Jun 21 14:52:47 2018: Debug: attr_filter.access_reject: -->
[email protected]
(513) Thu Jun 21 14:52:47 2018: Debug: attr_filter.access_reject: Matched entry
DEFAULT at line 11
(513) Thu Jun 21 14:52:47 2018: Debug: [attr_filter.access_reject] =
updated
(513) Thu Jun 21 14:52:47 2018: Debug: update outer.session-state {
(513) Thu Jun 21 14:52:47 2018: Debug: } # update outer.session-state =
noop
(513) Thu Jun 21 14:52:47 2018: Debug: } # Post-Auth-Type REJECT = updated
(513) Thu Jun 21 14:52:47 2018: Debug: } # server packetfence-tunnel
(513) Thu Jun 21 14:52:47 2018: Debug: Virtual server sending reply
(513) Thu Jun 21 14:52:47 2018: Debug: EAP-Message = 0x03090004
(513) Thu Jun 21 14:52:47 2018: Debug: Message-Authenticator =
0x00000000000000000000000000000000
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: Got tunneled reply code 3
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: EAP-Message = 0x03090004
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: Message-Authenticator =
0x00000000000000000000000000000000
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: Tunneled authentication was
rejected
(513) Thu Jun 21 14:52:47 2018: Debug: eap_peap: FAILURE
(513) Thu Jun 21 14:52:47 2018: Debug: eap: Sending EAP Request (code 1) ID 10
length 46
(513) Thu Jun 21 14:52:47 2018: Debug: eap: EAP session adding &reply:State =
0xf4599259fc538bde
(513) Thu Jun 21 14:52:47 2018: Debug: [eap] = handled
(513) Thu Jun 21 14:52:47 2018: Debug: } # authenticate = handled
(513) Thu Jun 21 14:52:47 2018: Debug: Using Post-Auth-Type Challenge
(513) Thu Jun 21 14:52:47 2018: Debug: Post-Auth-Type sub-section not found.
Ignoring.
(513) Thu Jun 21 14:52:47 2018: Debug: # Executing group from file
/usr/local/pf/raddb/sites-enabled/eduroam
(513) Thu Jun 21 14:52:47 2018: Debug: session-state: Saving cached attributes
(513) Thu Jun 21 14:52:47 2018: Debug: Module-Failure-Message := "rest:
Server returned:"
(513) Thu Jun 21 14:52:47 2018: Debug: Sent Access-Challenge Id 168 from
203.100.59.39:11812 to 203.100.23.60:42290 length 0
(513) Thu Jun 21 14:52:47 2018: Debug: EAP-Message =
0x010a002e19001703030023c222f6365e2a6d804d8867ac92c0b477d8f6faedcc15457dd2673e6691ab11f0d4cd32
(513) Thu Jun 21 14:52:47 2018: Debug: Message-Authenticator =
0x00000000000000000000000000000000
(513) Thu Jun 21 14:52:47 2018: Debug: State =
0xf4599259fc538bde1444eca174e1fcad
(513) Thu Jun 21 14:52:47 2018: Debug: Proxy-State = 0x3238
(513) Thu Jun 21 14:52:47 2018: Debug: Proxy-State = 0x3533
(513) Thu Jun 21 14:52:47 2018: Debug: Finished request
------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
PacketFence-users mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/packetfence-users
