-
Notifications
You must be signed in to change notification settings - Fork 103
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.
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
Add structlog instrumentation. #685
Merged
hmstepanek
merged 10 commits into
develop-logs-in-context-additions
from
instrument-structlog
Dec 2, 2022
Merged
Changes from all commits
Commits
Show all changes
10 commits
Select commit
Hold shift + click to select a range
1170957
Add initial structlog instrumentation.
umaannamalai e9efd87
Cleanup.
umaannamalai bb2747a
Add processor filtering and attribute testing.
umaannamalai 5cee7b0
Add more filtering tests.
umaannamalai 7cc73d9
Add co-authors.
umaannamalai 4d88c8a
Merge branch 'develop-logs-in-context-additions' into instrument-stru…
TimPansino 67feaa7
Remove pylint codes from flake8 config (#701)
hmstepanek f254bcb
Merge branch 'main' into instrument-structlog
hmstepanek 934b8d5
Create pytest fixtures and cleanup tests.
umaannamalai 2cafd61
Merge branch 'instrument-structlog' of github.com:newrelic/newrelic-p…
umaannamalai File filter
Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
There are no files selected for viewing
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,86 @@ | ||
# Copyright 2010 New Relic, Inc. | ||
# | ||
# 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 newrelic.common.object_wrapper import wrap_function_wrapper | ||
from newrelic.api.transaction import current_transaction, record_log_event | ||
from newrelic.core.config import global_settings | ||
from newrelic.api.application import application_instance | ||
from newrelic.hooks.logger_logging import add_nr_linking_metadata | ||
|
||
|
||
def normalize_level_name(method_name): | ||
# Look up level number for method name, using result to look up level name for that level number. | ||
# Convert result to upper case, and default to UNKNOWN in case of errors or missing values. | ||
try: | ||
from structlog._log_levels import _LEVEL_TO_NAME, _NAME_TO_LEVEL | ||
return _LEVEL_TO_NAME[_NAME_TO_LEVEL[method_name]].upper() | ||
except Exception: | ||
return "UNKNOWN" | ||
|
||
|
||
def bind_process_event(method_name, event, event_kw): | ||
return method_name, event, event_kw | ||
|
||
|
||
def wrap__process_event(wrapped, instance, args, kwargs): | ||
try: | ||
method_name, event, event_kw = bind_process_event(*args, **kwargs) | ||
except TypeError: | ||
return wrapped(*args, **kwargs) | ||
|
||
original_message = event # Save original undecorated message | ||
|
||
transaction = current_transaction() | ||
|
||
if transaction: | ||
settings = transaction.settings | ||
else: | ||
settings = global_settings() | ||
|
||
# Return early if application logging not enabled | ||
if settings and settings.application_logging and settings.application_logging.enabled: | ||
if settings.application_logging.local_decorating and settings.application_logging.local_decorating.enabled: | ||
event = add_nr_linking_metadata(event) | ||
|
||
# Send log to processors for filtering, allowing any DropEvent exceptions that occur to prevent instrumentation from recording the log event. | ||
result = wrapped(method_name, event, event_kw) | ||
|
||
level_name = normalize_level_name(method_name) | ||
|
||
if settings.application_logging.metrics and settings.application_logging.metrics.enabled: | ||
if transaction: | ||
transaction.record_custom_metric("Logging/lines", {"count": 1}) | ||
transaction.record_custom_metric("Logging/lines/%s" % level_name, {"count": 1}) | ||
else: | ||
application = application_instance(activate=False) | ||
if application and application.enabled: | ||
application.record_custom_metric("Logging/lines", {"count": 1}) | ||
application.record_custom_metric("Logging/lines/%s" % level_name, {"count": 1}) | ||
|
||
if settings.application_logging.forwarding and settings.application_logging.forwarding.enabled: | ||
try: | ||
record_log_event(original_message, level_name, attributes=event_kw) | ||
|
||
except Exception: | ||
pass | ||
|
||
# Return the result from wrapped after we've recorded the resulting log event. | ||
return result | ||
|
||
return wrapped(*args, **kwargs) | ||
|
||
|
||
def instrument_structlog__base(module): | ||
if hasattr(module, "BoundLoggerBase") and hasattr(module.BoundLoggerBase, "_process_event"): | ||
wrap_function_wrapper(module, "BoundLoggerBase._process_event", wrap__process_event) |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,150 @@ | ||
# Copyright 2010 New Relic, Inc. | ||
# | ||
# 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 logging | ||
import pytest | ||
from structlog import DropEvent, PrintLogger | ||
from newrelic.api.time_trace import current_trace | ||
from newrelic.api.transaction import current_transaction | ||
from testing_support.fixtures import ( | ||
code_coverage_fixture, | ||
collector_agent_registration_fixture, | ||
collector_available_fixture, | ||
) | ||
|
||
_coverage_source = [ | ||
"newrelic.hooks.logger_structlog", | ||
] | ||
|
||
code_coverage = code_coverage_fixture(source=_coverage_source) | ||
|
||
_default_settings = { | ||
"transaction_tracer.explain_threshold": 0.0, | ||
"transaction_tracer.transaction_threshold": 0.0, | ||
"transaction_tracer.stack_trace_threshold": 0.0, | ||
"debug.log_data_collector_payloads": True, | ||
"debug.record_transaction_failure": True, | ||
"application_logging.enabled": True, | ||
"application_logging.forwarding.enabled": True, | ||
"application_logging.metrics.enabled": True, | ||
"application_logging.local_decorating.enabled": True, | ||
"event_harvest_config.harvest_limits.log_event_data": 100000, | ||
} | ||
|
||
collector_agent_registration = collector_agent_registration_fixture( | ||
app_name="Python Agent Test (logger_structlog)", | ||
default_settings=_default_settings, | ||
) | ||
|
||
|
||
class StructLogCapLog(PrintLogger): | ||
def __init__(self, caplog): | ||
self.caplog = caplog if caplog is not None else [] | ||
|
||
def msg(self, event, **kwargs): | ||
self.caplog.append(event) | ||
return | ||
|
||
log = debug = info = warn = warning = msg | ||
fatal = failure = err = error = critical = exception = msg | ||
|
||
def __repr__(self): | ||
return "<StructLogCapLog %s>" % str(id(self)) | ||
|
||
__str__ = __repr__ | ||
|
||
|
||
@pytest.fixture | ||
def set_trace_ids(): | ||
def _set(): | ||
txn = current_transaction() | ||
if txn: | ||
txn._trace_id = "abcdefgh12345678" | ||
trace = current_trace() | ||
if trace: | ||
trace.guid = "abcdefgh" | ||
return _set | ||
|
||
def drop_event_processor(logger, method_name, event_dict): | ||
if method_name == "info": | ||
raise DropEvent | ||
else: | ||
return event_dict | ||
|
||
|
||
@pytest.fixture(scope="function") | ||
def structlog_caplog(): | ||
return list() | ||
|
||
|
||
@pytest.fixture(scope="function") | ||
def logger(structlog_caplog): | ||
import structlog | ||
structlog.configure(processors=[], logger_factory=lambda *args, **kwargs: StructLogCapLog(structlog_caplog)) | ||
_logger = structlog.get_logger() | ||
return _logger | ||
|
||
|
||
@pytest.fixture(scope="function") | ||
def filtering_logger(structlog_caplog): | ||
import structlog | ||
structlog.configure(processors=[drop_event_processor], logger_factory=lambda *args, **kwargs: StructLogCapLog(structlog_caplog)) | ||
_filtering_logger = structlog.get_logger() | ||
return _filtering_logger | ||
|
||
|
||
@pytest.fixture | ||
def exercise_logging_multiple_lines(set_trace_ids, logger, structlog_caplog): | ||
def _exercise(): | ||
set_trace_ids() | ||
|
||
logger.msg("Cat", a=42) | ||
logger.error("Dog") | ||
logger.critical("Elephant") | ||
|
||
assert len(structlog_caplog) == 3 | ||
|
||
assert "Cat" in structlog_caplog[0] | ||
assert "Dog" in structlog_caplog[1] | ||
assert "Elephant" in structlog_caplog[2] | ||
|
||
return _exercise | ||
|
||
|
||
@pytest.fixture | ||
def exercise_filtering_logging_multiple_lines(set_trace_ids, filtering_logger, structlog_caplog): | ||
def _exercise(): | ||
set_trace_ids() | ||
|
||
filtering_logger.msg("Cat", a=42) | ||
filtering_logger.error("Dog") | ||
filtering_logger.critical("Elephant") | ||
|
||
assert len(structlog_caplog) == 2 | ||
|
||
assert "Cat" not in structlog_caplog[0] | ||
assert "Dog" in structlog_caplog[0] | ||
assert "Elephant" in structlog_caplog[1] | ||
|
||
return _exercise | ||
|
||
|
||
@pytest.fixture | ||
def exercise_logging_single_line(set_trace_ids, logger, structlog_caplog): | ||
def _exercise(): | ||
set_trace_ids() | ||
logger.error("A", key="value") | ||
assert len(structlog_caplog) == 1 | ||
|
||
return _exercise |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,49 @@ | ||
# Copyright 2010 New Relic, Inc. | ||
# | ||
# 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 newrelic.api.background_task import background_task | ||
from testing_support.fixtures import override_application_settings, reset_core_stats_engine | ||
from testing_support.validators.validate_log_event_count import validate_log_event_count | ||
from testing_support.validators.validate_log_event_count_outside_transaction import validate_log_event_count_outside_transaction | ||
from testing_support.validators.validate_log_events import validate_log_events | ||
from testing_support.validators.validate_log_events_outside_transaction import validate_log_events_outside_transaction | ||
|
||
|
||
_event_attributes = {"message": "A", "context.key": "value"} | ||
|
||
|
||
@override_application_settings({ | ||
"application_logging.forwarding.context_data.enabled": True, | ||
}) | ||
def test_attributes_inside_transaction(exercise_logging_single_line): | ||
@validate_log_events([_event_attributes]) | ||
@validate_log_event_count(1) | ||
@background_task() | ||
def test(): | ||
exercise_logging_single_line() | ||
|
||
test() | ||
|
||
|
||
@reset_core_stats_engine() | ||
@override_application_settings({ | ||
"application_logging.forwarding.context_data.enabled": True, | ||
}) | ||
def test_attributes_outside_transaction(exercise_logging_single_line): | ||
@validate_log_events_outside_transaction([_event_attributes]) | ||
@validate_log_event_count_outside_transaction(1) | ||
def test(): | ||
exercise_logging_single_line() | ||
|
||
test() |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,54 @@ | ||
# Copyright 2010 New Relic, Inc. | ||
# | ||
# 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 platform | ||
|
||
from newrelic.api.application import application_settings | ||
from newrelic.api.background_task import background_task | ||
from testing_support.fixtures import reset_core_stats_engine | ||
from testing_support.validators.validate_log_event_count import validate_log_event_count | ||
from testing_support.validators.validate_log_event_count_outside_transaction import validate_log_event_count_outside_transaction | ||
|
||
|
||
def get_metadata_string(log_message, is_txn): | ||
host = platform.uname()[1] | ||
assert host | ||
entity_guid = application_settings().entity_guid | ||
if is_txn: | ||
metadata_string = "".join(('NR-LINKING|', entity_guid, '|', host, '|abcdefgh12345678|abcdefgh|Python%20Agent%20Test%20%28logger_structlog%29|')) | ||
else: | ||
metadata_string = "".join(('NR-LINKING|', entity_guid, '|', host, '|||Python%20Agent%20Test%20%28logger_structlog%29|')) | ||
formatted_string = log_message + " " + metadata_string | ||
return formatted_string | ||
|
||
|
||
@reset_core_stats_engine() | ||
def test_local_log_decoration_inside_transaction(exercise_logging_single_line, structlog_caplog): | ||
@validate_log_event_count(1) | ||
@background_task() | ||
def test(): | ||
exercise_logging_single_line() | ||
assert get_metadata_string('A', True) in structlog_caplog[0] | ||
|
||
test() | ||
|
||
|
||
@reset_core_stats_engine() | ||
def test_local_log_decoration_outside_transaction(exercise_logging_single_line, structlog_caplog): | ||
@validate_log_event_count_outside_transaction(1) | ||
def test(): | ||
exercise_logging_single_line() | ||
assert get_metadata_string('A', False) in structlog_caplog[0] | ||
|
||
test() |
Oops, something went wrong.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Since this is only used in two places I think it's preferable to hard code this directly into the test rather than abstracting it into a function. This would also reduce the complexity of the code (if-else logic) inside the test which reduces the risk of error within the test. While our tests tend to have a lot of complex logic which I'm not a fan of in general, I always try where I can to opt for some repetition over complexity.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
That's fair! We wouldn't be able to fully hardcode this into the tests since it includes variables like the host. We could construct the string each time in the inside and outside transaction tests though to skip the if-else logic. Another option is to move this into conftest as a fixture. This function is used in our other two logging test suites so they can import from this test suite and then we specify the test suite name in
Python%20Agent%20Test%20%28logger_structlog%29