From d40413fd4252dc095b6caaf26b92553ce427fee3 Mon Sep 17 00:00:00 2001 From: Norberto Arrieta Date: Wed, 20 Apr 2022 15:43:45 -0700 Subject: [PATCH] Change format of history items (#2560) * Change format of history directory * Update message; fix typo * py2 compat * py2 compat Co-authored-by: narrieta (cherry picked from commit 93a2564fd6509a93ddab1417507a61f40ba56424) --- azurelinuxagent/common/protocol/goal_state.py | 9 +++++---- azurelinuxagent/common/utils/archive.py | 19 +++++++++++-------- azurelinuxagent/common/utils/timeutil.py | 11 ++++++++++- azurelinuxagent/ga/update.py | 5 ++--- tests/protocol/test_goal_state.py | 2 +- tests/utils/test_archive.py | 10 ++++++++-- 6 files changed, 37 insertions(+), 19 deletions(-) diff --git a/azurelinuxagent/common/protocol/goal_state.py b/azurelinuxagent/common/protocol/goal_state.py index 6ec0a5ab64..da0de9a032 100644 --- a/azurelinuxagent/common/protocol/goal_state.py +++ b/azurelinuxagent/common/protocol/goal_state.py @@ -15,6 +15,7 @@ # limitations under the License. # # Requires Python 2.6+ and Openssl 1.0+ +import datetime import os import re import time @@ -31,7 +32,7 @@ from azurelinuxagent.common.protocol.extensions_goal_state import VmSettingsParseError, GoalStateSource from azurelinuxagent.common.protocol.hostplugin import VmSettingsNotSupported, VmSettingsSupportStopped from azurelinuxagent.common.protocol.restapi import Cert, CertList, RemoteAccessUser, RemoteAccessUsersList -from azurelinuxagent.common.utils import fileutil, timeutil +from azurelinuxagent.common.utils import fileutil from azurelinuxagent.common.utils.archive import GoalStateHistory from azurelinuxagent.common.utils.cryptutil import CryptUtil from azurelinuxagent.common.utils.textutil import parse_doc, findall, find, findtext, getattrib @@ -131,7 +132,7 @@ def update(self): # # Fetch the goal state from both the HGAP and the WireServer # - timestamp = timeutil.create_timestamp() + timestamp = datetime.datetime.utcnow() incarnation, xml_text, xml_doc = GoalState._fetch_goal_state(self._wire_client) goal_state_updated = incarnation != self._incarnation @@ -199,7 +200,7 @@ def update(self): def _restore_wire_server_goal_state(self, incarnation, xml_text, xml_doc, vm_settings_support_stopped_error): logger.info('The HGAP stopped supporting vmSettings; will fetched the goal state from the WireServer.') - self._history = GoalStateHistory(timeutil.create_timestamp(), incarnation) + self._history = GoalStateHistory(datetime.datetime.utcnow(), incarnation) self._history.save_goal_state(xml_text) self._extensions_goal_state = self._fetch_full_wire_server_goal_state(incarnation, xml_doc) if self._extensions_goal_state.created_on_timestamp < vm_settings_support_stopped_error.timestamp: @@ -270,7 +271,7 @@ def _fetch_vm_settings(wire_client): except VmSettingsParseError as exception: # ensure we save the vmSettings if there were parsing errors, but save them only once per ETag if not GoalStateHistory.tag_exists(exception.etag): - GoalStateHistory(timeutil.create_timestamp(), exception.etag).save_vm_settings(exception.vm_settings_text) + GoalStateHistory(datetime.datetime.utcnow(), exception.etag).save_vm_settings(exception.vm_settings_text) raise return vm_settings, vm_settings_updated diff --git a/azurelinuxagent/common/utils/archive.py b/azurelinuxagent/common/utils/archive.py index 880a23a119..6123fdb0d2 100644 --- a/azurelinuxagent/common/utils/archive.py +++ b/azurelinuxagent/common/utils/archive.py @@ -9,7 +9,7 @@ import azurelinuxagent.common.logger as logger import azurelinuxagent.common.conf as conf -from azurelinuxagent.common.utils import fileutil +from azurelinuxagent.common.utils import fileutil, timeutil # pylint: disable=W0105 @@ -58,13 +58,15 @@ # 2018-04-06T08:21:37.142697.zip # 2018-04-06T08:21:37.142697_incarnation_N # 2018-04-06T08:21:37.142697_incarnation_N.zip +# 2018-04-06T08:21:37.142697_N-M +# 2018-04-06T08:21:37.142697_N-M.zip # # Current names # -# 2018-04-06T08:21:37.142697_N-M -# 2018-04-06T08:21:37.142697_N-M.zip +# 2018-04-06T08-21-37__N-M +# 2018-04-06T08-21-37__N-M.zip # -_ARCHIVE_BASE_PATTERN = r"\d{4}\-\d{2}\-\d{2}T\d{2}:\d{2}:\d{2}\.\d+((_incarnation)?_(\d+|status)(-\d+)?)?" +_ARCHIVE_BASE_PATTERN = r"\d{4}\-\d{2}\-\d{2}T\d{2}[:-]\d{2}[:-]\d{2}(\.\d+)?((_incarnation)?_+(\d+|status)(-\d+)?)?" _ARCHIVE_PATTERNS_DIRECTORY = re.compile(r'^{0}$'.format(_ARCHIVE_BASE_PATTERN)) _ARCHIVE_PATTERNS_ZIP = re.compile(r'^{0}\.zip$'.format(_ARCHIVE_BASE_PATTERN)) @@ -163,7 +165,6 @@ def purge(self): newest ones. Also, clean up any legacy history files. """ states = self._get_archive_states() - states.sort(reverse=True) for state in states[_MAX_ARCHIVED_STATES:]: state.delete() @@ -184,7 +185,6 @@ def purge_legacy_goal_state_history(): def archive(self): states = self._get_archive_states() - states.sort(reverse=True) if len(states) > 0: # Skip the most recent goal state, since it may still be in use @@ -203,13 +203,16 @@ def _get_archive_states(self): if match is not None: states.append(StateZip(full_path, match.group(0))) + states.sort(key=lambda state: os.path.getctime(state._path), reverse=True) + return states class GoalStateHistory(object): - def __init__(self, timestamp, tag): + def __init__(self, time, tag): self._errors = False - self._root = os.path.join(conf.get_lib_dir(), ARCHIVE_DIRECTORY_NAME, "{0}_{1}".format(timestamp, tag) if tag is not None else timestamp) + timestamp = timeutil.create_history_timestamp(time) + self._root = os.path.join(conf.get_lib_dir(), ARCHIVE_DIRECTORY_NAME, "{0}__{1}".format(timestamp, tag) if tag is not None else timestamp) @staticmethod def tag_exists(tag): diff --git a/azurelinuxagent/common/utils/timeutil.py b/azurelinuxagent/common/utils/timeutil.py index c4dd755a0c..c8fa37647c 100644 --- a/azurelinuxagent/common/utils/timeutil.py +++ b/azurelinuxagent/common/utils/timeutil.py @@ -5,7 +5,7 @@ def create_timestamp(dt=None): """ - Returns a string with the given datetime iso format. If no datetime is given as parameter, it + Returns a string with the given datetime in iso format. If no datetime is given as parameter, it uses datetime.utcnow(). """ if dt is None: @@ -13,6 +13,15 @@ def create_timestamp(dt=None): return dt.isoformat() +def create_history_timestamp(dt=None): + """ + Returns a string with the given datetime formatted as a timestamp for the agent's history folder + """ + if dt is None: + dt = datetime.datetime.utcnow() + return dt.strftime('%Y-%m-%dT%H-%M-%S') + + def datetime_to_ticks(dt): """ Converts 'dt', a datetime, to the number of ticks (1 tick == 1/10000000 sec) since datetime.min (0001-01-01 00:00:00). diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py index d8b879ce42..1a453c8c05 100644 --- a/azurelinuxagent/ga/update.py +++ b/azurelinuxagent/ga/update.py @@ -54,7 +54,7 @@ from azurelinuxagent.common.utils.flexible_version import FlexibleVersion from azurelinuxagent.common.utils.networkutil import AddFirewallRules from azurelinuxagent.common.utils.shellutil import CommandError -from azurelinuxagent.common.version import AGENT_LONG_NAME, AGENT_NAME, AGENT_DIR_PATTERN, CURRENT_AGENT, \ +from azurelinuxagent.common.version import AGENT_LONG_NAME, AGENT_NAME, AGENT_DIR_PATTERN, CURRENT_AGENT, AGENT_VERSION, \ CURRENT_VERSION, DISTRO_NAME, DISTRO_VERSION, get_lis_version, \ has_logrotate, PY_VERSION_MAJOR, PY_VERSION_MINOR, PY_VERSION_MICRO, get_daemon_version from azurelinuxagent.ga.collect_logs import get_collect_logs_handler, is_log_collection_allowed @@ -324,10 +324,9 @@ def run(self, debug=False): """ try: - logger.info("{0} Version: {1}", AGENT_LONG_NAME, CURRENT_AGENT) + logger.info("{0} (Goal State Agent version {1})", AGENT_LONG_NAME, AGENT_VERSION) logger.info("OS: {0} {1}", DISTRO_NAME, DISTRO_VERSION) logger.info("Python: {0}.{1}.{2}", PY_VERSION_MAJOR, PY_VERSION_MINOR, PY_VERSION_MICRO) - logger.info(u"Agent {0} is running as the goal state agent", CURRENT_AGENT) os_info_msg = u"Distro: {dist_name}-{dist_ver}; "\ u"OSUtil: {util_name}; AgentService: {service_name}; "\ diff --git a/tests/protocol/test_goal_state.py b/tests/protocol/test_goal_state.py index 8cfa4842a8..c54a65f9f7 100644 --- a/tests/protocol/test_goal_state.py +++ b/tests/protocol/test_goal_state.py @@ -373,4 +373,4 @@ def test_it_should_report_missing_certificates(self): self.assertTrue( len(events) == 1, - "Missing certificate 59A10F50FFE2A0408D3F03FE336C8FD5716CF25C was note reported. Telemetry: {0}".format([kwargs['message'] for _, kwargs in add_event.call_args_list])) + "Missing certificate 59A10F50FFE2A0408D3F03FE336C8FD5716CF25C was not reported. Telemetry: {0}".format([kwargs['message'] for _, kwargs in add_event.call_args_list])) diff --git a/tests/utils/test_archive.py b/tests/utils/test_archive.py index 61214558c5..0c649c9e24 100644 --- a/tests/utils/test_archive.py +++ b/tests/utils/test_archive.py @@ -67,7 +67,10 @@ def test_archive_should_zip_all_but_the_latest_goal_state_in_the_history_folder( test_directories.append(directory) test_subject = StateArchiver(self.tmp_dir) - test_subject.archive() + # NOTE: StateArchiver sorts the state directories by creation time, but the test files are created too fast and the + # time resolution is too coarse, so instead we mock getctime to simply return the path of the file + with patch("azurelinuxagent.common.utils.archive.os.path.getctime", side_effect=lambda path: path): + test_subject.archive() for directory in test_directories[0:2]: zip_file = directory + ".zip" @@ -110,7 +113,10 @@ def test_archive02(self): self.assertEqual(total, len(os.listdir(self.history_dir))) test_subject = StateArchiver(self.tmp_dir) - test_subject.purge() + # NOTE: StateArchiver sorts the state directories by creation time, but the test files are created too fast and the + # time resolution is too coarse, so instead we mock getctime to simply return the path of the file + with patch("azurelinuxagent.common.utils.archive.os.path.getctime", side_effect=lambda path: path): + test_subject.purge() archived_entries = os.listdir(self.history_dir) self.assertEqual(_MAX_ARCHIVED_STATES, len(archived_entries))