two questions about migration from FR 2.X to 3.X
Hello. I have two question about migration from oldest to newest version. 1. After migration, the process authorization by MSCHAP-V2 wrote that can't make NT-password: Fri Nov 3 10:27:52 2017 : WARNING: (4) mschap: No Cleartext-Password configured. Cannot create NT-Password Fri Nov 3 10:27:52 2017 : WARNING: (4) mschap: No Cleartext-Password configured. Cannot create LM-Password Fri Nov 3 10:27:52 2017 : Debug: (4) mschap: Client is using MS-CHAPv1 with NT-Password Fri Nov 3 10:27:52 2017 : ERROR: (4) mschap: FAILED: No NT/LM-Password. Cannot perform authentication Fri Nov 3 10:27:52 2017 : ERROR: (4) mschap: MS-CHAP2-Response is incorrect This happened in inner-tunnel site with config: server inner-tunnel { authorize { chap mschap suffix update control { Proxy-To-Realm := LOCAL } eap { ok = return } files expiration logintime pap } authenticate { Auth-Type PAP { pap } Auth-Type CHAP { chap } Auth-Type MS-CHAP { mschap } eap } session { radutmp } post-auth { Post-Auth-Type REJECT { attr_filter.access_reject } } pre-proxy { } post-proxy { eap } } But I have the same config on FR 2.X in it worked. Could tell me why? The second question with another client. I've got the next error message: Thu Nov 2 21:44:19 2017 : ERROR: (159) eap_peap: Failed in __FUNCTION__ (SSL_read): s3_srvr.c[1240]:error:1408A0E3:SSL routines:ssl3_get_client_hello:parse tlsext Thu Nov 2 21:44:19 2017 : ERROR: (159) eap_peap: System call (I/O) error (-1) Thu Nov 2 21:44:19 2017 : ERROR: (159) eap_peap: TLS receive handshake failed during operation Thu Nov 2 21:44:19 2017 : ERROR: (159) eap_peap: [eaptls process] = fail Thu Nov 2 21:44:19 2017 : ERROR: (159) eap: Failed continuing EAP PEAP (25) session. EAP sub-module failed This is printer Canon 5240i and I can't change his software. As well as in the previous question, all work with FR 2.X. -- Best regards, Anton Kiryushkin
On Nov 3, 2017, at 6:39 AM, Anton Kiryushkin <swood@fotofor.biz> wrote:
I have two question about migration from oldest to newest version. 1. After migration, the process authorization by MSCHAP-V2 wrote that can't make NT-password:
The error is saying "No Cleartext-Password". i.e. you didn't tell the server what the users "known good" password is.
This happened in inner-tunnel site with config:
What does the *rest* of the debug output say? Reading that will tell you what's happening.
But I have the same config on FR 2.X in it worked. Could tell me why?
Read the debug output.
The second question with another client. I've got the next error message:
Thu Nov 2 21:44:19 2017 : ERROR: (159) eap_peap: Failed in __FUNCTION__ (SSL_read): s3_srvr.c[1240]:error:1408A0E3:SSL routines:ssl3_get_client_hello:parse tlsext Thu Nov 2 21:44:19 2017 : ERROR: (159) eap_peap: System call (I/O) error (-1)
Weird. It looks like that "tlsext" field is malformed.
Thu Nov 2 21:44:19 2017 : ERROR: (159) eap_peap: TLS receive handshake failed during operation Thu Nov 2 21:44:19 2017 : ERROR: (159) eap_peap: [eaptls process] = fail Thu Nov 2 21:44:19 2017 : ERROR: (159) eap: Failed continuing EAP PEAP (25) session. EAP sub-module failed
This is printer Canon 5240i and I can't change his software. As well as in the previous question, all work with FR 2.X.
Let me guess: you also changed operating systems, and OpenSSL versions at the same time. Older OpenSSL versions were more forgiving of bad data. Newer OpenSSL versions are more strict. This is (unfortunately) an OpenSSL thing. Nothing in FreeRADIUS will cause that error. The short answer is that the client is broken. It doesn't implement PEAP / SSL correctly. Alan DeKok.
Okay, thanks for your answer about the printer. It's bad news for him, but good for me. Returning to the question about a mschap. I have the next debug log: Thu Nov 2 21:43:58 2017 : Debug: (138) Received Access-Request Id 166 from 192.168.1.2:58178 to 192.168.4.3:1812 length 294 Thu Nov 2 21:43:58 2017 : Debug: (138) User-Name = "user" Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-Port = 96 Thu Nov 2 21:43:58 2017 : Debug: (138) State = 0x00729277067a8792b93b4156e0f7d618 Thu Nov 2 21:43:58 2017 : Debug: (138) EAP-Message = 0x020800731500170303006895b8c9fdff2c09f408380c8566150c90227a2acf00e9c0f952828448742f5bbe06780afedd931d703bc924ae15884e0be7bad9e7e815f271fd40879f6dd9fb6c745da9610115e99c44689ecf1eb5e846f0154d6730ac16769a43aa3934be6c2c54b85ca702492f4c Thu Nov 2 21:43:58 2017 : Debug: (138) Message-Authenticator = 0xdf453c3234f42d3628829ce35fb70e79 Thu Nov 2 21:43:58 2017 : Debug: (138) Acct-Session-Id = "8O2.1x818b430100008423" Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-Port-Id = "ge-0/0/13.0" Thu Nov 2 21:43:58 2017 : Debug: (138) Calling-Station-Id = "d0-50-99-2c-ff-00" Thu Nov 2 21:43:58 2017 : Debug: (138) Called-Station-Id = "88-e0-f3-b0-d6-00" Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-IP-Address = 192.168.1.2 Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-Identifier = "sw-" Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-Port-Type = Ethernet Thu Nov 2 21:43:58 2017 : Debug: (138) session-state: No cached attributes Thu Nov 2 21:43:58 2017 : Debug: (138) # Executing section authorize from file /etc/raddb/sites-enabled/default Thu Nov 2 21:43:58 2017 : Debug: (138) authorize { Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling preprocess (rlm_preprocess) Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from preprocess (rlm_preprocess) Thu Nov 2 21:43:58 2017 : Debug: (138) [preprocess] = ok Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling chap (rlm_chap) Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from chap (rlm_chap) Thu Nov 2 21:43:58 2017 : Debug: (138) [chap] = noop Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling mschap (rlm_mschap) Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from mschap (rlm_mschap) Thu Nov 2 21:43:58 2017 : Debug: (138) [mschap] = noop Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling suffix (rlm_realm) Thu Nov 2 21:43:58 2017 : Debug: (138) suffix: Checking for suffix after "@" Thu Nov 2 21:43:58 2017 : Debug: (138) suffix: No '@' in User-Name = "user", looking up realm NULL Thu Nov 2 21:43:58 2017 : Debug: (138) suffix: No such realm "NULL" Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from suffix (rlm_realm) Thu Nov 2 21:43:58 2017 : Debug: (138) [suffix] = noop Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling eap (rlm_eap) Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Peer sent EAP Response (code 2) ID 8 length 115 Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Continuing tunnel setup Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from eap (rlm_eap) Thu Nov 2 21:43:58 2017 : Debug: (138) [eap] = ok Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling sql-wifi (rlm_sql) Thu Nov 2 21:43:58 2017 : Debug: %{User-Name} Thu Nov 2 21:43:58 2017 : Debug: Parsed xlat tree: Thu Nov 2 21:43:58 2017 : Debug: attribute --> User-Name Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: EXPAND %{User-Name} Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: --> user Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: SQL-User-Name set to 'user' Thu Nov 2 21:43:58 2017 : Debug: rlm_sql (sql-wifi): Reserved connection (2) Thu Nov 2 21:43:58 2017 : Debug: SELECT wifi_id as id, username, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE username = '%{SQL-User-Name}' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: Parsed xlat tree: Thu Nov 2 21:43:58 2017 : Debug: literal --> SELECT wifi_id as id, username, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE username = ' Thu Nov 2 21:43:58 2017 : Debug: attribute --> SQL-User-Name Thu Nov 2 21:43:58 2017 : Debug: literal --> ' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: EXPAND SELECT wifi_id as id, username, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE username = '%{SQL-User-Name}' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: --> SELECT wifi_id as id, username, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE username = 'user' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: Executing select query: SELECT wifi_id as id, username, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE username = 'user' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: User found in radcheck table Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: Conditional check items matched, merging assignment check items Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: Cleartext-Password := "password" Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: FROM 1 TO 1 MAX 2 Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: Examining Cleartext-Password Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: APPENDING Cleartext-Password FROM 0 TO 1 Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: TO in 1 out 1 Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: to[0] = Auth-Type Thu Nov 2 21:43:58 2017 : Debug: SELECT id, UserName, Attribute, Value, op FROM wifi_attrs WHERE Username = '%{SQL-User-Name}' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: Parsed xlat tree: Thu Nov 2 21:43:58 2017 : Debug: literal --> SELECT id, UserName, Attribute, Value, op FROM wifi_attrs WHERE Username = ' Thu Nov 2 21:43:58 2017 : Debug: attribute --> SQL-User-Name Thu Nov 2 21:43:58 2017 : Debug: literal --> ' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: EXPAND SELECT id, UserName, Attribute, Value, op FROM wifi_attrs WHERE Username = '%{SQL-User-Name}' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: --> SELECT id, UserName, Attribute, Value, op FROM wifi_attrs WHERE Username = 'user' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: Executing select query: SELECT id, UserName, Attribute, Value, op FROM wifi_attrs WHERE Username = 'user' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ... falling-through to group processing Thu Nov 2 21:43:58 2017 : Debug: SELECT 'GroupWifi' as GroupName FROM wifiusers WHERE UserName='%{SQL-User-Name}' Thu Nov 2 21:43:58 2017 : Debug: Parsed xlat tree: Thu Nov 2 21:43:58 2017 : Debug: literal --> SELECT 'GroupWifi' as GroupName FROM wifiusers WHERE UserName=' Thu Nov 2 21:43:58 2017 : Debug: attribute --> SQL-User-Name Thu Nov 2 21:43:58 2017 : Debug: literal --> ' Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: EXPAND SELECT 'GroupWifi' as GroupName FROM wifiusers WHERE UserName='%{SQL-User-Name}' Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: --> SELECT 'GroupWifi' as GroupName FROM wifiusers WHERE UserName='user' Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: Executing select query: SELECT 'GroupWifi' as GroupName FROM wifiusers WHERE UserName='user' Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: User found in the group table Thu Nov 2 21:43:58 2017 : Debug: SELECT wifi_id as id, 'GroupWifi' as GroupName, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE Username = '%{SQL-User-Name}' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: Parsed xlat tree: Thu Nov 2 21:43:58 2017 : Debug: literal --> SELECT wifi_id as id, 'GroupWifi' as GroupName, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE Username = ' Thu Nov 2 21:43:58 2017 : Debug: attribute --> SQL-User-Name Thu Nov 2 21:43:58 2017 : Debug: literal --> ' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: EXPAND SELECT wifi_id as id, 'GroupWifi' as GroupName, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE Username = '%{SQL-User-Name}' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: --> SELECT wifi_id as id, 'GroupWifi' as GroupName, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE Username = 'user' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: Executing select query: SELECT wifi_id as id, 'GroupWifi' as GroupName, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE Username = 'user' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: Group "GroupWifi": Conditional check items matched Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: Group "GroupWifi": Merging assignment check items Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: Cleartext-Password := "password" Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: FROM 1 TO 2 MAX 3 Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: Examining Cleartext-Password Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: OVERWRITING Cleartext-Password FROM 0 TO 1 Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: TO in 2 out 2 Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: to[0] = Auth-Type Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: to[1] = Cleartext-Password Thu Nov 2 21:43:58 2017 : Debug: SELECT wifi_id as id, 'GroupWifi' as GroupName, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE Username = '%{SQL-User-Name}' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: Parsed xlat tree: Thu Nov 2 21:43:58 2017 : Debug: literal --> SELECT wifi_id as id, 'GroupWifi' as GroupName, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE Username = ' Thu Nov 2 21:43:58 2017 : Debug: attribute --> SQL-User-Name Thu Nov 2 21:43:58 2017 : Debug: literal --> ' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: EXPAND SELECT wifi_id as id, 'GroupWifi' as GroupName, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE Username = '%{SQL-User-Name}' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: --> SELECT wifi_id as id, 'GroupWifi' as GroupName, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE Username = 'user' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: Executing select query: SELECT wifi_id as id, 'GroupWifi' as GroupName, 'Cleartext-Password' as attribute, password, ':=' as op FROM wifiusers WHERE Username = 'user' ORDER BY id Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: Group "GroupWifi": Merging reply items Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: Cleartext-Password := "password" Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: FROM 1 TO 0 MAX 1 Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: Examining Cleartext-Password Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: APPENDING Cleartext-Password FROM 0 TO 0 Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ::: TO in 0 out 0 Thu Nov 2 21:43:58 2017 : Debug: (138) sql-wifi: ... falling-through to profile processing Thu Nov 2 21:43:58 2017 : Debug: rlm_sql (sql-wifi): Released connection (2) Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from sql-wifi (rlm_sql) Thu Nov 2 21:43:58 2017 : Debug: (138) [sql-wifi] = ok Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling pap (rlm_pap) Thu Nov 2 21:43:58 2017 : WARNING: (138) pap: Auth-Type already set. Not setting to PAP Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from pap (rlm_pap) Thu Nov 2 21:43:58 2017 : Debug: (138) [pap] = noop Thu Nov 2 21:43:58 2017 : Debug: (138) } # authorize = ok Thu Nov 2 21:43:58 2017 : Debug: (138) Found Auth-Type = eap Thu Nov 2 21:43:58 2017 : Debug: (138) # Executing group from file /etc/raddb/sites-enabled/default Thu Nov 2 21:43:58 2017 : Debug: (138) authenticate { Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authenticate]: calling eap (rlm_eap) Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Expiring EAP session with state 0xacf07a2badf260fe Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Finished EAP session with state 0x00729277067a8792 Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Previous EAP request found for state 0x00729277067a8792, released from the list Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Peer sent packet with method EAP TTLS (21) Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Calling submodule eap_ttls to process data Thu Nov 2 21:43:58 2017 : Debug: (138) eap_ttls: Authenticate Thu Nov 2 21:43:58 2017 : Debug: (138) eap_ttls: Continuing EAP-TLS Thu Nov 2 21:43:58 2017 : Debug: (138) eap_ttls: Peer sent flags --- Thu Nov 2 21:43:58 2017 : Debug: (138) eap_ttls: [eaptls verify] = ok Thu Nov 2 21:43:58 2017 : Debug: (138) eap_ttls: Done initial handshake Thu Nov 2 21:43:58 2017 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0 Thu Nov 2 21:43:58 2017 : Debug: (138) eap_ttls: [eaptls process] = ok Thu Nov 2 21:43:58 2017 : Debug: (138) eap_ttls: Session established. Proceeding to decode tunneled attributes TTLS tunnel data in 0000: 00 00 00 4f 40 00 00 4e 02 02 00 46 1a 02 02 00 TTLS tunnel data in 0010: 41 31 31 36 ff 7e 4e d5 c6 a5 ac 8a 61 c3 88 fb TTLS tunnel data in 0020: 88 a4 00 00 00 00 00 00 00 00 81 5c 45 83 b9 97 TTLS tunnel data in 0030: 70 9d eb 90 9a ba db 83 1f 25 d9 1c 11 72 89 3a TTLS tunnel data in 0040: 99 3b 00 61 2e 73 6f 6c 64 61 74 6b 69 6e 00 00 Thu Nov 2 21:43:58 2017 : Debug: (138) eap_ttls: Got tunneled request Thu Nov 2 21:43:58 2017 : Debug: (138) eap_ttls: EAP-Message = 0x020200461a02020041313136ff7e4ed5c6a5ac8a61c388fb88a40000000000000000815c4583b997709deb909abadb831f25d91c1172893a993b00612e736f6c6461746b696e Thu Nov 2 21:43:58 2017 : Debug: (138) eap_ttls: FreeRADIUS-Proxied-To = 127.0.0.1 Thu Nov 2 21:43:58 2017 : Debug: (138) eap_ttls: Sending tunneled request Thu Nov 2 21:43:58 2017 : Debug: (138) Virtual server inner-tunnel received request Thu Nov 2 21:43:58 2017 : Debug: (138) EAP-Message = 0x020200461a02020041313136ff7e4ed5c6a5ac8a61c388fb88a40000000000000000815c4583b997709deb909abadb831f25d91c1172893a993b00612e736f6c6461746b696e Thu Nov 2 21:43:58 2017 : Debug: (138) FreeRADIUS-Proxied-To = 127.0.0.1 Thu Nov 2 21:43:58 2017 : Debug: (138) User-Name = "user" Thu Nov 2 21:43:58 2017 : Debug: (138) State = 0xacf07a2badf260feda2e8d2e021e6186 Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-Port = 96 Thu Nov 2 21:43:58 2017 : Debug: (138) Acct-Session-Id = "8O2.1x818b430100008423" Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-Port-Id = "ge-0/0/13.0" Thu Nov 2 21:43:58 2017 : Debug: (138) Calling-Station-Id = "d0-50-99-2c-ff-00" Thu Nov 2 21:43:58 2017 : Debug: (138) Called-Station-Id = "88-e0-f3-b0-d6-00" Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-IP-Address = 192.168.1.2 Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-Identifier = "sw-" Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-Port-Type = Ethernet Thu Nov 2 21:43:58 2017 : Debug: (138) Event-Timestamp = "Nov 2 2017 21:43:58 UTC" Thu Nov 2 21:43:58 2017 : WARNING: (138) Outer and inner identities are the same. User privacy is compromised. Thu Nov 2 21:43:58 2017 : Debug: (138) FreeRADIUS-Proxied-To = 127.0.0.1 Thu Nov 2 21:43:58 2017 : Debug: (138) User-Name = "user" Thu Nov 2 21:43:58 2017 : Debug: (138) State = 0xacf07a2badf260feda2e8d2e021e6186 Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-Port = 96 Thu Nov 2 21:43:58 2017 : Debug: (138) Acct-Session-Id = "8O2.1x818b430100008423" Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-Port-Id = "ge-0/0/13.0" Thu Nov 2 21:43:58 2017 : Debug: (138) Calling-Station-Id = "d0-50-99-2c-ff-00" Thu Nov 2 21:43:58 2017 : Debug: (138) Called-Station-Id = "88-e0-f3-b0-d6-00" Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-IP-Address = 192.168.1.2 Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-Identifier = "sw-" Thu Nov 2 21:43:58 2017 : Debug: (138) NAS-Port-Type = Ethernet Thu Nov 2 21:43:58 2017 : Debug: (138) Event-Timestamp = "Nov 2 2017 21:43:58 UTC" Thu Nov 2 21:43:58 2017 : WARNING: (138) Outer and inner identities are the same. User privacy is compromised. Thu Nov 2 21:43:58 2017 : Debug: (138) server inner-tunnel { Thu Nov 2 21:43:58 2017 : Debug: (138) session-state: No cached attributes Thu Nov 2 21:43:58 2017 : Debug: (138) # Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel Thu Nov 2 21:43:58 2017 : Debug: (138) authorize { Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling chap (rlm_chap) Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from chap (rlm_chap) Thu Nov 2 21:43:58 2017 : Debug: (138) [chap] = noop Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling mschap (rlm_mschap) Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from mschap (rlm_mschap) Thu Nov 2 21:43:58 2017 : Debug: (138) [mschap] = noop Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling unix (rlm_unix) Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from unix (rlm_unix) Thu Nov 2 21:43:58 2017 : Debug: (138) [unix] = notfound Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling suffix (rlm_realm) Thu Nov 2 21:43:58 2017 : Debug: (138) suffix: Checking for suffix after "@" Thu Nov 2 21:43:58 2017 : Debug: (138) suffix: No '@' in User-Name = "user", looking up realm NULL Thu Nov 2 21:43:58 2017 : Debug: (138) suffix: No such realm "NULL" Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from suffix (rlm_realm) Thu Nov 2 21:43:58 2017 : Debug: (138) [suffix] = noop Thu Nov 2 21:43:58 2017 : Debug: (138) update control { Thu Nov 2 21:43:58 2017 : Debug: (138) Proxy-To-Realm := LOCAL Thu Nov 2 21:43:58 2017 : Debug: (138) } # update control = noop Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling eap (rlm_eap) Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Peer sent EAP Response (code 2) ID 2 length 70 Thu Nov 2 21:43:58 2017 : Debug: (138) eap: No EAP Start, assuming it's an on-going EAP conversation Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from eap (rlm_eap) Thu Nov 2 21:43:58 2017 : Debug: (138) [eap] = updated Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling files (rlm_files) Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from files (rlm_files) Thu Nov 2 21:43:58 2017 : Debug: (138) [files] = noop Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling expiration (rlm_expiration) Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from expiration (rlm_expiration) Thu Nov 2 21:43:58 2017 : Debug: (138) [expiration] = noop Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling logintime (rlm_logintime) Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from logintime (rlm_logintime) Thu Nov 2 21:43:58 2017 : Debug: (138) [logintime] = noop Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: calling pap (rlm_pap) Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authorize]: returned from pap (rlm_pap) Thu Nov 2 21:43:58 2017 : Debug: (138) [pap] = noop Thu Nov 2 21:43:58 2017 : Debug: (138) } # authorize = updated Thu Nov 2 21:43:58 2017 : Debug: (138) Found Auth-Type = eap Thu Nov 2 21:43:58 2017 : Debug: (138) # Executing group from file /etc/raddb/sites-enabled/inner-tunnel Thu Nov 2 21:43:58 2017 : Debug: (138) authenticate { Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authenticate]: calling eap (rlm_eap) Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Expiring EAP session with state 0xacf07a2badf260fe Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Finished EAP session with state 0xacf07a2badf260fe Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Previous EAP request found for state 0xacf07a2badf260fe, released from the list Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Peer sent packet with method EAP MSCHAPv2 (26) Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Calling submodule eap_mschapv2 to process data Thu Nov 2 21:43:58 2017 : Debug: (138) eap_mschapv2: # Executing group from file /etc/raddb/sites-enabled/inner-tunnel Thu Nov 2 21:43:58 2017 : Debug: (138) eap_mschapv2: Auth-Type MS-CHAP { Thu Nov 2 21:43:58 2017 : Debug: (138) eap_mschapv2: modsingle[authenticate]: calling mschap (rlm_mschap) Thu Nov 2 21:43:58 2017 : WARNING: (138) mschap: No Cleartext-Password configured. Cannot create NT-Password Thu Nov 2 21:43:58 2017 : WARNING: (138) mschap: No Cleartext-Password configured. Cannot create LM-Password Thu Nov 2 21:43:58 2017 : Debug: (138) mschap: Creating challenge hash with username: user Thu Nov 2 21:43:58 2017 : Debug: (138) mschap: Client is using MS-CHAPv2 Thu Nov 2 21:43:58 2017 : ERROR: (138) mschap: FAILED: No NT/LM-Password. Cannot perform authentication Thu Nov 2 21:43:58 2017 : ERROR: (138) mschap: MS-CHAP2-Response is incorrect Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authenticate]: returned from mschap (rlm_mschap) Thu Nov 2 21:43:58 2017 : Debug: (138) [mschap] = reject Thu Nov 2 21:43:58 2017 : Debug: (138) } # Auth-Type MS-CHAP = reject Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Sending EAP Failure (code 4) ID 2 length 4 Thu Nov 2 21:43:58 2017 : Debug: (138) eap: Freeing handler Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[authenticate]: returned from eap (rlm_eap) Thu Nov 2 21:43:58 2017 : Debug: (138) [eap] = reject Thu Nov 2 21:43:58 2017 : Debug: (138) } # authenticate = reject Thu Nov 2 21:43:58 2017 : Debug: (138) Failed to authenticate the user Thu Nov 2 21:43:58 2017 : Debug: (138) Using Post-Auth-Type Reject Thu Nov 2 21:43:58 2017 : Debug: (138) # Executing group from file /etc/raddb/sites-enabled/inner-tunnel Thu Nov 2 21:43:58 2017 : Debug: (138) Post-Auth-Type REJECT { Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) Thu Nov 2 21:43:58 2017 : Debug: %{User-Name} Thu Nov 2 21:43:58 2017 : Debug: Parsed xlat tree: Thu Nov 2 21:43:58 2017 : Debug: attribute --> User-Name Thu Nov 2 21:43:58 2017 : Debug: (138) attr_filter.access_reject: EXPAND %{User-Name} Thu Nov 2 21:43:58 2017 : Debug: (138) attr_filter.access_reject: --> user Thu Nov 2 21:43:58 2017 : Debug: (138) attr_filter.access_reject: Matched entry DEFAULT at line 11 Thu Nov 2 21:43:58 2017 : Debug: (138) attr_filter.access_reject: Attribute "MS-CHAP-Error" allowed by 0 rules, disallowed by 0 rules Thu Nov 2 21:43:58 2017 : Debug: (138) attr_filter.access_reject: EAP-Message = 0x04020004 allowed by EAP-Message =* 0x Thu Nov 2 21:43:58 2017 : Debug: (138) attr_filter.access_reject: Attribute "EAP-Message" allowed by 1 rules, disallowed by 0 rules Thu Nov 2 21:43:58 2017 : Debug: (138) attr_filter.access_reject: Message-Authenticator = 0x00000000000000000000000000000000 allowed by Message-Authenticator =* 0x Thu Nov 2 21:43:58 2017 : Debug: (138) attr_filter.access_reject: Attribute "Message-Authenticator" allowed by 1 rules, disallowed by 0 rules Thu Nov 2 21:43:58 2017 : Debug: (138) modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) Thu Nov 2 21:43:58 2017 : Debug: (138) [attr_filter.access_reject] = updated Thu Nov 2 21:43:58 2017 : Debug: (138) } # Post-Auth-Type REJECT = updated Thu Nov 2 21:43:58 2017 : Auth: (138) Login incorrect (mschap: FAILED: No NT/LM-Password. Cannot perform authentication): [user/<via Auth-Type = eap>] (from client EX port 96 cli d0-50-99-2c-ff-00 via TLS tunnel) 2017-11-03 13:49 GMT+03:00 Alan DeKok <aland@deployingradius.com>:
On Nov 3, 2017, at 6:39 AM, Anton Kiryushkin <swood@fotofor.biz> wrote:
I have two question about migration from oldest to newest version. 1. After migration, the process authorization by MSCHAP-V2 wrote that
can't
make NT-password:
The error is saying "No Cleartext-Password". i.e. you didn't tell the server what the users "known good" password is.
This happened in inner-tunnel site with config:
What does the *rest* of the debug output say? Reading that will tell you what's happening.
But I have the same config on FR 2.X in it worked. Could tell me why?
Read the debug output.
The second question with another client. I've got the next error message:
Thu Nov 2 21:44:19 2017 : ERROR: (159) eap_peap: Failed in __FUNCTION__ (SSL_read): s3_srvr.c[1240]:error:1408A0E3:SSL routines:ssl3_get_client_hello:parse tlsext Thu Nov 2 21:44:19 2017 : ERROR: (159) eap_peap: System call (I/O) error (-1)
Weird. It looks like that "tlsext" field is malformed.
Thu Nov 2 21:44:19 2017 : ERROR: (159) eap_peap: TLS receive handshake failed during operation Thu Nov 2 21:44:19 2017 : ERROR: (159) eap_peap: [eaptls process] = fail Thu Nov 2 21:44:19 2017 : ERROR: (159) eap: Failed continuing EAP PEAP (25) session. EAP sub-module failed
This is printer Canon 5240i and I can't change his software. As well as in the previous question, all work with FR 2.X.
Let me guess: you also changed operating systems, and OpenSSL versions at the same time.
Older OpenSSL versions were more forgiving of bad data. Newer OpenSSL versions are more strict.
This is (unfortunately) an OpenSSL thing. Nothing in FreeRADIUS will cause that error.
The short answer is that the client is broken. It doesn't implement PEAP / SSL correctly.
Alan DeKok.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/ list/users.html
-- Best regards, Anton Kiryushkin
On Nov 3, 2017, at 7:05 AM, Anton Kiryushkin <swood@fotofor.biz> wrote:
Returning to the question about a mschap. I have the next debug log:
PLEASE use "radiusd -X". DON'T use "radiusd -Xx". Honestly, this is almost a daily complaint now. The instructions say to use "radiusd -X" for a reason. If we wanted the output of "-Xx", we would ask for it. And we didn't ask for it. So we don't want it. The debug output shows that you put Cleartext-Password into an SQL database. And then configured the "sql" module in the "default" virtual server. But didn't configure it in the "inner-tunnel" virtual server. It helps to pay attention. You can't just randomly make changes, and expect them to work. You have to *understand* what the server is doing, and what you're doing. If you put users into "sql", and *don't* list "sql" in the inner-tunnel... then of *course* it's not going to work. Alan DeKok.
Yes, I understood this. But, why the same config works perfectly with FR 2.X? 2017-11-03 14:14 GMT+03:00 Alan DeKok <aland@deployingradius.com>:
On Nov 3, 2017, at 7:05 AM, Anton Kiryushkin <swood@fotofor.biz> wrote:
Returning to the question about a mschap. I have the next debug log:
PLEASE use "radiusd -X". DON'T use "radiusd -Xx". Honestly, this is almost a daily complaint now.
The instructions say to use "radiusd -X" for a reason. If we wanted the output of "-Xx", we would ask for it. And we didn't ask for it. So we don't want it.
The debug output shows that you put Cleartext-Password into an SQL database. And then configured the "sql" module in the "default" virtual server. But didn't configure it in the "inner-tunnel" virtual server.
It helps to pay attention. You can't just randomly make changes, and expect them to work. You have to *understand* what the server is doing, and what you're doing.
If you put users into "sql", and *don't* list "sql" in the inner-tunnel... then of *course* it's not going to work.
Alan DeKok.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/ list/users.html
-- Best regards, Anton Kiryushkin
And could you tell me that what kind of ways to disable TLS for one of the client? I mean printer. 2017-11-03 14:44 GMT+03:00 Anton Kiryushkin <swood@fotofor.biz>:
Yes, I understood this. But, why the same config works perfectly with FR 2.X?
2017-11-03 14:14 GMT+03:00 Alan DeKok <aland@deployingradius.com>:
On Nov 3, 2017, at 7:05 AM, Anton Kiryushkin <swood@fotofor.biz> wrote:
Returning to the question about a mschap. I have the next debug log:
PLEASE use "radiusd -X". DON'T use "radiusd -Xx". Honestly, this is almost a daily complaint now.
The instructions say to use "radiusd -X" for a reason. If we wanted the output of "-Xx", we would ask for it. And we didn't ask for it. So we don't want it.
The debug output shows that you put Cleartext-Password into an SQL database. And then configured the "sql" module in the "default" virtual server. But didn't configure it in the "inner-tunnel" virtual server.
It helps to pay attention. You can't just randomly make changes, and expect them to work. You have to *understand* what the server is doing, and what you're doing.
If you put users into "sql", and *don't* list "sql" in the inner-tunnel... then of *course* it's not going to work.
Alan DeKok.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list /users.html
-- Best regards, Anton Kiryushkin
-- Best regards, Anton Kiryushkin
On Nov 3, 2017, at 7:44 AM, Anton Kiryushkin <swood@fotofor.biz> wrote:
Yes, I understood this. But, why the same config works perfectly with FR 2.X?
You can read the debug output to see. It's not hard. As for disabling TLS for one client, you can't. You have to fix the client. Alan DeKok.
participants (2)
-
Alan DeKok -
Anton Kiryushkin