Handle more extra attribute types when logging (#2815)

* Handle params or nested objects correctly

* Add tests

* Update CHANGELOG.md

---------

Co-authored-by: Vivek <[email protected]>

Author: solnic

CHANGELOG.md

@@ -34,6 +34,11 @@
 ### Bug Fixes
 
 - Handle empty frames case gracefully with local vars ([#2807](https://github.com/getsentry/sentry-ruby/pull/2807))
+- Handle more extra attribute types when using `extra` attributes for structured logging ([#2815](https://github.com/getsentry/sentry-ruby/pull/2815))
+  ```ruby
+  # This now works too and the nested hash is dumped to JSON string
+  Sentry.logger.info("Hello World", extra: { today: Date.today, user_id: user.id })
+  ```
 
 ## 6.2.0
 
@@ -544,7 +549,6 @@
 - Use `Concurrent.available_processor_count` instead of `Concurrent.usable_processor_count` ([#2358](https://github.com/getsentry/sentry-ruby/pull/2358))
 
 - Support for tracing Faraday requests ([#2345](https://github.com/getsentry/sentry-ruby/pull/2345))
-
   - Closes [#1795](https://github.com/getsentry/sentry-ruby/issues/1795)
   - Please note that the Faraday instrumentation has some limitations in case of async requests: <https://github.com/lostisland/faraday/issues/1381>
 
@@ -567,7 +571,6 @@
   ```
 
 - Transaction data are now included in the context ([#2365](https://github.com/getsentry/sentry-ruby/pull/2365))
-
   - Closes [#2363](https://github.com/getsentry/sentry-ruby/issues/2363)
 
 - Inject Sentry meta tags in the Rails application layout automatically in the generator ([#2369](https://github.com/getsentry/sentry-ruby/pull/2369))
@@ -681,7 +684,6 @@
 - Fix warning about default gems on Ruby 3.3.0 ([#2225](https://github.com/getsentry/sentry-ruby/pull/2225))
 - Add `hint:` support to `Sentry::Rails::ErrorSubscriber` [#2235](https://github.com/getsentry/sentry-ruby/pull/2235)
 - Add [Metrics](https://docs.sentry.io/product/metrics/) support
-
   - Add main APIs and `Aggregator` thread [#2247](https://github.com/getsentry/sentry-ruby/pull/2247)
   - Add `Sentry::Metrics.timing` API for measuring block duration [#2254](https://github.com/getsentry/sentry-ruby/pull/2254)
   - Add metric summaries on spans [#2255](https://github.com/getsentry/sentry-ruby/pull/2255)
@@ -841,7 +843,6 @@
 - Improve default slug generation for Crons [#2168](https://github.com/getsentry/sentry-ruby/pull/2168)
 - Change release name generator to use full SHA commit hash and align with `sentry-cli` and other Sentry SDKs [#2174](https://github.com/getsentry/sentry-ruby/pull/2174)
 - Automatic Crons support for scheduling gems
-
   - Add support for [`sidekiq-cron`](https://github.com/sidekiq-cron/sidekiq-cron) [#2170](https://github.com/getsentry/sentry-ruby/pull/2170)
 
     You can opt in to the `sidekiq-cron` patch and we will automatically monitor check-ins for all jobs listed in your `config/schedule.yml` file.
@@ -897,7 +898,6 @@
 - Adopt Rails 7.1's new BroadcastLogger [#2120](https://github.com/getsentry/sentry-ruby/pull/2120)
 - Support sending events after all retries were performed (sentry-resque) [#2087](https://github.com/getsentry/sentry-ruby/pull/2087)
 - Add [Cron Monitoring](https://docs.sentry.io/product/crons/) support
-
   - Add `Sentry.capture_check_in` API for Cron Monitoring [#2117](https://github.com/getsentry/sentry-ruby/pull/2117)
 
     You can now track progress of long running scheduled jobs.
@@ -980,7 +980,6 @@
   ```
 
 - Tracing without Performance
-
   - Implement `PropagationContext` on `Scope` and add `Sentry.get_trace_propagation_headers` API [#2084](https://github.com/getsentry/sentry-ruby/pull/2084)
   - Implement `Sentry.continue_trace` API [#2089](https://github.com/getsentry/sentry-ruby/pull/2089)
 
@@ -1067,7 +1066,6 @@
   ```
 
   Some implementation caveats:
-
   - Profiles are sampled **relative** to traces, so if both rates are 0.5, we will capture 0.25 of all requests.
   - Profiles are only captured for code running within a transaction.
   - Profiles for multi-threaded servers like `puma` might not capture frames correctly when async I/O is happening. This is a `stackprof` limitation.
@@ -1152,7 +1150,6 @@
 - Expose `end_timestamp` in `Span#finish` and `Transaction#finish` [#1946](https://github.com/getsentry/sentry-ruby/pull/1946)
 - Add `Transaction#set_context` api [#1947](https://github.com/getsentry/sentry-ruby/pull/1947)
 - Add OpenTelemetry support with new `sentry-opentelemetry` gem
-
   - Add `config.instrumenter` to switch between `:sentry` and `:otel` instrumentation [#1944](https://github.com/getsentry/sentry-ruby/pull/1944)
 
     The new `sentry-opentelemetry` gem adds support to automatically integrate OpenTelemetry performance tracing with Sentry. [Give it a try](https://github.com/getsentry/sentry-ruby/tree/master/sentry-opentelemetry#getting-started) and let us know if you have any feedback or problems with using it.
@@ -1172,7 +1169,6 @@
   ```
 
 - Use `Sentry.with_child_span` in redis and net/http instead of `span.start_child` [#1920](https://github.com/getsentry/sentry-ruby/pull/1920)
-
   - This might change the nesting of some spans and make it more accurate
   - Followup fix to set the sentry-trace header in the correct place [#1922](https://github.com/getsentry/sentry-ruby/pull/1922)
 
@@ -1201,14 +1197,12 @@
 ### Features
 
 - Support rack 3 [#1884](https://github.com/getsentry/sentry-ruby/pull/1884)
-
   - We no longer need the `HTTP_VERSION` check for ignoring the header
 
 - Add [Dynamic Sampling](https://docs.sentry.io/product/sentry-basics/sampling/) support
   The SDK now supports Sentry's Dynamic Sampling product.
 
   Note that this is not supported for users still using the `config.async` option.
-
   - Parse incoming [W3C Baggage Headers](https://www.w3.org/TR/baggage/) and propagate them to continue traces [#1869](https://github.com/getsentry/sentry-ruby/pull/1869)
     - in all outgoing requests in our net/http patch
     - in Sentry transactions as [Dynamic Sampling Context](https://develop.sentry.dev/sdk/performance/dynamic-sampling-context/)
@@ -1244,7 +1238,6 @@
 - Expose `:values` in `ExceptionInterface`, so that it can be accessed in `before_send` under `event.exception.values` [#1843](https://github.com/getsentry/sentry-ruby/pull/1843)
 
 - Add top level `Sentry.close` API [#1844](https://github.com/getsentry/sentry-ruby/pull/1844)
-
   - Cleans up SDK state and sets it to uninitialized
   - No-ops all SDK APIs and also disables the transport layer, so nothing will be sent to Sentry after closing the SDK
 
@@ -1406,7 +1399,6 @@ end
 - Check envelope size before sending it [#1747](https://github.com/getsentry/sentry-ruby/pull/1747)
 
   The SDK will now check if the envelope's event items are oversized before sending the envelope. It goes like this:
-
   1. If an event is oversized (200kb), the SDK will remove its breadcrumbs (which in our experience is the most common cause).
   2. If the event size now falls within the limit, it'll be sent.
   3. Otherwise, the event will be thrown away. The SDK will also log a debug message about the event's attributes size (in bytes) breakdown. For example,
@@ -1725,7 +1717,6 @@ When `config.send_default_pii` is set as `true`, `:http_logger` will include que
 ### Features
 
 - Support exception frame's local variable capturing
-
   - [#1580](https://github.com/getsentry/sentry-ruby/pull/1580)
   - [#1589](https://github.com/getsentry/sentry-ruby/pull/1589)
 

sentry-rails/spec/sentry/rails/log_subscribers/action_controller_subscriber_spec.rb

@@ -34,7 +34,7 @@
 
         expect(log_event[:attributes][:method][:value]).to eq("GET")
         expect(log_event[:attributes][:path][:value]).to eq("/world")
-        expect(log_event[:attributes][:format][:value]).to eq(:html)
+        expect(log_event[:attributes][:format][:value]).to eq("\"html\"")
         expect(log_event[:attributes]["sentry.origin"][:value]).to eq("auto.log.rails.log_subscriber")
       end
 
@@ -275,8 +275,10 @@
           log_event = sentry_logs.find { |log| log[:body] == "HelloController#world" }
           expect(log_event).not_to be_nil
           expect(log_event[:attributes][:params]).to be_present
-          expect(log_event[:attributes][:params][:value]).to include("safe_param" => "value")
-          expect(log_event[:attributes][:params][:value]).to include("password" => "[FILTERED]")
+
+          params = JSON.parse(log_event[:attributes][:params][:value])
+          expect(params).to include("safe_param" => "value")
+          expect(params).to include("password" => "[FILTERED]")
         end
 
         it "filters sensitive parameter names" do
@@ -295,7 +297,7 @@
           log_event = sentry_logs.find { |log| log[:body] == "HelloController#world" }
           expect(log_event).not_to be_nil
 
-          params = log_event[:attributes][:params][:value]
+          params = JSON.parse(log_event[:attributes][:params][:value])
           expect(params).to include("normal_param" => "value")
           expect(params).to include("password" => "[FILTERED]")
           expect(params).to include("api_key" => "[FILTERED]")
@@ -323,7 +325,7 @@
           log_event = sentry_logs.find { |log| log[:body] == "HelloController#world" }
           expect(log_event).not_to be_nil
 
-          params = log_event[:attributes][:params][:value]
+          params = JSON.parse(log_event[:attributes][:params][:value])
           expect(params).to include("normal_param" => "value")
           expect(params["user"]).to include("name" => "John")
           expect(params["user"]).to include("password" => "[FILTERED]")

sentry-rails/spec/sentry/rails/log_subscribers/action_mailer_subscriber_spec.rb

@@ -37,7 +37,7 @@
         expect(log_event[:attributes][:mailer][:value]).to eq("UserMailer")
         expect(log_event[:attributes][:duration_ms][:value]).to be > 0
         expect(log_event[:attributes][:perform_deliveries][:value]).to be true
-        expect(log_event[:attributes][:delivery_method][:value]).to eq(:test)
+        expect(log_event[:attributes][:delivery_method][:value]).to eq("\"test\"")
         expect(log_event[:attributes]["sentry.origin"][:value]).to eq("auto.log.rails.log_subscriber")
         expect(log_event[:attributes][:date]).to be_present
       end
@@ -76,7 +76,7 @@
 
         log_event = sentry_logs.find { |log| log[:body] == "Email delivered via NotificationMailer" }
         expect(log_event).not_to be_nil
-        expect(log_event[:attributes][:delivery_method][:value]).to eq(:smtp)
+        expect(log_event[:attributes][:delivery_method][:value]).to eq("\"smtp\"")
       end
 
       it "includes date when available" do
@@ -179,12 +179,12 @@
           expect(log_event).not_to be_nil
           expect(log_event[:attributes][:params]).to be_present
 
-          params = log_event[:attributes][:params][:value]
+          params = JSON.parse(log_event[:attributes][:params][:value])
 
-          expect(params).to include(user_id: 123, safe_param: "value")
-          expect(params[:password]).to eq("[FILTERED]")
-          expect(params[:api_key]).to eq("[FILTERED]")
-          expect(params).to include(email_address: "[email protected]", subject: "Welcome!")
+          expect(params).to include("user_id" => 123, "safe_param" => "value")
+          expect(params["password"]).to eq("[FILTERED]")
+          expect(params["api_key"]).to eq("[FILTERED]")
+          expect(params).to include("email_address" => "[email protected]", "subject" => "Welcome!")
         end
       end
 

sentry-rails/spec/sentry/rails/log_subscribers/active_job_subscriber_spec.rb

@@ -57,7 +57,7 @@
         expect(attributes[:job_id][:value]).to be_a(String)
         expect(attributes[:queue_name][:value]).to eq("default")
         expect(attributes[:executions][:value]).to eq(1)
-        expect(attributes[:priority][:value]).to be_a(Integer).or be_nil
+        expect(attributes[:priority][:value]).to be_a(Integer).or(eq("null")).or be_nil
       end
 
       it "includes adapter information when available" do
@@ -122,8 +122,9 @@ def perform(*args, **kwargs)
           expect(log_event).not_to be_nil
 
           attributes = log_event[:attributes]
-          expect(attributes[:arguments][:value]).to be_a(Array)
-          expect(attributes[:arguments][:value]).to include("safe_arg")
+          arguments = JSON.parse(attributes[:arguments][:value])
+          expect(arguments).to be_a(Array)
+          expect(arguments).to include("safe_arg")
         end
 
         it "filters sensitive arguments" do
@@ -147,11 +148,11 @@ def perform(password:, token:, safe_data:)
           expect(log_event).not_to be_nil
 
           attributes = log_event[:attributes]
-          arguments = attributes[:arguments][:value]
+          arguments = JSON.parse(attributes[:arguments][:value])
 
-          expect(arguments.first).to include(safe_data: "public")
-          expect(arguments.first).to include(password: "[FILTERED]")
-          expect(arguments.first).to include(token: "[FILTERED]")
+          expect(arguments.first).to include("safe_data" => "public")
+          expect(arguments.first).to include("password" => "[FILTERED]")
+          expect(arguments.first).to include("token" => "[FILTERED]")
 
           Rails.application.config.filter_parameters = original_filter_params
         end
@@ -175,7 +176,7 @@ def perform(short_string, long_string)
           expect(log_event).not_to be_nil
 
           attributes = log_event[:attributes]
-          arguments = attributes[:arguments][:value]
+          arguments = JSON.parse(attributes[:arguments][:value])
 
           expect(arguments).to include("short")
           expect(arguments).to include("[FILTERED: 150 chars]")
@@ -204,11 +205,11 @@ def perform(string_arg, hash_arg, number_arg, array_arg)
           expect(log_event).not_to be_nil
 
           attributes = log_event[:attributes]
-          arguments = attributes[:arguments][:value]
+          arguments = JSON.parse(attributes[:arguments][:value])
 
           expect(arguments[0]).to eq("string_value")
-          expect(arguments[1]).to include(safe_key: "value")
-          expect(arguments[1]).to include(password: "[FILTERED]")
+          expect(arguments[1]).to include("safe_key" => "value")
+          expect(arguments[1]).to include("password" => "[FILTERED]")
           expect(arguments[2]).to eq(42)
           expect(arguments[3]).to eq([1, 2, 3])
         end

sentry-ruby/lib/sentry/log_event.rb

@@ -1,5 +1,7 @@
 # frozen_string_literal: true
 
+require "json"
+
 module Sentry
   # Event type that represents a log entry with its attributes
   #
@@ -62,13 +64,6 @@ class LogEvent
       user_email
     ].map { |name| [name, :"serialize_#{name}"] }.to_h
 
-    VALUE_TYPES = Hash.new("string").merge!({
-      TrueClass => "boolean",
-      FalseClass => "boolean",
-      Integer => "integer",
-      Float => "double"
-    }).freeze
-
     TOKEN_REGEXP = /%\{(\w+)\}/
 
     def initialize(configuration: Sentry.configuration, **options)
@@ -178,11 +173,22 @@ def serialize_attributes
     end
 
     def attribute_hash(value)
-      { value: value, type: value_type(value) }
-    end
-
-    def value_type(value)
-      VALUE_TYPES[value.class]
+      case value
+      when String
+        { value: value, type: "string" }
+      when TrueClass, FalseClass
+        { value: value, type: "boolean" }
+      when Integer
+        { value: value, type: "integer" }
+      when Float
+        { value: value, type: "double" }
+      else
+        begin
+          { value: JSON.generate(value), type: "string" }
+        rescue
+          { value: value, type: "string" }
+        end
+      end
     end
 
     def parameters

sentry-ruby/spec/sentry/structured_logger_spec.rb

@@ -67,6 +67,45 @@
           expect(log_event[:attributes]["sentry.message.parameter.1"]).to eql({ value: "Monday", type: "string" })
         end
 
+        it "logs with nested hash attributes" do
+          attributes = { number: 312, string: "hello" }
+
+          Sentry.logger.public_send(level, "Hello world", extra: attributes)
+
+          expect(sentry_logs).to_not be_empty
+
+          log_event = sentry_logs.last
+
+          expect(log_event[:level]).to eql(level)
+          expect(log_event[:attributes][:extra]).to eql({ type: "string", value: attributes.to_json })
+        end
+
+        it "logs with array attributes" do
+          attributes = [1, 2, 3, "hello"]
+
+          Sentry.logger.public_send(level, "Hello world", extra: attributes)
+
+          expect(sentry_logs).to_not be_empty
+
+          log_event = sentry_logs.last
+
+          expect(log_event[:level]).to eql(level)
+          expect(log_event[:attributes][:extra]).to eql({ type: "string", value: attributes.to_json })
+        end
+
+        it "logs with date in attributes" do
+          attributes = Date.today
+
+          Sentry.logger.public_send(level, "Hello world", extra: attributes)
+
+          expect(sentry_logs).to_not be_empty
+
+          log_event = sentry_logs.last
+
+          expect(log_event[:level]).to eql(level)
+          expect(log_event[:attributes][:extra]).to eql({ type: "string", value: attributes.to_json })
+        end
+
         it "logs with hash-based template parameters" do
           Sentry.logger.public_send(level, "Hello %{name}, it is %{day}", name: "Jane", day: "Monday")