freeradius 2.1.7 PEAP mschapv2 invalid parameter

12 Aug 2011

      Hi. I'm trying to set up PEAP authentication with AD on freeradius 2.1.7
(centos).

Everything in users file is commented out (including DEFAULTs) except the
test
user "bob" who authenticates successfully.

Auth requests fail in mschap module with "external program" complaining
about an
invalid parameter (which I cannot pinpoint).

radiusd -X:

FreeRADIUS Version 2.1.7, for host i686-redhat-linux-gnu, built on Mar 31
2010 at 00:25:31
Copyright (C) 1999-2009 The FreeRADIUS server project and contributors.
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE.
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License v2.
Starting - reading configuration files ...
including configuration file /etc/raddb/radiusd.conf
including configuration file /etc/raddb/proxy.conf
including configuration file /etc/raddb/clients.conf
including files in directory /etc/raddb/modules/
including configuration file /etc/raddb/modules/files
including configuration file /etc/raddb/modules/expiration
including configuration file /etc/raddb/modules/sradutmp
including configuration file /etc/raddb/modules/wimax
including configuration file /etc/raddb/modules/realm
including configuration file /etc/raddb/modules/sql_log
including configuration file /etc/raddb/modules/inner-eap
including configuration file /etc/raddb/modules/detail
including configuration file /etc/raddb/modules/smbpasswd
including configuration file /etc/raddb/modules/preprocess
including configuration file /etc/raddb/modules/unix
including configuration file /etc/raddb/modules/mschap
including configuration file /etc/raddb/modules/acct_unique
including configuration file /etc/raddb/modules/logintime
including configuration file /etc/raddb/modules/digest
including configuration file /etc/raddb/modules/checkval
including configuration file /etc/raddb/modules/mac2vlan
including configuration file /etc/raddb/modules/chap
including configuration file /etc/raddb/modules/counter
including configuration file /etc/raddb/modules/ippool
including configuration file /etc/raddb/modules/policy
including configuration file /etc/raddb/modules/pam
including configuration file /etc/raddb/modules/cui
including configuration file /etc/raddb/modules/radutmp
including configuration file /etc/raddb/modules/exec
including configuration file /etc/raddb/modules/detail.example.com
including configuration file /etc/raddb/modules/sqlcounter_expire_on_login
including configuration file /etc/raddb/modules/detail.log
including configuration file /etc/raddb/modules/linelog
including configuration file /etc/raddb/modules/smsotp
including configuration file /etc/raddb/modules/echo
including configuration file /etc/raddb/modules/pap
including configuration file /etc/raddb/modules/perl
including configuration file /etc/raddb/modules/otp
including configuration file /etc/raddb/modules/passwd
including configuration file /etc/raddb/modules/attr_rewrite
including configuration file /etc/raddb/modules/mac2ip
including configuration file /etc/raddb/modules/expr
including configuration file /etc/raddb/modules/always
including configuration file /etc/raddb/modules/etc_group
including configuration file /etc/raddb/modules/attr_filter
including configuration file /etc/raddb/eap.conf
including configuration file /etc/raddb/policy.conf
including files in directory /etc/raddb/sites-enabled/
including configuration file /etc/raddb/sites-enabled/control-socket
including configuration file /etc/raddb/sites-enabled/inner-tunnel
including configuration file /etc/raddb/sites-enabled/default
group = radiusd
user = radiusd
including dictionary file /etc/raddb/dictionary
main {
    prefix = "/usr"
    localstatedir = "/var"
    logdir = "/var/log/radius"
    libdir = "/usr/lib/freeradius"
    radacctdir = "/var/log/radius/radacct"
    hostname_lookups = no
    max_request_time = 30
    cleanup_delay = 5
    max_requests = 1024
    allow_core_dumps = no
    pidfile = "/var/run/radiusd/radiusd.pid"
    checkrad = "/usr/sbin/checkrad"
    debug_level = 0
    proxy_requests = yes
 log {
    stripped_names = no
    auth = no
    auth_badpass = no
    auth_goodpass = no
 }
 security {
    max_attributes = 200
    reject_delay = 1
    status_server = yes
 }
}
radiusd: #### Loading Realms and Home Servers ####
 proxy server {
    retry_delay = 5
    retry_count = 3
    default_fallback = no
    dead_time = 120
    wake_all_if_all_dead = no
 }
 realm CITYHALL {
 }
 realm LOCAL {
 }
 home_server localhost {
    ipaddr = 127.0.0.1
    port = 1812
    type = "auth"
    secret = "testing123"
    response_window = 20
    max_outstanding = 65536
    require_message_authenticator = no
    zombie_period = 40
    status_check = "status-server"
    ping_interval = 30
    check_interval = 30
    num_answers_to_alive = 3
    num_pings_to_alive = 3
    revive_interval = 120
    status_check_timeout = 4
    irt = 2
    mrt = 16
    mrc = 5
    mrd = 30
 }
 home_server_pool my_auth_failover {
    type = fail-over
    home_server = localhost
 }
radiusd: #### Loading Clients ####
 client localhost {
    ipaddr = 127.0.0.1
    require_message_authenticator = no
    secret = "testing123"
    nastype = "other"
 }
 client 10.39.0.0/24 {
    require_message_authenticator = no
    secret = "cityhall11"
    nastype = "other"
 }
radiusd: #### Instantiating modules ####
 instantiate {
 Module: Linked to module rlm_exec
 Module: Instantiating exec
  exec {
    wait = no
    input_pairs = "request"
    shell_escape = yes
  }
 Module: Linked to module rlm_expr
 Module: Instantiating expr
 Module: Linked to module rlm_expiration
 Module: Instantiating expiration
  expiration {
    reply-message = "Password Has Expired  "
  }
 Module: Linked to module rlm_logintime
 Module: Instantiating logintime
  logintime {
    reply-message = "You are calling outside your allowed timespan  "
    minimum-timeout = 60
  }
 }
radiusd: #### Loading Virtual Servers ####
server inner-tunnel {
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Linked to module rlm_pap
 Module: Instantiating pap
  pap {
    encryption_scheme = "auto"
    auto_header = no
  }
 Module: Linked to module rlm_chap
 Module: Instantiating chap
 Module: Linked to module rlm_mschap
 Module: Instantiating mschap
  mschap {
    use_mppe = yes
    require_encryption = yes
    require_strong = no
    with_ntdomain_hack = yes
    ntlm_auth = "/usr/bin/ntlm_auth --request-nt-key
--username=%{mschap:User-Name} --domain=%{mschap:NT-Domain}
--challenge=%{mschap:Challenge:-00} --nt-response=%{mschap:NT-Response:-00}"
  }
 Module: Linked to module rlm_unix
 Module: Instantiating unix
  unix {
    radwtmp = "/var/log/radius/radwtmp"
  }
 Module: Linked to module rlm_eap
 Module: Instantiating eap
  eap {
    default_eap_type = "peap"
    timer_expire = 60
    ignore_unknown_eap_types = no
    cisco_accounting_username_bug = no
    max_sessions = 2048
  }
 Module: Linked to sub-module rlm_eap_md5
 Module: Instantiating eap-md5
 Module: Linked to sub-module rlm_eap_leap
 Module: Instantiating eap-leap
 Module: Linked to sub-module rlm_eap_gtc
 Module: Instantiating eap-gtc
   gtc {
    challenge = "Password: "
    auth_type = "PAP"
   }
 Module: Linked to sub-module rlm_eap_tls
 Module: Instantiating eap-tls
   tls {
    rsa_key_exchange = no
    dh_key_exchange = yes
    rsa_key_length = 512
    dh_key_length = 512
    verify_depth = 0
    pem_file_type = yes
    private_key_file = "/etc/raddb/certs/radiuskey.pem"
    certificate_file = "/etc/raddb/certs/radius.pem"
    CA_file = "/etc/raddb/certs/ca.pem"
    private_key_password = "server2003"
    dh_file = "/etc/raddb/certs/dh"
    random_file = "/etc/raddb/certs/random"
    fragment_size = 1024
    include_length = yes
    check_crl = no
    cipher_list = "DEFAULT"
    cache {
    enable = no
    lifetime = 24
    max_entries = 255
    }
   }
 Module: Linked to sub-module rlm_eap_ttls
 Module: Instantiating eap-ttls
   ttls {
    default_eap_type = "peap"
    copy_request_to_tunnel = no
    use_tunneled_reply = no
    virtual_server = "inner-tunnel"
    include_length = yes
   }
 Module: Linked to sub-module rlm_eap_peap
 Module: Instantiating eap-peap
   peap {
    default_eap_type = "mschapv2"
    copy_request_to_tunnel = yes
    use_tunneled_reply = yes
    proxy_tunneled_request_as_eap = yes
    virtual_server = "inner-tunnel"
   }
 Module: Linked to sub-module rlm_eap_mschapv2
 Module: Instantiating eap-mschapv2
   mschapv2 {
    with_ntdomain_hack = no
   }
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_realm
 Module: Instantiating ntdomain
  realm ntdomain {
    format = "prefix"
    delimiter = "\"
    ignore_default = no
    ignore_null = no
  }
 Module: Linked to module rlm_files
 Module: Instantiating files
  files {
    usersfile = "/etc/raddb/users"
    acctusersfile = "/etc/raddb/acct_users"
    preproxy_usersfile = "/etc/raddb/preproxy_users"
    compat = "no"
  }
 Module: Checking session {...} for more modules to load
 Module: Linked to module rlm_radutmp
 Module: Instantiating radutmp
  radutmp {
    filename = "/var/log/radius/radutmp"
    username = "%{User-Name}"
    case_sensitive = yes
    check_with_nas = yes
    perm = 384
    callerid = yes
  }
 Module: Checking pre-proxy {...} for more modules to load
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 Module: Linked to module rlm_attr_filter
 Module: Instantiating attr_filter.access_reject
  attr_filter attr_filter.access_reject {
    attrsfile = "/etc/raddb/attrs.access_reject"
    key = "%{User-Name}"
  }
 } # modules
} # server
server {
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_preprocess
 Module: Instantiating preprocess
  preprocess {
    huntgroups = "/etc/raddb/huntgroups"
    hints = "/etc/raddb/hints"
    with_ascend_hack = no
    ascend_channels_per_line = 23
    with_ntdomain_hack = no
    with_specialix_jetstream_hack = no
    with_cisco_vsa_hack = no
    with_alvarion_vsa_hack = no
  }
 Module: Instantiating suffix
  realm suffix {
    format = "suffix"
    delimiter = "@"
    ignore_default = no
    ignore_null = no
  }
 Module: Checking preacct {...} for more modules to load
 Module: Linked to module rlm_acct_unique
 Module: Instantiating acct_unique
  acct_unique {
    key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address,
NAS-Port"
  }
 Module: Checking accounting {...} for more modules to load
 Module: Linked to module rlm_detail
 Module: Instantiating detail
  detail {
    detailfile =
"/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
    header = "%t"
    detailperm = 384
    dirperm = 493
    locking = no
    log_packet_header = no
  }
 Module: Instantiating attr_filter.accounting_response
  attr_filter attr_filter.accounting_response {
    attrsfile = "/etc/raddb/attrs.accounting_response"
    key = "%{User-Name}"
  }
 Module: Checking session {...} for more modules to load
 Module: Checking pre-proxy {...} for more modules to load
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 } # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
    type = "auth"
    ipaddr = *
    port = 0
}
listen {
    type = "acct"
    ipaddr = *
    port = 0
}
listen {
    type = "control"
 listen {
    socket = "/var/run/radiusd/radiusd.sock"
 }
}
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Listening on command file /var/run/radiusd/radiusd.sock
Listening on proxy address * port 1814
Ready to process requests.
rad_recv: Access-Request packet from host 10.39.0.31 port 8021, id=234,
length=245
    Framed-MTU = 1466
    NAS-IP-Address = 10.39.0.31
    NAS-Identifier = "D-Link"
    User-Name = "CITYHALL\\РђРґРјРёРЅРёСЃС‚СЂР°С‚РѕСЂ"
    Service-Type = Framed-User
    NAS-Port = 25
    NAS-Port-Type = Ethernet
    NAS-Port-Id = "ether25_385"
    Called-Station-Id = "00-15-e9-89-df-33"
    Calling-Station-Id = "90-e6-ba-19-a6-b4"
    Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
    EAP-Message =
0x02010028014349545948414c4c5cd090d0b4d0bcd0b8d0bdd0b8d181d182d180d0b0d182d0bed180
    Message-Authenticator = 0x490abe1078ee3c188763003c6e43e205
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 1 length 40
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "CITYHALL\Р?РґРјРёРЅРёС?С?С?Р°С?РѕС?",
looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[ntdomain] Looking up realm "CITYHALL" for User-Name =
"CITYHALL\Р?РґРјРёРЅРёС?С?С?Р°С?РѕС?"
[ntdomain] Found realm "CITYHALL"
[ntdomain] Adding Stripped-User-Name = "Р?РґРјРёРЅРёС?С?С?Р°С?РѕС?"
[ntdomain] Adding Realm = "CITYHALL"
[ntdomain] Authentication realm is LOCAL.
++[ntdomain] returns ok
++[unix] returns notfound
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication
may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 234 to 10.39.0.31 port 8021
    EAP-Message = 0x010200061920
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x8d379fb08d3586c6b10255917bdeca99
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.39.0.31 port 8021, id=235,
length=310
    Framed-MTU = 1466
    NAS-IP-Address = 10.39.0.31
    NAS-Identifier = "D-Link"
    User-Name = "CITYHALL\\РђРґРјРёРЅРёСЃС‚СЂР°С‚РѕСЂ"
    Service-Type = Framed-User
    NAS-Port = 25
    NAS-Port-Type = Ethernet
    NAS-Port-Id = "ether25_385"
    Called-Station-Id = "00-15-e9-89-df-33"
    Calling-Station-Id = "90-e6-ba-19-a6-b4"
    Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
    State = 0x8d379fb08d3586c6b10255917bdeca99
    EAP-Message =
0x0202005719800000004d16030100480100004403014e44cca9cfd29aea47fb1b5aac0d1e4525a05de3cf196712e5fcd92c5f9f15c500001600040005000a0009006400620003000600130012006301000005ff01000100
    Message-Authenticator = 0x38c1ccd58c27c231538169fa80f1cdee
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 2 length 87
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 77
[peap] Length Included
[peap] eaptls_verify returned 11
[peap]     (other): before/accept initialization
[peap]     TLS_accept: before/accept initialization
[peap] <<< TLS 1.0 Handshake [length 0048], ClientHello
[peap]     TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 0031], ServerHello
[peap]     TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 0795], Certificate
[peap]     TLS_accept: SSLv3 write certificate A
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[peap]     TLS_accept: SSLv3 write server done A
[peap]     TLS_accept: SSLv3 flush data
[peap]     TLS_accept: Need to read more data: SSLv3 read client certificate
A
In SSL Handshake Phase
In SSL Accept mode
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 235 to 10.39.0.31 port 8021
    EAP-Message =
0x0103040019c0000007d916030100310200002d03014e44ce2e9ba714cd6ce2c2b6f65ff2b111d047de00f9fc1ba16448194c9295b0000004000005ff0100010016030107950b00079100078e0002ea308202e6308201cea003020102020101300d06092a864886f70d0101050500304a31133011060a0992268993f22c6401191603676f7631183016060a0992268993f22c64011916086369747968616c6c31193017060355040313104369747968616c6c20726f6f74204341301e170d3131303532373039303335365a170d3132303532363039303335365a30818d310b3009060355040613025255311430120603550408130b4b616c696e696e67
    EAP-Message =
0x726164311430120603550407130b4b616c696e696e677261643111300f060355040a13084349545948414c4c310d300b060355040b130443494b54310f300d06035504031306726164697573311f301d06092a864886f70d0109011610616665646f746f76406b6c67642e727530819f300d06092a864886f70d010101050003818d0030818902818100a9bd01fbcd1c9a73ed78777a5e47d6cd1b1a2a60db68bcde416c57bb50d06dcc5fa138befe517fda4a711a0814b4c00712b87475f48fbdfdfac7c35f0ca6ae315722d0c120d0e4070acd700dca4e38f05dcfa6900c86bc967018524d89c568dde6a6735badfa6395a5f593db7405433859f7bd
    EAP-Message =
0xa737106bb78cf4b142fbc7ebf10203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010105050003820101001c15824d2f157cae2a05b2c8d789c4f5a3749e5fb167b9da4db29ce3516e3652a8f22be40dcc92501379ac9735107470f47a28298df01d50eed08e74a5ec221d7f83723d5cb80fbfb5f0b9da6efa688e6f15aefe1219a161418e99ce38d305bb0b2a29078f063ba77ab1066e32067f0aaa6d3043089e146016c4a3eda16e99df4eab49d4ae34811d1e34538ea010d40f4a9e0d077fda374798ede64caab96c71b74c0edf1f47c0c196335974c49e30edaf9ff4935998553a3d86a8bee30b
    EAP-Message =
0x754c01c0196a66b0e0819a55e41eab738bf64e15412245297cffd3b72320e03d314e7a9e086341d5ec412176d1e117484759070d24209bcadf7b9c21feeb74b1b33d00049e3082049a30820382a00302010202102fad09775656c3b0478e136a8c5e2f49300d06092a864886f70d0101050500304a31133011060a0992268993f22c6401191603676f7631183016060a0992268993f22c64011916086369747968616c6c31193017060355040313104369747968616c6c20726f6f74204341301e170d3131303132313130333132375a170d3136303132313130333833325a304a31133011060a0992268993f22c6401191603676f7631183016060a09
    EAP-Message = 0x92268993f22c640119160863
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x8d379fb08c3486c6b10255917bdeca99
Finished request 1.
Going to the next request
Waking up in 4.6 seconds.
rad_recv: Access-Request packet from host 10.39.0.31 port 8021, id=236,
length=229
    Framed-MTU = 1466
    NAS-IP-Address = 10.39.0.31
    NAS-Identifier = "D-Link"
    User-Name = "CITYHALL\\РђРґРјРёРЅРёСЃС‚СЂР°С‚РѕСЂ"
    Service-Type = Framed-User
    NAS-Port = 25
    NAS-Port-Type = Ethernet
    NAS-Port-Id = "ether25_385"
    Called-Station-Id = "00-15-e9-89-df-33"
    Calling-Station-Id = "90-e6-ba-19-a6-b4"
    Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
    State = 0x8d379fb08c3486c6b10255917bdeca99
    EAP-Message = 0x020300061900
    Message-Authenticator = 0x9883ed0aaa11a28c464901ada6337fdb
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 3 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering 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] returns handled
Sending Access-Challenge of id 236 to 10.39.0.31 port 8021
    EAP-Message =
0x010403e9190069747968616c6c31193017060355040313104369747968616c6c20726f6f7420434130820122300d06092a864886f70d01010105000382010f003082010a0282010100d135657ca57b1d317762f095fb46ffc5dd19e111a22f9de73622decfd2fc1682ba69f6d2d30a8b2cc4d3ca04b7eda61a4e5e45da02ae2a85bbf1b5c18a328e9d61f115bc16cdd048cf888aec1233d76dfb873a64df7bd89847c891deb710119f15e460b43a38cb7521d83925eff7ba75d9ab0c5b25d9de4db2164d118c573ddf378b794c1d53d97e0de48afb074103a6370d673cfc9f3ec5399fce8bb43072d9cf06dea65a5579cfbb0a2e7c39624836396a90f2
    EAP-Message =
0x9c08ce5273a8637ab8c90607392b530c4dfad4834a29e84c74aaa6affee215dc483ac3adc07f0e5d696dd38dce89cc46a45dbd981a9ebdb8439bd277f14b58d230eb97057a27134018bc54c70203010001a382017a30820176301306092b060104018237140204061e0400430041300b0603551d0f040403020146300f0603551d130101ff040530030101ff301d0603551d0e04160414b593101da731658da59dca69f6caf9fd70389f0d3082010e0603551d1f04820105308201013081fea081fba081f88681b86c6461703a2f2f2f434e3d4369747968616c6c253230726f6f7425323043412c434e3d6264632c434e3d4344502c434e3d5075626c
    EAP-Message =
0x69632532304b657925323053657276696365732c434e3d53657276696365732c434e3d436f6e66696775726174696f6e2c44433d6369747968616c6c2c44433d676f763f63657274696669636174655265766f636174696f6e4c6973743f626173653f6f626a656374436c6173733d63524c446973747269627574696f6e506f696e74863b687474703a2f2f6264632e6369747968616c6c2e676f762f43657274456e726f6c6c2f4369747968616c6c253230726f6f7425323043412e63726c301006092b06010401823715010403020100300d06092a864886f70d01010505000382010100290eb63146fa57bc17e2ad53cc23cfddbd401bec6e9dbd
    EAP-Message =
0x9830c126145da35ba20446567798f7448a1c2e246f96b92945059fd26a169768a3018e5862ce5f532680c81c19bf3ef62f054bb59140162dc340ac5bfc9e5ec8dd753f4fb85d63515d3318b5dcde064322d5ef1d188405905fcb036c3e0e1d0781fa3b359b0dbc033d788147b15e8cd8cb2112fdb01fe4fa13fe5e1adeae0fb16bd07d1757d562cd313c6c7ffbaa6b27e05e443e191ad9ee9ca78dbcfc1d64c5c5b254abbf680eb0afd3ac15d110277e9bc268324b9602a3a90ddf24d032daa1fd4a29838bfbf748533ae570380ff88bd7aa0e82dc3b5317208d880ec71d3b1d5080e624ac882c737616030100040e000000
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x8d379fb08f3386c6b10255917bdeca99
Finished request 2.
Going to the next request
Waking up in 4.2 seconds.
rad_recv: Access-Request packet from host 10.39.0.31 port 8021, id=237,
length=415
    Framed-MTU = 1466
    NAS-IP-Address = 10.39.0.31
    NAS-Identifier = "D-Link"
    User-Name = "CITYHALL\\РђРґРјРёРЅРёСЃС‚СЂР°С‚РѕСЂ"
    Service-Type = Framed-User
    NAS-Port = 25
    NAS-Port-Type = Ethernet
    NAS-Port-Id = "ether25_385"
    Called-Station-Id = "00-15-e9-89-df-33"
    Calling-Station-Id = "90-e6-ba-19-a6-b4"
    Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
    State = 0x8d379fb08f3386c6b10255917bdeca99
    EAP-Message =
0x020400c01980000000b61603010086100000820080236bdcc292f96b0adae8ef253c3cb67e3f890dfb46400795d06b8dfbeb45c6e0dc5b17ea6fec5e0d05d30b85beeba725430d3afc5b51eb415097ceeb3f2a6fde3338447dd7e798dc5cb6fbb1decb68aa8aa3d12eaf7737c16db714e482e1041769e3a101bd6493095f54b534b42c23a3f71f9ed5dfc7f0b1bf014154c2f38fd814030100010116030100206bf24afa2fcbee2b43b902dc86cc3ac4a01c7e898133f4acd87c2eba5aa4b9f8
    Message-Authenticator = 0xb247a94690e297dde906468db367fbb8
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 4 length 192
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 182
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange
[peap]     TLS_accept: SSLv3 read client key exchange A
[peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[peap] <<< TLS 1.0 Handshake [length 0010], Finished
[peap]     TLS_accept: SSLv3 read finished A
[peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[peap]     TLS_accept: SSLv3 write change cipher spec A
[peap] >>> TLS 1.0 Handshake [length 0010], Finished
[peap]     TLS_accept: SSLv3 write finished A
[peap]     TLS_accept: SSLv3 flush data
[peap]     (other): SSL negotiation finished successfully
SSL Connection Established
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 237 to 10.39.0.31 port 8021
    EAP-Message =
0x01050031190014030100010116030100209a715dd6ad5982ce3989d9ae57c213029d6e204b1ed737b033ed07a84aaff445
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x8d379fb08e3286c6b10255917bdeca99
Finished request 3.
Going to the next request
Waking up in 3.9 seconds.
rad_recv: Access-Request packet from host 10.39.0.31 port 8021, id=238,
length=229
    Framed-MTU = 1466
    NAS-IP-Address = 10.39.0.31
    NAS-Identifier = "D-Link"
    User-Name = "CITYHALL\\РђРґРјРёРЅРёСЃС‚СЂР°С‚РѕСЂ"
    Service-Type = Framed-User
    NAS-Port = 25
    NAS-Port-Type = Ethernet
    NAS-Port-Id = "ether25_385"
    Called-Station-Id = "00-15-e9-89-df-33"
    Calling-Station-Id = "90-e6-ba-19-a6-b4"
    Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
    State = 0x8d379fb08e3286c6b10255917bdeca99
    EAP-Message = 0x020500061900
    Message-Authenticator = 0x517d7879c30312c2bfb56144c18ab9c4
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 5 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering 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
++[eap] returns handled
Sending Access-Challenge of id 238 to 10.39.0.31 port 8021
    EAP-Message =
0x01060020190017030100157002069875e353f5077b12fa9c7f4e4f6b94a82296
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x8d379fb0893186c6b10255917bdeca99
Finished request 4.
Going to the next request
Waking up in 3.5 seconds.
rad_recv: Access-Request packet from host 10.39.0.31 port 8021, id=239,
length=273
    Framed-MTU = 1466
    NAS-IP-Address = 10.39.0.31
    NAS-Identifier = "D-Link"
    User-Name = "CITYHALL\\РђРґРјРёРЅРёСЃС‚СЂР°С‚РѕСЂ"
    Service-Type = Framed-User
    NAS-Port = 25
    NAS-Port-Type = Ethernet
    NAS-Port-Id = "ether25_385"
    Called-Station-Id = "00-15-e9-89-df-33"
    Calling-Station-Id = "90-e6-ba-19-a6-b4"
    Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
    State = 0x8d379fb0893186c6b10255917bdeca99
    EAP-Message =
0x0206003219001703010027a6784f0a6407aa8060b50026ac58d5f4dc07b743cf774080b0e4de533093eda7d924b25de04dec
    Message-Authenticator = 0xda9123f296bc3c3a0d63639b2a7fbc55
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 6 length 50
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering 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] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Identity - CITYHALL\Администратор
[peap] Got tunneled request
    EAP-Message = 0x0206001b014349545948414c4c5cc0e4ece8ede8f1f2f0e0f2eef0
server  {
  PEAP: Got tunneled identity of CITYHALL\Администратор
  PEAP: Setting default EAP type for tunneled EAP session.
  PEAP: Setting User-Name to CITYHALL\Администратор
Sending tunneled request
    EAP-Message = 0x0206001b014349545948414c4c5cc0e4ece8ede8f1f2f0e0f2eef0
    FreeRADIUS-Proxied-To = 127.0.0.1
    User-Name =
"CITYHALL\\\300\344\354\350\355\350\361\362\360\340\362\356\360"
    Framed-MTU = 1466
    NAS-IP-Address = 10.39.0.31
    NAS-Identifier = "D-Link"
    Service-Type = Framed-User
    NAS-Port = 25
    NAS-Port-Type = Ethernet
    NAS-Port-Id = "ether25_385"
    Called-Station-Id = "00-15-e9-89-df-33"
    Calling-Station-Id = "90-e6-ba-19-a6-b4"
    Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
server inner-tunnel {
+- entering group authorize {...}
++[chap] returns noop
++[mschap] returns noop
++[unix] returns notfound
[ntdomain] Looking up realm "CITYHALL" for User-Name =
"CITYHALL\Администратор"
[ntdomain] Found realm "CITYHALL"
[ntdomain] Adding Stripped-User-Name = "Администратор"
[ntdomain] Adding Realm = "CITYHALL"
[ntdomain] Authentication realm is LOCAL.
++[ntdomain] returns ok
[eap] EAP packet type response id 6 length 27
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication
may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type mschapv2
rlm_eap_mschapv2: Issuing Challenge
++[eap] returns handled
} # server inner-tunnel
[peap] Got tunneled reply code 11
    EAP-Message =
0x010700301a0107002b107b7305ea3d639e01377b94165b681bd34349545948414c4c5cc0e4ece8ede8f1f2f0e0f2eef0
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x8fe5640c8fe27eb8d28b73f97bdd495d
[peap] Got tunneled reply RADIUS code 11
    EAP-Message =
0x010700301a0107002b107b7305ea3d639e01377b94165b681bd34349545948414c4c5cc0e4ece8ede8f1f2f0e0f2eef0
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x8fe5640c8fe27eb8d28b73f97bdd495d
[peap] Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 239 to 10.39.0.31 port 8021
    EAP-Message =
0x010700471900170301003c9fab18041f649ec70fd959e26c8c64c5352072aba84b45fb915c0a3d15285cbed97e2138bbad857f7ebcec0e5343c9bd53f6b23d65442972e3d2eeb7
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x8d379fb0883086c6b10255917bdeca99
Finished request 5.
Going to the next request
Waking up in 3.3 seconds.
rad_recv: Access-Request packet from host 10.39.0.31 port 8021, id=240,
length=327
    Framed-MTU = 1466
    NAS-IP-Address = 10.39.0.31
    NAS-Identifier = "D-Link"
    User-Name = "CITYHALL\\РђРґРјРёРЅРёСЃС‚СЂР°С‚РѕСЂ"
    Service-Type = Framed-User
    NAS-Port = 25
    NAS-Port-Type = Ethernet
    NAS-Port-Id = "ether25_385"
    Called-Station-Id = "00-15-e9-89-df-33"
    Calling-Station-Id = "90-e6-ba-19-a6-b4"
    Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
    State = 0x8d379fb0883086c6b10255917bdeca99
    EAP-Message =
0x020700681900170301005da909dcf8173126b7ea1d4e916dac8852c048e706f0d1daa8fd70db91b9cd6b46caf88e50e4d91c0769209604f568bb6dbb9febdf9c5e58b04f90e7535b61a0b6c7d31d323dcab7b42425688402b194a0d3885662b5f11dea9b78dac3d2
    Message-Authenticator = 0x708d7f3eb810cc33c716ca7794e3a122
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 7 length 104
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering 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] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] EAP type mschapv2
[peap] Got tunneled request
    EAP-Message =
0x020700511a0207004c3186d476f9cd2a50a117453e30b8c0a9ee00000000000000003fa59f14170c3c64156be08dce431349620d99bc9f74cb79004349545948414c4c5cc0e4ece8ede8f1f2f0e0f2eef0
server  {
  PEAP: Setting User-Name to CITYHALL\Администратор
Sending tunneled request
    EAP-Message =
0x020700511a0207004c3186d476f9cd2a50a117453e30b8c0a9ee00000000000000003fa59f14170c3c64156be08dce431349620d99bc9f74cb79004349545948414c4c5cc0e4ece8ede8f1f2f0e0f2eef0
    FreeRADIUS-Proxied-To = 127.0.0.1
    User-Name =
"CITYHALL\\\300\344\354\350\355\350\361\362\360\340\362\356\360"
    State = 0x8fe5640c8fe27eb8d28b73f97bdd495d
    Framed-MTU = 1466
    NAS-IP-Address = 10.39.0.31
    NAS-Identifier = "D-Link"
    Service-Type = Framed-User
    NAS-Port = 25
    NAS-Port-Type = Ethernet
    NAS-Port-Id = "ether25_385"
    Called-Station-Id = "00-15-e9-89-df-33"
    Calling-Station-Id = "90-e6-ba-19-a6-b4"
    Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
server inner-tunnel {
+- entering group authorize {...}
++[chap] returns noop
++[mschap] returns noop
++[unix] returns notfound
[ntdomain] Looking up realm "CITYHALL" for User-Name =
"CITYHALL\Администратор"
[ntdomain] Found realm "CITYHALL"
[ntdomain] Adding Stripped-User-Name = "Администратор"
[ntdomain] Adding Realm = "CITYHALL"
[ntdomain] Authentication realm is LOCAL.
++[ntdomain] returns ok
[eap] EAP packet type response id 7 length 81
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication
may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[mschapv2] +- entering group MS-CHAP {...}
[mschap] Told to do MS-CHAPv2 for Администратор with NT-Password
[mschap]     expand: --username=%{mschap:User-Name} ->
--username=Администратор
[mschap]     expand: --domain=%{mschap:NT-Domain} -> --domain=CITYHALL
[mschap]  mschap2: 7b
[mschap]     expand: --challenge=%{mschap:Challenge:-00} ->
--challenge=86c94cfffd3f36fa
[mschap]     expand: --nt-response=%{mschap:NT-Response:-00} ->
--nt-response=3fa59f14170c3c64156be08dce431349620d99bc9f74cb79
Exec-Program output: Invalid parameter (0xc000000d)
Exec-Program-Wait: plaintext: Invalid parameter (0xc000000d)
Exec-Program: returned: 1
[mschap] External script failed.
[mschap] FAILED: MS-CHAP2-Response is incorrect
++[mschap] returns reject
[eap] Freeing handler
++[eap] returns reject
Failed to authenticate the user.
} # server inner-tunnel
[peap] Got tunneled reply code 3
    MS-CHAP-Error = "\007E=691 R=1"
    EAP-Message = 0x04070004
    Message-Authenticator = 0x00000000000000000000000000000000
[peap] Got tunneled reply RADIUS code 3
    MS-CHAP-Error = "\007E=691 R=1"
    EAP-Message = 0x04070004
    Message-Authenticator = 0x00000000000000000000000000000000
[peap] Tunneled authentication was rejected.
[peap] FAILURE
++[eap] returns handled
Sending Access-Challenge of id 240 to 10.39.0.31 port 8021
    EAP-Message =
0x010800261900170301001b1bde4546a9bbb84b9d5584803374118b54f1de192a880f8b560f02
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x8d379fb08b3f86c6b10255917bdeca99
Finished request 6.

...

The ntlm_auth string in mschap module has the following format:
ntlm_auth = "/usr/bin/ntlm_auth --request-nt-key
--username=%{mschap:User-Name}
    --domain=%{mschap:NT-Domain} --challenge=%{mschap:Challenge:-00}
    --nt-response=%{mschap:NT-Response:-00}"

ntlm_auth succeeds in authentication if I use it separately.

What's wrong with that "invalid parameter"? How do I trace it?

freeradius 2.1.7 PEAP mschapv2 invalid parameter

Eugene Vihman