Bug 2015102 - ipa-getcert request fails with JSON-RPC error: 903: an internal error has occurred
Summary: ipa-getcert request fails with JSON-RPC error: 903: an internal error has occ...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: certmonger
Version: rawhide
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Rob Crittenden
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2021-10-18 12:06 UTC by Martin Pitt
Modified: 2021-10-27 03:04 UTC (History)
17 users (show)

Fixed In Version: certmonger-0.79.14-2.fc34 certmonger-0.79.14-2.fc33
Clone Of:
Environment:
Last Closed: 2021-10-27 02:08:28 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
/var/log (589.46 KB, application/x-xz)
2021-10-18 12:41 UTC, Martin Pitt
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker FREEIPA-7097 0 None None None 2021-10-18 12:09:43 UTC

Description Martin Pitt 2021-10-18 12:06:40 UTC
Description of problem: Our Cockpit CI uses freeipa through the quay.io/freeipa/freeipa-server:fedora-rawhide [1] container on Fedora CoreOS. A recent version broke ipa-getcert [2]: The .key is still written, but not the .cert file.


Version-Release number of selected component (if applicable):

freeipa-server-4.9.7-2.fc36.1.x86_64

How reproducible: Always


Steps to Reproduce:
1. Join a domain

2. Request a certificate:
   ipa-getcert request -f /etc/pki/tls/ipa.cert -k /etc/pki/tls/private/ipa.key -K HTTP/$(hostname -f) -w -v

3. Check certificate:
   # ls -l /etc/pki/tls/ipa.cert /etc/pki/tls/private/ipa.key

Actual results:

2.

New signing request "20211018120057" added.
State NEWLY_ADDED_READING_KEYINFO, stuck: no.
State SUBMITTING, stuck: no.
State CA_UNREACHABLE, stuck: no.

3.
ls: cannot access '/etc/pki/tls/ipa.cert': No such file or directory
-rw-------. 1 root root 1704 Oct 18 12:00 /etc/pki/tls/private/ipa.key

Journal output:

2021-10-18 12:00:57 [3807] Setting "CERTMONGER_REQ_SUBJECT" to "CN=x0.cockpit.lan" for child.
2021-10-18 12:00:57 [3807] Setting "CERTMONGER_REQ_PRINCIPAL" to "HTTP/x0.cockpit.lan" for child.
2021-10-18 12:00:57 [3807] Setting "CERTMONGER_OPERATION" to "SUBMIT" for child.
2021-10-18 12:00:57 [3807] Setting "CERTMONGER_CSR" to "-----BEGIN NEW CERTIFICATE REQUEST-----
MIIDTzCCAjcCAQAwGTEXMBUGA1UEAxMOeDAuY29ja3BpdC5sYW4wggEiMA0GCSqG
SIb3DQEBAQUAA4IBDwAwggEKAoIBAQDYuuKn2SMMObuqhHYCgqzBh2Vg2+lmWCYR
XGdSYRkXe3j4206mOmQE1aqFP4C3QlOcVUPgdFLRQ3qe/aPpF2YIiSBJZ6Fuh6r+
nE8yInmK2nECwV1d5kfHSEKZTjbDsSRQ5kPQoDy7LoFL1LbHhRmDgt9xaZ7eG3tr
t5r8YSZqj7VcOsJNANVKg8cAKjm0Homl/5yyXs6L7yMj1KJRafCpaFsArLXcexIu
uMs6ooZ2YRBCNqCubovtPW117Rd8Ds42ZfdDehSyXNdLes7DWVwSQ/HFnAsx1C5+
7V2pFFOFEko7qUNw52OaG/veaVnTwOnttL2gV+qVP5z9EeiWeEaJAgMBAAGggfAw
KwYJKoZIhvcNAQkUMR4eHAAyADAAMgAxADEAMAAxADgAMQAyADAAMAA1ADcwgcAG
CSqGSIb3DQEJDjGBsjCBrzB9BgNVHREBAQAEczBxoC8GCisGAQQBgjcUAgOgIQwf
SFRUUC94MC5jb2NrcGl0LmxhbkBDT0NLUElULkxBTqA+BgYrBgEFAgKgNDAyoA0b
C0NPQ0tQSVQuTEFOoSEwH6ADAgEBoRgwFhsESFRUUBsOeDAuY29ja3BpdC5sYW4w
DAYDVR0TAQH/BAIwADAgBgNVHQ4BAQAEFgQUYwaIkSd0b0bTS/XTmc7NEBb0rUUw
DQYJKoZIhvcNAQELBQADggEBAEip/DMLVJbnVwq4EgwHM2dtpTYxFtHRrj1lw0Jc
b45j7Wbcxu/ItMWc8lh0vtGnuOaQ/CrWozLy6xEzv5KDiybzMGT9ZxyTXBZnFHqy
tgHFosAXLkIChbige6xpmbXAlemZuOUKgtCjsOwuVhK3g0F21svBxJbNIVi/bs1q
4aL1P21odeU7KCtgL0RGzGVipKTshfI5kabH/k5WJEd7nlBkFBcVyRWuNQvOO0Wi
cZaBFK1eR9hpl1r25IMrYlfU6Ayj8l4gVrRAZ2vGfg6SZZWVk4o8zljHUIFf+NxH
okvNVe9cC3ESfQWsVQODFJdnKUlp+4gSdRJcexH9DG1ZIGI=
-----END NEW CERTIFICATE REQUEST-----
" for child.
2021-10-18 12:00:57 [3807] Setting "CERTMONGER_SPKAC" to "MIICQDCCASgwggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQDYuuKn2SMMObuqhHYCgqzBh2Vg2+lmWCYRXGdSYRkXe3j4206mOmQE1aqFP4C3QlOcVUPgdFLRQ3qe/aPpF2YIiSBJZ6Fuh6r+nE8yInmK2nECwV1d5kfHSEKZTjbDsSRQ5kPQoDy7LoFL1LbHhRmDgt9xaZ7eG3trt5r8YSZqj7VcOsJNANVKg8cAKjm0Homl/5yyXs6L7yMj1KJRafCpaFsArLXcexIuuMs6ooZ2YRBCNqCubovtPW117Rd8Ds42ZfdDehSyXNdLes7DWVwSQ/HFnAsx1C5+7V2pFFOFEko7qUNw52OaG/veaVnTwOnttL2gV+qVP5z9EeiWeEaJAgMBAAEWADANBgkqhkiG9w0BAQsFAAOCAQEAtTHujP83EFBwaI7SR4FDB+KGwRRXwWmIHNIvZguZ+oj68RnxzqACNSFRHrWlKordcPQ0ITA8dSHv9W8KG7pBotvjS3Us51f5EBpahA7NlUIERSu52Kjw/5m4qEO2GbG388LCyFimJYcF8Mpv2XakxLKigxEP8NN7oLr39G5XaDhfqTDo+pa4cyZQIMwvsy0/Ud4pBPPMS65NUhOmUTbRspitkQ7jisJDDruuEjL2uvjYXqGZ5dppKbNkDJIhdwE1eL68MGG8ditIsCQ2WD/TuG5LDxoE/C+kP83ZqbcJU8ZtDfDbx9gNaTsAnLkee7bSxkQrW5ljI8D/XiZR/TepCQ==" for child.
2021-10-18 12:00:57 [3807] Setting "CERTMONGER_SPKI" to "MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEA2Lrip9kjDDm7qoR2AoKswYdlYNvpZlgmEVxnUmEZF3t4+NtOpjpkBNWqhT+At0JTnFVD4HRS0UN6nv2j6RdmCIkgSWehboeq/pxPMiJ5itpxAsFdXeZHx0hCmU42w7EkUOZD0KA8uy6BS9S2x4UZg4LfcWme3ht7a7ea/GEmao+1XDrCTQDVSoPHACo5tB6Jpf+csl7Oi+8jI9SiUWnwqWhbAKy13HsSLrjLOqKGdmEQQjagrm6L7T1tde0XfA7ONmX3Q3oUslzXS3rOw1lcEkPxxZwLMdQufu1dqRRThRJKO6lDcOdjmhv73mlZ08Dp7bS9oFfqlT+c/RHolnhGiQIDAQAB" for child.
2021-10-18 12:00:57 [3807] Setting "CERTMONGER_LOCAL_CA_DIR" to "/var/lib/certmonger/local" for child.
2021-10-18 12:00:57 [3807] Setting "CERTMONGER_KEY_TYPE" to "RSA" for child.
2021-10-18 12:00:57 [3807] Setting "CERTMONGER_CA_NICKNAME" to "IPA" for child.
2021-10-18 12:00:57 [3807] Redirecting stdin to /dev/null, leaving stdout and stderr open for child "/usr/libexec/certmonger/ipa-submit".
2021-10-18 12:00:57 [3807] Running enrollment helper "/usr/libexec/certmonger/ipa-submit".
Submitting request to "https://f0.cockpit.lan/ipa/json".
JSON-RPC error: 903: an internal error has occurred
GSSAPI client step 1
GSSAPI client step 1
GSSAPI client step 1
GSSAPI client step 1
GSSAPI client step 2
2021-10-18 12:00:58 [2636] Certificate submission still ongoing.
2021-10-18 12:00:58 [2636] Certificate submission attempt complete.
2021-10-18 12:00:58 [2636] Child status = 3.
2021-10-18 12:00:58 [2636] Child output:
"Server at https://f0.cockpit.lan/ipa/json failed request, will retry: 903 (an internal error has occurred).
"
2021-10-18 12:00:58 [2636] Server at https://f0.cockpit.lan/ipa/json failed request, will retry: 903 (an internal error has occurred).
2021-10-18 12:00:58 [2636] Certificate not (yet?) issued.



Expected results: Certificate gets created


Additional info:

Last known version to work was freeipa-server-4.9.6-3.fc35 (sorry, we don't refresh that image very often). Our currently pending image refresh actually has a slightly older version 4.9.7-1, so at first sight this *could* have been bug 2014658. But I updated to the latest container (version -2) with the fix, and same issue.


[1] https://quay.io/repository/freeipa/freeipa-server?tab=tags
[2] https://github.com/cockpit-project/bots/pull/2524

Comment 1 Alexander Bokovoy 2021-10-18 12:10:42 UTC
You need to wait until https://koji.fedoraproject.org/koji/buildinfo?buildID=1845811 is in Rawhide compose and freeipa-container is rebuilt.
I'll mark this as a duplicate of bug #2014658

*** This bug has been marked as a duplicate of bug 2014658 ***

Comment 2 Martin Pitt 2021-10-18 12:16:54 UTC
Hello Alexander,

as I wrote in the description, I already did that:

> at first sight this *could* have been bug 2014658. But I updated to the latest container (version -2) with the fix, and same issue.

. -2 is in Rawhide: https://bodhi.fedoraproject.org/updates/FEDORA-2021-7dac22d63a , and quay.io has an up to date container. This is *not* a duplicate.

Comment 3 Alexander Bokovoy 2021-10-18 12:27:03 UTC
Do you have httpd's error_log and PKI logs?

I cannot find them in your PR's logs. Without server's logs it is hard to see what else is broken in recent PKI's removal of XML-RPC support.

Comment 4 Martin Pitt 2021-10-18 12:41:42 UTC
Created attachment 1834215 [details]
/var/log

Indeed error_log has something that looks very relevant:

ipa: ERROR: non-public: ValueError: error parsing asn1 value: ParseError { kind: EncodedDefault, location: ["0", "Extension::critical"] }
Traceback (most recent call last):
  File "/usr/lib/python3.10/site-packages/ipaserver/rpcserver.py", line 405, in wsgi_execute
    result = command(*args, **options)
  File "/usr/lib/python3.10/site-packages/ipalib/frontend.py", line 471, in __call__
    return self.__do_call(*args, **options)
  File "/usr/lib/python3.10/site-packages/ipalib/frontend.py", line 499, in __do_call
    ret = self.run(*args, **options)
  File "/usr/lib/python3.10/site-packages/ipalib/frontend.py", line 821, in run
    return self.execute(*args, **options)
  File "/usr/lib/python3.10/site-packages/ipaserver/plugins/cert.py", line 719, in execute
    ext_san = csr.extensions.get_extension_for_oid(
ValueError: error parsing asn1 value: ParseError { kind: EncodedDefault, location: ["0", "Extension::critical"] }
ipa: INFO: [jsonserver_kerb] host/x0.cockpit.lan: cert_request('MIIDTzCCAjcCAQAwGTEXMBUGA1UEAxMOeDAuY29ja3BpdC5sYW4wggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQC9L2/NsS/B6qMywcUeqpgd9DtGRT7WjCRLGZSOt50+pfDYjP9NLLZAlHGFEqivlYrXhfP/rrOYmznZBwmAin7+f2SLIzcpKs1HEc8UoPtr9Tuf6gjYdFofGo94fjGjeZsax9pMFKAPc6Icm1YOqgzX1EZQ0OR2okvVV9p4lW14hy1xMZcDBmMvLovH+nABSeDwe4ucpdG/cE+yfwKEvirW7zx8Glc2hrzPaqBNBgIUcfZkfD8Nn+QAzx3JelI1u6D2qOaYDk9KQm0Z8MN5nXDYa4AbpjTnGRB2IOykFFSMA4OSwKxl3duH0P0vJ/ab8VjIAk3lRGvp3Baq7lgEgTnjAgMBAAGggfAwKwYJKoZIhvcNAQkUMR4eHAAyADAAMgAxADEAMAAxADgAMQAyADMANwAzADcwgcAGCSqGSIb3DQEJDjGBsjCBrzB9BgNVHREBAQAEczBxoC8GCisGAQQBgjcUAgOgIQwfSFRUUC94MC5jb2NrcGl0LmxhbkBDT0NLUElULkxBTqA+BgYrBgEFAgKgNDAyoA0bC0NPQ0tQSVQuTEFOoSEwH6ADAgEBoRgwFhsESFRUUBsOeDAuY29ja3BpdC5sYW4wDAYDVR0TAQH/BAIwADAgBgNVHQ4BAQAEFgQUglxkOudA1OQlVy0HBnAk23DoN9IwDQYJKoZIhvcNAQELBQADggEBAAyvaMeDs0MZ4b7TUIDr9HPVeulIQs6vs7lUVvZnnoCui2jEt8ydZiCIh/98LdlB5D6iLkQOlaM7AHnuSXwyKjNQMRz5nRMVCwg48atXeT/eDBYuONYn0+oBd3q7vDrsKEl+M3UabGaiPE1hqf1kkIj5k7s7t9t1qQl5hxGYQKU3z1h1s3mP+4xBt4M8hneXibP4kuB/zDVbXiZB5ViSTmHENfVPLNZ5w18BZv6BoQzpkOM5r+E8YiVDKfNajR7q02P24urI8eFbWgAvE+gmQvUS3nUHOqO6OCG09JZ+DEvdXh8tnKSow/CF61RpgyDaazOFDoV16D8huDeyndnV+R4=', principal='HTTP/x0.cockpit.lan', add=True): InternalError

I'll attach the complete /var/log from the container, in case it has something else that is interesting.

Comment 5 Alexander Bokovoy 2021-10-18 12:47:09 UTC
Ah, this is python-cryptography 35.0 issue: https://github.com/pyca/cryptography/issues/6340

We saw that in Rawhide just this weekend in IPA CI runs: http://freeipa-org-pr-ci.s3-website.eu-central-1.amazonaws.com/jobs/1ae3e78e-2eab-11ec-8838-fa163ef390f3/report.html

----
A few tests failed because of python cryptography issue #6340: CSR with 'BEGIN NEW CERTIFICATE REQUEST' no longer accepted (external_ca_TestExternalCAInvalidCert, external_ca_TestMultipleExternalCA, external_ca_TestExternalCAdirsrvStop, external_ca_templates, test_acme, test_caless_TestServerCALessToExternalCA, test_external_ca_TestExternalCA, test_ipahealthcheck_nodns_extca_file). There is already an upstream fix but no rawhide build yet.
----

python-cryptography update is not yet in Rawhide.

Comment 6 Alexander Bokovoy 2021-10-18 12:58:59 UTC
I will move this to python-cryptography for awareness.

Comment 7 Rob Crittenden 2021-10-18 13:04:15 UTC
What version of certmonger is this?

Comment 8 Christian Heimes 2021-10-18 13:08:19 UTC
This is actually a certmonger bug that was revealed by a new ASN.1 parser in python-cryptography. The new parser does not accept invalid ASN.1 DER. The problem should be fixed by certmonger-0.79.14-6.fc36. The update https://bodhi.fedoraproject.org/updates/FEDORA-2021-1881de28ed is in Rawhide.

Upstream python-cryptography has agreed to accept a temporary workaround for backwards compatibility. The workaround is still work in progress.

Comment 9 Martin Pitt 2021-10-18 13:15:03 UTC
Rob: certmonger-0.79.14-6.fc36.x86_64 on the server side (in the container), certmonger-0.79.14-2.fc35.x86_64 on the client side; I'm not sure which one is relevant.

Comment 10 Christian Heimes 2021-10-18 13:18:56 UTC
The relevant side is side that generates the CSR. In your case it's the client. 

https://bodhi.fedoraproject.org/updates/FEDORA-2021-08cd0d66af is not available in F35 yet. Could you please verify the update?

Comment 11 Martin Pitt 2021-10-18 14:13:53 UTC
On the client side I ran

    dnf update --enablerepo=updates-testing certmonger

which pulled in certmonger-0.79.14-3.fc35 from that bodhi update. I confirm that this works.

There is no corresponding fix for Fedora 34, so I can't test it there. Is this still planned? As that seems to break "over the wire" compatibility, all supported Fedora/RHEL versions ought to get that fix?

Thanks for tracking this down!

Comment 12 Rob Crittenden 2021-10-18 15:04:36 UTC
I'm working on builds for 33 and 34.

Comment 13 Fedora Update System 2021-10-18 15:33:08 UTC
FEDORA-2021-bf70829200 has been submitted as an update to Fedora 33. https://bodhi.fedoraproject.org/updates/FEDORA-2021-bf70829200

Comment 14 Fedora Update System 2021-10-19 00:48:15 UTC
FEDORA-2021-df9eee3325 has been pushed to the Fedora 34 testing repository.
Soon you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2021-df9eee3325`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2021-df9eee3325

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 15 Fedora Update System 2021-10-19 01:29:11 UTC
FEDORA-2021-bf70829200 has been pushed to the Fedora 33 testing repository.
Soon you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2021-bf70829200`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2021-bf70829200

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 16 Martin Pitt 2021-10-19 04:54:50 UTC
I tested the F34 update [1] and this works again. (Still a bit sad that e.g. stable Debian or CentOS 7/8 clients will be broken with 4.9.7)

Thanks!

[1] https://bodhi.fedoraproject.org/updates/FEDORA-2021-df9eee3325

Comment 17 Rob Crittenden 2021-10-19 11:40:42 UTC
I believe that python-cryptography is going to add an option to relax this validation which will help with unpatched certmonger releases.

Comment 18 Fedora Update System 2021-10-27 02:08:28 UTC
FEDORA-2021-df9eee3325 has been pushed to the Fedora 34 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 19 Fedora Update System 2021-10-27 03:04:19 UTC
FEDORA-2021-bf70829200 has been pushed to the Fedora 33 stable repository.
If problem still persists, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.