Bug 1573094

Summary:	FreeIPA external CA installation fails
Product:	[Fedora] Fedora	Reporter:	Christian Heimes <cheimes>
Component:	pki-core	Assignee:	Matthew Harmsen <mharmsen>
Status:	CLOSED ERRATA	QA Contact:	Fedora Extras Quality Assurance <extras-qa>
Severity:	urgent	Docs Contact:
Priority:	unspecified
Version:	28	CC:	alee, dennis, edewata, extras-orphan, kwright, mharmsen
Target Milestone:	---
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	pki-core-10.6.1-1.fc28	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2018-05-13 19:59:47 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Christian Heimes 2018-04-30 08:03:11 UTC

Description of problem:
A bug in Dogtag 10.6 breaks FreeIPA 4.7's external CA feature. It's not possible to install FreeIPA with an externally signed CA.

Version-Release number of selected component (if applicable):
freeipa-server-4.6.90.pre1.dev201804291746+git73c3495db-0.fc28.x86_64
pki-ca-10.6.0-1.fc28.noarch

How reproducible:
always

Steps to Reproduce:
1. ipa-server-install --external-ca

See https://fedorapeople.org/groups/freeipa/prci/jobs/11243180-4c42-11e8-87d9-fa163e63acdb/test_external_ca.py-TestExternalCA--test_external_ca/master.ipa.test/var/log/


Actual results:
Installation failed: memoryview: a bytes-like object is required, not 'str'

Expected results:
Installation passes

Additional info:
The issue is caused by a wrong type. In Python 3, the input to subprocess communiate() must be bytes, not str.

2018-04-30 06:49:09 pki.nssdb   : DEBUG    Command: certutil -R -d /var/lib/pki/pki-tomcat/alias -f /tmp/tmpehzy51ho/password.txt -s CN=Certificate Authority,O=IPA.TEST -o /tmp/tmpehzy51ho/request.bin -z /tmp/tmpehzy51ho/noise.bin -k rsa -g 2048 -Z SHA256 --keyUsage digitalSignature,nonRepudiation,certSigning,crlSigning,critical -2
2018-04-30 06:49:09 pkispawn    : DEBUG    ....... Error Type: TypeError
2018-04-30 06:49:09 pkispawn    : DEBUG    ....... Error Message: memoryview: a bytes-like object is required, not 'str'
2018-04-30 06:49:09 pkispawn    : DEBUG    .......   File "/usr/lib/python3.6/site-packages/pki/server/pkispawn.py", line 534, in main
    scriptlet.spawn(deployer)
  File "/usr/lib/python3.6/site-packages/pki/server/deployment/scriptlets/configuration.py", line 952, in spawn
    self.generate_system_cert_requests(deployer, nssdb, subsystem)
  File "/usr/lib/python3.6/site-packages/pki/server/deployment/scriptlets/configuration.py", line 353, in generate_system_cert_requests
    self.generate_ca_signing_csr(deployer, nssdb, subsystem)
  File "/usr/lib/python3.6/site-packages/pki/server/deployment/scriptlets/configuration.py", line 177, in generate_ca_signing_csr
    generic_exts=generic_exts
  File "/usr/lib/python3.6/site-packages/pki/server/deployment/scriptlets/configuration.py", line 124, in generate_csr
    generic_exts=generic_exts)
  File "/usr/lib/python3.6/site-packages/pki/nssdb.py", line 558, in create_request
    p.communicate(keystroke)
  File "/usr/lib64/python3.6/subprocess.py", line 843, in communicate
    stdout, stderr = self._communicate(input, endtime, timeout)
  File "/usr/lib64/python3.6/subprocess.py", line 1499, in _communicate
    input_view = memoryview(self._input)

Comment 1 Christian Heimes 2018-04-30 14:13:17 UTC

I found two more bugs related to external CA:

First bug reported as https://pagure.io/dogtagpki/issue/3007

# pki-server -v subsystem-cert-validate -i pki-tomcat ca signing
Command: subsystem-cert-validate -i pki-tomcat ca signing
  Cert ID: signing
  Nickname: caSigningCert cert-pki-ca
  Usage: SSLCA
  Token: Internal Key Storage Token
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/pki/server/pkiserver.py", line 119, in <module>
    cli.execute(sys.argv)
  File "/usr/lib/python3.6/site-packages/pki/server/pkiserver.py", line 111, in execute
    super(PKIServerCLI, self).execute(args)
  File "/usr/lib/python3.6/site-packages/pki/cli/__init__.py", line 204, in execute
    module.execute(module_args)
  File "/usr/lib/python3.6/site-packages/pki/cli/__init__.py", line 204, in execute
    module.execute(module_args)
  File "/usr/lib/python3.6/site-packages/pki/cli/__init__.py", line 204, in execute
    module.execute(module_args)
  File "/usr/lib/python3.6/site-packages/pki/server/cli/subsystem.py", line 966, in execute
    certs_valid &= self.validate_certificate(instance, cert)
  File "/usr/lib/python3.6/site-packages/pki/server/cli/subsystem.py", line 1007, in validate_certificate
    os.write(pwfile_handle, passwd)
TypeError: a bytes-like object is required, not 'str'
ERROR: a bytes-like object is required, not 'str'


Second bug reported as https://pagure.io/dogtagpki/issue/3008

2018-04-30 15:52:07 pkispawn    : INFO     ....... BtoA /root/.dogtag/pki-tomcat/ca/alias/admin_pkcs10.bin /root/.dogtag/pki-tomcat/ca/alias/admin_pkcs10.bin.asc
2018-04-30 15:52:07 pkispawn    : INFO     ....... loading caSigningCert External CA certificate
2018-04-30 15:52:07 pki.nssdb   : DEBUG    Command: certutil -L -d /var/lib/pki/pki-tomcat/alias -f /tmp/tmptv77qn7u/password.txt -n caSigningCert External CA -a
2018-04-30 15:52:07 pkispawn    : DEBUG    ....... Error Type: TypeError
2018-04-30 15:52:07 pkispawn    : DEBUG    ....... Error Message: Object of type 'bytes' is not JSON serializable
2018-04-30 15:52:07 pkispawn    : DEBUG    .......   File "/usr/lib/python3.6/site-packages/pki/server/pkispawn.py", line 534, in main
    scriptlet.spawn(deployer)
  File "/usr/lib/python3.6/site-packages/pki/server/deployment/scriptlets/configuration.py", line 1038, in spawn
    json.dumps(data, cls=pki.encoder.CustomTypeEncoder))
  File "/usr/lib64/python3.6/json/__init__.py", line 238, in dumps
    **kw).encode(obj)
  File "/usr/lib64/python3.6/json/encoder.py", line 199, in encode
    chunks = self.iterencode(o, _one_shot=True)
  File "/usr/lib64/python3.6/json/encoder.py", line 257, in iterencode
    return _iterencode(o, 0)
  File "/usr/lib/python3.6/site-packages/pki/encoder.py", line 92, in default
    return json.JSONEncoder.default(self, o)
  File "/usr/lib64/python3.6/json/encoder.py", line 180, in default
    o.__class__.__name__)

Comment 2 Christian Heimes 2018-04-30 14:15:04 UTC

https://pagure.io/dogtagpki/issue/3005 has been fixed in https://github.com/dogtagpki/pki/commit/f9a48a40491726c6c83bc5e1f624aa550c2a5b8d

https://pagure.io/dogtagpki/issue/3007 has been fixed in https://github.com/dogtagpki/pki/commit/22abe1c445135abdbb7b74b87d5131d6fa168ef8

https://pagure.io/dogtagpki/issue/3008 is still under investigation.

Comment 3 Christian Heimes 2018-05-02 07:05:15 UTC

https://pagure.io/dogtagpki/issue/3008 has been fixed in https://github.com/dogtagpki/pki/commit/16f3197aa4a69f1ba3b8e789e23d614df137bb80


Now external CA installation is failing in step 2:

2018-05-01 15:34:47 [https-jsse-nio-8443-exec-9] FINE: Established LDAP connection using basic authentication to host master.ipa.test port 389 as cn=Directory Manager
2018-05-01 15:34:47 [https-jsse-nio-8443-exec-9] FINE: initializing with mininum 3 and maximum 15 connections to host master.ipa.test port 389, secure connection, false, authentication type 1
2018-05-01 15:34:47 [https-jsse-nio-8443-exec-9] FINE: increasing minimum connections by 3
2018-05-01 15:34:47 [https-jsse-nio-8443-exec-9] FINE: new total available connections 3
2018-05-01 15:34:47 [https-jsse-nio-8443-exec-9] FINE: new number of connections 3
2018-05-01 15:34:47 [https-jsse-nio-8443-exec-9] FINE: Cert Repot inited
2018-05-01 15:34:47 [https-jsse-nio-8443-exec-9] FINE: CRL Repot inited
2018-05-01 15:34:47 [https-jsse-nio-8443-exec-9] FINE: Replica Repot inited
2018-05-01 15:34:47 [https-jsse-nio-8443-exec-9] FINE: CertificateAuthority:initSigUnit: ca cert found
2018-05-01 15:34:47 [https-jsse-nio-8443-exec-9] WARNING: java.security.cert.CertificateException: java.security.cert.CertificateException: Unable to initialize, java.io.IOException: DerInput.getLength(): lengthTag=66, too big.
	at netscape.security.x509.X509CertImpl.<init>(X509CertImpl.java:186)
	at netscape.security.x509.X509CertImpl.<init>(X509CertImpl.java:160)
	at com.netscape.ca.CertificateAuthority.initSigUnit(CertificateAuthority.java:1681)
	at com.netscape.ca.CertificateAuthority.init(CertificateAuthority.java:542)
	at com.netscape.cmscore.apps.CMSEngine.reinit(CMSEngine.java:1241)
	at com.netscape.certsrv.apps.CMS.reinit(CMS.java:195)
	at com.netscape.cms.servlet.csadmin.ConfigurationUtils.reInitSubsystem(ConfigurationUtils.java:2300)
	at org.dogtagpki.server.rest.SystemConfigService.configure(SystemConfigService.java:165)
	at org.dogtagpki.server.rest.SystemConfigService.configure(SystemConfigService.java:105)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:139)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:295)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:249)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:236)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:402)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:209)
	at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:221)
	at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
	at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
...
2018-05-01 15:34:48 [https-jsse-nio-8443-exec-9] FINE: CertInfoProfile: Populating certificate with com.netscape.cms.profile.def.ValidityDefault
2018-05-01 15:34:48 [https-jsse-nio-8443-exec-9] FINE: ValidityDefault: start time: 0
2018-05-01 15:34:48 [https-jsse-nio-8443-exec-9] FINE: ValidityDefault: not before: Tue May 01 15:34:48 UTC 2018
2018-05-01 15:34:48 [https-jsse-nio-8443-exec-9] FINE: ValidityDefault: range: 720
2018-05-01 15:34:48 [https-jsse-nio-8443-exec-9] FINE: ValidityDefault: range unit: day
2018-05-01 15:34:48 [https-jsse-nio-8443-exec-9] FINE: ValidityDefault: not after: Mon Apr 20 15:34:48 UTC 2020
2018-05-01 15:34:48 [https-jsse-nio-8443-exec-9] FINE: ValidityDefault: populate: adjustValidity is true
2018-05-01 15:34:48 [https-jsse-nio-8443-exec-9] FINE: CertInfoProfile: Unable to populate certificate: Unable to get ca certificate: Unable to initialize, java.io.IOException: DerInput.getLength(): lengthTag=66, too big.
2018-05-01 15:34:48 [https-jsse-nio-8443-exec-9] SEVERE: Configuration failed: Unable to get ca certificate: Unable to initialize, java.io.IOException: DerInput.getLength(): lengthTag=66, too big.
Unable to get ca certificate: Unable to initialize, java.io.IOException: DerInput.getLength(): lengthTag=66, too big.
	at com.netscape.cms.profile.def.ValidityDefault.populate(ValidityDefault.java:323)
	at com.netscape.certsrv.profile.CertInfoProfile.populate(CertInfoProfile.java:100)
	at com.netscape.cms.servlet.csadmin.CertUtil.createLocalCert(CertUtil.java:542)
	at com.netscape.cms.servlet.csadmin.ConfigurationUtils.configLocalCert(ConfigurationUtils.java:2754)
	at com.netscape.cms.servlet.csadmin.ConfigurationUtils.configCert(ConfigurationUtils.java:2578)
	at org.dogtagpki.server.rest.SystemConfigService.processCert(SystemConfigService.java:483)
	at org.dogtagpki.server.rest.SystemConfigService.processCerts(SystemConfigService.java:303)
	at org.dogtagpki.server.rest.SystemConfigService.configure(SystemConfigService.java:170)
	at org.dogtagpki.server.rest.SystemConfigService.configure(SystemConfigService.java:105)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

Comment 4 Christian Heimes 2018-05-02 08:42:19 UTC

"DerInput.getLength(): lengthTag=66, too big" is caused by another Python 3 regression. Due to a type handling bug, Dogtag writes the certificate as 

   ca.signing.cert=b'base64data'

instead of

   ca.signing.cert=base64data

to CS.cfg. Eventually this loads to a cert loading issue that materializes as an ASN.1 parsing error.

A subsequent fix for https://pagure.io/dogtagpki/issue/3005 addresses the issue. Further more, Dogtag will catch this kind of type bugs and report it much earlier. The patch is currently under testing.

Comment 5 Fedora Update System 2018-05-04 15:03:50 UTC

dogtag-pki-10.6.1-1.fc28 dogtag-pki-theme-10.6.1-1.fc28 pki-console-10.6.1-1.fc28 pki-core-10.6.1-1.fc28 has been submitted as an update to Fedora 28. https://bodhi.fedoraproject.org/updates/FEDORA-2018-4f684aab1a

Comment 6 Fedora Update System 2018-05-06 10:08:09 UTC

dogtag-pki-10.6.1-1.fc28, dogtag-pki-theme-10.6.1-1.fc28, pki-console-10.6.1-1.fc28, pki-core-10.6.1-1.fc28 has been pushed to the Fedora 28 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-4f684aab1a

Comment 7 Fedora Update System 2018-05-13 19:59:47 UTC

dogtag-pki-10.6.1-1.fc28, dogtag-pki-theme-10.6.1-1.fc28, pki-console-10.6.1-1.fc28, pki-core-10.6.1-1.fc28 has been pushed to the Fedora 28 stable repository. If problems still persist, please make note of it in this bug report.