Radius AD authentication issue
Franck Rakotonindrainy
franck.rakotonindrainy at fresenius-kabi.com
Mon Feb 24 10:51:05 CET 2020
Hello the list,
I have an issue in my radius authentication and I am unable to understand the cause of the issue, If anybody could point me to some tips for debugging
("same" config works on two other servers)
here is part of the debug log :
(253) Thu Feb 20 17:21:38 2020: Debug: Received Access-Request Id 170 from 10.211.120.171:49563 to 10.211.120.158:1812 length 514
(253) Thu Feb 20 17:21:38 2020: Debug: Framed-MTU = 1480
(253) Thu Feb 20 17:21:38 2020: Debug: NAS-IP-Address = 192.168.xxx.yyy
(253) Thu Feb 20 17:21:38 2020: Debug: NAS-Identifier = "SWAA-FV001234"
(253) Thu Feb 20 17:21:38 2020: Debug: User-Name = "host/FV004665.kabi.ads.fresenius.com"
(253) Thu Feb 20 17:21:38 2020: Debug: Service-Type = Framed-User
(253) Thu Feb 20 17:21:38 2020: Debug: Framed-Protocol = PPP
(253) Thu Feb 20 17:21:38 2020: Debug: NAS-Port = 40
(253) Thu Feb 20 17:21:38 2020: Debug: NAS-Port-Type = Ethernet
(253) Thu Feb 20 17:21:38 2020: Debug: NAS-Port-Id = "40"
(253) Thu Feb 20 17:21:38 2020: Debug: Called-Station-Id = "04-09-73-cc-dd-ee"
(253) Thu Feb 20 17:21:38 2020: Debug: Calling-Station-Id = "10-65-30-aa-bb-cc"
(253) Thu Feb 20 17:21:38 2020: Debug: Connect-Info = "CONNECT Ethernet 100Mbps Full duplex"
(253) Thu Feb 20 17:21:38 2020: Debug: Tunnel-Type:0 = VLAN
(253) Thu Feb 20 17:21:38 2020: Debug: Tunnel-Medium-Type:0 = IEEE-802
(253) Thu Feb 20 17:21:38 2020: Debug: Tunnel-Private-Group-Id:0 = "1136"
(253) Thu Feb 20 17:21:38 2020: Debug: State = 0xfa22c4baff2add06e61b85de3ed7b62c
(253) Thu Feb 20 17:21:38 2020: Debug: EAP-Message = 0x020800481900170303003d000000000000000123354593f8cee502592de9ad1a0b7d82103e59ac4049d7de806c086b98762c715fd0d287de74eb9828d7e4c143b6a8b09ddbeafcc5
(253) Thu Feb 20 17:21:38 2020: Debug: Message-Authenticator = 0xe58b264bf83043caafe7f2b4682ac5d7
(253) Thu Feb 20 17:21:38 2020: Debug: MS-RAS-Vendor = 11
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x011a0000000b28
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x011a0000000b2e
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x011a0000000b30
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x011a0000000b3d
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x011a0000000b18
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x011a0000000b19
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x0138
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x013a
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x0140
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x0141
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x0151
(253) Thu Feb 20 17:21:38 2020: Debug: PacketFence-KeyBalanced = "df58829ae3956b8619f745de7ed1580b"
(253) Thu Feb 20 17:21:38 2020: Debug: Proxy-State = 0x313237
(253) Thu Feb 20 17:21:38 2020: Debug: Restoring &session-state
(253) Thu Feb 20 17:21:38 2020: Debug: &session-state:TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(253) Thu Feb 20 17:21:38 2020: Debug: &session-state:TLS-Session-Version = "TLS 1.2"
(253) Thu Feb 20 17:21:38 2020: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence
(253) Thu Feb 20 17:21:38 2020: Debug: authorize {
(253) Thu Feb 20 17:21:38 2020: Debug: update {
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{Packet-Src-IP-Address}
(253) Thu Feb 20 17:21:38 2020: Debug: --> 10.211.120.171
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{Packet-Dst-IP-Address}
(253) Thu Feb 20 17:21:38 2020: Debug: --> 10.211.120.158
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %l
(253) Thu Feb 20 17:21:38 2020: Debug: --> 1582215698
(253) Thu Feb 20 17:21:38 2020: Debug: } # update = noop
(253) Thu Feb 20 17:21:38 2020: Debug: policy packetfence-set-realm-if-machine {
(253) Thu Feb 20 17:21:38 2020: Debug: if (User-Name =~ /host\/([a-z0-9_-]*)[\.](.*)/i) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (User-Name =~ /host\/([a-z0-9_-]*)[\.](.*)/i) -> TRUE
(253) Thu Feb 20 17:21:38 2020: Debug: if (User-Name =~ /host\/([a-z0-9_-]*)[\.](.*)/i) {
(253) Thu Feb 20 17:21:38 2020: Debug: update {
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{2}
(253) Thu Feb 20 17:21:38 2020: Debug: --> kabi.ads.fresenius.com
(253) Thu Feb 20 17:21:38 2020: Debug: } # update = noop
(253) Thu Feb 20 17:21:38 2020: Debug: } # if (User-Name =~ /host\/([a-z0-9_-]*)[\.](.*)/i) = noop
(253) Thu Feb 20 17:21:38 2020: Debug: } # policy packetfence-set-realm-if-machine = noop
(253) Thu Feb 20 17:21:38 2020: Debug: policy packetfence-balanced-key-policy {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.*)(.)$/i)) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.*)(.)$/i)) -> TRUE
(253) Thu Feb 20 17:21:38 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.*)(.)$/i)) {
(253) Thu Feb 20 17:21:38 2020: Debug: update {
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{md5:%{2}%{1}}
(253) Thu Feb 20 17:21:38 2020: Debug: --> 785ef37fa229298f465f6b3eee6eeb38
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{md5:%{2}%{1}}
(253) Thu Feb 20 17:21:38 2020: Debug: --> 785ef37fa229298f465f6b3eee6eeb38
(253) Thu Feb 20 17:21:38 2020: Debug: } # update = noop
(253) Thu Feb 20 17:21:38 2020: Debug: } # if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.*)(.)$/i)) = noop
(253) Thu Feb 20 17:21:38 2020: Debug: ... skipping else: Preceding "if" was taken
(253) Thu Feb 20 17:21:38 2020: Debug: } # policy packetfence-balanced-key-policy = noop
(253) Thu Feb 20 17:21:38 2020: Debug: policy packetfence-set-tenant-id {
(253) Thu Feb 20 17:21:38 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){
(253) Thu Feb 20 17:21:38 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0}
(253) Thu Feb 20 17:21:38 2020: Debug: --> 0
(253) Thu Feb 20 17:21:38 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE
(253) Thu Feb 20 17:21:38 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
(253) Thu Feb 20 17:21:38 2020: Debug: update control {
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{User-Name}
(253) Thu Feb 20 17:21:38 2020: Debug: --> host/FV004665.kabi.ads.fresenius.com
(253) Thu Feb 20 17:21:38 2020: Debug: SQL-User-Name set to 'host/FV004665.kabi.ads.fresenius.com'
(253) Thu Feb 20 17:21:38 2020: Debug: Executing select query: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '192.168.xxx.yyy'), 0)
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{sql: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '%{NAS-IP-Address}'), 0)}
(253) Thu Feb 20 17:21:38 2020: Debug: --> 1
(253) Thu Feb 20 17:21:38 2020: Debug: } # update control = noop
(253) Thu Feb 20 17:21:38 2020: Debug: } # if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop
(253) Thu Feb 20 17:21:38 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) {
(253) Thu Feb 20 17:21:38 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: } # policy packetfence-set-tenant-id = noop
(253) Thu Feb 20 17:21:38 2020: Debug: policy rewrite_calling_station_id {
(253) Thu Feb 20 17:21:38 2020: 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)) {
(253) Thu Feb 20 17:21:38 2020: 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
(253) Thu Feb 20 17:21:38 2020: 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)) {
(253) Thu Feb 20 17:21:38 2020: Debug: update request {
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(253) Thu Feb 20 17:21:38 2020: Debug: --> 10:65:30:aa:bb:cc
(253) Thu Feb 20 17:21:38 2020: Debug: } # update request = noop
(253) Thu Feb 20 17:21:38 2020: Debug: [updated] = updated
(253) Thu Feb 20 17:21:38 2020: 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
(253) Thu Feb 20 17:21:38 2020: Debug: ... skipping else: Preceding "if" was taken
(253) Thu Feb 20 17:21:38 2020: Debug: } # policy rewrite_calling_station_id = updated
(253) Thu Feb 20 17:21:38 2020: Debug: policy rewrite_called_station_id {
(253) Thu Feb 20 17:21:38 2020: 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)) {
(253) Thu Feb 20 17:21:38 2020: 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
(253) Thu Feb 20 17:21:38 2020: 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)) {
(253) Thu Feb 20 17:21:38 2020: Debug: update request {
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(253) Thu Feb 20 17:21:38 2020: Debug: --> 04:09:73:cc:dd:ee
(253) Thu Feb 20 17:21:38 2020: Debug: } # update request = noop
(253) Thu Feb 20 17:21:38 2020: Debug: if ("%{8}") {
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{8}
(253) Thu Feb 20 17:21:38 2020: Debug: -->
(253) Thu Feb 20 17:21:38 2020: Debug: if ("%{8}") -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) {
(253) Thu Feb 20 17:21:38 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: elsif (Aruba-Essid-Name) {
(253) Thu Feb 20 17:21:38 2020: Debug: elsif (Aruba-Essid-Name) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) {
(253) Thu Feb 20 17:21:38 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: [updated] = updated
(253) Thu Feb 20 17:21:38 2020: 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
(253) Thu Feb 20 17:21:38 2020: Debug: ... skipping else: Preceding "if" was taken
(253) Thu Feb 20 17:21:38 2020: Debug: } # policy rewrite_called_station_id = updated
(253) Thu Feb 20 17:21:38 2020: Debug: policy filter_username {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name) -> TRUE
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ / /) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ / /) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /@[^@]*@/ ) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /\.\./ ) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /\.\./ ) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {
(253) Thu Feb 20 17:21:38 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /\.$/) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /\.$/) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /@\./) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /@\./) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: } # if (&User-Name) = updated
(253) Thu Feb 20 17:21:38 2020: Debug: } # policy filter_username = updated
(253) Thu Feb 20 17:21:38 2020: Debug: policy filter_password {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: } # policy filter_password = updated
(253) Thu Feb 20 17:21:38 2020: Debug: [preprocess] = ok
(253) Thu Feb 20 17:21:38 2020: Debug: suffix: Request already has destination realm set. Ignoring
(253) Thu Feb 20 17:21:38 2020: Debug: [suffix] = noop
(253) Thu Feb 20 17:21:38 2020: Debug: ntdomain: Request already has destination realm set. Ignoring
(253) Thu Feb 20 17:21:38 2020: Debug: [ntdomain] = noop
(253) Thu Feb 20 17:21:38 2020: Debug: eap: Peer sent EAP Response (code 2) ID 8 length 72
(253) Thu Feb 20 17:21:38 2020: Debug: eap: Continuing tunnel setup
(253) Thu Feb 20 17:21:38 2020: Debug: [eap] = ok
(253) Thu Feb 20 17:21:38 2020: Debug: } # authorize = ok
(253) Thu Feb 20 17:21:38 2020: Debug: Found Auth-Type = eap
(253) Thu Feb 20 17:21:38 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence
(253) Thu Feb 20 17:21:38 2020: Debug: authenticate {
(253) Thu Feb 20 17:21:38 2020: Debug: eap: Expiring EAP session with state 0xfa22c4baff2add06
(253) Thu Feb 20 17:21:38 2020: Debug: eap: Finished EAP session with state 0xfa22c4baff2add06
(253) Thu Feb 20 17:21:38 2020: Debug: eap: Previous EAP request found for state 0xfa22c4baff2add06, released from the list
(253) Thu Feb 20 17:21:38 2020: Debug: eap: Peer sent packet with method EAP PEAP (25)
(253) Thu Feb 20 17:21:38 2020: Debug: eap: Calling submodule eap_peap to process data
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Continuing EAP-TLS
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: [eaptls verify] = ok
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Done initial handshake
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: [eaptls process] = ok
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Session established. Decoding tunneled attributes
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: PEAP state WAITING FOR INNER IDENTITY
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Identity - host/FV004665.kabi.ads.fresenius.com
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Got inner identity 'host/FV004665.kabi.ads.fresenius.com'
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Setting default EAP type for tunneled EAP session
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Got tunneled request
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: EAP-Message = 0x0208002901686f73742f46563030343636352e6b6162692e6164732e66726573656e6975732e636f6d
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Setting User-Name to host/FV004665.kabi.ads.fresenius.com
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Sending tunneled request to packetfence-tunnel
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: EAP-Message = 0x0208002901686f73742f46563030343636352e6b6162692e6164732e66726573656e6975732e636f6d
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: User-Name = "host/FV004665.kabi.ads.fresenius.com"
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Framed-MTU = 1480
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: NAS-IP-Address = 192.168.xxx.yyy
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: NAS-Identifier = "SWAA-FV001234"
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Service-Type = Framed-User
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Framed-Protocol = PPP
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: NAS-Port = 40
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: NAS-Port-Type = Ethernet
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: NAS-Port-Id = "40"
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Calling-Station-Id := "10:65:30:aa:bb:cc"
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Connect-Info = "CONNECT Ethernet 100Mbps Full duplex"
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Tunnel-Type:0 = VLAN
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Tunnel-Medium-Type:0 = IEEE-802
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Tunnel-Private-Group-Id:0 = "1136"
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: MS-RAS-Vendor = 11
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: HP-Capability-Advert = 0x011a0000000b28
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: HP-Capability-Advert = 0x011a0000000b2e
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: HP-Capability-Advert = 0x011a0000000b30
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: HP-Capability-Advert = 0x011a0000000b3d
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: HP-Capability-Advert = 0x011a0000000b18
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: HP-Capability-Advert = 0x011a0000000b19
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: HP-Capability-Advert = 0x0138
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: HP-Capability-Advert = 0x013a
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: HP-Capability-Advert = 0x0140
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: HP-Capability-Advert = 0x0141
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: HP-Capability-Advert = 0x0151
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: PacketFence-KeyBalanced := "785ef37fa229298f465f6b3eee6eeb38"
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: PacketFence-Radius-Ip := "10.211.120.158"
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Called-Station-Id := "04:09:73:cc:dd:ee"
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Event-Timestamp = "févr. 20 2020 17:21:38 CET"
(253) Thu Feb 20 17:21:38 2020: Debug: Virtual server packetfence-tunnel received request
(253) Thu Feb 20 17:21:38 2020: Debug: EAP-Message = 0x0208002901686f73742f46563030343636352e6b6162692e6164732e66726573656e6975732e636f6d
(253) Thu Feb 20 17:21:38 2020: Debug: FreeRADIUS-Proxied-To = 127.0.0.1
(253) Thu Feb 20 17:21:38 2020: Debug: User-Name = "host/FV004665.kabi.ads.fresenius.com"
(253) Thu Feb 20 17:21:38 2020: Debug: Framed-MTU = 1480
(253) Thu Feb 20 17:21:38 2020: Debug: NAS-IP-Address = 192.168.xxx.yyy
(253) Thu Feb 20 17:21:38 2020: Debug: NAS-Identifier = "SWAA-FV001234"
(253) Thu Feb 20 17:21:38 2020: Debug: Service-Type = Framed-User
(253) Thu Feb 20 17:21:38 2020: Debug: Framed-Protocol = PPP
(253) Thu Feb 20 17:21:38 2020: Debug: NAS-Port = 40
(253) Thu Feb 20 17:21:38 2020: Debug: NAS-Port-Type = Ethernet
(253) Thu Feb 20 17:21:38 2020: Debug: NAS-Port-Id = "40"
(253) Thu Feb 20 17:21:38 2020: Debug: Calling-Station-Id := "10:65:30:aa:bb:cc"
(253) Thu Feb 20 17:21:38 2020: Debug: Connect-Info = "CONNECT Ethernet 100Mbps Full duplex"
(253) Thu Feb 20 17:21:38 2020: Debug: Tunnel-Type:0 = VLAN
(253) Thu Feb 20 17:21:38 2020: Debug: Tunnel-Medium-Type:0 = IEEE-802
(253) Thu Feb 20 17:21:38 2020: Debug: Tunnel-Private-Group-Id:0 = "1136"
(253) Thu Feb 20 17:21:38 2020: Debug: MS-RAS-Vendor = 11
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x011a0000000b28
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x011a0000000b2e
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x011a0000000b30
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x011a0000000b3d
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x011a0000000b18
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x011a0000000b19
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x0138
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x013a
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x0140
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x0141
(253) Thu Feb 20 17:21:38 2020: Debug: HP-Capability-Advert = 0x0151
(253) Thu Feb 20 17:21:38 2020: Debug: PacketFence-KeyBalanced := "785ef37fa229298f465f6b3eee6eeb38"
(253) Thu Feb 20 17:21:38 2020: Debug: PacketFence-Radius-Ip := "10.211.120.158"
(253) Thu Feb 20 17:21:38 2020: Debug: Called-Station-Id := "04:09:73:cc:dd:ee"
(253) Thu Feb 20 17:21:38 2020: Debug: Event-Timestamp = "févr. 20 2020 17:21:38 CET"
(253) Thu Feb 20 17:21:38 2020: WARNING: Outer and inner identities are the same. User privacy is compromised.
(253) Thu Feb 20 17:21:38 2020: Debug: server packetfence-tunnel {
(253) Thu Feb 20 17:21:38 2020: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence-tunnel
(253) Thu Feb 20 17:21:38 2020: Debug: authorize {
(253) Thu Feb 20 17:21:38 2020: Debug: if ( outer.EAP-Type == TTLS) {
(253) Thu Feb 20 17:21:38 2020: Debug: if ( outer.EAP-Type == TTLS) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: policy packetfence-set-realm-if-machine {
(253) Thu Feb 20 17:21:38 2020: Debug: if (User-Name =~ /host\/([a-z0-9_-]*)[\.](.*)/i) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (User-Name =~ /host\/([a-z0-9_-]*)[\.](.*)/i) -> TRUE
(253) Thu Feb 20 17:21:38 2020: Debug: if (User-Name =~ /host\/([a-z0-9_-]*)[\.](.*)/i) {
(253) Thu Feb 20 17:21:38 2020: Debug: update {
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{2}
(253) Thu Feb 20 17:21:38 2020: Debug: --> kabi.ads.fresenius.com
(253) Thu Feb 20 17:21:38 2020: Debug: } # update = noop
(253) Thu Feb 20 17:21:38 2020: Debug: } # if (User-Name =~ /host\/([a-z0-9_-]*)[\.](.*)/i) = noop
(253) Thu Feb 20 17:21:38 2020: Debug: } # policy packetfence-set-realm-if-machine = noop
(253) Thu Feb 20 17:21:38 2020: Debug: policy packetfence-set-tenant-id {
(253) Thu Feb 20 17:21:38 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){
(253) Thu Feb 20 17:21:38 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0}
(253) Thu Feb 20 17:21:38 2020: Debug: --> 0
(253) Thu Feb 20 17:21:38 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE
(253) Thu Feb 20 17:21:38 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
(253) Thu Feb 20 17:21:38 2020: Debug: update control {
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{User-Name}
(253) Thu Feb 20 17:21:38 2020: Debug: --> host/FV004665.kabi.ads.fresenius.com
(253) Thu Feb 20 17:21:38 2020: Debug: SQL-User-Name set to 'host/FV004665.kabi.ads.fresenius.com'
(253) Thu Feb 20 17:21:38 2020: Debug: Executing select query: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '192.168.xxx.yyy'), 0)
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{sql: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '%{NAS-IP-Address}'), 0)}
(253) Thu Feb 20 17:21:38 2020: Debug: --> 1
(253) Thu Feb 20 17:21:38 2020: Debug: } # update control = noop
(253) Thu Feb 20 17:21:38 2020: Debug: } # if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop
(253) Thu Feb 20 17:21:38 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) {
(253) Thu Feb 20 17:21:38 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: } # policy packetfence-set-tenant-id = noop
(253) Thu Feb 20 17:21:38 2020: Debug: policy filter_username {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name) -> TRUE
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ / /) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ / /) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /@[^@]*@/ ) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /\.\./ ) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /\.\./ ) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {
(253) Thu Feb 20 17:21:38 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /\.$/) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /\.$/) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /@\./) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name =~ /@\./) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: } # if (&User-Name) = noop
(253) Thu Feb 20 17:21:38 2020: Debug: } # policy filter_username = noop
(253) Thu Feb 20 17:21:38 2020: Debug: [mschap] = noop
(253) Thu Feb 20 17:21:38 2020: Debug: suffix: Request already has destination realm set. Ignoring
(253) Thu Feb 20 17:21:38 2020: Debug: [suffix] = noop
(253) Thu Feb 20 17:21:38 2020: Debug: ntdomain: Request already has destination realm set. Ignoring
(253) Thu Feb 20 17:21:38 2020: Debug: [ntdomain] = noop
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'User-Name'} = &request:User-Name -> 'host/FV004665.kabi.ads.fresenius.com'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'NAS-IP-Address'} = &request:NAS-IP-Address -> '192.168.xxx.yyy'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'NAS-Port'} = &request:NAS-Port -> '40'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Service-Type'} = &request:Service-Type -> 'Framed-User'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Framed-Protocol'} = &request:Framed-Protocol -> 'PPP'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Framed-MTU'} = &request:Framed-MTU -> '1480'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Called-Station-Id'} = &request:Called-Station-Id -> '04:09:73:cc:dd:ee'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Calling-Station-Id'} = &request:Calling-Station-Id -> '10:65:30:aa:bb:cc'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'NAS-Identifier'} = &request:NAS-Identifier -> 'SWAA-FV001234'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'NAS-Port-Type'} = &request:NAS-Port-Type -> 'Ethernet'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Tunnel-Type'} = &request:Tunnel-Type -> 'VLAN'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Tunnel-Medium-Type'} = &request:Tunnel-Medium-Type -> 'IEEE-802'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Tunnel-Private-Group-Id'} = &request:Tunnel-Private-Group-Id -> '1136'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Event-Timestamp'} = &request:Event-Timestamp -> 'févr. 20 2020 17:21:38 CET'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Connect-Info'} = &request:Connect-Info -> 'CONNECT Ethernet 100Mbps Full duplex'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'EAP-Message'} = &request:EAP-Message -> '0x0208002901686f73742f46563030343636352e6b6162692e6164732e66726573656e6975732e636f6d'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'NAS-Port-Id'} = &request:NAS-Port-Id -> '40'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'FreeRADIUS-Proxied-To'} = &request:FreeRADIUS-Proxied-To -> '127.0.0.1'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[0] = &request:HP-Capability-Advert -> '0x011a0000000b28'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[1] = &request:HP-Capability-Advert -> '0x011a0000000b2e'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[2] = &request:HP-Capability-Advert -> '0x011a0000000b30'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[3] = &request:HP-Capability-Advert -> '0x011a0000000b3d'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[4] = &request:HP-Capability-Advert -> '0x011a0000000b18'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[5] = &request:HP-Capability-Advert -> '0x011a0000000b19'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[6] = &request:HP-Capability-Advert -> '0x0138'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[7] = &request:HP-Capability-Advert -> '0x013a'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[8] = &request:HP-Capability-Advert -> '0x0140'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[9] = &request:HP-Capability-Advert -> '0x0141'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[10] = &request:HP-Capability-Advert -> '0x0151'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'MS-RAS-Vendor'} = &request:MS-RAS-Vendor -> '11'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Realm'} = &request:Realm -> 'kabi.ads.fresenius.com'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'SQL-User-Name'} = &request:SQL-User-Name -> 'host/FV004665.kabi.ads.fresenius.com'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'PacketFence-KeyBalanced'} = &request:PacketFence-KeyBalanced -> '785ef37fa229298f465f6b3eee6eeb38'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'PacketFence-Radius-Ip'} = &request:PacketFence-Radius-Ip -> '10.211.120.158'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'EAP-Type'} = &control:EAP-Type -> 'MSCHAPv2'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'PacketFence-Tenant-Id'} = &control:PacketFence-Tenant-Id -> '1'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'EAP-Type'} = &control:EAP-Type -> 'MSCHAPv2'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'PacketFence-Tenant-Id'} = &control:PacketFence-Tenant-Id -> '1'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: perl_embed:: module = /usr/local/pf/raddb/mods-config/perl/packetfence-multi-domain.pm , func = authorize exit status= hash- or arrayref expected (not a simple scalar, use allow_nonref to allow this) at /usr/local/pf/lib/pfconfig/cached.pm line 182.
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:NAS-Port = $RAD_REQUEST{'NAS-Port'} -> '40'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:Tunnel-Medium-Type:0 = $RAD_REQUEST{'Tunnel-Medium-Type:0'} -> 'IEEE-802'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:NAS-IP-Address = $RAD_REQUEST{'NAS-IP-Address'} -> '192.168.xxx.yyy'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:Connect-Info = $RAD_REQUEST{'Connect-Info'} -> 'CONNECT Ethernet 100Mbps Full duplex'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:Framed-MTU = $RAD_REQUEST{'Framed-MTU'} -> '1480'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:Calling-Station-Id = $RAD_REQUEST{'Calling-Station-Id'} -> '10:65:30:aa:bb:cc'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:NAS-Port-Type = $RAD_REQUEST{'NAS-Port-Type'} -> 'Ethernet'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:Tunnel-Private-Group-Id:0 = $RAD_REQUEST{'Tunnel-Private-Group-Id:0'} -> '1136'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:PacketFence-KeyBalanced = $RAD_REQUEST{'PacketFence-KeyBalanced'} -> '785ef37fa229298f465f6b3eee6eeb38'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:Realm = $RAD_REQUEST{'Realm'} -> 'kabi.ads.fresenius.com'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:User-Name = $RAD_REQUEST{'User-Name'} -> 'host/FV004665.kabi.ads.fresenius.com'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:Framed-Protocol = $RAD_REQUEST{'Framed-Protocol'} -> 'PPP'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:SQL-User-Name = $RAD_REQUEST{'SQL-User-Name'} -> 'host/FV004665.kabi.ads.fresenius.com'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:NAS-Port-Id = $RAD_REQUEST{'NAS-Port-Id'} -> '40'
(253) Thu Feb 20 17:21:38 2020: ERROR: packetfence-multi-domain: Failed to create pair - failed to parse time string "févr. 20 2020 17:21:38 CET"
(253) Thu Feb 20 17:21:38 2020: ERROR: packetfence-multi-domain: &request:Event-Timestamp = $RAD_REQUEST{'Event-Timestamp'} -> 'févr. 20 2020 17:21:38 CET'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:Called-Station-Id = $RAD_REQUEST{'Called-Station-Id'} -> '04:09:73:cc:dd:ee'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:PacketFence-Radius-Ip = $RAD_REQUEST{'PacketFence-Radius-Ip'} -> '10.211.120.158'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:NAS-Identifier = $RAD_REQUEST{'NAS-Identifier'} -> 'SWAA-FV001234'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:MS-RAS-Vendor = $RAD_REQUEST{'MS-RAS-Vendor'} -> '11'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:Tunnel-Type:0 = $RAD_REQUEST{'Tunnel-Type:0'} -> 'VLAN'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:FreeRADIUS-Proxied-To = $RAD_REQUEST{'FreeRADIUS-Proxied-To'} -> '127.0.0.1'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:EAP-Message = $RAD_REQUEST{'EAP-Message'} -> '0x0208002901686f73742f46563030343636352e6b6162692e6164732e66726573656e6975732e636f6d'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x011a0000000b28'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x011a0000000b2e'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x011a0000000b30'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x011a0000000b3d'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x011a0000000b18'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x011a0000000b19'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x0138'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x013a'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x0140'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x0141'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x0151'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &request:Service-Type = $RAD_REQUEST{'Service-Type'} -> 'Framed-User'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &control:EAP-Type = $RAD_CHECK{'EAP-Type'} -> 'MSCHAPv2'
(253) Thu Feb 20 17:21:38 2020: Debug: packetfence-multi-domain: &control:PacketFence-Tenant-Id = $RAD_CHECK{'PacketFence-Tenant-Id'} -> '1'
(253) Thu Feb 20 17:21:38 2020: Debug: [packetfence-multi-domain] = fail
(253) Thu Feb 20 17:21:38 2020: Debug: } # authorize = fail
(253) Thu Feb 20 17:21:38 2020: Debug: Using Post-Auth-Type Reject
(253) Thu Feb 20 17:21:38 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence-tunnel
(253) Thu Feb 20 17:21:38 2020: Debug: Post-Auth-Type REJECT {
(253) Thu Feb 20 17:21:38 2020: Debug: policy packetfence-set-tenant-id {
(253) Thu Feb 20 17:21:38 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){
(253) Thu Feb 20 17:21:38 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0}
(253) Thu Feb 20 17:21:38 2020: Debug: --> 1
(253) Thu Feb 20 17:21:38 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) {
(253) Thu Feb 20 17:21:38 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: } # policy packetfence-set-tenant-id = noop
(253) Thu Feb 20 17:21:38 2020: Debug: update {
(253) Thu Feb 20 17:21:38 2020: Debug: } # update = noop
(253) Thu Feb 20 17:21:38 2020: Debug: policy packetfence-audit-log-reject {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name && (&User-Name == "dummy")) {
(253) Thu Feb 20 17:21:38 2020: Debug: if (&User-Name && (&User-Name == "dummy")) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: else {
(253) Thu Feb 20 17:21:38 2020: Debug: policy request-timing {
(253) Thu Feb 20 17:21:38 2020: Debug: if ("%{%{control:PacketFence-Request-Time}:-0}" != 0) {
(253) Thu Feb 20 17:21:38 2020: Debug: EXPAND %{%{control:PacketFence-Request-Time}:-0}
(253) Thu Feb 20 17:21:38 2020: Debug: --> 0
(253) Thu Feb 20 17:21:38 2020: Debug: if ("%{%{control:PacketFence-Request-Time}:-0}" != 0) -> FALSE
(253) Thu Feb 20 17:21:38 2020: Debug: } # policy request-timing = noop
(253) Thu Feb 20 17:21:38 2020: Debug: sql_reject: EXPAND type.reject.query
(253) Thu Feb 20 17:21:38 2020: Debug: sql_reject: --> type.reject.query
(253) Thu Feb 20 17:21:38 2020: Debug: sql_reject: Using query template 'query'
(253) Thu Feb 20 17:21:38 2020: Debug: sql_reject: EXPAND %{User-Name}
(253) Thu Feb 20 17:21:38 2020: Debug: sql_reject: --> host/FV004665.kabi.ads.fresenius.com
(253) Thu Feb 20 17:21:38 2020: Debug: sql_reject: SQL-User-Name set to 'host/FV004665.kabi.ads.fresenius.com'
(253) Thu Feb 20 17:21:38 2020: 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, radius_ip) 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}', '%{request:PacketFence-Radius-Ip}')
(253) Thu Feb 20 17:21:38 2020: 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, radius_ip) VALUES ( '10:65:30:aa:bb:cc', '', 'N/A', 'host/FV004665.kabi.ads.fresenius.com', '', 'kabi.ads.fresenius.com', 'Radius-Access-Request', 'N/A', 'N/A', 'N/A', '10.211.120.171', '04:09:73:cc:dd:ee', '10:65:30:aa:bb:cc', 'Ethernet', '', '40', 'N/A', '40', 'N/A', '192.168.xxx.yyy', 'SWAA-FV001234', 'Reject', '', '', '', 'N/A', 'N/A', 'N/A', 'N/A', '0', '0', '', '', 'NAS-Port =3D 40=2C Tunnel-Medium-Type:0 =3D IEEE-802=2C NAS-IP-Address =3D 192.168.xxx.yyy=2C Connect-Info =3D =22CONNECT Ethernet 100Mbps Full duplex=22=2C Framed-MTU =3D 1480=2C Calling-Station-Id =3D =2210:65:30:aa:bb:cc=22=2C NAS-Port-Type =3D Ethernet=2C Tunnel-Private-Group-Id:0 =3D =221136=22=2C PacketFence-KeyBalanced =3D =22785ef37fa229298f465f6b3eee6eeb38=22=2C Realm =3D =22kabi.ads.fresenius.com=22=2C User-Name =3D =22host/FV004665.kabi.ads.fresenius.com=22=2C Framed-Protocol =3D PPP=2C NAS-Port-Id =3D =2240=22=2C Event-Timestamp =3D =22janv. 1 1970 01:00:00 CET=22=2C Called-Station-Id =3D =2204:09:73:cc:dd:ee=22=2C PacketFence-Radius-Ip =3D =2210.211.120.158=22=2C NAS-Identifier =3D =22SWAA-FV001234=22=2C MS-RAS-Vendor =3D 11=2C Tunnel-Type:0 =3D VLAN=2C FreeRADIUS-Proxied-To =3D 127.0.0.1=2C EAP-Message =3D 0x0208002901686f73742f46563030343636352e6b6162692e6164732e66726573656e6975732e636f6d=2C HP-Capability-Advert =3D 0x011a0000000b28=2C HP-Capability-Advert =3D 0x011a0000000b2e=2C HP-Capability-Advert =3D 0x011a0000000b30=2C HP-Capability-Advert =3D 0x011a0000000b3d=2C HP-Capability-Advert =3D 0x011a0000000b18=2C HP-Capability-Advert =3D 0x011a0000000b19=2C HP-Capability-Advert =3D 0x0138=2C HP-Capability-Advert =3D 0x013a=2C HP-Capability-Advert =3D 0x0140=2C HP-Capability-Advert =3D 0x0141=2C HP-Capability-Advert =3D 0x0151=2C Service-Type =3D Framed-User=2C User-Password =3D =22=2A=2A=2A=2A=2A=2A=22=2C SQL-User-Name =3D =22host/FV004665.kabi.ads.fresenius.com=22','', 'N/A', '1', '10.211.120.158')
(253) Thu Feb 20 17:21:38 2020: 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, radius_ip) VALUES ( '10:65:30:aa:bb:cc', '', 'N/A', 'host/FV004665.kabi.ads.fresenius.com', '', 'kabi.ads.fresenius.com', 'Radius-Access-Request', 'N/A', 'N/A', 'N/A', '10.211.120.171', '04:09:73:cc:dd:ee', '10:65:30:aa:bb:cc', 'Ethernet', '', '40', 'N/A', '40', 'N/A', '192.168.xxx.yyy', 'SWAA-FV001234', 'Reject', '', '', '', 'N/A', 'N/A', 'N/A', 'N/A', '0', '0', '', '', 'NAS-Port =3D 40=2C Tunnel-Medium-Type:0 =3D IEEE-802=2C NAS-IP-Address =3D 192.168.xxx.yyy=2C Connect-Info =3D =22CONNECT Ethernet 100Mbps Full duplex=22=2C Framed-MTU =3D 1480=2C Calling-Station-Id =3D =2210:65:30:aa:bb:cc=22=2C NAS-Port-Type =3D Ethernet=2C Tunnel-Private-Group-Id:0 =3D =221136=22=2C PacketFence-KeyBalanced =3D =22785ef37fa229298f465f6b3eee6eeb38=22=2C Realm =3D =22kabi.ads.fresenius.com=22=2C User-Name =3D =22host/FV004665.kabi.ads.fresenius.com=22=2C Framed-Protocol =3D PPP=2C NAS-Port-Id =3D =2240=22=2C Event-Timestamp =3D =22janv. 1 1970 01:00:00 CET=22=2C Called-Station-Id =3D =2204:09:73:cc:dd:ee=22=2C PacketFence-Radius-Ip =3D =2210.211.120.158=22=2C NAS-Identifier =3D =22SWAA-FV001234=22=2C MS-RAS-Vendor =3D 11=2C Tunnel-Type:0 =3D VLAN=2C FreeRADIUS-Proxied-To =3D 127.0.0.1=2C EAP-Message =3D 0x0208002901686f73742f46563030343636352e6b6162692e6164732e66726573656e6975732e636f6d=2C HP-Capability-Advert =3D 0x011a0000000b28=2C HP-Capability-Advert =3D 0x011a0000000b2e=2C HP-Capability-Advert =3D 0x011a0000000b30=2C HP-Capability-Advert =3D 0x011a0000000b3d=2C HP-Capability-Advert =3D 0x011a0000000b18=2C HP-Capability-Advert =3D 0x011a0000000b19=2C HP-Capability-Advert =3D 0x0138=2C HP-Capability-Advert =3D 0x013a=2C HP-Capability-Advert =3D 0x0140=2C HP-Capability-Advert =3D 0x0141=2C HP-Capability-Advert =3D 0x0151=2C Service-Type =3D Framed-User=2C User-Password =3D =22=2A=2A=2A=2A=2A=2A=22=2C SQL-User-Name =3D =22host/FV004665.kabi.ads.fresenius.com=22','', 'N/A', '1', '10.211.120.158')
(253) Thu Feb 20 17:21:38 2020: Debug: sql_reject: SQL query returned: success
(253) Thu Feb 20 17:21:38 2020: Debug: sql_reject: 1 record(s) updated
(253) Thu Feb 20 17:21:38 2020: Debug: [sql_reject] = ok
(253) Thu Feb 20 17:21:38 2020: Debug: } # else = ok
(253) Thu Feb 20 17:21:38 2020: Debug: } # policy packetfence-audit-log-reject = ok
(253) Thu Feb 20 17:21:38 2020: Debug: attr_filter.access_reject: EXPAND %{User-Name}
(253) Thu Feb 20 17:21:38 2020: Debug: attr_filter.access_reject: --> host/FV004665.kabi.ads.fresenius.com
(253) Thu Feb 20 17:21:38 2020: Debug: attr_filter.access_reject: Matched entry DEFAULT at line 11
(253) Thu Feb 20 17:21:38 2020: Debug: [attr_filter.access_reject] = updated
(253) Thu Feb 20 17:21:38 2020: Debug: update outer.session-state {
(253) Thu Feb 20 17:21:38 2020: Debug: No attributes updated for RHS &request:Module-Failure-Message
(253) Thu Feb 20 17:21:38 2020: Debug: } # update outer.session-state = noop
(253) Thu Feb 20 17:21:38 2020: Debug: } # Post-Auth-Type REJECT = updated
(253) Thu Feb 20 17:21:38 2020: Debug: } # server packetfence-tunnel
(253) Thu Feb 20 17:21:38 2020: Debug: Virtual server sending reply
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Got tunneled reply code 3
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: Tunneled authentication was rejected
(253) Thu Feb 20 17:21:38 2020: Debug: eap_peap: FAILURE
(253) Thu Feb 20 17:21:38 2020: Debug: eap: Sending EAP Request (code 1) ID 9 length 46
(253) Thu Feb 20 17:21:38 2020: Debug: eap: EAP session adding &reply:State = 0xfa22c4bafc2bdd06
(253) Thu Feb 20 17:21:38 2020: Debug: [eap] = handled
(253) Thu Feb 20 17:21:38 2020: Debug: } # authenticate = handled
(253) Thu Feb 20 17:21:38 2020: Debug: Using Post-Auth-Type Challenge
(253) Thu Feb 20 17:21:38 2020: Debug: Post-Auth-Type sub-section not found. Ignoring.
(253) Thu Feb 20 17:21:38 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence
(253) Thu Feb 20 17:21:38 2020: Debug: session-state: Saving cached attributes
(253) Thu Feb 20 17:21:38 2020: Debug: TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(253) Thu Feb 20 17:21:38 2020: Debug: TLS-Session-Version = "TLS 1.2"
(253) Thu Feb 20 17:21:38 2020: Debug: Sent Access-Challenge Id 170 from 10.211.120.158:1812 to 10.211.120.171:49563 length 0
(253) Thu Feb 20 17:21:38 2020: Debug: EAP-Message = 0x0109002e190017030300234e17d2e7d99c021227e423d81418fe42c210ab655c8f76b79125105cc4f39aa16ae0fd
(253) Thu Feb 20 17:21:38 2020: Debug: Message-Authenticator = 0x00000000000000000000000000000000
(253) Thu Feb 20 17:21:38 2020: Debug: State = 0xfa22c4bafc2bdd06e61b85de3ed7b62c
(253) Thu Feb 20 17:21:38 2020: Debug: Proxy-State = 0x313237
(253) Thu Feb 20 17:21:38 2020: Debug: Finished request
Thank you
Franck R
More information about the Freeradius-Users
mailing list