diff --git a/teeth_agent/standby.py b/teeth_agent/standby.py index 21462c561..53a9d0a69 100644 --- a/teeth_agent/standby.py +++ b/teeth_agent/standby.py @@ -16,15 +16,18 @@ limitations under the License. import hashlib import os -import subprocess - import requests +import structlog +import subprocess +import time from teeth_agent import base from teeth_agent import configdrive from teeth_agent import errors from teeth_agent import hardware +log = structlog.get_logger() + def _configdrive_location(): return '/tmp/configdrive' @@ -40,14 +43,17 @@ def _path_to_script(script): def _write_image(image_info, configdrive_dir, device): + starttime = time.time() image = _image_location(image_info) script = _path_to_script('shell/makefs.sh') command = ['/bin/bash', script, configdrive_dir, image, device] - + log.info('Writing image', command=' '.join(command)) exit_code = subprocess.call(command) if exit_code != 0: raise errors.ImageWriteError(exit_code, device) + totaltime = time.time() - starttime + log.info('Image written', device=device, seconds=totaltime, image=image) def _request_url(image_info, url): @@ -58,11 +64,15 @@ def _request_url(image_info, url): def _download_image(image_info): + starttime = time.time() resp = None for url in image_info['urls']: try: + log.info("Attempting to download image", url=url) resp = _request_url(image_info, url) except errors.ImageDownloadError: + failtime = time.time() - starttime + log.warning("Image download failed", url=url, seconds=failtime) continue else: break @@ -77,6 +87,9 @@ def _download_image(image_info): except Exception: raise errors.ImageDownloadError(image_info['id']) + totaltime = time.time() - starttime + log.info("Image downloaded", image=image_location, seconds=totaltime) + if not _verify_image(image_info, image_location): raise errors.ImageChecksumError(image_info['id']) @@ -87,14 +100,25 @@ def _verify_image(image_info, image_location): algo = getattr(hashlib, k, None) if algo is None: continue + log.debug('Verifying image', + image=image_location, + algo=k, + passed_hash=v) hash_ = algo(open(image_location).read()).hexdigest() if hash_ == v: return True + else: + log.warning('Image verification failed', + image=image_location, + algo=k, + imagehash=hash_, + passed_hash=v) return False def _run_image(): script = _path_to_script('shell/reboot.sh') + log.info("Rebooting system") command = ['/bin/bash', script] # this should never return if successful exit_code = subprocess.call(command) @@ -118,6 +142,7 @@ class PrepareImageCommand(base.AsyncCommandResult): device = hardware.get_manager().get_os_install_device() _download_image(image_info) + log.debug('Writing configdrive', location=location) configdrive.write_configdrive(location, metadata, files) _write_image(image_info, location, device)