def test_add_log_event_should_not_create_event_if_not_allowed_and_not_forced(
self):
add_log_event(logger.LogLevel.WARNING, 'A test WARNING log event')
event_list = self._collect_events()
self.assertEqual(
len(event_list), 0,
"No events should be created if not forced and not allowed")
def _event_file_size_allowed(self, event_file_path):
event_file_size = os.stat(event_file_path).st_size
if event_file_size > self._EXTENSION_EVENT_FILE_MAX_SIZE:
convert_to_mb = lambda x: (1.0 * x) / (1000 * 1000)
msg = "Skipping file: {0} as its size is {1:.2f} Mb > Max size allowed {2:.1f} Mb".format(
event_file_path, convert_to_mb(event_file_size),
convert_to_mb(self._EXTENSION_EVENT_FILE_MAX_SIZE))
logger.warn(msg)
add_log_event(level=logger.LogLevel.WARNING,
message=msg,
forced=True)
return False
return True
def test_add_log_event_should_create_events_that_have_all_the_parameters_in_the_telemetry_schema(
self):
self._test_create_event_function_should_create_events_that_have_all_the_parameters_in_the_telemetry_schema(
create_event_function=lambda: add_log_event(
logger.LogLevel.INFO, 'A test INFO log event'),
expected_parameters={
GuestAgentGenericLogsSchema.EventName: 'Log',
GuestAgentGenericLogsSchema.CapabilityUsed: 'INFO',
GuestAgentGenericLogsSchema.Context1: 'log event',
GuestAgentGenericLogsSchema.Context3: ''
})
def test_add_log_event_should_always_create_events_when_forced(self):
self._test_create_event_function_should_create_events_that_have_all_the_parameters_in_the_telemetry_schema(
create_event_function=lambda: add_log_event(
logger.LogLevel.WARNING,
'A test WARNING log event',
forced=True),
expected_parameters={
GuestAgentGenericLogsSchema.EventName: 'Log',
GuestAgentGenericLogsSchema.CapabilityUsed: 'WARNING',
GuestAgentGenericLogsSchema.Context1: 'log event',
GuestAgentGenericLogsSchema.Context3: ''
})
def test_add_log_event_should_create_events_that_have_all_the_parameters_in_the_telemetry_schema(
self):
self._test_create_event_function_should_create_events_that_have_all_the_parameters_in_the_telemetry_schema(
create_event_function=lambda: add_log_event(
logger.LogLevel.INFO, 'A test INFO log event'),
expected_parameters={
'EventName': 'Log',
'CapabilityUsed': 'INFO',
'Context1': 'A test INFO log event',
'Context2': '',
'Context3': '',
'ExtensionType': ''
})
def _capture_extension_events(self, handler_name, handler_event_dir_path):
"""
Capture Extension events and add them to the events_list
:param handler_name: Complete Handler Name. Eg: Microsoft.CPlat.Core.RunCommandLinux
:param handler_event_dir_path: Full path. Eg: '/var/log/azure/Microsoft.CPlat.Core.RunCommandLinux/events'
"""
# Filter out the files that do not follow the pre-defined EXTENSION_EVENT_FILE_NAME_REGEX
event_files = [
event_file
for event_file in os.listdir(handler_event_dir_path) if re.match(
self._EXTENSION_EVENT_FILE_NAME_REGEX, event_file) is not None
]
# Pick the latest files first, we'll discard older events if len(events) > MAX_EVENT_COUNT
event_files.sort(reverse=True)
captured_extension_events_count = 0
dropped_events_with_error_count = defaultdict(int)
try:
for event_file in event_files:
event_file_path = os.path.join(handler_event_dir_path,
event_file)
try:
logger.verbose("Processing event file: {0}",
event_file_path)
if not self._event_file_size_allowed(event_file_path):
continue
# We support multiple events in a file, read the file and parse events.
captured_extension_events_count = self._enqueue_events_and_get_count(
handler_name, event_file_path,
captured_extension_events_count,
dropped_events_with_error_count)
# We only allow MAX_NUMBER_OF_EVENTS_PER_EXTENSION_PER_PERIOD=300 maximum events per period per handler
if captured_extension_events_count >= self._MAX_NUMBER_OF_EVENTS_PER_EXTENSION_PER_PERIOD:
msg = "Reached max count for the extension: {0}; Max Limit: {1}. Skipping the rest.".format(
handler_name, self.
_MAX_NUMBER_OF_EVENTS_PER_EXTENSION_PER_PERIOD)
logger.warn(msg)
add_log_event(level=logger.LogLevel.WARNING,
message=msg,
forced=True)
break
except ServiceStoppedError:
# Not logging here as already logged once, re-raising
# Since we already started processing this file, deleting it as we could've already sent some events out
# This is a trade-off between data replication vs data loss.
raise
except Exception as error:
msg = "Failed to process event file {0}:{1}".format(
event_file, textutil.format_exception(error))
logger.warn(msg)
add_log_event(level=logger.LogLevel.WARNING,
message=msg,
forced=True)
finally:
# Todo: We should delete files after ensuring that we sent the data to Wireserver successfully
# from our end rather than deleting first and sending later. This is to ensure the data reliability
# of the agent telemetry pipeline.
os.remove(event_file_path)
finally:
if dropped_events_with_error_count:
msg = "Dropped events for Extension: {0}; Details:\n\t{1}".format(
handler_name, '\n\t'.join([
"Reason: {0}; Dropped Count: {1}".format(k, v)
for k, v in dropped_events_with_error_count.items()
]))
logger.warn(msg)
add_log_event(level=logger.LogLevel.WARNING,
message=msg,
forced=True)
if captured_extension_events_count > 0:
logger.info("Collected {0} events for extension: {1}".format(
captured_extension_events_count, handler_name))
