Switching from service_restarted to validate_service_config_changed, the race in this bug still exists, as the process may not be started at the moment that it is checked. I think it needs a try/retry loop with a timeout threshold.
2015-08-24 16:27:24,641 test_900_restart_on_config_change DEBUG: Making config change on neutron-api...
DEBUG:amulet-logger:Making config change on neutron-api...
2015-08-24 16:27:26,794 test_900_restart_on_config_change DEBUG: Checking that service restarted: neutron-server
DEBUG:amulet-logger:Checking that service restarted: neutron-server
2015-08-24 16:27:26,796 validate_service_config_changed DEBUG: Checking neutron-server restarted since 1440433643.0
DEBUG:amulet-logger:Checking neutron-server restarted since 1440433643.0
2015-08-24 16:28:26,856 service_restarted_since DEBUG: Checking neutron-server restarted since 1440433643.0
DEBUG:amulet-logger:Checking neutron-server restarted since 1440433643.0
2015-08-24 16:29:15,571 _get_proc_start_time DEBUG: CMDout: (u'15786', 0)
DEBUG:amulet-logger:CMDout: (u'15786', 0)
2015-08-24 16:29:15,571 _get_proc_start_time DEBUG: Pid for neutron-server 15786
DEBUG:amulet-logger:Pid for neutron-server 15786
Traceback (most recent call last):
File "tests/019-basic-vivid-kilo", line 9, in <module>
deployment.run_tests()
File "/home/ubuntu/bzr/next/neutron-api/tests/charmhelpers/contrib/amulet/deployment.py", line 93, in run_tests
getattr(self, test)()
File "/home/ubuntu/bzr/next/neutron-api/tests/basic_deployment.py", line 548, in test_900_restart_on_config_change
sleep_time=sleep_time):
File "/home/ubuntu/bzr/next/neutron-api/tests/charmhelpers/contrib/amulet/utils.py", line 411, in validate_service_config_changed
retry_count=retry_count)
File "/home/ubuntu/bzr/next/neutron-api/tests/charmhelpers/contrib/amulet/utils.py", line 327, in service_restarted_since
pgrep_full)
File "/home/ubuntu/bzr/next/neutron-api/tests/charmhelpers/contrib/amulet/utils.py", line 289, in _get_proc_start_time
return self._get_dir_mtime(sentry_unit, proc_dir)
File "/home/ubuntu/bzr/next/neutron-api/tests/charmhelpers/contrib/amulet/utils.py", line 270, in _get_dir_mtime
return sentry_unit.directory_stat(directory)['mtime']
File "/usr/lib/python2.7/dist-packages/amulet/sentry.py", line 88, in directory_stat
return self._fs_data(path)
File "/usr/lib/python2.7/dist-packages/amulet/sentry.py", line 75, in _fs_data
return self._run_unit_script("filesystem_data.py {}".format(path))
File "/usr/lib/python2.7/dist-packages/amulet/sentry.py", line 126, in _run_unit_script
raise IOError(output)
IOError: Traceback (most recent call last):
File "/tmp/amulet/filesystem_data.py", line 7, in <module>
s = os.stat(sys.argv[1])
OSError: [Errno 2] No such file or directory: '/proc/15786'
ERROR subprocess encountered error code 1
Switching from service_restarted to validate_ service_ config_ changed, the race in this bug still exists, as the process may not be started at the moment that it is checked. I think it needs a try/retry loop with a timeout threshold.
2015-08-24 16:27:24,641 test_900_ restart_ on_config_ change DEBUG: Making config change on neutron-api... logger: Making config change on neutron-api... restart_ on_config_ change DEBUG: Checking that service restarted: neutron-server logger: Checking that service restarted: neutron-server service_ config_ changed DEBUG: Checking neutron-server restarted since 1440433643.0 logger: Checking neutron-server restarted since 1440433643.0 restarted_ since DEBUG: Checking neutron-server restarted since 1440433643.0 logger: Checking neutron-server restarted since 1440433643.0 start_time DEBUG: CMDout: (u'15786', 0) logger: CMDout: (u'15786', 0) start_time DEBUG: Pid for neutron-server 15786 logger: Pid for neutron-server 15786 019-basic- vivid-kilo" , line 9, in <module> run_tests( ) ubuntu/ bzr/next/ neutron- api/tests/ charmhelpers/ contrib/ amulet/ deployment. py", line 93, in run_tests ubuntu/ bzr/next/ neutron- api/tests/ basic_deploymen t.py", line 548, in test_900_ restart_ on_config_ change time=sleep_ time): ubuntu/ bzr/next/ neutron- api/tests/ charmhelpers/ contrib/ amulet/ utils.py" , line 411, in validate_ service_ config_ changed count=retry_ count) ubuntu/ bzr/next/ neutron- api/tests/ charmhelpers/ contrib/ amulet/ utils.py" , line 327, in service_ restarted_ since ubuntu/ bzr/next/ neutron- api/tests/ charmhelpers/ contrib/ amulet/ utils.py" , line 289, in _get_proc_ start_time dir_mtime( sentry_ unit, proc_dir) ubuntu/ bzr/next/ neutron- api/tests/ charmhelpers/ contrib/ amulet/ utils.py" , line 270, in _get_dir_mtime unit.directory_ stat(directory) ['mtime' ] python2. 7/dist- packages/ amulet/ sentry. py", line 88, in directory_stat python2. 7/dist- packages/ amulet/ sentry. py", line 75, in _fs_data unit_script( "filesystem_ data.py {}".format(path)) python2. 7/dist- packages/ amulet/ sentry. py", line 126, in _run_unit_script filesystem_ data.py" , line 7, in <module> sys.argv[ 1])
DEBUG:amulet-
2015-08-24 16:27:26,794 test_900_
DEBUG:amulet-
2015-08-24 16:27:26,796 validate_
DEBUG:amulet-
2015-08-24 16:28:26,856 service_
DEBUG:amulet-
2015-08-24 16:29:15,571 _get_proc_
DEBUG:amulet-
2015-08-24 16:29:15,571 _get_proc_
DEBUG:amulet-
Traceback (most recent call last):
File "tests/
deployment.
File "/home/
getattr(self, test)()
File "/home/
sleep_
File "/home/
retry_
File "/home/
pgrep_full)
File "/home/
return self._get_
File "/home/
return sentry_
File "/usr/lib/
return self._fs_data(path)
File "/usr/lib/
return self._run_
File "/usr/lib/
raise IOError(output)
IOError: Traceback (most recent call last):
File "/tmp/amulet/
s = os.stat(
OSError: [Errno 2] No such file or directory: '/proc/15786'
ERROR subprocess encountered error code 1