Sentry/Rails: monotonic_active_support_logger results in incorrect timestamps

[mjhoy]

Issue Description

I believe that the MonotonicActiveSupportLogger is not submitting correct data to Sentry::Breadcrumb. We saw breadcrumb dates hovering around 1970 when we enabled this; switching to ActiveSupportLogger fixed the issue.

The reason for this is that I believe ActiveSupport::Notifications.monotonic_subscribe uses Process.clock_gettime(Process::CLOCK_MONOTONIC). The values from this call are floats that don't correspond to Unix epoch timestamps, which I believe is what Sentry::Breadcrumb expects.

ActiveSupport code in question: https://github.com/rails/rails/blob/v7.0.3.1/activesupport/lib/active_support/notifications/fanout.rb#L240-L255

MonotonicActiveSupportLogger calls .to_i on the timestamp: https://github.com/getsentry/sentry-ruby/blob/71da6736cea07727c9be9ac0fc4ab93309f0b7d5/sentry-rails/lib/sentry/rails/breadcrumb/monotonic_active_support_logger.rb#L23

Reproduction Steps

1. Enable monotonic_active_support_logger in config.breadcrumbs_logger for Sentry initialization.
2. Submit some data
3. Inspect breadcrumb timestamps in Sentry

Expected Behavior

The timestamps are correct.

Actual Behavior

The timestamps are shown as early in the year 1970.

Ruby Version

3.1.2

SDK Version

5.4.2

Integration and Its Version

No response

Sentry Config

No response

[sl0thentr0py]

@st0012 we added this logger in https://github.com/getsentry/sentry-ruby/pull/1531 but as far as I understand CLOCK_MONOTONIC is only useful to compute durations (end - start), it can't actually be converted to any normal timestamp since the reference 0 time is arbitrary.

From man clock_getres

CLOCK_MONOTONIC
              A nonsettable system-wide clock that represents monotonic
              time since—as described by POSIX—"some unspecified point
              in the past".  On Linux, that point corresponds to the
              number of seconds that the system has been running since
              it was booted.

So we should just remove the timestamp from the breadcrumbs in this logger, but then I also don't see what the use of this separate logger is?

[st0012]

@sl0thentr0py The only difference this logger provides is the timestamp format AFAIK. So if we remove the timestamp we might as well just remove the logger.

I think we can use to_f instead and let Sentry display the raw value (by sending string?). Then users can use them to compare the time elapse but don't try to think of it as a certain time. WDYT?

[sl0thentr0py]

Just sending a random float in the timestamp field will not work as far as I can tell because relay will try to parse it as a Timestamp and it will probably end up in one of the error cases.

I think this monotonic stuff is more useful in span instrumentation than breadcrumbs because we have durations (end - start) there.

[st0012]

@sl0thentr0py Yeah then I don't see a value of keeping it for breadcrumbs. I think we can remove it from 6.0 by redirecting monotonic_active_support_logger to active_support_logger. But I want to check users' opinion before committing to drop it.

@mjhoy Why do you decide to use this logger instead of active_support_logger in the first place?

@morissetcl Do you still use logger? What do you use it for?

[mjhoy]

@st0012 Not sure why, to be honest. Probably because "monotonic" sounded better than not being monotonic. Looking at the documentation here: https://docs.sentry.io/platforms/ruby/guides/rails/configuration/options/ At the very least, I would expect that documentation to warn about the somewhat useless timestamp values.