Created attachment 1441668 [details] Complete Controller upgrade log Description of problem: While upgrading Controller node, the logs did not specify that the upgrade was unsuccessful, this might need improvement. Version-Release number of selected component (if applicable): None How reproducible: Always Steps to Reproduce: 1. Start the upgrade procedure from RHOS-12 to RHOS-13 2. openstack overcloud upgrade run --roles Controller Workflow tripleo.package_update.v1.update_nodes. Execution ID: 56cc0653-fb22-4f66-8e10-4f45eacb92c8 [u'Using /tmp/ansible-mistral-actionZ77KQb/ansible.cfg as config file', u' [WARNING]: Skipping unexpected key (hostvars) in group (_meta), only "vars",', u'"children" and "hosts" are valid', u"[DEPRECATION WARNING]: The use of 'include' for tasks has been deprecated. Use ", u"'import_tasks' for static inclusions or 'include_tasks' for dynamic inclusions.", u' This feature will be removed in a future release. Deprecation warnings can be ', u'disabled by setting deprecation_warnings=False in ansible.cfg.', u'[DEPRECATION WARNING]: include is kept for backwards compatibility but usage is', u' discouraged. The module documentation details page may explain more about this', u' rationale.. This feature will be removed in a future release. Deprecation ', u'warnings can be disabled by setting deprecation_warnings=False in ansible.cfg.', u'', u'PLAY [overcloud] ***************************************************************', u'', u'TASK [Gathering Facts] *********************************************************', u'ok: [192.168.24.7]', u'', u'TASK [include] *****************************************************************', u'included: /var/lib/mistral/56cc0653-fb22-4f66-8e10-4f45eacb92c8/upgrade_steps_tasks.yaml for 192.168.24.7', u'included: /var/lib/mistral/56cc0653-fb22-4f66-8e10-4f45eacb92c8/upgrade_steps_tasks.yaml for 192.168.24.7', u'included: /var/lib/mistral/56cc0653-fb22-4f66-8e10-4f45eacb92c8/upgrade_steps_tasks.yaml for 192.168.24.7', u'included: /var/lib/mistral/56cc0653-fb22-4f66-8e10-4f45eacb92c8/upgrade_steps_tasks.yaml for 192.168.24.7', u'included: /var/lib/mistral/56cc0653-fb22-4f66-8e10-4f45eacb92c8/upgrade_steps_tasks.yaml for 192.168.24.7', u'included: /var/lib/mistral/56cc0653-fb22-4f66-8e10-4f45eacb92c8/upgrade_steps_tasks.yaml for 192.168.24.7', u'', u'TASK [include] *****************************************************************', u'included: /var/lib/mistral/56cc0653-fb22-4f66-8e10-4f45eacb92c8/Controller/upgrade_tasks.yaml for 192.168.24.7', u'', u'TASK [Check for aodh api service running under apache] *************************', u'fatal: [192.168.24.7]: FAILED! => {"changed": true, "cmd": "httpd -t -D DUMP_VHOSTS | grep -q aodh", "delta": "0:00:00.056203", "end": "2018-05-25 16:09:14.362046", "msg": "non-zero return code", "rc": 1, "start": "2018-05-25 16:09:14.305843", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}', u'...ignoring', u'', u'TASK [Check if httpd is running] ***********************************************', u'fatal: [192.168.24.7]: FAILED! => {"changed": true, "cmd": ["systemctl", "is-active", "--quiet", "httpd"], "delta": "0:00:00.011728", "end": "2018-05-25 16:09:16.680176", "msg": "non-zero return code", "rc": 3, "start": "2018-05-25 16:09:16.668448", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}', u'...ignoring', u'', u'TASK [Check if aodh_evaluator is deployed] *************************************', u'fatal: [192.168.24.7]: FAILED! => {"changed": true, "cmd": ["systemctl", "is-enabled", "--quiet", "openstack-aodh-evaluator"], "delta": "0:00:00.014672", "end": "2018-05-25 16:09:19.032107", "msg": "non-zero return code", "rc": 1, "start": "2018-05-25 16:09:19.017435", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}', u'...ignoring', u'', u'TASK [Check if aodh_listener is deployed] **************************************', u'fatal: [192.168.24.7]: FAILED! => {"changed": true, "cmd": ["systemctl", "is-enabled", "--quiet", "openstack-aodh-listener"], "delta": "0:00:00.013498", "end": "2018-05-25 16:09:21.359029", "msg": "non-zero return code", "rc": 1, "start": "2018-05-25 16:09:21.345531", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}', u'...ignoring', u'', u'TASK [Check if aodh_notifier is deployed] **************************************', u'fatal: [192.168.24.7]: FAILED! => {"changed": true, "cmd": ["systemctl", "is-enabled", "--quiet", "openstack-aodh-notifier"], "delta": "0:00:00.014066", "end": "2018-05-25 16:09:23.749082", "msg": "non-zero return code", "rc": 1, "start": "2018-05-25 16:09:23.735016", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}', u'...ignoring', u'', u'TASK [Check if ceilometer_agent_central is deployed] ***************************', u'fatal: [192.168.24.7]: FAILED! => {"changed": true, "cmd": ["systemctl", "is-enabled", "--quiet", "openstack-ceilometer-central"], "delta": "0:00:00.012788", "end": "2018-05-25 16:09:26.189478", "msg": "non-zero return code", "rc": 1, "start": "2018-05-25 16:09:26.176690", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}', u'...ignoring', u'', u'TASK [Check if ceilometer_agent_notification is deployed] **********************', u'fatal: [192.168.24.7]: FAILED! => {"changed": true, "cmd": ["systemctl", "is-enabled", "--quiet", "openstack-ceilometer-notification"], "delta": "0:00:00.015527", "end": "2018-05-25 16:09:28.602843", "msg": "non-zero return code", "rc": 1, "start": "2018-05-25 16:09:28.587316", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}', u'...ignoring', u'', u'TASK [Check is cinder_api is deployed] *****************************************', u'fatal: [192.168.24.7]: FAILED! => {"changed": true, "cmd": ["systemctl", "is-enabled", "openstack-cinder-api"], "delta": "0:00:00.013182", "end": "2018-05-25 16:09:30.986835", "msg": "non-zero return code", "rc": 1, "start": "2018-05-25 16:09:30.973653", "stderr": "", "stderr_lines": [], "stdout": "disabled", "stdout_lines": ["disabled"]}', u'...ignoring', u'', u'TASK [Check if cinder_scheduler is deployed] ***********************************', u'fatal: [192.168.24.7]: FAILED! => {"changed": true, "cmd": ["systemctl", "is-enabled", "openstack-cinder-scheduler"], "delta": "0:00:00.014102", "end": "2018-05-25 16:09:33.284501", "msg": "non-zero return code", "rc": 1, "start": "2018-05-25 16:09:33.270399", "stderr": "", "stderr_lines": [], "stdout": "disabled", "stdout_lines": ["disabled"]}'] [u'...ignoring', u'', u'TASK [Get docker Cinder-Volume image] ******************************************', u'ok: [192.168.24.7] => {"ansible_facts": {"cinder_volume_docker_image_latest": "registry.access.redhat.com/rhosp13/openstack-cinder-volume:pcmklatest"}, "changed": false}', u'', u'TASK [Check for Cinder-Volume Kolla configuration] *****************************', u'fatal: [192.168.24.7]: FAILED! => {"changed": false, "cmd": ["grep", "^volume_driver[ \\\\t]*=", "/var/lib/config-data/puppet-generated/cinder/etc/cinder/cinder.conf"], "delta": "0:00:00.003739", "end": "2018-05-25 16:09:35.676191", "msg": "non-zero return code", "rc": 2, "start": "2018-05-25 16:09:35.672452", "stderr": "grep: /var/lib/config-data/puppet-generated/cinder/etc/cinder/cinder.conf: No such file or directory", "stderr_lines": ["grep: /var/lib/config-data/puppet-generated/cinder/etc/cinder/cinder.conf: No such file or directory"], "stdout": "", "stdout_lines": []}', u'...ignoring', u'', u'TASK [Check if Cinder-Volume is already containerized] *************************', u'ok: [192.168.24.7] => {"ansible_facts": {"cinder_volume_containerized": false}, "changed": false}', u'', u'TASK [Check openstack-cinder-volume cluster resource status] *******************', u'fatal: [192.168.24.7]: FAILED! => {"changed": false, "error": "Error: unable to find resource \'openstack-cinder-volume\'\\n", "msg": "Failed, to set the resource openstack-cinder-volume to the state show", "output": "", "rc": 1}', u'...ignoring', u'', u'TASK [Check if glance_api is deployed] *****************************************', u'fatal: [192.168.24.7]: FAILED! => {"changed": true, "cmd": ["systemctl", "is-enabled", "--quiet", "openstack-glance-api"], "delta": "0:00:00.013784", "end": "2018-05-25 16:09:41.475210", "msg": "non-zero return code", "rc": 1, "start": "2018-05-25 16:09:41.461426", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}', u'...ignoring', u'', u'TASK [Check if gnocchi_api is deployed] ****************************************', u'fatal: [192.168.24.7]: FAILED! => {"changed": true, "cmd": ["systemctl", "is-enabled", "--quiet", "openstack-gnocchi-api"], "delta": "0:00:00.013891", "end": "2018-05-25 16:09:43.799806", "msg": "non-zero return code", "rc": 1, "start": "2018-05-25 16:09:43.785915", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}', u'...ignoring', u'', u'TASK [Check for gnocchi_api running under apache] ******************************', u'fatal: [192.168.24.7]: FAILED! => {"changed": true, "cmd": "httpd -t -D DUMP_VHOSTS | grep -q gnocchi", "delta": "0:00:00.056522", "end": "2018-05-25 16:09:46.141007", "msg": "non-zero return code", "rc": 1, "start": "2018-05-25 16:09:46.084485", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}', u'...ignoring', u'', u'TASK [Check if httpd service is running] ***************************************', u'fatal: [192.168.24.7]: FAILED! => {"changed": true, "cmd": ["systemctl", "is-active", "--quiet", "httpd"], "delta": "0:00:00.010274", "end": "2018-05-25 16:09:48.491925", "msg": "non-zero return code", "rc": 3, "start": "2018-05-25 16:09:48.481651", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}', u'...ignoring', Actual results: Controller upgrade finished without specifying any error Expected results: StdError: Displayed if upgrade is unsuccessful Additional info:
Created attachment 1441669 [details] mistral-paackage_update.log
Seems to be a known issue, just to confirm from Jose Luis and ask for more logs.
This issue was reported already in https://bugzilla.redhat.com/show_bug.cgi?id=1573496 , the size of the log obtained from the ansible playbooks executed is way too long to be handled by mistral, and it simply crops it. This patch should handle the issue: https://review.openstack.org/#/c/566884/3 which was already cherry-picked downstream and being included in openstack-tripleo-common-8.6.1-14.el7ost. Anyway, you can see the whole full output inside /var/log/mistral/package_update.log And the ansible task which failed during the upgrade process was this one: INFO:__main__:Writing out command to execute", "+ chown -R mysql:mysql /var/lib/mysql", "+ timeout 60 sh -c \'while ! mysqladmin ping --silent; do sleep 1; done\'", "+ mysqld_safe --user=mysql --wsrep-provider=none --skip-networking --wsrep-on=off", "/usr/bin/mysqld_safe: line 728: ulimit: -1: invalid option", "ulimit: usage: ulimit [-SHacdefilmnpqrstuvx] [limit]", "+ mysql_upgrade"], "stdout": "180525 16:41:26 mysqld_safe Logging to \'/var/log/mariadb/mariadb.log\'.\\n180525 16:41:26 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql\\n180525 16:41:26 mysqld_safe WSREP: Running position recovery with --log_error=\'/var/lib/mysql/wsrep_recovery.ZlEvxe\' --pid-file=\'/var/lib/mysql/controller-0-recover.pid\'\\n180525 16:41:28 mysqld_safe WSREP: Recovered position bb8b69e3-5ecb-11e8-a4f7-1e48510494c2:115648\\nmysqld is alive\\nThis installation of MySQL is already upgraded to 5.5.42-MariaDB, use --force if you still need to run mysql_upgrade", "stdout_lines": ["180525 16:41:26 mysqld_safe Logging to \'/var/log/mariadb/mariadb.log\'.", "180525 16:41:26 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql", "180525 16:41:26 mysqld_safe WSREP: Running position recovery with --log_error=\'/var/lib/mysql/wsrep_recovery.ZlEvxe\' --pid-file=\'/var/lib/mysql/controller-0-recover.pid\'", "180525 16:41:28 mysqld_safe WSREP: Recovered position bb8b69e3-5ecb-11e8-a4f7-1e48510494c2:115648", "mysqld is alive", "This installation of MySQL is already upgraded to 5.5.42-MariaDB, use --force if you still need to run mysql_upgrade"
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:2331