Skip to content

Commit aebf47f

Browse files
TimPansinoumaannamalaihmstepaneklrafeeimergify[bot]
authored
Logging Attributes (#1033)
* Log Forwarding User Attributes (#682) * Add context data setting Co-authored-by: Uma Annamalai <[email protected]> Co-authored-by: Hannah Stepanek <[email protected]> Co-authored-by: Lalleh Rafeei <[email protected]> * Update record_log_event signature with attributes * Logging attributes initial implementation * Fix settings attribute error * Update logging instrumentation with attributes * Update log handler API * Add loguru support for extra attrs * Add more explicit messaging to validator * Expanding testing for record_log_event * Expand record log event testing * Fix settings typo * Remove missing loguru attributes from test * Adjust safe log attr encoding * Correct py2 issues * Fix missing record attrs in logging. Co-authored-by: Uma Annamalai <[email protected]> Co-authored-by: Hannah Stepanek <[email protected]> Co-authored-by: Lalleh Rafeei <[email protected]> Co-authored-by: Hannah Stepanek <[email protected]> * Log Attribute Filtering (#1008) * Expand validator for log events * Add settings for context data filtering * Add attribute filtering for log events * Linting * Apply suggestions from code review * Remove none check on attributes * Squashed commit of the following: commit 3962f54 Author: Uma Annamalai <[email protected]> Date: Thu Jan 4 12:50:58 2024 -0800 Remove case sensitive check in ASGIBrowserMiddleware check. (#1017) * Remove case sensitive check in should_insert_html. * [Mega-Linter] Apply linters fixes * Remove header decoding. --------- Co-authored-by: umaannamalai <[email protected]> commit c3314ae Author: Lalleh Rafeei <[email protected]> Date: Tue Jan 2 17:17:20 2024 -0800 Temporarily pin hypercorn version in tests (#1021) * Temporarily pin hypercorn to <0.16 * Temporarily pin hypercorn to <0.16 * Add comment to tox.ini --------- Co-authored-by: mergify[bot] <37929162+mergify[bot]@users.noreply.github.com> commit 1357145 Author: Uma Annamalai <[email protected]> Date: Tue Jan 2 16:17:08 2024 -0800 Drop py27 from memcache testing. (#1018) commit 23f969f Author: Timothy Pansino <[email protected]> Date: Wed Dec 20 17:01:50 2023 -0800 Nonced CSP Support (#998) * Add nonce to CSP in browser agent * Adjust nonce position * Add testing for browser timing nonces commit 8bfd2b7 Author: Uma Annamalai <[email protected]> Date: Mon Dec 18 13:58:10 2023 -0800 Remove RPM config workflow. (#1007) * Add Dictionary Log Message Support (#1014) * Add tests for logging's json logging * Upgrade record_log_event to handle dict logging * Update logging to capture dict messages * Add attributes for dict log messages * Implementation of JSON message filtering * Correct attributes only log behavior * Testing for logging attributes * Add logging context test for py2 * Logically separate attribute tests * Clean out imports * Fix failing tests * Remove logging instrumentation changes for new PR * Add test for record log event edge cases * Update record_log_event for code review * Fix truncation * Move safe_json_encode back to api.log as it's unused elsewhere * Black formatting * Add missing import * Fixup warning message --------- Co-authored-by: mergify[bot] <37929162+mergify[bot]@users.noreply.github.com> * Logging Attribute Instrumentation (#1015) * Add tests for logging's json logging * Upgrade record_log_event to handle dict logging * Update logging to capture dict messages * Add attributes for dict log messages * Implementation of JSON message filtering * Correct attributes only log behavior * Testing for logging attributes * Add logging context test for py2 * Logically separate attribute tests * Clean out imports * Fix failing tests * Linting * Ignore path hash * Fix linter errors * Fix linting issues * Apply suggestions from code review * StructLog Attribute Instrumentation (#1026) * Add tests for logging's json logging * Upgrade record_log_event to handle dict logging * Update logging to capture dict messages * Add attributes for dict log messages * Implementation of JSON message filtering * Correct attributes only log behavior * Testing for logging attributes * Add logging context test for py2 * Logically separate attribute tests * Clean out imports * Fix failing tests * Structlog cleanup * Attempting list instrumentation * Structlog attributes support Co-authored-by: Lalleh Rafeei <[email protected]> Co-authored-by: Uma Annamalai <[email protected]> * Remove other frameworks changes * Bump tests * Change cache to lru cache * Linting * Remove TODO * Remove unnecessary check --------- Co-authored-by: Lalleh Rafeei <[email protected]> Co-authored-by: Uma Annamalai <[email protected]> * Loguru Attribute Instrumentation (#1025) * Add tests for logging's json logging * Upgrade record_log_event to handle dict logging * Update logging to capture dict messages * Add attributes for dict log messages * Implementation of JSON message filtering * Correct attributes only log behavior * Testing for logging attributes * Add logging context test for py2 * Logically separate attribute tests * Clean out imports * Fix failing tests * Structlog cleanup * Attempting list instrumentation * Structlog attributes support Co-authored-by: Lalleh Rafeei <[email protected]> Co-authored-by: Uma Annamalai <[email protected]> * Loguru instrumentation refactor * New attribute testing * Move exception settings * Clean up testing * Remove unneeded option * Remove other framework changes * [Mega-Linter] Apply linters fixes * Bump tests --------- Co-authored-by: Lalleh Rafeei <[email protected]> Co-authored-by: Uma Annamalai <[email protected]> Co-authored-by: TimPansino <[email protected]> Co-authored-by: mergify[bot] <37929162+mergify[bot]@users.noreply.github.com> * Temporarily pin starlette tests * Update web_transaction.py --------- Co-authored-by: Uma Annamalai <[email protected]> Co-authored-by: Hannah Stepanek <[email protected]> Co-authored-by: Lalleh Rafeei <[email protected]> Co-authored-by: Hannah Stepanek <[email protected]> Co-authored-by: mergify[bot] <37929162+mergify[bot]@users.noreply.github.com> Co-authored-by: TimPansino <[email protected]>
1 parent 9990e71 commit aebf47f

33 files changed

+1208
-503
lines changed

newrelic/api/application.py

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -22,7 +22,6 @@
2222

2323

2424
class Application(object):
25-
2625
_lock = threading.Lock()
2726
_instances = {}
2827

@@ -162,9 +161,11 @@ def record_transaction(self, data):
162161
if self.active:
163162
self._agent.record_transaction(self._name, data)
164163

165-
def record_log_event(self, message, level=None, timestamp=None, priority=None):
164+
def record_log_event(self, message, level=None, timestamp=None, attributes=None, priority=None):
166165
if self.active:
167-
self._agent.record_log_event(self._name, message, level, timestamp, priority=priority)
166+
self._agent.record_log_event(
167+
self._name, message, level, timestamp, attributes=attributes, priority=priority
168+
)
168169

169170
def normalize_name(self, name, rule_type="url"):
170171
if self.active:

newrelic/api/log.py

Lines changed: 41 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -21,9 +21,11 @@
2121
from newrelic.api.time_trace import get_linking_metadata
2222
from newrelic.api.transaction import current_transaction, record_log_event
2323
from newrelic.common import agent_http
24+
from newrelic.common.encoding_utils import json_encode
2425
from newrelic.common.object_names import parse_exc_info
2526
from newrelic.core.attribute import truncate
2627
from newrelic.core.config import global_settings, is_expected_error
28+
from newrelic.packages import six
2729

2830

2931
def format_exc_info(exc_info):
@@ -42,8 +44,30 @@ def format_exc_info(exc_info):
4244
return formatted
4345

4446

47+
def safe_json_encode(obj, ignore_string_types=False, **kwargs):
48+
# Performs the same operation as json_encode but replaces unserializable objects with a string containing their class name.
49+
# If ignore_string_types is True, do not encode string types further.
50+
# Currently used for safely encoding logging attributes.
51+
52+
if ignore_string_types and isinstance(obj, (six.string_types, six.binary_type)):
53+
return obj
54+
55+
# Attempt to run through JSON serialization
56+
try:
57+
return json_encode(obj, **kwargs)
58+
except Exception:
59+
pass
60+
61+
# If JSON serialization fails then return a repr
62+
try:
63+
return repr(obj)
64+
except Exception:
65+
# If repr fails then default to an unprinatable object name
66+
return "<unprintable %s object>" % type(obj).__name__
67+
68+
4569
class NewRelicContextFormatter(Formatter):
46-
DEFAULT_LOG_RECORD_KEYS = frozenset(vars(LogRecord("", 0, "", 0, "", (), None)))
70+
DEFAULT_LOG_RECORD_KEYS = frozenset(set(vars(LogRecord("", 0, "", 0, "", (), None))) | {"message"})
4771

4872
def __init__(self, *args, **kwargs):
4973
super(NewRelicContextFormatter, self).__init__()
@@ -76,17 +100,12 @@ def log_record_to_dict(cls, record):
76100
return output
77101

78102
def format(self, record):
79-
def safe_str(object, *args, **kwargs):
80-
"""Convert object to str, catching any errors raised."""
81-
try:
82-
return str(object, *args, **kwargs)
83-
except:
84-
return "<unprintable %s object>" % type(object).__name__
85-
86-
return json.dumps(self.log_record_to_dict(record), default=safe_str, separators=(",", ":"))
103+
return json.dumps(self.log_record_to_dict(record), default=safe_json_encode, separators=(",", ":"))
87104

88105

89106
class NewRelicLogForwardingHandler(logging.Handler):
107+
DEFAULT_LOG_RECORD_KEYS = frozenset(set(vars(LogRecord("", 0, "", 0, "", (), None))) | {"message"})
108+
90109
def emit(self, record):
91110
try:
92111
# Avoid getting local log decorated message
@@ -95,10 +114,20 @@ def emit(self, record):
95114
else:
96115
message = record.getMessage()
97116

98-
record_log_event(message, record.levelname, int(record.created * 1000))
117+
attrs = self.filter_record_attributes(record)
118+
record_log_event(message, record.levelname, int(record.created * 1000), attributes=attrs)
99119
except Exception:
100120
self.handleError(record)
101121

122+
@classmethod
123+
def filter_record_attributes(cls, record):
124+
record_attrs = vars(record)
125+
DEFAULT_LOG_RECORD_KEYS = cls.DEFAULT_LOG_RECORD_KEYS
126+
if len(record_attrs) > len(DEFAULT_LOG_RECORD_KEYS):
127+
return {k: v for k, v in six.iteritems(vars(record)) if k not in DEFAULT_LOG_RECORD_KEYS}
128+
else:
129+
return None
130+
102131

103132
class NewRelicLogHandler(logging.Handler):
104133
"""
@@ -126,8 +155,8 @@ def __init__(
126155
"The contributed NewRelicLogHandler has been superseded by automatic instrumentation for "
127156
"logging in the standard lib. If for some reason you need to manually configure a handler, "
128157
"please use newrelic.api.log.NewRelicLogForwardingHandler to take advantage of all the "
129-
"features included in application log forwarding such as proper batching.",
130-
DeprecationWarning
158+
"features included in application log forwarding such as proper batching.",
159+
DeprecationWarning,
131160
)
132161
super(NewRelicLogHandler, self).__init__(level=level)
133162
self.license_key = license_key or self.settings.license_key

newrelic/api/transaction.py

Lines changed: 55 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -54,6 +54,7 @@
5454
create_attributes,
5555
create_user_attributes,
5656
process_user_attribute,
57+
resolve_logging_context_attributes,
5758
truncate,
5859
)
5960
from newrelic.core.attribute_filter import (
@@ -1524,7 +1525,7 @@ def set_transaction_name(self, name, group=None, priority=None):
15241525
self._group = group
15251526
self._name = name
15261527

1527-
def record_log_event(self, message, level=None, timestamp=None, priority=None):
1528+
def record_log_event(self, message, level=None, timestamp=None, attributes=None, priority=None):
15281529
settings = self.settings
15291530
if not (
15301531
settings
@@ -1537,18 +1538,62 @@ def record_log_event(self, message, level=None, timestamp=None, priority=None):
15371538

15381539
timestamp = timestamp if timestamp is not None else time.time()
15391540
level = str(level) if level is not None else "UNKNOWN"
1541+
context_attributes = attributes # Name reassigned for clarity
15401542

1541-
if not message or message.isspace():
1542-
_logger.debug("record_log_event called where message was missing. No log event will be sent.")
1543-
return
1543+
# Unpack message and attributes from dict inputs
1544+
if isinstance(message, dict):
1545+
message_attributes = {k: v for k, v in message.items() if k != "message"}
1546+
message = message.get("message", "")
1547+
else:
1548+
message_attributes = None
1549+
1550+
if message is not None:
1551+
# Coerce message into a string type
1552+
if not isinstance(message, six.string_types):
1553+
try:
1554+
message = str(message)
1555+
except Exception:
1556+
# Exit early for invalid message type after unpacking
1557+
_logger.debug(
1558+
"record_log_event called where message could not be converted to a string type. No log event will be sent."
1559+
)
1560+
return
1561+
1562+
# Truncate the now unpacked and string converted message
1563+
message = truncate(message, MAX_LOG_MESSAGE_LENGTH)
1564+
1565+
# Collect attributes from linking metadata, context data, and message attributes
1566+
collected_attributes = {}
1567+
if settings and settings.application_logging.forwarding.context_data.enabled:
1568+
if context_attributes:
1569+
context_attributes = resolve_logging_context_attributes(
1570+
context_attributes, settings.attribute_filter, "context."
1571+
)
1572+
if context_attributes:
1573+
collected_attributes.update(context_attributes)
1574+
1575+
if message_attributes:
1576+
message_attributes = resolve_logging_context_attributes(
1577+
message_attributes, settings.attribute_filter, "message."
1578+
)
1579+
if message_attributes:
1580+
collected_attributes.update(message_attributes)
1581+
1582+
# Exit early if no message or attributes found after filtering
1583+
if (not message or message.isspace()) and not context_attributes and not message_attributes:
1584+
_logger.debug(
1585+
"record_log_event called where no message and no attributes were found. No log event will be sent."
1586+
)
1587+
return
15441588

1545-
message = truncate(message, MAX_LOG_MESSAGE_LENGTH)
1589+
# Finally, add in linking attributes after checking that there is a valid message or at least 1 attribute
1590+
collected_attributes.update(get_linking_metadata())
15461591

15471592
event = LogEventNode(
15481593
timestamp=timestamp,
15491594
level=level,
15501595
message=message,
1551-
attributes=get_linking_metadata(),
1596+
attributes=collected_attributes,
15521597
)
15531598

15541599
self._log_events.add(event, priority=priority)
@@ -2062,7 +2107,7 @@ def record_ml_event(event_type, params, application=None):
20622107
application.record_ml_event(event_type, params)
20632108

20642109

2065-
def record_log_event(message, level=None, timestamp=None, application=None, priority=None):
2110+
def record_log_event(message, level=None, timestamp=None, attributes=None, application=None, priority=None):
20662111
"""Record a log event.
20672112
20682113
Args:
@@ -2073,12 +2118,12 @@ def record_log_event(message, level=None, timestamp=None, application=None, prio
20732118
if application is None:
20742119
transaction = current_transaction()
20752120
if transaction:
2076-
transaction.record_log_event(message, level, timestamp)
2121+
transaction.record_log_event(message, level, timestamp, attributes=attributes)
20772122
else:
20782123
application = application_instance(activate=False)
20792124

20802125
if application and application.enabled:
2081-
application.record_log_event(message, level, timestamp, priority=priority)
2126+
application.record_log_event(message, level, timestamp, attributes=attributes, priority=priority)
20822127
else:
20832128
_logger.debug(
20842129
"record_log_event has been called but no transaction or application was running. As a result, "
@@ -2089,7 +2134,7 @@ def record_log_event(message, level=None, timestamp=None, application=None, prio
20892134
timestamp,
20902135
)
20912136
elif application.enabled:
2092-
application.record_log_event(message, level, timestamp, priority=priority)
2137+
application.record_log_event(message, level, timestamp, attributes=attributes, priority=priority)
20932138

20942139

20952140
def accept_distributed_trace_payload(payload, transport_type="HTTP"):

0 commit comments

Comments
 (0)