Bug 1470119

Summary:	puppet4: puppetserver keeps failing during service init with Permission denied to /etc/puppetlabs/puppet/ssl/crl.pem
Product:	Red Hat Satellite	Reporter:	Lukas Pramuk <lpramuk>
Component:	Installation	Assignee:	Ewoud Kohl van Wijngaarden <ekohlvan>
Status:	CLOSED ERRATA	QA Contact:	Lukas Pramuk <lpramuk>
Severity:	high	Docs Contact:
Priority:	medium
Version:	6.3.0	CC:	bbuckingham, bkearney, chrobert, egolov, ehelms, ekohlvan, lpramuk, swadeley
Target Milestone:	Unspecified	Keywords:	Regression, Triaged
Target Release:	Unused
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	puppetserver-2.8	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:		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 Lukas Pramuk 2017-07-12 12:18:28 UTC

Description of problem:
Install fresh Sat6.3 with puppet4 and then puppetserver keeps failing during service init with Permission denied to /etc/puppetlabs/puppet/ssl/crl.pem though the file exists and puppet user can read it

Version-Release number of selected component (if applicable):
@satellite-6.3.0-16.0.beta.el7sat.noarch
puppetserver-2.7.2-2.el7sat.noarch

How reproducible:
100%

Steps to Reproduce:
1. Enable Puppet4 repo
2. Install Satellite
3. Check puppetserver status

# tail -f  /var/log/puppetlabs/puppetserver/puppetserver.log
2017-07-12 00:00:06,212 INFO  [async-dispatch-2] [p.t.s.w.jetty9-service] Initializing web server(s).
2017-07-12 00:00:06,277 INFO  [async-dispatch-2] [p.s.j.jruby-puppet-service] Initializing the JRuby service
2017-07-12 00:00:06,330 INFO  [async-dispatch-2] [p.s.j.jruby-pool-manager-service] Initializing the JRuby service
2017-07-12 00:00:06,420 INFO  [clojure-agent-send-pool-0] [p.s.j.i.jruby-internal] Creating JRubyInstance with id 1.
2017-07-12 00:00:22,897 INFO  [clojure-agent-send-pool-0] [puppetserver] Puppet Puppet settings initialized; run mode: master
2017-07-12 00:00:24,135 INFO  [clojure-agent-send-pool-0] [p.s.j.i.jruby-agents] Finished creating JRubyInstance 1 of 4
2017-07-12 00:00:24,136 INFO  [clojure-agent-send-pool-0] [p.s.j.i.jruby-internal] Creating JRubyInstance with id 2.
2017-07-12 00:00:24,259 INFO  [async-dispatch-2] [p.s.c.puppet-server-config-core] Not overriding webserver settings with values from core Puppet
2017-07-12 00:00:24,335 INFO  [async-dispatch-2] [p.p.certificate-authority] CA already initialized for SSL
2017-07-12 00:00:24,338 INFO  [async-dispatch-2] [p.s.c.certificate-authority-service] CA Service adding a ring handler
2017-07-12 00:00:24,422 INFO  [async-dispatch-2] [p.s.v.versioned-code-service] No code-id-command set for versioned-code-service. Code-id will be nil.
2017-07-12 00:00:24,430 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.
2017-07-12 00:00:24,466 WARN  [async-dispatch-2] [o.e.j.s.h.ContextHandler] Empty contextPath
2017-07-12 00:00:24,534 ERROR [async-dispatch-2] [p.t.internal] Error during service init!!!
java.io.FileNotFoundException: /etc/puppetlabs/puppet/ssl/crl.pem (Permission denied)
        at java.io.FileOutputStream.open0(Native Method)
        at java.io.FileOutputStream.open(FileOutputStream.java:270)
        at java.io.FileOutputStream.<init>(FileOutputStream.java:213)
        at java.io.FileOutputStream.<init>(FileOutputStream.java:162)
        at clojure.java.io$fn__9570.invokeStatic(io.clj:355)
        at clojure.java.io$fn__9570.invoke(io.clj:354)
        at clojure.lang.MultiFn.invoke(MultiFn.java:238)
        at clojure.java.io$copy.invokeStatic(io.clj:406)
        at clojure.java.io$copy.doInvoke(io.clj:391)
        at clojure.lang.RestFn.invoke(RestFn.java:425)
        at me.raynes.fs$copy.invokeStatic(fs.clj:293)
        at me.raynes.fs$copy.invoke(fs.clj:289)
        at puppetlabs.puppetserver.certificate_authority$eval16660$retrieve_ca_crl_BANG___16665$fn__16666.invoke(certificate_authority.clj:752)
        at puppetlabs.puppetserver.certificate_authority$eval16660$retrieve_ca_crl_BANG___16665.invoke(certificate_authority.clj:744)
        at puppetlabs.services.ca.certificate_authority_service$reify__24897$service_fnk__5222__auto___positional$reify__24908.retrieve_ca_crl_BANG_(certificate_authority_service.clj:52)

# ll -Z /etc/puppetlabs/puppet/ssl/crl.pem 
-rw-r--r--. root puppet system_u:object_r:puppet_etc_t:s0 /etc/puppetlabs/puppet/ssl/crl.pem

Actual results:
puppetserver service keeps on starting and failing on and on

Expected results:
puppetserver service starts successfully

Additional info:
workaround is to change owner from root to puppet so that puppet user can also write

# chown puppet /etc/puppetlabs/puppet/ssl/crl.pem
# ll -Z /etc/puppetlabs/puppet/ssl/crl.pem 
-rw-r--r--. puppet puppet system_u:object_r:puppet_etc_t:s0 /etc/puppetlabs/puppet/ssl/crl.pem

... and puppetservice starts successfully

Puppet3 Satellite has also owner=puppet, group=puppet
# ll -Z /var/lib/puppet/ssl/crl.pem
-rw-r--r--. puppet puppet system_u:object_r:puppet_var_lib_t:s0 /var/lib/puppet/ssl/crl.pem

Comment 3 Evgeni Golov 2017-08-09 09:32:23 UTC

reproducer:

$ vagrant up sat63-qa-rhel7-puppet4
[wait]
$ vagrant ssh sat63-qa-rhel7-puppet4
$ sudo systemctl restart puppetserver
Job for puppetserver.service failed because the control process exited with error code. See "systemctl status puppetserver.service" and "journalctl -xe" for details.

workaround:

$ sudo chown -R puppet /etc/puppetlabs/puppet/ssl

Comment 4 Lukas Pramuk 2017-09-04 16:58:42 UTC

Found another workaround = another installer run:

@fresh p4 install (having issue):
# find /etc /var -name crl.pem -exec namei -l {} \;
f: /etc/puppetlabs/puppet/ssl/crl.pem
dr-xr-xr-x root root   /
drwxr-xr-x root root   etc
drwxr-xr-x root root   puppetlabs
drwxr-xr-x root root   puppet
drwxrwx--x root puppet ssl
-rw-r--r-- root puppet crl.pem

# satellite-installer 
Installing
...

# find /etc /var -name crl.pem -exec namei -l {} \;
f: /etc/puppetlabs/puppet/ssl/crl.pem
dr-xr-xr-x root   root   /
drwxr-xr-x root   root   etc
drwxr-xr-x root   root   puppetlabs
drwxr-xr-x root   root   puppet    < still wrong owner and group (root cause?)
drwxrwx--x puppet puppet ssl       < fixed owner
-rw-r--r-- puppet puppet crl.pem   < fixed owner

Comment 5 Lukas Pramuk 2017-09-04 16:59:41 UTC

Looking into upgraded p4 install makes it obvious what diverged and caused issue
>>> created files/dirs in directory having bad perms will also have bad perms

@upgraded p4 install:
# find /etc /var -name crl.pem -exec namei -l {} \;
f: /etc/puppetlabs/puppet/ssl/crl.pem
dr-xr-xr-x root   root   /
drwxr-xr-x root   root   etc
drwxr-xr-x root   root   puppetlabs
drwxr-xr-x puppet puppet puppet
drwxrwx--x puppet puppet ssl
-rw-r--r-- puppet puppet crl.pem
f: /var/lib/puppet/ssl/crl.pem
dr-xr-xr-x root   root   /
drwxr-xr-x root   root   var
drwxr-xr-x root   root   lib
drwxr-x--- puppet puppet puppet
drwxrwx--x puppet puppet ssl
-rw-r--r-- puppet puppet crl.pem

>>> on p3 install /var/lib/puppet is owned by puppet:puppet (no issue)

>>> on upgraded p4 install /etc/puppetlabs/puppet is owned by puppet:puppet (no issue)

>>> on fresh p4 install /etc/puppetlabs/puppet is owned by root:root (ISSUE!) - any file created will have bad perms

Comment 7 Lukas Pramuk 2017-09-06 15:58:23 UTC

Bad perms of /etc/puppetlabs/puppet originate from that preinstall script of puppet-agent is lacking "puppet" user creation.

Thus /etc/puppetlabs/puppet are owned by root:root 
See differences between puppet rpms:

(Puppet 3)
# rpm -q --scripts puppet | grep useradd
useradd -r -u 52 -g puppet -d /var/lib/puppet -s /sbin/nologin \

vs.

(Puppet 4)
#  rpm -q --scripts puppet-agent | grep useradd
<none>   <<< this is BAD! (content gets created under root)

#  rpm -q --scripts puppetserver | grep useradd
  useradd -r --gid puppet --home /opt/puppetlabs/server/data/puppetserver --shell $(which nologin) \

Comment 8 Lukas Pramuk 2017-09-06 16:00:39 UTC

...though p4 puppetserver brings in puppet user, it is too late as content already exists 
(puppet-agent pulled in by rpm deps vs. puppetserver pulled in by installer)

Comment 9 Lukas Pramuk 2017-09-07 11:33:42 UTC

During installation right after puppetserver installation (puppet user available) I changed perms of /etc/puppetlabs/puppet from root:root to puppet:puppet and watched content (esp. crl.pem) being  populated with right puppet:puppet perms.

But later on during install something changed just owner of some files/dirs from puppet to root and group stayed (root:puppet)

Below you can see final result after installation finished:

-rw-r--r--. 1 root   puppet 1003 Sep  6 11:45 /etc/puppetlabs/puppet/ssl/crl.pem

/etc/puppetlabs/puppet/ssl:
total 28
drwxr-xr-x. 5 puppet puppet 4096 Sep  6 11:44 ca
drwxr-xr-x. 2 root   puppet 4096 Sep  6 11:44 certificate_requests
drwxr-xr-x. 2 root   puppet 4096 Sep  6 11:44 certs
-rw-r--r--. 1 root   puppet 1003 Sep  6 11:45 crl.pem
drwxr-x---. 2 root   puppet 4096 Sep  6 11:29 private
drwxr-x---. 2 root   puppet 4096 Sep  6 11:44 private_keys
drwxr-xr-x. 2 root   puppet 4096 Sep  6 11:44 public_keys

/etc/puppetlabs/puppet/ssl/ca:
total 36
-rw-r--r--. 1 puppet puppet 1003 Sep  6 11:44 ca_crl.pem
-rw-r--r--. 1 puppet puppet 2078 Sep  6 11:44 ca_crt.pem
-rw-r-----. 1 puppet puppet 3247 Sep  6 11:44 ca_key.pem
-rw-r--r--. 1 puppet puppet  800 Sep  6 11:44 ca_pub.pem
-rw-r--r--. 1 puppet puppet  215 Sep  6 11:44 inventory.txt
drwxr-x---. 2 puppet puppet 4096 Sep  6 11:44 private
drwxr-xr-x. 2 puppet puppet 4096 Sep  6 11:44 requests
-rw-r--r--. 1 puppet puppet    4 Sep  6 11:44 serial
drwxr-xr-x. 2 puppet puppet 4096 Sep  6 11:44 signed

/etc/puppetlabs/puppet/ssl/certificate_requests:
total 0

/etc/puppetlabs/puppet/ssl/certs:
total 8
-rw-r--r--. 1 root puppet 2078 Sep  6 11:44 ca.pem
-rw-r--r--. 1 root puppet 2175 Sep  6 11:44 <fqdn>.pem

/etc/puppetlabs/puppet/ssl/private:
total 0

Comment 10 Lukas Pramuk 2017-09-13 10:34:15 UTC

This part (just before installation finished) reset perms back to wrong root:puppet


[ WARN 2017-09-13 06:15:10 verbose]  /Stage[main]/Certs::Katello/Certs::Rhsm_reconfigure_script[/var/www/html/pub/katello-rhsm-consumer]/Concat[/var/www/html/pub/katello-rhsm-consumer]/File[/var/www/html/pub/katello-rhsm-consumer]/ensure: defined content as '{md5}7d4ebd59db4f68fb46245153fa615970'
[ INFO 2017-09-13 06:15:10 verbose]  Certs::Rhsm_reconfigure_script[/var/www/html/pub/katello-rhsm-consumer]: Scheduling refresh of Certs_bootstrap_rpm[katello-ca-consumer-<SATFQDN>]
[ WARN 2017-09-13 06:15:11 verbose]  /Stage[main]/Certs::Katello/Certs_bootstrap_rpm[katello-ca-consumer-<SATFQDN>]: Triggered 'refresh' from 3 events

[ WARN 2017-09-13 06:15:12 verbose]  Applied catalog in 1565.49 seconds

[ INFO 2017-09-13 06:15:17 verbose] Puppet has finished, bye!
[ INFO 2017-09-13 06:15:17 verbose] Executing hooks in group post
  Success!
  * Katello is running at https://<SATFQDN>

Comment 12 Ewoud Kohl van Wijngaarden 2017-09-29 08:37:54 UTC

This is mostly notes for myself.

In the logs we see (after the main installation):

[DEBUG 2017-09-27 14:01:39 main] Applying settings catalog for sections main, reporting, metrics
[DEBUG 2017-09-27 13:57:49 main]  Using settings: adding file resource 'hostcrl': 'File[/etc/puppetlabs/puppet/ssl/crl.pem]{:path=>"/etc/puppetlabs/puppet/ssl/crl.pem", :mode=>"644", :owner=>"root", :ensure=>:file, :loglevel=>:debug, :links=>:follow, :backup=>false}'

On a second run we see this with the proper owner and group:

[DEBUG 2017-09-27 14:01:39 main] Using settings: adding file resource 'hostcrl': 'File[/etc/puppetlabs/puppet/ssl/crl.pem]{:path=>"/etc/puppetlabs/puppet/ssl/crl.pem", :mode=>"644", :owner=>"puppet", :group=>"puppet", :ensure=>:file, :loglevel=>:debug, :links=>:follow, :backup=>false}'

This default comes from https://github.com/puppetlabs/puppet/blob/1baa0b189ee38d965dce239651db8b62688d7f9a/lib/puppet/defaults.rb#L847-L855 combined with the fallback code at https://github.com/puppetlabs/puppet/blob/1baa0b189ee38d965dce239651db8b62688d7f9a/lib/puppet/settings.rb#L788-L810 and https://github.com/puppetlabs/puppet/blob/1baa0b189ee38d965dce239651db8b62688d7f9a/lib/puppet/settings/file_setting.rb#L91

It looks like the report processor indirector triggers it. 

https://github.com/puppetlabs/puppet/blob/1baa0b189ee38d965dce239651db8b62688d7f9a/lib/puppet/indirector/report/processor.rb#L10 triggers the line

[DEBUG 2017-09-27 14:01:39 main] Applying settings catalog for sections main, reporting, metrics

Then we see it reset the permissions. Then we see

[DEBUG 2017-09-27 13:57:49 main] Received report to process from centos7-foreman-bats-ci.wisse.example.com

This comes from https://github.com/puppetlabs/puppet/blob/1baa0b189ee38d965dce239651db8b62688d7f9a/lib/puppet/indirector/report/processor.rb#L29

Still working on finding the minimal reproducer.

Comment 13 Ewoud Kohl van Wijngaarden 2017-10-05 10:13:09 UTC

It appears it was fixed in puppetserver 2.8.0 with the automatic CRL refresher. See https://docs.puppet.com/puppetserver/2.8/release_notes.html#new-feature-automatic-crl-refresh-on-certificate-revocation

Comment 14 Satellite Program 2017-10-05 12:19:29 UTC

Moving this bug to POST for triage into Satellite 6 since the upstream issue http://projects.theforeman.org/issues/19986 has been resolved.

Comment 15 Lukas Pramuk 2017-10-10 20:05:30 UTC

FailedQA.

@satellite-6.3.0-19.0.beta.el7sat.noarch
puppetserver-2.8.0-1.el7sat.noarch

# satellite-installer -S satellite
 Systemd start for puppetserver failed!
journalctl log for puppetserver:
-- Logs begin at Tue 2017-10-03 06:35:48 EDT, end at Tue 2017-10-10 10:47:12 EDT. --
Oct 10 10:47:12 <SAT_FQDN> systemd[1]: Starting puppetserver Service...
Oct 10 10:47:12 <SAT_FQDN> systemd[1]: puppetserver.service: control process exited, code=exited status=1
Oct 10 10:47:12 <SAT_FQDN> systemd[1]: Failed to start puppetserver Service.
Oct 10 10:47:12 <SAT_FQDN> systemd[1]: Unit puppetserver.service entered failed state.
Oct 10 10:47:12 <SAT_FQDN> systemd[1]: puppetserver.service failed.

/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/provider/service/systemd.rb:166:in `rescue in start'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/provider/service/systemd.rb:163:in `start'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/service.rb:103:in `block (3 levels) in <module:Puppet>'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/property.rb:487:in `set'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/property.rb:561:in `sync'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/service.rb:114:in `sync'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:236:in `sync'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:134:in `sync_if_needed'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:80:in `perform_changes'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:21:in `evaluate'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:230:in `apply'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:246:in `eval_resource'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `call'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `block (2 levels) in evaluate'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:507:in `block in thinmark'
/opt/puppetlabs/puppet/lib/ruby/2.1.0/benchmark.rb:294:in `realtime'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:506:in `thinmark'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:163:in `block in evaluate'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/graph/relationship_graph.rb:118:in `traverse'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:154:in `evaluate'
/usr/share/gems/gems/kafo-2.0.0/modules/kafo_configure/lib/puppet/parser/functions/add_progress.rb:30:in `evaluate_with_trigger'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:222:in `block in apply'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:155:in `with_destination'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/report.rb:142:in `as_logging_destination'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:221:in `apply'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:171:in `block in apply_catalog'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:224:in `block in benchmark'
/opt/puppetlabs/puppet/lib/ruby/2.1.0/benchmark.rb:294:in `realtime'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:223:in `benchmark'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:170:in `apply_catalog'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:343:in `run_internal'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:221:in `block in run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/context.rb:65:in `override'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet.rb:306:in `override'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:195:in `run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:350:in `apply_catalog'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:274:in `block in main'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/context.rb:65:in `override'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet.rb:306:in `override'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:225:in `main'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:170:in `run_command'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:358:in `block in run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:662:in `exit_on_fail'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:358:in `run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:132:in `run'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:72:in `execute'
/opt/puppetlabs/puppet/bin/puppet:5:in `<main>'
 /Stage[main]/Puppet::Server::Service/Service[puppetserver]/ensure: change from stopped to running failed: Systemd start for puppetserver failed!
journalctl log for puppetserver:
-- Logs begin at Tue 2017-10-03 06:35:48 EDT, end at Tue 2017-10-10 10:47:12 EDT. --
Oct 10 10:47:12 <SAT_FQDN> systemd[1]: Starting puppetserver Service...
Oct 10 10:47:12 <SAT_FQDN> systemd[1]: puppetserver.service: control process exited, code=exited status=1
Oct 10 10:47:12 <SAT_FQDN> systemd[1]: Failed to start puppetserver Service.
Oct 10 10:47:12 <SAT_FQDN> systemd[1]: Unit puppetserver.service entered failed state.
Oct 10 10:47:12 <SAT_FQDN> systemd[1]: puppetserver.service failed.
Installing             Done                                               [100%] [.....................................]
  Something went wrong! Check the log for ERROR-level output
  The full log is at /var/log/foreman-installer/satellite.log

# service puppetserver status
Redirecting to /bin/systemctl status puppetserver.service
● puppetserver.service - puppetserver Service
   Loaded: loaded (/usr/lib/systemd/system/puppetserver.service; disabled; vendor preset: disabled)
   Active: failed (Result: start-limit) since Tue 2017-10-10 10:47:13 EDT; 2h 25min ago

Oct 10 10:47:13 <SAT_FQDN> systemd[1]: Failed to start puppetserver Service.
Oct 10 10:47:13 <SAT_FQDN> systemd[1]: Unit puppetserver.service entered failed state.
Oct 10 10:47:13 <SAT_FQDN> systemd[1]: puppetserver.service failed.
Oct 10 10:47:13 <SAT_FQDN> systemd[1]: puppetserver.service holdoff time over, sche...t.
Oct 10 10:47:13 <SAT_FQDN> systemd[1]: start request repeated too quickly for puppe...ce
Oct 10 10:47:13 <SAT_FQDN> systemd[1]: Failed to start puppetserver Service.
Oct 10 10:47:13 <SAT_FQDN> systemd[1]: Unit puppetserver.service entered failed state.
Oct 10 10:47:13 <SAT_FQDN> systemd[1]: puppetserver.service failed.

>>> after rebase to 2.8.0 puppetserver service fails to start

Comment 18 Lukas Pramuk 2017-10-11 19:24:50 UTC

After puppetserver installation most of time the CRL was puppet:puppet owned, but still right before installer ends it was switch to be root:puppet owned.

/etc/puppetlabs/puppet/ssl:
total 4
drwxr-xr-x. 5 puppet puppet 158 Oct 11 11:08 ca
drwxr-xr-x. 2 root   puppet   6 Oct 11 11:08 certificate_requests
drwxr-xr-x. 2 root   puppet  74 Oct 11 11:08 certs
-rw-r--r--. 1 root   puppet 999 Oct 11 11:09 crl.pem
drwxr-x---. 2 root   puppet   6 Oct 11 10:50 private
drwxr-x---. 2 root   puppet  60 Oct 11 11:08 private_keys
drwxr-xr-x. 2 root   puppet  60 Oct 11 11:08 public_keys

The change with puppetserver 2.8.0 (compared to 2.7.2) is that the error is not fatal and the service keeps running, however still complains in the logs:

2017-10-11 11:36:56,310 INFO  [clojure-agent-send-pool-0] [puppetserver] Puppet Puppet settings initialized; run mode: master
2017-10-11 11:36:57,499 INFO  [clojure-agent-send-pool-0] [p.s.j.i.jruby-agents] Finished creating JRubyInstance 1 of 8
2017-10-11 11:36:57,500 INFO  [clojure-agent-send-pool-0] [p.s.j.i.jruby-internal] Creating JRubyInstance with id 2.
2017-10-11 11:36:57,521 INFO  [async-dispatch-2] [p.s.c.puppet-server-config-core] Not overriding webserver settings with values from core Puppet
2017-10-11 11:36:57,540 INFO  [async-dispatch-2] [p.p.certificate-authority] CA already initialized for SSL
2017-10-11 11:36:57,545 INFO  [async-dispatch-2] [p.s.c.certificate-authority-service] CA Service adding a ring handler
2017-10-11 11:36:57,640 WARN  [async-dispatch-2] [o.e.j.s.h.ContextHandler] Empty contextPath
2017-10-11 11:36:58,167 INFO  [clojure-agent-send-off-pool-0] [p.d.version-check] Newer version 5.1.3 is available! Visit https://docs.puppet.com/puppetserver/latest/release_notes.html#puppet-server-513 for details.
2017-10-11 11:37:00,227 ERROR [async-dispatch-2] [p.p.certificate-authority] Unable to synchronize crl file /etc/puppetlabs/puppet/ssl/ca/ca_crl.pem to /etc/puppetlabs/puppet/ssl/crl.pem: /etc/puppetlabs/puppet/ssl/crl.pem (Permission denied).
Recent changes to the CRL may not have taken effect.
To load the updated CRL reload or restart the Puppet Server service.
2017-10-11 11:37:00,231 INFO  [async-dispatch-2] [p.p.certificate-authority] Master already initialized for SSL

Ewoud, I'm not sure if I can consider this BZ as fixed?

Comment 20 Ewoud Kohl van Wijngaarden 2017-10-12 13:43:28 UTC

I think it can be considered fixed. It no longer blocks on startup. Sync appeared to be an issue on the first run, but after restarting puppetserver it does properly sync. Given we use the other file (ca/ca_crl.pem) to expose over the network, I believe this is not an issue. We can still file an issue on puppet about the ERROR for the initial sync but it should no longer impede the beta.

Comment 21 Lukas Pramuk 2017-10-13 08:15:53 UTC

VERIFIED.

@satellite-6.3.0-19.0.beta.el7sat.noarch
puppetserver-2.8.0-1.el7sat.noarch

# satellite-installer -S satellite
...

# service puppetserver status
Redirecting to /bin/systemctl status puppetserver.service
● puppetserver.service - puppetserver Service
   Loaded: loaded (/usr/lib/systemd/system/puppetserver.service; enabled; vendor preset: disabled)
   Active: active (running) since Thu 2017-10-12 07:02:03 EDT; 21h ago
  Process: 57681 ExecStop=/opt/puppetlabs/server/apps/puppetserver/bin/puppetserver stop (code=exited, status=0/SUCCESS)
  Process: 57699 ExecStart=/opt/puppetlabs/server/apps/puppetserver/bin/puppetserver start (code=exited, status=0/SUCCESS)
 Main PID: 57706 (java)
   CGroup: /system.slice/puppetserver.service
           └─57706 /usr/bin/java -Xms2G -Xmx2G -XX:MaxPermSize=256m -Djava.security.egd=/dev/urandom -XX:OnOutOfMemor...

Oct 12 07:01:24 <SAT_FQDN> systemd[1]: Starting puppetserver Service...
Oct 12 07:01:24 <SAT_FQDN> puppetserver[57699]: OpenJDK 64-Bit Server VM warning: ig...0
Oct 12 07:02:03 <SAT_FQDN> systemd[1]: Started puppetserver Service.

>>> puppetserver 2.8.0 (compared to 2.7.2) is able to overcome ownership issue and the service keeps running

Comment 22 Bryan Kearney 2018-02-21 17:33:23 UTC

Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA.

For information on the advisory, and where to find the updated files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2018:0336

Comment 23 Bryan Kearney 2018-02-21 17:33:43 UTC

Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA.

For information on the advisory, and where to find the updated files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2018:0336