The users session was previously rejected
Hi, I fairly new at Freeradius and I have been upgrading our version 2 servers to version 3.0.10 and I have what I believe is a configuration issue. The user is correctly rejected by eap/MSCHAP but it continues into eap/PEAP where I get the error Sat Oct 31 09:08:24 2015 : Info: (11) eap_peap: The users session was previously rejected: returning reject (again.) Sat Oct 31 09:08:24 2015 : Info: (11) eap_peap: This means you need to read the PREVIOUS messages in the debug output Sat Oct 31 09:08:24 2015 : Info: (11) eap_peap: to find out the reason why the user was rejected Sat Oct 31 09:08:24 2015 : Info: (11) eap_peap: Look for "reject" or "fail". Those earlier messages will tell you Sat Oct 31 09:08:24 2015 : Info: (11) eap_peap: what went wrong, and how to fix the problem How do I avoid dropping into the peap section if the user is rejected further up the chain? I've attached the portion of the debug log that shows this error. Many thanks Tim
On Oct 31, 2015, at 5:40 AM, Pretlove, Tim <T.Pretlove@liverpool.ac.uk> wrote:
I fairly new at Freeradius and I have been upgrading our version 2 servers to version 3.0.10 and I have what I believe is a configuration issue.
The user is correctly rejected by eap/MSCHAP but it continues into eap/PEAP where I get the error
Sat Oct 31 09:08:24 2015 : Info: (11) eap_peap: The users session was previously rejected: returning reject (again.)
Those messages say "Info". Not "Error".
How do I avoid dropping into the peap section if the user is rejected further up the chain?
You don't. It's doing PEAP as expected. The message is there for people who read only the last few lines of the debug output. It tells them to read the PREVIOUS messages to see the error. Alan DeKok.
Hi Alan, On Sat, 31 Oct 2015, Alan DeKok wrote:
On Oct 31, 2015, at 5:40 AM, Pretlove, Tim <T.Pretlove@liverpool.ac.uk> wrote:
I fairly new at Freeradius and I have been upgrading our version 2 servers to version 3.0.10 and I have what I believe is a configuration issue.
The user is correctly rejected by eap/MSCHAP but it continues into eap/PEAP where I get the error
Sat Oct 31 09:08:24 2015 : Info: (11) eap_peap: The users session was previously rejected: returning reject (again.)
Those messages say "Info". Not "Error".
The Error message is ERROR: (11) eap: Failed continuing EAP PEAP (25) session. EAP sub-module failed. and in Debug I also see Debug: (11) eap: Sending EAP Failure (code 4) ID 11 length 4 Debug: (11) eap: Failed in EAP select
How do I avoid dropping into the peap section if the user is rejected further up the chain?
You don't. It's doing PEAP as expected.
Okay that's fine
The message is there for people who read only the last few lines of the debug output. It tells them to read the PREVIOUS messages to see the error.
I see this appearing in the log file without debug enabled.
Alan DeKok.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Thanks Tim Pretlove Computing Services University of Liverpool Brownlow Hill
On 31 Oct 2015, at 13:14, Tim Pretlove <T.Pretlove@liverpool.ac.uk> wrote:
Hi Alan,
On Sat, 31 Oct 2015, Alan DeKok wrote:
On Oct 31, 2015, at 5:40 AM, Pretlove, Tim <T.Pretlove@liverpool.ac.uk> wrote:
I fairly new at Freeradius and I have been upgrading our version 2 servers to version 3.0.10 and I have what I believe is a configuration issue. The user is correctly rejected by eap/MSCHAP but it continues into eap/PEAP where I get the error Sat Oct 31 09:08:24 2015 : Info: (11) eap_peap: The users session was previously rejected: returning reject (again.)
Those messages say "Info". Not "Error".
The Error message is
ERROR: (11) eap: Failed continuing EAP PEAP (25) session. EAP sub-module failed.
Nope, above that. Copy all the red things (if logging to stdout) :) -Arran Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS development team FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
Hi Arran, On Sat, 31 Oct 2015, Arran Cudbard-Bell wrote:
On 31 Oct 2015, at 13:14, Tim Pretlove <T.Pretlove@liverpool.ac.uk> wrote:
Hi Alan,
On Sat, 31 Oct 2015, Alan DeKok wrote:
On Oct 31, 2015, at 5:40 AM, Pretlove, Tim <T.Pretlove@liverpool.ac.uk> wrote:
I fairly new at Freeradius and I have been upgrading our version 2 servers to version 3.0.10 and I have what I believe is a configuration issue. The user is correctly rejected by eap/MSCHAP but it continues into eap/PEAP where I get the error Sat Oct 31 09:08:24 2015 : Info: (11) eap_peap: The users session was previously rejected: returning reject (again.)
Those messages say "Info". Not "Error".
The Error message is
ERROR: (11) eap: Failed continuing EAP PEAP (25) session. EAP sub-module failed.
Nope, above that. Copy all the red things (if logging to stdout) :)
That is the only error I'm getting plus the info messages. The reject from MSCHAP is correct (log to stdout is a bit of a pain with 2000 connects/min)
-Arran
Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS development team
FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
Regards Tim Pretlove Computing Services University of Liverpool Brownlow Hill Liverpool, L69 3GG
Hi (again) Arran, On Sat, 31 Oct 2015, Tim Pretlove wrote:
Hi Arran,
On Sat, 31 Oct 2015, Arran Cudbard-Bell wrote:
On 31 Oct 2015, at 13:14, Tim Pretlove <T.Pretlove@liverpool.ac.uk> wrote:
Hi Alan,
On Sat, 31 Oct 2015, Alan DeKok wrote:
On Oct 31, 2015, at 5:40 AM, Pretlove, Tim <T.Pretlove@liverpool.ac.uk>
wrote:
I fairly new at Freeradius and I have been upgrading our version 2 servers to version 3.0.10 and I have what I believe is a configuration issue. The user is correctly rejected by eap/MSCHAP but it continues into eap/PEAP where I get the error Sat Oct 31 09:08:24 2015 : Info: (11) eap_peap: The users session was previously rejected: returning reject (again.)
Those messages say "Info". Not "Error".
The Error message is
ERROR: (11) eap: Failed continuing EAP PEAP (25) session. EAP sub-module failed.
Nope, above that. Copy all the red things (if logging to stdout) :)
Is this what you refering to Arran? Sat Oct 31 09:08:24 2015 : Debug: (11) eap_peap: Continuing EAP-TLS Sat Oct 31 09:08:24 2015 : Debug: (11) eap_peap: Peer sent flags --- Sat Oct 31 09:08:24 2015 : Debug: (11) eap_peap: [eaptls verify] = ok Sat Oct 31 09:08:24 2015 : Debug: (11) eap_peap: Done initial handshake Sat Oct 31 09:08:24 2015 : Debug: (11) eap_peap: [eaptls process] = ok Sat Oct 31 09:08:24 2015 : Debug: (11) eap_peap: Session established. Decoding tunneled attributes Sat Oct 31 09:08:24 2015 : Debug: (11) eap_peap: PEAP state send tlv failure Sat Oct 31 09:08:24 2015 : Debug: (11) eap_peap: Received EAP-TLV response
That is the only error I'm getting plus the info messages. The reject from MSCHAP is correct (log to stdout is a bit of a pain with 2000 connects/min)
-Arran
Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS development team
FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
Regards
Tim Pretlove Computing Services University of Liverpool Brownlow Hill Liverpool, L69 3GG - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Tim Pretlove Computing Services University of Liverpool Brownlow Hill Liverpool, L69 3GG Email: pretlove@liverpool.ac.uk Phone: 0151-794-4479
Hi Alan, Is this what you want to see? Debug: <running>: Received Access-Request Id 11 from 138.253.100.106:43157 to 138.253.100.213:1812 length 211 Debug: <running>: User-Name = "@liv.ac.uk" Debug: <running>: NAS-IP-Address = 127.0.0.1 Debug: <running>: Calling-Station-Id = "02-00-00-00-00-01" Debug: <running>: Framed-MTU = 1400 Debug: <running>: NAS-Port-Type = Wireless-802.11 Debug: <running>: Connect-Info = "CONNECT 11Mbps 802.11b" Debug: <running>: EAP-Message = 0x020b005019001703010020f695d007ae23cdf71cae1d9399914a8fa32ab903ae990463ed0d593b6e9074e317030100209c394163311b9e013ad36d6830e3429c4c1ce402d31eb1256480213810d4ba11 Debug: <running>: State = 0xcc743382c67f2a3839968af4b7f3717b Debug: <running>: Message-Authenticator = 0x7502c284b61413840659458cb9481582 Debug: <running>: session-state: No cached attributes Debug: <running>: # Executing section authorize from file /usr/local/freeradius-3.0.10/etc/raddb/sites-enabled/eduroam Debug: <running>: authorize { Debug: <running>: if (User-Name =~ /@$/){ Debug: <running>: if (User-Name =~ /@$/) -> FALSE Debug: <running>: if (User-Name =~ /@.+?@/){ Debug: <running>: if (User-Name =~ /@.+?@/) -> FALSE Debug: <running>: if (User-Name =~ /@.+?[^[:alnum:]\\.-]/){ Debug: <running>: if (User-Name =~ /@.+?[^[:alnum:]\\.-]/) -> FALSE Debug: <running>: if (User-Name =~ /@[\\.-]/){ Debug: <running>: if (User-Name =~ /@[\\.-]/) -> FALSE Debug: <running>: if (User-Name =~ /@.+?[\\.-]$/){ Debug: <running>: if (User-Name =~ /@.+?[\\.-]$/) -> FALSE Debug: <running>: if (User-Name =~ /@[^\\.]+$/){ Debug: <running>: if (User-Name =~ /@[^\\.]+$/) -> FALSE Debug: <running>: if (User-Name =~ /@.+?\\.\\./){ Debug: <running>: if (User-Name =~ /@.+?\\.\\./) -> FALSE Debug: <running>: if (User-Name =~ /@myabc\\.com$/i){ Debug: <running>: if (User-Name =~ /@myabc\\.com$/i) -> FALSE Debug: <running>: if (User-Name =~ /@wlan\\.[[:alnum:]]+\\.[[:alnum:]]+\\.3gppnetwork\\.org$/i){ Debug: <running>: if (User-Name =~ /@wlan\\.[[:alnum:]]+\\.[[:alnum:]]+\\.3gppnetwork\\.org$/i) -> FALSE Debug: <running>: if (User-Name =~ /@gmail\\.co(m|\\.[[:alnum:]][[:alnum:]])$/i){ Debug: <running>: if (User-Name =~ /@gmail\\.co(m|\\.[[:alnum:]][[:alnum:]])$/i) -> FALSE Debug: <running>: if (User-Name =~ /@yahoo\\.co(m|\\.[[:alnum:]][[:alnum:]])$/i){ Debug: <running>: if (User-Name =~ /@yahoo\\.co(m|\\.[[:alnum:]][[:alnum:]])$/i) -> FALSE Debug: <running>: if (User-Name =~ /@hotmail\\.co(m|\\.[[:alnum:]][[:alnum:]])$/i){ Debug: <running>: if (User-Name =~ /@hotmail\\.co(m|\\.[[:alnum:]][[:alnum:]])$/i) -> FALSE Debug: <running>: if (User-Name =~ /@\\.?ac\\.uk$/i){ Debug: <running>: if (User-Name =~ /@\\.?ac\\.uk$/i) -> FALSE Debug: <running>: if (User-Name =~ /@.+?\\.ax\\.uk$/i){ Debug: <running>: if (User-Name =~ /@.+?\\.ax\\.uk$/i) -> FALSE Debug: <running>: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 9776 Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 9776 Debug: [preprocess] = ok Debug: policy operator-name.authorize { Debug: if ("%{client:Operator-Name}") { Debug: EXPAND TMPL XLAT STRUCT Debug: EXPAND %{client:Operator-Name} Debug: --> 1liv.ac.uk Debug: if ("%{client:Operator-Name}") -> TRUE Debug: if ("%{client:Operator-Name}") { Debug: update request { Debug: EXPAND %{client:Operator-Name} Debug: --> 1liv.ac.uk Debug: &Operator-Name = 1liv.ac.uk Debug: } # update request = noop Debug: } # if ("%{client:Operator-Name}") = noop Debug: } # policy operator-name.authorize = noop Debug: policy cui.authorize { Debug: if ("%{client:add_cui}" == 'yes') { Debug: EXPAND TMPL XLAT STRUCT Debug: EXPAND %{client:add_cui} Debug: --> yes Debug: if ("%{client:add_cui}" == 'yes') -> TRUE Debug: if ("%{client:add_cui}" == 'yes') { Debug: update request { Debug: &Chargeable-User-Identity := 0x00 Debug: } # update request = noop Debug: } # if ("%{client:add_cui}" == 'yes') = noop Debug: } # policy cui.authorize = noop Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 9776 Debug: auth_log: EXPAND /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d Debug: auth_log: --> /var/log/radius/radacct/138.253.100.106/auth-detail-20151101 Debug: auth_log: /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/138.253.100.106/auth-detail-20151101 Debug: auth_log: EXPAND %t Debug: auth_log: --> Sun Nov 1 11:33:39 2015 Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 9776 Debug: [auth_log] = ok Debug: modsingle[authorize]: calling chap (rlm_chap) for request 9776 Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 9776 Debug: [chap] = noop Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 9776 Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 9776 Debug: [mschap] = noop Debug: modsingle[authorize]: calling digest (rlm_digest) for request 9776 Debug: modsingle[authorize]: returned from digest (rlm_digest) for request 9776 Debug: [digest] = noop Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 9776 Debug: suffix: Checking for suffix after "@" Debug: suffix: Looking up realm "liv.ac.uk" for User-Name = "@liv.ac.uk" Debug: suffix: Found realm "liv.ac.uk" Debug: suffix: Adding Stripped-User-Name = "" Debug: suffix: Adding Realm = "liv.ac.uk" Debug: suffix: Authentication realm is LOCAL Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 9776 Debug: [suffix] = ok Debug: modsingle[authorize]: calling eap (rlm_eap) for request 9776 Debug: eap: Peer sent EAP Response (code 2) ID 11 length 80 Debug: eap: Continuing tunnel setup Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 9776 Debug: [eap] = ok Debug: } # authorize = ok Debug: Found Auth-Type = EAP Debug: # Executing group from file /usr/local/freeradius-3.0.10/etc/raddb/sites-enabled/eduroam Debug: authenticate { Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 9776 Debug: eap: Expiring EAP session with state 0x1c8798b11c8582ab Debug: eap: Finished EAP session with state 0xcc743382c67f2a38 Debug: eap: Previous EAP request found for state 0xcc743382c67f2a38, released from the list Debug: eap: Peer sent packet with method EAP PEAP (25) Debug: eap: Calling submodule eap_peap to process data Debug: eap_peap: Continuing EAP-TLS Debug: eap_peap: Peer sent flags --- Debug: eap_peap: [eaptls verify] = ok Debug: eap_peap: Done initial handshake Debug: eap_peap: [eaptls process] = ok Debug: eap_peap: Session established. Decoding tunneled attributes Debug: eap_peap: PEAP state send tlv failure Debug: eap_peap: Received EAP-TLV response ERROR: eap: Failed continuing EAP PEAP (25) session. EAP sub-module failed Debug: eap: Sending EAP Failure (code 4) ID 11 length 4 Debug: eap: Failed in EAP select Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 9776 Debug: [eap] = invalid Debug: } # authenticate = invalid Debug: Failed to authenticate the user Debug: Using Post-Auth-Type Reject Debug: # Executing group from file /usr/local/freeradius-3.0.10/etc/raddb/sites-enabled/eduroam Debug: Post-Auth-Type REJECT { Debug: modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) for request 9776 Debug: attr_filter.access_reject: EXPAND %{User-Name} Debug: attr_filter.access_reject: --> @liv.ac.uk Debug: attr_filter.access_reject: Matched entry DEFAULT at line 11 Debug: attr_filter.access_reject: EAP-Message = 0x040b0004 allowed by EAP-Message =* 0x Debug: attr_filter.access_reject: Attribute "EAP-Message" allowed by 1 rules, disallowed by 0 rules Debug: attr_filter.access_reject: Message-Authenticator = 0x00000000000000000000000000000000 allowed by Message-Authenticator =* 0x Debug: attr_filter.access_reject: Attribute "Message-Authenticator" allowed by 1 rules, disallowed by 0 rules Debug: modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) for request 9776 Debug: [attr_filter.access_reject] = updated Debug: modsingle[post-auth]: calling eap (rlm_eap) for request 9776 Debug: eap: Reply already contained an EAP-Message, not inserting EAP-Failure Debug: modsingle[post-auth]: returned from eap (rlm_eap) for request 9776 Debug: [eap] = noop Debug: policy remove_reply_message_if_eap { Debug: if (&reply:EAP-Message && &reply:Reply-Message) { Debug: if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE Debug: else { Debug: modsingle[post-auth]: calling noop (rlm_always) for request 9776 Debug: modsingle[post-auth]: returned from noop (rlm_always) for request 9776 Debug: [noop] = noop Debug: } # else = noop Debug: } # policy remove_reply_message_if_eap = noop Debug: } # Post-Auth-Type REJECT = updated Debug: Delaying response for 1.000000 seconds Tim Pretlove Computing Services University of Liverpool Brownlow Hill Liverpool, L69 3GG Email: pretlove@liverpool.ac.uk Phone: 0151-794-4479
Use radmin to only do a full debug for a particular client (ie the one that's failing) alan
participants (5)
-
Alan Buxey -
Alan DeKok -
Arran Cudbard-Bell -
Pretlove, Tim -
Tim Pretlove