Comment 2 for bug 1592129

Revision history for this message
David Ames (thedac) wrote :

Race condition on restart_pid_check. Apache should be down but is not:

2016-06-13 18:00:45 INFO config-changed Traceback (most recent call last):
2016-06-13 18:00:45 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/config-changed", line 707, in <module>
2016-06-13 18:00:45 INFO config-changed main()
2016-06-13 18:00:45 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/config-changed", line 700, in main
2016-06-13 18:00:45 INFO config-changed hooks.execute(sys.argv)
2016-06-13 18:00:45 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/core/hookenv.py", line 717, in execute
2016-06-13 18:00:45 INFO config-changed self._hooks[hook_name]()
2016-06-13 18:00:45 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/contrib/openstack/utils.py", line 1574, in wrapped_f
2016-06-13 18:00:45 INFO config-changed restart_functions)
2016-06-13 18:00:45 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/core/host.py", line 486, in restart_on_change_helper
2016-06-13 18:00:45 INFO config-changed restart_functions[service_name](service_name)
2016-06-13 18:00:45 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 386, in restart_pid_check
2016-06-13 18:00:45 INFO config-changed check_pids_gone(ptable_string)
2016-06-13 18:00:45 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/core/decorators.py", line 42, in _retry_on_exception_inner_2
2016-06-13 18:00:45 INFO config-changed return f(*args, **kwargs)
2016-06-13 18:00:45 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 381, in check_pids_gone
2016-06-13 18:00:45 INFO config-changed assert(subprocess.call(["pgrep", svc_string]) == 1)
2016-06-13 18:00:45 INFO config-changed AssertionError

2016-06-13 18:21:09 INFO config-changed 16846
2016-06-13 18:21:09 INFO config-changed 16847
2016-06-13 18:21:09 INFO config-changed Traceback (most recent call last):
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/config-changed", line 707, in <module>
2016-06-13 18:21:09 INFO config-changed main()
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/config-changed", line 700, in main
2016-06-13 18:21:09 INFO config-changed hooks.execute(sys.argv)
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/core/hookenv.py", line 717, in execute
2016-06-13 18:21:09 INFO config-changed self._hooks[hook_name]()
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/contrib/openstack/utils.py", line 1574, in wrapped_f
2016-06-13 18:21:09 INFO config-changed restart_functions)
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/core/host.py", line 475, in restart_on_change_helper
2016-06-13 18:21:09 INFO config-changed r = lambda_f()
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/contrib/openstack/utils.py", line 1573, in <lambda>
2016-06-13 18:21:09 INFO config-changed (lambda: f(*args, **kwargs)), restart_map, stopstart,
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 1460, in inner_synchronize_ca_if_changed2
2016-06-13 18:21:09 INFO config-changed ret = f(*args, **kwargs)
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/contrib/hardening/harden.py", line 81, in _harden_inner2
2016-06-13 18:21:09 INFO config-changed return f(*args, **kwargs)
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/config-changed", line 175, in config_changed
2016-06-13 18:21:09 INFO config-changed config_changed_postupgrade()
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/contrib/openstack/utils.py", line 1574, in wrapped_f
2016-06-13 18:21:09 INFO config-changed restart_functions)
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/core/host.py", line 475, in restart_on_change_helper
2016-06-13 18:21:09 INFO config-changed r = lambda_f()
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/contrib/openstack/utils.py", line 1573, in <lambda>
2016-06-13 18:21:09 INFO config-changed (lambda: f(*args, **kwargs)), restart_map, stopstart,
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 1448, in inner_synchronize_ca_if_changed2
2016-06-13 18:21:09 INFO config-changed return f(*args, **kwargs)
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/contrib/hardening/harden.py", line 81, in _harden_inner2
2016-06-13 18:21:09 INFO config-changed return f(*args, **kwargs)
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/config-changed", line 198, in config_changed_postupgrade
2016-06-13 18:21:09 INFO config-changed restart_pid_check('apache2')
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 386, in restart_pid_check
2016-06-13 18:21:09 INFO config-changed check_pids_gone(ptable_string)
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/charmhelpers/core/decorators.py", line 42, in _retry_on_exception_inner_2
2016-06-13 18:21:09 INFO config-changed return f(*args, **kwargs)
2016-06-13 18:21:09 INFO config-changed File "/var/lib/juju/agents/unit-keystone-0/charm/hooks/keystone_utils.py", line 381, in check_pids_gone
2016-06-13 18:21:09 INFO config-changed assert(subprocess.call(["pgrep", svc_string]) == 1)
2016-06-13 18:21:09 INFO config-changed AssertionError
2016-06-13 18:21:09 INFO juju.worker.uniter.context context.go:579 handling reboot
2016-06-13 18:21:09 ERROR juju.worker.uniter.operation runhook.go:107 hook "config-changed" failed: exit status 1
2016-06-13 18:21:09 DEBUG juju.worker.uniter modes.go:31 [AGENT-STATUS] failed: clear resolved flag and run config-changed hook
2016-06-13 18:21:09 DEBUG juju.worker.leadership tracker.go:138 keystone/0 renewing lease for keystone leadership
2016-06-13 18:21:09 DEBUG juju.worker.leadership tracker.go:165 checking keystone/0 for keystone leadership
2016-06-13 18:21:09 DEBUG juju.worker.uniter modes.go:31 [AGENT-STATUS] error: hook failed: "config-changed"