Thank you very much for the response, Sumit.
> Can you send the full output of
>
> KRB5_TRACE=/dev/stdout kinit -X
> X509_user_identity='PKCS11:opensc-pkcs11.so'
> username
Here it is. There are indeed 9 certs on the smartcard and the card auth cert is
at location 01
# KRB5_TRACE=/dev/stdout kinit -X X509_user_identity='PKCS11:opensc-pkcs11.so'
username
[7257] 1558722893.754383: Getting initial credentials for usern...@domain.com
[7257] 1558722893.754385: Sending unauthenticated request
[7257] 1558722893.754386: Sending request (172 bytes) to DOMAIN.COM
[7257] 1558722893.754387: Initiating TCP connection to stream 192.168.162.10:88
[7257] 1558722893.754388: Sending TCP request to stream 192.168.162.10:88
[7257] 1558722893.754389: Received answer (299 bytes) from stream
192.168.162.10:88
[7257] 1558722893.754390: Terminating TCP connection to stream 192.168.162.10:88
[7257] 1558722893.754391: Response was from master KDC
[7257] 1558722893.754392: Received error from KDC: -1765328359/Additional
pre-authentication required
[7257] 1558722893.754395: Preauthenticating using KDC method data
[7257] 1558722893.754396: Processing preauth types: PA-PK-AS-REQ (16),
PA-PK-AS-REP_OLD (15), PA-PK-AS-REQ_OLD (14), PA-FX-FAST (136), PA-ETYPE-INFO2
(19), PA-PKINIT-KX (147), PA-ENC-TIMESTAMP (2), PA-FX-COOKIE (133)
[7257] 1558722893.754397: Selected etype info: etype aes256-cts, salt
",NA#[[..snip]]E&?", params ""
[7257] 1558722893.754398: Received cookie: MIT
[7257] 1558722901.787875: Preauth module pkinit (147) (info) returned: 0/Success
PIV_II PIN:
[7257] 1558722912.887018: PKINIT error: There are 9 certs, but there must be
exactly one.
[7257] 1558722912.887019: PKINIT client has no configured identity; giving up
[7257] 1558722912.887020: Preauth module pkinit (16) (real) returned:
22/Invalid argument
[7257] 1558722912.887021: PKINIT client has no configured identity; giving up
[7257] 1558722912.887022: Preauth module pkinit (14) (real) returned:
22/Invalid argument
Password for usern...@domain.com:
[7257] 1558722919.439664: Preauth module encrypted_timestamp (2) (real)
returned: -1765328252/Password read interrupted
kinit: Pre-authentication failed: Invalid argument while getting initial
credentials
> user for the certificate. Can you send the KDC logs from
> /var/log/krb5kdc.log which covers the time of the login attempts?
Without krb5_auth_timeout = 15
May 24 14:41:02 replica01.dom.ain.com krb5kdc[37038](info): AS_REQ (8 etypes
{18 17 20 19 16 23 25 26}) 192.168.160.14: NEEDED_PREAUTH: username@DOMAIN for
krbtgt/DOMAIN@DOMAIN, Additional pre-authentication required
May 24 14:41:02 replica01.dom.ain.com krb5kdc[37038](info): closing down fd 11
May 24 14:41:02 replica01.dom.ain.com krb5kdc[37039](info): AS_REQ (8 etypes
{18 17 20 19 16 23 25 26}) 192.168.160.14: NEEDED_PREAUTH: username@DOMAIN for
krbtgt/DOMAIN@DOMAIN, Additional pre-authentication required
May 24 14:41:02 replica01.dom.ain.com krb5kdc[37039](info): closing down fd 11
May 24 14:41:21 replica01.dom.ain.com krb5kdc[37042](info): AS_REQ (8 etypes
{18 17 20 19 16 23 25 26}) 192.168.160.14: NEEDED_PREAUTH: username@DOMAIN for
krbtgt/DOMAIN@DOMAIN, Additional pre-authentication required
May 24 14:41:21 replica01.dom.ain.com krb5kdc[37042](info): closing down fd 11
May 24 14:41:21 replica01.dom.ain.com krb5kdc[37039](info): AS_REQ (8 etypes
{18 17 20 19 16 23 25 26}) 192.168.160.14: NEEDED_PREAUTH: username@DOMAIN for
krbtgt/DOMAIN@DOMAIN, Additional pre-authentication required
May 24 14:41:21 replica01.dom.ain.com krb5kdc[37039](info): closing down fd 11
WITH krb5_auth_timeout = 15
May 24 14:44:47 replica01.dom.ain.com krb5kdc[37040](info): AS_REQ (8 etypes
{18 17 20 19 16 23 25 26}) 192.168.160.14: NEEDED_PREAUTH: username@DOMAIN for
krbtgt/DOMAIN@DOMAIN, Additional pre-authentication required
May 24 14:44:47 replica01.dom.ain.com krb5kdc[37040](info): closing down fd 11
May 24 14:44:47 replica01.dom.ain.com krb5kdc[37038](info): AS_REQ (8 etypes
{18 17 20 19 16 23 25 26}) 192.168.160.14: NEEDED_PREAUTH: username@DOMAIN for
krbtgt/DOMAIN@DOMAIN, Additional pre-authentication required
May 24 14:44:47 replica01.dom.ain.com krb5kdc[37038](info): closing down fd 11
May 24 14:45:01 replica01.dom.ain.com krb5kdc[37037](info): AS_REQ (8 etypes
{18 17 20 19 16 23 25 26}) 192.168.160.14: NEEDED_PREAUTH: username@DOMAIN for
krbtgt/DOMAIN@DOMAIN, Additional pre-authentication required
May 24 14:45:01 replica01.dom.ain.com krb5kdc[37037](info): closing down fd 11
May 24 14:45:01 replica01.dom.ain.com krb5kdc[37040](info): AS_REQ (8 etypes
{18 17 20 19 16 23 25 26}) 192.168.160.14: NEEDED_PREAUTH: username@DOMAIN for
krbtgt/DOMAIN@DOMAIN, Additional pre-authentication required
May 24 14:45:01 replica01.dom.ain.com krb5kdc[37040](info): closing down fd 11
May 24 14:45:13 replica01.dom.ain.com krb5kdc[37040](info): Initializing IPA
certauth plugin.
May 24 14:45:13 replica01.dom.ain.com krb5kdc[37040](info): sss_certmap
initialized.
May 24 14:45:13 replica01.dom.ain.com krb5kdc[37040](info): Doing certauth
authorize for [username@DOMAIN]
May 24 14:45:13 replica01.dom.ain.com krb5kdc[37040](info): Got cert filter
[(userCertificate;binary=\30\82\07\fd\30\82\06\e5\a0\03\02\01\02\02\04\5c\5f\9d\[[..SNIP...]]\30\17\06\03\55\1d\20
May 24 14:45:14 replica01.dom.ain.com krb5kdc[37040](info): AS_REQ (8 etypes
{18 17 20 19 16 23 25 26}) 192.168.160.14: ISSUE: authtime 1558723513, etypes
{rep=18 tkt=18 ses=18}, username@DOMAIN for krbtgt/DOMAIN@DOMAIN
May 24 14:45:14 replica01.dom.ain.com krb5kdc[37040](info): closing down fd 11
May 24 14:45:23 replica01.dom.ain.com krb5kdc[37042](info): AS_REQ (8 etypes
{18 17 20 19 16 23 25 26}) 192.168.160.14: NEEDED_PREAUTH: username@DOMAIN for
krbtgt/DOMAIN@DOMAIN, Additional pre-authentication required
May 24 14:45:23 replica01.dom.ain.com krb5kdc[37042](info): closing down fd 11
May 24 14:45:23 replica01.dom.ain.com krb5kdc[37040](info): AS_REQ (8 etypes
{18 17 20 19 16 23 25 26}) 192.168.160.14: NEEDED_PREAUTH: username@DOMAIN for
krbtgt/DOMAIN@DOMAIN, Additional pre-authentication required
May 24 14:45:23 replica01.dom.ain.com krb5kdc[37040](info): closing down fd 11
> On Fri, May 24, 2019 at 04:12:20PM -0000, Khurrum Maqb via FreeIPA-users
> wrote:
>
> Hi,
>
> 'Additional pre-authentication required' is expected. 'Matching
> credential not found' sounds a bit like the KDC cannot find a matching
> user for the certificate. Can you send the KDC logs from
> /var/log/krb5kdc.log which covers the time of the login attempts?
>
>
> Can you send the full output of
>
> KRB5_TRACE=/dev/stdout kinit -X
> X509_user_identity='PKCS11:opensc-pkcs11.so'
> username
>
> at least until you are asked for the password?
>
> bye,
> Sumit
>
> >
> > prompts the user for the PIN, but after the PIN is entered, it immiediately
> > asks for
> the password. So it looks like the part that is failing is the KRB
> authentication.
> >
> > Any suggestions would be very appreciated. Ideally I'd like for the
> > smartcard
> auth to let the users in in a timely manner (ie ~5-15 seconds) and also give
> the users a
> kerberos ticket.
> >
> > Thanks!
> > _______________________________________________
> > FreeIPA-users mailing list -- freeipa-users(a)lists.fedorahosted.org
> > To unsubscribe send an email to freeipa-users-leave(a)lists.fedorahosted.org
> > Fedora Code of Conduct: https://getfedora.org/code-of-conduct.html
> > List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
> > List Archives:
> https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedoraho...
_______________________________________________
FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org
To unsubscribe send an email to freeipa-users-le...@lists.fedorahosted.org
Fedora Code of Conduct: https://getfedora.org/code-of-conduct.html
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives:
https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahosted.org
