Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Puppetserver CA API race-condition(?) #2851

Closed
anders-larsson opened this issue May 6, 2024 · 3 comments · Fixed by #2853 or voxpupuli/container-puppetserver#92
Closed

Puppetserver CA API race-condition(?) #2851

anders-larsson opened this issue May 6, 2024 · 3 comments · Fixed by #2853 or voxpupuli/container-puppetserver#92
Labels

Comments

@anders-larsson
Copy link

Describe the Bug

Puppetserver CA API gets into a race-condition sometimes when the Certificate Status endpoint is used to first revoke and afterwards clean the certificate. When this occurs puppetserver will start throwing ERROR [p.r.core] Internal Server Error: java.io.FileNotFoundException: /path/to/cert.pem (No such file or directory) when attempts to revoke/clean said certificate occurs.

We have not seen this bug in 7.13.0 and earlier versions. First time it occurred was after updating to 8.4.0.

Expected Behavior

Certificate is successfully revoked and cleaned and can be re-used.

Steps to Reproduce

Steps to reproduce the behavior:

  • PUT /puppet-ca/v1/certificate_status/mycertname
  • DELETE /puppet-ca/v1/certificate_status/mycertname
  • GET /puppet-ca/v1/certificate_status/mycertname returns ERROR [p.r.core] Internal Server Error: java.io.FileNotFoundException: /path/to/cert.pem (No such file or directory)

As stated earlier. This does not always happen.

Environment

  • puppetserver 8.6.0
  • Ubuntu 22.04
  • CA directory is stored in glusterfs
  • Container image used with extra customizations
  • Modifications (both in 7.x and 8.x):
    -- puppet.conf - autosign set to run a script
    -- auth.conf - allow a specific certificate to use endpoint - /puppet-ca/v1/certificate_status
  • Modifications (new for 8.x):
    -- puppetserver.conf - ca-ttl set: 5y
    -- puppetserver.conf - allow-auto-renewal: true
    -- puppetserver.conf - auto-renewal-cert-ttl: 5y

Additional Context

It seems to help to have the node reach out to the CA and have a new certificate request recreated and then use API to sign it. Afterwards it works again as expected.

puppetlabs/puppetserver-ca-cli#120 migh be related.

Example logs:

19/Apr/2024:11:33:35 +0000 "GET /puppet-ca/v1/certificate_status/client.domain.tld HTTP/1.1" 200 932 10.0.8.41 10.0.8.41 8140 18
2024-04-19 11:33:36,062 INFO  [p.p.certificate-authority] Entity revoker.domain.tld revoked 1 certificate: client.domain.tld.
19/Apr/2024:11:33:36 +0000 "PUT /puppet-ca/v1/certificate_status/client.domain.tld HTTP/1.1" 204 0 10.0.8.41 10.0.8.41 8140 48
2024-04-19 11:33:36,073 WARN  [p.p.certificate-authority] No certificate request for client.domain.tld at expected path /etc/puppetlabs/puppetserver/ca/requests/client.domain.tld.pem
19/Apr/2024:11:33:36 +0000 "DELETE /puppet-ca/v1/certificate_status/client.domain.tld HTTP/1.1" 204 162 10.0.8.41 10.0.8.41 8140 5
2024-04-19 11:33:36,315 INFO  [o.e.j.u.s.SslContextFactory] x509=X509@5e09380f(private key,h=[puppet, puppet.domain.tld, puppetca, puppetca.domain.tld],a=[],w=[]) for InternalSslContextFactory@56114dcd[provider=null,keyStore=null,trustStore=null]
2024-04-19 11:34:34,070 ERROR [p.r.core] Internal Server Error: java.io.FileNotFoundException: /etc/puppetlabs/puppetserver/ca/requests/client.domain.tld.pem (No such file or directory)
	at java.base/java.io.FileInputStream.open0(Native Method)
	at java.base/java.io.FileInputStream.open(FileInputStream.java:216)
	at java.base/java.io.FileInputStream.<init>(FileInputStream.java:157)
	at clojure.java.io$fn__11617.invokeStatic(io.clj:229)
	at clojure.java.io$fn__11617.invoke(io.clj:229)
	at clojure.java.io$fn__11569$G__11523__11576.invoke(io.clj:69)
	at clojure.java.io$fn__11629.invokeStatic(io.clj:258)
	at clojure.java.io$fn__11629.invoke(io.clj:254)
	at clojure.java.io$fn__11569$G__11523__11576.invoke(io.clj:69)
	at clojure.java.io$fn__11591.invokeStatic(io.clj:165)
	at clojure.java.io$fn__11591.invoke(io.clj:165)
	at clojure.java.io$fn__11530$G__11519__11537.invoke(io.clj:69)
	at clojure.java.io$reader.invokeStatic(io.clj:102)
	at clojure.java.io$reader.doInvoke(io.clj:86)
	at clojure.lang.RestFn.invoke(RestFn.java:410)
	at puppetlabs.ssl_utils.core$fn__21975$pem__GT_csr__21980$fn__21981.invoke(core.clj:727)
	at puppetlabs.ssl_utils.core$fn__21975$pem__GT_csr__21980.invoke(core.clj:721)
	at puppetlabs.puppetserver.certificate_authority$fn__39741$get_cert_or_csr_status__39746$fn__39750.invoke(certificate_authority.clj:2062)
	at puppetlabs.puppetserver.certificate_authority$fn__39741$get_cert_or_csr_status__39746.invoke(certificate_authority.clj:2051)
	at puppetlabs.services.ca.certificate_authority_core$certificate_status$fn__42391$fn__42408.invoke(certificate_authority_core.clj:471)
	at liberator.core$run_handler.invokeStatic(core.clj:176)
	at liberator.core$run_handler.invoke(core.clj:131)
	at liberator.core$handle_ok.invokeStatic(core.clj:224)
	at liberator.core$handle_ok.invoke(core.clj:224)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$multiple_representations_QMARK_.invokeStatic(core.clj:232)
	at liberator.core$multiple_representations_QMARK_.invoke(core.clj:232)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$put_to_existing_QMARK_.invokeStatic(core.clj:305)
	at liberator.core$put_to_existing_QMARK_.invoke(core.clj:305)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$post_to_existing_QMARK_.invokeStatic(core.clj:308)
	at liberator.core$post_to_existing_QMARK_.invoke(core.clj:308)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$method_patch_QMARK_.invokeStatic(core.clj:315)
	at liberator.core$method_patch_QMARK_.invoke(core.clj:315)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$method_delete_QMARK_.invokeStatic(core.clj:317)
	at liberator.core$method_delete_QMARK_.invoke(core.clj:317)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$if_modified_since_exists_QMARK_.invokeStatic(core.clj:337)
	at liberator.core$if_modified_since_exists_QMARK_.invoke(core.clj:337)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$if_none_match_exists_QMARK_.invokeStatic(core.clj:355)
	at liberator.core$if_none_match_exists_QMARK_.invoke(core.clj:355)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$if_unmodified_since_exists_QMARK_.invokeStatic(core.clj:375)
	at liberator.core$if_unmodified_since_exists_QMARK_.invoke(core.clj:375)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$if_match_exists_QMARK_.invokeStatic(core.clj:389)
	at liberator.core$if_match_exists_QMARK_.invoke(core.clj:389)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$exists_QMARK_.invokeStatic(core.clj:392)
	at liberator.core$exists_QMARK_.invoke(core.clj:392)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$processable_QMARK_.invokeStatic(core.clj:395)
	at liberator.core$processable_QMARK_.invoke(core.clj:395)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$accept_encoding_exists_QMARK_.invokeStatic(core.clj:416)
	at liberator.core$accept_encoding_exists_QMARK_.invoke(core.clj:416)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$accept_charset_exists_QMARK_.invokeStatic(core.clj:429)
	at liberator.core$accept_charset_exists_QMARK_.invoke(core.clj:429)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$accept_language_exists_QMARK_.invokeStatic(core.clj:443)
	at liberator.core$accept_language_exists_QMARK_.invoke(core.clj:443)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$accept_exists_QMARK_.invokeStatic(core.clj:456)
	at liberator.core$accept_exists_QMARK_.invoke(core.clj:456)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$is_options_QMARK_.invokeStatic(core.clj:473)
	at liberator.core$is_options_QMARK_.invoke(core.clj:473)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$valid_entity_length_QMARK_.invokeStatic(core.clj:476)
	at liberator.core$valid_entity_length_QMARK_.invoke(core.clj:476)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$known_content_type_QMARK_.invokeStatic(core.clj:479)
	at liberator.core$known_content_type_QMARK_.invoke(core.clj:479)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$valid_content_header_QMARK_.invokeStatic(core.clj:481)
	at liberator.core$valid_content_header_QMARK_.invoke(core.clj:481)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$allowed_QMARK_.invokeStatic(core.clj:484)
	at liberator.core$allowed_QMARK_.invoke(core.clj:484)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$authorized_QMARK_.invokeStatic(core.clj:487)
	at liberator.core$authorized_QMARK_.invoke(core.clj:487)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$malformed_QMARK_.invokeStatic(core.clj:490)
	at liberator.core$malformed_QMARK_.invoke(core.clj:490)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$method_allowed_QMARK_.invokeStatic(core.clj:493)
	at liberator.core$method_allowed_QMARK_.invoke(core.clj:493)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$uri_too_long_QMARK_.invokeStatic(core.clj:496)
	at liberator.core$uri_too_long_QMARK_.invoke(core.clj:496)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$known_method_QMARK_.invokeStatic(core.clj:499)
	at liberator.core$known_method_QMARK_.invoke(core.clj:499)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$service_available_QMARK_.invokeStatic(core.clj:502)
	at liberator.core$service_available_QMARK_.invoke(core.clj:502)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$initialize_context.invokeStatic(core.clj:504)
	at liberator.core$initialize_context.invoke(core.clj:504)
	at liberator.core$run_resource.invokeStatic(core.clj:595)
	at liberator.core$run_resource.invoke(core.clj:593)
	at puppetlabs.services.ca.certificate_authority_core$certificate_status$fn__42391.invoke(certificate_authority_core.clj:409)
	at compojure.response$fn__17255.invokeStatic(response.clj:33)
	at compojure.response$fn__17255.invoke(response.clj:21)
	at compojure.response$fn__17228$G__17223__17235.invoke(response.clj:6)
	at puppetlabs.services.ca.certificate_authority_core$fn__42441$web_routes__42446$fn__42447$fn__42448.invoke(certificate_authority_core.clj:548)
	at bidi.ring$fn__17042.invokeStatic(ring.cljc:25)
	at bidi.ring$fn__17042.invoke(ring.cljc:21)
	at bidi.ring$fn__17027$G__17022__17036.invoke(ring.cljc:16)
	at puppetlabs.comidi$make_handler$fn__18958.invoke(comidi.clj:245)
	at puppetlabs.trapperkeeper.authorization.ring_middleware$fn__25846$wrap_authorization_check__25851$fn__25852$fn__25853.invoke(ring_middleware.clj:293)
	at puppetlabs.ring_middleware.core$fn__23328$wrap_bad_request__23337$fn__23340$fn__23346.invoke(core.clj:187)
	at puppetlabs.puppetserver.ringutils$fn__36917$wrap_with_trapperkeeper_or_client_whitelist_authorization__36922$fn__36923$fn__36927.invoke(ringutils.clj:131)
	at puppetlabs.i18n.core$locale_negotiator$fn__4728.invoke(core.clj:361)
	at puppetlabs.ring_middleware.core$fn__23426$wrap_uncaught_errors__23435$fn__23438$fn__23443.invoke(core.clj:233)
	at puppetlabs.puppetserver.ringutils$wrap_with_puppet_version_header$fn__36906.invoke(ringutils.clj:90)
	at puppetlabs.ring_middleware.core$fn__23025$wrap_response_logging__23030$fn__23031$fn__23032.invoke(core.clj:53)
	at puppetlabs.trapperkeeper.services.webserver.jetty10_core$ring_handler$fn__29347.invoke(jetty10_core.clj:533)
	at puppetlabs.trapperkeeper.services.webserver.jetty10_core.proxy$org.eclipse.jetty.server.handler.HandlerWrapper$ff19274a.handle(Unknown Source)
	at jdk.internal.reflect.GeneratedMethodAccessor16.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at clojure.lang.Reflector.invokeMatchingMethod(Reflector.java:167)
	at clojure.lang.Reflector.invokeInstanceMethod(Reflector.java:102)
	at puppetlabs.trapperkeeper.services.webserver.normalized_uri_helpers$fn__28883$normalize_uri_handler__28888$fn__28889$fn__28890.invoke(normalized_uri_helpers.clj:73)
	at puppetlabs.trapperkeeper.services.webserver.normalized_uri_helpers.proxy$org.eclipse.jetty.server.handler.HandlerWrapper$ff19274a.handle(Unknown Source)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1384)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1306)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129)
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:192)
	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:141)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:822)
	at com.puppetlabs.trapperkeeper.services.webserver.jetty10.utils.MDCRequestLogHandler.handle(MDCRequestLogHandler.java:48)
	at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
	at org.eclipse.jetty.server.Server.handle(Server.java:563)
	at org.eclipse.jetty.server.HttpChannel$RequestDispatchable.dispatch(HttpChannel.java:1598)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:753)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:501)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:287)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:314)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
	at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:558)
	at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:379)
	at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:146)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
	at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
	at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:421)
	at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:390)
	at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:277)
	at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.run(AdaptiveExecutionStrategy.java:199)
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:411)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:969)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1194)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1149)
	at java.base/java.lang.Thread.run(Thread.java:840)
 
19/Apr/2024:11:34:34 +0000 "GET /puppet-ca/v1/certificate_status/client.domain.tld HTTP/1.1" 500 163 10.0.8.41 10.0.8.41 8140 18
2024-04-19 11:34:46,538 ERROR [p.r.core] Internal Server Error: java.io.FileNotFoundException: /etc/puppetlabs/puppetserver/ca/requests/client.domain.tld.pem (No such file or directory)
	at java.base/java.io.FileInputStream.open0(Native Method)
	at java.base/java.io.FileInputStream.open(FileInputStream.java:216)
	at java.base/java.io.FileInputStream.<init>(FileInputStream.java:157)
	at clojure.java.io$fn__11617.invokeStatic(io.clj:229)
	at clojure.java.io$fn__11617.invoke(io.clj:229)
	at clojure.java.io$fn__11569$G__11523__11576.invoke(io.clj:69)
	at clojure.java.io$fn__11629.invokeStatic(io.clj:258)
	at clojure.java.io$fn__11629.invoke(io.clj:254)
	at clojure.java.io$fn__11569$G__11523__11576.invoke(io.clj:69)
	at clojure.java.io$fn__11591.invokeStatic(io.clj:165)
	at clojure.java.io$fn__11591.invoke(io.clj:165)
	at clojure.java.io$fn__11530$G__11519__11537.invoke(io.clj:69)
	at clojure.java.io$reader.invokeStatic(io.clj:102)
	at clojure.java.io$reader.doInvoke(io.clj:86)
	at clojure.lang.RestFn.invoke(RestFn.java:410)
	at puppetlabs.ssl_utils.core$fn__21975$pem__GT_csr__21980$fn__21981.invoke(core.clj:727)
	at puppetlabs.ssl_utils.core$fn__21975$pem__GT_csr__21980.invoke(core.clj:721)
	at puppetlabs.puppetserver.certificate_authority$fn__39741$get_cert_or_csr_status__39746$fn__39750.invoke(certificate_authority.clj:2062)
	at puppetlabs.puppetserver.certificate_authority$fn__39741$get_cert_or_csr_status__39746.invoke(certificate_authority.clj:2051)
	at puppetlabs.services.ca.certificate_authority_core$certificate_status$fn__42391$fn__42408.invoke(certificate_authority_core.clj:471)
	at liberator.core$run_handler.invokeStatic(core.clj:176)
	at liberator.core$run_handler.invoke(core.clj:131)
	at liberator.core$handle_ok.invokeStatic(core.clj:224)
	at liberator.core$handle_ok.invoke(core.clj:224)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$multiple_representations_QMARK_.invokeStatic(core.clj:232)
	at liberator.core$multiple_representations_QMARK_.invoke(core.clj:232)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$put_to_existing_QMARK_.invokeStatic(core.clj:305)
	at liberator.core$put_to_existing_QMARK_.invoke(core.clj:305)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$post_to_existing_QMARK_.invokeStatic(core.clj:308)
	at liberator.core$post_to_existing_QMARK_.invoke(core.clj:308)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$method_patch_QMARK_.invokeStatic(core.clj:315)
	at liberator.core$method_patch_QMARK_.invoke(core.clj:315)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$method_delete_QMARK_.invokeStatic(core.clj:317)
	at liberator.core$method_delete_QMARK_.invoke(core.clj:317)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$if_modified_since_exists_QMARK_.invokeStatic(core.clj:337)
	at liberator.core$if_modified_since_exists_QMARK_.invoke(core.clj:337)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$if_none_match_exists_QMARK_.invokeStatic(core.clj:355)
	at liberator.core$if_none_match_exists_QMARK_.invoke(core.clj:355)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$if_unmodified_since_exists_QMARK_.invokeStatic(core.clj:375)
	at liberator.core$if_unmodified_since_exists_QMARK_.invoke(core.clj:375)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$if_match_exists_QMARK_.invokeStatic(core.clj:389)
	at liberator.core$if_match_exists_QMARK_.invoke(core.clj:389)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$exists_QMARK_.invokeStatic(core.clj:392)
	at liberator.core$exists_QMARK_.invoke(core.clj:392)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$processable_QMARK_.invokeStatic(core.clj:395)
	at liberator.core$processable_QMARK_.invoke(core.clj:395)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$accept_encoding_exists_QMARK_.invokeStatic(core.clj:416)
	at liberator.core$accept_encoding_exists_QMARK_.invoke(core.clj:416)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$accept_charset_exists_QMARK_.invokeStatic(core.clj:429)
	at liberator.core$accept_charset_exists_QMARK_.invoke(core.clj:429)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$accept_language_exists_QMARK_.invokeStatic(core.clj:443)
	at liberator.core$accept_language_exists_QMARK_.invoke(core.clj:443)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$accept_exists_QMARK_.invokeStatic(core.clj:456)
	at liberator.core$accept_exists_QMARK_.invoke(core.clj:456)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$is_options_QMARK_.invokeStatic(core.clj:473)
	at liberator.core$is_options_QMARK_.invoke(core.clj:473)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$valid_entity_length_QMARK_.invokeStatic(core.clj:476)
	at liberator.core$valid_entity_length_QMARK_.invoke(core.clj:476)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$known_content_type_QMARK_.invokeStatic(core.clj:479)
	at liberator.core$known_content_type_QMARK_.invoke(core.clj:479)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$valid_content_header_QMARK_.invokeStatic(core.clj:481)
	at liberator.core$valid_content_header_QMARK_.invoke(core.clj:481)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$allowed_QMARK_.invokeStatic(core.clj:484)
	at liberator.core$allowed_QMARK_.invoke(core.clj:484)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$authorized_QMARK_.invokeStatic(core.clj:487)
	at liberator.core$authorized_QMARK_.invoke(core.clj:487)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$malformed_QMARK_.invokeStatic(core.clj:490)
	at liberator.core$malformed_QMARK_.invoke(core.clj:490)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$method_allowed_QMARK_.invokeStatic(core.clj:493)
	at liberator.core$method_allowed_QMARK_.invoke(core.clj:493)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$uri_too_long_QMARK_.invokeStatic(core.clj:496)
	at liberator.core$uri_too_long_QMARK_.invoke(core.clj:496)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$known_method_QMARK_.invokeStatic(core.clj:499)
	at liberator.core$known_method_QMARK_.invoke(core.clj:499)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$service_available_QMARK_.invokeStatic(core.clj:502)
	at liberator.core$service_available_QMARK_.invoke(core.clj:502)
	at liberator.core$decide.invokeStatic(core.clj:87)
	at liberator.core$decide.invoke(core.clj:74)
	at liberator.core$initialize_context.invokeStatic(core.clj:504)
	at liberator.core$initialize_context.invoke(core.clj:504)
	at liberator.core$run_resource.invokeStatic(core.clj:595)
	at liberator.core$run_resource.invoke(core.clj:593)
	at puppetlabs.services.ca.certificate_authority_core$certificate_status$fn__42391.invoke(certificate_authority_core.clj:409)
	at compojure.response$fn__17255.invokeStatic(response.clj:33)
	at compojure.response$fn__17255.invoke(response.clj:21)
	at compojure.response$fn__17228$G__17223__17235.invoke(response.clj:6)
	at puppetlabs.services.ca.certificate_authority_core$fn__42441$web_routes__42446$fn__42447$fn__42448.invoke(certificate_authority_core.clj:548)
	at bidi.ring$fn__17042.invokeStatic(ring.cljc:25)
	at bidi.ring$fn__17042.invoke(ring.cljc:21)
	at bidi.ring$fn__17027$G__17022__17036.invoke(ring.cljc:16)
	at puppetlabs.comidi$make_handler$fn__18958.invoke(comidi.clj:245)
	at puppetlabs.trapperkeeper.authorization.ring_middleware$fn__25846$wrap_authorization_check__25851$fn__25852$fn__25853.invoke(ring_middleware.clj:293)
	at puppetlabs.ring_middleware.core$fn__23328$wrap_bad_request__23337$fn__23340$fn__23346.invoke(core.clj:187)
	at puppetlabs.puppetserver.ringutils$fn__36917$wrap_with_trapperkeeper_or_client_whitelist_authorization__36922$fn__36923$fn__36927.invoke(ringutils.clj:131)
	at puppetlabs.i18n.core$locale_negotiator$fn__4728.invoke(core.clj:361)
	at puppetlabs.ring_middleware.core$fn__23426$wrap_uncaught_errors__23435$fn__23438$fn__23443.invoke(core.clj:233)
	at puppetlabs.puppetserver.ringutils$wrap_with_puppet_version_header$fn__36906.invoke(ringutils.clj:90)
	at puppetlabs.ring_middleware.core$fn__23025$wrap_response_logging__23030$fn__23031$fn__23032.invoke(core.clj:53)
	at puppetlabs.trapperkeeper.services.webserver.jetty10_core$ring_handler$fn__29347.invoke(jetty10_core.clj:533)
	at puppetlabs.trapperkeeper.services.webserver.jetty10_core.proxy$org.eclipse.jetty.server.handler.HandlerWrapper$ff19274a.handle(Unknown Source)
	at jdk.internal.reflect.GeneratedMethodAccessor16.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at clojure.lang.Reflector.invokeMatchingMethod(Reflector.java:167)
	at clojure.lang.Reflector.invokeInstanceMethod(Reflector.java:102)
	at puppetlabs.trapperkeeper.services.webserver.normalized_uri_helpers$fn__28883$normalize_uri_handler__28888$fn__28889$fn__28890.invoke(normalized_uri_helpers.clj:73)
	at puppetlabs.trapperkeeper.services.webserver.normalized_uri_helpers.proxy$org.eclipse.jetty.server.handler.HandlerWrapper$ff19274a.handle(Unknown Source)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1384)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1306)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129)
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:192)
	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:141)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:822)
	at com.puppetlabs.trapperkeeper.services.webserver.jetty10.utils.MDCRequestLogHandler.handle(MDCRequestLogHandler.java:48)
	at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
	at org.eclipse.jetty.server.Server.handle(Server.java:563)
	at org.eclipse.jetty.server.HttpChannel$RequestDispatchable.dispatch(HttpChannel.java:1598)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:753)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:501)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:287)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:314)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
	at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:558)
	at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:379)
	at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:146)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
	at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
	at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:421)
	at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:390)
	at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:277)
	at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.run(AdaptiveExecutionStrategy.java:199)
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:411)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:969)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1194)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1149)
	at java.base/java.lang.Thread.run(Thread.java:840)
 
19/Apr/2024:11:34:46 +0000 "GET /puppet-ca/v1/certificate_status/client.domain.tld HTTP/1.1" 500 163 10.0.8.41 10.0.8.41 8140 16
@anders-larsson
Copy link
Author

anders-larsson commented May 20, 2024

Example when executed on the CA server itself:

curl --tlsv1 \
  --cacert /etc/puppetlabs/puppet/ssl/certs/ca.pem \
  --cert /etc/puppetlabs/puppet/ssl/certs/puppet.pem \
  --key /etc/puppetlabs/puppet/ssl/private_keys/puppet.pem  \
  -k https://localhost:8140/puppet-ca/v1/certificate_status/client.domain.tld
Internal Server Error: java.io.FileNotFoundException: /etc/puppetlabs/puppetserver/ca/requests/client.domain.tld.pem (No such file or directory)

The system in question has had a certificate previously but no longer does. Neither a certificate or a certificate request file exists for the system on the CA. For other non-existing nodes it correctly returns Resource not found. if the resource does not exist.

One workaround seems to be having the node connect to the CA and hence generating a new CSR file. However, revoking PUT /puppet-ca/v1/certificate_status/client.domain.tld and cleaning it DELETE /puppet-ca/v1/certificate_status/client.domain.tld causes the problem to show itself again. Same thing happens regardless if a certificate or a CSR is going through this process.

As mentioned earlier this only happens sometimes and after it has started to happen it is persistent for that particular subject DN.

The CA is also much slower to process CSRs -> Cert (as also mentioned in linked issue).

@jonathannewman
Copy link
Contributor

Thanks for your report. The issue is a simple logic problem that I will resolve shortly.

jonathannewman added a commit to jonathannewman/puppetserver that referenced this issue May 21, 2024
The inventory is managed in several ways in the CA, including an inventory
file, which records certificates, expiration periods and serial numbers.
In the case where we want to get the actual certificate status, we don't want
to use the inventory file. The liberator `exists` method was checking in both
the filesystem and the inventory file for the certificate in question for
a `GET` request.  This alters that behavior to only check the file system under
those circumstances.

A test is added to demonstrate the behavior.

Resolves puppetlabs#2851
jonathannewman added a commit to jonathannewman/puppetserver that referenced this issue May 21, 2024
The inventory is managed in several ways in the CA, including an inventory
file, which records certificates, expiration periods and serial numbers.
In the case where we want to get the actual certificate status, we don't want
to use the inventory file. The liberator `exists` method was checking in both
the filesystem and the inventory file for the certificate in question for
a `GET` request.  This alters that behavior to only check the file system under
those circumstances.

A test is added to demonstrate the behavior.

Resolves puppetlabs#2851
@anders-larsson
Copy link
Author

@jonathannewman @justinstoller Hi, when will there be a release which includes this fix? Thanks.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
2 participants