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: [email protected]
  User authentication types: radius, otp
  RADIUS proxy configuration: privacyidea
  Password: True
  Kerberos keys available: True

# ipa user-show ipa_test
  Principal name: [email protected]
  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: [email protected] for krbtgt/[email protected], 
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: [email protected] for krbtgt/[email protected], 
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: [email protected] for krbtgt/[email protected], 
Preauthentication failed
Sep 22 05:27:04 ipa krb5kdc[8615](info): closing down fd 11
_______________________________________________
FreeIPA-users mailing list -- [email protected]
To unsubscribe send an email to [email protected]
Fedora Code of Conduct: 
https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives: 
https://lists.fedorahosted.org/archives/list/[email protected]
Do not reply to spam on the list, report it: 
https://pagure.io/fedora-infrastructure

Reply via email to