Skip to content

Adding status file for non enable commands and catching early errors #144

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 9 commits into from
Jun 15, 2022
Merged

Adding status file for non enable commands and catching early errors #144

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
9 commits
Select commit Hold shift + click to select a range
ad2e576
Adding status file for non enable commands and catching early errors
rane-rajasi May 31, 2022
52ae945
Merge branch 'master' into rarane-errorhandlingchanges
rane-rajasi May 31, 2022
76ef9d4
Changes based on earlier discussions and adding UT coverage
rane-rajasi Jun 1, 2022
4aceeac
Addressing PR feedback
rane-rajasi Jun 2, 2022
bb46e3c
Modifying exit code values acc to agent team's inputs
rane-rajasi Jun 8, 2022
b6453c0
Addressing PR comments
rane-rajasi Jun 13, 2022
054e02c
Merge branch 'master' into rarane-errorhandlingchanges
rane-rajasi Jun 13, 2022
4b2ced2
Reverting a small change leftover from earlier iterations
rane-rajasi Jun 14, 2022
b45aa59
Merge branch 'master' into rarane-errorhandlingchanges
rane-rajasi Jun 14, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
75 changes: 58 additions & 17 deletions src/extension/src/ActionHandler.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,7 @@ def __init__(self, logger, env_layer, telemetry_writer, utility, runtime_context
self.stdout_file_mirror = None
self.file_logger = None
self.operation_id_substitute_for_all_actions_in_telemetry = str((datetime.datetime.utcnow()).strftime(Constants.UTC_DATETIME_FORMAT))
self.seq_no = self.ext_config_settings_handler.get_seq_no_from_env_var()

def determine_operation(self, command):
switcher = {
Expand All @@ -64,32 +65,49 @@ def determine_operation(self, command):
raise e

def setup(self, action, log_message):
self.setup_file_logger(action)
self.setup_telemetry()
self.logger.log(log_message)
if action == Constants.ENABLE:
self.write_basic_status()
try:
self.setup_file_logger(action)
self.validate_sudo() # Validating sudo as early as possible and before it's use in setup_telemetry
self.setup_telemetry()
self.logger.log(log_message)
except Exception:
raise
finally:
self.write_basic_status(action)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

curiosity: If lines 69 through 72 throw, can the exception be written to the basic status file and then rethrown?

It looks like you'll have to write basic status on line 73 at the end of the try and within the except. In that case a finally will no longer be necessary.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

With basic status, we set the top level status to "transitioning". Now incase of exceptions, and all these are currently terminal, the status is re-written to "error"

The way the code is in all setup() callers right now, we can have write_basic_status() on line 72, just before except, so a basic status (with status=Transitioning) is written in a happy path, and incase of exceptions, there is only 1 status write with status=error (instead of 2 writes). But thought of keeping write_basic_status() in finally, in case something changes in callers later


def validate_sudo(self):
# Disable tty for sudo access, if required
self.env_health_manager.ensure_tty_not_required()

# Ensure sudo works in the environment
sudo_check_result = self.env_health_manager.check_sudo_status()
self.logger.log_debug("Sudo status check: " + str(sudo_check_result) + "\n")

def write_basic_status(self):
def write_basic_status(self, action):
""" Writes a basic status file if one for the same sequence number does not exist """
try:
# read seq no, if not found, log error and return, as this code opportunistically tries to write status file as early as possible
seq_no = self.ext_config_settings_handler.get_seq_no_from_env_var()
if seq_no is None:
if self.seq_no is None:
self.logger.log_error("Since sequence number for current operation was not found, handler could not write an initial/basic status file")
return

# check if a status file for this sequence exists, if yes, do nothing
if not os.path.exists(os.path.join(self.ext_env_handler.status_folder, str(seq_no) + Constants.STATUS_FILE_EXTENSION)):
config_settings = self.ext_config_settings_handler.read_file(seq_no)
if os.path.exists(os.path.join(self.ext_env_handler.status_folder, str(self.seq_no) + Constants.STATUS_FILE_EXTENSION)):
return

# if status file for this sequence does not exist and enable is executed, read and use values from config setting file, else do not set those in status file
operation = ""
if action == Constants.ENABLE:
config_settings = self.ext_config_settings_handler.read_file(self.seq_no)

# set activity_id in telemetry
if self.telemetry_writer is not None:
self.telemetry_writer.set_operation_id(config_settings.__getattribute__(Constants.ConfigPublicSettingsFields.activity_id))

operation = config_settings.__getattribute__(Constants.ConfigPublicSettingsFields.operation)
# create status file with basic status
self.ext_output_status_handler.write_status_file(operation, seq_no)

# create status file with basic status
self.ext_output_status_handler.write_status_file(operation, self.seq_no)

except Exception as error:
self.logger.log_error("Exception occurred while writing basic status. [Exception={0}]".format(repr(error)))
Expand Down Expand Up @@ -159,10 +177,16 @@ def install(self):
try:
self.setup(action=Constants.INSTALL, log_message="Extension installation started")
install_command_handler = InstallCommandHandler(self.logger, self.ext_env_handler)
return install_command_handler.execute_handler_action()
exit_code_from_executing_install = install_command_handler.execute_handler_action()
if exit_code_from_executing_install == Constants.ExitCode.Okay or exit_code_from_executing_install is None:
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Success.lower())
else:
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Error.lower(), message="Error occurred during extension install", code=exit_code_from_executing_install)
return exit_code_from_executing_install

except Exception as error:
self.logger.log_error("Error occurred during extension install. [Error={0}]".format(repr(error)))
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Error.lower(), message="Error occurred during extension install", code=Constants.ExitCode.HandlerFailed)
return Constants.ExitCode.HandlerFailed

finally:
Expand Down Expand Up @@ -191,27 +215,34 @@ def update(self):
# Extension Update action called when
# a) artifacts for the preceding version do not exist on the machine, or
# b) after all artifacts from the preceding versions have been deleted
self.logger.log_error("No earlier versions for the extension found on the machine. So, could not copy any references to the current version.")
error_msg = "No earlier versions for the extension found on the machine. So, could not copy any references to the current version."
self.logger.log_error(error_msg)
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Error.lower(), message=error_msg, code=Constants.ExitCode.HandlerFailed)
return Constants.ExitCode.HandlerFailed

# identify the version preceding current
self.logger.log("Fetching the extension version preceding current from all available versions...")
paths_to_all_versions.sort(reverse=True, key=LooseVersion)
preceding_version_path = paths_to_all_versions[1]
if preceding_version_path is None or preceding_version_path == "" or not os.path.exists(preceding_version_path):
self.logger.log_error("Could not find path where preceding extension version artifacts are stored. Hence, cannot copy the required artifacts to the latest version. "
"[Preceding extension version path={0}]".format(str(preceding_version_path)))
error_msg = "Could not find path where preceding extension version artifacts are stored. Hence, cannot copy the required artifacts to the latest version. "\
"[Preceding extension version path={0}]".format(str(preceding_version_path))
self.logger.log_error(error_msg)
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Error.lower(), message=error_msg, code=Constants.ExitCode.HandlerFailed)
return Constants.ExitCode.HandlerFailed

self.logger.log("Preceding version path. [Path={0}]".format(str(preceding_version_path)))

# copy all required files from preceding version to current
self.copy_config_files(preceding_version_path, new_version_config_folder)

self.logger.log("All update actions from extension handler completed.")
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Success.lower())
return Constants.ExitCode.Okay

except Exception as error:
self.logger.log_error("Error occurred during extension update. [Error={0}]".format(repr(error)))
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Error.lower(), message="Error occurred during extension update", code=Constants.ExitCode.HandlerFailed)
return Constants.ExitCode.HandlerFailed

finally:
Expand Down Expand Up @@ -260,10 +291,12 @@ def copy_config_files(self, src, dst, raise_if_not_copied=False):
def uninstall(self):
try:
self.setup(action=Constants.UNINSTALL, log_message="Extension uninstalled")
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Success.lower())
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please check with Jemal about the cases where the Windows extension writes a status file to ensure alignment between the extensions.

Copy link
Contributor Author

@rane-rajasi rane-rajasi Jun 13, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done, windows extension also writes status only for enable. Windows agent may write status file for enable, this is considered by our extension while writing status. As for other handler actions, we aren't sure if agent does write status and the extension does not write status

return Constants.ExitCode.Okay

except Exception as error:
self.logger.log_error("Error occurred during extension uninstall. [Error={0}]".format(repr(error)))
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Error.lower(), message="Error occurred during extension uninstall", code=Constants.ExitCode.HandlerFailed)
return Constants.ExitCode.HandlerFailed

finally:
Expand All @@ -273,10 +306,14 @@ def enable(self):
try:
self.setup(action=Constants.ENABLE, log_message="Enable triggered on extension")
enable_command_handler = EnableCommandHandler(self.logger, self.telemetry_writer, self.utility, self.env_health_manager, self.runtime_context_handler, self.ext_env_handler, self.ext_config_settings_handler, self.core_state_handler, self.ext_state_handler, self.ext_output_status_handler, self.process_handler, self.cmd_exec_start_time)
return enable_command_handler.execute_handler_action()
exit_code_returned_from_executing_enable = enable_command_handler.execute_handler_action()
if exit_code_returned_from_executing_enable is not None and exit_code_returned_from_executing_enable != Constants.ExitCode.Okay:
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Error.lower(), message="Error occurred during extension enable", code=exit_code_returned_from_executing_enable)
return Constants.ExitCode.Okay if exit_code_returned_from_executing_enable is None else exit_code_returned_from_executing_enable

except Exception as error:
self.logger.log_error("Error occurred during extension enable. [Error={0}]".format(repr(error)))
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Error.lower(), message="Error occurred during extension enable", code=Constants.ExitCode.HandlerFailed)
return Constants.ExitCode.HandlerFailed
finally:
self.tear_down()
Expand Down Expand Up @@ -306,10 +343,12 @@ def disable(self):
# End of temporary auto-assessment disablement

self.logger.log("Extension disabled successfully")
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Success.lower())
return Constants.ExitCode.Okay

except Exception as error:
self.logger.log_error("Error occurred during extension disable. [Error={0}]".format(repr(error)))
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Error.lower(), message="Error occurred during extension disable", code=Constants.ExitCode.HandlerFailed)
return Constants.ExitCode.HandlerFailed
finally:
self.tear_down()
Expand All @@ -319,10 +358,12 @@ def reset(self):
self.setup(action=Constants.RESET, log_message="Reset triggered on extension, deleting CoreState and ExtState files")
self.utility.delete_file(self.core_state_handler.dir_path, self.core_state_handler.file, raise_if_not_found=False)
self.utility.delete_file(self.ext_state_handler.dir_path, self.ext_state_handler.file, raise_if_not_found=False)
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Success.lower())
return Constants.ExitCode.Okay

except Exception as error:
self.logger.log_error("Error occurred during extension reset. [Error={0}]".format(repr(error)))
self.ext_output_status_handler.write_status_file("", self.seq_no, status=Constants.Status.Error.lower(), message="Error occurred during extension reset", code=Constants.ExitCode.HandlerFailed)
return Constants.ExitCode.HandlerFailed
finally:
self.tear_down()
Expand Down
20 changes: 10 additions & 10 deletions src/extension/src/Constants.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -201,19 +201,19 @@ class Status(EnumBackport):

class ExitCode(EnumBackport):
Okay = 0
HandlerFailed = -1
MissingConfig = -2
BadConfig = -3
UnsupportedOperatingSystem = 51
MissingDependency = 52
ConfigurationError = 53
BadHandlerEnvironmentFile = 3560
UnableToReadStatusFile = 3561
CreateFileLoggerFailure = 3562
ReadingAndDeserializingConfigFileFailure = 3563
InvalidConfigSettingPropertyValue = 3564
CreateLoggerFailure = 3565
CreateStatusWriterFailure = 3566
BadHandlerEnvironmentFile = 81
UnableToReadStatusFile = 82
CreateFileLoggerFailure = 83
ReadingAndDeserializingConfigFileFailure = 84
InvalidConfigSettingPropertyValue = 85
CreateLoggerFailure = 86
CreateStatusWriterFailure = 87
HandlerFailed = 88
MissingConfig = 89
OperationNotSupported = 90

class AgentEnvVarStatusCode(EnumBackport):
AGENT_ENABLED = "AGENT_ENABLED"
Expand Down
12 changes: 3 additions & 9 deletions src/extension/src/EnableCommandHandler.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -41,13 +41,6 @@ def __init__(self, logger, telemetry_writer, utility, env_health_manager, runtim
def execute_handler_action(self):
""" Responsible for taking appropriate action for enable command as per the request sent in Handler Configuration file by user """
try:
# Disable tty for sudo access, if required
self.env_health_manager.ensure_tty_not_required()

# Ensure sudo works in the environment
sudo_check_result = self.env_health_manager.check_sudo_status()
self.logger.log_debug("Sudo status check: " + str(sudo_check_result) + "\n")

# fetch seq_no
self.seq_no = self.ext_config_settings_handler.get_seq_no(is_enable_request=True)
if self.seq_no is None:
Expand All @@ -68,7 +61,8 @@ def execute_handler_action(self):
# Allow only certain operations
if operation not in [Constants.NOOPERATION, Constants.ASSESSMENT, Constants.INSTALLATION, Constants.CONFIGURE_PATCHING]:
self.logger.log_error("Requested operation is not supported by the extension")
exit(Constants.ExitCode.InvalidConfigSettingPropertyValue)
self.ext_output_status_handler.write_status_file(operation, self.seq_no, status=Constants.Status.Error.lower(), message="Requested operation {0} is not supported by the extension".format(str(operation)), code=Constants.ExitCode.OperationNotSupported)
exit(Constants.ExitCode.OperationNotSupported)

prev_patch_max_end_time = self.cmd_exec_start_time + datetime.timedelta(hours=0, minutes=Constants.ENABLE_MAX_RUNTIME)
self.ext_state_handler.create_file(self.seq_no, operation, prev_patch_max_end_time)
Expand Down Expand Up @@ -125,7 +119,7 @@ def launch_new_process(self, config_settings, create_status_output_file):
if create_status_output_file:
self.ext_output_status_handler.write_status_file(config_settings.__getattribute__(self.config_public_settings.operation), self.seq_no, status=self.status.Transitioning.lower())
else:
self.ext_output_status_handler.update_file(self.seq_no, self.ext_env_handler.status_folder)
self.ext_output_status_handler.update_file(self.seq_no)
# launch core code in a process and exit extension handler
process = self.process_handler.start_daemon(self.seq_no, config_settings, self.ext_env_handler)
self.logger.log("exiting extension handler")
Expand Down
7 changes: 5 additions & 2 deletions src/extension/src/__main__.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -41,6 +41,7 @@ def main(argv):
logger = Logger()
telemetry_writer = TelemetryWriter(logger, env_layer)
logger.telemetry_writer = telemetry_writer # Need to set telemetry_writer within logger to enable sending all logs to telemetry
exit_code = None
try:
# initializing action handler
# args will have values install, uninstall, etc, as given in MsftLinuxPatchExtShim.sh in the operation var
Expand All @@ -62,19 +63,21 @@ def main(argv):
ext_output_status_handler = ExtOutputStatusHandler(logger, utility, json_file_handler, ext_env_handler.status_folder)
process_handler = ProcessHandler(logger, env_layer, ext_output_status_handler)
action_handler = ActionHandler(logger, env_layer, telemetry_writer, utility, runtime_context_handler, json_file_handler, env_health_manager, ext_env_handler, ext_config_settings_handler, core_state_handler, ext_state_handler, ext_output_status_handler, process_handler, cmd_exec_start_time)
action_handler.determine_operation(argv[1])
exit_code_from_handler_actions = action_handler.determine_operation(argv[1])
exit_code = Constants.ExitCode.Okay if exit_code_from_handler_actions is None else exit_code_from_handler_actions
else:
error_cause = "No configuration provided in HandlerEnvironment" if ext_env_handler.handler_environment_json is None else "Path to config folder not specified in HandlerEnvironment"
error_msg = "Error processing file. [File={0}] [Error={1}]".format(Constants.HANDLER_ENVIRONMENT_FILE, error_cause)
raise Exception(error_msg)
except Exception as error:
logger.log_error(repr(error))
return Constants.ExitCode.HandlerFailed
exit_code = Constants.ExitCode.HandlerFailed
finally:
if stdout_file_mirror is not None:
stdout_file_mirror.stop()
if file_logger is not None:
file_logger.close()
exit(exit_code)


if __name__ == '__main__':
Expand Down
Loading