Proxy problem when switching from version2 to version3
Hi, when switching to version 3 I have a little problem to find my misconfiguration. the home server says: access rejected because the freeradius sends:
From wireshark on home server:
Fail: Extensible Authentication Protocol Code: Response (2) ID: 2 Length: 8 Type: Legacy Nak ( Response Only) (3) Desired Auth Type: protected EAP ( EAP-PEAP) (25) OK with version 2: Extensible Authentication Protocol Code: Response (2) ID: 10 Length: 70 Type: MS-Authentication EAP (EAP-MS-AUTH) (26) EAP-MS-CHAP-v2 OpCode: Response (2) EAP-MS-CHAP-v2 Id: 10 EAP-MS-CHAP-v2 ..... ..... EAP-MS-CHAP-v2 Name: radius@itmc Where do I have to look in the configuration? Regards Hans Hans Bornemann Abteilung Datanet Technische Universität Dortmund ITMC Otto-Hahn-Str. 12 44227 Dortmund Tel.: +49 231-755 2132 hans.bornemann@tu-dortmund.de www.itmc.tu-dortmund.de Wichtiger Hinweis: Die Information in dieser E-Mail ist vertraulich. Sie ist ausschließlich für den Adressaten bestimmt. Sollten Sie nicht der für diese E-Mail bestimmte Adressat sein, unterrichten Sie bitte den Absender und vernichten Sie diese Mail. Vielen Dank. Unbeschadet der Korrespondenz per E-Mail, sind unsere Erklärungen ausschließlich final rechtsverbindlich, wenn sie in herkömmlicher Schriftform (mit eigenhändiger Unterschrift) oder durch Übermittlung eines solchen Schriftstücks per Telefax erfolgen. Important note: The information included in this e-mail is confidential. It is solely intended for the recipient. If you are not the intended recipient of this e-mail please contact the sender and delete this message. Thank you. Without prejudice of e-mail correspondence, our statements are only legally binding when they are made in the conventional written form (with personal signature) or when such documents are sent by fax.
On Jan 23, 2018, at 3:48 AM, Bornemann, Hans <hans.bornemann@tu-dortmund.de> wrote:
when switching to version 3 I have a little problem to find my misconfiguration.
the home server says: access rejected because the freeradius sends:
From wireshark on home server:
There *is* a debug log on the proxy which can give you more information. Why not post the debug output, as suggested in the documentation, FAQ, web site, "man" page, and daily on this list? i.e. following the documentation is better than look at random third-party tools. Also, FreeRADIUS doesn't *originate* EAP packets. It just proxies them. So if EAP is different, it's because the EAP client (i.e. laptop / desktop) is behaving differently.
Where do I have to look in the configuration?
Read the documentation. Follow the instructions for debugging problems. Ask *good* questions. If you have no idea what's going wrong, describe what's happening. In detail. Don't assume it's one thing, and then ask how to fix that... Alan DeKok.
Hi Alan, if you like, take a look to the debug output. first the failing proxy with version 3, then successful with version 2, proxy conf. anything more needed? ----- Debug Output freeradius 3 --> proxy to home server --> failing Thu Jan 18 10:22:37 2018 : Debug: (0) Received Access-Request Id 68 from 129.217.251.242:32775 to 129.217.131.207:1812 length 304 Thu Jan 18 10:22:37 2018 : Debug: (0) User-Name = "rtmobilnetz@rtmobil" Thu Jan 18 10:22:37 2018 : Debug: (0) Chargeable-User-Identity = 0x00 Thu Jan 18 10:22:37 2018 : Debug: (0) Location-Capable = Civic-Location Thu Jan 18 10:22:37 2018 : Debug: (0) Calling-Station-Id = "3c-15-c2-e8-40-fe" Thu Jan 18 10:22:37 2018 : Debug: (0) Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" Thu Jan 18 10:22:37 2018 : Debug: (0) NAS-Port = 1 Thu Jan 18 10:22:37 2018 : Debug: (0) Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Thu Jan 18 10:22:37 2018 : Debug: (0) Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" Thu Jan 18 10:22:37 2018 : Debug: (0) NAS-IP-Address = 129.217.251.242 Thu Jan 18 10:22:37 2018 : Debug: (0) NAS-Identifier = "wlc-staging" Thu Jan 18 10:22:37 2018 : Debug: (0) Airespace-Wlan-Id = 8 Thu Jan 18 10:22:37 2018 : Debug: (0) Service-Type = Framed-User Thu Jan 18 10:22:37 2018 : Debug: (0) Framed-MTU = 1300 Thu Jan 18 10:22:37 2018 : Debug: (0) NAS-Port-Type = Wireless-802.11 Thu Jan 18 10:22:37 2018 : Debug: (0) Tunnel-Type:0 = VLAN Thu Jan 18 10:22:37 2018 : Debug: (0) Tunnel-Medium-Type:0 = IEEE-802 Thu Jan 18 10:22:37 2018 : Debug: (0) Tunnel-Private-Group-Id:0 = "3503" Thu Jan 18 10:22:37 2018 : Debug: (0) EAP-Message = 0x020100180172746d6f62696c6e65747a4072746d6f62696c Thu Jan 18 10:22:37 2018 : Debug: (0) Message-Authenticator = 0xbede1e965b3fc497b387e44d3dd44344 Thu Jan 18 10:22:37 2018 : Debug: (0) session-state: No State attribute Thu Jan 18 10:22:37 2018 : Debug: (0) # Executing section authorize from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:22:37 2018 : Debug: (0) authorize { Thu Jan 18 10:22:37 2018 : Debug: (0) if (NAS-IP-Address =~ /^129\.217\.142\./) { Thu Jan 18 10:22:37 2018 : Debug: (0) if (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:22:37 2018 : Debug: (0) if (NAS-IP-Address =~ /^129\.217\.131\./) { Thu Jan 18 10:22:37 2018 : Debug: (0) if (NAS-IP-Address =~ /^129\.217\.131\./) -> FALSE Thu Jan 18 10:22:37 2018 : Debug: (0) modsingle[authorize]: calling preprocess (rlm_preprocess) Thu Jan 18 10:22:37 2018 : Debug: (0) modsingle[authorize]: returned from preprocess (rlm_preprocess) Thu Jan 18 10:22:37 2018 : Debug: (0) [preprocess] = ok Thu Jan 18 10:22:37 2018 : Debug: (0) modsingle[authorize]: calling suffix (rlm_realm) Thu Jan 18 10:22:37 2018 : Debug: (0) suffix: Checking for suffix after "@" Thu Jan 18 10:22:37 2018 : Debug: (0) suffix: Looking up realm "rtmobil" for User-Name = "rtmobilnetz@rtmobil" Thu Jan 18 10:22:37 2018 : Debug: (0) suffix: Found realm "rtmobil" Thu Jan 18 10:22:37 2018 : Debug: (0) suffix: Adding Realm = "rtmobil" Thu Jan 18 10:22:37 2018 : Debug: (0) suffix: Proxying request from user rtmobilnetz@rtmobil to realm rtmobil Thu Jan 18 10:22:37 2018 : Debug: (0) suffix: Preparing to proxy authentication request to realm "rtmobil" Thu Jan 18 10:22:37 2018 : Debug: (0) modsingle[authorize]: returned from suffix (rlm_realm) Thu Jan 18 10:22:37 2018 : Debug: (0) [suffix] = updated Thu Jan 18 10:22:37 2018 : Debug: (0) if (&User-Name =~ /telesec/ ) { Thu Jan 18 10:22:37 2018 : Debug: (0) if (&User-Name =~ /telesec/ ) -> FALSE Thu Jan 18 10:22:37 2018 : Debug: (0) else { Thu Jan 18 10:22:37 2018 : Debug: (0) modsingle[authorize]: calling eapoldca (rlm_eap) Thu Jan 18 10:22:37 2018 : Debug: (0) eapoldca: Request is supposed to be proxied to Realm rtmobil. Not doing EAP. Thu Jan 18 10:22:37 2018 : Debug: (0) modsingle[authorize]: returned from eapoldca (rlm_eap) Thu Jan 18 10:22:37 2018 : Debug: (0) [eapoldca] = noop Thu Jan 18 10:22:37 2018 : Debug: (0) } # else = noop Thu Jan 18 10:22:37 2018 : Debug: (0) modsingle[authorize]: calling sql (rlm_sql) Thu Jan 18 10:22:37 2018 : Debug: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} Thu Jan 18 10:22:37 2018 : Debug: Parsed xlat tree: Thu Jan 18 10:22:37 2018 : Debug: XLAT-IF { Thu Jan 18 10:22:37 2018 : Debug: attribute --> Stripped-User-Name Thu Jan 18 10:22:37 2018 : Debug: } Thu Jan 18 10:22:37 2018 : Debug: XLAT-ELSE { Thu Jan 18 10:22:37 2018 : Debug: XLAT-IF { Thu Jan 18 10:22:37 2018 : Debug: attribute --> User-Name Thu Jan 18 10:22:37 2018 : Debug: } Thu Jan 18 10:22:37 2018 : Debug: XLAT-ELSE { Thu Jan 18 10:22:37 2018 : Debug: literal --> DEFAULT Thu Jan 18 10:22:37 2018 : Debug: } Thu Jan 18 10:22:37 2018 : Debug: } Thu Jan 18 10:22:37 2018 : Debug: (0) sql: EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} Thu Jan 18 10:22:37 2018 : Debug: (0) sql: --> rtmobilnetz@rtmobil Thu Jan 18 10:22:37 2018 : Debug: (0) sql: SQL-User-Name set to 'rtmobilnetz@rtmobil' Thu Jan 18 10:22:37 2018 : Debug: rlm_sql (sql): Reserved connection (0) Thu Jan 18 10:22:37 2018 : Debug: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id Thu Jan 18 10:22:37 2018 : Debug: Parsed xlat tree: Thu Jan 18 10:22:37 2018 : Debug: literal --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = ' Thu Jan 18 10:22:37 2018 : Debug: attribute --> SQL-User-Name Thu Jan 18 10:22:37 2018 : Debug: literal --> ' ORDER BY id Thu Jan 18 10:22:37 2018 : Debug: (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id Thu Jan 18 10:22:37 2018 : Debug: (0) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'rtmobilnetz@rtmobil' ORDER BY id Thu Jan 18 10:22:37 2018 : Debug: (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'rtmobilnetz@rtmobil' ORDER BY id Thu Jan 18 10:22:37 2018 : Debug: (0) sql: ... falling-through to group processing Thu Jan 18 10:22:37 2018 : Debug: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority Thu Jan 18 10:22:37 2018 : Debug: Parsed xlat tree: Thu Jan 18 10:22:37 2018 : Debug: literal --> SELECT groupname FROM radusergroup WHERE username = ' Thu Jan 18 10:22:37 2018 : Debug: attribute --> SQL-User-Name Thu Jan 18 10:22:37 2018 : Debug: literal --> ' ORDER BY priority Thu Jan 18 10:22:37 2018 : Debug: (0) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority Thu Jan 18 10:22:37 2018 : Debug: (0) sql: --> SELECT groupname FROM radusergroup WHERE username = 'rtmobilnetz@rtmobil' ORDER BY priority Thu Jan 18 10:22:37 2018 : Debug: (0) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'rtmobilnetz@rtmobil' ORDER BY priority Thu Jan 18 10:22:37 2018 : Debug: (0) sql: User not found in any groups Thu Jan 18 10:22:37 2018 : Debug: (0) sql: ... falling-through to profile processing Thu Jan 18 10:22:37 2018 : Debug: rlm_sql (sql): Released connection (0) Thu Jan 18 10:22:37 2018 : Debug: (0) modsingle[authorize]: returned from sql (rlm_sql) Thu Jan 18 10:22:37 2018 : Debug: (0) [sql] = notfound Thu Jan 18 10:22:37 2018 : Debug: (0) modsingle[authorize]: calling pap (rlm_pap) Thu Jan 18 10:22:37 2018 : Debug: (0) modsingle[authorize]: returned from pap (rlm_pap) Thu Jan 18 10:22:37 2018 : Debug: (0) [pap] = noop Thu Jan 18 10:22:37 2018 : Debug: (0) } # authorize = updated Thu Jan 18 10:22:37 2018 : Debug: (0) Starting proxy to home server 129.217.197.132 port 1812 Thu Jan 18 10:22:37 2018 : Debug: (0) Empty pre-proxy section in virtual server "itmc-wlan". Using default return values. Thu Jan 18 10:22:37 2018 : Debug: (0) proxy: Trying to allocate ID (0/2) Thu Jan 18 10:22:37 2018 : Debug: (0) proxy: request is now in proxy hash Thu Jan 18 10:22:37 2018 : Debug: (0) proxy: allocating destination 129.217.197.132 port 1812 - Id 206 Thu Jan 18 10:22:37 2018 : Debug: (0) Proxying request to home server 129.217.197.132 port 1812 timeout 20.000000 Thu Jan 18 10:22:38 2018 : Debug: (0) Sent Access-Request Id 206 from 0.0.0.0:48124 to 129.217.197.132:1812 length 314 Thu Jan 18 10:22:38 2018 : Debug: (0) User-Name = "rtmobilnetz@rtmobil" Thu Jan 18 10:22:38 2018 : Debug: (0) Chargeable-User-Identity = 0x00 Thu Jan 18 10:22:38 2018 : Debug: (0) Location-Capable = Civic-Location Thu Jan 18 10:22:38 2018 : Debug: (0) Calling-Station-Id = "3c-15-c2-e8-40-fe" Thu Jan 18 10:22:38 2018 : Debug: (0) Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" Thu Jan 18 10:22:38 2018 : Debug: (0) NAS-Port = 1 Thu Jan 18 10:22:38 2018 : Debug: (0) Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Thu Jan 18 10:22:38 2018 : Debug: (0) Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" Thu Jan 18 10:22:38 2018 : Debug: (0) NAS-IP-Address = 129.217.251.242 Thu Jan 18 10:22:38 2018 : Debug: (0) NAS-Identifier = "wlc-staging" Thu Jan 18 10:22:38 2018 : Debug: (0) Airespace-Wlan-Id = 8 Thu Jan 18 10:22:38 2018 : Debug: (0) Service-Type = Framed-User Thu Jan 18 10:22:38 2018 : Debug: (0) Framed-MTU = 1300 Thu Jan 18 10:22:38 2018 : Debug: (0) NAS-Port-Type = Wireless-802.11 Thu Jan 18 10:22:38 2018 : Debug: (0) Tunnel-Type:0 = VLAN Thu Jan 18 10:22:38 2018 : Debug: (0) Tunnel-Medium-Type:0 = IEEE-802 Thu Jan 18 10:22:38 2018 : Debug: (0) Tunnel-Private-Group-Id:0 = "3503" Thu Jan 18 10:22:38 2018 : Debug: (0) EAP-Message = 0x020100180172746d6f62696c6e65747a4072746d6f62696c Thu Jan 18 10:22:38 2018 : Debug: (0) Message-Authenticator = 0xbede1e965b3fc497b387e44d3dd44344 Thu Jan 18 10:22:38 2018 : Debug: (0) Event-Timestamp = "Jan 18 2018 10:22:37 CET" Thu Jan 18 10:22:38 2018 : Debug: (0) Proxy-State = 0x3638 Thu Jan 18 10:22:38 2018 : Debug: Waking up in 0.3 seconds. Thu Jan 18 10:22:38 2018 : Proxy: (0) Marking home server 129.217.197.132 port 1812 alive Thu Jan 18 10:22:38 2018 : Debug: (0) Clearing existing &reply: attributes Thu Jan 18 10:22:38 2018 : Debug: (0) Received Access-Challenge Id 206 from 129.217.197.132:1812 to 129.217.131.207:48124 length 124 Thu Jan 18 10:22:38 2018 : Debug: (0) Proxy-State = 0x3638 Thu Jan 18 10:22:38 2018 : Debug: (0) Session-Timeout = 60 Thu Jan 18 10:22:38 2018 : Debug: (0) EAP-Message = 0x010200241a0102001f103a19daaaee38d70eaedc727f0ccb621f504f4f4c2d4144533031 Thu Jan 18 10:22:38 2018 : Debug: (0) State = 0x45300497000001370001020081d9c584000000000000000000000000000000100d436aee Thu Jan 18 10:22:38 2018 : Debug: (0) Message-Authenticator = 0xe9ebcfb379a08e2bb3205a9451a1b0de Thu Jan 18 10:22:38 2018 : Debug: (0) # Executing section post-proxy from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:22:38 2018 : Debug: (0) post-proxy { Thu Jan 18 10:22:38 2018 : Debug: (0) modsingle[post-proxy]: calling attr_filter.post-proxy (rlm_attr_filter) Thu Jan 18 10:22:38 2018 : Debug: %{Realm} Thu Jan 18 10:22:38 2018 : Debug: Parsed xlat tree: Thu Jan 18 10:22:38 2018 : Debug: attribute --> Realm Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: EXPAND %{Realm} Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: --> rtmobil Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: Matched entry rtmobil at line 17 Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: Attribute "Proxy-State" allowed by 0 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: Attribute "Session-Timeout" allowed by 0 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: Attribute "EAP-Message" allowed by 0 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: Attribute "State" allowed by 0 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: Attribute "Message-Authenticator" allowed by 0 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: Matched entry DEFAULT at line 32 Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: Proxy-State = 0x3638 allowed by Proxy-State =* 0x Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: Attribute "Proxy-State" allowed by 1 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: Attribute "Session-Timeout" allowed by 0 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: EAP-Message = 0x010200241a0102001f103a19daaaee38d70eaedc727f0ccb621f504f4f4c2d4144533031 allowed by EAP-Message =* 0x Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: Attribute "EAP-Message" allowed by 1 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: State = 0x45300497000001370001020081d9c584000000000000000000000000000000100d436aee allowed by State =* 0x Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: Attribute "State" allowed by 1 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: Message-Authenticator = 0xe9ebcfb379a08e2bb3205a9451a1b0de allowed by Message-Authenticator =* 0x Thu Jan 18 10:22:38 2018 : Debug: (0) attr_filter.post-proxy: Attribute "Message-Authenticator" allowed by 1 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (0) modsingle[post-proxy]: returned from attr_filter.post-proxy (rlm_attr_filter) Thu Jan 18 10:22:38 2018 : Debug: (0) [attr_filter.post-proxy] = updated Thu Jan 18 10:22:38 2018 : Debug: (0) modsingle[post-proxy]: calling eap_wlan (rlm_eap) Thu Jan 18 10:22:38 2018 : Debug: (0) eap_wlan: No pre-existing handler found Thu Jan 18 10:22:38 2018 : Debug: (0) modsingle[post-proxy]: returned from eap_wlan (rlm_eap) Thu Jan 18 10:22:38 2018 : Debug: (0) [eap_wlan] = noop Thu Jan 18 10:22:38 2018 : Debug: (0) } # post-proxy = updated Thu Jan 18 10:22:38 2018 : Debug: (0) session-state: Nothing to cache Thu Jan 18 10:22:38 2018 : Debug: (0) Using Post-Auth-Type Challenge Thu Jan 18 10:22:38 2018 : Debug: (0) Post-Auth-Type sub-section not found. Ignoring. Thu Jan 18 10:22:38 2018 : Debug: (0) # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:22:38 2018 : Debug: (0) session-state: Nothing to cache Thu Jan 18 10:22:38 2018 : Debug: (0) Sent Access-Challenge Id 68 from 129.217.131.207:1812 to 129.217.251.242:32775 length 0 Thu Jan 18 10:22:38 2018 : Debug: (0) Tunnel-Private-Group-Id := "26" Thu Jan 18 10:22:38 2018 : Debug: (0) Tunnel-Type := VLAN Thu Jan 18 10:22:38 2018 : Debug: (0) Tunnel-Medium-Type := IEEE-802 Thu Jan 18 10:22:38 2018 : Debug: (0) EAP-Message = 0x010200241a0102001f103a19daaaee38d70eaedc727f0ccb621f504f4f4c2d4144533031 Thu Jan 18 10:22:38 2018 : Debug: (0) State = 0x45300497000001370001020081d9c584000000000000000000000000000000100d436aee Thu Jan 18 10:22:38 2018 : Debug: (0) Message-Authenticator = 0xe9ebcfb379a08e2bb3205a9451a1b0de Thu Jan 18 10:22:38 2018 : Debug: (0) Finished request Thu Jan 18 10:22:38 2018 : Debug: Waking up in 4.9 seconds. Thu Jan 18 10:22:38 2018 : Debug: (1) Received Access-Request Id 69 from 129.217.251.242:32775 to 129.217.131.207:1812 length 326 Thu Jan 18 10:22:38 2018 : Debug: (1) User-Name = "rtmobilnetz@rtmobil" Thu Jan 18 10:22:38 2018 : Debug: (1) Chargeable-User-Identity = 0x00 Thu Jan 18 10:22:38 2018 : Debug: (1) Location-Capable = Civic-Location Thu Jan 18 10:22:38 2018 : Debug: (1) Calling-Station-Id = "3c-15-c2-e8-40-fe" Thu Jan 18 10:22:38 2018 : Debug: (1) Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-Port = 1 Thu Jan 18 10:22:38 2018 : Debug: (1) Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Thu Jan 18 10:22:38 2018 : Debug: (1) Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-IP-Address = 129.217.251.242 Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-Identifier = "wlc-staging" Thu Jan 18 10:22:38 2018 : Debug: (1) Airespace-Wlan-Id = 8 Thu Jan 18 10:22:38 2018 : Debug: (1) Service-Type = Framed-User Thu Jan 18 10:22:38 2018 : Debug: (1) Framed-MTU = 1300 Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-Port-Type = Wireless-802.11 Thu Jan 18 10:22:38 2018 : Debug: (1) Tunnel-Type:0 = VLAN Thu Jan 18 10:22:38 2018 : Debug: (1) Tunnel-Medium-Type:0 = IEEE-802 Thu Jan 18 10:22:38 2018 : Debug: (1) Tunnel-Private-Group-Id:0 = "3503" Thu Jan 18 10:22:38 2018 : Debug: (1) EAP-Message = 0x020200080319152b Thu Jan 18 10:22:38 2018 : Debug: (1) State = 0x45300497000001370001020081d9c584000000000000000000000000000000100d436aee Thu Jan 18 10:22:38 2018 : Debug: (1) Message-Authenticator = 0x31a7b8a02c1f45acee5e637c48d8f20d Thu Jan 18 10:22:38 2018 : Debug: (1) session-state: No cached attributes Thu Jan 18 10:22:38 2018 : Debug: (1) # Executing section authorize from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:22:38 2018 : Debug: (1) authorize { Thu Jan 18 10:22:38 2018 : Debug: (1) if (NAS-IP-Address =~ /^129\.217\.142\./) { Thu Jan 18 10:22:38 2018 : Debug: (1) if (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:22:38 2018 : Debug: (1) if (NAS-IP-Address =~ /^129\.217\.131\./) { Thu Jan 18 10:22:38 2018 : Debug: (1) if (NAS-IP-Address =~ /^129\.217\.131\./) -> FALSE Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[authorize]: calling preprocess (rlm_preprocess) Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[authorize]: returned from preprocess (rlm_preprocess) Thu Jan 18 10:22:38 2018 : Debug: (1) [preprocess] = ok Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[authorize]: calling suffix (rlm_realm) Thu Jan 18 10:22:38 2018 : Debug: (1) suffix: Checking for suffix after "@" Thu Jan 18 10:22:38 2018 : Debug: (1) suffix: Looking up realm "rtmobil" for User-Name = "rtmobilnetz@rtmobil" Thu Jan 18 10:22:38 2018 : Debug: (1) suffix: Found realm "rtmobil" Thu Jan 18 10:22:38 2018 : Debug: (1) suffix: Adding Realm = "rtmobil" Thu Jan 18 10:22:38 2018 : Debug: (1) suffix: Proxying request from user rtmobilnetz@rtmobil to realm rtmobil Thu Jan 18 10:22:38 2018 : Debug: (1) suffix: Preparing to proxy authentication request to realm "rtmobil" Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[authorize]: returned from suffix (rlm_realm) Thu Jan 18 10:22:38 2018 : Debug: (1) [suffix] = updated Thu Jan 18 10:22:38 2018 : Debug: (1) if (&User-Name =~ /telesec/ ) { Thu Jan 18 10:22:38 2018 : Debug: (1) if (&User-Name =~ /telesec/ ) -> FALSE Thu Jan 18 10:22:38 2018 : Debug: (1) else { Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[authorize]: calling eapoldca (rlm_eap) Thu Jan 18 10:22:38 2018 : Debug: (1) eapoldca: Request is supposed to be proxied to Realm rtmobil. Not doing EAP. Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[authorize]: returned from eapoldca (rlm_eap) Thu Jan 18 10:22:38 2018 : Debug: (1) [eapoldca] = noop Thu Jan 18 10:22:38 2018 : Debug: (1) } # else = noop Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[authorize]: calling sql (rlm_sql) Thu Jan 18 10:22:38 2018 : Debug: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} Thu Jan 18 10:22:38 2018 : Debug: Parsed xlat tree: Thu Jan 18 10:22:38 2018 : Debug: XLAT-IF { Thu Jan 18 10:22:38 2018 : Debug: attribute --> Stripped-User-Name Thu Jan 18 10:22:38 2018 : Debug: } Thu Jan 18 10:22:38 2018 : Debug: XLAT-ELSE { Thu Jan 18 10:22:38 2018 : Debug: XLAT-IF { Thu Jan 18 10:22:38 2018 : Debug: attribute --> User-Name Thu Jan 18 10:22:38 2018 : Debug: } Thu Jan 18 10:22:38 2018 : Debug: XLAT-ELSE { Thu Jan 18 10:22:38 2018 : Debug: literal --> DEFAULT Thu Jan 18 10:22:38 2018 : Debug: } Thu Jan 18 10:22:38 2018 : Debug: } Thu Jan 18 10:22:38 2018 : Debug: (1) sql: EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} Thu Jan 18 10:22:38 2018 : Debug: (1) sql: --> rtmobilnetz@rtmobil Thu Jan 18 10:22:38 2018 : Debug: (1) sql: SQL-User-Name set to 'rtmobilnetz@rtmobil' Thu Jan 18 10:22:38 2018 : Debug: rlm_sql (sql): Reserved connection (1) Thu Jan 18 10:22:38 2018 : Debug: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id Thu Jan 18 10:22:38 2018 : Debug: Parsed xlat tree: Thu Jan 18 10:22:38 2018 : Debug: literal --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = ' Thu Jan 18 10:22:38 2018 : Debug: attribute --> SQL-User-Name Thu Jan 18 10:22:38 2018 : Debug: literal --> ' ORDER BY id Thu Jan 18 10:22:38 2018 : Debug: (1) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id Thu Jan 18 10:22:38 2018 : Debug: (1) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'rtmobilnetz@rtmobil' ORDER BY id Thu Jan 18 10:22:38 2018 : Debug: (1) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'rtmobilnetz@rtmobil' ORDER BY id Thu Jan 18 10:22:38 2018 : Debug: (1) sql: ... falling-through to group processing Thu Jan 18 10:22:38 2018 : Debug: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority Thu Jan 18 10:22:38 2018 : Debug: Parsed xlat tree: Thu Jan 18 10:22:38 2018 : Debug: literal --> SELECT groupname FROM radusergroup WHERE username = ' Thu Jan 18 10:22:38 2018 : Debug: attribute --> SQL-User-Name Thu Jan 18 10:22:38 2018 : Debug: literal --> ' ORDER BY priority Thu Jan 18 10:22:38 2018 : Debug: (1) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority Thu Jan 18 10:22:38 2018 : Debug: (1) sql: --> SELECT groupname FROM radusergroup WHERE username = 'rtmobilnetz@rtmobil' ORDER BY priority Thu Jan 18 10:22:38 2018 : Debug: (1) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'rtmobilnetz@rtmobil' ORDER BY priority Thu Jan 18 10:22:38 2018 : Debug: (1) sql: User not found in any groups Thu Jan 18 10:22:38 2018 : Debug: (1) sql: ... falling-through to profile processing Thu Jan 18 10:22:38 2018 : Debug: rlm_sql (sql): Released connection (1) Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[authorize]: returned from sql (rlm_sql) Thu Jan 18 10:22:38 2018 : Debug: (1) [sql] = notfound Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[authorize]: calling pap (rlm_pap) Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[authorize]: returned from pap (rlm_pap) Thu Jan 18 10:22:38 2018 : Debug: (1) [pap] = noop Thu Jan 18 10:22:38 2018 : Debug: (1) } # authorize = updated Thu Jan 18 10:22:38 2018 : Debug: (1) Starting proxy to home server 129.217.197.132 port 1812 Thu Jan 18 10:22:38 2018 : Debug: (1) Empty pre-proxy section in virtual server "itmc-wlan". Using default return values. Thu Jan 18 10:22:38 2018 : Debug: (1) proxy: Trying to allocate ID (0/2) Thu Jan 18 10:22:38 2018 : Debug: (1) proxy: request is now in proxy hash Thu Jan 18 10:22:38 2018 : Debug: (1) proxy: allocating destination 129.217.197.132 port 1812 - Id 189 Thu Jan 18 10:22:38 2018 : Debug: (1) Proxying request to home server 129.217.197.132 port 1812 timeout 20.000000 Thu Jan 18 10:22:38 2018 : Debug: (1) Sent Access-Request Id 189 from 0.0.0.0:48124 to 129.217.197.132:1812 length 336 Thu Jan 18 10:22:38 2018 : Debug: (1) User-Name = "rtmobilnetz@rtmobil" Thu Jan 18 10:22:38 2018 : Debug: (1) Chargeable-User-Identity = 0x00 Thu Jan 18 10:22:38 2018 : Debug: (1) Location-Capable = Civic-Location Thu Jan 18 10:22:38 2018 : Debug: (1) Calling-Station-Id = "3c-15-c2-e8-40-fe" Thu Jan 18 10:22:38 2018 : Debug: (1) Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-Port = 1 Thu Jan 18 10:22:38 2018 : Debug: (1) Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Thu Jan 18 10:22:38 2018 : Debug: (1) Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-IP-Address = 129.217.251.242 Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-Identifier = "wlc-staging" Thu Jan 18 10:22:38 2018 : Debug: (1) Airespace-Wlan-Id = 8 Thu Jan 18 10:22:38 2018 : Debug: (1) Service-Type = Framed-User Thu Jan 18 10:22:38 2018 : Debug: (1) Framed-MTU = 1300 Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-Port-Type = Wireless-802.11 Thu Jan 18 10:22:38 2018 : Debug: (1) Tunnel-Type:0 = VLAN Thu Jan 18 10:22:38 2018 : Debug: (1) Tunnel-Medium-Type:0 = IEEE-802 Thu Jan 18 10:22:38 2018 : Debug: (1) Tunnel-Private-Group-Id:0 = "3503" Thu Jan 18 10:22:38 2018 : Debug: (1) EAP-Message = 0x020200080319152b Thu Jan 18 10:22:38 2018 : Debug: (1) State = 0x45300497000001370001020081d9c584000000000000000000000000000000100d436aee Thu Jan 18 10:22:38 2018 : Debug: (1) Message-Authenticator = 0x31a7b8a02c1f45acee5e637c48d8f20d Thu Jan 18 10:22:38 2018 : Debug: (1) Event-Timestamp = "Jan 18 2018 10:22:38 CET" Thu Jan 18 10:22:38 2018 : Debug: (1) Proxy-State = 0x3639 Thu Jan 18 10:22:38 2018 : Debug: Waking up in 0.3 seconds. Thu Jan 18 10:22:38 2018 : Debug: (1) Clearing existing &reply: attributes Thu Jan 18 10:22:38 2018 : Debug: (1) Received Access-Reject Id 189 from 129.217.197.132:1812 to 129.217.131.207:48124 length 48 Thu Jan 18 10:22:38 2018 : Debug: (1) Proxy-State = 0x3639 Thu Jan 18 10:22:38 2018 : Debug: (1) EAP-Message = 0x04020004 Thu Jan 18 10:22:38 2018 : Debug: (1) Message-Authenticator = 0x9e213d17e11b8899c78a36353803fdad Thu Jan 18 10:22:38 2018 : Debug: (1) # Executing section post-proxy from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:22:38 2018 : Debug: (1) post-proxy { Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[post-proxy]: calling attr_filter.post-proxy (rlm_attr_filter) Thu Jan 18 10:22:38 2018 : Debug: %{Realm} Thu Jan 18 10:22:38 2018 : Debug: Parsed xlat tree: Thu Jan 18 10:22:38 2018 : Debug: attribute --> Realm Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.post-proxy: EXPAND %{Realm} Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.post-proxy: --> rtmobil Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.post-proxy: Matched entry rtmobil at line 17 Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.post-proxy: Attribute "Proxy-State" allowed by 0 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.post-proxy: Attribute "EAP-Message" allowed by 0 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.post-proxy: Attribute "Message-Authenticator" allowed by 0 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.post-proxy: Matched entry DEFAULT at line 32 Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.post-proxy: Proxy-State = 0x3639 allowed by Proxy-State =* 0x Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.post-proxy: Attribute "Proxy-State" allowed by 1 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.post-proxy: EAP-Message = 0x04020004 allowed by EAP-Message =* 0x Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.post-proxy: Attribute "EAP-Message" allowed by 1 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.post-proxy: Message-Authenticator = 0x9e213d17e11b8899c78a36353803fdad allowed by Message-Authenticator =* 0x Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.post-proxy: Attribute "Message-Authenticator" allowed by 1 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[post-proxy]: returned from attr_filter.post-proxy (rlm_attr_filter) Thu Jan 18 10:22:38 2018 : Debug: (1) [attr_filter.post-proxy] = updated Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[post-proxy]: calling eap_wlan (rlm_eap) Thu Jan 18 10:22:38 2018 : Debug: (1) eap_wlan: No pre-existing handler found Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[post-proxy]: returned from eap_wlan (rlm_eap) Thu Jan 18 10:22:38 2018 : Debug: (1) [eap_wlan] = noop Thu Jan 18 10:22:38 2018 : Debug: (1) } # post-proxy = updated Thu Jan 18 10:22:38 2018 : Auth: (1) Login incorrect (Home Server says so): [rtmobilnetz@rtmobil/<no User-Password attribute>] (from client wlc-management-wism2 port 1 cli 3c-15-c2-e8-40-fe) Thu Jan 18 10:22:38 2018 : Debug: (1) Using Post-Auth-Type Reject Thu Jan 18 10:22:38 2018 : Debug: (1) # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:22:38 2018 : Debug: (1) Post-Auth-Type REJECT { Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) Thu Jan 18 10:22:38 2018 : Debug: %{User-Name} Thu Jan 18 10:22:38 2018 : Debug: Parsed xlat tree: Thu Jan 18 10:22:38 2018 : Debug: attribute --> User-Name Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.access_reject: EXPAND %{User-Name} Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.access_reject: --> rtmobilnetz@rtmobil Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.access_reject: Matched entry DEFAULT at line 11 Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.access_reject: Attribute "Tunnel-Private-Group-Id" allowed by 0 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.access_reject: Attribute "Tunnel-Type" allowed by 0 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.access_reject: Attribute "Tunnel-Medium-Type" allowed by 0 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.access_reject: EAP-Message = 0x04020004 allowed by EAP-Message =* 0x Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.access_reject: Attribute "EAP-Message" allowed by 1 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.access_reject: Message-Authenticator = 0x9e213d17e11b8899c78a36353803fdad allowed by Message-Authenticator =* 0x Thu Jan 18 10:22:38 2018 : Debug: (1) attr_filter.access_reject: Attribute "Message-Authenticator" allowed by 1 rules, disallowed by 0 rules Thu Jan 18 10:22:38 2018 : Debug: (1) modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) Thu Jan 18 10:22:38 2018 : Debug: (1) [attr_filter.access_reject] = updated Thu Jan 18 10:22:38 2018 : Debug: (1) } # Post-Auth-Type REJECT = updated Thu Jan 18 10:22:38 2018 : Auth: (1) Login incorrect: [rtmobilnetz@rtmobil/<no User-Password attribute>] (from client wlc-management-wism2 port 1 cli 3c-15-c2-e8-40-fe) Thu Jan 18 10:22:38 2018 : Debug: (1) Delaying response for 1.000000 seconds Thu Jan 18 10:22:38 2018 : Debug: Waking up in 0.3 seconds. Thu Jan 18 10:22:38 2018 : Debug: Waking up in 0.6 seconds. Thu Jan 18 10:22:39 2018 : Debug: (1) Sending delayed response Thu Jan 18 10:22:39 2018 : Debug: (1) Sent Access-Reject Id 69 from 129.217.131.207:1812 to 129.217.251.242:32775 length 44 Thu Jan 18 10:22:39 2018 : Debug: (1) EAP-Message = 0x04020004 Thu Jan 18 10:22:39 2018 : Debug: (1) Message-Authenticator = 0x9e213d17e11b8899c78a36353803fdad Thu Jan 18 10:22:39 2018 : Debug: Waking up in 3.9 seconds. Thu Jan 18 10:22:43 2018 : Debug: (0) Cleaning up request packet ID 68 with timestamp +50 Thu Jan 18 10:22:43 2018 : Debug: (1) Cleaning up request packet ID 69 with timestamp +51 Thu Jan 18 10:22:43 2018 : Info: Ready to process requests Debug freeradius 2 - proxy to home server - ok rad_recv: Access-Request packet from host 129.217.251.242 port 32775, id=56, length=304 User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" EAP-Message = 0x020100180172746d6f62696c6e65747a4072746d6f62696c Message-Authenticator = 0x5ad647c1cb63e15f0ab31291f47480c0 Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) Thu Jan 18 10:08:43 2018 : Info: ? Evaluating (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP packet type response id 1 length 24 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] No EAP Start, assuming it's an on-going EAP conversation Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = updated Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{Stripped-User-Name} -> Thu Jan 18 10:08:43 2018 : Info: [sql] ... expanding second conditional Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{User-Name} -> rtmobilnetz@rtmobil Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{%{User-Name}:-DEFAULT} -> rtmobilnetz@rtmobil Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> rtmobilnetz@rtmobil Thu Jan 18 10:08:43 2018 : Info: [sql] sql_set_user escaped user --> 'rtmobilnetz@rtmobil' Thu Jan 18 10:08:43 2018 : Debug: rlm_sql (sql): Reserving sql socket id: 9 Thu Jan 18 10:08:43 2018 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'rtmobilnetz@rtmobil' ORDER BY id Thu Jan 18 10:08:43 2018 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'rtmobilnetz@rtmobil' ORDER BY id Thu Jan 18 10:08:43 2018 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'rtmobilnetz@rtmobil' ORDER BY priority Thu Jan 18 10:08:43 2018 : Debug: rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = 'rtmobilnetz@rtmobil' ORDER BY priority Thu Jan 18 10:08:43 2018 : Debug: rlm_sql (sql): Released sql socket id: 9 Thu Jan 18 10:08:43 2018 : Info: [sql] User rtmobilnetz@rtmobil not found Thu Jan 18 10:08:43 2018 : Info: ++[sql] = notfound Thu Jan 18 10:08:43 2018 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Thu Jan 18 10:08:43 2018 : Info: ++[pap] = noop Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = updated Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authenticate { Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP Identity Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] processing type tls Thu Jan 18 10:08:43 2018 : Info: [tls] Initiate Thu Jan 18 10:08:43 2018 : Info: [tls] Start returned 1 Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = handled Thu Jan 18 10:08:43 2018 : Info: +} # group authenticate = handled Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Sending Access-Challenge of id 56 to 129.217.251.242 port 32775 EAP-Message = 0x010200061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3c98a70a3c9abea1f795a66daa110d86 Thu Jan 18 10:08:43 2018 : Info: Finished request 0. Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 129.217.251.242 port 32775, id=57, length=459 User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" EAP-Message = 0x020200a119800000009716030100920100008e03035a60641b5a6d658e034c219ee9a5b5eb3ef0afc88ffa56e0d6ff9b11f476954200002c00ffc02cc02bc024c023c00ac009c008c030c02fc028c027c014c013c012009d009c003d003c0035002f000a01000039000a00080006001700180019000b00020100000d00120010040102010501060104030203050306030005000501000000000012000000170000 State = 0x3c98a70a3c9abea1f795a66daa110d86 Message-Authenticator = 0xb55b58648c6498496af46a597e0a274d Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) Thu Jan 18 10:08:43 2018 : Info: ? Evaluating (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP packet type response id 2 length 161 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Continuing tunnel setup. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = ok Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authenticate { Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request found, released from the list Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP/peap Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] processing type peap Thu Jan 18 10:08:43 2018 : Info: [peap] processing EAP-TLS Thu Jan 18 10:08:43 2018 : Debug: TLS Length 151 Thu Jan 18 10:08:43 2018 : Info: [peap] Length Included Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_verify returned 11 Thu Jan 18 10:08:43 2018 : Info: [peap] (other): before/accept initialization Thu Jan 18 10:08:43 2018 : Info: [peap] TLS_accept: before/accept initialization Thu Jan 18 10:08:43 2018 : Info: [peap] <<< Unknown TLS version [length 0092] Thu Jan 18 10:08:43 2018 : Info: [peap] TLS_accept: SSLv3 read client hello A Thu Jan 18 10:08:43 2018 : Info: [peap] >>> Unknown TLS version [length 0039] Thu Jan 18 10:08:43 2018 : Info: [peap] TLS_accept: SSLv3 write server hello A Thu Jan 18 10:08:43 2018 : Info: [peap] >>> Unknown TLS version [length 0f5c] Thu Jan 18 10:08:43 2018 : Info: [peap] TLS_accept: SSLv3 write certificate A Thu Jan 18 10:08:43 2018 : Info: [peap] >>> Unknown TLS version [length 014d] Thu Jan 18 10:08:43 2018 : Info: [peap] TLS_accept: SSLv3 write key exchange A Thu Jan 18 10:08:43 2018 : Info: [peap] >>> Unknown TLS version [length 0004] Thu Jan 18 10:08:43 2018 : Info: [peap] TLS_accept: SSLv3 write server done A Thu Jan 18 10:08:43 2018 : Info: [peap] TLS_accept: SSLv3 flush data Thu Jan 18 10:08:43 2018 : Info: [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A Thu Jan 18 10:08:43 2018 : Info: [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A Thu Jan 18 10:08:43 2018 : Debug: In SSL Handshake Phase Thu Jan 18 10:08:43 2018 : Debug: In SSL Accept mode Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_process returned 13 Thu Jan 18 10:08:43 2018 : Info: [peap] EAPTLS_HANDLED Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = handled Thu Jan 18 10:08:43 2018 : Info: +} # group authenticate = handled Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Sending Access-Challenge of id 57 to 129.217.251.242 port 32775 EAP-Message = 0x0103040019c0000010fa160303003902000035030335833298b504c882c4f7664bb0d5607a607b72eb3fdcef219a99bfeb9eb8809200c03000000dff01000100000b0004030001021603030f5c0b000f58000f5500060530820601308204e9a003020102020c1c4a3f94e98ce7fd9b7d977a300d06092a864886f70d01010b050030818c310b300906035504061302444531293027060355040a1320546563686e697363686520556e6976657273697461657420446f72746d756e64310d300b060355040b130449544d43311d301b06035504031314545520446f72746d756e64204341202d204730313124302206092a864886f70d01090116156361 EAP-Message = 0x40706b692e74752d646f72746d756e642e6465301e170d3136313131353038303632385a170d3139303730393233353930305a30818a310b3009060355040613024445311c301a06035504080c134e6f7264726865696e2d5765737466616c656e3111300f06035504070c08446f72746d756e6431293027060355040a0c20546563686e697363686520556e6976657273697461657420446f72746d756e64311f301d06035504030c16726164697573332e74752d646f72746d756e642e646530820122300d06092a864886f70d01010105000382010f003082010a0282010100dd8a4902370c77cbd05b13a4776f4907ca8b3b69b42df0e5d6c462dc EAP-Message = 0xf5986b4e19bddf06b87e3e181d9320a1575d75070b44f957ec04c3cf4e50046f475d0c5b2eb170163b62ca2938426a5e2cc4282cfa9bc3a992eacf1a76c889a738b748a975e963b65e405ad99bb87605bccdd17ed33662966650f99069cc6fdb18ec9bcf306262578561ad48c472e593115ec42e8039469f6fe7aaffc2ec0b5b17402898867461d2e18dbf9d60d2b14d98dfd493227eaaf0272c7fab98ecb884b9f1f13cbca1f0be411f79f99b016af926d6471d9fb255370ec228902f0417d3770d0eda4d767d3d8418b7d2636f915cd6488df2bcb9aae0dbec38a0e2a69b6faff75a4d0203010001a38202613082025d30590603551d200452305030 EAP-Message = 0x11060f2b0601040181ad21822c01010403053011060f2b0601040181ad21822c0201040301300f060d2b0601040181ad21822c010104300d060b2b0601040181ad21822c1e3008060667810c01020230090603551d1304023000300e0603551d0f0101ff0404030205a0301d0603551d250416301406082b0601050507030206082b06010505070301301d0603551d0e041604149ddf5679d261d42c116d7dca1e23d317515bef82301f0603551d23041830168014fbb15c9b6de825e4a9aa3244ef0283450de606ec30210603551d11041a30188216726164697573332e74752d646f72746d756e642e64653081880603551d1f048180307e303da03b EAP-Message = 0xa0398637687474703a2f2f63 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3c98a70a3d9bbea1f795a66daa110d86 Thu Jan 18 10:08:43 2018 : Info: Finished request 1. Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 129.217.251.242 port 32775, id=58, length=304 User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" EAP-Message = 0x020300061900 State = 0x3c98a70a3d9bbea1f795a66daa110d86 Message-Authenticator = 0x9d83a317c6e1bf62ee7c76cda9726457 Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) Thu Jan 18 10:08:43 2018 : Info: ? Evaluating (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP packet type response id 3 length 6 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Continuing tunnel setup. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = ok Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authenticate { Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request found, released from the list Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP/peap Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] processing type peap Thu Jan 18 10:08:43 2018 : Info: [peap] processing EAP-TLS Thu Jan 18 10:08:43 2018 : Info: [peap] Received TLS ACK Thu Jan 18 10:08:43 2018 : Info: [peap] ACK handshake fragment handler Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_verify returned 1 Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_process returned 13 Thu Jan 18 10:08:43 2018 : Info: [peap] EAPTLS_HANDLED Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = handled Thu Jan 18 10:08:43 2018 : Info: +} # group authenticate = handled Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Sending Access-Challenge of id 58 to 129.217.251.242 port 32775 EAP-Message = 0x010403fc19406470312e7063612e64666e2e64652f74752d646f72746d756e642d63612f7075622f63726c2f636163726c2e63726c303da03ba0398637687474703a2f2f636470322e7063612e64666e2e64652f74752d646f72746d756e642d63612f7075622f63726c2f636163726c2e63726c3081d706082b060105050701010481ca3081c7303306082b060105050730018627687474703a2f2f6f6373702e7063612e64666e2e64652f4f4353502d5365727665722f4f435350304706082b06010505073002863b687474703a2f2f636470312e7063612e64666e2e64652f74752d646f72746d756e642d63612f7075622f6361636572742f6361 EAP-Message = 0x636572742e637274304706082b06010505073002863b687474703a2f2f636470322e7063612e64666e2e64652f74752d646f72746d756e642d63612f7075622f6361636572742f6361636572742e637274300d06092a864886f70d01010b05000382010100bcbf44bca0f8dd220f4e82ee83cca847bdd8b5e22a5a02144ac9674ee1983bc6ce8fd48f9dcc095ea0ebccedb22136742485de7ebf0d13ca9761e7e0e659bee28788eaaad69db87fae62b54d15bca9b999c0a4a4580af1100b9c43977d86b74fdfcb8dc08f2010af8a5bd55403c68d7acbe153b7b98badeefc8d9fdf4c1511a5479823f2c8eaa8c69e39a95bd2a68d9460bfe162d0d99578 EAP-Message = 0xeb0652818a7a01620389b664eb78c71855ff50c95563b66a9ba50a20d021eefa295ea64e23e48bdeaa81ae08fc23ba05da989ff4b2ac579208adace73c2ed62ce116cf7db32635a10a78be707463680873caf22f5867461820a16e54ca71b1bf993d965d698e30120005223082051e30820406a00302010202040c438cd5300d06092a864886f70d0101050500305a310b300906035504061302444531133011060355040a130a44464e2d56657265696e3110300e060355040b130744464e2d504b49312430220603550403131b44464e2d56657265696e2050434120476c6f62616c202d20473031301e170d3038303530393038343535385a170d31 EAP-Message = 0x39303633303030303030305a30818c310b300906035504061302444531293027060355040a1320546563686e697363686520556e6976657273697461657420446f72746d756e64310d300b060355040b130449544d43311d301b06035504031314545520446f72746d756e64204341202d204730313124302206092a864886f70d0109011615636140706b692e74752d646f72746d756e642e646530820122300d06092a864886f70d01010105000382010f003082010a0282010100f4ba0476ee5a973fb8ae918abd1f22165fe77137645b220be30e687170303370e48a254f64a9f7ed2f97800e03caa7270c5c33780b7acdcd83c161cb76532df6a7 EAP-Message = 0x38c8f3956c305740 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3c98a70a3e9cbea1f795a66daa110d86 Thu Jan 18 10:08:43 2018 : Info: Finished request 2. Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 129.217.251.242 port 32775, id=59, length=304 User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" EAP-Message = 0x020400061900 State = 0x3c98a70a3e9cbea1f795a66daa110d86 Message-Authenticator = 0xc9e8ba6e82ff9ee3f60b4ac4f198b861 Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) Thu Jan 18 10:08:43 2018 : Info: ? Evaluating (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP packet type response id 4 length 6 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Continuing tunnel setup. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = ok Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authenticate { Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request found, released from the list Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP/peap Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] processing type peap Thu Jan 18 10:08:43 2018 : Info: [peap] processing EAP-TLS Thu Jan 18 10:08:43 2018 : Info: [peap] Received TLS ACK Thu Jan 18 10:08:43 2018 : Info: [peap] ACK handshake fragment handler Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_verify returned 1 Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_process returned 13 Thu Jan 18 10:08:43 2018 : Info: [peap] EAPTLS_HANDLED Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = handled Thu Jan 18 10:08:43 2018 : Info: +} # group authenticate = handled Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Sending Access-Challenge of id 59 to 129.217.251.242 port 32775 EAP-Message = 0x010503fc19409befa84e1efc913c27d239cf8c37a388dfe7282d6b6f8f089ff8ee47cd3e8d6ca3e4441e4c22823f5292f81e11312fb39dfdf2191696a4138d716cb57e750810a46c2b4135218ae72bbb9cb59d956fc2cb5451111e7b78f41690757257ad1aadaeaa35533e90c635a49ee20f0ba7023eea5214c02756fc3010d976c7f3a8401d23b28d3204cf423011c3554046dc1645578693b195826cab728f4b09e00f73aff9423d09a598ad3b55128b589e01262b6b37a0429e70b90203010001a38201b7308201b330120603551d130101ff040830060101ff020101300b0603551d0f040403020106301d0603551d0e04160414fbb15c9b6de825 EAP-Message = 0xe4a9aa3244ef0283450de606ec301f0603551d2304183016801449b7c6cfe83d1f7fea447b1329f7f10a703ede6430200603551d11041930178115636140706b692e74752d646f72746d756e642e64653081880603551d1f048180307e303da03ba0398637687474703a2f2f636470312e7063612e64666e2e64652f676c6f62616c2d726f6f742d63612f7075622f63726c2f636163726c2e63726c303da03ba0398637687474703a2f2f636470322e7063612e64666e2e64652f676c6f62616c2d726f6f742d63612f7075622f63726c2f636163726c2e63726c3081a206082b06010505070101048195308192304706082b06010505073002863b68 EAP-Message = 0x7474703a2f2f636470312e7063612e64666e2e64652f676c6f62616c2d726f6f742d63612f7075622f6361636572742f6361636572742e637274304706082b06010505073002863b687474703a2f2f636470322e7063612e64666e2e64652f676c6f62616c2d726f6f742d63612f7075622f6361636572742f6361636572742e637274300d06092a864886f70d010105050003820101004d463fdb53b4543fb01bd22fe95aeffe713d7a179cbf2797df89f6a32900779cd69a0fba5c6aced8c4dbcf5ccb53b81e44ac02f0fc397cadd9203b15d6fff9abade6666b9b5a74b68e2624ebfc170b0ac7de9c7375318972421bef5d8893edb41f213eab19de EAP-Message = 0x5786d31c288355fb77e0f260ab70c5f4fe4257adf97b00e3291dea65acaf6e6122162087cee95f23214cdaa865c124f130e6e4f2532bd94bbbc10c10cfe61a89df0c1efec34181adeffc64da4d8250abd4d054997700ea7b70acdb7d072ed2c0d3ca9e4efeece28a06993d9b4296500f556e9b930e2df0e27e91c9c9a8ae115746a6d75b3845055fcd1b0c6bf36ad0c2d4faba2ca110bb0e74ee0004253082042130820309a003020102020200c7300d06092a864886f70d01010505003071310b3009060355040613024445311c301a060355040a131344657574736368652054656c656b6f6d204147311f301d060355040b1316542d54656c655365 EAP-Message = 0x6320547275737420 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3c98a70a3f9dbea1f795a66daa110d86 Thu Jan 18 10:08:43 2018 : Info: Finished request 3. Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 129.217.251.242 port 32775, id=60, length=304 User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" EAP-Message = 0x020500061900 State = 0x3c98a70a3f9dbea1f795a66daa110d86 Message-Authenticator = 0x0083688d4095e4f4232e1488fda2798e Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) Thu Jan 18 10:08:43 2018 : Info: ? Evaluating (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP packet type response id 5 length 6 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Continuing tunnel setup. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = ok Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authenticate { Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request found, released from the list Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP/peap Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] processing type peap Thu Jan 18 10:08:43 2018 : Info: [peap] processing EAP-TLS Thu Jan 18 10:08:43 2018 : Info: [peap] Received TLS ACK Thu Jan 18 10:08:43 2018 : Info: [peap] ACK handshake fragment handler Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_verify returned 1 Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_process returned 13 Thu Jan 18 10:08:43 2018 : Info: [peap] EAPTLS_HANDLED Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = handled Thu Jan 18 10:08:43 2018 : Info: +} # group authenticate = handled Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Sending Access-Challenge of id 60 to 129.217.251.242 port 32775 EAP-Message = 0x010603fc194043656e746572312330210603550403131a44657574736368652054656c656b6f6d20526f6f742043412032301e170d3036313231393130323930305a170d3139303633303233353930305a305a310b300906035504061302444531133011060355040a130a44464e2d56657265696e3110300e060355040b130744464e2d504b49312430220603550403131b44464e2d56657265696e2050434120476c6f62616c202d2047303130820122300d06092a864886f70d01010105000382010f003082010a0282010100e99bc36785f90daef58d54c39650353d62e96e4ced94d7005b952274d420eb348fd6ecc031040b9981e2a614d252a0 EAP-Message = 0x2823848b7489045e5be0e278c178cb16cb2835397b2d9045d0eda0007a7cbf4a0e1b00c386e95c2b31117b0cf38224438c1c388b6a68009aeedc4f78abd2c6139b76adeede26e8ef01af740fc109a2f66bcebdd3cd14304ff5e5e3a4c8629b821a0327300d0265604dedd109232a96355827d376c671b6901dc4edff35867d6f33b3db0fc511c28a83a1945d416bd8d210f54cfdca51acd9bdef9283bbdaeb8b16565643cfe1d5133da61f2730cd4954dbc913349a7175c56ceaa70b98f9219d27af3ea33939486a8cadc999fbc312f2bd0203010001a381d93081d630700603551d1f046930673065a063a061865f687474703a2f2f706b692e74656c EAP-Message = 0x657365632e64652f6367692d62696e2f736572766963652f61665f446f776e6c6f616441524c2e63726c3f2d63726c5f666f726d61743d585f353039262d6973737565723d44545f524f4f545f43415f32301d0603551d0e0416041449b7c6cfe83d1f7fea447b1329f7f10a703ede64301f0603551d2304183016801431c3791bbaf553d717e0897a2d176c0ab32b9d33300e0603551d0f0101ff04040302010630120603551d130101ff040830060101ff020102300d06092a864886f70d010105050003820101003be15a77c04817dca918ec81af5a89f0bd2892a6ca59181270ec28f2e7ae7f962ce7f25d1931f6132b74bdbd80b2b9f767c939a2 EAP-Message = 0x793be11111ee6b7891337e3b5f26277553658e3363eecf73c3b092234921507523a11f18e294853d3f33e977208da2bde6a1852940f63f7332580d096ba6da856cc03fbb8d666456244eae0d3f3235015be98c82d972594fb18685f1748556e5c3f85cf38dee47b3530570e7e54d8a698328e11309869e5ec8ea581e0c1ff9a4d45a0468fd283e8b02b658b5f6a12c37570067ab23688d63a5ef996b5cfd4b56f6ab408734d411926cec87c50a0b073372b46f0c1d542cd851c7ccbf30d34372f132bf8cce4963a800f7f21c160303014d0c000149030017410453131d6ba785c86860bfe67949a93cf5d860d6e5d46e5b3577917dc2426666e4dde09f EAP-Message = 0xcf3ba7dc467abd28 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3c98a70a389ebea1f795a66daa110d86 Thu Jan 18 10:08:43 2018 : Info: Finished request 4. Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 129.217.251.242 port 32775, id=61, length=304 User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" EAP-Message = 0x020600061900 State = 0x3c98a70a389ebea1f795a66daa110d86 Message-Authenticator = 0x5a61790459d1d162d38ceb815f045035 Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) Thu Jan 18 10:08:43 2018 : Info: ? Evaluating (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP packet type response id 6 length 6 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Continuing tunnel setup. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = ok Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authenticate { Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request found, released from the list Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP/peap Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] processing type peap Thu Jan 18 10:08:43 2018 : Info: [peap] processing EAP-TLS Thu Jan 18 10:08:43 2018 : Info: [peap] Received TLS ACK Thu Jan 18 10:08:43 2018 : Info: [peap] ACK handshake fragment handler Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_verify returned 1 Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_process returned 13 Thu Jan 18 10:08:43 2018 : Info: [peap] EAPTLS_HANDLED Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = handled Thu Jan 18 10:08:43 2018 : Info: +} # group authenticate = handled Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Sending Access-Challenge of id 61 to 129.217.251.242 port 32775 EAP-Message = 0x010701281900354f9c32064ed9e7d5e75c44b763b1511472eba320040101005c31aa28b4dbb9d01a95e3db398a72ce00754dc61ed011edd7c98bbe879e3e7bf20824fdf369fd8e5f5ec25fe3c3a8d2d84f50fc266c9be94e565f7fea379c03babc658a90f655a9bca8c96e97f8bd2adc108a60e3eda86058e0bdd3079b83a8f9ab854e66311ae8278acedc726537083f2350d5e8de48159547c2779406d4c384a9f2da77df9427e9c84a0f2de42f771ca63516035eb439acfa75a276ca016e0969d0a7d320bc74fd4bef2ffac9d59676436ac57fc552bc1b6cc38f7f0cc3f1f8f30dbe89f8a50dd8a97082eabf67fe2ec697d8fb55feb2e43496960d7e EAP-Message = 0x03af69b4f875ad58a7590939f8d1d9d158c4a2b73868fb3a589c6f06e10dc168959816030300040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3c98a70a399fbea1f795a66daa110d86 Thu Jan 18 10:08:43 2018 : Info: Finished request 5. Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 129.217.251.242 port 32775, id=62, length=434 User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" EAP-Message = 0x0207008819800000007e16030300461000004241040b0ab49ba3325dfdaf81cd8bdd72b1a2d493fa6d7b9d93b17d6b05342febbdaef9eb2f310dc4d1287ba6cf71371d6b3e8bb798706401ca980310ce47ee42b8d714030300010116030300288c46983303f6f502b347d4709551ff636ad157dbe449cf43c973cfaaf4bd3ef7ad265753ddc4cead State = 0x3c98a70a399fbea1f795a66daa110d86 Message-Authenticator = 0x171ae347783220465e00e196b1a9e966 Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) Thu Jan 18 10:08:43 2018 : Info: ? Evaluating (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP packet type response id 7 length 136 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Continuing tunnel setup. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = ok Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authenticate { Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request found, released from the list Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP/peap Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] processing type peap Thu Jan 18 10:08:43 2018 : Info: [peap] processing EAP-TLS Thu Jan 18 10:08:43 2018 : Debug: TLS Length 126 Thu Jan 18 10:08:43 2018 : Info: [peap] Length Included Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_verify returned 11 Thu Jan 18 10:08:43 2018 : Info: [peap] <<< Unknown TLS version [length 0046] Thu Jan 18 10:08:43 2018 : Info: [peap] TLS_accept: SSLv3 read client key exchange A Thu Jan 18 10:08:43 2018 : Info: [peap] <<< Unknown TLS version [length 0001] Thu Jan 18 10:08:43 2018 : Info: [peap] <<< Unknown TLS version [length 0010] Thu Jan 18 10:08:43 2018 : Info: [peap] TLS_accept: SSLv3 read finished A Thu Jan 18 10:08:43 2018 : Info: [peap] >>> Unknown TLS version [length 0001] Thu Jan 18 10:08:43 2018 : Info: [peap] TLS_accept: SSLv3 write change cipher spec A Thu Jan 18 10:08:43 2018 : Info: [peap] >>> Unknown TLS version [length 0010] Thu Jan 18 10:08:43 2018 : Info: [peap] TLS_accept: SSLv3 write finished A Thu Jan 18 10:08:43 2018 : Info: [peap] TLS_accept: SSLv3 flush data Thu Jan 18 10:08:43 2018 : Info: [peap] (other): SSL negotiation finished successfully Thu Jan 18 10:08:43 2018 : Debug: SSL Connection Established Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_process returned 13 Thu Jan 18 10:08:43 2018 : Info: [peap] EAPTLS_HANDLED Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = handled Thu Jan 18 10:08:43 2018 : Info: +} # group authenticate = handled Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Sending Access-Challenge of id 62 to 129.217.251.242 port 32775 EAP-Message = 0x01080039190014030300010116030300288ba36faaaa8eca19b9006ddf468af903754172914f3e754614f283fa0cd9357f8aa05da2a0e52f22 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3c98a70a3a90bea1f795a66daa110d86 Thu Jan 18 10:08:43 2018 : Info: Finished request 6. Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 129.217.251.242 port 32775, id=63, length=304 User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" EAP-Message = 0x020800061900 State = 0x3c98a70a3a90bea1f795a66daa110d86 Message-Authenticator = 0x56b73b5f66b4b80486760fde696d339f Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) Thu Jan 18 10:08:43 2018 : Info: ? Evaluating (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP packet type response id 8 length 6 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Continuing tunnel setup. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = ok Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authenticate { Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request found, released from the list Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP/peap Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] processing type peap Thu Jan 18 10:08:43 2018 : Info: [peap] processing EAP-TLS Thu Jan 18 10:08:43 2018 : Info: [peap] Received TLS ACK Thu Jan 18 10:08:43 2018 : Info: [peap] ACK handshake is finished Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_verify returned 3 Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_process returned 3 Thu Jan 18 10:08:43 2018 : Info: [peap] EAPTLS_SUCCESS Thu Jan 18 10:08:43 2018 : Info: [peap] Session established. Decoding tunneled attributes. Thu Jan 18 10:08:43 2018 : Info: [peap] Peap state TUNNEL ESTABLISHED Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = handled Thu Jan 18 10:08:43 2018 : Info: +} # group authenticate = handled Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Sending Access-Challenge of id 63 to 129.217.251.242 port 32775 EAP-Message = 0x010900281900170303001d8ba36faaaa8eca1a0d5899d2c8a1e69049e71bee2e03f50c593b8a0226 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3c98a70a3b91bea1f795a66daa110d86 Thu Jan 18 10:08:43 2018 : Info: Finished request 7. Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 129.217.251.242 port 32775, id=64, length=353 User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" EAP-Message = 0x020900371900170303002c8c46983303f6f503d71c1b48c58a7b0cc5a3b787a602127e5cc5077cfe572c8874d79ade89d7db1df5151a4c State = 0x3c98a70a3b91bea1f795a66daa110d86 Message-Authenticator = 0xda187bab0fe1c2184182fca00c1cb5bd Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) Thu Jan 18 10:08:43 2018 : Info: ? Evaluating (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP packet type response id 9 length 55 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Continuing tunnel setup. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = ok Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authenticate { Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request found, released from the list Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP/peap Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] processing type peap Thu Jan 18 10:08:43 2018 : Info: [peap] processing EAP-TLS Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_verify returned 7 Thu Jan 18 10:08:43 2018 : Info: [peap] Done initial handshake Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_process returned 7 Thu Jan 18 10:08:43 2018 : Info: [peap] EAPTLS_OK Thu Jan 18 10:08:43 2018 : Info: [peap] Session established. Decoding tunneled attributes. Thu Jan 18 10:08:43 2018 : Info: [peap] Peap state WAITING FOR INNER IDENTITY Thu Jan 18 10:08:43 2018 : Info: [peap] Identity - rtmobilnetz@rtmobil Thu Jan 18 10:08:43 2018 : Info: [peap] Got inner identity 'rtmobilnetz@rtmobil' Thu Jan 18 10:08:43 2018 : Info: [peap] Setting default EAP type for tunneled EAP session. Thu Jan 18 10:08:43 2018 : Info: [peap] Got tunneled request EAP-Message = 0x020900180172746d6f62696c6e65747a4072746d6f62696c server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: [peap] Setting User-Name to rtmobilnetz@rtmobil Sending tunneled request EAP-Message = 0x020900180172746d6f62696c6e65747a4072746d6f62696c FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" server inner-wlan-peap { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-wlan-peap Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [suffix] Looking up realm "rtmobil" for User-Name = "rtmobilnetz@rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Found realm "rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Adding Realm = "rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Proxying request from user rtmobilnetz to realm rtmobil Thu Jan 18 10:08:43 2018 : Info: [suffix] Preparing to proxy authentication request to realm "rtmobil" Thu Jan 18 10:08:43 2018 : Info: ++[suffix] = updated Thu Jan 18 10:08:43 2018 : Info: ++[mschap] = noop Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request is supposed to be proxied to Realm rtmobil. Not doing EAP. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = noop Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{Stripped-User-Name} -> Thu Jan 18 10:08:43 2018 : Info: [sql] ... expanding second conditional Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{User-Name} -> rtmobilnetz@rtmobil Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{%{User-Name}:-DEFAULT} -> rtmobilnetz@rtmobil Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> rtmobilnetz@rtmobil Thu Jan 18 10:08:43 2018 : Info: [sql] sql_set_user escaped user --> 'rtmobilnetz@rtmobil' Thu Jan 18 10:08:43 2018 : Debug: rlm_sql (sql): Reserving sql socket id: 8 Thu Jan 18 10:08:43 2018 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'rtmobilnetz@rtmobil' ORDER BY id Thu Jan 18 10:08:43 2018 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'rtmobilnetz@rtmobil' ORDER BY id Thu Jan 18 10:08:43 2018 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'rtmobilnetz@rtmobil' ORDER BY priority Thu Jan 18 10:08:43 2018 : Debug: rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = 'rtmobilnetz@rtmobil' ORDER BY priority Thu Jan 18 10:08:43 2018 : Debug: rlm_sql (sql): Released sql socket id: 8 Thu Jan 18 10:08:43 2018 : Info: [sql] User rtmobilnetz@rtmobil not found Thu Jan 18 10:08:43 2018 : Info: ++[sql] = notfound Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:NT-Password}" == "") Thu Jan 18 10:08:43 2018 : Info: expand: %{check:NT-Password} -> Thu Jan 18 10:08:43 2018 : Info: ? Evaluating ("%{check:NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++if ("%{check:NT-Password}" == "") { Thu Jan 18 10:08:43 2018 : Info: +++[noop] = noop Thu Jan 18 10:08:43 2018 : Info: ++} # if ("%{check:NT-Password}" == "") = noop Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:wlan-NT-Password}" == "") Thu Jan 18 10:08:43 2018 : Info: expand: %{check:wlan-NT-Password} -> Thu Jan 18 10:08:43 2018 : Info: ? Evaluating ("%{check:wlan-NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:wlan-NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++if ("%{check:wlan-NT-Password}" == "") { Thu Jan 18 10:08:43 2018 : Info: +++update config { Thu Jan 18 10:08:43 2018 : Info: +++} # update config = noop Thu Jan 18 10:08:43 2018 : Info: ++} # if ("%{check:wlan-NT-Password}" == "") = noop Thu Jan 18 10:08:43 2018 : Info: ++ ... skipping else for request 8: Preceding "if" was taken Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:NT-Password}" == "") Thu Jan 18 10:08:43 2018 : Info: expand: %{check:NT-Password} -> Thu Jan 18 10:08:43 2018 : Info: ? Evaluating ("%{check:NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++if ("%{check:NT-Password}" == "") { Thu Jan 18 10:08:43 2018 : Info: +++[noop] = noop Thu Jan 18 10:08:43 2018 : Info: ++} # if ("%{check:NT-Password}" == "") = noop Thu Jan 18 10:08:43 2018 : Info: ++[expiration] = noop Thu Jan 18 10:08:43 2018 : Info: ++[logintime] = noop Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = updated } # server inner-wlan-peap Thu Jan 18 10:08:43 2018 : Info: [peap] Got tunneled reply code 0 Thu Jan 18 10:08:43 2018 : Debug: PEAP: Tunneled authentication will be proxied to rtmobil Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Tunneled session will be proxied. Not doing EAP. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = handled Thu Jan 18 10:08:43 2018 : Info: +} # group authenticate = handled Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Thu Jan 18 10:08:43 2018 : Info: WARNING: Empty pre-proxy section. Using default return values. Sending Access-Request of id 22 to 129.217.197.132 port 1812 EAP-Message = 0x020900180172746d6f62696c6e65747a4072746d6f62696c User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x3634 Thu Jan 18 10:08:43 2018 : Info: Proxying request 8 to home server 129.217.197.132 port 1812 Sending Access-Request of id 22 to 129.217.197.132 port 1812 EAP-Message = 0x020900180172746d6f62696c6e65747a4072746d6f62696c User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x3634 Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 0.9 seconds. rad_recv: Access-Challenge packet from host 129.217.197.132 port 1812, id=22, length=124 Proxy-State = 0x3634 Session-Timeout = 60 EAP-Message = 0x010a00241a010a001f108ab94c4fc3267e8169cea1d199664752504f4f4c2d4144533031 State = 0x452f0496000001370001020081d9c584000000000000000000000000000000100d436aed Message-Authenticator = 0xbd9d88907cf10737d8c053c498a8673a Thu Jan 18 10:08:43 2018 : Info: # Executing section post-proxy from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group post-proxy { Thu Jan 18 10:08:43 2018 : Info: [post_proxy_log] expand: %{Packet-Src-IP-Address} -> 129.217.251.242 Thu Jan 18 10:08:43 2018 : Info: [post_proxy_log] expand: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/129.217.251.242/post-proxy-detail-20180118 Thu Jan 18 10:08:43 2018 : Info: [post_proxy_log] /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/129.217.251.242/post-proxy-detail-20180118 Thu Jan 18 10:08:43 2018 : Info: [post_proxy_log] expand: %t -> Thu Jan 18 10:08:43 2018 Thu Jan 18 10:08:43 2018 : Info: ++[post_proxy_log] = ok Thu Jan 18 10:08:43 2018 : Info: [attr_filter.post-proxy] expand: %{Realm} -> rtmobil Thu Jan 18 10:08:43 2018 : Debug: attr_filter: Matched entry rtmobil at line 17 Thu Jan 18 10:08:43 2018 : Debug: attr_filter: Matched entry DEFAULT at line 32 Thu Jan 18 10:08:43 2018 : Info: ++[attr_filter.post-proxy] = updated Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Doing post-proxy callback Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Passing reply from proxy back into the tunnel. Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Got tunneled reply RADIUS code Access-Challenge Tunnel-Private-Group-Id:0 := "26" Tunnel-Type:0 := VLAN Tunnel-Medium-Type:0 := IEEE-802 Proxy-State = 0x3634 EAP-Message = 0x010a00241a010a001f108ab94c4fc3267e8169cea1d199664752504f4f4c2d4144533031 State = 0x452f0496000001370001020081d9c584000000000000000000000000000000100d436aed Message-Authenticator = 0xbd9d88907cf10737d8c053c498a8673a Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Got tunneled Access-Challenge PEAP tunnel data out 0000: 1a 01 0a 00 1f 10 8a b9 4c 4f c3 26 7e 81 69 ce PEAP tunnel data out 0010: a1 d1 99 66 47 52 50 4f 4f 4c 2d 41 44 53 30 31 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Reply was handled Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group post-proxy = updated Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Sending Access-Challenge of id 64 to 129.217.251.242 port 32775 EAP-Message = 0x010a0043190017030300388ba36faaaa8eca1b8ac205e1a35087ef050e5c1d41dff46abfb7964e17243d093c486c809fee94f43c644e5dd597b5fe68bb464e8a868ef1 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3c98a70a3492bea1f795a66daa110d86 Thu Jan 18 10:08:43 2018 : Info: Finished request 8. Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 129.217.251.242 port 32775, id=65, length=407 User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" EAP-Message = 0x020a006d190017030300628c46983303f6f504750b0f900c8378e551f1bd944e1c82f4bf52fd9269af5e9fcec96df83d0ac713ca6a69f2ea788cf44316296588be7882456b509376840d03cb08346088231b9f691f35065490d2951b949ac0f7ec1640c4d7893f230bdeb61795 State = 0x3c98a70a3492bea1f795a66daa110d86 Message-Authenticator = 0x3d925e61fc134337fdcf31e32530c77a Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) Thu Jan 18 10:08:43 2018 : Info: ? Evaluating (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP packet type response id 10 length 109 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Continuing tunnel setup. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = ok Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authenticate { Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request found, released from the list Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP/peap Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] processing type peap Thu Jan 18 10:08:43 2018 : Info: [peap] processing EAP-TLS Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_verify returned 7 Thu Jan 18 10:08:43 2018 : Info: [peap] Done initial handshake Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_process returned 7 Thu Jan 18 10:08:43 2018 : Info: [peap] EAPTLS_OK Thu Jan 18 10:08:43 2018 : Info: [peap] Session established. Decoding tunneled attributes. Thu Jan 18 10:08:43 2018 : Info: [peap] Peap state phase2 Thu Jan 18 10:08:43 2018 : Info: [peap] EAP type mschapv2 Thu Jan 18 10:08:43 2018 : Info: [peap] Got tunneled request EAP-Message = 0x020a004e1a020a004931e961cd1959c9c3069bf68107e3a510f60000000000000000466bda68b9093af3824d2e4aa0ad5230cf96900a181daacb0072746d6f62696c6e65747a4072746d6f62696c server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: [peap] Setting User-Name to rtmobilnetz@rtmobil Sending tunneled request EAP-Message = 0x020a004e1a020a004931e961cd1959c9c3069bf68107e3a510f60000000000000000466bda68b9093af3824d2e4aa0ad5230cf96900a181daacb0072746d6f62696c6e65747a4072746d6f62696c FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "rtmobilnetz@rtmobil" State = 0x452f0496000001370001020081d9c584000000000000000000000000000000100d436aed Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" server inner-wlan-peap { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-wlan-peap Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [suffix] Looking up realm "rtmobil" for User-Name = "rtmobilnetz@rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Found realm "rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Adding Realm = "rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Proxying request from user rtmobilnetz to realm rtmobil Thu Jan 18 10:08:43 2018 : Info: [suffix] Preparing to proxy authentication request to realm "rtmobil" Thu Jan 18 10:08:43 2018 : Info: ++[suffix] = updated Thu Jan 18 10:08:43 2018 : Info: ++[mschap] = noop Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request is supposed to be proxied to Realm rtmobil. Not doing EAP. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = noop Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{Stripped-User-Name} -> Thu Jan 18 10:08:43 2018 : Info: [sql] ... expanding second conditional Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{User-Name} -> rtmobilnetz@rtmobil Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{%{User-Name}:-DEFAULT} -> rtmobilnetz@rtmobil Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> rtmobilnetz@rtmobil Thu Jan 18 10:08:43 2018 : Info: [sql] sql_set_user escaped user --> 'rtmobilnetz@rtmobil' Thu Jan 18 10:08:43 2018 : Debug: rlm_sql (sql): Reserving sql socket id: 7 Thu Jan 18 10:08:43 2018 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'rtmobilnetz@rtmobil' ORDER BY id Thu Jan 18 10:08:43 2018 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'rtmobilnetz@rtmobil' ORDER BY id Thu Jan 18 10:08:43 2018 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'rtmobilnetz@rtmobil' ORDER BY priority Thu Jan 18 10:08:43 2018 : Debug: rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = 'rtmobilnetz@rtmobil' ORDER BY priority Thu Jan 18 10:08:43 2018 : Debug: rlm_sql (sql): Released sql socket id: 7 Thu Jan 18 10:08:43 2018 : Info: [sql] User rtmobilnetz@rtmobil not found Thu Jan 18 10:08:43 2018 : Info: ++[sql] = notfound Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:NT-Password}" == "") Thu Jan 18 10:08:43 2018 : Info: expand: %{check:NT-Password} -> Thu Jan 18 10:08:43 2018 : Info: ? Evaluating ("%{check:NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++if ("%{check:NT-Password}" == "") { Thu Jan 18 10:08:43 2018 : Info: +++[noop] = noop Thu Jan 18 10:08:43 2018 : Info: ++} # if ("%{check:NT-Password}" == "") = noop Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:wlan-NT-Password}" == "") Thu Jan 18 10:08:43 2018 : Info: expand: %{check:wlan-NT-Password} -> Thu Jan 18 10:08:43 2018 : Info: ? Evaluating ("%{check:wlan-NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:wlan-NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++if ("%{check:wlan-NT-Password}" == "") { Thu Jan 18 10:08:43 2018 : Info: +++update config { Thu Jan 18 10:08:43 2018 : Info: +++} # update config = noop Thu Jan 18 10:08:43 2018 : Info: ++} # if ("%{check:wlan-NT-Password}" == "") = noop Thu Jan 18 10:08:43 2018 : Info: ++ ... skipping else for request 9: Preceding "if" was taken Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:NT-Password}" == "") Thu Jan 18 10:08:43 2018 : Info: expand: %{check:NT-Password} -> Thu Jan 18 10:08:43 2018 : Info: ? Evaluating ("%{check:NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++if ("%{check:NT-Password}" == "") { Thu Jan 18 10:08:43 2018 : Info: +++[noop] = noop Thu Jan 18 10:08:43 2018 : Info: ++} # if ("%{check:NT-Password}" == "") = noop Thu Jan 18 10:08:43 2018 : Info: ++[expiration] = noop Thu Jan 18 10:08:43 2018 : Info: ++[logintime] = noop Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = updated } # server inner-wlan-peap Thu Jan 18 10:08:43 2018 : Info: [peap] Got tunneled reply code 0 Thu Jan 18 10:08:43 2018 : Debug: PEAP: Tunneled authentication will be proxied to rtmobil Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Tunneled session will be proxied. Not doing EAP. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = handled Thu Jan 18 10:08:43 2018 : Info: +} # group authenticate = handled Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Thu Jan 18 10:08:43 2018 : Info: WARNING: Empty pre-proxy section. Using default return values. Sending Access-Request of id 220 to 129.217.197.132 port 1812 EAP-Message = 0x020a004e1a020a004931e961cd1959c9c3069bf68107e3a510f60000000000000000466bda68b9093af3824d2e4aa0ad5230cf96900a181daacb0072746d6f62696c6e65747a4072746d6f62696c User-Name = "rtmobilnetz@rtmobil" State = 0x452f0496000001370001020081d9c584000000000000000000000000000000100d436aed Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x3635 Thu Jan 18 10:08:43 2018 : Info: Proxying request 9 to home server 129.217.197.132 port 1812 Sending Access-Request of id 220 to 129.217.197.132 port 1812 EAP-Message = 0x020a004e1a020a004931e961cd1959c9c3069bf68107e3a510f60000000000000000466bda68b9093af3824d2e4aa0ad5230cf96900a181daacb0072746d6f62696c6e65747a4072746d6f62696c User-Name = "rtmobilnetz@rtmobil" State = 0x452f0496000001370001020081d9c584000000000000000000000000000000100d436aed Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x3635 Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 0.9 seconds. rad_recv: Access-Challenge packet from host 129.217.197.132 port 1812, id=220, length=139 Proxy-State = 0x3635 Session-Timeout = 60 EAP-Message = 0x010b00331a030a002e533d34434246433531333243453236433136363037353236333245394632363041453232383536433233 State = 0x452f0496000001370001020081d9c584000000000000000000000000000000100d436aed Message-Authenticator = 0x008aa898c0a1141888fe6cf38f403101 Thu Jan 18 10:08:43 2018 : Info: # Executing section post-proxy from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group post-proxy { Thu Jan 18 10:08:43 2018 : Info: [post_proxy_log] expand: %{Packet-Src-IP-Address} -> 129.217.251.242 Thu Jan 18 10:08:43 2018 : Info: [post_proxy_log] expand: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/129.217.251.242/post-proxy-detail-20180118 Thu Jan 18 10:08:43 2018 : Info: [post_proxy_log] /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/129.217.251.242/post-proxy-detail-20180118 Thu Jan 18 10:08:43 2018 : Info: [post_proxy_log] expand: %t -> Thu Jan 18 10:08:43 2018 Thu Jan 18 10:08:43 2018 : Info: ++[post_proxy_log] = ok Thu Jan 18 10:08:43 2018 : Info: [attr_filter.post-proxy] expand: %{Realm} -> rtmobil Thu Jan 18 10:08:43 2018 : Debug: attr_filter: Matched entry rtmobil at line 17 Thu Jan 18 10:08:43 2018 : Debug: attr_filter: Matched entry DEFAULT at line 32 Thu Jan 18 10:08:43 2018 : Info: ++[attr_filter.post-proxy] = updated Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Doing post-proxy callback Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Passing reply from proxy back into the tunnel. Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Got tunneled reply RADIUS code Access-Challenge Tunnel-Private-Group-Id:0 := "26" Tunnel-Type:0 := VLAN Tunnel-Medium-Type:0 := IEEE-802 Proxy-State = 0x3635 EAP-Message = 0x010b00331a030a002e533d34434246433531333243453236433136363037353236333245394632363041453232383536433233 State = 0x452f0496000001370001020081d9c584000000000000000000000000000000100d436aed Message-Authenticator = 0x008aa898c0a1141888fe6cf38f403101 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Got tunneled Access-Challenge PEAP tunnel data out 0000: 1a 03 0a 00 2e 53 3d 34 43 42 46 43 35 31 33 32 PEAP tunnel data out 0010: 43 45 32 36 43 31 36 36 30 37 35 32 36 33 32 45 PEAP tunnel data out 0020: 39 46 32 36 30 41 45 32 32 38 35 36 43 32 33 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Reply was handled Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group post-proxy = updated Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Sending Access-Challenge of id 65 to 129.217.251.242 port 32775 EAP-Message = 0x010b0052190017030300478ba36faaaa8eca1c5c5759b9c4c249a64a66cdc97de32775882db10c9df3f622659db59e7bd86ab63e249e5260034ed209f549ae3e30898ec036c7017be62a9440c1b340de7ac6 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3c98a70a3593bea1f795a66daa110d86 Thu Jan 18 10:08:43 2018 : Info: Finished request 9. Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 129.217.251.242 port 32775, id=66, length=335 User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" EAP-Message = 0x020b00251900170303001a8c46983303f6f5052f75f8c24f8c2830b62c9232dd5ca34fbf18 State = 0x3c98a70a3593bea1f795a66daa110d86 Message-Authenticator = 0x0a34052605c5c33ebd93eb14d44f4c81 Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) Thu Jan 18 10:08:43 2018 : Info: ? Evaluating (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP packet type response id 11 length 37 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Continuing tunnel setup. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = ok Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authenticate { Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request found, released from the list Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP/peap Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] processing type peap Thu Jan 18 10:08:43 2018 : Info: [peap] processing EAP-TLS Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_verify returned 7 Thu Jan 18 10:08:43 2018 : Info: [peap] Done initial handshake Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_process returned 7 Thu Jan 18 10:08:43 2018 : Info: [peap] EAPTLS_OK Thu Jan 18 10:08:43 2018 : Info: [peap] Session established. Decoding tunneled attributes. Thu Jan 18 10:08:43 2018 : Info: [peap] Peap state phase2 Thu Jan 18 10:08:43 2018 : Info: [peap] EAP type mschapv2 Thu Jan 18 10:08:43 2018 : Info: [peap] Got tunneled request EAP-Message = 0x020b00061a03 server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: [peap] Setting User-Name to rtmobilnetz@rtmobil Sending tunneled request EAP-Message = 0x020b00061a03 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "rtmobilnetz@rtmobil" State = 0x452f0496000001370001020081d9c584000000000000000000000000000000100d436aed Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" server inner-wlan-peap { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-wlan-peap Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [suffix] Looking up realm "rtmobil" for User-Name = "rtmobilnetz@rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Found realm "rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Adding Realm = "rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Proxying request from user rtmobilnetz to realm rtmobil Thu Jan 18 10:08:43 2018 : Info: [suffix] Preparing to proxy authentication request to realm "rtmobil" Thu Jan 18 10:08:43 2018 : Info: ++[suffix] = updated Thu Jan 18 10:08:43 2018 : Info: ++[mschap] = noop Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request is supposed to be proxied to Realm rtmobil. Not doing EAP. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = noop Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{Stripped-User-Name} -> Thu Jan 18 10:08:43 2018 : Info: [sql] ... expanding second conditional Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{User-Name} -> rtmobilnetz@rtmobil Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{%{User-Name}:-DEFAULT} -> rtmobilnetz@rtmobil Thu Jan 18 10:08:43 2018 : Info: [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> rtmobilnetz@rtmobil Thu Jan 18 10:08:43 2018 : Info: [sql] sql_set_user escaped user --> 'rtmobilnetz@rtmobil' Thu Jan 18 10:08:43 2018 : Debug: rlm_sql (sql): Reserving sql socket id: 6 Thu Jan 18 10:08:43 2018 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'rtmobilnetz@rtmobil' ORDER BY id Thu Jan 18 10:08:43 2018 : Debug: rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'rtmobilnetz@rtmobil' ORDER BY id Thu Jan 18 10:08:43 2018 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'rtmobilnetz@rtmobil' ORDER BY priority Thu Jan 18 10:08:43 2018 : Debug: rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = 'rtmobilnetz@rtmobil' ORDER BY priority Thu Jan 18 10:08:43 2018 : Debug: rlm_sql (sql): Released sql socket id: 6 Thu Jan 18 10:08:43 2018 : Info: [sql] User rtmobilnetz@rtmobil not found Thu Jan 18 10:08:43 2018 : Info: ++[sql] = notfound Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:NT-Password}" == "") Thu Jan 18 10:08:43 2018 : Info: expand: %{check:NT-Password} -> Thu Jan 18 10:08:43 2018 : Info: ? Evaluating ("%{check:NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++if ("%{check:NT-Password}" == "") { Thu Jan 18 10:08:43 2018 : Info: +++[noop] = noop Thu Jan 18 10:08:43 2018 : Info: ++} # if ("%{check:NT-Password}" == "") = noop Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:wlan-NT-Password}" == "") Thu Jan 18 10:08:43 2018 : Info: expand: %{check:wlan-NT-Password} -> Thu Jan 18 10:08:43 2018 : Info: ? Evaluating ("%{check:wlan-NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:wlan-NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++if ("%{check:wlan-NT-Password}" == "") { Thu Jan 18 10:08:43 2018 : Info: +++update config { Thu Jan 18 10:08:43 2018 : Info: +++} # update config = noop Thu Jan 18 10:08:43 2018 : Info: ++} # if ("%{check:wlan-NT-Password}" == "") = noop Thu Jan 18 10:08:43 2018 : Info: ++ ... skipping else for request 10: Preceding "if" was taken Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:NT-Password}" == "") Thu Jan 18 10:08:43 2018 : Info: expand: %{check:NT-Password} -> Thu Jan 18 10:08:43 2018 : Info: ? Evaluating ("%{check:NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++? if ("%{check:NT-Password}" == "") -> TRUE Thu Jan 18 10:08:43 2018 : Info: ++if ("%{check:NT-Password}" == "") { Thu Jan 18 10:08:43 2018 : Info: +++[noop] = noop Thu Jan 18 10:08:43 2018 : Info: ++} # if ("%{check:NT-Password}" == "") = noop Thu Jan 18 10:08:43 2018 : Info: ++[expiration] = noop Thu Jan 18 10:08:43 2018 : Info: ++[logintime] = noop Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = updated } # server inner-wlan-peap Thu Jan 18 10:08:43 2018 : Info: [peap] Got tunneled reply code 0 Thu Jan 18 10:08:43 2018 : Debug: PEAP: Tunneled authentication will be proxied to rtmobil Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Tunneled session will be proxied. Not doing EAP. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = handled Thu Jan 18 10:08:43 2018 : Info: +} # group authenticate = handled Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Thu Jan 18 10:08:43 2018 : Info: WARNING: Empty pre-proxy section. Using default return values. Sending Access-Request of id 38 to 129.217.197.132 port 1812 EAP-Message = 0x020b00061a03 User-Name = "rtmobilnetz@rtmobil" State = 0x452f0496000001370001020081d9c584000000000000000000000000000000100d436aed Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x3636 Thu Jan 18 10:08:43 2018 : Info: Proxying request 10 to home server 129.217.197.132 port 1812 Sending Access-Request of id 38 to 129.217.197.132 port 1812 EAP-Message = 0x020b00061a03 User-Name = "rtmobilnetz@rtmobil" State = 0x452f0496000001370001020081d9c584000000000000000000000000000000100d436aed Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x3636 Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 0.9 seconds. rad_recv: Access-Accept packet from host 129.217.197.132 port 1812, id=38, length=280 Proxy-State = 0x3636 Framed-Protocol = PPP Service-Type = Framed-User EAP-Message = 0x030b0004 Class = 0x897b06ee000001370001020081d9c58400000000000000000000000001d38f9bbe093fef000000000000001c MS-Link-Utilization-Threshold = 50 MS-Link-Drop-Time-Limit = 120 MS-CHAP-Domain = "\001RETINA" HERE 3420 HERE 3448 HERE 3467 MS-MPPE-Send-Key = 0xf344120d1add5d94421ab104cb34ed37 HERE 3420 HERE 3448 HERE 3467 MS-MPPE-Recv-Key = 0xf21c3293252983303b6cbcf1bcbb3333 MS-CHAP2-Success = 0x01533d34434246433531333243453236433136363037353236333245394632363041453232383536433233 Message-Authenticator = 0x6cd828d98d8401d1f6f09b67e94c212a Thu Jan 18 10:08:43 2018 : Info: # Executing section post-proxy from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group post-proxy { Thu Jan 18 10:08:43 2018 : Info: [post_proxy_log] expand: %{Packet-Src-IP-Address} -> 129.217.251.242 Thu Jan 18 10:08:43 2018 : Info: [post_proxy_log] expand: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/129.217.251.242/post-proxy-detail-20180118 Thu Jan 18 10:08:43 2018 : Info: [post_proxy_log] /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/129.217.251.242/post-proxy-detail-20180118 Thu Jan 18 10:08:43 2018 : Info: [post_proxy_log] expand: %t -> Thu Jan 18 10:08:43 2018 Thu Jan 18 10:08:43 2018 : Info: ++[post_proxy_log] = ok Thu Jan 18 10:08:43 2018 : Info: [attr_filter.post-proxy] expand: %{Realm} -> rtmobil Thu Jan 18 10:08:43 2018 : Debug: attr_filter: Matched entry rtmobil at line 17 Thu Jan 18 10:08:43 2018 : Debug: attr_filter: Matched entry DEFAULT at line 32 Thu Jan 18 10:08:43 2018 : Info: ++[attr_filter.post-proxy] = updated Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Doing post-proxy callback Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Passing reply from proxy back into the tunnel. Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Got tunneled reply RADIUS code Access-Accept Tunnel-Private-Group-Id:0 := "26" Tunnel-Type:0 := VLAN Tunnel-Medium-Type:0 := IEEE-802 Proxy-State = 0x3636 EAP-Message = 0x030b0004 MS-MPPE-Send-Key = 0xf344120d1add5d94421ab104cb34ed37 MS-MPPE-Recv-Key = 0xf21c3293252983303b6cbcf1bcbb3333 Message-Authenticator = 0x6cd828d98d8401d1f6f09b67e94c212a Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Tunneled authentication was successful. Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] SUCCESS Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Saving tunneled attributes for later Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Reply was handled Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group post-proxy = updated Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = Accept Thu Jan 18 10:08:43 2018 : Error: Warning: Found 2 auth-types on request for user 'rtmobilnetz@rtmobil' Thu Jan 18 10:08:43 2018 : Info: Auth-Type = Accept, accepting the user Thu Jan 18 10:08:43 2018 : Auth: Login OK: [rtmobilnetz@rtmobil] (from client wlc-management-wism2 port 1 cli 3c-15-c2-e8-40-fe) Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Sending Access-Challenge of id 66 to 129.217.251.242 port 32775 EAP-Message = 0x010c002e190017030300238ba36faaaa8eca1dad5d8436c834ed3299018005160165f2c94c81630e317746ffb3ba Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3c98a70a3694bea1f795a66daa110d86 Thu Jan 18 10:08:43 2018 : Info: Finished request 10. Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 129.217.251.242 port 32775, id=67, length=344 User-Name = "rtmobilnetz@rtmobil" Chargeable-User-Identity = "" Location-Capable = Civix-Location Calling-Station-Id = "3c-15-c2-e8-40-fe" Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" NAS-Port = 1 Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" NAS-IP-Address = 129.217.251.242 NAS-Identifier = "wlc-staging" Airespace-Wlan-Id = 8 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3503" EAP-Message = 0x020c002e190017030300238c46983303f6f506ab3dd0d6867c3d0ffde22aafd4280172673cad608beb456f10cfec State = 0x3c98a70a3694bea1f795a66daa110d86 Message-Authenticator = 0x1c46e2485d06f42b5c938da00d7b1ba6 Thu Jan 18 10:08:43 2018 : Info: server itmc-wlan { Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) Thu Jan 18 10:08:43 2018 : Info: ? Evaluating (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++? if (NAS-IP-Address =~ /^129\.217\.142\./) -> FALSE Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP packet type response id 12 length 46 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Continuing tunnel setup. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = ok Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authenticate { Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request found, released from the list Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP/peap Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] processing type peap Thu Jan 18 10:08:43 2018 : Info: [peap] processing EAP-TLS Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_verify returned 7 Thu Jan 18 10:08:43 2018 : Info: [peap] Done initial handshake Thu Jan 18 10:08:43 2018 : Info: [peap] eaptls_process returned 7 Thu Jan 18 10:08:43 2018 : Info: [peap] EAPTLS_OK Thu Jan 18 10:08:43 2018 : Info: [peap] Session established. Decoding tunneled attributes. Thu Jan 18 10:08:43 2018 : Info: [peap] Peap state send tlv success Thu Jan 18 10:08:43 2018 : Info: [peap] Received EAP-TLV response. Thu Jan 18 10:08:43 2018 : Info: [peap] Success Thu Jan 18 10:08:43 2018 : Info: [peap] Using saved attributes from the original Access-Accept Tunnel-Private-Group-Id:0 := "26" Tunnel-Type:0 := VLAN Tunnel-Medium-Type:0 := IEEE-802 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Freeing handler Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group authenticate = ok Thu Jan 18 10:08:43 2018 : Auth: Login OK: [rtmobilnetz@rtmobil] (from client wlc-management-wism2 port 1 cli 3c-15-c2-e8-40-fe) Thu Jan 18 10:08:43 2018 : Info: } # server itmc-wlan Thu Jan 18 10:08:43 2018 : Info: # Executing section post-auth from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group post-auth { Thu Jan 18 10:08:43 2018 : Info: ++[exec] = noop Thu Jan 18 10:08:43 2018 : Info: +} # group post-auth = noop Sending Access-Accept of id 67 to 129.217.251.242 port 32775 Tunnel-Private-Group-Id:0 := "26" Tunnel-Type:0 := VLAN Tunnel-Medium-Type:0 := IEEE-802 MS-MPPE-Recv-Key = 0x4dbed983678cb8daa6ebbfc2a2352532b17775a289d0a5c98f6d7da9a7d23377 MS-MPPE-Send-Key = 0xf11ab516c6bf4d3d56f94a5323906a542b8a6784efb7b8e60e04626844b0b0e3 EAP-Message = 0x030c0004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "rtmobilnetz@rtmobil" Thu Jan 18 10:08:43 2018 : Info: Finished request 11. Thu Jan 18 10:08:43 2018 : Debug: Going to the next request Thu Jan 18 10:08:43 2018 : Debug: Waking up in 4.8 seconds. Thu Jan 18 10:08:48 2018 : Info: Cleaning up request 0 ID 56 with timestamp +81 Thu Jan 18 10:08:48 2018 : Info: Cleaning up request 1 ID 57 with timestamp +81 Thu Jan 18 10:08:48 2018 : Info: Cleaning up request 2 ID 58 with timestamp +81 Thu Jan 18 10:08:48 2018 : Info: Cleaning up request 3 ID 59 with timestamp +81 Thu Jan 18 10:08:48 2018 : Info: Cleaning up request 4 ID 60 with timestamp +81 Thu Jan 18 10:08:48 2018 : Info: Cleaning up request 5 ID 61 with timestamp +81 Thu Jan 18 10:08:48 2018 : Info: Cleaning up request 6 ID 62 with timestamp +81 Thu Jan 18 10:08:48 2018 : Info: Cleaning up request 7 ID 63 with timestamp +81 Thu Jan 18 10:08:48 2018 : Info: Cleaning up request 8 ID 64 with timestamp +81 Thu Jan 18 10:08:48 2018 : Info: Cleaning up request 9 ID 65 with timestamp +81 Thu Jan 18 10:08:48 2018 : Info: Cleaning up request 10 ID 66 with timestamp +81 Thu Jan 18 10:08:48 2018 : Info: Cleaning up request 11 ID 67 with timestamp +81 Thu Jan 18 10:08:48 2018 : Info: Ready to process requests. ---------------------- Proxy config ... realm rtmobil { nostrip auth_pool = rtmobil_pool } ########## rtmobil ########## home_server rtmobil { type = auth ipaddr = 129.217.197.132 secret = ZGel#Ex3Stx port = 1812 response_window = 20 } home_server_pool rtmobil_pool { home_server = rtmobil } .... -----Ursprüngliche Nachricht----- Von: Freeradius-Users [mailto:freeradius-users-bounces+hans.bornemann=tu-dortmund.de@lists.freeradius.org] Im Auftrag von Alan DeKok Gesendet: Dienstag, 23. Januar 2018 13:55 An: FreeRadius users mailing list Betreff: Re: Proxy problem when switching from version2 to version3 On Jan 23, 2018, at 3:48 AM, Bornemann, Hans <hans.bornemann@tu-dortmund.de> wrote:
when switching to version 3 I have a little problem to find my misconfiguration.
the home server says: access rejected because the freeradius sends:
From wireshark on home server:
There *is* a debug log on the proxy which can give you more information. Why not post the debug output, as suggested in the documentation, FAQ, web site, "man" page, and daily on this list? i.e. following the documentation is better than look at random third-party tools. Also, FreeRADIUS doesn't *originate* EAP packets. It just proxies them. So if EAP is different, it's because the EAP client (i.e. laptop / desktop) is behaving differently.
Where do I have to look in the configuration?
Read the documentation. Follow the instructions for debugging problems. Ask *good* questions. If you have no idea what's going wrong, describe what's happening. In detail. Don't assume it's one thing, and then ask how to fix that... Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html Wichtiger Hinweis: Die Information in dieser E-Mail ist vertraulich. Sie ist ausschließlich für den Adressaten bestimmt. Sollten Sie nicht der für diese E-Mail bestimmte Adressat sein, unterrichten Sie bitte den Absender und vernichten Sie diese Mail. Vielen Dank. Unbeschadet der Korrespondenz per E-Mail, sind unsere Erklärungen ausschließlich final rechtsverbindlich, wenn sie in herkömmlicher Schriftform (mit eigenhändiger Unterschrift) oder durch Übermittlung eines solchen Schriftstücks per Telefax erfolgen. Important note: The information included in this e-mail is confidential. It is solely intended for the recipient. If you are not the intended recipient of this e-mail please contact the sender and delete this message. Thank you. Without prejudice of e-mail correspondence, our statements are only legally binding when they are made in the conventional written form (with personal signature) or when such documents are sent by fax.
On Jan 23, 2018, at 8:13 AM, Bornemann, Hans <hans.bornemann@tu-dortmund.de> wrote:
if you like, take a look to the debug output.
first the failing proxy with version 3, then successful with version 2, proxy conf.
anything more needed?
PLEASE FOLLOW THE DOCUMENTATION. Honestly... everything says to use "freeradius -X". Can you explain why people keep using "-xxx"? Just... don't.
... Thu Jan 18 10:22:38 2018 : Debug: (1) eapoldca: Request is supposed to be proxied to Realm rtmobil. Not doing EAP.
That's telling.
Thu Jan 18 10:22:38 2018 : Debug: (1) Proxying request to home server 129.217.197.132 port 1812 timeout 20.000000 ... Thu Jan 18 10:22:38 2018 : Debug: (1) Sent Access-Request Id 189 from 0.0.0.0:48124 to 129.217.197.132:1812 length 336 Thu Jan 18 10:22:38 2018 : Debug: (1) User-Name = "rtmobilnetz@rtmobil" Thu Jan 18 10:22:38 2018 : Debug: (1) Chargeable-User-Identity = 0x00 Thu Jan 18 10:22:38 2018 : Debug: (1) Location-Capable = Civic-Location Thu Jan 18 10:22:38 2018 : Debug: (1) Calling-Station-Id = "3c-15-c2-e8-40-fe" Thu Jan 18 10:22:38 2018 : Debug: (1) Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-Port = 1 Thu Jan 18 10:22:38 2018 : Debug: (1) Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Thu Jan 18 10:22:38 2018 : Debug: (1) Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-IP-Address = 129.217.251.242 Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-Identifier = "wlc-staging" Thu Jan 18 10:22:38 2018 : Debug: (1) Airespace-Wlan-Id = 8 Thu Jan 18 10:22:38 2018 : Debug: (1) Service-Type = Framed-User Thu Jan 18 10:22:38 2018 : Debug: (1) Framed-MTU = 1300 Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-Port-Type = Wireless-802.11 Thu Jan 18 10:22:38 2018 : Debug: (1) Tunnel-Type:0 = VLAN Thu Jan 18 10:22:38 2018 : Debug: (1) Tunnel-Medium-Type:0 = IEEE-802 Thu Jan 18 10:22:38 2018 : Debug: (1) Tunnel-Private-Group-Id:0 = "3503" Thu Jan 18 10:22:38 2018 : Debug: (1) EAP-Message = 0x020200080319152b
That isn't an EAP NAK. It's just an empty PEAP ACK.
Thu Jan 18 10:22:38 2018 : Debug: (1) State = 0x45300497000001370001020081d9c584000000000000000000000000000000100d436aee Thu Jan 18 10:22:38 2018 : Debug: (1) Message-Authenticator = 0x31a7b8a02c1f45acee5e637c48d8f20d Thu Jan 18 10:22:38 2018 : Debug: (1) Event-Timestamp = "Jan 18 2018 10:22:38 CET" Thu Jan 18 10:22:38 2018 : Debug: (1) Proxy-State = 0x3639 Thu Jan 18 10:22:38 2018 : Debug: Waking up in 0.3 seconds. Thu Jan 18 10:22:38 2018 : Debug: (1) Clearing existing &reply: attributes Thu Jan 18 10:22:38 2018 : Debug: (1) Received Access-Reject Id 189 from 129.217.197.132:1812 to 129.217.131.207:48124 length 48
Well, the home server is rejecting the packet. There isn't much you can do to FreeRADIUS to fix that.
Debug freeradius 2 - proxy to home server - ok ... Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP packet type response id 2 length 161 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Continuing tunnel setup. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = ok Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authenticate { Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request found, released from the list Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP/peap Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] processing type peap Thu Jan 18 10:08:43 2018 : Info: [peap] processing EAP-TLS
Uh... you do realize that v2 isn't proxying the packets, right? It's doing PEAP itself. i.e. the two systems are configured to do different things. Which sort of explains why they're behaving differently.
Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-wlan-peap Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [suffix] Looking up realm "rtmobil" for User-Name = "rtmobilnetz@rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Found realm "rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Adding Realm = "rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Proxying request from user rtmobilnetz to realm rtmobil Thu Jan 18 10:08:43 2018 : Info: [suffix] Preparing to proxy authentication request to realm "rtmobil"
In v2, you're proxying the *inner* authentication data to the home server. In v3, you're proxying the *outer* data. i.e. all of PEAP. This would have been a WHOLE lot easier to see without the utterly useless extra debugging.
Proxy config
Which was never asked for. So.. you've configured the systems to do two different things. As a result, they behave differently. If you want to make v3 behave like v2, you have to configure v3 with the same / similar configuration as v2. This means understanding what the v2 system does, and why. And then making v3 do the same thing. Alan DeKok.
Hi, thank you very much. This hint was very useful. Regards -----Ursprüngliche Nachricht----- Von: Freeradius-Users [mailto:freeradius-users-bounces+hans.bornemann=tu-dortmund.de@lists.freeradius.org] Im Auftrag von Alan DeKok Gesendet: Dienstag, 23. Januar 2018 14:27 An: FreeRadius users mailing list Betreff: Re: Proxy problem when switching from version2 to version3 On Jan 23, 2018, at 8:13 AM, Bornemann, Hans <hans.bornemann@tu-dortmund.de> wrote:
if you like, take a look to the debug output.
first the failing proxy with version 3, then successful with version 2, proxy conf.
anything more needed?
PLEASE FOLLOW THE DOCUMENTATION. Honestly... everything says to use "freeradius -X". Can you explain why people keep using "-xxx"? Just... don't.
... Thu Jan 18 10:22:38 2018 : Debug: (1) eapoldca: Request is supposed to be proxied to Realm rtmobil. Not doing EAP.
That's telling.
Thu Jan 18 10:22:38 2018 : Debug: (1) Proxying request to home server 129.217.197.132 port 1812 timeout 20.000000 ... Thu Jan 18 10:22:38 2018 : Debug: (1) Sent Access-Request Id 189 from 0.0.0.0:48124 to 129.217.197.132:1812 length 336 Thu Jan 18 10:22:38 2018 : Debug: (1) User-Name = "rtmobilnetz@rtmobil" Thu Jan 18 10:22:38 2018 : Debug: (1) Chargeable-User-Identity = 0x00 Thu Jan 18 10:22:38 2018 : Debug: (1) Location-Capable = Civic-Location Thu Jan 18 10:22:38 2018 : Debug: (1) Calling-Station-Id = "3c-15-c2-e8-40-fe" Thu Jan 18 10:22:38 2018 : Debug: (1) Called-Station-Id = "6c-b2-ae-30-36-c0:ITMC-WPA2-STAGING" Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-Port = 1 Thu Jan 18 10:22:38 2018 : Debug: (1) Cisco-AVPair = "audit-session-id=81d9fbf2000000b85a60641b" Thu Jan 18 10:22:38 2018 : Debug: (1) Acct-Session-Id = "5a60641b/3c:15:c2:e8:40:fe/307" Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-IP-Address = 129.217.251.242 Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-Identifier = "wlc-staging" Thu Jan 18 10:22:38 2018 : Debug: (1) Airespace-Wlan-Id = 8 Thu Jan 18 10:22:38 2018 : Debug: (1) Service-Type = Framed-User Thu Jan 18 10:22:38 2018 : Debug: (1) Framed-MTU = 1300 Thu Jan 18 10:22:38 2018 : Debug: (1) NAS-Port-Type = Wireless-802.11 Thu Jan 18 10:22:38 2018 : Debug: (1) Tunnel-Type:0 = VLAN Thu Jan 18 10:22:38 2018 : Debug: (1) Tunnel-Medium-Type:0 = IEEE-802 Thu Jan 18 10:22:38 2018 : Debug: (1) Tunnel-Private-Group-Id:0 = "3503" Thu Jan 18 10:22:38 2018 : Debug: (1) EAP-Message = 0x020200080319152b
That isn't an EAP NAK. It's just an empty PEAP ACK.
Thu Jan 18 10:22:38 2018 : Debug: (1) State = 0x45300497000001370001020081d9c584000000000000000000000000000000100d436aee Thu Jan 18 10:22:38 2018 : Debug: (1) Message-Authenticator = 0x31a7b8a02c1f45acee5e637c48d8f20d Thu Jan 18 10:22:38 2018 : Debug: (1) Event-Timestamp = "Jan 18 2018 10:22:38 CET" Thu Jan 18 10:22:38 2018 : Debug: (1) Proxy-State = 0x3639 Thu Jan 18 10:22:38 2018 : Debug: Waking up in 0.3 seconds. Thu Jan 18 10:22:38 2018 : Debug: (1) Clearing existing &reply: attributes Thu Jan 18 10:22:38 2018 : Debug: (1) Received Access-Reject Id 189 from 129.217.197.132:1812 to 129.217.131.207:48124 length 48
Well, the home server is rejecting the packet. There isn't much you can do to FreeRADIUS to fix that.
Debug freeradius 2 - proxy to home server - ok ... Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP packet type response id 2 length 161 Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Continuing tunnel setup. Thu Jan 18 10:08:43 2018 : Info: ++[eap_wlan] = ok Thu Jan 18 10:08:43 2018 : Info: +} # group authorize = ok Thu Jan 18 10:08:43 2018 : Info: Found Auth-Type = eap_wlan Thu Jan 18 10:08:43 2018 : Info: # Executing group from file /etc/freeradius/sites-enabled/itmc-wlan Thu Jan 18 10:08:43 2018 : Info: +group authenticate { Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] Request found, released from the list Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] EAP/peap Thu Jan 18 10:08:43 2018 : Info: [eap_wlan] processing type peap Thu Jan 18 10:08:43 2018 : Info: [peap] processing EAP-TLS
Uh... you do realize that v2 isn't proxying the packets, right? It's doing PEAP itself. i.e. the two systems are configured to do different things. Which sort of explains why they're behaving differently.
Thu Jan 18 10:08:43 2018 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-wlan-peap Thu Jan 18 10:08:43 2018 : Info: +group authorize { Thu Jan 18 10:08:43 2018 : Info: ++[preprocess] = ok Thu Jan 18 10:08:43 2018 : Info: [suffix] Looking up realm "rtmobil" for User-Name = "rtmobilnetz@rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Found realm "rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Adding Realm = "rtmobil" Thu Jan 18 10:08:43 2018 : Info: [suffix] Proxying request from user rtmobilnetz to realm rtmobil Thu Jan 18 10:08:43 2018 : Info: [suffix] Preparing to proxy authentication request to realm "rtmobil"
In v2, you're proxying the *inner* authentication data to the home server. In v3, you're proxying the *outer* data. i.e. all of PEAP. This would have been a WHOLE lot easier to see without the utterly useless extra debugging.
Proxy config
Which was never asked for. So.. you've configured the systems to do two different things. As a result, they behave differently. If you want to make v3 behave like v2, you have to configure v3 with the same / similar configuration as v2. This means understanding what the v2 system does, and why. And then making v3 do the same thing. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html Wichtiger Hinweis: Die Information in dieser E-Mail ist vertraulich. Sie ist ausschließlich für den Adressaten bestimmt. Sollten Sie nicht der für diese E-Mail bestimmte Adressat sein, unterrichten Sie bitte den Absender und vernichten Sie diese Mail. Vielen Dank. Unbeschadet der Korrespondenz per E-Mail, sind unsere Erklärungen ausschließlich final rechtsverbindlich, wenn sie in herkömmlicher Schriftform (mit eigenhändiger Unterschrift) oder durch Übermittlung eines solchen Schriftstücks per Telefax erfolgen. Important note: The information included in this e-mail is confidential. It is solely intended for the recipient. If you are not the intended recipient of this e-mail please contact the sender and delete this message. Thank you. Without prejudice of e-mail correspondence, our statements are only legally binding when they are made in the conventional written form (with personal signature) or when such documents are sent by fax.
participants (2)
-
Alan DeKok -
Bornemann, Hans