[Bug]: OpenVox Agent fails/gets deactivated after update with puppet-puppet #973
Description
Problem
I tried to update our puppet-agents to 8.24.1 using the theforeman-puppet-module. After doing so, I noticed that several nodes got unreported after a while. When checking them I noticed that on all Debian (12 and 13) and CentOS (9) nodes the service was stopped and on Ubuntu (24.04) it was failed. After some conversation in the Slack channel the assumption is that it is a race condition restarting the agent to early.
Expected behaviour
The agent should still be running after the update and not stopped or failed.
Steps to reproduce
Update the Puppet agent using the theforeman-puppet module
- Update e.g. node yaml to use the new version:
- Run
puppet agent -ton this node
Logs
journalctl -xeu puppet
Dec 15 13:41:09 $HOSTNAME dhcpcd[304003]: dhcpcd is not running
Dec 15 13:41:09 $HOSTNAME dhcpcd[304004]: dhcpcd is not running
Dec 15 13:41:12 $HOSTNAME puppet-agent[303894]: Requesting catalog from puppetserver.domain:8140 ($IP9)
Dec 15 13:41:13 $HOSTNAME puppet-agent[303894]: Catalog compiled by puppetserver.domain
Dec 15 13:41:14 $HOSTNAME crontab[304092]: (root) LIST (root)
Dec 15 13:41:14 $HOSTNAME puppet-agent[303894]: Applied catalog in 0.52 seconds
Dec 15 13:44:56 $HOSTNAME systemd[1]: Stopping puppet.service - Puppet agent...
░░ Subject: A stop job for unit puppet.service has begun execution
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░
░░ A stop job for unit puppet.service has begun execution.
░░
░░ The job identifier is 28865.
Dec 15 13:44:56 $HOSTNAME puppet-agent[303821]: Caught TERM; exiting
Dec 15 13:44:56 $HOSTNAME systemd[1]: puppet.service: Deactivated successfully.
░░ Subject: Unit succeeded
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░
░░ The unit puppet.service has successfully entered the 'dead' state.
Dec 15 13:44:56 $HOSTNAME systemd[1]: Stopped puppet.service - Puppet agent.
░░ Subject: A stop job for unit puppet.service has finished
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░
░░ A stop job for unit puppet.service has finished.
░░
░░ The job identifier is 28865 and the job result is done.
Dec 15 13:44:56 $HOSTNAME systemd[1]: puppet.service: Consumed 6.408s CPU time, 166.3M memory peak.
░░ Subject: Resources consumed by unit runtime
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░
░░ The unit puppet.service completed and consumed the indicated resources.
Dec 15 13:44:56 $HOSTNAME systemd[1]: Started puppet.service - Puppet agent.
░░ Subject: A start job for unit puppet.service has finished successfully
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░
░░ A start job for unit puppet.service has finished successfully.
░░
░░ The job identifier is 28865.
Dec 15 13:44:56 $HOSTNAME (puppet)[304369]: puppet.service: Referenced but unset environment variable evaluates to an empty string: PUPPET_EXTRA_OPTS
Dec 15 13:44:57 $HOSTNAME systemd[1]: Reloading puppet.service - Puppet agent...
░░ Subject: A reload job for unit puppet.service has begun execution
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░
░░ A reload job for unit puppet.service has begun execution.
░░
░░ The job identifier is 28995.
Dec 15 13:44:57 $HOSTNAME systemd[1]: Reloaded puppet.service - Puppet agent.
░░ Subject: A reload job for unit puppet.service has finished
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░
░░ A reload job for unit puppet.service has finished.
░░
░░ The job identifier is 28995 and the job result is done.
Dec 15 13:44:57 $HOSTNAME systemd[1]: puppet.service: Deactivated successfully.
░░ Subject: Unit succeeded
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░
░░ The unit puppet.service has successfully entered the 'dead' state.
---------------------------------------------------------------------------------
root@HOSTNAME4:~# journalctl -xeu puppet
Dec 15 17:32:37 $HOST_FQDN systemd[1]: puppet.service: Deactivated successfully.
░░ Subject: Unit succeeded
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ The unit puppet.service has successfully entered the 'dead' state.
Dec 15 17:32:37 $HOST_FQDN systemd[1]: Stopped puppet.service - Puppet agent.
░░ Subject: A stop job for unit puppet.service has finished
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ A stop job for unit puppet.service has finished.
░░
░░ The job identifier is 86157 and the job result is done.
Dec 15 17:32:37 $HOST_FQDN systemd[1]: puppet.service: Consumed 10.878s CPU time, 188.2M memory peak, 0B memory swap peak.
░░ Subject: Resources consumed by unit runtime
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ The unit puppet.service completed and consumed the indicated resources.
Dec 15 17:32:37 $HOST_FQDN systemd[1]: Started puppet.service - Puppet agent.
░░ Subject: A start job for unit puppet.service has finished successfully
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ A start job for unit puppet.service has finished successfully.
░░
░░ The job identifier is 86157.
Dec 15 17:32:37 $HOST_FQDN (puppet)[123731]: puppet.service: Referenced but unset environment variable evaluates to an empty string: PUPPET_EXTRA_OPTS
Dec 15 17:32:41 $HOST_FQDN systemd[1]: Reloading puppet.service - Puppet agent...
░░ Subject: A reload job for unit puppet.service has begun execution
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ A reload job for unit puppet.service has begun execution.
░░
░░ The job identifier is 86407.
Dec 15 17:32:41 $HOST_FQDN systemd[1]: Reloaded puppet.service - Puppet agent.
░░ Subject: A reload job for unit puppet.service has finished
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ A reload job for unit puppet.service has finished.
░░
░░ The job identifier is 86407 and the job result is done.
Dec 15 17:32:41 $HOST_FQDN puppet[123731]: Error: Could not initialize global default settings: SIGHUP
Dec 15 17:32:41 $HOST_FQDN systemd[1]: puppet.service: Main process exited, code=exited, status=1/FAILURE
░░ Subject: Unit process exited
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ An ExecStart= process belonging to unit puppet.service has exited.
░░
░░ The process' exit code is 'exited' and its exit status is 1.
Dec 15 17:32:41 $HOST_FQDN systemd[1]: puppet.service: Failed with result 'exit-code'.
░░ Subject: Unit failed
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ The unit puppet.service has entered the 'failed' state with result 'exit-code'.
Dec 15 17:32:41 $HOST_FQDN systemd[1]: puppet.service: Consumed 1.034s CPU time, 55.1M memory peak, 0B memory swap peak.
░░ Subject: Resources consumed by unit runtime
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ The unit puppet.service completed and consumed the indicated resources.
----------------------------------------------------------------------------------------
2025-12-15T14:46:02.315390+01:00 HOSTNAME puppet-agent[306923]: (/Stage[main]/Puppet::Agent::Install/Package[openvox-agent]/ensure) ensure changed '8.23.1-1+debian13' to '8.24.1-1+debian13'
2025-12-15T14:46:02.316438+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Install]) Scheduling refresh of Class[Puppet::Agent::Config]
2025-12-15T14:46:02.323182+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Install]) Scheduling refresh of Class[Puppet::Agent::Service]
2025-12-15T14:46:02.324182+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Config]) Scheduling refresh of Puppet::Config::Agent[classfile]
2025-12-15T14:46:02.324217+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Config]) Scheduling refresh of Puppet::Config::Agent[default_schedules]
2025-12-15T14:46:02.324252+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Config]) Scheduling refresh of Puppet::Config::Agent[report]
2025-12-15T14:46:02.324279+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Config]) Scheduling refresh of Puppet::Config::Agent[masterport]
2025-12-15T14:46:02.324305+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Config]) Scheduling refresh of Puppet::Config::Agent[splay]
2025-12-15T14:46:02.324326+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Config]) Scheduling refresh of Puppet::Config::Agent[splaylimit]
2025-12-15T14:46:02.324346+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Config]) Scheduling refresh of Puppet::Config::Agent[runinterval]
2025-12-15T14:46:02.324379+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Config]) Scheduling refresh of Puppet::Config::Agent[noop]
2025-12-15T14:46:02.324400+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Config]) Scheduling refresh of Puppet::Config::Agent[usecacheonfailure]
2025-12-15T14:46:02.324423+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Config]) Scheduling refresh of Puppet::Config::Agent[environment]
2025-12-15T14:46:02.324459+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Agent[classfile]) Scheduling refresh of Puppet::Config::Entry[agent_classfile]
2025-12-15T14:46:02.324484+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Agent[default_schedules]) Scheduling refresh of Puppet::Config::Entry[agent_default_schedules]
2025-12-15T14:46:02.324507+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Agent[report]) Scheduling refresh of Puppet::Config::Entry[agent_report]
2025-12-15T14:46:02.324527+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Agent[masterport]) Scheduling refresh of Puppet::Config::Entry[agent_masterport]
2025-12-15T14:46:02.324547+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Agent[splay]) Scheduling refresh of Puppet::Config::Entry[agent_splay]
2025-12-15T14:46:02.324571+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Agent[splaylimit]) Scheduling refresh of Puppet::Config::Entry[agent_splaylimit]
2025-12-15T14:46:02.324592+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Agent[runinterval]) Scheduling refresh of Puppet::Config::Entry[agent_runinterval]
2025-12-15T14:46:02.324613+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Agent[noop]) Scheduling refresh of Puppet::Config::Entry[agent_noop]
2025-12-15T14:46:02.324632+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Agent[usecacheonfailure]) Scheduling refresh of Puppet::Config::Entry[agent_usecacheonfailure]
2025-12-15T14:46:02.324657+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Agent[environment]) Scheduling refresh of Puppet::Config::Entry[agent_environment]
2025-12-15T14:46:02.340328+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Entry[agent_classfile]) Scheduling refresh of Concat::Fragment[puppet.conf_agent]
2025-12-15T14:46:02.340427+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Entry[agent_classfile]) Scheduling refresh of Concat::Fragment[puppet.conf_agent_end]
2025-12-15T14:46:02.340452+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Entry[agent_classfile]) Scheduling refresh of Concat::Fragment[puppet.conf_agent_classfile]
2025-12-15T14:46:02.340474+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Entry[agent_default_schedules]) Scheduling refresh of Concat::Fragment[puppet.conf_agent_default_schedules]
2025-12-15T14:46:02.340498+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Entry[agent_report]) Scheduling refresh of Concat::Fragment[puppet.conf_agent_report]
2025-12-15T14:46:02.340683+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Entry[agent_masterport]) Scheduling refresh of Concat::Fragment[puppet.conf_agent_masterport]
2025-12-15T14:46:02.345912+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Entry[agent_splay]) Scheduling refresh of Concat::Fragment[puppet.conf_agent_splay]
2025-12-15T14:46:02.346002+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Entry[agent_splaylimit]) Scheduling refresh of Concat::Fragment[puppet.conf_agent_splaylimit]
2025-12-15T14:46:02.346027+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Entry[agent_runinterval]) Scheduling refresh of Concat::Fragment[puppet.conf_agent_runinterval]
2025-12-15T14:46:02.346050+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Entry[agent_noop]) Scheduling refresh of Concat::Fragment[puppet.conf_agent_noop]
2025-12-15T14:46:02.346241+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Entry[agent_usecacheonfailure]) Scheduling refresh of Concat::Fragment[puppet.conf_agent_usecacheonfailure]
2025-12-15T14:46:02.351143+01:00 HOSTNAME puppet-agent[306923]: (Puppet::Config::Entry[agent_environment]) Scheduling refresh of Concat::Fragment[puppet.conf_agent_environment]
2025-12-15T14:46:02.490805+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Service]) Scheduling refresh of Class[Puppet::Agent::Service::Daemon]
2025-12-15T14:46:02.490892+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Service]) Scheduling refresh of Class[Puppet::Agent::Service::Systemd]
2025-12-15T14:46:02.490918+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Service]) Scheduling refresh of Class[Puppet::Agent::Service::Cron]
2025-12-15T14:46:02.490945+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Service::Daemon]) Scheduling refresh of Service[puppet]
2025-12-15T14:46:02.604063+01:00 HOSTNAME systemd[1]: Reloading puppet.service - Puppet agent...
2025-12-15T14:46:02.625055+01:00 HOSTNAME systemd[1]: Reloaded puppet.service - Puppet agent.
2025-12-15T14:46:02.627570+01:00 HOSTNAME puppet-agent[306923]: (/Stage[main]/Puppet::Agent::Service::Daemon/Service[puppet]) Triggered 'refresh' from 1 event
2025-12-15T14:46:02.629971+01:00 HOSTNAME puppet-agent[306923]: (Class[Puppet::Agent::Service::Systemd]) Scheduling refresh of Systemd::Timer[puppet-run.timer]
2025-12-15T14:46:02.634315+01:00 HOSTNAME puppet-agent[306923]: (Systemd::Timer[puppet-run.timer]) Scheduling refresh of Systemd::Unit_file[puppet-run.service]
2025-12-15T14:46:02.634383+01:00 HOSTNAME puppet-agent[306923]: (Systemd::Timer[puppet-run.timer]) Scheduling refresh of Systemd::Unit_file[puppet-run.timer]
2025-12-15T14:46:02.642147+01:00 HOSTNAME crontab[307244]: (root) LIST (root)
2025-12-15T14:46:02.643022+01:00 HOSTNAME systemd[1]: puppet.service: Deactivated successfully.
2025-12-15T14:46:02.644956+01:00 HOSTNAME puppet-agent[306923]: (Systemd::Unit_file[puppet-run.service]) Scheduling refresh of Systemd::Daemon_reload[puppet-run.service]
2025-12-15T14:46:02.647010+01:00 HOSTNAME puppet-agent[306923]: (Systemd::Daemon_reload[puppet-run.service]) Scheduling refresh of Exec[systemd-puppet-run.service-systemctl-daemon-reload]
2025-12-15T14:46:02.657407+01:00 HOSTNAME systemd[1]: Reload requested from client PID 307246 ('systemctl') (unit session-771.scope)...
2025-12-15T14:46:02.657542+01:00 HOSTNAME systemd[1]: Reloading...
2025-12-15T14:46:02.848409+01:00 HOSTNAME systemd[1]: Reloading finished in 190 ms.
2025-12-15T14:46:02.877685+01:00 HOSTNAME puppet-agent[306923]: (/Stage[main]/Puppet::Agent::Service::Systemd/Systemd::Timer[puppet-run.timer]/Systemd::Unit_file[puppet-run.service]/Systemd::Daemon_reload[puppet-run.service]/Exec[systemd-puppet-run.service-systemctl-daemon-reload]) Triggered 'refresh' from 1 event
2025-12-15T14:46:02.879237+01:00 HOSTNAME puppet-agent[306923]: (Systemd::Unit_file[puppet-run.timer]) Scheduling refresh of Systemd::Daemon_reload[puppet-run.timer]
2025-12-15T14:46:02.879266+01:00 HOSTNAME puppet-agent[306923]: (Systemd::Unit_file[puppet-run.timer]) Scheduling refresh of Service[puppet-run.timer]
2025-12-15T14:46:02.913869+01:00 HOSTNAME puppet-agent[306923]: (/Stage[main]/Puppet::Agent::Service::Systemd/Systemd::Timer[puppet-run.timer]/Systemd::Unit_file[puppet-run.timer]/Service[puppet-run.timer]) Triggered 'refresh' from 1 event
2025-12-15T14:46:02.914163+01:00 HOSTNAME puppet-agent[306923]: (Systemd::Daemon_reload[puppet-run.timer]) Scheduling refresh of Exec[systemd-puppet-run.timer-systemctl-daemon-reload]
2025-12-15T14:46:02.924213+01:00 HOSTNAME systemd[1]: Reload requested from client PID 307279 ('systemctl') (unit session-771.scope)...
2025-12-15T14:46:02.924364+01:00 HOSTNAME systemd[1]: Reloading...
2025-12-15T14:46:03.128740+01:00 HOSTNAME systemd[1]: Reloading finished in 203 ms.
2025-12-15T14:46:03.155183+01:00 HOSTNAME puppet-agent[306923]: (/Stage[main]/Puppet::Agent::Service::Systemd/Systemd::Timer[puppet-run.timer]/Systemd::Unit_file[puppet-run.timer]/Systemd::Daemon_reload[puppet-run.timer]/Exec[systemd-puppet-run.timer-systemctl-daemon-reload]) Triggered 'refresh' from 1 event
2025-12-15T14:46:03.177698+01:00 HOSTNAME puppet-agent[306923]: Applied catalog in 4.22 seconds
--------------------------------------------------------------------------------------
2025-12-15T17:32:41.518373+01:00 HOSTNAME puppet-agent[123415]: Executing: '/bin/systemctl reload-or-restart puppet'
2025-12-15T17:32:41.543005+01:00 HOSTNAME systemd[1]: Reloading puppet.service - Puppet agent...
2025-12-15T17:32:41.567432+01:00 HOSTNAME systemd[1]: Reloaded puppet.service - Puppet agent.
2025-12-15T17:32:41.567681+01:00 HOSTNAME puppet[123731]: #033[1;31mError: Could not initialize global default settings: SIGHUP#033[0m
2025-12-15T17:32:41.594219+01:00 HOSTNAME puppet-agent[123415]: (/Stage[main]/Puppet::Agent::Service::Cron/Cron[puppet]) Nothing to manage: no ensure and the resource doesn't exist
2025-12-15T17:32:41.597377+01:00 HOSTNAME puppet-agent[123415]: (Systemd::Unit_file[puppet-run.service]) Scheduling refresh of Systemd::Daemon_reload[puppet-run.service]
2025-12-15T17:32:41.597442+01:00 HOSTNAME puppet-agent[123415]: (/Stage[main]/Puppet::Agent::Service::Systemd/Systemd::Timer[puppet-run.timer]/Systemd::Unit_file[puppet-run.service]/File[/etc/systemd/system/puppet-run.service]) Nothing to manage:
no ensure and the resource doesn't exist
2025-12-15T17:32:41.598144+01:00 HOSTNAME puppet-agent[123415]: (Systemd::Daemon_reload[puppet-run.service]) Scheduling refresh of Exec[systemd-puppet-run.service-systemctl-daemon-reload]
2025-12-15T17:32:41.599827+01:00 HOSTNAME puppet-agent[123415]: (/Stage[main]/Puppet::Agent::Service::Systemd/Systemd::Timer[puppet-run.timer]/Systemd::Unit_file[puppet-run.service]/Systemd::Daemon_reload[puppet-run.service]/Exec[systemd-puppet-ru
n.service-systemctl-daemon-reload]) '["systemctl", "daemon-reload"]' won't be executed because of failed check 'refreshonly'
2025-12-15T17:32:41.600029+01:00 HOSTNAME puppet-agent[123415]: (Exec[systemd-puppet-run.service-systemctl-daemon-reload](provider=posix)) Executing '["systemctl", "daemon-reload"]'
2025-12-15T17:32:41.601393+01:00 HOSTNAME puppet-agent[123415]: Executing: 'systemctl daemon-reload'
2025-12-15T17:32:41.601470+01:00 HOSTNAME systemd[1]: puppet.service: Main process exited, code=exited, status=1/FAILURE
2025-12-15T17:32:41.601539+01:00 HOSTNAME systemd[1]: puppet.service: Failed with result 'exit-code'.
2025-12-15T17:32:41.602376+01:00 HOSTNAME systemd[1]: puppet.service: Consumed 1.034s CPU time, 55.1M memory peak, 0B memory swap peak.