fix(logs): don't choke on malformed attributes (#2780)

* fix(logs): don't choke on malformed attributes

* Replace malformed strings instead of dropping logs

* Add another test scenario

Author: solnic

.devcontainer/run

@@ -7,8 +7,8 @@ cd /workspace/sentry
 sudo mkdir -p vendor/gems
 sudo chown -R sentry:sentry vendor/gems
 
-git config --global --replace-all safe.directory /workspace/sentry
-git config --global --replace-all safe.directory /workspace/sentry/vendor/gems/*
+# git config --global --replace-all safe.directory /workspace/sentry
+# git config --global --replace-all safe.directory /workspace/sentry/vendor/gems/*
 
 sudo chown -R sentry:sentry .
 

sentry-ruby/lib/sentry/client.rb

@@ -197,9 +197,15 @@ def event_from_log(message, level:, **options)
       origin = options[:origin]
       body = Utils::EncodingHelper.safe_utf_8_string(message)
 
-      return unless body
+      sanitized_attributes = attributes.transform_values do |value|
+        if value.is_a?(String)
+          Utils::EncodingHelper.safe_utf_8_string(value)
+        else
+          value
+        end
+      end
 
-      LogEvent.new(level: level, body: body, attributes: attributes, origin: origin)
+      LogEvent.new(level: level, body: body, attributes: sanitized_attributes, origin: origin)
     end
 
     # Initializes an Event object with the given Transaction object.

sentry-ruby/lib/sentry/utils/encoding_helper.rb

@@ -4,6 +4,7 @@ module Sentry
   module Utils
     module EncodingHelper
       EMPTY_STRING = ""
+      MALFORMED_STRING = "<malformed-string>"
 
       def self.encode_to_utf_8(value)
         if value.encoding != Encoding::UTF_8 && value.respond_to?(:force_encoding)
@@ -21,7 +22,7 @@ def self.valid_utf_8?(value)
       end
 
       def self.safe_utf_8_string(value)
-        valid_utf_8?(value) && value
+        valid_utf_8?(value) ? value : MALFORMED_STRING
       end
     end
   end

sentry-ruby/spec/sentry/structured_logger_spec.rb

@@ -96,11 +96,52 @@
           expect(log_event[:attributes]["sentry.message.parameter.day"]).to eql({ value: "Monday", type: "string" })
         end
 
-        it "doesn't choke on malformed UTF-8 strings" do
-          malformed_string = "Hello World\x92".dup.force_encoding("UTF-8")
-          Sentry.logger.public_send(level, malformed_string, user_id: 123)
+        context "handling of malformed strings" do
+          let(:malformed_string_default) do
+            Sentry::Utils::EncodingHelper::MALFORMED_STRING
+          end
+
+          it "doesn't choke on malformed UTF-8 strings" do
+            malformed_string = "Hello World\x92".dup.force_encoding("UTF-8")
+            Sentry.logger.public_send(level, malformed_string, user_id: 123)
+
+            expect(sentry_logs).to_not be_empty
+
+            log_event = sentry_logs.last
+
+            expect(log_event[:level]).to eql(level)
+            expect(log_event[:body]).to eql(malformed_string_default)
+          end
+
+          it "doesn't choke on malformed UTF-8 in body and attributes" do
+            malformed_string = "Hello World %{user_agent} \x92".dup.force_encoding("UTF-8")
+            malformed_user_agent = "Mozilla/5.0 (compatible; Yahoo! Slurp; http://help.yahoo.com/help/us/ysearch/slurp\xA1\xB1)".dup.force_encoding("UTF-8")
+            Sentry.logger.public_send(level, malformed_string, user_agent: malformed_user_agent, user_id: 312)
+
+            expect(sentry_logs).to_not be_empty
 
-          expect(sentry_logs).to be_empty
+            log_event = sentry_logs.last
+
+            expect(log_event[:level]).to eql(level)
+            expect(log_event[:body]).to eql(malformed_string_default)
+
+            expect(log_event[:attributes]["sentry.message.parameter.user_id"]).to be_nil
+            expect(log_event[:attributes]["sentry.message.parameter.user_agent"]).to be_nil
+          end
+
+          it "doesn't choke on malformed UTF-8 in attributes" do
+            malformed_user_agent = "Mozilla/5.0 (compatible; Yahoo! Slurp; http://help.yahoo.com/help/us/ysearch/slurp\xA1\xB1)".dup.force_encoding("UTF-8")
+            Sentry.logger.public_send(level, "Valid message %{user_agent}", user_agent: malformed_user_agent)
+
+            expect(sentry_logs).to_not be_empty
+
+            log_event = sentry_logs.last
+
+            expect(log_event[:level]).to eql(level)
+            expect(log_event[:body]).to include("Valid message")
+            expect(log_event[:attributes]["sentry.message.parameter.user_agent"])
+              .to eql({ value: malformed_string_default, type: "string" })
+          end
         end
       end
     end