Problem:
Puppet agent could not connect to puppet server
Expected outcome:
puppet agent can connect to puppet server and reports will be synced
Foreman and Proxy versions:
foreman-3.4
foreman-proxy-3.4
Foreman and Proxy plugin versions:’
katello-4.6
Distribution and version:
Rocky Linux 8.7
Other relevant data:
See error logs below from messages log file
Dec 2 17:27:32 mltlws-web-01 puppet-agent[1608572]: Connection to https://nestor.url3.net:8140/puppet/v3 failed, trying next route: Request to https://nestor.url3.net:8140/puppet/v3 timed out connect operation after 120.001 seconds
Dec 2 17:27:32 mltlws-web-01 puppet-agent[1608572]: Wrapped exception:
Dec 2 17:27:32 mltlws-web-01 puppet-agent[1608572]: execution expired
Dec 2 17:27:32 mltlws-web-01 puppet-agent[1608572]: No more routes to fileserver
Dec 2 17:29:34 mltlws-web-01 puppet-agent[1608572]: Connection to https://nestor.url3.net:8140/puppet/v3 failed, trying next route: Request to https://nestor.url3.net:8140/puppet/v3 timed out connect operation after 120.001 seconds
Dec 2 17:29:34 mltlws-web-01 puppet-agent[1608572]: Wrapped exception:
Dec 2 17:29:34 mltlws-web-01 puppet-agent[1608572]: execution expired
Dec 2 17:29:34 mltlws-web-01 puppet-agent[1608572]: Could not retrieve catalog from remote server: No more routes to puppet
Dec 2 17:29:34 mltlws-web-01 puppet-agent[1608572]: Applied catalog in 0.03 seconds
i’d start just checking the basics, such as network connectivity, dns resolution, and ssl chain
the fact that you’re not getting a response suggests a lack of network connectivity over other things, but I have seen dns lookups fail and not get trapped, so the error is a a time out as the host can’t be resolved, but the cause is name resolution is failing (example only)
2022-12-01T17:49:05.488+08:00 INFO [Thread-2] [p.t.internal] Shutting down due to JVM shutdown hook.
2022-12-01T17:49:05.491+08:00 INFO [Thread-2] [p.t.internal] Beginning shutdown sequence
2022-12-01T17:49:05.497+08:00 INFO [async-dispatch-3] [p.s.j.jruby-metrics-service] JRuby Metrics Service: stopping metrics sampler job
2022-12-01T17:49:05.497+08:00 INFO [async-dispatch-3] [p.s.j.jruby-metrics-service] JRuby Metrics Service: stopped metrics sampler job
2022-12-01T17:49:05.500+08:00 INFO [async-dispatch-3] [p.s.j.i.jruby-agents] Draining JRuby pool.
2022-12-01T17:49:05.504+08:00 INFO [async-dispatch-3] [p.s.j.i.jruby-agents] Borrowed all JRuby instances, proceeding with cleanup.
2022-12-01T17:49:05.577+08:00 INFO [clojure-agent-send-pool-1] [p.s.j.i.jruby-internal] Cleaned up old JRubyInstance with id 2.
2022-12-01T17:49:05.612+08:00 INFO [clojure-agent-send-pool-1] [p.s.j.i.jruby-internal] Cleaned up old JRubyInstance with id 1.
2022-12-01T17:49:05.613+08:00 INFO [clojure-agent-send-pool-1] [p.s.j.i.jruby-agents] Finished draining pool.
2022-12-01T17:49:05.629+08:00 INFO [async-dispatch-3] [p.t.s.w.jetty9-service] Shutting down web server(s).
2022-12-01T17:49:05.633+08:00 INFO [async-dispatch-3] [p.t.s.w.jetty9-core] Shutting down web server.
2022-12-01T17:49:05.639+08:00 INFO [async-dispatch-3] [o.e.j.s.AbstractConnector] Stopped ServerConnector@1d5b98df{SSL, (ssl, http/1.1)}{0.0.0.0:8140}
2022-12-01T17:49:05.639+08:00 INFO [async-dispatch-3] [o.e.j.s.session] node0 Stopped scavenging
2022-12-01T17:49:05.639+08:00 INFO [async-dispatch-3] [o.e.j.s.h.ContextHandler] Stopped o.e.j.s.h.ContextHandler@220bcb{/status,null,STOPPED}
2022-12-01T17:49:05.639+08:00 INFO [async-dispatch-3] [o.e.j.s.h.ContextHandler] Stopped o.e.j.s.h.ContextHandler@29ca46ad{/puppet,null,STOPPED}
2022-12-01T17:49:05.639+08:00 INFO [async-dispatch-3] [o.e.j.s.h.ContextHandler] Stopped o.e.j.s.h.ContextHandler@3f109f89{/puppet-admin-api,null,STOPPED}
2022-12-01T17:49:05.639+08:00 INFO [async-dispatch-3] [o.e.j.s.h.ContextHandler] Stopped o.e.j.s.h.ContextHandler@fbbc654{/puppet-ca,null,STOPPED}
2022-12-01T17:49:05.642+08:00 INFO [async-dispatch-3] [o.e.j.s.h.ContextHandler] Stopped o.e.j.s.ServletContextHandler@74b498d9{/metrics/v2,null,STOPPED}
2022-12-01T17:49:05.652+08:00 INFO [async-dispatch-3] [p.t.s.w.jetty9-core] Web server shutdown
2022-12-01T17:49:05.655+08:00 INFO [clojure-agent-send-off-pool-0] [p.t.s.w.filesystem-watch-core] Closing watcher puppetlabs.trapperkeeper.services.watcher.filesystem_watch_core.WatcherImpl@20deac45
2022-12-01T17:49:05.667+08:00 INFO [async-dispatch-3] [p.t.s.s.scheduler-service] Shutting down Scheduler Service
2022-12-01T17:49:05.667+08:00 INFO [clojure-agent-send-off-pool-1] [p.t.s.w.filesystem-watch-core] Closing watcher puppetlabs.trapperkeeper.services.watcher.filesystem_watch_core.WatcherImpl@4f85bb05
2022-12-01T17:49:05.672+08:00 INFO [clojure-agent-send-off-pool-1] [o.q.c.QuartzScheduler] Scheduler 875c4908-a528-4696-84e9-ff99e68e5b3d_$_NON_CLUSTERED shutting down.
2022-12-01T17:49:05.673+08:00 INFO [clojure-agent-send-off-pool-1] [o.q.c.QuartzScheduler] Scheduler 875c4908-a528-4696-84e9-ff99e68e5b3d_$_NON_CLUSTERED paused.
2022-12-01T17:49:06.128+08:00 INFO [clojure-agent-send-off-pool-1] [o.q.c.QuartzScheduler] Scheduler 875c4908-a528-4696-84e9-ff99e68e5b3d_$_NON_CLUSTERED shutdown complete.
2022-12-01T17:49:06.129+08:00 INFO [async-dispatch-3] [p.t.s.s.scheduler-service] Scheduler Service shutdown complete.
2022-12-01T17:49:06.136+08:00 INFO [Thread-2] [p.t.internal] Finished shutdown sequence
2022-12-01T17:49:29.761+08:00 INFO [main] [o.e.j.u.log] Logging initialized @17238ms to org.eclipse.jetty.util.log.Slf4jLog
2022-12-01T17:49:30.664+08:00 INFO [async-dispatch-2] [p.t.s.s.scheduler-service] Initializing Scheduler Service
2022-12-01T17:49:30.694+08:00 INFO [async-dispatch-2] [o.q.i.StdSchedulerFactory] Using default implementation for ThreadExecutor
2022-12-01T17:49:30.709+08:00 INFO [async-dispatch-2] [o.q.c.SchedulerSignalerImpl] Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2022-12-01T17:49:30.709+08:00 INFO [async-dispatch-2] [o.q.c.QuartzScheduler] Quartz Scheduler v.2.3.2 created.
2022-12-01T17:49:30.710+08:00 INFO [async-dispatch-2] [o.q.s.RAMJobStore] RAMJobStore initialized.
2022-12-01T17:49:30.710+08:00 INFO [async-dispatch-2] [o.q.c.QuartzScheduler] Scheduler meta-data: Quartz Scheduler (v2.3.2) 'b8281704-1dfb-4547-9f75-a4b88cadfb61' with instanceId 'NON_CLUSTERED'
Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
NOT STARTED.
Currently in standby mode.
Number of jobs executed: 0
Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 10 threads.
Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.
2022-12-01T17:49:30.711+08:00 INFO [async-dispatch-2] [o.q.i.StdSchedulerFactory] Quartz scheduler 'b8281704-1dfb-4547-9f75-a4b88cadfb61' initialized from an externally provided properties instance.
2022-12-01T17:49:30.711+08:00 INFO [async-dispatch-2] [o.q.i.StdSchedulerFactory] Quartz scheduler version: 2.3.2
2022-12-01T17:49:30.711+08:00 INFO [async-dispatch-2] [o.q.c.QuartzScheduler] Scheduler b8281704-1dfb-4547-9f75-a4b88cadfb61_$_NON_CLUSTERED started.
2022-12-01T17:49:30.713+08:00 INFO [async-dispatch-2] [p.t.s.w.jetty9-service] Initializing web server(s).
2022-12-01T17:49:30.753+08:00 INFO [async-dispatch-2] [p.t.s.s.status-service] Registering status callback function for service 'puppet-profiler', version 7.9.2
2022-12-01T17:49:30.755+08:00 INFO [async-dispatch-2] [p.s.j.jruby-puppet-service] Initializing the JRuby service
2022-12-01T17:49:30.772+08:00 INFO [async-dispatch-2] [p.s.j.jruby-pool-manager-service] Initializing the JRuby service
2022-12-01T17:49:30.784+08:00 INFO [async-dispatch-2] [p.s.j.jruby-puppet-service] JRuby version info: jruby 9.3.4.0 (2.6.8) 2022-03-23 eff48c1ebf OpenJDK 64-Bit Server VM 25.352-b08 on 1.8.0_352-b08 +jit [x86_64-linux]
2022-12-01T17:49:30.807+08:00 INFO [async-dispatch-2] [p.t.s.s.status-service] Registering status callback function for service 'jruby-metrics', version 7.9.2
2022-12-01T17:49:30.808+08:00 INFO [async-dispatch-2] [p.s.v.versioned-code-service] No code-id-command set for versioned-code-service. Code-id will be nil.
2022-12-01T17:49:30.808+08:00 INFO [async-dispatch-2] [p.s.v.versioned-code-service] No code-content-command set for versioned-code-service. Attempting to fetch code content will fail.
2022-12-01T17:49:30.819+08:00 INFO [clojure-agent-send-pool-0] [p.s.j.i.jruby-internal] Creating JRubyInstance with id 1.
2022-12-01T17:49:30.830+08:00 INFO [async-dispatch-2] [p.t.s.m.jolokia] Metrics access control using trapperkeeper-authorization is enabled.
2022-12-01T17:49:39.032+08:00 INFO [clojure-agent-send-pool-0] [puppetserver] Puppet Puppet settings initialized; run mode: server
2022-12-01T17:49:41.707+08:00 INFO [clojure-agent-send-pool-0] [p.s.j.i.jruby-agents] Finished creating JRubyInstance 1 of 2
2022-12-01T17:49:41.708+08:00 INFO [clojure-agent-send-pool-0] [p.s.j.i.jruby-internal] Creating JRubyInstance with id 2.
2022-12-01T17:49:41.786+08:00 INFO [async-dispatch-2] [p.s.c.puppet-server-config-core] Not overriding webserver settings with values from core Puppet
2022-12-01T17:49:41.826+08:00 INFO [async-dispatch-2] [p.p.certificate-authority] CA already initialized for SSL
2022-12-01T17:49:41.827+08:00 INFO [async-dispatch-2] [p.s.c.certificate-authority-service] CA Service adding a ring handler
2022-12-01T17:49:41.876+08:00 INFO [async-dispatch-2] [p.t.s.s.status-service] Registering status callback function for service 'ca', version 7.9.2
2022-12-01T17:49:41.877+08:00 INFO [async-dispatch-2] [p.s.p.puppet-admin-service] Starting Puppet Admin web app
2022-12-01T17:49:42.046+08:00 INFO [async-dispatch-2] [p.p.certificate-authority] Master already initialized for SSL
2022-12-01T17:49:42.056+08:00 INFO [async-dispatch-2] [p.s.m.master-service] Master Service adding ring handlers
2022-12-01T17:49:42.062+08:00 INFO [async-dispatch-2] [p.t.s.s.status-service] Registering status callback function for service 'master', version 7.9.2
2022-12-01T17:49:42.063+08:00 INFO [async-dispatch-2] [p.t.s.s.status-service] Registering status callback function for service 'server', version 7.9.2
2022-12-01T17:49:42.065+08:00 INFO [async-dispatch-2] [p.t.s.w.jetty9-service] Starting web server(s).
2022-12-01T17:49:42.295+08:00 INFO [async-dispatch-2] [p.t.s.w.jetty9-core] Starting web server.
2022-12-01T17:49:42.300+08:00 INFO [async-dispatch-2] [o.e.j.s.Server] jetty-9.4.48.v20220622; built: 2022-06-21T20:42:25.880Z; git: 6b67c5719d1f4371b33655ff2d047d24e171e49a; jvm 1.8.0_352-b08
2022-12-01T17:49:42.419+08:00 INFO [async-dispatch-2] [o.e.j.s.session] DefaultSessionIdManager workerName=node0
2022-12-01T17:49:42.419+08:00 INFO [async-dispatch-2] [o.e.j.s.session] No SessionScavenger set, using defaults
2022-12-01T17:49:42.420+08:00 INFO [async-dispatch-2] [o.e.j.s.session] node0 Scavenging every 660000ms
2022-12-01T17:49:42.457+08:00 INFO [async-dispatch-2] [p.t.s.m.jolokia] Using policy access restrictor classpath:/jolokia-access.xml
2022-12-01T17:49:42.518+08:00 INFO [async-dispatch-2] [o.e.j.s.h.ContextHandler] Started o.e.j.s.ServletContextHandler@10ba6e0b{/metrics/v2,null,AVAILABLE}
2022-12-01T17:49:42.519+08:00 INFO [async-dispatch-2] [o.e.j.s.h.ContextHandler] Started o.e.j.s.h.ContextHandler@a24804b{/puppet-ca,null,AVAILABLE}
2022-12-01T17:49:42.519+08:00 INFO [async-dispatch-2] [o.e.j.s.h.ContextHandler] Started o.e.j.s.h.ContextHandler@788ead78{/puppet-admin-api,null,AVAILABLE}
2022-12-01T17:49:42.520+08:00 INFO [async-dispatch-2] [o.e.j.s.h.ContextHandler] Started o.e.j.s.h.ContextHandler@1123088e{/puppet,null,AVAILABLE}
2022-12-01T17:49:42.558+08:00 INFO [async-dispatch-2] [o.e.j.u.s.SslContextFactory] x509=X509@30fc3ef(private key,h=[puppet, nestor.url3.net],a=[],w=[]) for InternalSslContextFactory@d08f268[provider=null,keyStore=null,trustStore=null]
2022-12-01T17:49:42.655+08:00 INFO [async-dispatch-2] [o.e.j.s.AbstractConnector] Started ServerConnector@3ab6e376{SSL, (ssl, http/1.1)}{0.0.0.0:8140}
2022-12-01T17:49:42.655+08:00 INFO [async-dispatch-2] [o.e.j.s.Server] Started @30135ms
2022-12-01T17:49:42.667+08:00 INFO [async-dispatch-2] [p.t.s.s.status-core] Starting background monitoring of cpu usage metrics
2022-12-01T17:49:42.684+08:00 INFO [async-dispatch-2] [p.t.s.s.status-service] Registering status callback function for service 'status-service', version 1.1.1
2022-12-01T17:49:42.684+08:00 INFO [async-dispatch-2] [p.t.s.s.status-service] Registering status service HTTP API at /status
2022-12-01T17:49:42.696+08:00 INFO [async-dispatch-2] [o.e.j.s.h.ContextHandler] Started o.e.j.s.h.ContextHandler@476f279d{/status,null,AVAILABLE}
2022-12-01T17:49:42.725+08:00 INFO [async-dispatch-2] [p.s.a.analytics-service] Puppet Server Update Service has successfully started and will run in the background
2022-12-01T17:49:42.729+08:00 INFO [async-dispatch-2] [p.s.m.master-service] Puppet Server has successfully started and is now ready to handle requests
2022-12-01T17:49:45.563+08:00 INFO [b8281704-1dfb-4547-9f75-a4b88cadfb61_Worker-3] [p.s.a.dropsonde] Successfully submitted module metrics via Dropsonde.
2022-12-01T17:49:46.691+08:00 INFO [clojure-agent-send-pool-0] [puppetserver] Puppet Puppet settings initialized; run mode: server
2022-12-01T17:49:48.988+08:00 INFO [clojure-agent-send-pool-0] [p.s.j.i.jruby-agents] Finished creating JRubyInstance 2 of 2
2022-12-01T17:51:21.001+08:00 WARN [qtp133146353-59] [puppetserver] Puppet The node parameter 'fqdn' for node 'nestor.url3.net' was already set to 'nestor.url3.net'. It could not be set to 'nestor.url3.net'
2022-12-01T17:51:21.002+08:00 WARN [qtp133146353-59] [puppetserver] Puppet The node parameter 'hostname' for node 'nestor.url3.net' was already set to 'nestor'. It could not be set to 'nestor'
2022-12-01T17:51:21.233+08:00 INFO [qtp133146353-59] [puppetserver] Puppet Compiled catalog for nestor.url3.net in environment production in 0.21 seconds
2022-12-01T18:21:20.252+08:00 INFO [qtp133146353-60] [puppetserver] Puppet Compiled catalog for nestor.url3.net in environment production in 0.15 seconds
2022-12-01T18:51:20.177+08:00 INFO [qtp133146353-58] [puppetserver] Puppet Compiled catalog for nestor.url3.net in environment production in 0.13 seconds
2022-12-01T19:21:19.879+08:00 INFO [qtp133146353-58] [puppetserver] Puppet Compiled catalog for nestor.url3.net in environment production in 0.06 seconds
2022-12-01T19:51:20.001+08:00 INFO [qtp133146353-59] [puppetserver] Puppet Compiled catalog for nestor.url3.net in environment production in 0.10 seconds
2022-12-01T20:21:19.975+08:00 INFO [qtp133146353-63] [puppetserver] Puppet Compiled catalog for nestor.url3.net in environment production in 0.08 seconds
2022-12-01T20:51:19.994+08:00 INFO [qtp133146353-62] [puppetserver] Puppet Compiled catalog for nestor.url3.net in environment production in 0.05 seconds
2022-12-01T21:21:20.074+08:00 INFO [qtp133146353-62] [puppetserver] Puppet Compiled catalog for nestor.url3.net in environment production in 0.05 seconds
2022-12-01T21:51:21.228+08:00 INFO [qtp133146353-58] [puppetserver] Puppet Compiled catalog for nestor.url3.net in environment production in 1.46 seconds
2022-12-01T22:21:19.815+08:00 INFO [qtp133146353-63] [puppetserver] Puppet Compiled catalog for nestor.url3.net in environment production in 0.04 seconds
2022-12-01T22:51:20.068+08:00 INFO [qtp133146353-62] [puppetserver] Puppet Compiled catalog for nestor.url3.net in environment production in 0.03 seconds
2022-12-01T23:21:19.954+08:00 INFO [qtp133146353-60] [puppetserver] Puppet Compiled catalog for nestor.url3.net in environment production in 0.04 seconds
2022-12-01T23:51:19.807+08:00 INFO [qtp133146353-63] [puppetserver] Puppet Compiled catalog for nestor.url3.net in environment production in 0.05 seconds
that looks like it’s talking to itself fine and building the catalogue for itself as a host, but I’m still guessing your remote host can’t talk to the target
