fix: avoid generating invalid events by truncating string attributes when converting log entries to events

README.md

@@ -1249,6 +1249,10 @@ Salesforce event log file data is mapped to New Relic data as follows.
        types from the [numeric fields mapping file](#numeric-fields-mapping-file),
        is converted to a numeric value. If the conversion fails, the value
        remains as a string.
+    1. String attributes (including non-numeric strings for fields specified in
+       the [numeric fields mapping file](#numeric-fields-mapping-file)) that
+       have a length greater than 4096 characters are automatically truncated to
+       4096 characters.
     1. The `eventType` of the event is set to the `EVENT_TYPE` attribute.
 
 Below is an example of an `EventLogFile` record, a single log message, and the
@@ -1666,6 +1670,11 @@ Query records are mapped to New Relic data as follows.
        `timestamp`, the `timestamp` for the New Relic log entry is set to the
        calculated timestamp value. Otherwise, the time of ingestion will be used
        as the timestamp of the log entry.
+1. If the target New Relic data type is an event, the calculated log entry is
+   converted to an event as described in the [event log file data mapping](#event-log-file-data-mapping),
+   with the exception that the `eventType` of the event is set to the value
+   `UnknownSFEvent` if the `EVENT_TYPE` attribute is not set in the `attributes`
+   of the calculated log entry.
 
 Below is an example of an SOQL query, a query result record, and the New Relic
 log entry or New Relic event that would result from the above transformation.
@@ -1836,6 +1845,14 @@ Limits data is mapped to New Relic data as follows.
     1. The `timestamp` for the New Relic log entry is set to the current time in
        milliseconds since the epoch.
 
+1. If the target New Relic data type is an event, the calculated log entry is
+   converted to an event as described in the [event log file data mapping](#event-log-file-data-mapping).
+
+   **NOTE:** While numeric field mapping conversion is applied to events
+   generated from the calculated log entries for limits data, there are no
+   attributes with non-numeric string values in log entries for limits data so
+   no conversion will be performed.
+
 Below is an example of an abridged result returned from the
 the [limits API](https://developer.salesforce.com/docs/atlas.en-us.api_rest.meta/api_rest/resources_limits.htm).
 and the New Relic log entry or New Relic event that would result from the above

src/newrelic_logging/__init__.py

@@ -3,7 +3,7 @@
 
 # Integration definitions
 
-VERSION         = "2.7.0"
+VERSION         = "2.7.1"
 NAME            = "salesforce-exporter"
 PROVIDER        = "newrelic-labs"
 COLLECTOR_NAME  = "newrelic-salesforce-exporter"

src/newrelic_logging/pipeline.py

@@ -7,7 +7,7 @@
 from .http_session import new_retry_session
 from .newrelic import NewRelic
 from .telemetry import print_info
-from .util import maybe_convert_str_to_num
+from .util import maybe_convert_str_to_num, maybe_truncate_str
 
 
 DEFAULT_MAX_ROWS = 1000
@@ -70,11 +70,11 @@ def pack_log_into_event(
 
         if key in numeric_fields_list:
             log_event[key] = \
-                maybe_convert_str_to_num(value) if value \
+                maybe_truncate_str(maybe_convert_str_to_num(value)) if value \
                 else 0
             continue
 
-        log_event[key] = value
+        log_event[key] = maybe_truncate_str(value)
 
     log_event.update(labels)
     log_event['eventType'] = log_event.get('EVENT_TYPE', "UnknownSFEvent")

src/newrelic_logging/util.py

@@ -49,6 +49,14 @@ def maybe_convert_str_to_num(val: str) -> Union[int, str, float]:
             return val
 
 
+def maybe_truncate_str(val: Any) -> Any:
+    if isinstance(val, str):
+        if len(val) > 4096:
+            return val[0:4096]
+
+    return val
+
+
 def is_primitive(val: Any) -> bool:
     vt = type(val)
 

src/tests/test_pipeline.py

@@ -228,29 +228,88 @@ def test_pack_log_into_event_returns_event_given_log_labels_and_numeric_fields_s
             in the 'attributes' field of the log
         and: an 'eventType' property set to the value of the `EVENT_TYPE`
             property of the log entry
-        and: attribute values for fields specified in the numeric fields set
-            are converted to numeric values
+        and: numeric string values for fields specified in the numeric fields
+            set are converted to numeric values
+        and: non-numeric string values for fields specified in the numeric
+            fields set are not converted to numeric values and are properly
+            truncated
         '''
 
         # setup
+        log_line = copy.deepcopy(self.log_lines[0])
+
+        # set one of the fields to a numeric floating point string value
+        log_line['REQUEST_SIZE'] = '8192.5'
+
+        # generate long strings to test that non-numeric string values for
+        # fields specified in the numeric fields set are properly truncated at
+        # 4096 characters - one that is exactly 4096 characters and one that is
+        # greater than 4096 characters
+        s = ''.join(['a' for _ in range(4096)])
+        t = ''.join(['b' for _ in range(5000)])
+
+        # manually generate the truncated value for `t` to test that the value
+        # is properly truncated when returned in the event
+        t1 = t[0:4096]
+
+        # replace two of the existing string fields with the generated long
+        # string values
+        log_line['SESSION_KEY'] = s
+        log_line['LOGIN_KEY'] = t
+
         log = {
             'message': 'Foo and Bar',
-            'attributes': self.log_lines[0]
+            'attributes': log_line,
         }
 
         # execute
         event = pipeline.pack_log_into_event(
             log,
             { 'foo': 'bar' },
-            set(['RUN_TIME', 'CPU_TIME', 'SUCCESS', 'URI']),
+            set([
+                'RUN_TIME',
+                'CPU_TIME',
+                'SUCCESS',
+                'REQUEST_SIZE',
+                'URI',
+                'SESSION_KEY',
+                'LOGIN_KEY',
+            ]),
         )
 
         # verify
-        self.assertEqual(len(event), len(self.log_lines[0]) + 2)
+        self.assertEqual(len(event), len(log_line) + 2)
+        self.assertTrue('eventType' in event)
+        self.assertEqual(event['eventType'], 'ApexCallout')
+        self.assertTrue('foo' in event)
+        self.assertEqual(event['foo'], 'bar')
+        self.assertTrue('RUN_TIME' in event)
         self.assertTrue(type(event['RUN_TIME']) == int)
+        self.assertEqual(event['RUN_TIME'], 2112)
+        self.assertTrue('CPU_TIME' in event)
         self.assertTrue(type(event['CPU_TIME']) == int)
+        self.assertEqual(event['CPU_TIME'], 10)
+        self.assertTrue('SUCCESS' in event)
         self.assertTrue(type(event['SUCCESS']) == int)
+        self.assertEqual(event['SUCCESS'], 1)
+        self.assertTrue('REQUEST_SIZE' in event)
+        self.assertTrue(type(event['REQUEST_SIZE']) == float)
+        self.assertEqual(event['REQUEST_SIZE'], 8192.5)
+        # non-numeric string value < 4096
+        self.assertTrue('URI' in event)
         self.assertTrue(type(event['URI']) == str)
+        self.assertEqual(len(event['URI']), len(log_line['URI']))
+        self.assertEqual(event['URI'], 'TEST-LOG-1')
+        # non-numeric string value == 4096
+        self.assertTrue('SESSION_KEY' in event)
+        self.assertTrue(type(event['SESSION_KEY']) == str)
+        self.assertEqual(len(event['SESSION_KEY']), 4096)
+        self.assertEqual(event['SESSION_KEY'], s)
+        # non-numeric string value > 4096
+        self.assertTrue('LOGIN_KEY' in event)
+        self.assertTrue(type(event['LOGIN_KEY']) == str)
+        self.assertEqual(len(event['LOGIN_KEY']), 4096)
+        self.assertEqual(event['LOGIN_KEY'], t1)
 
     def test_pack_log_into_event_returns_event_with_default_event_type_given_log_labels_and_empty_numeric_fields_set(self):
         '''
@@ -288,6 +347,53 @@ def test_pack_log_into_event_returns_event_with_default_event_type_given_log_lab
         self.assertTrue('eventType' in event)
         self.assertEqual(event['eventType'], 'UnknownSFEvent')
 
+    def test_pack_log_into_event_returns_event_with_default_event_type_and_truncates_strings_given_log_labels_and_empty_numeric_fields_set(self):
+        '''
+        pack_log_into_event() returns an event with properties for each attribute in the given log entry and the default event type where no attributes are converted to numeric values and strings are truncated to 4096 characters
+        given: a single log entry
+        and given: a dict of key:value pairs to use as labels
+        and given: a set of numeric field names
+        when: pack_log_into_event() is called
+        and when: the set of numeric field names is the empty set
+        and when: the log entry does not contain an 'EVENT_TYPE' property
+        and when: the log entry contains strings with length greater than 4096 characters
+        then: return a single event with a property for each attribute specified
+            in the 'attributes' field of the log
+        and: an 'eventType' property set to the default event type
+        and: the strings are truncated to 4096 characters
+        '''
+
+        # setup
+        s = ''.join(['0' for _ in range(5000)])
+        s1 = s[0:4096]
+        t = ''.join(['1' for _ in range(6000)])
+        t1 = t[0:4096]
+
+        log = {
+            'message': 'Foo and Bar',
+            'attributes': {'s': s, 't': t}
+        }
+
+        # execute
+        event = pipeline.pack_log_into_event(
+            log,
+            { 'foo': 'bar' },
+            set(),
+        )
+
+        # verify
+        self.assertEqual(len(event), 4)
+        self.assertTrue('eventType' in event)
+        self.assertEqual(event['eventType'], 'UnknownSFEvent')
+        self.assertTrue('foo' in event)
+        self.assertEqual(event['foo'], 'bar')
+        self.assertTrue('s' in event)
+        self.assertEqual(len(event['s']), 4096)
+        self.assertEqual(event['s'], s1)
+        self.assertTrue('t' in event)
+        self.assertEqual(len(event['t']), 4096)
+        self.assertEqual(event['t'], t1)
+
     def test_load_as_events_sends_one_request_when_log_entries_less_than_max_rows(self):
         '''
         load_as_events() sends a single Events API request when the number of log entries is less than max rows

src/tests/test_util.py

@@ -206,6 +206,81 @@ def test_maybe_convert_str_to_num(self):
         self.assertTrue(type(val) is str)
         self.assertEqual(val, 'not a number')
 
+    def test_maybe_truncate_str_non_string(self):
+        '''
+        maybe_truncate_str() returns input value given input value is not a string
+        given: an input value
+        when: maybe_truncate_str() is called
+        and when: the input value is not a string
+        then: returns the input value
+        '''
+
+        # execute
+        val = util.maybe_truncate_str(17)
+
+        # verify
+        self.assertIsInstance(val, int)
+        self.assertEqual(val, 17)
+
+    def test_maybe_truncate_str_string_length_less_than_4096(self):
+        '''
+        maybe_truncate_str() returns input value given input value is a string of less than 4096 characters in length
+        given: an input value
+        when: maybe_truncate_str() is called
+        and when: the input value is a string
+        and when: the length of the string is less than 4096 characters
+        then: returns the string
+        '''
+
+        # execute
+        val = util.maybe_truncate_str('this is not a long string')
+
+        # verify
+        self.assertIsInstance(val, str)
+        self.assertEqual(val, 'this is not a long string')
+
+    def test_maybe_truncate_str_string_length_equal_to_4096(self):
+        '''
+        maybe_truncate_str() returns input value given input value is a string of exactly 4096 characters in length
+        given: an input value
+        when: maybe_truncate_str() is called
+        and when: the input value is a string
+        and when: the length of the string is equal to 4096 characters
+        then: returns the string
+        '''
+
+        # setup
+        s = ''.join(['0' for _ in range(4096)])
+
+        # execute
+        val = util.maybe_truncate_str(s)
+
+        # verify
+        self.assertIsInstance(val, str)
+        self.assertEqual(val, s)
+
+    def test_maybe_truncate_str_string_length_greater_than_4096(self):
+        '''
+        maybe_truncate_str() returns input value truncated to 4096 characters in length given input value is a string greater than 4096 characters in length
+        given: an input value
+        when: maybe_truncate_str() is called
+        and when: the input value is a string
+        and when: the length of the string is greater than 4096 characters
+        then: returns the string truncated to 4096 characters in length
+        '''
+
+        # setup
+        s = ''.join(['0' for _ in range(5000)])
+        s1 = s[0:4096]
+
+        # execute
+        val = util.maybe_truncate_str(s)
+
+        # verify
+        self.assertIsInstance(val, str)
+        self.assertEqual(len(val), 4096)
+        self.assertEqual(val, s1)
+
     def test_get_iso_date_with_offset(self):
         _now = datetime.utcnow()