Configuration: FreeIPA and FreeRADIUS : Fedora 34 on host ipa.example.com with ip 192.168.1.139 (Proxmox LXC Container) privacyIDEA: Debian 10 on host mfa.example.com with ip 192.168.1.136 (Proxmox LXC Container) yum info freeipa-server Version : 4.9.6 yum info freeradius Version : 3.0.21 pip show privacyidea Name: privacyIDEA Version: 3.5.1 The connection between FreeRADIUS and privacyIDEA is configured with the perl module privacyidea_radius.pm # ipa user-show otp_test Principal name: otp_test(a)EXAMPLE.COM User authentication types: radius, otp RADIUS proxy configuration: privacyidea Password: True Kerberos keys available: True # ipa user-show ipa_test Principal name: ipa_test(a)EXAMPLE.COM User authentication types: password Password: True Kerberos keys available: True # ipa radiusproxy-show privacyidea RADIUS proxy server name: privacyidea Server: 192.168.1.139 Problem: It is not possible to login with user otp_test when the policy in privacyIDEA is set to 'otppin = userstore'. Test: [ipa_test@ipa ~]$ su otp_test First Factor: <password> Second Factor: <otp> su: Authentication failure If I set the privacyIDEA policy to 'otppin = tokenpin' and set the pin = <password> login works. So I think that in general authentication with privacyIDEA works. The problem is that privacyIDEA can not check the password against the FreeIPA LDAP as you can see in the privacyidea.log file. In the krb5kdc.log you can see 'preauth (otp) verify failure: Generic preauthentication failure' Can anybody help me to fix that? Here are parts of the logs: /var/log/privacyidea/privacyidea.log ------------------------------------ [2021-09-22 05:27:03,157][5358][139872937498368][INFO][privacyidea.lib.crypto:821] initializing HSM class: <class 'privacyidea.lib.security.default.DefaultSecurityModule'> [2021-09-22 05:27:03,158][5358][139872937498368][INFO][privacyidea.lib.crypto:260] Initialized HSM object {'obj': <privacyidea.lib.security.default.DefaultSecurityModule object at 0x7f36a43b48d0>} [2021-09-22 05:27:03,486][5358][139872937498368][INFO][privacyidea.lib.user:233] user 'otp_test' found in resolver 'FreeIPA' [2021-09-22 05:27:03,486][5358][139872937498368][INFO][privacyidea.lib.user:234] userid resolved to '69820e7e-1872-11ec-b5e7-8ae8999d4764' [2021-09-22 05:27:03,492][5358][139872937498368][INFO][privacyidea.lib.pooling:119] Created a new engine registry: <privacyidea.lib.pooling.NullEngineRegistry object at 0x7f369fa787b8> [2021-09-22 05:27:03,557][5358][139872937498368][INFO][privacyidea.lib.tokens.vasco:56] PI_VASCO_LIBRARY option is not set, functionality disabled [2021-09-22 05:27:03,566][5358][139872937498368][INFO][privacyidea.lib.user:360] User 'otp_test' from realm 'example.com' tries to authenticate [2021-09-22 05:27:03,576][5358][139872937498368][WARNING][privacyidea.lib.resolvers.LDAPIdResolver:354] failed to check password for '69820e7e-1872-11ec-b5e7-8ae8999d4764'/'uid=otp_test,cn=users,cn=accounts,dc=nottebrok,dc=net': Exception('Wrong credentials') [2021-09-22 05:27:03,577][5358][139872937498368][INFO][privacyidea.lib.user:371] user User(login='otp_test', realm='example.com', resolver='FreeIPA') failed to authenticate. /var/log/radius/radius.log -------------------------- Wed Sep 22 05:27:01 2021 : Info: rlm_perl: Config File /etc/privacyidea/rlm_perl.ini found! Wed Sep 22 05:27:01 2021 : Info: rlm_perl: Debugging config: true Wed Sep 22 05:27:01 2021 : Info: rlm_perl: Default URL https://mfa.example.com/validate/check Wed Sep 22 05:27:01 2021 : Info: rlm_perl: Looking for config for auth-type Perl Wed Sep 22 05:27:01 2021 : rlm_perl: RAD_REQUEST: User-Password = <password><otp> Wed Sep 22 05:27:01 2021 : rlm_perl: RAD_REQUEST: Packet-Src-IP-Address = 192.168.1.139 Wed Sep 22 05:27:01 2021 : rlm_perl: RAD_REQUEST: NAS-Identifier = ipa.example.com Wed Sep 22 05:27:01 2021 : rlm_perl: RAD_REQUEST: Service-Type = Authenticate-Only Wed Sep 22 05:27:01 2021 : rlm_perl: RAD_REQUEST: User-Name = otp_test Wed Sep 22 05:27:01 2021 : Info: rlm_perl: Password encoding guessed: ascii Wed Sep 22 05:27:01 2021 : Info: rlm_perl: Setting client IP to 192.168.1.139. Wed Sep 22 05:27:01 2021 : Info: rlm_perl: Auth-Type: Perl Wed Sep 22 05:27:01 2021 : Info: rlm_perl: url: https://mfa.example.com/validate/check Wed Sep 22 05:27:01 2021 : Info: rlm_perl: user sent to privacyidea: otp_test Wed Sep 22 05:27:01 2021 : Info: rlm_perl: realm sent to privacyidea: Wed Sep 22 05:27:01 2021 : Info: rlm_perl: resolver sent to privacyidea: Wed Sep 22 05:27:01 2021 : Info: rlm_perl: client sent to privacyidea: 192.168.1.139 Wed Sep 22 05:27:01 2021 : Info: rlm_perl: state sent to privacyidea: Wed Sep 22 05:27:01 2021 : rlm_perl: urlparam client = 192.168.1.139 Wed Sep 22 05:27:01 2021 : rlm_perl: urlparam pass = <password><otp> Wed Sep 22 05:27:01 2021 : rlm_perl: urlparam user = otp_test Wed Sep 22 05:27:01 2021 : Info: rlm_perl: Request timeout: 10 Wed Sep 22 05:27:01 2021 : Info: rlm_perl: Not verifying SSL certificate! Wed Sep 22 05:27:03 2021 : Info: rlm_perl: elapsed time for privacyidea call: 2.298527 Wed Sep 22 05:27:03 2021 : rlm_perl: Content {"detail": {"message": "wrong otp pin", "threadid": 139872937498368}, "id": 1, "jsonrpc": "2.0", "result": {"status": true, "value": false}, "time": 1632288423.7560399, "version": "privacyIDEA 3.5.1", "versionnumber": "3.5.1", "signature": "rsa_sha256_pss:a4ea05ca498b36c09137d1f492bc882109adfc8a7fb3a185fb4b8638255dd2539659897591afdffd99b6cdd1bb5c5741f63f2037abdc85c5bafae669a97f1e7cbc76f26da70139651e796e60550d9410c7f7c6cab8f3581cbb6f676683da9a1c4659ec2f30187d18c25297dda2a61e06085ee4265606670377040247e19bb58ca0f04aca71cf30b198376eaf263503228176ec249dccb82036e987d190c6108fddadebd250deb2c19995b7dbeeb8ed2d233066389c871e99c76d85ef908009448c5af2ca7d0605852720bdb9ade99b58711593c9b9f92a2ca45aa351d0d33c721df9417d464aaf9052cdce99440d851ea6f9940de8576df4023974866cc5fb16"} Wed Sep 22 05:27:03 2021 : Info: rlm_perl: privacyIDEA Result status is true! Wed Sep 22 05:27:03 2021 : Info: rlm_perl: privacyIDEA access denied for otp_test realm='' Wed Sep 22 05:27:03 2021 : Info: rlm_perl: return RLM_MODULE_REJECT /var/log/dirsrv/slapd-NOTTEBROK-NET/access ------------------------------------------ [22/Sep/2021:05:27:01.564080274 +0000] conn=3895 op=2 RESULT err=0 tag=101 nentries=1 wtime=0.000049870 optime=0.000150998 etime=0.000199231 [22/Sep/2021:05:27:01.564323730 +0000] conn=3895 op=3 SRCH base="cn=privacyidea,cn=radiusproxy,dc=nottebrok,dc=net" scope=0 filter="(objectClass=*)" attrs="ipatokenRadiusServer ipatokenRadiusSecret ipatokenRadiusTimeout ipatokenRadiusRetries ipatokenUserMapAttribute" [22/Sep/2021:05:27:01.564421567 +0000] conn=3895 op=3 RESULT err=0 tag=101 nentries=1 wtime=0.000041954 optime=0.000099034 etime=0.000139513 [22/Sep/2021:05:27:01.566557293 +0000] conn=3892 op=11 SRCH base="cn=ipservices,cn=accounts,dc=nottebrok,dc=net" scope=2 filter="(&(cn=radius)(ipServiceProtocol=udp)(objectClass=ipService))" attrs="objectClass cn ipServicePort ipServiceProtocol entryusn" [22/Sep/2021:05:27:01.566712813 +0000] conn=3892 op=11 RESULT err=0 tag=101 nentries=0 wtime=0.000084750 optime=0.000157349 etime=0.000240250 [22/Sep/2021:05:27:03.246250221 +0000] conn=3897 fd=121 slot=121 connection from 192.168.1.136 to 192.168.1.139 [22/Sep/2021:05:27:03.246571254 +0000] conn=3897 op=-1 fd=121 closed error - B1 [22/Sep/2021:05:27:03.246630909 +0000] conn=3898 fd=126 slot=126 connection from 192.168.1.136 to 192.168.1.139 [22/Sep/2021:05:27:03.246931986 +0000] conn=3898 op=0 EXT oid="1.3.6.1.4.1.1466.20037" name="start_tls_plugin" [22/Sep/2021:05:27:03.246975107 +0000] conn=3898 op=0 RESULT err=0 tag=120 nentries=0 wtime=0.000135107 optime=0.000048051 etime=0.000181367 [22/Sep/2021:05:27:03.250916223 +0000] conn=3898 TLS1.2 128-bit AES-GCM [22/Sep/2021:05:27:03.251829337 +0000] conn=3898 op=1 BIND dn="uid=privacyidea-bind,cn=sysaccounts,cn=etc,dc=nottebrok,dc=net" method=128 version=3 [22/Sep/2021:05:27:03.252339317 +0000] conn=3898 op=1 RESULT err=0 tag=97 nentries=0 wtime=0.004225141 optime=0.000524375 etime=0.004747290 dn="uid=privacyidea-bind,cn=sysaccounts,cn=etc,dc=nottebrok,dc=net" [22/Sep/2021:05:27:03.253292531 +0000] conn=3898 op=2 SRCH base="" scope=0 filter="(objectClass=*)" attrs="subschemaSubentry +" [22/Sep/2021:05:27:03.254751970 +0000] conn=3898 op=2 RESULT err=0 tag=101 nentries=1 wtime=0.000091257 optime=0.001461035 etime=0.001549672 [22/Sep/2021:05:27:03.256597869 +0000] conn=3898 op=3 SRCH base="cn=schema" scope=0 filter="(objectClass=subschema)" attrs="objectClasses attributeTypes ldapSyntaxes matchingRules matchingRuleUse dITContentRules dITStructureRules nameForms createTimestamp modifyTimestamp * + aci" [22/Sep/2021:05:27:03.351666572 +0000] conn=3898 op=3 RESULT err=0 tag=101 nentries=1 wtime=0.000120956 optime=0.095069951 etime=0.095184874 [22/Sep/2021:05:27:03.484292759 +0000] conn=3898 op=4 SRCH base="cn=users,cn=accounts,dc=nottebrok,dc=net" scope=2 filter="(&(uid=*)(objectClass=inetOrgPerson)(uid=otp_test))" attrs="telephoneNumber mobile mail sn givenName gecos uid ipaUniqueID" [22/Sep/2021:05:27:03.485807992 +0000] conn=3898 op=4 RESULT err=0 tag=101 nentries=1 wtime=0.000140279 optime=0.001516926 etime=0.001653375 notes=U details="Partially Unindexed Filter" [22/Sep/2021:05:27:03.564155920 +0000] conn=3898 op=5 SRCH base="cn=users,cn=accounts,dc=nottebrok,dc=net" scope=2 filter="(&(uid=*)(objectClass=inetOrgPerson)(ipaUniqueID=69820e7e-1872-11ec-b5e7-8ae8999d4764))" attrs="telephoneNumber mobile mail sn givenName gecos uid" [22/Sep/2021:05:27:03.565628714 +0000] conn=3898 op=5 RESULT err=0 tag=101 nentries=1 wtime=0.000138785 optime=0.001475478 etime=0.001609564 notes=U details="Partially Unindexed Filter" [22/Sep/2021:05:27:03.568418557 +0000] conn=3898 op=6 SRCH base="cn=users,cn=accounts,dc=nottebrok,dc=net" scope=2 filter="(&(uid=*)(objectClass=inetOrgPerson)(ipaUniqueID=69820e7e-1872-11ec-b5e7-8ae8999d4764))" attrs="telephoneNumber mobile mail sn givenName gecos uid" [22/Sep/2021:05:27:03.569936263 +0000] conn=3898 op=6 RESULT err=0 tag=101 nentries=1 wtime=0.000139985 optime=0.001520723 etime=0.001656185 notes=U details="Partially Unindexed Filter" [22/Sep/2021:05:27:03.570551770 +0000] conn=3899 fd=121 slot=121 connection from 192.168.1.136 to 192.168.1.139 [22/Sep/2021:05:27:03.570832412 +0000] conn=3899 op=-1 fd=121 closed error - B1 [22/Sep/2021:05:27:03.570894957 +0000] conn=3900 fd=127 slot=127 connection from 192.168.1.136 to 192.168.1.139 [22/Sep/2021:05:27:03.571225293 +0000] conn=3900 op=0 EXT oid="1.3.6.1.4.1.1466.20037" name="start_tls_plugin" [22/Sep/2021:05:27:03.571270580 +0000] conn=3900 op=0 RESULT err=0 tag=120 nentries=0 wtime=0.000153969 optime=0.000047853 etime=0.000200296 [22/Sep/2021:05:27:03.574890946 +0000] conn=3900 TLS1.2 128-bit AES-GCM [22/Sep/2021:05:27:03.575569529 +0000] conn=3900 op=1 BIND dn="uid=otp_test,cn=users,cn=accounts,dc=nottebrok,dc=net" method=128 version=3 [22/Sep/2021:05:27:03.576077489 +0000] conn=3900 op=1 RESULT err=49 tag=97 nentries=0 wtime=0.003805205 optime=0.000518648 etime=0.004320920 [22/Sep/2021:05:27:04.869258275 +0000] conn=3029 op=13493 MOD dn="uid=otp_test,cn=users,cn=accounts,dc=nottebrok,dc=net" [22/Sep/2021:05:27:04.939090470 +0000] conn=3029 op=13493 RESULT err=0 tag=103 nentries=0 wtime=0.000077276 optime=0.069837500 etime=0.069910794 [22/Sep/2021:05:27:04.940438540 +0000] conn=3890 op=36 SRCH base="cn=etc,dc=nottebrok,dc=net" scope=2 filter="(&(cn=ipaConfig)(objectClass=ipaGuiConfig))" attrs="ipaMigrationEnabled ipaSELinuxUserMapDefault ipaSELinuxUserMapOrder" [22/Sep/2021:05:27:04.940991039 +0000] conn=3890 op=36 RESULT err=0 tag=101 nentries=1 wtime=0.000166940 optime=0.000555022 etime=0.000718249 /var/log/krb5kdc.log -------------------- Sep 22 05:27:01 ipa krb5kdc[8615](info): AS_REQ (8 etypes {aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), UNSUPPORTED:des3-hmac-sha1(16), DEPRECATED:arcfour-hmac(23), camellia128-cts-cmac(25), camellia256-cts-cmac(26)}) 192.168.1.129: NEEDED_PREAUTH: otp_test(a)EXAMPLE.COM for krbtgt/EXAMPLE.COM(a)EXAMPLE.COM, Additional pre-authentication required Sep 22 05:27:01 ipa krb5kdc[8615](info): closing down fd 11 Sep 22 05:27:01 ipa krb5kdc[8615](info): AS_REQ (8 etypes {aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), UNSUPPORTED:des3-hmac-sha1(16), DEPRECATED:arcfour-hmac(23), camellia128-cts-cmac(25), camellia256-cts-cmac(26)}) 192.168.1.129: NEEDED_PREAUTH: otp_test(a)EXAMPLE.COM for krbtgt/EXAMPLE.COM(a)EXAMPLE.COM, Additional pre-authentication required Sep 22 05:27:01 ipa krb5kdc[8615](info): closing down fd 11 Sep 22 05:27:04 ipa krb5kdc[8615](info): preauth (otp) verify failure: Generic preauthentication failure Sep 22 05:27:04 ipa krb5kdc[8615](info): AS_REQ (8 etypes {aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), UNSUPPORTED:des3-hmac-sha1(16), DEPRECATED:arcfour-hmac(23), camellia128-cts-cmac(25), camellia256-cts-cmac(26)}) 192.168.1.129: PREAUTH_FAILED: otp_test(a)EXAMPLE.COM for krbtgt/EXAMPLE.COM(a)EXAMPLE.COM, Preauthentication failed Sep 22 05:27:04 ipa krb5kdc[8615](info): closing down fd 11