def _assert_extension_event_includes_all_parameters_in_the_telemetry_schema(
self, event_file):
# Extensions drop their events as *.tld files on the events directory. They populate only a subset of fields,
# and the rest are added by the agent when events are collected.
test_file = self._create_test_event_file(event_file)
event_creation_time = TestEvent._get_file_creation_timestamp(test_file)
event_list = event.collect_events()
self.assertEquals(len(event_list.events), 1)
self._assert_event_includes_all_parameters_in_the_telemetry_schema(
event_list.events[0],
expected_parameters={
'Name': 'Microsoft.Azure.Extensions.CustomScript',
'Version': '2.0.4',
'Operation': 'Scenario',
'OperationSuccess': True,
'Message': 'A test telemetry message.',
'Duration': 150000,
'ExtensionType': 'json'
},
assert_timestamp=lambda timestamp: self.assertEquals(
timestamp, event_creation_time,
"The event timestamp (opcode) is incorrect"))
def test_collect_events_should_add_all_the_parameters_in_the_telemetry_schema_to_legacy_agent_events(
self):
# Agents <= 2.2.46 use *.tld as the extension for event files (newer agents use "*.waagent.tld") and they populate
# only a subset of fields; the rest are added by the current agent when events are collected.
self._create_test_event_file("legacy_agent.tld")
event_list = event.collect_events()
self.assertEquals(len(event_list.events), 1)
self._assert_event_includes_all_parameters_in_the_telemetry_schema(
event_list.events[0],
expected_parameters={
"Name": "WALinuxAgent",
"Version": "9.9.9",
"IsInternal": False,
"Operation": "InitializeCGroups",
"OperationSuccess": True,
"Message": "The cgroup filesystem is ready to use",
"Duration": 1234,
"ExtensionType": "ALegacyExtensionType",
"GAVersion": "WALinuxAgent-1.1.1",
"ContainerId": "AAAAAAAA-BBBB-CCCC-DDDD-EEEEEEEEEEEE",
"EventTid": 98765,
"EventPid": 4321,
"TaskName": "ALegacyTask",
"KeywordName": "ALegacyKeywordName"
},
assert_timestamp=lambda timestamp: self.assertEquals(
timestamp, '1970-01-01 12:00:00',
"The event timestamp (opcode) is incorrect"))
def test_collect_events_should_use_the_file_creation_time_for_legacy_agent_events_missing_a_timestamp(
self):
test_file = self._create_test_event_file(
"legacy_agent_no_timestamp.tld")
event_creation_time = TestEvent._get_file_creation_timestamp(test_file)
event_list = event.collect_events()
self.assertEquals(len(event_list.events), 1)
self._assert_event_includes_all_parameters_in_the_telemetry_schema(
event_list.events[0],
expected_parameters={
"Name": "WALinuxAgent",
"Version": "9.9.9",
"IsInternal": False,
"Operation": "InitializeCGroups",
"OperationSuccess": True,
"Message": "The cgroup filesystem is ready to use",
"Duration": 1234,
"ExtensionType": "ALegacyExtensionType",
"GAVersion": "WALinuxAgent-1.1.1",
"ContainerId": "AAAAAAAA-BBBB-CCCC-DDDD-EEEEEEEEEEEE",
"EventTid": 98765,
"EventPid": 4321,
"TaskName": "ALegacyTask",
"KeywordName": "ALegacyKeywordName"
},
assert_timestamp=lambda timestamp: self.assertEquals(
timestamp, event_creation_time,
"The event timestamp (opcode) is incorrect"))
def collect_and_send_events(self):
"""
Periodically send any events located in the events folder
"""
event_list = collect_events()
if len(event_list.events) > 0:
self.protocol.report_event(event_list)
def test_collect_events_should_be_able_to_process_events_with_non_ascii_characters(
self):
self._create_test_event_file("custom_script_nonascii_characters.tld")
event_list = event.collect_events()
self.assertEquals(len(event_list.events), 1)
self.assertEquals(
TestEvent._get_event_message(event_list.events[0]),
u'World\u05e2\u05d9\u05d5\u05ea \u05d0\u05d7\u05e8\u05d5\u05ea\u0906\u091c'
)
def create_event_and_return_container_id():
event.add_event(name='Event')
event_list = event.collect_events()
self.assertEquals(len(event_list.events), 1,
"Could not find the event created by add_event")
for p in event_list.events[0].parameters:
if p.name == 'ContainerId':
return p.value
self.fail("Could not find Contained ID on event")
def test_collect_events_should_delete_event_files(self):
add_event(name='Event1')
add_event(name='Event1')
add_event(name='Event3')
event_files = os.listdir(self.event_dir)
self.assertEquals(
len(event_files), 3,
"Did not find all the event files that were created")
event_list = event.collect_events()
event_files = os.listdir(self.event_dir)
self.assertEquals(len(event_list.events), 3,
"Did not collect all the events that were created")
self.assertEquals(len(event_files), 0,
"The event files were not deleted")
def _test_create_event_function_should_create_events_that_have_all_the_parameters_in_the_telemetry_schema(
self, create_event_function, expected_parameters):
"""
Helper to tests methods that create events (e.g. add_event, add_log_event, etc).
"""
# execute the method that creates the event, capturing the time range of the execution
timestamp_lower = TestEvent._datetime_to_event_timestamp(
datetime.utcnow())
create_event_function()
timestamp_upper = TestEvent._datetime_to_event_timestamp(
datetime.utcnow())
# retrieve the event that was created
event_list = event.collect_events()
self.assertEquals(len(event_list.events), 1)
# verify the event parameters
self._assert_event_includes_all_parameters_in_the_telemetry_schema(
event_list.events[0],
expected_parameters,
assert_timestamp=lambda timestamp: self.assertTrue(
timestamp_lower <= timestamp <= timestamp_upper,
"The event timestamp (opcode) is incorrect"))
def test_collect_events_should_ignore_invalid_event_files(self):
self._create_test_event_file("custom_script_1.tld") # a valid event
self._create_test_event_file("custom_script_utf-16.tld")
self._create_test_event_file("custom_script_invalid_json.tld")
os.chmod(
self._create_test_event_file("custom_script_no_read_access.tld"),
0o200)
self._create_test_event_file(
"custom_script_2.tld") # another valid event
with patch("azurelinuxagent.common.event.logger.warn") as mock_warn:
event_list = event.collect_events()
self.assertEquals(len(event_list.events), 2)
self.assertTrue(
all(
TestEvent._get_event_message(evt) ==
"A test telemetry message." for evt in event_list.events),
"The valid events were not found")
invalid_events = {}
for args in mock_warn.call_args_list:
if re.search('Failed to process event file',
args[0][0]) is not None:
invalid_events[args[0][1]] = args[0][1]
def assert_invalid_file_was_reported(file):
self.assertIn(
file, invalid_events,
'{0} was not reported as an invalid event file'.format(
file))
assert_invalid_file_was_reported("custom_script_utf-16.tld")
assert_invalid_file_was_reported("custom_script_invalid_json.tld")
assert_invalid_file_was_reported(
"custom_script_no_read_access.tld")
def test_report_event_should_encode_call_stack_correctly(self):
"""
The Message in some telemetry events that include call stacks are being truncated in Kusto. While the issue doesn't seem
to be in the agent itself, this test verifies that the Message of the event we send in the HTTP request matches the
Message we read from the event's file.
"""
def get_event_message_from_event_file(event_file):
with open(event_file, "rb") as fd:
event_data = fd.read().decode(
"utf-8") # event files are UTF-8 encoded
telemetry_event = json.loads(event_data)
for p in telemetry_event['parameters']:
if p['name'] == 'Message':
return p['value']
raise ValueError(
'Could not find the Message for the telemetry event in {0}'.
format(path))
def get_event_message_from_http_request_body(http_request_body):
# The XML for the event is sent over as a CDATA element ("Event") in the request's body
request_body_xml_doc = textutil.parse_doc(http_request_body)
event_node = textutil.find(request_body_xml_doc, "Event")
if event_node is None:
raise ValueError(
'Could not find the Event node in the XML document')
if len(event_node.childNodes) != 1:
raise ValueError(
'The Event node in the XML document should have exactly 1 child'
)
event_node_first_child = event_node.childNodes[0]
if event_node_first_child.nodeType != xml.dom.Node.CDATA_SECTION_NODE:
raise ValueError('The Event node contents should be CDATA')
event_node_cdata = event_node_first_child.nodeValue
# The CDATA will contain a sequence of "<Param Name='foo' Value='bar'/>" nodes, which
# correspond to the parameters of the telemetry event. Wrap those into a "Helper" node
# and extract the "Message"
event_xml_text = '<?xml version="1.0"?><Helper>{0}</Helper>'.format(
event_node_cdata)
event_xml_doc = textutil.parse_doc(event_xml_text)
helper_node = textutil.find(event_xml_doc, "Helper")
for child in helper_node.childNodes:
if child.getAttribute('Name') == 'Message':
return child.getAttribute('Value')
raise ValueError(
'Could not find the Message for the telemetry event. Request body: {0}'
.format(http_request_body))
def http_post_handler(url, body, **__):
if self.is_telemetry_request(url):
http_post_handler.request_body = body
return MockHttpResponse(status=200)
return None
http_post_handler.request_body = None
with mock_wire_protocol(
mockwiredata.DATA_FILE,
http_post_handler=http_post_handler) as protocol:
event_file_path = self._create_test_event_file(
"event_with_callstack.waagent.tld")
expected_message = get_event_message_from_event_file(
event_file_path)
event_list = event.collect_events()
protocol.client.report_event(event_list)
event_message = get_event_message_from_http_request_body(
http_post_handler.request_body)
self.assertEquals(
event_message, expected_message,
"The Message in the HTTP request does not match the Message in the event's *.tld file"
)
