Bug 1132480

Summary: pulp-manage-db exists with 0 even when it crashes
Product: [Retired] Pulp Reporter: Ivan Necas <inecas>
Component: rel-engAssignee: Chris Duryee <cduryee>
Status: CLOSED UPSTREAM QA Contact: Preethi Thomas <pthomas>
Severity: unspecified Docs Contact:
Priority: medium    
Version: 2.4.0CC: bkearney, bmbouter, cduryee, cristi.falcas, jhutar, katello-bugs, katello-qa-list, mmccune, pthomas
Target Milestone: ---Keywords: Triaged
Target Release: 2.6.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: 1132475 Environment:
Last Closed: 2015-02-28 22:15:57 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:
Bug Depends On:    
Bug Blocks: 1132475    

Description Ivan Necas 2014-08-21 12:27:08 UTC 
How to reproduce:

1. service qpidd stop
2. pulp-manage-db (provided it was not run before
3. pulp-manage-db exists with 0 (but a stack-trace in /var/log/messages

This breaks katello-installer, as it has no clue that the migration failed.

+++ This bug was initially created as a clone of Bug #1132475 +++

Description of problem:
Installer do not reports failure in pulp-manage-db.


Version-Release number of selected component (if applicable):
Satellite-6.0.4-RHEL-6-20140820.2


How reproducible:
1 occurrences out of 2 attempts


Steps to Reproduce:
1. Attempt to install Satellite 6 on RHEL5 with:
   # katello-installer --foreman-admin-email 'root@localhost' \
       --foreman-admin-username 'admin' --foreman-admin-password 'changeme'


Actual results:
[...]
[31m /Stage[main]/Foreman::Database/Foreman::Rake[db:seed]/Exec[foreman-rake-db:seed]: Failed to call refresh: /usr/sbin/foreman-rake db:seed returned 1 instead of one of [0]
[0m[31m /Stage[main]/Foreman::Database/Foreman::Rake[db:seed]/Exec[foreman-rake-db:seed]: /usr/sbin/foreman-rake db:seed returned 1 instead of one of [0]
[0mNotice: /Stage[main]/Foreman::Database/Foreman::Ra: 478/479, 99%, 0.0/s, elapsed: 00:10:55
Debug: Executing '/sbin/chkconfig foreman-tasks'  : 478/479, 99%, 0.0/s, elapsed: 00:11:53
Notice: /Stage[main]/Foreman::Service/Exec[restart: 478/479, 99%, 0.0/s, elapsed: 00:11:55
Debug: /Stage[main]/Certs::Foreman/Exec[foreman_ce: 478/479, 99%, 0.0/s, elapsed: 00:12:57
Notice: /Stage[main]/Certs::Foreman/Exec[foreman_c: 478/479, 99%, 0.0/s, elapsed: 00:13:56
E, [2014-08-20T21:09:16.481482 #13443] ERROR -- : : 478/479, 99%, 0.0/s, elapsed: 00:14:58
[31m /Stage[main]/Foreman_proxy::Register/Foreman_smartproxy[cisco-c210-01.rhts.eng.bos.redhat.com]: Could not evaluate: 500 Internal Server Error
[0m[32mDone                                              [0m: 479/479, 100%, 0.0/s, elapsed: 00:15:03
[32mDone                                              [0m: 479/479, 100%, 0.0/s, elapsed: 00:15:03
  [1m[31mSomething went wrong![0m Check the log for ERROR-level output
  The full log is at [1m[36m/var/log/katello-installer/katello-installer.log[0m


Expected results:
As inecas investigated, this is caused by failing pulp-manage-db which was not noticed by installer:

# cat /var/log/messages
[...]
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:INFO: Applying pulp.server.db.migrations version 9
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL: Applying migration pulp.server.db.migrations.0009_qpid_queues failed.
Aug 20 21:02:43 <host> qpidd[8670]: 2014-08-20 21:02:43 [System] error Error reading socket: Success(0)
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL: [Errno 336265218] _ssl.c:341: error:140B0002:SSL routines:SSL_CTX_use_PrivateKey_file:system lib
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL: Traceback (most recent call last):
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL:   File "/usr/lib/python2.6/site-packages/pulp/server/db/manage.py", line 86, in migrate_database
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL:     update_current_version=not options.test)
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL:   File "/usr/lib/python2.6/site-packages/pulp/server/db/migrate/models.py", line 161, in apply_migration
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL:     migration.migrate()
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL:   File "/usr/lib/python2.6/site-packages/pulp/server/db/migrations/0009_qpid_queues.py", line 67, in migrate
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL:     connection.attach()
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL:   File "<string>", line 6, in attach
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL:   File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 286, in attach
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL:     if not self._ewait(lambda: self._transport_connected and not self._unlinked(), timeout=timeout):
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL:   File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 219, in _ewait
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL:     self.check_error()
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL:   File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 212, in check_error
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL:     raise e
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL: ConnectError: [Errno 336265218] _ssl.c:341: error:140B0002:SSL routines:SSL_CTX_use_PrivateKey_file:system lib
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:CRITICAL: 
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:INFO: Applying pulp_puppet.plugins.migrations version 1
Aug 20 21:02:43 <host> pulp: pulp:INFO: Migrated puppet modules to include checksum
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:INFO: Migration to pulp_puppet.plugins.migrations version 1 complete.
Aug 20 21:02:43 <host> pulp: pulp.server.db.manage:INFO: Applying pulp_puppet.plugins.migrations version 2
[...]
Aug 20 21:03:28 <host> pulp: pulp.server.agent.direct.services:INFO: AMQP broker configured: {<fqdn>:5671}:|transport=S
SL|host=<fqdn>|port=5671|cacert=/etc/pki/katello/certs/katello-default-ca.crt|clientcert=/etc/pki/katello/qpid_client_striped.
crt|userid=None|password=None|vhost=None
Aug 20 21:03:28 <host> pulp: pulp.server.db.migrate.models:ERROR: pulp.server.db.migrations hasn't been updated to the latest available migration.
Aug 20 21:03:28 <host> pulp: pulp.server.webservices.application:CRITICAL: *************************************************************
Aug 20 21:03:28 <host> pulp: pulp.server.webservices.application:CRITICAL: The Pulp server failed to start due to the following reasons:
Aug 20 21:03:28 <host> pulp: pulp.server.webservices.application:ERROR:   The database has not been migrated to the current version. Run pulp-manage-db and restart the application.
Aug 20 21:03:28 <host> pulp: pulp.server.webservices.application:ERROR: Traceback (most recent call last):
Aug 20 21:03:28 <host> pulp: pulp.server.webservices.application:ERROR:   File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 147, in wsgi_application
Aug 20 21:03:28 <host> pulp: pulp.server.webservices.application:ERROR:     _initialize_pulp()
Aug 20 21:03:28 <host> pulp: pulp.server.webservices.application:ERROR:   File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 102, in _initialize_pulp
Aug 20 21:03:28 <host> pulp: pulp.server.webservices.application:ERROR:     migration_models.check_package_versions()
Aug 20 21:03:28 <host> pulp: pulp.server.webservices.application:ERROR:   File "/usr/lib/python2.6/site-packages/pulp/server/db/migrate/models.py", line 291, in check_package_versions
Aug 20 21:03:28 <host> pulp: pulp.server.webservices.application:ERROR:     raise Exception(error_message)
Aug 20 21:03:28 <host> pulp: pulp.server.webservices.application:ERROR: InitializationException: The database has not been migrated to the current version. Run pulp-manage-db and restart the application.
Aug 20 21:03:28 <host> pulp: pulp.server.webservices.application:CRITICAL: *************************************************************
Aug 20 21:03:29 <host> qpidd[8670]: 2014-08-20 21:03:29 [System] error Error reading socket: Success(0)
Aug 20 21:03:29 <host> pulp: celery.worker.consumer:ERROR: consumer: Cannot connect to qpid://guest@<fqdn>:5671//: [Errno 336265218] _ssl.c:341: error:140B0002:SSL routines:SSL_CTX_use_PrivateKey_file:system lib.
[...]


Additional info:
Bugzilla about this failing was reported as bug 1132471. This bug is about "installer did not noticed this kind of error".
Comment 1 Chris Duryee 2014-09-08 19:47:47 UTC 
The fix for #1093760 also fixes this BZ. Marking as ON_QA.
Comment 2 Preethi Thomas 2014-09-10 12:39:01 UTC 
verified

[root@pulp-24-server ~]# rpm -qa pulp-server
pulp-server-2.4.1-0.7.beta.el6.noarch
[root@pulp-24-server ~]# 

[root@pulp-24-server ~]#  service qpidd stop
Stopping Qpid AMQP daemon:                                 [  OK  ]

[root@pulp-24-server ~]# sudo -u apache pulp-manage-db
Loading content types.
/usr/lib/python2.6/site-packages/pulp/server/db/connection.py:133: DeprecationWarning: The safe parameter is deprecated. Please use write concern options instead.
  return method(*args, **kwargs)
Content types loaded.
Ensuring the admin role and user are in place.
Admin role and user are in place.
Beginning database migrations.
Applying pulp.server.db.migrations version 1
Migration to pulp.server.db.migrations version 1 complete.
Applying pulp.server.db.migrations version 2
Migration to pulp.server.db.migrations version 2 complete.
Applying pulp.server.db.migrations version 3
Migration to pulp.server.db.migrations version 3 complete.
Applying pulp.server.db.migrations version 4
Migration to pulp.server.db.migrations version 4 complete.
Applying pulp.server.db.migrations version 5
Migration to pulp.server.db.migrations version 5 complete.
Applying pulp.server.db.migrations version 6
Migration to pulp.server.db.migrations version 6 complete.
Applying pulp.server.db.migrations version 7
Migration to pulp.server.db.migrations version 7 complete.
Applying pulp.server.db.migrations version 8
Migration to pulp.server.db.migrations version 8 complete.
Applying pulp.server.db.migrations version 9
Applying migration pulp.server.db.migrations.0009_qpid_queues failed.

Halting migrations due to a migration failure.  See log for details.
[Errno 111] Connection refused
Comment 3 Brian Bouterse 2015-02-28 22:15:57 UTC 
Moved to https://pulp.plan.io/issues/492