CalledProcessError: Command ‘/usr/bin/kinit -n -c /var/run/ipa/ccaches/armor_12728 -X X509_anchors=FILE:/var/kerberos/krb5kdc/kdc.crt -X X509_anchors=FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem’ returned non-zero exit status 1

Getting one of these messages in the HTTPD error_log of a FreeIPA server?

[Thu Jan 28 23:32:39.440152 2021] [:error] [pid 12728] ipa: DEBUG: WSGI wsgi_dispatch.__call__:
[Thu Jan 28 23:32:39.440345 2021] [:error] [pid 12728] ipa: DEBUG: WSGI login_password.__call__:
[Thu Jan 28 23:32:39.442215 2021] [:error] [pid 12728] ipa: DEBUG: Obtaining armor in ccache /var/run/ipa/ccaches/armor_12728
[Thu Jan 28 23:32:39.442377 2021] [:error] [pid 12728] ipa: DEBUG: Initializing anonymous ccache
[Thu Jan 28 23:32:39.442660 2021] [:error] [pid 12728] ipa: DEBUG: Starting external process
[Thu Jan 28 23:32:39.442815 2021] [:error] [pid 12728] ipa: DEBUG: args=/usr/bin/kinit -n -c /var/run/ipa/ccaches/armor_12728 -X X509_anchors=FILE:/var/kerberos/krb5kdc/kdc.crt -X X509_anchors=FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem
[Thu Jan 28 23:32:39.646898 2021] [:error] [pid 12728] ipa: DEBUG: Process finished, return code=1
[Thu Jan 28 23:32:39.647109 2021] [:error] [pid 12728] ipa: DEBUG: stdout=
[Thu Jan 28 23:32:39.647256 2021] [:error] [pid 12728] ipa: DEBUG: stderr=kinit: Preauthentication failed while getting initial credentials
[Thu Jan 28 23:32:39.647281 2021] [:error] [pid 12728]
[Thu Jan 28 23:32:39.647613 2021] [:error] [pid 12728] [remote 192.168.0.136:112] mod_wsgi (pid=12728): Exception occurred processing WSGI script '/usr/share/ipa/wsgi.py'.
[Thu Jan 28 23:32:39.647727 2021] [:error] [pid 12728] [remote 192.168.0.136:112] Traceback (most recent call last):
[Thu Jan 28 23:32:39.647840 2021] [:error] [pid 12728] [remote 192.168.0.136:112] File "/usr/share/ipa/wsgi.py", line 59, in application
[Thu Jan 28 23:32:39.648086 2021] [:error] [pid 12728] [remote 192.168.0.136:112] return api.Backend.wsgi_dispatch(environ, start_response)
[Thu Jan 28 23:32:39.648143 2021] [:error] [pid 12728] [remote 192.168.0.136:112] File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 267, in __call__
[Thu Jan 28 23:32:39.648852 2021] [:error] [pid 12728] [remote 192.168.0.136:112] return self.route(environ, start_response)
[Thu Jan 28 23:32:39.648901 2021] [:error] [pid 12728] [remote 192.168.0.136:112] File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 279, in route
[Thu Jan 28 23:32:39.648952 2021] [:error] [pid 12728] [remote 192.168.0.136:112] return app(environ, start_response)
[Thu Jan 28 23:32:39.648989 2021] [:error] [pid 12728] [remote 192.168.0.136:112] File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 937, in __call__
[Thu Jan 28 23:32:39.649034 2021] [:error] [pid 12728] [remote 192.168.0.136:112] self.kinit(user_principal, password, ipa_ccache_name)
[Thu Jan 28 23:32:39.649076 2021] [:error] [pid 12728] [remote 192.168.0.136:112] File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 973, in kinit
[Thu Jan 28 23:32:39.649121 2021] [:error] [pid 12728] [remote 192.168.0.136:112] pkinit_anchors=[paths.KDC_CERT, paths.KDC_CA_BUNDLE_PEM],
[Thu Jan 28 23:32:39.649165 2021] [:error] [pid 12728] [remote 192.168.0.136:112] File "/usr/lib/python2.7/site-packages/ipalib/install/kinit.py", line 127, in kinit_armor
[Thu Jan 28 23:32:39.649365 2021] [:error] [pid 12728] [remote 192.168.0.136:112] run(args, env=env, raiseonerr=True, capture_error=True)
[Thu Jan 28 23:32:39.649407 2021] [:error] [pid 12728] [remote 192.168.0.136:112] File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 563, in run
[Thu Jan 28 23:32:39.650151 2021] [:error] [pid 12728] [remote 192.168.0.136:112] raise CalledProcessError(p.returncode, arg_string, str(output))
[Thu Jan 28 23:32:39.650286 2021] [:error] [pid 12728] [remote 192.168.0.136:112] CalledProcessError: Command '/usr/bin/kinit -n -c /var/run/ipa/ccaches/armor_12728 -X X509_anchors=FILE:/var/kerberos/krb5kdc/kdc.crt -X X509_anchors=FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem' returned non-zero exit status 1

This prevented Web UI logins as well:

Solve it by reenabling PKINIT, if it was disabled earlier for reasons that escape me:

# ipa-pkinit-manage status
PKINIT is disabled
The ipa-pkinit-manage command was successful
# ipa-pkinit-manage enable
Configuring Kerberos KDC (krb5kdc)
[1/1]: installing X509 Certificate for PKINIT
Done configuring Kerberos KDC (krb5kdc).
The ipa-pkinit-manage command was successful
# ls -altri /var/kerberos/krb5kdc/kdc.crt /var/kerberos/krb5kdc/kdc.key /var/kerberos/krb5kdc/
201364201 -rw——-. 1 root root 1708 Jan 29 00:18 /var/kerberos/krb5kdc/kdc.key
201364200 -rw-r–r–. 1 root root 1635 Jan 29 00:18 /var/kerberos/krb5kdc/kdc.crt

/var/kerberos/krb5kdc/:
total 32
201645664 -rw——-. 1 root root 22 Nov 27 2019 kadm5.acl
134764626 drwxr-xr-x. 4 root root 31 Mar 31 2020 ..
201364197 -rw-r–r–. 1 root root 1448 Jan 8 21:13 kdc.crt-backup
201328018 -rw——-. 1 root root 1708 Jan 28 23:42 kdc.key-backup
201657540 -rw——-. 1 root root 626 Jan 28 23:59 kdc.conf
201364201 -rw——-. 1 root root 1708 Jan 29 00:18 kdc.key
201364200 -rw-r–r–. 1 root root 1635 Jan 29 00:18 kdc.crt
201645673 drwxr-xr-x. 2 root root 4096 Jan 29 00:18 .
201657542 -rw-r–r–. 1 root root 2578 Jan 29 00:18 cacert.pem
#

Note, prior to the reenabling PKINIT, the size of the kdc.crt was wrong and contained this:

# ls -altri /var/kerberos/krb5kdc/kdc.crt /var/kerberos/krb5kdc/kdc.key
201657540 -rw——-. 1 root root 1708 Jan 28 23:42 /var/kerberos/krb5kdc/kdc.key
201657541 -rw-r–r–. 1 root root 1448 Jan 28 23:42 /var/kerberos/krb5kdc/kdc.crt
# df -h
Filesystem Size Used Avail Use% Mounted on
devtmpfs 1.9G 0 1.9G 0% /dev
tmpfs 1.9G 4.0K 1.9G 1% /dev/shm
tmpfs 1.9G 17M 1.9G 1% /run
tmpfs 1.9G 0 1.9G 0% /sys/fs/cgroup
/dev/mapper/centos-root 41G 5.1G 35G 13% /
/dev/mapper/centos-home 20G 33M 20G 1% /home
/dev/sda1 497M 298M 200M 60% /boot
tmpfs 379M 0 379M 0% /run/user/155601104
# openssl x509 -in /var/kerberos/krb5kdc/kdc.crt -noout -text
Certificate:
Data:
Version: 3 (0x2)
Serial Number: 2 (0x2)
Signature Algorithm: sha256WithRSAEncryption
Issuer: O=MWS.MDS.XYZ, CN=idmipa03.mws.mds.xyz
Validity
Not Before: Jan 29 04:42:04 2021 GMT
Not After : Jan 29 04:42:04 2022 GMT
Subject: O=MWS.MDS.XYZ, CN=idmipa03.mws.mds.xyz
Subject Public Key Info:
Public Key Algorithm: rsaEncryption
Public-Key: (2048 bit)
Modulus:
00:ca:db:95:45:44:40:7e:0d:5b:f7:98:b6:5f:98:
10:c7:4a:27:5d:54:aa:97:59:58:85:e5:f4:12:b8:
0d:8f:9d:62:f5:35:b1:5a:40:d0:c9:98:76:5d:97:
80:1f:02:a1:e6:7e:9c:54:ff:f6:ba:a9:55:4e:c0:
c4:4c:71:91:32:cd:e0:a9:47:c6:88:ae:13:9f:6f:
7a:54:ee:1f:4a:82:cb:d4:b4:08:b5:44:18:e7:98:
b4:b8:8a:1f:76:56:5d:93:b8:fc:dc:61:40:66:6b:
d3:46:17:b5:cf:60:21:7f:b0:82:34:3c:d6:a3:17:
78:a6:75:0b:03:0d:cf:7f:df:8b:9e:05:40:cf:03:
22:f8:86:46:c9:82:d4:91:f3:26:7e:c9:b7:8d:a2:
f6:35:15:ef:0c:d3:52:55:96:e4:f7:71:72:12:a8:
c0:76:db:bc:4d:89:9f:46:99:6b:07:84:2e:2d:b2:
da:57:1f:36:8e:d5:27:f5:ea:d9:0e:d7:c6:98:91:
82:16:cb:e9:c1:f3:6e:27:de:9a:91:0d:b5:84:97:
6a:43:c3:84:e0:9b:b2:1a:2f:bd:d9:58:b4:0d:c6:
52:e1:30:ec:df:dd:88:d7:58:cb:69:ec:e6:22:c5:
92:b4:a3:e8:f9:73:c4:87:b2:e8:3c:e1:5c:b3:40:
b8:f9
Exponent: 65537 (0x10001)
X509v3 extensions:
X509v3 Key Usage:
Digital Signature, Non Repudiation, Key Encipherment, Data Encipherment
X509v3 Subject Alternative Name:
othername:<unsupported>, othername:<unsupported>
X509v3 Extended Key Usage:
TLS Web Server Authentication, 1.3.6.1.5.2.3.5
X509v3 Basic Constraints: critical
CA:FALSE
X509v3 Subject Key Identifier:
66:59:08:5F:BB:10:A2:E1:E1:57:44:4F:4D:54:20:3E:5A:41:84:E6
1.3.6.1.4.1.311.20.2:
.".K.D.C.s._.P.K.I.N.I.T._.C.e.r.t.s
Signature Algorithm: sha256WithRSAEncryption
00:0f:98:62:de:ad:cd:61:d1:ab:89:ce:10:33:eb:a2:7b:d1:
55:c5:ec:2e:25:f0:09:72:08:ef:cb:b0:17:9e:06:fa:df:84:
a6:42:5b:86:32:38:35:b1:25:8f:6e:39:eb:12:fc:2a:1f:1d:
39:eb:2f:01:19:a8:c6:d6:12:35:6c:2a:ae:7c:3e:86:16:41:
d5:a5:f0:50:ac:90:67:6e:5b:7d:41:6a:7f:f2:74:49:38:36:
d3:c0:57:a0:8c:4a:40:97:eb:0b:6e:d4:9a:ee:b3:30:f4:8b:
60:0a:32:8e:22:9b:39:0c:d3:67:71:71:30:da:82:d9:41:71:
e2:83:f3:6a:75:b2:d7:62:a7:14:6e:a7:23:19:c1:05:c0:f0:
cc:db:ea:93:32:cc:a5:c5:4a:b8:00:51:27:7a:94:62:e3:41:
43:58:45:8c:99:25:e2:e7:e5:97:13:fa:fc:04:8b:97:75:f9:
b2:25:a8:e8:e8:e1:77:da:c1:3d:c2:e3:3c:5d:6b:b8:38:f9:
ac:dc:b1:68:fe:70:9f:6f:a0:54:67:0c:80:c2:da:21:40:b5:
94:ea:9f:cf:4e:bd:df:ad:c6:b7:38:5f:2d:1e:a7:43:ed:ee:
bb:3a:52:a3:ed:a9:8a:c9:64:80:12:8a:ff:86:69:9a:19:2e:
80:1e:b4:e9

Hope this help!

Regards,

This entry was posted on Friday, January 29th, 2021 at 12:25 am and is filed under NIX Posts. You can follow any responses to this entry through the RSS 2.0 feed. You can leave a response, or trackback from your own site.

You must be logged in to post a comment.

Thoughts and Scribbles | MicroDevSys.com