Issue #492
closedpulp-manage-db exists with 0 even when it crashes
Description
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".
+ This bug was cloned from Bugzilla Bug #1132480 +