AW: LDAP / mschap Error

Andreas Zwinzscher andreas.zwinzscher at bod-datennetze.de
Thu Aug 25 07:13:55 CEST 2016


Here I have the freeradius -X output log from the failed authentication. 

Ready to process requests.
rad_recv: Access-Request packet from host 10.0.10.2 port 2897, id=231, length=205
        User-Name = "CORNET\\Administrator"
        Framed-MTU = 1450
        EAP-Message = 0x020b001901434f524e45545c41646d696e6973747261746f72
        Message-Authenticator = 0x546ef3904298a6a5d47e4da54a19bfd7
        NAS-IP-Address = 10.0.10.2
        NAS-Identifier = "Switch_2"
        NAS-Port = 16830465
        NAS-Port-Id = "slot=1;subslot=0;port=13;vlanid=1"
        NAS-Port-Type = Ethernet
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Calling-Station-Id = "00-22-4D-AB-2D-19"
        Acct-Session-Id = "1000429113760010"
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[digest] = noop
[ntdomain] Looking up realm "CORNET" for User-Name = "CORNET\Administrator"
[ntdomain] No such realm "CORNET"
++[ntdomain] = noop
[eap] EAP packet type response id 11 length 25
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
  [ldap] Entering ldap_groupcmp()
[files]         expand: ou=Benutzer,dc=cornet,dc=local -> ou=Benutzer,dc=cornet,dc=local
[files]         expand: (sAMAccountName=%{mschap:User-Name}) -> (sAMAccountName=Administrator)
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] attempting LDAP reconnection
  [ldap] (re)connect to cordc.cornet.local:389, authentication 0
  [ldap] bind as cn=Radius,ou=Verwaltung,ou=Benutzer,dc=cornet,dc=local/password to cordc.cornet.local:389
  [ldap] waiting for bind result ...
  [ldap] Bind was successful
  [ldap] performing search in ou=Benutzer,dc=cornet,dc=local, with filter (sAMAccountName=Administrator)
  [ldap] object not found
rlm_ldap::ldap_groupcmp: search failed
  [ldap] ldap_release_conn: Release Id: 0
[files] users: Matched entry DEFAULT at line 182
++[files] = ok
[ldap] performing user authorization for CORNET\Administrator
[ldap]  expand: (sAMAccountName=%{mschap:User-Name}) -> (sAMAccountName=Administrator)
[ldap]  expand: ou=Benutzer,dc=cornet,dc=local -> ou=Benutzer,dc=cornet,dc=local
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in ou=Benutzer,dc=cornet,dc=local, with filter (sAMAccountName=Administrator)
  [ldap] object not found
[ldap] search failed
  [ldap] ldap_release_conn: Release Id: 0
++[ldap] = notfound
++[expiration] = noop
++[logintime] = noop
[pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
++[pap] = noop
+} # group authorize = updated
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+group authenticate {
[eap] EAP Identity
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 231 to 10.0.10.2 port 2897
        Framed-Protocol = PPP
        Framed-Compression = Van-Jacobson-TCP-IP
        EAP-Message = 0x010c00061920
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xb80ddd5cb801c4b706d6087b7083c2b4
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.0.10.2 port 2897, id=232, length=316
        User-Name = "CORNET\\Administrator"
        Framed-MTU = 1450
        EAP-Message = 0x020c007619800000006c160301006701000063030157bc27882b1a68202e3351a2f8b715f52bc49793f8e157db73e91f877af3da4b000018c014c0130035002fc00ac00900380032000a00130005000401000022ff01000100000500050100000000000a0006000400170018000b0002010000230000
        Message-Authenticator = 0x5d612487b73f60218f3187d3892486a0
        NAS-IP-Address = 10.0.10.2
        NAS-Identifier = "Switch_2"
        NAS-Port = 16830465
        NAS-Port-Id = "slot=1;subslot=0;port=13;vlanid=1"
        NAS-Port-Type = Ethernet
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Calling-Station-Id = "00-22-4D-AB-2D-19"
        Acct-Session-Id = "1000429113760010"
        State = 0xb80ddd5cb801c4b706d6087b7083c2b4
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[digest] = noop
[ntdomain] Looking up realm "CORNET" for User-Name = "CORNET\Administrator"
[ntdomain] No such realm "CORNET"
++[ntdomain] = noop
[eap] EAP packet type response id 12 length 118
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 108
[peap] Length Included
[peap] eaptls_verify returned 11
[peap]     (other): before/accept initialization
[peap]     TLS_accept: before/accept initialization
[peap] <<< Unknown TLS version [length 0005]
[peap] <<< TLS 1.0 Handshake [length 0067], ClientHello
[peap]     TLS_accept: unknown state
[peap] >>> Unknown TLS version [length 0005]
[peap] >>> TLS 1.0 Handshake [length 0039], ServerHello
[peap]     TLS_accept: unknown state
[peap] >>> Unknown TLS version [length 0005]
[peap] >>> TLS 1.0 Handshake [length 087b], Certificate
[peap]     TLS_accept: unknown state
[peap] >>> Unknown TLS version [length 0005]
[peap] >>> TLS 1.0 Handshake [length 014b], ServerKeyExchange
[peap]     TLS_accept: unknown state
[peap] >>> Unknown TLS version [length 0005]
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[peap]     TLS_accept: unknown state
[peap]     TLS_accept: unknown state
[peap]     TLS_accept: unknown state
[peap]     TLS_accept: Need to read more data: unknown state
[peap]     TLS_accept: Need to read more data: unknown state
In SSL Handshake Phase
In SSL Accept mode
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 232 to 10.0.10.2 port 2897
        EAP-Message = 0x010d040019c000000a1716030100390200003503010487d34e6a4ce252108cd33a8692e842a975b28b5c31fe207878f913aa4be40100c01400000dff01000100000b000403000102160301087b0b0008770008740003bf308203bb308202a3a00302010202021001300d06092a864886f70d01010b0500308181310b30090603550406130244453114301206035504080c0b446575747363686c616e643111300f06035504070c084368656d6e69747a31143012060355040a0c0b546572726f7420476d6248311b301906092a864886f70d010901160c697440746572726f742e64653116301406035504030c0d436f726e657420526164697573301e
        EAP-Message = 0x170d3136303831353130303631355a170d3137303831353130303631355a306e310b30090603550406130244453114301206035504080c0b446575747363686c616e6431143012060355040a0c0b546572726f7420476d62483116301406035504030c0d436f726e657420526164697573311b301906092a864886f70d010901160c697440746572726f742e646530820122300d06092a864886f70d01010105000382010f003082010a0282010100f78bbe5a0de5b8616fa403038f713a9942f17eabced5952648a45a7aa58b485ae9688517c7d4de53ae0bfd588246d7265ec3532c6094fb3dcd942ef93da5a12f2a2bb3e0cb85f1f95f49332ba091
        EAP-Message = 0xe8bac7158abdb17d4bf498a3414c5f3feaf13600f8bb8bbbe7c0e0b60dcff49293b84659b12f9a7c5e0027e916056901cae5f3cc1962e454a93fba2273a52699697851ad182be89c7649a30b7da823aef3c2ca0868dd027ea13d56aa9fc73d38b4cbb092a5f366192449b3bd9f378d9337d00b76caa2e10cbe397a0cefb92f65bafd04b500e48d9e28b0c49230d9d7b1aa6a6dd08bb731fbacba3de58ce445b33ca7cb0ce13faf7fd87ec5feefcb48d22b190203010001a34f304d30130603551d25040c300a06082b0601050507030130360603551d1f042f302d302ba029a0278625687474703a2f2f7777772e6578616d706c652e636f6d2f657861
        EAP-Message = 0x6d706c655f63612e63726c300d06092a864886f70d01010b050003820101001dbec46407b4dd34328e60d4e8e3db47aeb0794288177ba5cc8ce30ba1a2b3a65a21e197a546b902c15506eb509fcd40560d773d9dfa9da6392433a06ca9fde54ff1c936645ec7d5f9966ffd7f2284434eaf53e6fc8a5106c2bf198bdcfa943f682c359994f6f2587700b77c97617870b83cac81c0f841b3ea7e5393f3a24dfe16c8dcb639eb4b21185203d0ec9e1aeaf53ee6d164793694f8fefc95d770918c11a543b0cdb8a0ec9fe0c05c1a0a6ccc18ac4c9a46e819d8fd4cbd42df6af607e2fd91f13dc058842cf277db06f33613dd4393ae52424bbbaad8f2e2d28b
        EAP-Message = 0x068fad9b93e5824966416ba7
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xb80ddd5cb900c4b706d6087b7083c2b4
Finished request 1.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 10.0.10.2 port 2897, id=233, length=204
        User-Name = "CORNET\\Administrator"
        Framed-MTU = 1450
        EAP-Message = 0x020d00061900
        Message-Authenticator = 0xb08e06e3b448cdafef6357a1292c4eb8
        NAS-IP-Address = 10.0.10.2
        NAS-Identifier = "Switch_2"
        NAS-Port = 16830465
        NAS-Port-Id = "slot=1;subslot=0;port=13;vlanid=1"
        NAS-Port-Type = Ethernet
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Calling-Station-Id = "00-22-4D-AB-2D-19"
        Acct-Session-Id = "1000429113760010"
        State = 0xb80ddd5cb900c4b706d6087b7083c2b4
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[digest] = noop
[ntdomain] Looking up realm "CORNET" for User-Name = "CORNET\Administrator"
[ntdomain] No such realm "CORNET"
++[ntdomain] = noop
[eap] EAP packet type response id 13 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 233 to 10.0.10.2 port 2897
        EAP-Message = 0x010e03fc1940aa9b641aa6a9bb2f1f1243ec58a20bcffbc249bdda120004af308204ab30820393a003020102020900cff66ec74eed107d300d06092a864886f70d01010b0500308181310b30090603550406130244453114301206035504080c0b446575747363686c616e643111300f06035504070c084368656d6e69747a31143012060355040a0c0b546572726f7420476d6248311b301906092a864886f70d010901160c697440746572726f742e64653116301406035504030c0d436f726e657420526164697573301e170d3136303831353130303631355a170d3137303831353130303631355a308181310b3009060355040613024445311430
        EAP-Message = 0x1206035504080c0b446575747363686c616e643111300f06035504070c084368656d6e69747a31143012060355040a0c0b546572726f7420476d6248311b301906092a864886f70d010901160c697440746572726f742e64653116301406035504030c0d436f726e65742052616469757330820122300d06092a864886f70d01010105000382010f003082010a0282010100b838d20acae95ef1dd38944b405897d83798dec693f1cb919530abcca91e314bf9e785a9b76e93a131590d5e42d1c2084f9ff4ad13290fda32232fca7e7856f7a19e91ee9f032f91e24c50311f58dec04d3d78ea7ae0722fb6205b21fb39d235c08e019dcf73caae92f8a4
        EAP-Message = 0x1dfbd8fa03cf5b34809779e07859a0a794c8527fd950b4fc4350aa186eb3c4f3cfbbb4a255621af9792007047e096be226562db3b13cf1f46c79876656983e03a962dd4046613d53cfd1665b4112329f6a5eaa5fae1ff906ee6cde3c50abc83c1e9088cc3ed25862d41c0088cb3f83778591ca81f3113cf23fd54331e321392d0910a4a6a9074703ea2ec30e481f2b82a487bcc81d0203010001a38201223082011e301d0603551d0e04160414d1c8eec78a52a55df0af1ffb849c6af696aadf1c3081b60603551d230481ae3081ab8014d1c8eec78a52a55df0af1ffb849c6af696aadf1ca18187a48184308181310b30090603550406130244453114
        EAP-Message = 0x301206035504080c0b446575747363686c616e643111300f06035504070c084368656d6e69747a31143012060355040a0c0b546572726f7420476d6248311b301906092a864886f70d010901160c697440746572726f742e64653116301406035504030c0d436f726e657420526164697573820900cff66ec74eed107d300c0603551d13040530030101ff30360603551d1f042f302d302ba029a0278625687474703a2f2f7777772e6578616d706c652e636f6d2f6578616d706c655f63612e63726c300d06092a864886f70d01010b050003820101003faebd556c4f1a5a88702531a06be7e4e5e85f801ea91b8c75bca5235e5a54d83fba75235a8d
        EAP-Message = 0x4dcc6170236c2c86
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xb80ddd5cba03c4b706d6087b7083c2b4
Finished request 2.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 10.0.10.2 port 2897, id=234, length=204
        User-Name = "CORNET\\Administrator"
        Framed-MTU = 1450
        EAP-Message = 0x020e00061900
        Message-Authenticator = 0x02fe848f4d30c98b3a127887012bad38
        NAS-IP-Address = 10.0.10.2
        NAS-Identifier = "Switch_2"
        NAS-Port = 16830465
        NAS-Port-Id = "slot=1;subslot=0;port=13;vlanid=1"
        NAS-Port-Type = Ethernet
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Calling-Station-Id = "00-22-4D-AB-2D-19"
        Acct-Session-Id = "1000429113760010"
        State = 0xb80ddd5cba03c4b706d6087b7083c2b4
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[digest] = noop
[ntdomain] Looking up realm "CORNET" for User-Name = "CORNET\Administrator"
[ntdomain] No such realm "CORNET"
++[ntdomain] = noop
[eap] EAP packet type response id 14 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 234 to 10.0.10.2 port 2897
        EAP-Message = 0x010f02311900de6c5e3eb8d2b6528cb64951c8694febca579e1f7dc45420523c8d2aba5ba09a48d03276ee016aa833377e71f480b68bb7899c737d7d19f0e556e3cfbaf8e69da70d35ab1fc5453fc8a65e7ef8ba122988bd583562ab96e3a1901de2388bfdcca6eed24857d2db3a5f92ec3b9c3504a3222bb544772f2a03a13c87cc6d84bafea9e38faf83d9ec42c5854a2b3e869bd848f696789db3c5252f6cc4130364f780a15598401af88060ab5d34549038327c5e0663fffc5e741e3b0475527cd4bcad01b9dd08be153b799bbb29699e72b7b85f7c160301014b0c00014703001741042c237f1373c08f37d7aa8322fec731d17da31fa9d87b47
        EAP-Message = 0xf2e4d13bb856e26849cc79470dcbbaa005fcf179f17451ec25869c0ad682d03bd97691f2d600f89f2901004040e9cfded8334191e6de417d23e43031bb92f15a4f283f13ccb07b44f87b09f243f940643c121e72c0671f268134ddf4618a254bf1830e30fa6800b437abe1d281d679322522e4e96f121d83a54277344e8604317cdbc5f061b022694ad0a5e322f2eb98f1727443b94d652e6033b3dbb17adf822a0c3a562437a330b0fb705f123c5aff5a70bf1b309dc2cdd76173e9262640f24c231cbe6cbb743959b059c83977dba0ba67bd4392fc3198dd68a9f1b92c23ed59cba18371a41aefd62b706d42bf40be9cbca6b55e04ff4ef651203ff4
        EAP-Message = 0x7a20de1a85006c63a58897c6c76d89d2e9ad9a51551bd65e144719804bd5bd34ec4f51fdfad6590a70cbd753454f16030100040e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xb80ddd5cbb02c4b706d6087b7083c2b4
Finished request 3.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 10.0.10.2 port 2897, id=235, length=342
        User-Name = "CORNET\\Administrator"
        Framed-MTU = 1450
        EAP-Message = 0x020f009019800000008616030100461000004241042fd863b65294e06048626602bfbb689c5fe2a29d1a6d953c569b4e8984ddce9087d5599dde81d8a27037e8c4666613f3286f41d4e5858e2c4084ffc02608ba371403010001011603010030fcd561477b7760bd353bf2007b5a8b58c96a89679b9d118e448e33474d2abe79eefd6abeafb39009977472c633dc5abe
        Message-Authenticator = 0xee577ed826384f78a93cbd5f02efdf52
        NAS-IP-Address = 10.0.10.2
        NAS-Identifier = "Switch_2"
        NAS-Port = 16830465
        NAS-Port-Id = "slot=1;subslot=0;port=13;vlanid=1"
        NAS-Port-Type = Ethernet
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Calling-Station-Id = "00-22-4D-AB-2D-19"
        Acct-Session-Id = "1000429113760010"
        State = 0xb80ddd5cbb02c4b706d6087b7083c2b4
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[digest] = noop
[ntdomain] Looking up realm "CORNET" for User-Name = "CORNET\Administrator"
[ntdomain] No such realm "CORNET"
++[ntdomain] = noop
[eap] EAP packet type response id 15 length 144
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 134
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] <<< Unknown TLS version [length 0005]
[peap] <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange
[peap]     TLS_accept: unknown state
[peap]     TLS_accept: unknown state
[peap] <<< Unknown TLS version [length 0005]
[peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[peap] <<< Unknown TLS version [length 0005]
[peap] <<< TLS 1.0 Handshake [length 0010], Finished
[peap]     TLS_accept: unknown state
[peap] >>> Unknown TLS version [length 0005]
[peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[peap]     TLS_accept: unknown state
[peap] >>> Unknown TLS version [length 0005]
[peap] >>> TLS 1.0 Handshake [length 0010], Finished
[peap]     TLS_accept: unknown state
[peap]     TLS_accept: unknown state
[peap]     (other): SSL negotiation finished successfully
SSL Connection Established
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 235 to 10.0.10.2 port 2897
        EAP-Message = 0x01100041190014030100010116030100307fdd0a2a9489d438599dde12320c8be4fe22bac663cbbeaefdaec79408ae612cb2588613b3a7c9972fe457c92eb6423f
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xb80ddd5cbc1dc4b706d6087b7083c2b4
Finished request 4.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.0.10.2 port 2897, id=236, length=204
        User-Name = "CORNET\\Administrator"
        Framed-MTU = 1450
        EAP-Message = 0x021000061900
        Message-Authenticator = 0x88b6fa497997239eb039a29e32a1f67a
        NAS-IP-Address = 10.0.10.2
        NAS-Identifier = "Switch_2"
        NAS-Port = 16830465
        NAS-Port-Id = "slot=1;subslot=0;port=13;vlanid=1"
        NAS-Port-Type = Ethernet
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Calling-Station-Id = "00-22-4D-AB-2D-19"
        Acct-Session-Id = "1000429113760010"
        State = 0xb80ddd5cbc1dc4b706d6087b7083c2b4
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[digest] = noop
[ntdomain] Looking up realm "CORNET" for User-Name = "CORNET\Administrator"
[ntdomain] No such realm "CORNET"
++[ntdomain] = noop
[eap] EAP packet type response id 16 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake is finished
[peap] eaptls_verify returned 3
[peap] eaptls_process returned 3
[peap] EAPTLS_SUCCESS
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state TUNNEL ESTABLISHED
[peap] >>> Unknown TLS version [length 0005]
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 236 to 10.0.10.2 port 2897
        EAP-Message = 0x0111002b190017030100209e552e5abb7202d671f4084838b4ed5783740c7ae2166edec683d2ed4a67956a
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xb80ddd5cbd1cc4b706d6087b7083c2b4
Finished request 5.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.0.10.2 port 2897, id=237, length=257
        User-Name = "CORNET\\Administrator"
        Framed-MTU = 1450
        EAP-Message = 0x0211003b190017030100307d53ed09d423b14c3d0f3421f8ee7dda650537ec0696ebd1383f32c358502e3560d990d26895d273391ee37899008e12
        Message-Authenticator = 0xcc595e84d620788a64afb533de748b03
        NAS-IP-Address = 10.0.10.2
        NAS-Identifier = "Switch_2"
        NAS-Port = 16830465
        NAS-Port-Id = "slot=1;subslot=0;port=13;vlanid=1"
        NAS-Port-Type = Ethernet
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Calling-Station-Id = "00-22-4D-AB-2D-19"
        Acct-Session-Id = "1000429113760010"
        State = 0xb80ddd5cbd1cc4b706d6087b7083c2b4
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[digest] = noop
[ntdomain] Looking up realm "CORNET" for User-Name = "CORNET\Administrator"
[ntdomain] No such realm "CORNET"
++[ntdomain] = noop
[eap] EAP packet type response id 17 length 59
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] <<< Unknown TLS version [length 0005]
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state WAITING FOR INNER IDENTITY
[peap] Identity - CORNET\Administrator
[peap] Got inner identity 'CORNET\Administrator'
[peap] Setting default EAP type for tunneled EAP session.
[peap] Got tunneled request
        EAP-Message = 0x0211001901434f524e45545c41646d696e6973747261746f72
server  {
[peap] Setting User-Name to CORNET\Administrator
Sending tunneled request
        EAP-Message = 0x0211001901434f524e45545c41646d696e6973747261746f72
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "CORNET\\Administrator"
server inner-tunnel {
# Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
+group authorize {
++[chap] = noop
[ldap] performing user authorization for CORNET\Administrator
[ldap]  expand: (sAMAccountName=%{mschap:User-Name}) -> (sAMAccountName=Administrator)
[ldap]  expand: ou=Benutzer,dc=cornet,dc=local -> ou=Benutzer,dc=cornet,dc=local
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in ou=Benutzer,dc=cornet,dc=local, with filter (sAMAccountName=Administrator)
  [ldap] object not found
[ldap] search failed
  [ldap] ldap_release_conn: Release Id: 0
++[ldap] = notfound
++[mschap] = noop
[ntdomain] Looking up realm "CORNET" for User-Name = "CORNET\Administrator"
[ntdomain] No such realm "CORNET"
++[ntdomain] = noop
++update control {
++} # update control = noop
[eap] EAP packet type response id 17 length 25
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
  [ldap] Entering ldap_groupcmp()
[files]         expand: ou=Benutzer,dc=cornet,dc=local -> ou=Benutzer,dc=cornet,dc=local
[files]         expand: (sAMAccountName=%{mschap:User-Name}) -> (sAMAccountName=Administrator)
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in ou=Benutzer,dc=cornet,dc=local, with filter (sAMAccountName=Administrator)
  [ldap] object not found
rlm_ldap::ldap_groupcmp: search failed
  [ldap] ldap_release_conn: Release Id: 0
++[files] = noop
[ldap] performing user authorization for CORNET\Administrator
[ldap]  expand: (sAMAccountName=%{mschap:User-Name}) -> (sAMAccountName=Administrator)
[ldap]  expand: ou=Benutzer,dc=cornet,dc=local -> ou=Benutzer,dc=cornet,dc=local
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in ou=Benutzer,dc=cornet,dc=local, with filter (sAMAccountName=Administrator)
  [ldap] object not found
[ldap] search failed
  [ldap] ldap_release_conn: Release Id: 0
++[ldap] = notfound
++[expiration] = noop
++[logintime] = noop
++[pap] = noop
+} # group authorize = updated
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
+group authenticate {
[eap] EAP Identity
[eap] processing type mschapv2
rlm_eap_mschapv2: Issuing Challenge
++[eap] = handled
+} # group authenticate = handled
} # server inner-tunnel
[peap] Got tunneled reply code 11
        EAP-Message = 0x0112002e1a0112002910916f1a91c6d94a4e323eb431a469e9cc434f524e45545c41646d696e6973747261746f72
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x8467475784755ddfbef9adc7a7522e51
[peap] Got tunneled reply RADIUS code Access-Challenge
        EAP-Message = 0x0112002e1a0112002910916f1a91c6d94a4e323eb431a469e9cc434f524e45545c41646d696e6973747261746f72
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x8467475784755ddfbef9adc7a7522e51
[peap] Got tunneled Access-Challenge
[peap] >>> Unknown TLS version [length 0005]
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 237 to 10.0.10.2 port 2897
        EAP-Message = 0x0112004b190017030100401f14174cc5828e40e200757de75fe171b41dd2e9e8ecaf6294d31756849c58ae1a4cf00aec1b5a5785e2b5b32b78b8ed791d07cc57d6b5d559d146e93c6e7ecf
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xb80ddd5cbe1fc4b706d6087b7083c2b4
Finished request 6.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.0.10.2 port 2897, id=238, length=305
        User-Name = "CORNET\\Administrator"
        Framed-MTU = 1450
        EAP-Message = 0x0212006b19001703010060c62ba8a47767fef0c328d4db9c33147720b3a043b229c5d86454d6f20c9a9eee815f4f71e330321d548269663cb66da19ee99431db1dbf09ec4728b15909b3e9d5219f745738d58a3df228557f9c1dafb1fbdd85ef8d8ee575db46b24fe08861
        Message-Authenticator = 0xe3d33131e22c8175aa29fc234aba3768
        NAS-IP-Address = 10.0.10.2
        NAS-Identifier = "Switch_2"
        NAS-Port = 16830465
        NAS-Port-Id = "slot=1;subslot=0;port=13;vlanid=1"
        NAS-Port-Type = Ethernet
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Calling-Station-Id = "00-22-4D-AB-2D-19"
        Acct-Session-Id = "1000429113760010"
        State = 0xb80ddd5cbe1fc4b706d6087b7083c2b4
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[digest] = noop
[ntdomain] Looking up realm "CORNET" for User-Name = "CORNET\Administrator"
[ntdomain] No such realm "CORNET"
++[ntdomain] = noop
[eap] EAP packet type response id 18 length 107
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] <<< Unknown TLS version [length 0005]
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state phase2
[peap] EAP type mschapv2
[peap] Got tunneled request
        EAP-Message = 0x0212004f1a0212004a314764102663d4a6b703e33d2f38496b38000000000000000047dddb601f337b40cbedc92fe89619468b70254dd2a7590e00434f524e45545c41646d696e6973747261746f72
server  {
[peap] Setting User-Name to CORNET\Administrator
Sending tunneled request
        EAP-Message = 0x0212004f1a0212004a314764102663d4a6b703e33d2f38496b38000000000000000047dddb601f337b40cbedc92fe89619468b70254dd2a7590e00434f524e45545c41646d696e6973747261746f72
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "CORNET\\Administrator"
        State = 0x8467475784755ddfbef9adc7a7522e51
server inner-tunnel {
# Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
+group authorize {
++[chap] = noop
[ldap] performing user authorization for CORNET\Administrator
[ldap]  expand: (sAMAccountName=%{mschap:User-Name}) -> (sAMAccountName=Administrator)
[ldap]  expand: ou=Benutzer,dc=cornet,dc=local -> ou=Benutzer,dc=cornet,dc=local
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in ou=Benutzer,dc=cornet,dc=local, with filter (sAMAccountName=Administrator)
  [ldap] object not found
[ldap] search failed
  [ldap] ldap_release_conn: Release Id: 0
++[ldap] = notfound
++[mschap] = noop
[ntdomain] Looking up realm "CORNET" for User-Name = "CORNET\Administrator"
[ntdomain] No such realm "CORNET"
++[ntdomain] = noop
++update control {
++} # update control = noop
[eap] EAP packet type response id 18 length 79
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
  [ldap] Entering ldap_groupcmp()
[files]         expand: ou=Benutzer,dc=cornet,dc=local -> ou=Benutzer,dc=cornet,dc=local
[files]         expand: (sAMAccountName=%{mschap:User-Name}) -> (sAMAccountName=Administrator)
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in ou=Benutzer,dc=cornet,dc=local, with filter (sAMAccountName=Administrator)
  [ldap] object not found
rlm_ldap::ldap_groupcmp: search failed
  [ldap] ldap_release_conn: Release Id: 0
++[files] = noop
[ldap] performing user authorization for CORNET\Administrator
[ldap]  expand: (sAMAccountName=%{mschap:User-Name}) -> (sAMAccountName=Administrator)
[ldap]  expand: ou=Benutzer,dc=cornet,dc=local -> ou=Benutzer,dc=cornet,dc=local
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in ou=Benutzer,dc=cornet,dc=local, with filter (sAMAccountName=Administrator)
  [ldap] object not found
[ldap] search failed
  [ldap] ldap_release_conn: Release Id: 0
++[ldap] = notfound
++[expiration] = noop
++[logintime] = noop
++[pap] = noop
+} # group authorize = updated
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[mschapv2] # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
[mschapv2] +group MS-CHAP {
[mschap] Creating challenge hash with username: Administrator
[mschap] Client is using MS-CHAPv2 for Administrator, we need NT-Password
[mschap]        expand: %{Stripped-User-Name} ->
[mschap]        ... expanding second conditional
[mschap]        expand: %{User-Name} -> CORNET\\Administrator
[mschap]        expand: %{%{User-Name}:-None} -> CORNET\\Administrator
[mschap]        expand: --username=%{%{Stripped-User-Name}:-%{%{User-Name}:-None}} -> --username=CORNET\\Administrator
[mschap] Creating challenge hash with username: Administrator
[mschap]        expand: %{mschap:Challenge} -> 4adcd405e7337023
[mschap]        expand: --challenge=%{%{mschap:Challenge}:-00} -> --challenge=4adcd405e7337023
[mschap]        expand: %{mschap:NT-Response} -> 47dddb601f337b40cbedc92fe89619468b70254dd2a7590e
[mschap]        expand: --nt-response=%{%{mschap:NT-Response}:-00} -> --nt-response=47dddb601f337b40cbedc92fe89619468b70254dd2a7590e
Exec output: Logon failure (0xc000006d)
Exec plaintext: Logon failure (0xc000006d)
[mschap] Exec: program returned: 1
[mschap] External script failed.
[mschap] FAILED: MS-CHAP2-Response is incorrect
++[mschap] = reject
+} # group MS-CHAP = reject
[eap] Freeing handler
++[eap] = reject
+} # group authenticate = reject
Failed to authenticate the user.
Using Post-Auth-Type Reject
# Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
+group REJECT {
[attr_filter.access_reject]     expand: %{User-Name} -> CORNET\\Administrator
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] = updated
+} # group REJECT = updated
} # server inner-tunnel
[peap] Got tunneled reply code 3
        MS-CHAP-Error = "\022E=691 R=1"
        EAP-Message = 0x04120004
        Message-Authenticator = 0x00000000000000000000000000000000
[peap] Got tunneled reply RADIUS code Access-Reject
        MS-CHAP-Error = "\022E=691 R=1"
        EAP-Message = 0x04120004
        Message-Authenticator = 0x00000000000000000000000000000000
[peap] Tunneled authentication was rejected.
[peap] FAILURE
[peap] >>> Unknown TLS version [length 0005]
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 238 to 10.0.10.2 port 2897
        EAP-Message = 0x0113002b19001703010020034aa81fdd553dcbd8d2abd349b36dc21d00f68571e1ed98dfa1da7494bf7021
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xb80ddd5cbf1ec4b706d6087b7083c2b4
Finished request 7.
Going to the next request
Waking up in 4.3 seconds.
rad_recv: Access-Request packet from host 10.0.10.2 port 2897, id=239, length=241
        User-Name = "CORNET\\Administrator"
        Framed-MTU = 1450
        EAP-Message = 0x0213002b19001703010020ce3251e3b7ad30facad36a0d2e90bc3d481930f9721a0317ae58b5e1d4cb4b03
        Message-Authenticator = 0x8c49188ed98543fb50467302c0362bf2
        NAS-IP-Address = 10.0.10.2
        NAS-Identifier = "Switch_2"
        NAS-Port = 16830465
        NAS-Port-Id = "slot=1;subslot=0;port=13;vlanid=1"
        NAS-Port-Type = Ethernet
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Calling-Station-Id = "00-22-4D-AB-2D-19"
        Acct-Session-Id = "1000429113760010"
        State = 0xb80ddd5cbf1ec4b706d6087b7083c2b4
# Executing section authorize from file /etc/freeradius/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[digest] = noop
[ntdomain] Looking up realm "CORNET" for User-Name = "CORNET\Administrator"
[ntdomain] No such realm "CORNET"
++[ntdomain] = noop
[eap] EAP packet type response id 19 length 43
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] <<< Unknown TLS version [length 0005]
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state send tlv failure
[peap] Received EAP-TLV response.
[peap]  The users session was previously rejected: returning reject (again.)
[peap]  *** This means you need to read the PREVIOUS messages in the debug output
[peap]  *** to find out the reason why the user was rejected.
[peap]  *** Look for "reject" or "fail".  Those earlier messages will tell you.
[peap]  *** what went wrong, and how to fix the problem.
[eap] Handler failed in EAP/peap
[eap] Failed in EAP select
++[eap] = invalid
+} # group authenticate = invalid
Failed to authenticate the user.
Using Post-Auth-Type Reject
# Executing group from file /etc/freeradius/sites-enabled/default
+group REJECT {
[attr_filter.access_reject]     expand: %{User-Name} -> CORNET\\Administrator
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] = updated
+} # group REJECT = updated
Delaying reject of request 8 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 8
Sending Access-Reject of id 239 to 10.0.10.2 port 2897
        EAP-Message = 0x04130004
        Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 3.3 seconds.
Cleaning up request 0 ID 231 with timestamp +11
Waking up in 0.1 seconds.
Cleaning up request 1 ID 232 with timestamp +11
Cleaning up request 2 ID 233 with timestamp +11
Cleaning up request 3 ID 234 with timestamp +11
Cleaning up request 4 ID 235 with timestamp +11
Cleaning up request 5 ID 236 with timestamp +11
Cleaning up request 6 ID 237 with timestamp +11
Waking up in 0.4 seconds.
Cleaning up request 7 ID 238 with timestamp +11
Waking up in 1.0 seconds.
Cleaning up request 8 ID 239 with timestamp +12
Ready to process requests.


I also have a output of the debug when authentication went successful. The main difference I see is in the mschap-section - there is no error and everything is allright.
Here the short excerpt of the mschap-section of the successful authentication:

[mschapv2] # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
[mschapv2] +group MS-CHAP {
[mschap] Creating challenge hash with username: administrator
[mschap] Client is using MS-CHAPv2 for administrator, we need NT-Password
[mschap]        expand: %{Stripped-User-Name} ->
[mschap]        ... expanding second conditional
[mschap]        expand: %{User-Name} -> administrator
[mschap]        expand: %{%{User-Name}:-None} -> administrator
[mschap]        expand: --username=%{%{Stripped-User-Name}:-%{%{User-Name}:-None}} -> --username=administrator
[mschap] Creating challenge hash with username: administrator
[mschap]        expand: %{mschap:Challenge} -> 3564d0819818bbda
[mschap]        expand: --challenge=%{%{mschap:Challenge}:-00} -> --challenge=3564d0819818bbda
[mschap]        expand: %{mschap:NT-Response} -> c1c7cd76b5a207f96903fdf5dcba5a7fbd00723b3acf3f79
[mschap]        expand: --nt-response=%{%{mschap:NT-Response}:-00} -> --nt-response=c1c7cd76b5a207f96903fdf5dcba5a7fbd00723b3acf3f79
Exec output: NT_KEY: 57844B8153522FC1A76F101B98CC9E8F
Exec plaintext: NT_KEY: 57844B8153522FC1A76F101B98CC9E8F
[mschap] Exec: program returned: 0
[mschap] adding MS-CHAPv2 MPPE keys
++[mschap] = ok
+} # group MS-CHAP = ok
MSCHAP Success



-----Ursprüngliche Nachricht-----
Von: Freeradius-Users [mailto:freeradius-users-bounces+andreas.zwinzscher=bod-datennetze.de at lists.freeradius.org] Im Auftrag von Alan DeKok
Gesendet: Mittwoch, 24. August 2016 15:48
An: FreeRadius users mailing list <freeradius-users at lists.freeradius.org>
Betreff: Re: LDAP / mschap Error

On Aug 24, 2016, at 9:32 AM, Andreas Zwinzscher <andreas.zwinzscher at bod-datennetze.de> wrote:
> The clients are using Windows 7 , 8.1 or 10. If I do a manual login with username/password the authentication works well. But if I activate the option to use the windows login informations, the authentication fails. I got an MSCHAP error. So I tried a few things to figure out where the problem is.

  Please post the debug output as suggested in the FAQ, "man" page, and web pages.

> Well...this also works. I recieve an access-accept packet. So I studied the logs more in detail and found out, that the first letter of the username is case sensitive. So I did a new test:
> 
> radtest -t mschap DOMAIN//Username password localhost 0 testing123
> 
> And here I got the same mschap-error as with the (automatic) windows authentication. 

  What is the error?  Please post the FULL debug log.

  Alan DeKok.


-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html



More information about the Freeradius-Users mailing list