diff --git a/tests_e2e/GuestAgentDcrTestExtension/GuestAgentDcrTest.py b/tests_e2e/GuestAgentDcrTestExtension/GuestAgentDcrTest.py new file mode 100644 index 000000000..df6c1b517 --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/GuestAgentDcrTest.py @@ -0,0 +1,123 @@ +#!/usr/bin/env python +# pylint: disable=all +from __future__ import print_function + +from Utils.WAAgentUtil import waagent +import Utils.HandlerUtil as Util +import sys +import re +import traceback +import os +import datetime + +ExtensionShortName = "GADcrTestExt" +OperationFileName = "operations-{0}.log" + + +def install(): + operation = "install" + status = "success" + msg = "Installed successfully" + + hutil = parse_context(operation) + hutil.log("Start to install.") + hutil.log(msg) + hutil.do_exit(0, operation, status, '0', msg) + + +def enable(): + # Global Variables definition + operation = "enable" + status = "success" + msg = "Enabled successfully." + + # Operations.append(operation) + hutil = parse_context(operation) + hutil.log("Start to enable.") + public_settings = hutil.get_public_settings() + name = public_settings.get("name") + if name: + name = "Name: {0}".format(name) + hutil.log(name) + msg = "{0} {1}".format(msg, name) + print(name) + else: + hutil.error("The name in public settings is not provided.") + # msg = msg % ','.join(Operations) + hutil.log(msg) + hutil.do_exit(0, operation, status, '0', msg) + + +def disable(): + operation = "disable" + status = "success" + msg = "Disabled successfully." + + # Operations.append(operation) + hutil = parse_context(operation) + hutil.log("Start to disable.") + # msg % ','.join(Operations) + hutil.log(msg) + hutil.do_exit(0, operation, status, '0', msg) + + +def uninstall(): + operation = "uninstall" + status = "success" + msg = "Uninstalled successfully." + + # Operations.append(operation) + hutil = parse_context(operation) + hutil.log("Start to uninstall.") + # msg % ','.join(Operations) + hutil.log(msg) + hutil.do_exit(0, operation, status, '0', msg) + + +def update(): + operation = "update" + status = "success" + msg = "Updated successfully." + + # Operations.append(operation) + hutil = parse_context(operation) + hutil.log("Start to update.") + # msg % ','.join(Operations) + hutil.log(msg) + hutil.do_exit(0, operation, status, '0', msg) + + +def parse_context(operation): + hutil = Util.HandlerUtility(waagent.Log, waagent.Error) + hutil.do_parse_context(operation) + op_log = os.path.join(hutil.get_log_dir(), OperationFileName.format(hutil.get_extension_version())) + with open(op_log, 'a+') as oplog_handler: + oplog_handler.write("Date:{0}; Operation:{1}; SeqNo:{2}\n" + .format(datetime.datetime.utcnow().strftime("%Y-%m-%dT%H:%M:%SZ"), + operation, hutil.get_seq_no())) + return hutil + + +def main(): + waagent.LoggerInit('/var/log/waagent.log', '/dev/stdout') + waagent.Log("%s started to handle." % (ExtensionShortName)) + + try: + for a in sys.argv[1:]: + if re.match("^([-/]*)(disable)", a): + disable() + elif re.match("^([-/]*)(uninstall)", a): + uninstall() + elif re.match("^([-/]*)(install)", a): + install() + elif re.match("^([-/]*)(enable)", a): + enable() + elif re.match("^([-/]*)(update)", a): + update() + except Exception as e: + err_msg = "Failed with error: {0}, {1}".format(e, traceback.format_exc()) + waagent.Error(err_msg) + + +if __name__ == '__main__': + main() diff --git a/tests_e2e/GuestAgentDcrTestExtension/HandlerManifest.json b/tests_e2e/GuestAgentDcrTestExtension/HandlerManifest.json new file mode 100644 index 000000000..398aab864 --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/HandlerManifest.json @@ -0,0 +1,14 @@ +[{ + "name": "GuestAgentDcrTestExtension", + "version": 1.0, + "handlerManifest": { + "installCommand": "./GuestAgentDcrTest.py --install", + "uninstallCommand": "./GuestAgentDcrTest.py --uninstall", + "updateCommand": "./GuestAgentDcrTest.py --update", + "enableCommand": "./GuestAgentDcrTest.py --enable", + "disableCommand": "./GuestAgentDcrTest.py --disable", + "updateMode": "UpdateWithoutInstall", + "rebootAfterInstall": false, + "reportHeartbeat": false + } +}] diff --git a/tests_e2e/GuestAgentDcrTestExtension/Makefile b/tests_e2e/GuestAgentDcrTestExtension/Makefile new file mode 100644 index 000000000..d766ef63a --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/Makefile @@ -0,0 +1,8 @@ +default: build + +build: + $(eval NAME = $(shell grep -Pom1 "(?<=)[^<]+" manifest.xml)) + $(eval VERSION = $(shell grep -Pom1 "(?<=)[^<]+" manifest.xml)) + + @echo "Building '$(NAME)-$(VERSION).zip' ..." + zip -r9 $(NAME)-$(VERSION).zip * diff --git a/tests_e2e/GuestAgentDcrTestExtension/Utils/HandlerUtil.py b/tests_e2e/GuestAgentDcrTestExtension/Utils/HandlerUtil.py new file mode 100755 index 000000000..56343f2e5 --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/Utils/HandlerUtil.py @@ -0,0 +1,387 @@ +# +# Handler library for Linux IaaS +# +# Copyright 2014 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# pylint: disable=all + +""" +JSON def: +HandlerEnvironment.json +[{ + "name": "ExampleHandlerLinux", + "seqNo": "seqNo", + "version": "1.0", + "handlerEnvironment": { + "logFolder": "", + "configFolder": "", + "statusFolder": "", + "heartbeatFile": "", + + } +}] + +Example ./config/1.settings +"{"runtimeSettings":[{"handlerSettings":{"protectedSettingsCertThumbprint":"1BE9A13AA1321C7C515EF109746998BAB6D86FD1","protectedSettings": +"MIIByAYJKoZIhvcNAQcDoIIBuTCCAbUCAQAxggFxMIIBbQIBADBVMEExPzA9BgoJkiaJk/IsZAEZFi9XaW5kb3dzIEF6dXJlIFNlcnZpY2UgTWFuYWdlbWVudCBmb3IgR+nhc6VHQTQpCiiV2zANBgkqhkiG9w0BAQEFAASCAQCKr09QKMGhwYe+O4/a8td+vpB4eTR+BQso84cV5KCAnD6iUIMcSYTrn9aveY6v6ykRLEw8GRKfri2d6tvVDggUrBqDwIgzejGTlCstcMJItWa8Je8gHZVSDfoN80AEOTws9Fp+wNXAbSuMJNb8EnpkpvigAWU2v6pGLEFvSKC0MCjDTkjpjqciGMcbe/r85RG3Zo21HLl0xNOpjDs/qqikc/ri43Y76E/Xv1vBSHEGMFprPy/Hwo3PqZCnulcbVzNnaXN3qi/kxV897xGMPPC3IrO7Nc++AT9qRLFI0841JLcLTlnoVG1okPzK9w6ttksDQmKBSHt3mfYV+skqs+EOMDsGCSqGSIb3DQEHATAUBggqhkiG9w0DBwQITgu0Nu3iFPuAGD6/QzKdtrnCI5425fIUy7LtpXJGmpWDUA==","publicSettings":{"port":"3000"}}}]}" + + +Example HeartBeat +{ +"version": 1.0, + "heartbeat" : { + "status": "ready", + "code": 0, + "Message": "Sample Handler running. Waiting for a new configuration from user." + } +} +Example Status Report: +[{"version":"1.0","timestampUTC":"2014-05-29T04:20:13Z","status":{"name":"Chef Extension Handler","operation":"chef-client-run","status":"success","code":0,"formattedMessage":{"lang":"en-US","message":"Chef-client run success"}}}] + +""" + +import os +import os.path +import sys +import imp +import base64 +import json +import time +import re + +from xml.etree import ElementTree +from os.path import join +from Utils.WAAgentUtil import waagent +from waagent import LoggerInit + +DateTimeFormat = "%Y-%m-%dT%H:%M:%SZ" + +MANIFEST_XML = "manifest.xml" + + +class HandlerContext: + def __init__(self, name): + self._name = name + self._version = '0.0' + self._config_dir = None + self._log_dir = None + self._log_file = None + self._status_dir = None + self._heartbeat_file = None + self._seq_no = -1 + self._status_file = None + self._settings_file = None + self._config = None + return + + +class HandlerUtility: + def __init__(self, log, error, s_name=None, l_name=None, extension_version=None, logFileName='extension.log', + console_logger=None, file_logger=None): + self._log = log + self._log_to_con = console_logger + self._log_to_file = file_logger + self._error = error + self._logFileName = logFileName + if s_name is None or l_name is None or extension_version is None: + (l_name, s_name, extension_version) = self._get_extension_info() + + self._short_name = s_name + self._extension_version = extension_version + self._log_prefix = '[%s-%s] ' % (l_name, extension_version) + + def get_extension_version(self): + return self._extension_version + + def _get_log_prefix(self): + return self._log_prefix + + def _get_extension_info(self): + if os.path.isfile(MANIFEST_XML): + return self._get_extension_info_manifest() + + ext_dir = os.path.basename(os.getcwd()) + (long_name, version) = ext_dir.split('-') + short_name = long_name.split('.')[-1] + + return long_name, short_name, version + + def _get_extension_info_manifest(self): + with open(MANIFEST_XML) as fh: + doc = ElementTree.parse(fh) + namespace = doc.find('{http://schemas.microsoft.com/windowsazure}ProviderNameSpace').text + short_name = doc.find('{http://schemas.microsoft.com/windowsazure}Type').text + version = doc.find('{http://schemas.microsoft.com/windowsazure}Version').text + + long_name = "%s.%s" % (namespace, short_name) + return (long_name, short_name, version) + + def _get_current_seq_no(self, config_folder): + seq_no = -1 + cur_seq_no = -1 + freshest_time = None + for subdir, dirs, files in os.walk(config_folder): + for file in files: + try: + cur_seq_no = int(os.path.basename(file).split('.')[0]) + if (freshest_time == None): + freshest_time = os.path.getmtime(join(config_folder, file)) + seq_no = cur_seq_no + else: + current_file_m_time = os.path.getmtime(join(config_folder, file)) + if (current_file_m_time > freshest_time): + freshest_time = current_file_m_time + seq_no = cur_seq_no + except ValueError: + continue + return seq_no + + def log(self, message): + self._log(self._get_log_prefix() + message) + + def log_to_console(self, message): + if self._log_to_con is not None: + self._log_to_con(self._get_log_prefix() + message) + else: + self.error("Unable to log to console, console log method not set") + + def log_to_file(self, message): + if self._log_to_file is not None: + self._log_to_file(self._get_log_prefix() + message) + else: + self.error("Unable to log to file, file log method not set") + + def error(self, message): + self._error(self._get_log_prefix() + message) + + @staticmethod + def redact_protected_settings(content): + redacted_tmp = re.sub('"protectedSettings":\s*"[^"]+=="', '"protectedSettings": "*** REDACTED ***"', content) + redacted = re.sub('"protectedSettingsCertThumbprint":\s*"[^"]+"', '"protectedSettingsCertThumbprint": "*** REDACTED ***"', redacted_tmp) + return redacted + + def _parse_config(self, ctxt): + config = None + try: + config = json.loads(ctxt) + except: + self.error('JSON exception decoding ' + HandlerUtility.redact_protected_settings(ctxt)) + + if config is None: + self.error("JSON error processing settings file:" + HandlerUtility.redact_protected_settings(ctxt)) + else: + handlerSettings = config['runtimeSettings'][0]['handlerSettings'] + if 'protectedSettings' in handlerSettings and \ + 'protectedSettingsCertThumbprint' in handlerSettings and \ + handlerSettings['protectedSettings'] is not None and \ + handlerSettings["protectedSettingsCertThumbprint"] is not None: + protectedSettings = handlerSettings['protectedSettings'] + thumb = handlerSettings['protectedSettingsCertThumbprint'] + cert = waagent.LibDir + '/' + thumb + '.crt' + pkey = waagent.LibDir + '/' + thumb + '.prv' + unencodedSettings = base64.standard_b64decode(protectedSettings) + openSSLcmd = "openssl smime -inform DER -decrypt -recip {0} -inkey {1}" + cleartxt = waagent.RunSendStdin(openSSLcmd.format(cert, pkey), unencodedSettings)[1] + if cleartxt is None: + self.error("OpenSSL decode error using thumbprint " + thumb) + self.do_exit(1, "Enable", 'error', '1', 'Failed to decrypt protectedSettings') + jctxt = '' + try: + jctxt = json.loads(cleartxt) + except: + self.error('JSON exception decoding ' + HandlerUtility.redact_protected_settings(cleartxt)) + handlerSettings['protectedSettings']=jctxt + self.log('Config decoded correctly.') + return config + + def do_parse_context(self, operation): + _context = self.try_parse_context() + if not _context: + self.do_exit(1, operation, 'error', '1', operation + ' Failed') + return _context + + def try_parse_context(self): + self._context = HandlerContext(self._short_name) + handler_env = None + config = None + ctxt = None + code = 0 + # get the HandlerEnvironment.json. According to the extension handler spec, it is always in the ./ directory + self.log('cwd is ' + os.path.realpath(os.path.curdir)) + handler_env_file = './HandlerEnvironment.json' + if not os.path.isfile(handler_env_file): + self.error("Unable to locate " + handler_env_file) + return None + ctxt = waagent.GetFileContents(handler_env_file) + if ctxt == None: + self.error("Unable to read " + handler_env_file) + try: + handler_env = json.loads(ctxt) + except: + pass + if handler_env == None: + self.log("JSON error processing " + handler_env_file) + return None + if type(handler_env) == list: + handler_env = handler_env[0] + + self._context._name = handler_env['name'] + self._context._version = str(handler_env['version']) + self._context._config_dir = handler_env['handlerEnvironment']['configFolder'] + self._context._log_dir = handler_env['handlerEnvironment']['logFolder'] + + self._context._log_file = os.path.join(handler_env['handlerEnvironment']['logFolder'], self._logFileName) + self._change_log_file() + self._context._status_dir = handler_env['handlerEnvironment']['statusFolder'] + self._context._heartbeat_file = handler_env['handlerEnvironment']['heartbeatFile'] + self._context._seq_no = self._get_current_seq_no(self._context._config_dir) + if self._context._seq_no < 0: + self.error("Unable to locate a .settings file!") + return None + self._context._seq_no = str(self._context._seq_no) + self.log('sequence number is ' + self._context._seq_no) + self._context._status_file = os.path.join(self._context._status_dir, self._context._seq_no + '.status') + self._context._settings_file = os.path.join(self._context._config_dir, self._context._seq_no + '.settings') + self.log("setting file path is" + self._context._settings_file) + ctxt = None + ctxt = waagent.GetFileContents(self._context._settings_file) + if ctxt == None: + error_msg = 'Unable to read ' + self._context._settings_file + '. ' + self.error(error_msg) + return None + + self.log("JSON config: " + HandlerUtility.redact_protected_settings(ctxt)) + self._context._config = self._parse_config(ctxt) + return self._context + + def _change_log_file(self): + self.log("Change log file to " + self._context._log_file) + LoggerInit(self._context._log_file, '/dev/stdout') + self._log = waagent.Log + self._error = waagent.Error + + def set_verbose_log(self, verbose): + if (verbose == "1" or verbose == 1): + self.log("Enable verbose log") + LoggerInit(self._context._log_file, '/dev/stdout', verbose=True) + else: + self.log("Disable verbose log") + LoggerInit(self._context._log_file, '/dev/stdout', verbose=False) + + def is_seq_smaller(self): + return int(self._context._seq_no) <= self._get_most_recent_seq() + + def save_seq(self): + self._set_most_recent_seq(self._context._seq_no) + self.log("set most recent sequence number to " + self._context._seq_no) + + def exit_if_enabled(self, remove_protected_settings=False): + self.exit_if_seq_smaller(remove_protected_settings) + + def exit_if_seq_smaller(self, remove_protected_settings): + if(self.is_seq_smaller()): + self.log("Current sequence number, " + self._context._seq_no + ", is not greater than the sequnce number of the most recent executed configuration. Exiting...") + sys.exit(0) + self.save_seq() + + if remove_protected_settings: + self.scrub_settings_file() + + def _get_most_recent_seq(self): + if (os.path.isfile('mrseq')): + seq = waagent.GetFileContents('mrseq') + if (seq): + return int(seq) + + return -1 + + def is_current_config_seq_greater_inused(self): + return int(self._context._seq_no) > self._get_most_recent_seq() + + def get_inused_config_seq(self): + return self._get_most_recent_seq() + + def set_inused_config_seq(self, seq): + self._set_most_recent_seq(seq) + + def _set_most_recent_seq(self, seq): + waagent.SetFileContents('mrseq', str(seq)) + + def do_status_report(self, operation, status, status_code, message): + self.log("{0},{1},{2},{3}".format(operation, status, status_code, message)) + tstamp = time.strftime(DateTimeFormat, time.gmtime()) + stat = [{ + "version": self._context._version, + "timestampUTC": tstamp, + "status": { + "name": self._context._name, + "operation": operation, + "status": status, + "code": status_code, + "formattedMessage": { + "lang": "en-US", + "message": message + } + } + }] + stat_rept = json.dumps(stat) + if self._context._status_file: + tmp = "%s.tmp" % (self._context._status_file) + with open(tmp, 'w+') as f: + f.write(stat_rept) + os.rename(tmp, self._context._status_file) + + def do_heartbeat_report(self, heartbeat_file, status, code, message): + # heartbeat + health_report = '[{"version":"1.0","heartbeat":{"status":"' + status + '","code":"' + code + '","Message":"' + message + '"}}]' + if waagent.SetFileContents(heartbeat_file, health_report) == None: + self.error('Unable to wite heartbeat info to ' + heartbeat_file) + + def do_exit(self, exit_code, operation, status, code, message): + try: + self.do_status_report(operation, status, code, message) + except Exception as e: + self.log("Can't update status: " + str(e)) + sys.exit(exit_code) + + def get_name(self): + return self._context._name + + def get_seq_no(self): + return self._context._seq_no + + def get_log_dir(self): + return self._context._log_dir + + def get_handler_settings(self): + if (self._context._config != None): + return self._context._config['runtimeSettings'][0]['handlerSettings'] + return None + + def get_protected_settings(self): + if (self._context._config != None): + return self.get_handler_settings().get('protectedSettings') + return None + + def get_public_settings(self): + handlerSettings = self.get_handler_settings() + if (handlerSettings != None): + return self.get_handler_settings().get('publicSettings') + return None + + def scrub_settings_file(self): + content = waagent.GetFileContents(self._context._settings_file) + redacted = HandlerUtility.redact_protected_settings(content) + + waagent.SetFileContents(self._context._settings_file, redacted) \ No newline at end of file diff --git a/tests_e2e/GuestAgentDcrTestExtension/Utils/LogUtil.py b/tests_e2e/GuestAgentDcrTestExtension/Utils/LogUtil.py new file mode 100755 index 000000000..71c200cec --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/Utils/LogUtil.py @@ -0,0 +1,50 @@ +# Logging utilities +# +# Copyright 2014 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# pylint: disable=all + +import os +import os.path +import string +import sys + +OutputSize = 4 * 1024 + + +def tail(log_file, output_size = OutputSize): + pos = min(output_size, os.path.getsize(log_file)) + with open(log_file, "r") as log: + log.seek(0, os.SEEK_END) + log.seek(log.tell() - pos, os.SEEK_SET) + buf = log.read(output_size) + buf = filter(lambda x: x in string.printable, buf) + + # encoding works different for between interpreter version, we are keeping separate implementation to ensure + # backward compatibility + if sys.version_info[0] == 3: + buf = ''.join(list(buf)).encode('ascii', 'ignore').decode("ascii", "ignore") + elif sys.version_info[0] == 2: + buf = buf.decode("ascii", "ignore") + + return buf + + +def get_formatted_log(summary, stdout, stderr): + msg_format = ("{0}\n" + "---stdout---\n" + "{1}\n" + "---errout---\n" + "{2}\n") + return msg_format.format(summary, stdout, stderr) \ No newline at end of file diff --git a/tests_e2e/GuestAgentDcrTestExtension/Utils/ScriptUtil.py b/tests_e2e/GuestAgentDcrTestExtension/Utils/ScriptUtil.py new file mode 100755 index 000000000..3987cc04c --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/Utils/ScriptUtil.py @@ -0,0 +1,140 @@ +# Script utilities +# +# Copyright 2014 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# pylint: disable=all + +import os +import os.path +import time +import subprocess +import traceback +import string +import shlex +import sys + +from Utils import LogUtil +from Utils.WAAgentUtil import waagent + +DefaultStdoutFile = "stdout" +DefaultErroutFile = "errout" + + +def run_command(hutil, args, cwd, operation, extension_short_name, version, exit_after_run=True, interval=30, + std_out_file_name=DefaultStdoutFile, std_err_file_name=DefaultErroutFile): + std_out_file = os.path.join(cwd, std_out_file_name) + err_out_file = os.path.join(cwd, std_err_file_name) + std_out = None + err_out = None + try: + std_out = open(std_out_file, "w") + err_out = open(err_out_file, "w") + start_time = time.time() + child = subprocess.Popen(args, + cwd=cwd, + stdout=std_out, + stderr=err_out) + time.sleep(1) + while child.poll() is None: + msg = "Command is running..." + msg_with_cmd_output = LogUtil.get_formatted_log(msg, LogUtil.tail(std_out_file), LogUtil.tail(err_out_file)) + msg_without_cmd_output = msg + " Stdout/Stderr omitted from output." + + hutil.log_to_file(msg_with_cmd_output) + hutil.log_to_console(msg_without_cmd_output) + hutil.do_status_report(operation, 'transitioning', '0', msg_without_cmd_output) + time.sleep(interval) + + exit_code = child.returncode + if child.returncode and child.returncode != 0: + msg = "Command returned an error." + msg_with_cmd_output = LogUtil.get_formatted_log(msg, LogUtil.tail(std_out_file), LogUtil.tail(err_out_file)) + msg_without_cmd_output = msg + " Stdout/Stderr omitted from output." + + hutil.error(msg_without_cmd_output) + waagent.AddExtensionEvent(name=extension_short_name, + op=operation, + isSuccess=False, + version=version, + message="(01302)" + msg_without_cmd_output) + else: + msg = "Command is finished." + msg_with_cmd_output = LogUtil.get_formatted_log(msg, LogUtil.tail(std_out_file), LogUtil.tail(err_out_file)) + msg_without_cmd_output = msg + " Stdout/Stderr omitted from output." + + hutil.log_to_file(msg_with_cmd_output) + hutil.log_to_console(msg_without_cmd_output) + waagent.AddExtensionEvent(name=extension_short_name, + op=operation, + isSuccess=True, + version=version, + message="(01302)" + msg_without_cmd_output) + end_time = time.time() + waagent.AddExtensionEvent(name=extension_short_name, + op=operation, + isSuccess=True, + version=version, + message=("(01304)Command execution time: " + "{0}s").format(str(end_time - start_time))) + + log_or_exit(hutil, exit_after_run, exit_code, operation, msg_with_cmd_output) + except Exception as e: + error_msg = ("Failed to launch command with error: {0}," + "stacktrace: {1}").format(e, traceback.format_exc()) + hutil.error(error_msg) + waagent.AddExtensionEvent(name=extension_short_name, + op=operation, + isSuccess=False, + version=version, + message="(01101)" + error_msg) + exit_code = 1 + msg = 'Launch command failed: {0}'.format(e) + + log_or_exit(hutil, exit_after_run, exit_code, operation, msg) + finally: + if std_out: + std_out.close() + if err_out: + err_out.close() + return exit_code + + +# do_exit calls sys.exit which raises an exception so we do not call it from the finally block +def log_or_exit(hutil, exit_after_run, exit_code, operation, msg): + status = 'success' if exit_code == 0 else 'failed' + if exit_after_run: + hutil.do_exit(exit_code, operation, status, str(exit_code), msg) + else: + hutil.do_status_report(operation, status, str(exit_code), msg) + + +def parse_args(cmd): + cmd = filter(lambda x: x in string.printable, cmd) + + # encoding works different for between interpreter version, we are keeping separate implementation to ensure + # backward compatibility + if sys.version_info[0] == 3: + cmd = ''.join(list(cmd)).encode('ascii', 'ignore').decode("ascii", "ignore") + elif sys.version_info[0] == 2: + cmd = cmd.decode("ascii", "ignore") + + args = shlex.split(cmd) + # From python 2.6 to python 2.7.2, shlex.split output UCS-4 result like + # '\x00\x00a'. Temp workaround is to replace \x00 + for idx, val in enumerate(args): + if '\x00' in args[idx]: + args[idx] = args[idx].replace('\x00', '') + return args + + diff --git a/tests_e2e/GuestAgentDcrTestExtension/Utils/WAAgentUtil.py b/tests_e2e/GuestAgentDcrTestExtension/Utils/WAAgentUtil.py new file mode 100755 index 000000000..41ef3bb11 --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/Utils/WAAgentUtil.py @@ -0,0 +1,140 @@ +# Wrapper module for waagent +# +# waagent is not written as a module. This wrapper module is created +# to use the waagent code as a module. +# +# Copyright 2014 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# pylint: disable=all + +import imp +import os +import os.path + + +# +# The following code will search and load waagent code and expose +# it as a submodule of current module +# +def searchWAAgent(): + # if the extension ships waagent in its package to default to this version first + pkg_agent_path = os.path.join(os.getcwd(), 'waagent') + if os.path.isfile(pkg_agent_path): + return pkg_agent_path + + agentPath = '/usr/sbin/waagent' + if os.path.isfile(agentPath): + return agentPath + + user_paths = os.environ['PYTHONPATH'].split(os.pathsep) + for user_path in user_paths: + agentPath = os.path.join(user_path, 'waagent') + if os.path.isfile(agentPath): + return agentPath + return None + + +waagent = None +agentPath = searchWAAgent() +if agentPath: + waagent = imp.load_source('waagent', agentPath) +else: + raise Exception("Can't load waagent.") + +if not hasattr(waagent, "AddExtensionEvent"): + """ + If AddExtensionEvent is not defined, provide a dummy impl. + """ + + + def _AddExtensionEvent(*args, **kwargs): + pass + + + waagent.AddExtensionEvent = _AddExtensionEvent + +if not hasattr(waagent, "WALAEventOperation"): + class _WALAEventOperation: + HeartBeat = "HeartBeat" + Provision = "Provision" + Install = "Install" + UnIsntall = "UnInstall" + Disable = "Disable" + Enable = "Enable" + Download = "Download" + Upgrade = "Upgrade" + Update = "Update" + + + waagent.WALAEventOperation = _WALAEventOperation + +# Better deal with the silly waagent typo, in anticipation of a proper fix of the typo later on waagent +if not hasattr(waagent.WALAEventOperation, 'Uninstall'): + if hasattr(waagent.WALAEventOperation, 'UnIsntall'): + waagent.WALAEventOperation.Uninstall = waagent.WALAEventOperation.UnIsntall + else: # This shouldn't happen, but just in case... + waagent.WALAEventOperation.Uninstall = 'Uninstall' + + +def GetWaagentHttpProxyConfigString(): + """ + Get http_proxy and https_proxy from waagent config. + Username and password is not supported now. + This code is adopted from /usr/sbin/waagent + """ + host = None + port = None + try: + waagent.Config = waagent.ConfigurationProvider( + None) # Use default waagent conf file (most likely /etc/waagent.conf) + + host = waagent.Config.get("HttpProxy.Host") + port = waagent.Config.get("HttpProxy.Port") + except Exception as e: + # waagent.ConfigurationProvider(None) will throw an exception on an old waagent + # Has to silently swallow because logging is not yet available here + # and we don't want to bring that in here. Also if the call fails, then there's + # no proxy config in waagent.conf anyway, so it's safe to silently swallow. + pass + + result = '' + if host is not None: + result = "http://" + host + if port is not None: + result += ":" + port + + return result + + +waagent.HttpProxyConfigString = GetWaagentHttpProxyConfigString() + +# end: waagent http proxy config stuff + +__ExtensionName__ = None + + +def InitExtensionEventLog(name): + global __ExtensionName__ + __ExtensionName__ = name + + +def AddExtensionEvent(name=__ExtensionName__, + op=waagent.WALAEventOperation.Enable, + isSuccess=False, + message=None): + if name is not None: + waagent.AddExtensionEvent(name=name, + op=op, + isSuccess=isSuccess, + message=message) diff --git a/tests_e2e/GuestAgentDcrTestExtension/Utils/test/MockUtil.py b/tests_e2e/GuestAgentDcrTestExtension/Utils/test/MockUtil.py new file mode 100755 index 000000000..8c8c24271 --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/Utils/test/MockUtil.py @@ -0,0 +1,44 @@ +#!/usr/bin/env python +# +# Sample Extension +# +# Copyright 2014 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# pylint: disable=all + +# TODO: These tests were copied as reference - they are not currently running + +class MockUtil(): + def __init__(self, test): + self.test = test + + def get_log_dir(self): + return "/tmp" + + def log(self, msg): + print(msg) + + def error(self, msg): + print(msg) + + def get_seq_no(self): + return "0" + + def do_status_report(self, operation, status, status_code, message): + self.test.assertNotEqual(None, message) + self.last = "do_status_report" + + def do_exit(self,exit_code,operation,status,code,message): + self.test.assertNotEqual(None, message) + self.last = "do_exit" diff --git a/tests_e2e/GuestAgentDcrTestExtension/Utils/test/env.py b/tests_e2e/GuestAgentDcrTestExtension/Utils/test/env.py new file mode 100755 index 000000000..fa447fcc6 --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/Utils/test/env.py @@ -0,0 +1,24 @@ +#!/usr/bin/env python +# +# Sample Extension +# +# Copyright 2014 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +import sys +import os + +#append installer directory to sys.path +root = os.path.dirname(os.path.dirname(os.path.abspath(__file__))) +sys.path.append(root) diff --git a/tests_e2e/GuestAgentDcrTestExtension/Utils/test/mock.sh b/tests_e2e/GuestAgentDcrTestExtension/Utils/test/mock.sh new file mode 100755 index 000000000..da2fec539 --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/Utils/test/mock.sh @@ -0,0 +1,23 @@ +#!/bin/bash +# +# Copyright 2014 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +echo "Start..." +sleep 0.1 +echo "Running" +>&2 echo "Warning" +sleep 0.1 +echo "Finished" +exit $1 diff --git a/tests_e2e/GuestAgentDcrTestExtension/Utils/test/test_logutil.py b/tests_e2e/GuestAgentDcrTestExtension/Utils/test/test_logutil.py new file mode 100755 index 000000000..163ad7a91 --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/Utils/test/test_logutil.py @@ -0,0 +1,35 @@ +#!/usr/bin/env python +# +# Copyright 2014 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# pylint: disable=all + +# TODO: These tests were copied as reference - they are not currently running + +import unittest +import LogUtil as lu + + +class TestLogUtil(unittest.TestCase): + def test_tail(self): + with open("/tmp/testtail", "w+") as F: + F.write(u"abcdefghijklmnopqrstu\u6211vwxyz".encode("utf-8")) + tail = lu.tail("/tmp/testtail", 2) + self.assertEquals("yz", tail) + + tail = lu.tail("/tmp/testtail") + self.assertEquals("abcdefghijklmnopqrstuvwxyz", tail) + +if __name__ == '__main__': + unittest.main() diff --git a/tests_e2e/GuestAgentDcrTestExtension/Utils/test/test_null_protected_settings.py b/tests_e2e/GuestAgentDcrTestExtension/Utils/test/test_null_protected_settings.py new file mode 100755 index 000000000..bbb6dbbd6 --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/Utils/test/test_null_protected_settings.py @@ -0,0 +1,48 @@ +#!/usr/bin/env python +# +# Sample Extension +# +# Copyright 2014 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# pylint: disable=all + +# TODO: These tests were copied as reference - they are not currently running + +import unittest +import HandlerUtil as Util + +def mock_log(*args, **kwargs): + pass + +class TestNullProtectedSettings(unittest.TestCase): + def test_null_protected_settings(self): + hutil = Util.HandlerUtility(mock_log, mock_log, "UnitTest", "HandlerUtil.UnitTest", "0.0.1") + config = hutil._parse_config(Settings) + handlerSettings = config['runtimeSettings'][0]['handlerSettings'] + self.assertEquals(handlerSettings["protectedSettings"], None) + +Settings="""\ +{ + "runtimeSettings":[{ + "handlerSettings":{ + "protectedSettingsCertThumbprint":null, + "protectedSettings":null, + "publicSettings":{} + } + }] +} +""" + +if __name__ == '__main__': + unittest.main() diff --git a/tests_e2e/GuestAgentDcrTestExtension/Utils/test/test_redacted_settings.py b/tests_e2e/GuestAgentDcrTestExtension/Utils/test/test_redacted_settings.py new file mode 100644 index 000000000..d3ed63ba7 --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/Utils/test/test_redacted_settings.py @@ -0,0 +1,47 @@ +#!/usr/bin/env python +# +# Tests for redacted settings +# +# Copyright 2014 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# pylint: disable=all + +# TODO: These tests were copied as reference - they are not currently running + +import unittest +import Utils.HandlerUtil as Util + + +class TestRedactedProtectedSettings(unittest.TestCase): + + def test_redacted_protected_settings(self): + redacted = Util.HandlerUtility.redact_protected_settings(settings_original) + self.assertIn('"protectedSettings": "*** REDACTED ***"', redacted) + self.assertIn('"protectedSettingsCertThumbprint": "*** REDACTED ***"', redacted) + + +settings_original = """\ +{ + "runtimeSettings": [{ + "handlerSettings": { + "protectedSettingsCertThumbprint": "9310D2O49D7216D4A1CEDCE9D8A7CE5DBD7FB7BF", + "protectedSettings": "MIIC4AYJKoZIhvcNAQcWoIIB0TCDEc0CAQAxggFpMIIBZQIBADBNMDkxNzA1BgoJkiaJk/IsZAEZFidXaW5kb3dzIEF6dXJlIENSUCBDZXJ0aWZpY2F0ZSBHZW5lcmF0b3ICEB8f7DyzHLGjSDLnEWd4YeAwDQYJKoZIhvcNAQEBBQAEggEAiZj2gQtT4MpdTaEH8rUVFB/8Ucc8OxGFWu8VKbIdoHLKp1WcDb7Vlzv6fHLBIccgXGuR1XHTvtlD4QiKpSet341tPPug/R5ZtLSRz1pqtXZdrFcuuSxOa6ib/+la5ukdygcVwkEnmNSQaiipPKyqPH2JsuhmGCdXFiKwCSTrgGE6GyCBtaK9KOf48V/tYXHnDGrS9q5a1gRF5KVI2B26UYSO7V7pXjzYCd/Sp9yGj7Rw3Kqf9Lpix/sPuqWjV6e2XFlD3YxaHSeHVnLI/Bkz2E6Ri8yfPYus52r/mECXPL2YXqY9dGyrlKKIaD9AuzMyvvy1A74a9VBq7zxQQ4adEzBbBgkqhkiG9w0BBwEwFAYIKoZIhvcNAwcECDyEf4mRrmWJgDhW4j2nRNTJU4yXxocQm/PhAr39Um7n0pgI2Cn28AabYtsHWjKqr8Al9LX6bKm8cnmnLjqTntphCw==", + "publicSettings": {} + } + }] +} +""" + +if __name__ == '__main__': + unittest.main() diff --git a/tests_e2e/GuestAgentDcrTestExtension/Utils/test/test_scriptutil.py b/tests_e2e/GuestAgentDcrTestExtension/Utils/test/test_scriptutil.py new file mode 100755 index 000000000..4f84cefb2 --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/Utils/test/test_scriptutil.py @@ -0,0 +1,55 @@ +#!/usr/bin/env python +# +# Copyright 2014 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# pylint: disable=all + +# TODO: These tests were copied as reference - they are not currently running + +import os +import os.path +import env +import ScriptUtil as su +import unittest +from MockUtil import MockUtil + +class TestScriptUtil(unittest.TestCase): + def test_parse_args(self): + print(__file__) + cmd = u'sh foo.bar.sh -af bar --foo=bar | more \u6211' + args = su.parse_args(cmd.encode('utf-8')) + self.assertNotEquals(None, args) + self.assertNotEquals(0, len(args)) + print(args) + + def test_run_command(self): + hutil = MockUtil(self) + test_script = "mock.sh" + os.chdir(os.path.join(env.root, "test")) + exit_code = su.run_command(hutil, ["sh", test_script, "0"], os.getcwd(), 'RunScript-0', 'TestExtension', '1.0', True, 0.1) + self.assertEquals(0, exit_code) + self.assertEquals("do_exit", hutil.last) + exit_code = su.run_command(hutil, ["sh", test_script, "75"], os.getcwd(), 'RunScript-1', 'TestExtension', '1.0', False, 0.1) + self.assertEquals(75, exit_code) + self.assertEquals("do_status_report", hutil.last) + + def test_log_or_exit(self): + hutil = MockUtil(self) + su.log_or_exit(hutil, True, 0, 'LogOrExit-0', 'Message1') + self.assertEquals("do_exit", hutil.last) + su.log_or_exit(hutil, False, 0, 'LogOrExit-1', 'Message2') + self.assertEquals("do_status_report", hutil.last) + +if __name__ == '__main__': + unittest.main() diff --git a/tests_e2e/GuestAgentDcrTestExtension/manifest.xml b/tests_e2e/GuestAgentDcrTestExtension/manifest.xml new file mode 100644 index 000000000..a4b0c755f --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/manifest.xml @@ -0,0 +1,17 @@ + + + Microsoft.Azure.TestExtensions + GuestAgentDcrTest + 1.4.1 + + VmRole + + Microsoft Azure Guest Agent test Extension for testing Linux Virtual Machines in DCR + true + https://github.com/larohra/GuestAgentDcrTestExtension/blob/master/LICENSE + http://www.microsoft.com/privacystatement/en-us/OnlineServices/Default.aspx + https://github.com/larohra/GuestAgentDcrTestExtension + true + Linux + Microsoft + diff --git a/tests_e2e/GuestAgentDcrTestExtension/references b/tests_e2e/GuestAgentDcrTestExtension/references new file mode 100644 index 000000000..442153ec8 --- /dev/null +++ b/tests_e2e/GuestAgentDcrTestExtension/references @@ -0,0 +1,2 @@ +# TODO: Investigate the use of this file +Utils/ diff --git a/tests_e2e/orchestrator/runbook.yml b/tests_e2e/orchestrator/runbook.yml index a1370bd6e..ca9f8dde4 100644 --- a/tests_e2e/orchestrator/runbook.yml +++ b/tests_e2e/orchestrator/runbook.yml @@ -51,7 +51,7 @@ variable: # # The test suites to execute - name: test_suites - value: "agent_bvt, no_outbound_connections, extensions_disabled, agent_not_provisioned, fips" + value: "agent_bvt, no_outbound_connections, extensions_disabled, agent_not_provisioned, fips, agent_ext_workflow" - name: cloud value: "AzureCloud" is_case_visible: true diff --git a/tests_e2e/test_suites/agent_ext_workflow.yml b/tests_e2e/test_suites/agent_ext_workflow.yml new file mode 100644 index 000000000..1e965317b --- /dev/null +++ b/tests_e2e/test_suites/agent_ext_workflow.yml @@ -0,0 +1,11 @@ +name: "AgentExtWorkflow" +tests: + - "agent_ext_workflow/extension_workflow.py" +images: + - "centos_79" + - "suse_12" + - "rhel_79" + - "ubuntu_1604" + - "ubuntu_1804" +# This test suite uses the DCR Test Extension, which is only published in South Central US +locations: "AzureCloud:southcentralus" diff --git a/tests_e2e/tests/agent_ext_workflow/README.md b/tests_e2e/tests/agent_ext_workflow/README.md new file mode 100644 index 000000000..a8d59fc15 --- /dev/null +++ b/tests_e2e/tests/agent_ext_workflow/README.md @@ -0,0 +1,45 @@ +# Agent Extension Worflow Test + +This scenario tests if the correct extension workflow sequence is being executed from the agent. + +### GuestAgentDcrTestExtension + +This is a test extension that exists for the sole purpose of testing the extension workflow of agent. This is currently deployed to SCUS only. + +All the extension does is prints the settings['name'] out to stdout. It is run everytime enable is called. + +Another important feature of this extension is that it maintains a `operations-.log` **for every operation that the agent executes on that extension**. We use this to confirm that the agent executed the correct sequence of operations. + +Sample operations-.log file snippet - +```text +Date:2019-07-30T21:54:03Z; Operation:install; SeqNo:0 +Date:2019-07-30T21:54:05Z; Operation:enable; SeqNo:0 +Date:2019-07-30T21:54:37Z; Operation:enable; SeqNo:1 +Date:2019-07-30T21:55:20Z; Operation:disable; SeqNo:1 +Date:2019-07-30T21:55:22Z; Operation:uninstall; SeqNo:1 +``` +The setting for this extension is of the format - +```json +{ + "name": String +} +``` +##### Repo link +https://github.com/larohra/GuestAgentDcrTestExtension + +##### Available Versions: +- 1.1.5 - Version with Basic functionalities as mentioned above +- 1.2.0 - Same functionalities as above with `"updateMode": "UpdateWithInstall"` in HandlerManifest.json to test update case +- 1.3.0 - Same functionalities as above with `"updateMode": "UpdateWithoutInstall"` in HandlerManifest.json to test update case + +### Test Sequence + +- Install the test extension on the VM +- Assert the extension status by checking if our Enable string matches the status message (We receive the status message by using the Azure SDK by polling for the VM instance view and parsing the extension status message) + +The Enable string of our test is of the following format (this is set in the `Settings` object when we call enable from the tests ) - +```text +[ExtensionName]-[Version], Count: [Enable-count] +``` +- Match the operation sequence as per the test and make sure they are in the correct chronological order +- Restart the agent and verify if the correct operation sequence is followed \ No newline at end of file diff --git a/tests_e2e/tests/agent_ext_workflow/extension_workflow.py b/tests_e2e/tests/agent_ext_workflow/extension_workflow.py new file mode 100644 index 000000000..8c08ea7d3 --- /dev/null +++ b/tests_e2e/tests/agent_ext_workflow/extension_workflow.py @@ -0,0 +1,447 @@ +#!/usr/bin/env python3 + +# Microsoft Azure Linux Agent +# +# Copyright 2018 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +from azure.mgmt.compute.models import VirtualMachineExtensionInstanceView +from assertpy import assert_that, soft_assertions +from datetime import datetime +from random import choice +import uuid + +from tests_e2e.tests.lib.agent_test import AgentTest +from tests_e2e.tests.lib.agent_test_context import AgentTestContext +from tests_e2e.tests.lib.identifiers import VmExtensionIds, VmExtensionIdentifier +from tests_e2e.tests.lib.logging import log +from tests_e2e.tests.lib.ssh_client import SshClient +from tests_e2e.tests.lib.virtual_machine_extension_client import VirtualMachineExtensionClient + + +class ExtensionWorkflow(AgentTest): + """ + This scenario tests if the correct extension workflow sequence is being executed from the agent. It installs the + GuestAgentDcrTestExtension on the test VM and makes requests to install, enable, update, and delete the extension + from the VM. The GuestAgentDcrTestExtension maintains a local `operations-.log` for every operation that + the agent executes on that extension. We use this to confirm that the agent executed the correct sequence of + operations. + + Sample operations-.log file snippet - + Date:2019-07-30T21:54:03Z; Operation:install; SeqNo:0 + Date:2019-07-30T21:54:05Z; Operation:enable; SeqNo:0 + Date:2019-07-30T21:54:37Z; Operation:enable; SeqNo:1 + Date:2019-07-30T21:55:20Z; Operation:disable; SeqNo:1 + Date:2019-07-30T21:55:22Z; Operation:uninstall; SeqNo:1 + + The setting for the GuestAgentDcrTestExtension is of the format - + { + "name": String + } + + Test sequence - + - Install the test extension on the VM + - Assert the extension status by checking if our Enable string matches the status message + - The Enable string of our test is of the following format (this is set in the `Settings` object when we c + all enable from the tests): [ExtensionName]-[Version], Count: [Enable-count] + - Match the operation sequence as per the test and make sure they are in the correct chronological order + - Restart the agent and verify if the correct operation sequence is followed + """ + def __init__(self, context: AgentTestContext): + super().__init__(context) + self._ssh_client = SshClient( + ip_address=self._context.vm_ip_address, + username=self._context.username, + private_key_file=self._context.private_key_file) + + # This class represents the GuestAgentDcrTestExtension running on the test VM + class GuestAgentDcrTestExtension: + COUNT_KEY_NAME = "Count" + NAME_KEY_NAME = "name" + DATA_KEY_NAME = "data" + + def __init__(self, extension: VirtualMachineExtensionClient, ssh_client: SshClient, version: str): + self.extension = extension + self.name = "GuestAgentDcrTestExt" + self.version = version + self.expected_message = "" + self.enable_count = 0 + self.ssh_client = ssh_client + self.data = None + + def modify_ext_settings_and_enable(self, data=None): + self.enable_count += 1 + + # Settings follows the following format: [ExtensionName]-[Version], Count: [Enable-count] + setting_name = "%s-%s, %s: %s" % (self.name, self.version, self.COUNT_KEY_NAME, self.enable_count) + # We include data in the settings to test the special characters case. The settings with data follows the + # following format: [ExtensionName]-[Version], Count: [Enable-count], data: [data] + if data is not None: + setting_name = "{0}, {1}: {2}".format(setting_name, self.DATA_KEY_NAME, data) + + self.expected_message = setting_name + settings = {self.NAME_KEY_NAME: setting_name.encode('utf-8')} + + log.info("") + log.info("Add or update extension {0} , version {1}, settings {2}".format(self.extension, self.version, + settings)) + self.extension.enable(settings=settings, auto_upgrade_minor_version=False) + + def assert_instance_view(self, data=None): + log.info("") + + # If data is not None, we want to assert the instance view has the expected data + if data is None: + log.info("Assert instance view has expected message for test extension. Expected version: {0}, " + "Expected message: {1}".format(self.version, self.expected_message)) + self.extension.assert_instance_view(expected_version=self.version, + expected_message=self.expected_message) + else: + self.data = data + log.info("Assert instance view has expected data for test extension. Expected version: {0}, " + "Expected data: {1}".format(self.version, data)) + self.extension.assert_instance_view(expected_version=self.version, + assert_function=self.assert_data_in_instance_view) + + def assert_data_in_instance_view(self, instance_view: VirtualMachineExtensionInstanceView): + log.info("Asserting extension status ...") + status_message = instance_view.statuses[0].message + log.info("Status message: %s" % status_message) + + with soft_assertions(): + expected_ext_version = "%s-%s" % (self.name, self.version) + assert_that(expected_ext_version in status_message).described_as( + f"Specific extension version name should be in the InstanceView message ({expected_ext_version})").is_true() + + expected_count = "%s: %s" % (self.COUNT_KEY_NAME, self.enable_count) + assert_that(expected_count in status_message).described_as( + f"Expected count should be in the InstanceView message ({expected_count})").is_true() + + if self.data is not None: + expected_data = "{0}: {1}".format(self.DATA_KEY_NAME, self.data) + assert_that(expected_data in status_message).described_as( + f"Expected data should be in the InstanceView message ({expected_data})").is_true() + + def execute_assertion_script(self, file_name, args): + log.info("") + log.info("Running {0} remotely with arguments {1}".format(file_name, args)) + result = self.ssh_client.run_command(f"{file_name} {args}", use_sudo=True) + log.info(result) + log.info("Assertion completed successfully") + + def assert_scenario(self, file_name: str, command_args: str, assert_status: bool = False, restart_agent: list = None, data: str = None): + # Assert the extension status by checking if our Enable string matches the status message in the instance + # view + if assert_status: + self.assert_instance_view(data=data) + + # Remotely execute the assertion script + self.execute_assertion_script(file_name, command_args) + + # Restart the agent and test the status again if enabled (by checking the operations.log file in the VM) + # Restarting agent should just run enable again and rerun the same settings + if restart_agent is not None: + log.info("") + log.info("Restarting the agent...") + output = self.ssh_client.run_command("agent-service restart", use_sudo=True) + log.info("Restart completed:\n%s", output) + + for args in restart_agent: + self.execute_assertion_script('agent_ext_workflow-assert_operation_sequence.py', args) + + if assert_status: + self.assert_instance_view() + + def update_ext_version(self, extension: VirtualMachineExtensionClient, version: str): + self.extension = extension + self.version = version + + def run(self): + is_arm64: bool = self._ssh_client.get_architecture() == "aarch64" + + if is_arm64: + log.info("Skipping test case for %s, since it has not been published on ARM64", VmExtensionIds.GuestAgentDcrTestExtension) + else: + log.info("") + log.info("*******Verifying the extension install scenario*******") + + # Record the time we start the test + start_time = datetime.utcnow().strftime("%Y-%m-%dT%H:%M:%SZ") + + # Create DcrTestExtension with version 1.1.5 + dcr_test_ext_id_1_1 = VmExtensionIdentifier( + VmExtensionIds.GuestAgentDcrTestExtension.publisher, + VmExtensionIds.GuestAgentDcrTestExtension.type, + "1.1" + ) + dcr_test_ext_client = VirtualMachineExtensionClient( + self._context.vm, + dcr_test_ext_id_1_1, + resource_name="GuestAgentDcrTestExt" + ) + dcr_ext = ExtensionWorkflow.GuestAgentDcrTestExtension( + extension=dcr_test_ext_client, + ssh_client=self._ssh_client, + version="1.1.5" + ) + + # Install test extension on the VM + dcr_ext.modify_ext_settings_and_enable() + + # command_args are the args we pass to the agent_ext_workflow-assert_operation_sequence.py file to verify + # the operation sequence for the current test + command_args = f"--start-time {start_time} " \ + f"normal_ops_sequence " \ + f"--version {dcr_ext.version} " \ + f"--ops install enable" + # restart_agentcommand_args are the args we pass to the agent_ext_workflow-assert_operation_sequence.py file + # to verify the operation sequence after restarting the agent. Restarting agent should just run enable again + # and rerun the same settings + restart_agent_command_args = [f"--start-time {start_time} " + f"normal_ops_sequence " + f"--version {dcr_ext.version} " + f"--ops install enable enable"] + + # Assert the operation sequence to confirm the agent executed the operations in the correct chronological + # order + dcr_ext.assert_scenario( + file_name='agent_ext_workflow-assert_operation_sequence.py', + command_args=command_args, + assert_status=True, + restart_agent=restart_agent_command_args + ) + + log.info("") + log.info("*******Verifying the extension enable scenario*******") + + # Record the time we start the test + start_time = datetime.utcnow().strftime("%Y-%m-%dT%H:%M:%SZ") + + # Enable test extension on the VM + dcr_ext.modify_ext_settings_and_enable() + + command_args = f"--start-time {start_time} " \ + f"normal_ops_sequence " \ + f"--version {dcr_ext.version} " \ + f"--ops enable" + restart_agent_command_args = [f"--start-time {start_time} " + f"normal_ops_sequence " + f"--version {dcr_ext.version} " + f"--ops enable enable"] + + dcr_ext.assert_scenario( + file_name='agent_ext_workflow-assert_operation_sequence.py', + command_args=command_args, + assert_status=True, + restart_agent=restart_agent_command_args + ) + + log.info("") + log.info("*******Verifying the extension enable with special characters scenario*******") + + test_guid = str(uuid.uuid4()) + random_special_char_sentences = [ + "Quizdeltagerne spiste jordbær med fløde, mens cirkusklovnen Wolther spillede på xylofon.", + "Falsches Üben von Xylophonmusik quält jeden größeren Zwerg", + "Zwölf Boxkämpfer jagten Eva quer über den Sylter Deich", + "Heizölrückstoßabdämpfung", + "Γαζέες καὶ μυρτιὲς δὲν θὰ βρῶ πιὰ στὸ χρυσαφὶ ξέφωτο", + "Ξεσκεπάζω τὴν ψυχοφθόρα βδελυγμία", + "El pingüino Wenceslao hizo kilómetros bajo exhaustiva lluvia y frío, añoraba a su querido cachorro.", + "Portez ce vieux whisky au juge blond qui fume sur son île intérieure, à côté de l'alcôve ovoïde, où les bûches" + ] + sentence = choice(random_special_char_sentences) + test_str = "{0}; Special chars: {1}".format(test_guid, sentence) + + # Enable test extension on the VM + dcr_ext.modify_ext_settings_and_enable(data=test_str) + + command_args = f"--data {test_guid}" + + # We first ensure that the stdout contains the special characters and then we check if the test_guid is + # logged atleast once in the agent log to ensure that there were no errors when handling special characters + # in the agent + dcr_ext.assert_scenario( + file_name='agent_ext_workflow-check_data_in_agent_log.py', + command_args=command_args, + assert_status=True, + data=test_guid + ) + + log.info("") + log.info("*******Verifying the extension uninstall scenario*******") + + # Record the time we start the test + start_time = datetime.utcnow().strftime("%Y-%m-%dT%H:%M:%SZ") + + # Remove the test extension on the VM + log.info("Delete %s from VM", dcr_test_ext_client) + dcr_ext.extension.delete() + + command_args = f"--start-time {start_time} " \ + f"normal_ops_sequence " \ + f"--version {dcr_ext.version} " \ + f"--ops disable uninstall" + restart_agent_command_args = [f"--start-time {start_time} " + f"normal_ops_sequence " + f"--version {dcr_ext.version} " + f"--ops disable uninstall"] + + dcr_ext.assert_scenario( + file_name='agent_ext_workflow-assert_operation_sequence.py', + command_args=command_args, + restart_agent=restart_agent_command_args + ) + + log.info("") + log.info("*******Verifying the extension update with install scenario*******") + + # Record the time we start the test + start_time = datetime.utcnow().strftime("%Y-%m-%dT%H:%M:%SZ") + + # Version 1.2.0 of the test extension has the same functionalities as 1.1.5 with + # "updateMode": "UpdateWithInstall" in HandlerManifest.json to test update case + new_version_update_mode_with_install = "1.2.0" + old_version = "1.1.5" + + # Create DcrTestExtension with version 1.1 and 1.2 + dcr_test_ext_id_1_2 = VmExtensionIdentifier( + VmExtensionIds.GuestAgentDcrTestExtension.publisher, + VmExtensionIds.GuestAgentDcrTestExtension.type, + "1.2" + ) + dcr_test_ext_client_1_2 = VirtualMachineExtensionClient( + self._context.vm, + dcr_test_ext_id_1_2, + resource_name="GuestAgentDcrTestExt" + ) + dcr_ext = ExtensionWorkflow.GuestAgentDcrTestExtension( + extension=dcr_test_ext_client, + ssh_client=self._ssh_client, + version=old_version + ) + + # Install test extension v1.1.5 on the VM and assert instance view + dcr_ext.modify_ext_settings_and_enable() + dcr_ext.assert_instance_view() + + # Update extension object & version to new version + dcr_ext.update_ext_version(dcr_test_ext_client_1_2, new_version_update_mode_with_install) + + # Install test extension v1.2.0 on the VM + dcr_ext.modify_ext_settings_and_enable() + + command_args = f"--start-time {start_time} " \ + f"update_sequence " \ + f"--old-version {old_version} " \ + f"--old-ver-ops disable uninstall " \ + f"--new-version {new_version_update_mode_with_install} " \ + f"--new-ver-ops update install enable " \ + f"--final-ops disable update uninstall install enable" + restart_agent_command_args = [ + f"--start-time {start_time} " + f"normal_ops_sequence " + f"--version {old_version} " + f"--ops disable uninstall", + f"--start-time {start_time} " + f"normal_ops_sequence " + f"--version {new_version_update_mode_with_install} " + f"--ops update install enable enable" + ] + + dcr_ext.assert_scenario( + file_name='agent_ext_workflow-assert_operation_sequence.py', + command_args=command_args, + assert_status=True, + restart_agent=restart_agent_command_args + ) + + log.info("") + log.info("Delete %s from VM", dcr_test_ext_client_1_2) + dcr_ext.extension.delete() + + log.info("") + log.info("*******Verifying the extension update without install scenario*******") + + # Record the time we start the test + start_time = datetime.utcnow().strftime("%Y-%m-%dT%H:%M:%SZ") + + # Version 1.3.0 of the test extension has the same functionalities as 1.1.5 with + # "updateMode": "UpdateWithoutInstall" in HandlerManifest.json to test update case + new_version_update_mode_without_install = "1.3.0" + + # Create DcrTestExtension with version 1.1 and 1.3 + dcr_test_ext_id_1_3 = VmExtensionIdentifier( + VmExtensionIds.GuestAgentDcrTestExtension.publisher, + VmExtensionIds.GuestAgentDcrTestExtension.type, + "1.3") + dcr_test_ext_client_1_3 = VirtualMachineExtensionClient( + self._context.vm, + dcr_test_ext_id_1_3, + resource_name="GuestAgentDcrTestExt" + ) + dcr_ext = ExtensionWorkflow.GuestAgentDcrTestExtension( + extension=dcr_test_ext_client, + ssh_client=self._ssh_client, + version=old_version + ) + + # Install test extension v1.1.5 on the VM and assert instance view + dcr_ext.modify_ext_settings_and_enable() + dcr_ext.assert_instance_view() + + # Update extension object & version to new version + dcr_ext.update_ext_version(dcr_test_ext_client_1_3, new_version_update_mode_without_install) + + # Install test extension v1.3.0 on the VM + dcr_ext.modify_ext_settings_and_enable() + + command_args = f"--start-time {start_time} " \ + f"update_sequence " \ + f"--old-version {old_version} " \ + f"--old-ver-ops disable uninstall " \ + f"--new-version {new_version_update_mode_without_install} " \ + f"--new-ver-ops update enable " \ + f"--final-ops disable update uninstall enable" + restart_agent_command_args = [ + f"--start-time {start_time} " + f"normal_ops_sequence " + f"--version {old_version} " + f"--ops disable uninstall", + f"--start-time {start_time} " + f"normal_ops_sequence " + f"--version {new_version_update_mode_without_install} " + f"--ops update enable enable" + ] + + dcr_ext.assert_scenario( + file_name='agent_ext_workflow-assert_operation_sequence.py', + command_args=command_args, + assert_status=True, + restart_agent=restart_agent_command_args + ) + + log.info("") + log.info("*******Verifying no lag between agent start and gs processing*******") + + log.info("") + log.info("Running agent_ext_workflow-validate_no_lag_between_agent_start_and_gs_processing.py remotely...") + result = self._ssh_client.run_command("agent_ext_workflow-validate_no_lag_between_agent_start_and_gs_processing.py", use_sudo=True) + log.info(result) + log.info("Validation for no lag time between agent start and gs processing completed successfully") + + +if __name__ == "__main__": + ExtensionWorkflow.run_from_command_line() diff --git a/tests_e2e/tests/lib/agent_log.py b/tests_e2e/tests/lib/agent_log.py index c9ca25847..b5c488520 100644 --- a/tests_e2e/tests/lib/agent_log.py +++ b/tests_e2e/tests/lib/agent_log.py @@ -358,6 +358,17 @@ def is_error(r: AgentLogRecord) -> bool: return errors + def agent_log_contains(self, data: str): + """ + This function looks for the specified test data string in the WALinuxAgent logs and returns if found or not. + :param data: The string to look for in the agent logs + :return: True if test data string found in the agent log and False if not. + """ + for record in self.read(): + if data in record.text: + return True + return False + @staticmethod def _is_systemd(): # Taken from azurelinuxagent/common/osutil/systemd.py; repeated here because it is available only on agents >= 2.3 diff --git a/tests_e2e/tests/lib/identifiers.py b/tests_e2e/tests/lib/identifiers.py index 398ffd61c..149d89ce3 100644 --- a/tests_e2e/tests/lib/identifiers.py +++ b/tests_e2e/tests/lib/identifiers.py @@ -62,3 +62,4 @@ class VmExtensionIds(object): # New run command extension, with support for multi-config RunCommandHandler: VmExtensionIdentifier = VmExtensionIdentifier(publisher='Microsoft.CPlat.Core', ext_type='RunCommandHandlerLinux', version="1.0") VmAccess: VmExtensionIdentifier = VmExtensionIdentifier(publisher='Microsoft.OSTCExtensions', ext_type='VMAccessForLinux', version="1.0") + GuestAgentDcrTestExtension: VmExtensionIdentifier = VmExtensionIdentifier(publisher='Microsoft.Azure.TestExtensions.Edp', ext_type='GuestAgentDcrTest', version='1.0') diff --git a/tests_e2e/tests/scripts/agent_ext_workflow-assert_operation_sequence.py b/tests_e2e/tests/scripts/agent_ext_workflow-assert_operation_sequence.py new file mode 100755 index 000000000..d01d27799 --- /dev/null +++ b/tests_e2e/tests/scripts/agent_ext_workflow-assert_operation_sequence.py @@ -0,0 +1,183 @@ +#!/usr/bin/env pypy3 + +# Microsoft Azure Linux Agent +# +# Copyright 2018 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# +# The DcrTestExtension maintains an `operations-.log` for every operation that the agent executes on that +# extension. This script asserts that the operations sequence in the log file matches the expected operations given as +# input to this script. We do this to confirm that the agent executed the correct sequence of operations. +# +# Sample operations-.log file snippet - +# Date:2019-07-30T21:54:03Z; Operation:install; SeqNo:0 +# Date:2019-07-30T21:54:05Z; Operation:enable; SeqNo:0 +# Date:2019-07-30T21:54:37Z; Operation:enable; SeqNo:1 +# Date:2019-07-30T21:55:20Z; Operation:disable; SeqNo:1 +# Date:2019-07-30T21:55:22Z; Operation:uninstall; SeqNo:1 +# +import argparse +import os +import sys +import time +from datetime import datetime +from typing import Any, Dict, List + +DELIMITER = ";" +OPS_FILE_DIR = "/var/log/azure/Microsoft.Azure.TestExtensions.Edp.GuestAgentDcrTest/" +OPS_FILE_PATTERN = ["operations-%s.log", "%s/operations-%s.log"] +MAX_RETRY = 5 +SLEEP_TIMER = 30 + + +def parse_ops_log(ops_version: str, input_ops: List[str], start_time: str): + # input_ops are the expected operations that we expect to see in the operations log file + ver = (ops_version,) + ops_file_name = None + for file_pat in OPS_FILE_PATTERN: + ops_file_name = os.path.join(OPS_FILE_DIR, file_pat % ver) + if not os.path.exists(ops_file_name): + ver = ver + (ops_version,) + ops_file_name = None + continue + break + + if not ops_file_name: + raise IOError("Operations File %s not found" % os.path.join(OPS_FILE_DIR, OPS_FILE_PATTERN[0] % ops_version)) + + ops = [] + with open(ops_file_name, 'r') as ops_log: + # we get the last len(input_ops) from the log file and ensure they match with the input_ops + # Example of a line in the log file - `Date:2019-07-30T21:54:03Z; Operation:install; SeqNo:0` + content = ops_log.readlines()[-len(input_ops):] + for op_log in content: + data = op_log.split(DELIMITER) + date = datetime.strptime(data[0].split("Date:")[1], "%Y-%m-%dT%H:%M:%SZ") + op = data[1].split("Operation:")[1] + seq_no = data[2].split("SeqNo:")[1].strip('\n') + + # We only capture the operations that > start_time of the test + if start_time > date: + continue + + ops.append({'date': date, 'op': op, 'seq_no': seq_no}) + return ops + + +def assert_ops_in_sequence(actual_ops: List[Dict[str, Any]], expected_ops: List[str]): + exit_code = 0 + if len(actual_ops) != len(expected_ops): + print("Operation sequence length doesn't match, exit code 2") + exit_code = 2 + + last_date = datetime(70, 1, 1) + for idx, val in enumerate(actual_ops): + if exit_code != 0: + break + + if val['date'] < last_date or val['op'] != expected_ops[idx]: + print("Operation sequence doesn't match, exit code 2") + exit_code = 2 + + last_date = val['date'] + + return exit_code + + +def check_update_sequence(args): + # old_ops_file_name = OPS_FILE_PATTERN % args.old_version + # new_ops_file_name = OPS_FILE_PATTERN % args.new_version + + actual_ops = parse_ops_log(args.old_version, args.old_ops, args.start_time) + actual_ops.extend(parse_ops_log(args.new_version, args.new_ops, args.start_time)) + actual_ops = sorted(actual_ops, key=lambda op: op['date']) + + exit_code = assert_ops_in_sequence(actual_ops, args.ops) + + return exit_code, actual_ops + + +def check_operation_sequence(args): + # ops_file_name = OPS_FILE_PATTERN % args.version + + actual_ops = parse_ops_log(args.version, args.ops, args.start_time) + exit_code = assert_ops_in_sequence(actual_ops, args.ops) + + return exit_code, actual_ops + + +def main(): + # There are 2 main ways you can call this file - normal_ops_sequence or update_sequence + parser = argparse.ArgumentParser() + cmd_parsers = parser.add_subparsers(help="sub-command help", dest="command") + + # We use start_time to make sure we're testing the correct test and not some other test + parser.add_argument("--start-time", dest='start_time', required=True) + + # Normal_ops_sequence gets the version of the ext and parses the corresponding operations file to get the operation + # sequence that were run on the extension + normal_ops_sequence_parser = cmd_parsers.add_parser("normal_ops_sequence", help="Test the normal operation sequence") + normal_ops_sequence_parser.add_argument('--version', dest='version') + normal_ops_sequence_parser.add_argument('--ops', nargs='*', dest='ops', default=argparse.SUPPRESS) + + # Update_sequence mode is used to check for the update scenario. We get the expected old operations, expected + # new operations and the final operation list and verify if the expected operations match the actual ones + update_sequence_parser = cmd_parsers.add_parser("update_sequence", help="Test the update operation sequence") + update_sequence_parser.add_argument("--old-version", dest="old_version") + update_sequence_parser.add_argument("--new-version", dest="new_version") + update_sequence_parser.add_argument("--old-ver-ops", nargs="*", dest="old_ops", default=argparse.SUPPRESS) + update_sequence_parser.add_argument("--new-ver-ops", nargs="*", dest="new_ops", default=argparse.SUPPRESS) + update_sequence_parser.add_argument("--final-ops", nargs="*", dest="ops", default=argparse.SUPPRESS) + + args, unknown = parser.parse_known_args() + + if unknown or len(unknown) > 0: + # Print any unknown arguments passed to this script and fix them with low priority + print("[Low Proiority][To-Fix] Found unknown args: %s" % ', '.join(unknown)) + + args.start_time = datetime.strptime(args.start_time, "%Y-%m-%dT%H:%M:%SZ") + + exit_code = 999 + actual_ops = [] + + for i in range(0, MAX_RETRY): + if args.command == "update_sequence": + exit_code, actual_ops = check_update_sequence(args) + elif args.command == "normal_ops_sequence": + exit_code, actual_ops = check_operation_sequence(args) + else: + print("No such command %s, exit code 5\n" % args.command) + exit_code, actual_ops = 5, [] + break + + if exit_code == 0: + break + + print("{0} test failed with exit code: {1}; Retry attempt: {2}; Retrying in {3} secs".format(args.command, + exit_code, i, + SLEEP_TIMER)) + time.sleep(SLEEP_TIMER) + + if exit_code != 0: + print("Expected Operations: %s" % ", ".join(args.ops)) + print("Actual Operations: %s" % + ','.join(["[%s, Date: %s]" % (op['op'], op['date'].strftime("%Y-%m-%dT%H:%M:%SZ")) for op in actual_ops])) + + print("Assertion completed, exiting with code: %s" % exit_code) + sys.exit(exit_code) + + +if __name__ == "__main__": + print("Asserting operations\n") + main() diff --git a/tests_e2e/tests/scripts/agent_ext_workflow-check_data_in_agent_log.py b/tests_e2e/tests/scripts/agent_ext_workflow-check_data_in_agent_log.py new file mode 100755 index 000000000..867c9b67d --- /dev/null +++ b/tests_e2e/tests/scripts/agent_ext_workflow-check_data_in_agent_log.py @@ -0,0 +1,49 @@ +#!/usr/bin/env pypy3 + +# Microsoft Azure Linux Agent +# +# Copyright 2018 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# +# Checks that the input data is found in the agent log +# +import argparse +import sys + +from pathlib import Path +from tests_e2e.tests.lib.agent_log import AgentLog + + +def main(): + parser = argparse.ArgumentParser() + parser.add_argument("--data", dest='data', required=True) + args, _ = parser.parse_known_args() + + print("Verifying data: {0} in waagent.log".format(args.data)) + found = False + + try: + found = AgentLog(Path('/var/log/waagent.log')).agent_log_contains(args.data) + if found: + print("Found data: {0} in agent log".format(args.data)) + else: + print("Did not find data: {0} in agent log".format(args.data)) + except Exception as e: + print("Error thrown when searching for test data in agent log: {0}".format(str(e))) + + sys.exit(0 if found else 1) + + +if __name__ == "__main__": + main() \ No newline at end of file diff --git a/tests_e2e/tests/scripts/agent_ext_workflow-validate_no_lag_between_agent_start_and_gs_processing.py b/tests_e2e/tests/scripts/agent_ext_workflow-validate_no_lag_between_agent_start_and_gs_processing.py new file mode 100755 index 000000000..7e75c87ef --- /dev/null +++ b/tests_e2e/tests/scripts/agent_ext_workflow-validate_no_lag_between_agent_start_and_gs_processing.py @@ -0,0 +1,96 @@ +#!/usr/bin/env pypy3 + +# Microsoft Azure Linux Agent +# +# Copyright 2018 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# +# Asserts that goal state processing completed no more than 15 seconds after agent start +# +from datetime import timedelta +import re +import sys + +from pathlib import Path +from tests_e2e.tests.lib.agent_log import AgentLog + + +def main(): + success = True + + agent_started_time = [] + agent_msg = [] + time_diff_max_secs = 15 + + # Example: Agent WALinuxAgent-2.2.47.2 is running as the goal state agent + agent_started_regex = r"Azure Linux Agent \(Goal State Agent version [0-9.]+\)" + gs_completed_regex = r"ProcessExtensionsGoalState completed\s\[(?P[a-z_\d]{13,14})\s(?P\d+)\sms\]" + + verified_atleast_one_log_line = False + verified_atleast_one_agent_started_log_line = False + verified_atleast_one_gs_complete_log_line = False + + agent_log = AgentLog(Path('/var/log/waagent.log')) + + try: + for agent_record in agent_log.read(): + verified_atleast_one_log_line = True + + agent_started = re.match(agent_started_regex, agent_record.message) + verified_atleast_one_agent_started_log_line = verified_atleast_one_agent_started_log_line or agent_started + if agent_started: + agent_started_time.append(agent_record.timestamp) + agent_msg.append(agent_record.text) + + gs_complete = re.match(gs_completed_regex, agent_record.message) + verified_atleast_one_gs_complete_log_line = verified_atleast_one_gs_complete_log_line or gs_complete + if agent_started_time and gs_complete: + duration = gs_complete.group('duration') + diff = agent_record.timestamp - agent_started_time.pop() + # Reduce the duration it took to complete the Goalstate, essentially we should only care about how long + # the agent took after start/restart to start processing GS + diff -= timedelta(milliseconds=int(duration)) + agent_msg_line = agent_msg.pop() + if diff.seconds > time_diff_max_secs: + success = False + print("Found delay between agent start and GoalState Processing > {0}secs: " + "Messages: \n {1} {2}".format(time_diff_max_secs, agent_msg_line, agent_record.text)) + + except IOError as e: + print("Unable to validate no lag time: {0}".format(str(e))) + + if not verified_atleast_one_log_line: + success = False + print("Didn't parse a single log line, ensure the log_parser is working fine and verify log regex") + + if not verified_atleast_one_agent_started_log_line: + success = False + print("Didn't parse a single agent started log line, ensure the Regex is working fine: {0}" + .format(agent_started_regex)) + + if not verified_atleast_one_gs_complete_log_line: + success = False + print("Didn't parse a single GS completed log line, ensure the Regex is working fine: {0}" + .format(gs_completed_regex)) + + if agent_started_time or agent_msg: + success = False + print("Mismatch between number of agent start messages and number of GoalState Processing messages\n " + "Agent Start Messages: \n {0}".format('\n'.join(agent_msg))) + + sys.exit(0 if success else 1) + + +if __name__ == "__main__": + main()