Bug 1252932

Summary: 3rd party ssl certs throw an error during upgrade to 6.1.1
Product: Red Hat Satellite Reporter: Matthew Davis <mdavis>
Component: UpgradesAssignee: Chris Roberts <chrobert>
Status: CLOSED CURRENTRELEASE QA Contact: Katello QA List <katello-qa-list>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 6.1.0CC: bbuckingham, chrobert
Target Milestone: UnspecifiedKeywords: Triaged
Target Release: Unused   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-08-31 19:04:30 UTC 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:
Attachments:
Description Flags
katelllo-installer log none

Description Matthew Davis 2015-08-12 14:26:49 UTC 
Created attachment 1062003 [details]
katelllo-installer log

Description of problem:

[root@satellite6 ~]# katello-installer --upgrade
Upgrading...
Upgrade Step: stop_services...
Upgrade Step: start_mongo...
Upgrade Step: migrate_pulp...
Upgrade Step: start_httpd...
Upgrade Step: migrate_candlepin...
Upgrade Step: migrate_foreman...
Upgrade Step: Running installer...
 does not exist at /usr/share/katello-installer/modules/certs/manifests/init.pp:115 on node satellite6.rdu.salab.redhat.com
 does not exist at /usr/share/katello-installer/modules/certs/manifests/init.pp:115 on node satellite6.rdu.salab.redhat.com
Preparing installation Done                                              
  Something went wrong! Check the log for ERROR-level output
  The full log is at /var/log/katello-installer/katello-installer.log
Upgrade Step: restart_services...
Upgrade step restart_services failed. Check logs for more information.
[root@satellite6 ~]#

[root@satellite6 ~]# sed -n '113,117p' /usr/share/katello-installer/modules/certs/manifests/init.pp

  if $server_cert {
    validate_file_exists($server_cert, $server_cert_req, $server_key, $server_ca_cert)
  }

Version-Release number of selected component (if applicable):
6.1.1
Comment 1 Matthew Davis 2015-08-12 14:27:59 UTC 
upgrade log is attached and here is the katello-service status command after the upgrade.


mongod.service - High-performance, schema-free document-oriented database
   Loaded: loaded (/usr/lib/systemd/system/mongod.service; enabled)
   Active: failed (Result: timeout) since Wed 2015-08-12 10:13:18 EDT; 11min ago
  Process: 28788 ExecStart=/usr/bin/mongod $OPTIONS run (code=exited, status=0/SUCCESS)
 Main PID: 27029 (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/mongod.service

Aug 12 10:11:48 satellite6.rdu.salab.redhat.com mongod[28788]: about to fork child process, waiting until server is ready for connections.
Aug 12 10:11:48 satellite6.rdu.salab.redhat.com mongod[28788]: forked process: 28790
Aug 12 10:11:48 satellite6.rdu.salab.redhat.com mongod[28788]: all output going to: /var/lib/mongodb/mongodb.log
Aug 12 10:11:51 satellite6.rdu.salab.redhat.com mongod[28788]: child process started successfully, parent exiting
Aug 12 10:11:51 satellite6.rdu.salab.redhat.com systemd[1]: PID file /var/run/mongodb/mongodb.pid not readable (yet?) after start.
Aug 12 10:13:18 satellite6.rdu.salab.redhat.com systemd[1]: mongod.service operation timed out. Terminating.
Aug 12 10:13:18 satellite6.rdu.salab.redhat.com systemd[1]: Failed to start High-performance, schema-free document-oriented database.
Aug 12 10:13:18 satellite6.rdu.salab.redhat.com systemd[1]: Unit mongod.service entered failed state.
qpidd.service - An AMQP message broker daemon.
   Loaded: loaded (/usr/lib/systemd/system/qpidd.service; enabled)
   Active: active (running) since Wed 2015-08-12 10:13:24 EDT; 11min ago
     Docs: man:qpidd(1)
           http://qpid.apache.org/
 Main PID: 28923 (qpidd)
   CGroup: /system.slice/qpidd.service
           └─28923 /usr/sbin/qpidd --config /etc/qpid/qpidd.conf

Aug 12 10:13:24 satellite6.rdu.salab.redhat.com systemd[1]: Starting An AMQP message broker daemon....
Aug 12 10:13:24 satellite6.rdu.salab.redhat.com systemd[1]: Started An AMQP message broker daemon..
qdrouterd.service - Qpid Dispatch router daemon
   Loaded: loaded (/usr/lib/systemd/system/qdrouterd.service; enabled)
   Active: active (running) since Wed 2015-08-12 10:13:24 EDT; 11min ago
 Main PID: 28938 (qdrouterd)
   CGroup: /system.slice/qdrouterd.service
           └─28938 /usr/sbin/qdrouterd -c /etc/qpid-dispatch/qdrouterd.conf

Aug 12 10:13:24 satellite6.rdu.salab.redhat.com qdrouterd[28938]: Wed Aug 12 10:13:24 2015 ROUTER (info) Configured Address: prefix=/ phase=0 fanout=QD_SCHEMA_FIXEDADDRESS_FANOUT_MULTIPLE
Aug 12 10:13:24 satellite6.rdu.salab.redhat.com qdrouterd[28938]: Wed Aug 12 10:13:24 2015 CONN_MGR (info) Configured Listener: 0.0.0.0:5647 role=normal
Aug 12 10:13:24 satellite6.rdu.salab.redhat.com qdrouterd[28938]: Wed Aug 12 10:13:24 2015 CONN_MGR (info) Configured Listener: 0.0.0.0:5646 role=inter-router
Aug 12 10:13:24 satellite6.rdu.salab.redhat.com qdrouterd[28938]: Wed Aug 12 10:13:24 2015 CONN_MGR (info) Configured on-demand connector: satellite6.rdu.salab.redhat.com:5671 name=broker
Aug 12 10:13:24 satellite6.rdu.salab.redhat.com qdrouterd[28938]: Wed Aug 12 10:13:24 2015 ROUTER (info) Configured Link-route-pattern: prefix=pulp. connector=broker
Aug 12 10:13:24 satellite6.rdu.salab.redhat.com qdrouterd[28938]: Wed Aug 12 10:13:24 2015 ROUTER (info) Configured Link-route-pattern: prefix=qmf. connector=broker
Aug 12 10:13:24 satellite6.rdu.salab.redhat.com qdrouterd[28938]: Wed Aug 12 10:13:24 2015 CONN_MGR (info) Starting on-demand connector: broker
Aug 12 10:13:24 satellite6.rdu.salab.redhat.com qdrouterd[28938]: Wed Aug 12 10:13:24 2015 SERVER (info) Operational, 16 Threads Running
Aug 12 10:13:31 satellite6.rdu.salab.redhat.com qdrouterd[28938]: Wed Aug 12 10:13:31 2015 ROUTER (info) Activating Prefix 'pulp.' for routed links to 'broker'
Aug 12 10:13:31 satellite6.rdu.salab.redhat.com qdrouterd[28938]: Wed Aug 12 10:13:31 2015 ROUTER (info) Activating Prefix 'qmf.' for routed links to 'broker'
tomcat.service - Apache Tomcat Web Application Container
   Loaded: loaded (/usr/lib/systemd/system/tomcat.service; enabled)
   Active: active (running) since Wed 2015-08-12 10:13:24 EDT; 11min ago
 Main PID: 28954 (java)
   CGroup: /system.slice/tomcat.service
           └─28954 java -classpath /usr/share/tomcat/bin/bootstrap.jar:/usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/commons-daemon.jar -Dcatalina.base=/usr/share/tomcat -Dcatalina.home=/usr/share/tomcat -Djava.endorsed.dirs= -Djava.io.tmpdir=/var/cache/tomcat/temp -Djava.util.logging.config.file=/usr/share/tomcat/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager org.apache.catalina.startup.Bootstrap start

Aug 12 10:13:41 satellite6.rdu.salab.redhat.com server[28954]: Aug 12, 2015 10:13:41 AM org.apache.catalina.startup.HostConfig deployDirectory
Aug 12 10:13:41 satellite6.rdu.salab.redhat.com server[28954]: INFO: Deployment of web application directory /var/lib/tomcat/webapps/candlepin has finished in 9,300 ms
Aug 12 10:13:41 satellite6.rdu.salab.redhat.com server[28954]: Aug 12, 2015 10:13:41 AM org.apache.coyote.AbstractProtocol start
Aug 12 10:13:41 satellite6.rdu.salab.redhat.com server[28954]: INFO: Starting ProtocolHandler ["http-bio-8080"]
Aug 12 10:13:41 satellite6.rdu.salab.redhat.com server[28954]: Aug 12, 2015 10:13:41 AM org.apache.coyote.AbstractProtocol start
Aug 12 10:13:41 satellite6.rdu.salab.redhat.com server[28954]: INFO: Starting ProtocolHandler ["http-bio-8443"]
Aug 12 10:13:41 satellite6.rdu.salab.redhat.com server[28954]: Aug 12, 2015 10:13:41 AM org.apache.coyote.AbstractProtocol start
Aug 12 10:13:41 satellite6.rdu.salab.redhat.com server[28954]: INFO: Starting ProtocolHandler ["ajp-bio-8009"]
Aug 12 10:13:41 satellite6.rdu.salab.redhat.com server[28954]: Aug 12, 2015 10:13:41 AM org.apache.catalina.startup.Catalina start
Aug 12 10:13:41 satellite6.rdu.salab.redhat.com server[28954]: INFO: Server startup in 16745 ms
elasticsearch.service - LSB: Starts elasticsearch
   Loaded: loaded (/etc/rc.d/init.d/elasticsearch)
   Active: active (running) since Wed 2015-08-12 10:13:24 EDT; 11min ago
  Process: 29002 ExecStart=/etc/rc.d/init.d/elasticsearch start (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/elasticsearch.service
           └─29014 java -Xms256m -Xmx256m -Xss256k -Djava.awt.headless=true -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly -XX:+HeapDumpOnOutOfMemoryError -Delasticsearch -Des.pidfile=/var/run/elasticsearch/elasticsearch.pid -Des.path.home=/usr/share/java/elasticsearch -cp :/usr/share/java/elasticsearch/lib/elasticsearch-0.90.10.redhat-1.jar:/usr/share/java/lucene4-core.jar:/usr/share/java/lucene4-contrib/*:/usr/share/java/sigar/sigar.jar -Des.config=/etc/elasticsearch/elasticsearch.yml -Des.path.conf=/etc/elasticsearch -Des.path.home=/usr/share/java/elasticsearch -Des.path.logs=/var/log/elasticsearch -Des.path.data=/var/lib/elasticsearch -Des.path.work=/tmp/elasticsearch -Des.path.plugins=/usr/share/java/elasticsearch/plugins org.elasticsearch.bootstrap.ElasticSearch

Aug 12 10:13:24 satellite6.rdu.salab.redhat.com systemd[1]: Starting LSB: Starts elasticsearch...
Aug 12 10:13:24 satellite6.rdu.salab.redhat.com runuser[29007]: pam_unix(runuser:session): session opened for user elasticsearch by (uid=0)
Aug 12 10:13:24 satellite6.rdu.salab.redhat.com elasticsearch[29002]: Starting elasticsearch: [  OK  ]
Aug 12 10:13:24 satellite6.rdu.salab.redhat.com systemd[1]: Started LSB: Starts elasticsearch.
foreman-proxy.service - Foreman Proxy
   Loaded: loaded (/usr/lib/systemd/system/foreman-proxy.service; enabled)
   Active: active (running) since Wed 2015-08-12 10:13:35 EDT; 10min ago
  Process: 29230 ExecStart=/usr/share/foreman-proxy/bin/smart-proxy (code=exited, status=0/SUCCESS)
 Main PID: 29240 (ruby)
   CGroup: /system.slice/foreman-proxy.service
           └─29240 ruby /usr/share/foreman-proxy/bin/smart-proxy

Aug 12 10:13:34 satellite6.rdu.salab.redhat.com systemd[1]: Starting Foreman Proxy...
Aug 12 10:13:35 satellite6.rdu.salab.redhat.com systemd[1]: PID file /run/foreman-proxy/foreman-proxy.pid not readable (yet?) after start.
Aug 12 10:13:35 satellite6.rdu.salab.redhat.com systemd[1]: Started Foreman Proxy.
pulp_celerybeat.service - Pulp's Celerybeat
   Loaded: loaded (/usr/lib/systemd/system/pulp_celerybeat.service; enabled)
   Active: active (running) since Wed 2015-08-12 10:13:35 EDT; 10min ago
 Main PID: 29258 (celery)
   CGroup: /system.slice/pulp_celerybeat.service
           └─29258 /usr/bin/python /usr/bin/celery beat --scheduler=pulp.server.async.scheduler.Scheduler

Aug 12 10:23:11 satellite6.rdu.salab.redhat.com pulp[29258]: pulp.server.db.connection:ERROR: (29258-23424) ... Waiting 32 seconds and trying again.
Aug 12 10:23:36 satellite6.rdu.salab.redhat.com pulp[29258]: pulp.server.async.scheduler:ERROR: Cannot get collection from uninitialized database
Aug 12 10:23:43 satellite6.rdu.salab.redhat.com pulp[29258]: pulp.server.db.connection:ERROR: (29258-23424) Could not connect to MongoDB at localhost:27017:
Aug 12 10:23:43 satellite6.rdu.salab.redhat.com pulp[29258]: pulp.server.db.connection:ERROR: (29258-23424) Cannot connect to database default :
Aug 12 10:23:43 satellite6.rdu.salab.redhat.com pulp[29258]: pulp.server.db.connection:ERROR: (29258-23424) could not connect to localhost:27017: [Errno 111] Connection refused
Aug 12 10:23:43 satellite6.rdu.salab.redhat.com pulp[29258]: pulp.server.db.connection:ERROR: (29258-23424) ... Waiting 32 seconds and trying again.
Aug 12 10:24:15 satellite6.rdu.salab.redhat.com pulp[29258]: pulp.server.db.connection:ERROR: (29258-23424) Could not connect to MongoDB at localhost:27017:
Aug 12 10:24:15 satellite6.rdu.salab.redhat.com pulp[29258]: pulp.server.db.connection:ERROR: (29258-23424) Cannot connect to database default :
Aug 12 10:24:15 satellite6.rdu.salab.redhat.com pulp[29258]: pulp.server.db.connection:ERROR: (29258-23424) could not connect to localhost:27017: [Errno 111] Connection refused
Aug 12 10:24:15 satellite6.rdu.salab.redhat.com pulp[29258]: pulp.server.db.connection:ERROR: (29258-23424) ... Waiting 32 seconds and trying again.
pulp_resource_manager.service - Pulp Resource Manager
   Loaded: loaded (/usr/lib/systemd/system/pulp_resource_manager.service; enabled)
   Active: active (running) since Wed 2015-08-12 10:13:35 EDT; 10min ago
 Main PID: 29272 (celery)
   CGroup: /system.slice/pulp_resource_manager.service
           └─29272 /usr/bin/python /usr/bin/celery worker -A pulp.server.async.app -n resource_manager@%h -Q resource_manager -c 1 --events --umask 18

Aug 12 10:13:35 satellite6.rdu.salab.redhat.com systemd[1]: Started Pulp Resource Manager.
Aug 12 10:13:35 satellite6.rdu.salab.redhat.com celery[29272]: No handlers could be found for logger "pulp.server.db.connection"
pulp_workers.service - Pulp Celery Workers
   Loaded: loaded (/usr/lib/systemd/system/pulp_workers.service; enabled)
   Active: active (exited) since Wed 2015-08-12 10:13:35 EDT; 10min ago
  Process: 29286 ExecStart=/usr/libexec/pulp-manage-workers start (code=exited, status=0/SUCCESS)
 Main PID: 29286 (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/pulp_workers.service

Aug 12 10:13:35 satellite6.rdu.salab.redhat.com systemd[1]: Started Pulp Celery Workers.
httpd.service - The Apache HTTP Server
   Loaded: loaded (/usr/lib/systemd/system/httpd.service; enabled)
   Active: active (running) since Wed 2015-08-12 10:13:37 EDT; 10min ago
  Process: 29340 ExecStop=/bin/kill -WINCH ${MAINPID} (code=exited, status=0/SUCCESS)
 Main PID: 29406 (httpd)
   Status: "Total requests: 0; Current requests/sec: 0; Current traffic:   0 B/sec"
   CGroup: /system.slice/httpd.service
           ├─29406 /usr/sbin/httpd -DFOREGROUND
           ├─29427 PassengerWatchdog
           ├─29430 PassengerHelperAgent
           ├─29436 PassengerLoggingAgent
           ├─29445 (wsgi:pulp)     -DFOREGROUND
           ├─29446 /usr/sbin/httpd -DFOREGROUND
           ├─29447 /usr/sbin/httpd -DFOREGROUND
           ├─29448 /usr/sbin/httpd -DFOREGROUND
           ├─29450 /usr/sbin/httpd -DFOREGROUND
           ├─29451 /usr/sbin/httpd -DFOREGROUND
           ├─29452 /usr/sbin/httpd -DFOREGROUND
           ├─29453 /usr/sbin/httpd -DFOREGROUND
           ├─29454 /usr/sbin/httpd -DFOREGROUND
           ├─29685 Passenger RackApp: /usr/share/foreman                                      
           ├─29904 /bin/bash /usr/bin/ruby193-ruby /usr/share/gems/gems/passenger-4.0.18/helper-scripts/rack-preloader.rb
           ├─29913 scl enable ruby193 v8314 ruby /usr/share/gems/gems/passenger-4.0.18/helper-scripts/rack-preloader.rb
           ├─29914 /bin/bash /var/tmp/sclZ8QI7r
           ├─29920 Passenger AppPreloader: /usr/share/foreman                                 
           ├─29925 /usr/sbin/httpd -DFOREGROUND
           ├─29928 /usr/sbin/httpd -DFOREGROUND
           ├─29929 /usr/sbin/httpd -DFOREGROUND
           ├─30069 Passenger RackApp: /usr/share/foreman                                      
           └─30103 Passenger RackApp: /usr/share/foreman                                      

Aug 12 10:23:12 satellite6.rdu.salab.redhat.com pulp[29445]: pulp.server.db.connection:ERROR: (29445-30304) could not connect to localhost:27017: [Errno 111] Connection refused
Aug 12 10:23:12 satellite6.rdu.salab.redhat.com pulp[29445]: pulp.server.db.connection:ERROR: (29445-30304) ... Waiting 32 seconds and trying again.
Aug 12 10:23:44 satellite6.rdu.salab.redhat.com pulp[29445]: pulp.server.db.connection:ERROR: (29445-30304) Could not connect to MongoDB at localhost:27017:
Aug 12 10:23:44 satellite6.rdu.salab.redhat.com pulp[29445]: pulp.server.db.connection:ERROR: (29445-30304) Cannot connect to database default :
Aug 12 10:23:44 satellite6.rdu.salab.redhat.com pulp[29445]: pulp.server.db.connection:ERROR: (29445-30304) could not connect to localhost:27017: [Errno 111] Connection refused
Aug 12 10:23:44 satellite6.rdu.salab.redhat.com pulp[29445]: pulp.server.db.connection:ERROR: (29445-30304) ... Waiting 32 seconds and trying again.
Aug 12 10:24:16 satellite6.rdu.salab.redhat.com pulp[29445]: pulp.server.db.connection:ERROR: (29445-30304) Could not connect to MongoDB at localhost:27017:
Aug 12 10:24:16 satellite6.rdu.salab.redhat.com pulp[29445]: pulp.server.db.connection:ERROR: (29445-30304) Cannot connect to database default :
Aug 12 10:24:16 satellite6.rdu.salab.redhat.com pulp[29445]: pulp.server.db.connection:ERROR: (29445-30304) could not connect to localhost:27017: [Errno 111] Connection refused
Aug 12 10:24:16 satellite6.rdu.salab.redhat.com pulp[29445]: pulp.server.db.connection:ERROR: (29445-30304) ... Waiting 32 seconds and trying again.
foreman-tasks.service - Foreman jobs daemon
   Loaded: loaded (/usr/lib/systemd/system/foreman-tasks.service; enabled)
   Active: active (running) since Wed 2015-08-12 10:14:34 EDT; 10min ago
     Docs: https://github.com/theforeman/foreman-tasks
  Process: 29590 ExecStart=/usr/bin/foreman-tasks start (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/foreman-tasks.service
           ├─29622 dynflow_executor                 
           └─29623 dynflow_executor_monitor         

Aug 12 10:13:42 satellite6.rdu.salab.redhat.com systemd[1]: Starting Foreman jobs daemon...
Aug 12 10:13:49 satellite6.rdu.salab.redhat.com foreman-tasks[29590]: Dynflow Executor: start in progress
Aug 12 10:13:49 satellite6.rdu.salab.redhat.com foreman-tasks[29590]: dynflow_executor: process with pid 29622 started.
Aug 12 10:13:49 satellite6.rdu.salab.redhat.com foreman-tasks[29590]: Waiting for the executor to be ready...
Aug 12 10:14:34 satellite6.rdu.salab.redhat.com foreman-tasks[29590]: ..............................................executor started successfully
Aug 12 10:14:34 satellite6.rdu.salab.redhat.com systemd[1]: Started Foreman jobs daemon.
Some services failed: mongod
Comment 2 Matthew Davis 2015-08-12 16:08:19 UTC 
After running sat a bit, it doesn't seem to have caused any issues. The ssl cert is still being served up.  Ignore the mongodb starting error that is being tracked with Bug 1252974 and not related to this.
Comment 4 Bryan Kearney 2016-07-26 15:25:24 UTC 
Moving 6.2 bugs out to sat-backlog.
Comment 5 Bryan Kearney 2016-07-26 15:41:47 UTC 
Moving 6.2 bugs out to sat-backlog.
Comment 7 Chris Roberts 2016-08-31 19:04:30 UTC 
Hi All,

Tested an upgrade from 6.1.8 to 6.1.9 with custom certs and it worked correctly closing this out.

- Chris Roberts