Puppetserver External CA with CRL not working

[Steve Viola]

Hello,

I've configured my puppetserver with an External CA, and everything was working as expected off the bat, but when I add the CRL path, puppet agent runs on all hosts stops running. webserver.conf looks like this:

webserver: {
    access-log-config: /etc/puppetlabs/puppetserver/request-logging.xml
    client-auth: want
    ssl-host: 0.0.0.0
    ssl-port: 8140
    ssl-cert: /etc/puppetlabs/puppet/ssl/certs/<hostname>
    ssl-key: /etc/puppetlabs/puppet/ssl/private_keys/<hostname>
    ssl-ca-cert: /etc/puppetlabs/puppet/ssl/ca/ca.crt
    ssl-cert-chain: /etc/puppetlabs/puppet/ssl/ca/ca_chain.pem
    ssl-crl-path: /etc/puppetlabs/puppet/ssl/ca/ca_crl.pem
}

 At first there were not any errors appearing in the puppetserver logs, but after changing the logback log level to DEBUG, I finally saw found errors in the puppetserver.log file:

2017-03-21 16:28:11,652 DEBUG [qtp1057116152-68] [o.e.j.s.HttpConnection]
javax.net.ssl.SSLHandshakeException: General SSLEngine problem
at sun.security.ssl.Handshaker.checkThrown(Handshaker.java:1478)
at sun.security.ssl.SSLEngineImpl.checkTaskThrown(SSLEngineImpl.java:535)
at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:813)
at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781)
at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624)
at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:516)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:239)
at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
at java.lang.Thread.run(Thread.java:745)
Caused by: javax.net.ssl.SSLHandshakeException: General SSLEngine problem
at sun.security.ssl.Alerts.getSSLException(Alerts.java:192)
at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1728)
at sun.security.ssl.Handshaker.fatalSE(Handshaker.java:304)
at sun.security.ssl.Handshaker.fatalSE(Handshaker.java:296)
at sun.security.ssl.ServerHandshaker.clientCertificate(ServerHandshaker.java:1906)
at sun.security.ssl.ServerHandshaker.processMessage(ServerHandshaker.java:233)
at sun.security.ssl.Handshaker.processLoop(Handshaker.java:1026)
at sun.security.ssl.Handshaker$1.run(Handshaker.java:966)
at sun.security.ssl.Handshaker$1.run(Handshaker.java:963)
at java.security.AccessController.doPrivileged(Native Method)
at sun.security.ssl.Handshaker$DelegatedTask.run(Handshaker.java:1416)
at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:612)
... 5 common frames omitted
Caused by: sun.security.validator.ValidatorException: PKIX path validation failed: java.security.cert.CertPathValidatorException: Could not determine revocation status
at sun.security.validator.PKIXValidator.doValidate(PKIXValidator.java:352)
at sun.security.validator.PKIXValidator.engineValidate(PKIXValidator.java:249)
at sun.security.validator.Validator.validate(Validator.java:260)
at sun.security.ssl.X509TrustManagerImpl.validate(X509TrustManagerImpl.java:324)
at sun.security.ssl.X509TrustManagerImpl.checkTrusted(X509TrustManagerImpl.java:279)
at sun.security.ssl.X509TrustManagerImpl.checkClientTrusted(X509TrustManagerImpl.java:130)
at sun.security.ssl.ServerHandshaker.clientCertificate(ServerHandshaker.java:1893)
... 12 common frames omitted
Caused by: java.security.cert.CertPathValidatorException: Could not determine revocation status
at sun.security.provider.certpath.PKIXMasterCertPathValidator.validate(PKIXMasterCertPathValidator.java:135)
at sun.security.provider.certpath.PKIXCertPathValidator.validate(PKIXCertPathValidator.java:219)
at sun.security.provider.certpath.PKIXCertPathValidator.validate(PKIXCertPathValidator.java:140)
at sun.security.provider.certpath.PKIXCertPathValidator.engineValidate(PKIXCertPathValidator.java:79)
at java.security.cert.CertPathValidator.validate(CertPathValidator.java:292)
at sun.security.validator.PKIXValidator.doValidate(PKIXValidator.java:347)
... 18 common frames omitted
Caused by: java.security.cert.CertPathValidatorException: Could not determine revocation status
at sun.security.provider.certpath.RevocationChecker.buildToNewKey(RevocationChecker.java:1092)
at sun.security.provider.certpath.RevocationChecker.verifyWithSeparateSigningKey(RevocationChecker.java:910)
at sun.security.provider.certpath.RevocationChecker.checkCRLs(RevocationChecker.java:577)
at sun.security.provider.certpath.RevocationChecker.checkCRLs(RevocationChecker.java:465)
at sun.security.provider.certpath.RevocationChecker.check(RevocationChecker.java:367)
at sun.security.provider.certpath.RevocationChecker.check(RevocationChecker.java:337)
at sun.security.provider.certpath.PKIXMasterCertPathValidator.validate(PKIXMasterCertPathValidator.java:125)
... 23 common frames omitted

Testing the CRL using openssl works as expected, after concatenating the CA crt and the CRL crt, and running the openssl command below verifies the cert hasn't been revoked.

$ openssl verify -crl_check -CAfile crl_ca.pem /etc/puppetlabs/puppet/ssl/certs/<hostname>.pem
/etc/puppetlabs/puppet/ssl/certs/<hostname>.pem: OK

OpenSSL also verifies that certs have been revoked as well:

$ openssl verify -crl_check -CAfile crl_chain3.pem <revoked cert>.pem
<revoked cert>.pem: O = <domain>, CN = <hostname>
error 23 at 0 depth lookup:certificate revoked

Are there any additional setting needed to get Java working to honor the CRL? Is there any resource for better logging to be able to narrow down the issue? Is using a CRL with an external CA still supported in puppetserver, or should I avoid using a CRL and use OCSP instead?

Any help or advice would be hugely appreciated.

Thanks a lot.

[Steve Viola]

To clarify, I this is with puppetserver 2.7.2 from the puppetlabs yum repo. Using the version of openssl in /opt/puppetlabs/puppet/bin/ provides the same output as the system openssl

[Adrien Thebo]

The best that I can determine from the stack traces that you've shown and the error messages is that Puppetserver somehow can't associate the CRLs that you've provided with your external CA or signed certificate. It looks like adding `-Djava.security.debug=all` will provide a lot of information into SSL operations - though it's incredibly verbose so you won't want to do this on a production node. I'm doing some tests on my end with this as well but you may want to test this in your environment and see if it provides any useful information.

Would it be possible for you to provide your CA cert/client cert/CRL? Or is that private?

Lastly, Puppet and Puppetserver have two CRLs. One is '/etc/puppetlabs/puppet/ssl/ca/ca_crt.pem' and the other is '/etc/puppetlabs/puppet/ssl/crl.pem'. It's possible for these to get out of sync which can lead to all sorts of confusing behavior. Could you confirm that those CRLs match?

[Adrien Thebo]

Whoops, instead of '/etc/puppetlabs/puppet/ssl/ca/ca_crt.pem' that should be '/etc/puppetlabs/puppet/ssl/ca/ca_crl.pem' - the CRL in the CA directory instead of the CA certificate. Sorry about mixing those up!

[Steve Viola]

Adrien, thanks for the info and suggestions. Yeah, the crl is the same in both locations. According to the puppet documentation, this file should be copied from cacrl to hostcrl, but I haven't seen that behavior, so I've been manually syncing those up. In my case the values for these variables are  '/etc/puppetlabs/puppet/ssl/ca/ca_crl.pem' and '/etc/puppetlabs/puppet/ssl/crl.pem', respectively.

Good idea with the java arguments. I've gone ahead and added that, and you were right, this is a lot of output. Here's a whole bunch of additional output:

certpath: PKIXCertPathValidator.engineValidate()...

certpath: X509CertSelector.match(SN: 1

  Issuer: CN=Certificate Authority, O=CRITICALMENTION.COM

  Subject: CN=Certificate Authority, O=CRITICALMENTION.COM)

certpath: X509CertSelector.match returning: true

certpath: YES - try this trustedCert

certpath: anchor.getTrustedCert().getSubjectX500Principal() = CN=Certificate Authority, O=CRITICALMENTION.COM

certpath: --------------------------------------------------------------

certpath: Executing PKIX certification path validation algorithm.

certpath: Checking cert1 - Subject: CN=ip-10-0-101-7.ec2.internal, O=CRITICALMENTION.COM

certpath: Set of critical extensions: {2.5.29.15}

certpath: -Using checker1 ... [sun.security.provider.certpath.UntrustedChecker]

certpath: -checker1 validation succeeded

certpath: -Using checker2 ... [sun.security.provider.certpath.AlgorithmChecker]

certpath: Constraints.permits(): SHA256withRSA

certpath: KeySizeConstraints.permits(): RSA

certpath: -checker2 validation succeeded

certpath: -Using checker3 ... [sun.security.provider.certpath.KeyChecker]

certpath: X509CertSelector.match(SN: 6ffe018a

  Issuer: CN=Certificate Authority, O=CRITICALMENTION.COM

  Subject: CN=ip-10-0-101-7.ec2.internal, O=CRITICALMENTION.COM)

certpath: X509CertSelector.match returning: true

certpath: -checker3 validation succeeded

certpath: -Using checker4 ... [sun.security.provider.certpath.ConstraintsChecker]

certpath: ---checking basic constraints...

certpath: i = 1, maxPathLength = 1

certpath: after processing, maxPathLength = 1

certpath: basic constraints verified.

certpath: ---checking name constraints...

certpath: prevNC = null, newNC = null

certpath: mergedNC = null

certpath: name constraints verified.

certpath: -checker4 validation succeeded

certpath: -Using checker5 ... [sun.security.provider.certpath.PolicyChecker]

certpath: PolicyChecker.checkPolicy() ---checking certificate policies...

certpath: PolicyChecker.checkPolicy() certIndex = 1

certpath: PolicyChecker.checkPolicy() BEFORE PROCESSING: explicitPolicy = 2

certpath: PolicyChecker.checkPolicy() BEFORE PROCESSING: policyMapping = 2

certpath: PolicyChecker.checkPolicy() BEFORE PROCESSING: inhibitAnyPolicy = 2

certpath: PolicyChecker.checkPolicy() BEFORE PROCESSING: policyTree = anyPolicy  ROOT

certpath: PolicyChecker.processPolicies() no policies present in cert

certpath: PolicyChecker.checkPolicy() AFTER PROCESSING: explicitPolicy = 2

certpath: PolicyChecker.checkPolicy() AFTER PROCESSING: policyMapping = 2

certpath: PolicyChecker.checkPolicy() AFTER PROCESSING: inhibitAnyPolicy = 2

certpath: PolicyChecker.checkPolicy() AFTER PROCESSING: policyTree = null

certpath: PolicyChecker.checkPolicy() certificate policies verified

certpath: -checker5 validation succeeded

certpath: -Using checker6 ... [sun.security.provider.certpath.BasicChecker]

certpath: ---checking timestamp:Fri Mar 24 18:42:35 UTC 2017...

certpath: timestamp verified.

certpath: ---checking subject/issuer name chaining...

certpath: subject/issuer name chaining verified.

certpath: ---checking signature...

certpath: signature verified.

certpath: BasicChecker.updateState issuer: CN=Certificate Authority, O=CRITICALMENTION.COM; subject: CN=ip-10-0-101-7.ec2.internal, O=CRITICALMENTION.COM; serial#: 1878917514
certpath: -checker6 validation succeeded
certpath: -Using checker7 ... [sun.security.provider.certpath.RevocationChecker]
certpath: RevocationChecker.check: checking cert
  SN:     6ffe018a
  Subject: CN=ip-10-0-101-7.ec2.internal, O=CRITICALMENTION.COM
  Issuer: CN=Certificate Authority, O=CRITICALMENTION.COM
certpath: RevocationChecker.checkCRLs() ---checking revocation status ...
certpath: RevocationChecker.checkCRLs() possible crls.size() = 1
certpath: RevocationChecker.verifyPossibleCRLs: Checking CRLDPs for CN=ip-10-0-101-7.ec2.internal, O=CRITICALMENTION.COM
certpath: DistributionPointFetcher.verifyCRL: checking revocation status for
  SN:     6ffe018a
  Subject: CN=ip-10-0-101-7.ec2.internal, O=CRITICALMENTION.COM
  Issuer: CN=Certificate Authority, O=CRITICALMENTION.COM
certpath: RevocationChecker.checkCRLs() approved crls.size() = 0
certpath: RevocationChecker.verifyWithSeparateSigningKey() ---checking revocation status...
certpath: RevocationChecker.buildToNewKey() starting work
certpath: RevocationChecker.buildToNewKey() about to try build ...
certpath: SunCertPathBuilder.engineBuild([ (lots of verbose stuff removed here) )
certpath: SunCertPathBuilder.buildForward()...
certpath: SunCertPathBuilder.depthFirstSearchForward(CN=Certificate Authority, O=CRITICALMENTION.COM, State [
  issuerDN of last cert: null
  traversedCACerts: 0
  init: true
  keyParamsNeeded: false
  subjectNamesTraversed:
[]]
)
certpath: ForwardBuilder.getMatchingCerts()...
certpath: ForwardBuilder.getMatchingEECerts()...
certpath: X509CertSelector.match(SN: 6ffe018a
  Issuer: CN=Certificate Authority, O=CRITICALMENTION.COM
  Subject: CN=ip-10-0-101-7.ec2.internal, O=CRITICALMENTION.COM)
certpath: X509CertSelector.match: subject DNs don't match
certpath: ForwardBuilder.getMatchingCACerts()...
certpath: ForwardBuilder.getMatchingCACerts(): the target is a CA
certpath: X509CertSelector.match(SN: 1
  Issuer: CN=Certificate Authority, O=CRITICALMENTION.COM
  Subject: CN=Certificate Authority, O=CRITICALMENTION.COM)
certpath: X509CertSelector.match returning: true
certpath: RejectKeySelector.match: bad key
certpath: X509CertSelector.match(SN: 6ffe018a
  Issuer: CN=Certificate Authority, O=CRITICALMENTION.COM
  Subject: CN=ip-10-0-101-7.ec2.internal, O=CRITICALMENTION.COM)
certpath: X509CertSelector.match: subject DNs don't match
certpath: ForwardBuilder.getMatchingCACerts: found 0 CA certs
certpath: SunCertPathBuilder.depthFirstSearchForward(): certs.size=0
certpath: SunCertPathBuilder.engineBuild: 2nd pass; try building again searching all certstores
certpath: SunCertPathBuilder.buildForward()...
certpath: SunCertPathBuilder.depthFirstSearchForward(CN=Certificate Authority, O=CRITICALMENTION.COM, State [
  issuerDN of last cert: null
  traversedCACerts: 0
  init: true
  keyParamsNeeded: false
  subjectNamesTraversed:
[]]
)
certpath: ForwardBuilder.getMatchingCerts()...
certpath: ForwardBuilder.getMatchingEECerts()...
certpath: X509CertSelector.match(SN: 6ffe018a
  Issuer: CN=Certificate Authority, O=CRITICALMENTION.COM
  Subject: CN=ip-10-0-101-7.ec2.internal, O=CRITICALMENTION.COM)
certpath: X509CertSelector.match: subject DNs don't match
certpath: ForwardBuilder.getMatchingCACerts()...
certpath: ForwardBuilder.getMatchingCACerts(): the target is a CA
certpath: X509CertSelector.match(SN: 1
  Issuer: CN=Certificate Authority, O=CRITICALMENTION.COM
  Subject: CN=Certificate Authority, O=CRITICALMENTION.COM)
certpath: X509CertSelector.match returning: true
certpath: RejectKeySelector.match: bad key
certpath: X509CertSelector.match(SN: 6ffe018a
  Issuer: CN=Certificate Authority, O=CRITICALMENTION.COM
  Subject: CN=ip-10-0-101-7.ec2.internal, O=CRITICALMENTION.COM)
certpath: X509CertSelector.match: subject DNs don't match
certpath: ForwardBuilder.getMatchingCACerts: found 0 CA certs
certpath: SunCertPathBuilder.depthFirstSearchForward(): certs.size=0

When removing the crl from webserver conf, that output doesn't happen in the logs, so it looks like it's output from the CRL checks. I'm not even sure if that's an error, but it looks like it could be one? Is it possible that I'm not pulling in the CA cert or the CRL? I'm not sure what subject DNs it's checking that doesn't match, but right now, that's my biggest target to figure out.

The Puppetserver documentation is kinda confusing, since it says ssl-crl-path is Equivalent to the ‘SSLCARevocationPath’ Apache config setting, but the Apache settings take the directory with PEM-encoded CRLs, and providing a path in the webserver.conf results in the puppetserver not starting up, so I'm assuming I need to provide the crl file, and not directory to the puppetserver. Maybe I'm setting this incorrectly?

I will send over the CA file, client cert and the CRL in a separate message directly to you.

Thanks for your suggestions and help

[Adrien Thebo]

A coworker just pointed out that the CRL nextUpdate field in the CRL that you provided was March 24th; it's quite possible that Jetty is treating the nextUpdate field as the end date of the CRL and considering it invalid. That would explain why no CRL could be found - the only one present was effectively expired. I've tinkered around with CRLs on the Ruby/OpenSSL side of things and have encountered cases where OpenSSL treats  the CRL nextUpdate field as the expiration date so it's not inconceivable that Puppetserver/Jetty does the same thing.

For what it's worth I duplicated your `openssl verify` invocation with a bundled CA cert/CRL and it's failing on my end because it can't find a CRL; this might lend support for the expired CRL argument.

[Steve Viola]

Hey Adrien,

A coworker just pointed out that the CRL nextUpdate field in the CRL that you provided was March 24th; it's quite possible that Jetty is treating the nextUpdate field as the end date of the CRL and considering it invalid.

Yeah, that date was the nextUpdate value when I grabbed the CRL from the CA on Friday. Basically the CA is updating the CRL every hour at the time in the nextUpdate field. On the puppetserver, I'm going to grab it every hour to make sure it always has an updated CRL with any revoked certs. I guess if jetty is using that time as expired, and it's only a few hours in the future, it might be considering it already expired, but that seems a bit silly on jetty's end, especially to not log it.

For what it's worth I duplicated your `openssl verify` invocation with a bundled CA cert/CRL and it's failing on my end because it can't find a CRL; this might lend support for the expired CRL argument.

I really appreciate all your help. I think possibly the short interval between renewals of the CRL makes it hard for us to sync up and see the timing in between those windows. When I run the openssl verify with the CRL file I provided to you (with the outdated timestamp), it does tell me the CRL has expired, but does also show the status of the certificate, and sets the exit code appropriately based on if the cert is expired or not, even when using the expired CRL.

I'll continue to play with the CA settings and will see if I can make the CRL update every day (or longer) to verify the Jetty thoughts, and to also have a something better to send over if you still want to look into a non-expired CRL.

Thanks a lot for your help and advice.

[Kelvin To]

Hi all,

I had the same issue and it was CRL nextUpdate field that caused the issue.