From 3a648981140c8e52433f304370a005f9d9c5ac28 Mon Sep 17 00:00:00 2001 From: doshi36 Date: Mon, 15 Apr 2024 21:55:07 -0400 Subject: [PATCH 1/2] Buggy Test Cases --- .../tests/test_logging.py | 82 +++++++++++++++++-- 1 file changed, 75 insertions(+), 7 deletions(-) diff --git a/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py b/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py index ecd96fd810..f22289a710 100644 --- a/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py +++ b/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py @@ -22,7 +22,7 @@ from unittest.mock import Mock from handlers.opentelemetry_structlog.src.exporter import LogExporter from datetime import datetime, timezone -from unittest.mock import MagicMock +from unittest.mock import MagicMock, patch @@ -247,7 +247,6 @@ def structlog_exporter(self): exporter = StructlogHandler("test_service", "test_host", mock_exporter) return exporter - def test_initialization(self): exporter = self.structlog_exporter() assert exporter._logger_provider is not None, "LoggerProvider should be initialized" @@ -271,7 +270,6 @@ def test_parse_exception(self): parsed_exception = self.structlog_exporter()._parse_exception(event_dict) assert parsed_exception["exception.type"] == "ValueError", "Exception type should be parsed" assert parsed_exception["exception.message"] == "mock error", "Exception message should be parsed" - # Further assertions can be added for stack trace def test_parse_timestamp(self): # Assuming a specific datetime for consistency @@ -296,7 +294,77 @@ def test_call_method_processes_log_correctly(self): # Assert that the logger's emit method was called with the processed event logger.emit.assert_called_once() - - - - + + # Adding new test cases + def test_log_record_translation_attributes(self): + """Verify that event_dict translates correctly into a LogRecord with the correct attributes.""" + exporter = MagicMock() + logger = MagicMock() + exporter_instance = StructlogHandler("test_service", "test_host", exporter) + exporter_instance._logger = logger + + timestamp = datetime.now(timezone.utc) + event_dict = { + "level": "info", + "event": "test event", + "timestamp": timestamp + } + # Get the StructlogHandler instance + + # Assuming StructlogHandler has a method to process and possibly log the event_dict directly. + # Use the instance to process the event_dict. + # Mocking the internal logger's emit method to capture the log record + with patch.object(exporter_instance._logger, 'emit') as mock_emit: + exporter_instance(event_dict=event_dict, logger=None, name=None) + calls = mock_emit.call_args_list + assert len(calls) > 0, "Emit should be called" + log_record = calls[0][0][0] # First call, first arg + + # Assuming log_record is the structured log that would have been emitted, + # and you need to verify its contents. + # Need to adjust the assertion depending on how log records are structured. + # I am assuming log_record is a dictionary that was passed to logger.emit. + assert log_record["body"] == event_dict["event"], "LogRecord body should match event" + assert log_record["timestamp"] == timestamp, "LogRecord timestamp should match event" + assert log_record["level"] == event_dict["level"], "LogRecord level should match event" + + # def test_filtering_of_excluded_attributes(self): + # """Ensure specified attributes are not passed to the log record.""" + # event_dict = { + # "level": "error", + # "event": "Something happened!", + # "timestamp": datetime.now(timezone.utc), + # "exception": ValueError("An error occurred") + # } + + # # Get the StructlogHandler instance + # exporter_instance = self.structlog_exporter() + + # with patch.object(exporter_instance._logger, "_logger") as mocked_logger: + # exporter_instance(event_dict=event_dict, logger=None, name=None) + # calls = mocked_logger.emit.call_args_list + # log_record = calls[0][0][0] + # assert "exception" not in log_record.attributes, "Excluded attributes should not be in the log record" + + # def test_trace_context_propogation(self): + # """Ensure trace context is correctly propagated to the log record.""" + # with self.tracer.start_as_current_span("test_span") as span: + # span_id = format(span.get_span_context().span_id, "016x") + # trace_id = format(span.get_span_context().trace_id, "032x") + # trace_sampled = span.get_span_context().trace_flags.sampled + # event_dict = { + # "level": "info", + # "event": "test event", + # "timestamp": datetime.now(timezone.utc) + # } + + # # Get the StructlogHandler instance + # exporter_instance = self.structlog_exporter() + + # with patch.object(exporter_instance, "_logger") as mocked_logger: + # exporter_instance(event_dict=event_dict, logger=None, name=None) + # calls = mocked_logger.emit.call_args_list + # log_record = calls[0][0][0] + # assert log_record.attributes["otelSpanID"] == span_id, "Span ID should be propagated" + # assert log_record.attributes["otelTraceID"] == trace_id, "Trace ID should be propagated" + # assert log_record.attributes["otelTraceSampled"] == trace_sampled, "" From 45aa0a3a5b7c80816216a2daaeda95a2a73427f5 Mon Sep 17 00:00:00 2001 From: Caroline Gilbert Date: Wed, 17 Apr 2024 10:55:20 -0400 Subject: [PATCH 2/2] Caroline Gilbert: new structlog tests pass --- .../src/test_logging.py | 55 --------- .../tests/test_logging.py | 106 ++++++++++-------- 2 files changed, 60 insertions(+), 101 deletions(-) delete mode 100644 handlers/opentelemetry_structlog/src/test_logging.py diff --git a/handlers/opentelemetry_structlog/src/test_logging.py b/handlers/opentelemetry_structlog/src/test_logging.py deleted file mode 100644 index cc4c0d14a0..0000000000 --- a/handlers/opentelemetry_structlog/src/test_logging.py +++ /dev/null @@ -1,55 +0,0 @@ -import pytest -from unittest.mock import Mock -from exporter import OpenTelemetryExporter -from opentelemetry.sdk._logs._internal.export import LogExporter -from datetime import datetime, timezone - -# Test Initialization -@pytest.fixture -def otel_exporter(): - # Mock the LogExporter dependency - mock_exporter = Mock(spec=LogExporter) - # Instantiate the OpenTelemetryExporter with mock dependencies - exporter = OpenTelemetryExporter("test_service", "test_host", mock_exporter) - return exporter - -def test_initialization(otel_exporter): - assert otel_exporter._logger_provider is not None, "LoggerProvider should be initialized" - assert otel_exporter._logger is not None, "Logger should be initialized" - -def test_pre_process_adds_timestamp(otel_exporter): - event_dict = {"event": "test_event"} - processed_event = otel_exporter._pre_process(event_dict) - assert "timestamp" in processed_event, "Timestamp should be added in pre-processing" - -def test_post_process_formats_timestamp(otel_exporter): - # Assuming the pre_process method has added a datetime object - event_dict = {"timestamp": datetime.now(timezone.utc)} - processed_event = otel_exporter._post_process(event_dict) - assert isinstance(processed_event["timestamp"], str), "Timestamp should be formatted to string in ISO format" - -def test_parse_exception(otel_exporter): - # Mocking an exception event - exception = (ValueError, ValueError("mock error"), None) - event_dict = {"exception": exception} - parsed_exception = otel_exporter._parse_exception(event_dict) - assert parsed_exception["exception.type"] == "ValueError", "Exception type should be parsed" - assert parsed_exception["exception.message"] == "mock error", "Exception message should be parsed" - # Further assertions can be added for stack trace - -def test_parse_timestamp(otel_exporter): - # Assuming a specific datetime for consistency - fixed_datetime = datetime(2020, 1, 1, tzinfo=timezone.utc) - event_dict = {"timestamp": fixed_datetime} - timestamp = otel_exporter._parse_timestamp(event_dict) - expected_timestamp = 1577836800000000000 # Expected nanoseconds since epoch - assert timestamp == expected_timestamp, "Timestamp should be correctly parsed to nanoseconds" - -def test_call_method_processes_log_correctly(otel_exporter, mocker): - mocker.patch.object(otel_exporter._logger, 'emit') - event_dict = {"level": "info", "event": "test event", "timestamp": datetime.now(timezone.utc)} - processed_event = otel_exporter(logger=None, name=None, event_dict=event_dict) - - otel_exporter._logger.emit.assert_called_once() - assert "timestamp" in processed_event, "Processed event should contain a timestamp" - # Add more assertions based on expected transformations and processing outcomes \ No newline at end of file diff --git a/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py b/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py index f22289a710..399888769d 100644 --- a/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py +++ b/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py @@ -21,7 +21,7 @@ # Imports for StructlogHandler tests from unittest.mock import Mock from handlers.opentelemetry_structlog.src.exporter import LogExporter -from datetime import datetime, timezone +from datetime import datetime, timezone, timedelta from unittest.mock import MagicMock, patch @@ -295,7 +295,7 @@ def test_call_method_processes_log_correctly(self): # Assert that the logger's emit method was called with the processed event logger.emit.assert_called_once() - # Adding new test cases + def test_log_record_translation_attributes(self): """Verify that event_dict translates correctly into a LogRecord with the correct attributes.""" exporter = MagicMock() @@ -303,7 +303,7 @@ def test_log_record_translation_attributes(self): exporter_instance = StructlogHandler("test_service", "test_host", exporter) exporter_instance._logger = logger - timestamp = datetime.now(timezone.utc) + timestamp = datetime.now(timezone.utc).isoformat() event_dict = { "level": "info", "event": "test event", @@ -315,7 +315,7 @@ def test_log_record_translation_attributes(self): # Use the instance to process the event_dict. # Mocking the internal logger's emit method to capture the log record with patch.object(exporter_instance._logger, 'emit') as mock_emit: - exporter_instance(event_dict=event_dict, logger=None, name=None) + exporter_instance(event_dict=event_dict, logger=logger, name=None) calls = mock_emit.call_args_list assert len(calls) > 0, "Emit should be called" log_record = calls[0][0][0] # First call, first arg @@ -324,47 +324,61 @@ def test_log_record_translation_attributes(self): # and you need to verify its contents. # Need to adjust the assertion depending on how log records are structured. # I am assuming log_record is a dictionary that was passed to logger.emit. - assert log_record["body"] == event_dict["event"], "LogRecord body should match event" - assert log_record["timestamp"] == timestamp, "LogRecord timestamp should match event" - assert log_record["level"] == event_dict["level"], "LogRecord level should match event" + assert log_record.body == event_dict["event"], "LogRecord body should match event" + + assert log_record.attributes["level"] == event_dict["level"], "LogRecord level should match event" + + def test_filtering_of_excluded_attributes(self): + """Ensure specified attributes are not passed to the log record.""" + event_dict = { + "level": "error", + "event": "Something happened!", + "timestamp": datetime.now(timezone.utc), + "exception": (ValueError, ValueError("An error occurred"), None) + } + + # Get the StructlogHandler instance + exporter_instance = self.structlog_exporter() + + with patch.object(exporter_instance._logger, "emit") as mocked_emit: + # Call the exporter_instance with the event_dict + exporter_instance(event_dict=event_dict, logger=None, name=None) + + # Check if emit method was called + mocked_emit.assert_called_once() + + # Get the log record passed to emit method + log_record = mocked_emit.call_args.args[0] + + # Check if the exception attribute is not present in the log record + assert "exception" not in log_record.attributes, "Excluded attributes should not be in the log record" - # def test_filtering_of_excluded_attributes(self): - # """Ensure specified attributes are not passed to the log record.""" - # event_dict = { - # "level": "error", - # "event": "Something happened!", - # "timestamp": datetime.now(timezone.utc), - # "exception": ValueError("An error occurred") - # } - - # # Get the StructlogHandler instance - # exporter_instance = self.structlog_exporter() - - # with patch.object(exporter_instance._logger, "_logger") as mocked_logger: - # exporter_instance(event_dict=event_dict, logger=None, name=None) - # calls = mocked_logger.emit.call_args_list - # log_record = calls[0][0][0] - # assert "exception" not in log_record.attributes, "Excluded attributes should not be in the log record" - - # def test_trace_context_propogation(self): - # """Ensure trace context is correctly propagated to the log record.""" - # with self.tracer.start_as_current_span("test_span") as span: - # span_id = format(span.get_span_context().span_id, "016x") - # trace_id = format(span.get_span_context().trace_id, "032x") - # trace_sampled = span.get_span_context().trace_flags.sampled - # event_dict = { - # "level": "info", - # "event": "test event", - # "timestamp": datetime.now(timezone.utc) - # } + + def test_trace_context_propogation(self): + """Ensure trace context is correctly propagated to the log record.""" + with self.tracer.start_as_current_span("test_span") as span: + span_id = format(span.get_span_context().span_id, "016x") + trace_id = format(span.get_span_context().trace_id, "032x") + trace_sampled = span.get_span_context().trace_flags.sampled + event_dict = { + "level": "info", + "event": "test event", + "timestamp": datetime.now(timezone.utc) + } - # # Get the StructlogHandler instance - # exporter_instance = self.structlog_exporter() - - # with patch.object(exporter_instance, "_logger") as mocked_logger: - # exporter_instance(event_dict=event_dict, logger=None, name=None) - # calls = mocked_logger.emit.call_args_list - # log_record = calls[0][0][0] - # assert log_record.attributes["otelSpanID"] == span_id, "Span ID should be propagated" - # assert log_record.attributes["otelTraceID"] == trace_id, "Trace ID should be propagated" - # assert log_record.attributes["otelTraceSampled"] == trace_sampled, "" + # Get the StructlogHandler instance + exporter_instance = self.structlog_exporter() + + with patch.object(exporter_instance, "_logger") as mocked_logger: + exporter_instance(event_dict=event_dict, logger=None, name=None) + calls = mocked_logger.emit.call_args_list + log_record = calls[0][0][0] + + # Assert that the log record has the correct trace context + actual_span_id = format(log_record.span_id, "016x") + assert actual_span_id == span_id, "Span ID should be propagated" + + actual_trace_id = format(log_record.trace_id, "032x") + assert actual_trace_id == trace_id, "Trace ID should be propagated" + + assert log_record.trace_flags == trace_sampled, "Trace flags should be propagated"