feat(sessions): Implement automatic session tracking #1715

sl0thentr0py · 2022-02-09T10:07:42Z

This adds automatic session tracking to our rack middleware (and hence rails).
The key components here are a SessionFlusher that spawns a new thread that sends pending aggregate sessions once a minute and a simple Session class for recording those individual sessions.

Note that we currently only implement request mode sessions which are aggregated in the SDK as compared to application mode sessions which are sent as soon as they finish. The main reason for this is the scale of most servers out there which would overload our ingestion pipelines.

The Session class could potentially be extended in the future for application mode sessions but for now it doesn't add much user value.

There are a couple of TODOs left which are slightly orthogonal to the main feature so I will make separate PRs for those.

closes #1711

References

https://develop.sentry.dev/sdk/sessions/

Implementation progress

In separate PRs

move rate limiting logic to envelope and unify send_envelope / send_event
~~exception handled / session crashed status~~ moved to Add mechanism to the exception interfaces #1743

codecov-commenter · 2022-02-09T10:31:46Z

Codecov Report

Merging #1715 (6ddd1ed) into master (bad64df) will increase coverage by 0.03%.
The diff coverage is 98.80%.

❗ Current head 6ddd1ed differs from pull request most recent head 6e89778. Consider uploading reports for the commit 6e89778 to get more accurate results

@@            Coverage Diff             @@
##           master    #1715      +/-   ##
==========================================
+ Coverage   98.40%   98.43%   +0.03%     
==========================================
  Files         141      144       +3     
  Lines        8079     8312     +233     
==========================================
+ Hits         7950     8182     +232     
- Misses        129      130       +1

Impacted Files	Coverage Δ
sentry-ruby/lib/sentry/rack/capture_exceptions.rb	`95.12% <87.50%> (+0.12%)`	⬆️
sentry-ruby/lib/sentry/session_flusher.rb	`97.77% <97.77%> (ø)`
sentry-ruby/lib/sentry-ruby.rb	`95.86% <100.00%> (+0.27%)`	⬆️
sentry-ruby/lib/sentry/configuration.rb	`98.42% <100.00%> (+0.01%)`	⬆️
sentry-ruby/lib/sentry/hub.rb	`100.00% <100.00%> (ø)`
sentry-ruby/lib/sentry/scope.rb	`100.00% <100.00%> (ø)`
sentry-ruby/lib/sentry/session.rb	`100.00% <100.00%> (ø)`
sentry-ruby/lib/sentry/transport.rb	`98.88% <100.00%> (+0.01%)`	⬆️
...entry-ruby/lib/sentry/transport/dummy_transport.rb	`100.00% <100.00%> (ø)`
sentry-ruby/spec/sentry/configuration_spec.rb	`100.00% <100.00%> (ø)`
... and 3 more

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update bad64df...6e89778. Read the comment docs.

method

for now

sl0thentr0py · 2022-02-28T13:18:46Z

So I'm gonna document my testing here one by one.
The setup is as follows:
I'm using this branch with a simple logging of the total thread counts and the session flusher thread count every 10 seconds and on init and exit. And the rails app I'm using is here.

First run, normal behavior with some success and error routes. We see that during normal behavior, there is one flusher thread and it is killed successfully before exiting.

Thread Count log

INIT STATE
--------------------
total count: 1
flusher count: 0
--------------------
--------------------
total count: 25
flusher count: 1
--------------------
--------------------
total count: 25
flusher count: 1
--------------------
--------------------
total count: 25
flusher count: 1
--------------------
--------------------
total count: 25
flusher count: 1
--------------------
--------------------
total count: 25
flusher count: 1
--------------------
--------------------
total count: 25
flusher count: 1
--------------------
EXIT STATE
--------------------
total count: 9
flusher count: 0
--------------------

Proof that end-end flow worked

sentry-ruby/lib/sentry/session.rb

antonpirker · 2022-03-01T11:22:21Z

My review is just very "on the surface", because I am not an Ruby export. But everything looks clean (and done the same way as in Python)

sl0thentr0py · 2022-03-01T11:22:58Z

thx for taking a look!

sl0thentr0py · 2022-03-01T14:56:30Z

Next test was to test the failure resiliency of the flusher. Basically checking two things

if there's an exception inside the thread, the ensure_thread ensures that a new thread respawns eventually
there is only a single flusher thread at a time, other threads exit/don't leak and we don't add more threads randomly

This was done with this commit to throw a random exception with 25% probability.

Thread exception in rails log

#<Thread:0x00007f91d0123ce8@/Users/neel/sentry/sdks/sentry-ruby/sentry-ruby/lib/sentry/session_flusher.rb:77 run> terminated with exception (report_on_exception is true):
Traceback (most recent call last):
	3: from /Users/neel/sentry/sdks/sentry-ruby/sentry-ruby/lib/sentry/session_flusher.rb:78:in `block in ensure_thread'
	2: from /Users/neel/sentry/sdks/sentry-ruby/sentry-ruby/lib/sentry/session_flusher.rb:78:in `loop'
	1: from /Users/neel/sentry/sdks/sentry-ruby/sentry-ruby/lib/sentry/session_flusher.rb:80:in `block (2 levels) in ensure_thread'
/Users/neel/sentry/sdks/sentry-ruby/sentry-ruby/lib/sentry/session_flusher.rb:21:in `flush': Oops in thread (RuntimeError)

The thread count log shows 0 for the flusher thread count when that exception happens and the thread crashes. A new one is eventually respawned on the the next add_session call. We see that the thread count will always be 0/1 and we will not add more threads in any way if there is already an existing thread.

Thread Count log

INIT STATE
--------------------
total count: 1
flusher count: 0
--------------------
--------------------
total count: 26
flusher count: 1
--------------------
--------------------
total count: 26
flusher count: 1
--------------------
--------------------
total count: 25
flusher count: 0   # <---- crash happened before this log
--------------------
--------------------
total count: 25
flusher count: 0
--------------------
--------------------
total count: 26
flusher count: 1  # <----- thread respawned here once I visited some pages
--------------------
--------------------
total count: 26
flusher count: 1
--------------------
--------------------
total count: 26
flusher count: 1
--------------------
EXIT STATE
--------------------
total count: 9
flusher count: 0
--------------------

st0012

I finally got time to do a more thorough review, sorry for the waiting.
The overall feature still looks good 👍 I only added some nitpick-ish naming/testing suggestions 🙂

sentry-ruby/lib/sentry/session.rb

sentry-ruby/lib/sentry/session_flusher.rb

sentry-ruby/lib/sentry/transport.rb

sentry-ruby/spec/sentry/session_flusher_spec.rb

sl0thentr0py · 2022-03-07T11:49:24Z

@st0012 made some updates and left comments for the rest

st0012 · 2022-03-07T14:31:25Z

@sl0thentr0py since we're now close to completion, can you also add a changelog entry for the feature? preferably also include a simple description, related configs & Sentry doc, and a screenshot? Example: https://github.com/getsentry/sentry-ruby/releases/tag/4.8.0

sl0thentr0py · 2022-03-07T14:54:29Z

@st0012 done!

CHANGELOG.md

st0012

🎉

st0012 · 2022-03-09T21:38:52Z

sentry-ruby/lib/sentry-ruby.rb

@@ -189,11 +194,18 @@ def init(&block)
      @main_hub = hub
      @background_worker = Sentry::BackgroundWorker.new(config)

+      @session_flusher = if config.auto_session_tracking
+                           Sentry::SessionFlusher.new(config, client)


@sl0thentr0py I think we should also check if the SDK is deactivated before initializing the flusher, especially to avoid the additional thread that won't be used. We can use Configuration#enabled_in_current_env? for it.

sl0thentr0py force-pushed the sessions branch 2 times, most recently from 55a5c1e to 02464a1 Compare February 14, 2022 11:38

sl0thentr0py force-pushed the sessions branch from 5b090de to a0b5702 Compare February 16, 2022 13:08

sl0thentr0py marked this pull request as ready for review February 18, 2022 14:35

sl0thentr0py requested review from st0012 and antonpirker February 18, 2022 14:35

sl0thentr0py changed the title ~~Sessions WIP~~ feat(sessions): Implement automatic session tracking Feb 18, 2022

sl0thentr0py and others added 22 commits February 18, 2022 15:49

SessionFlusher spawning new thread with 60s periodic flush

e8c0b19

Hub start_session/end_session api, add session object to scope

e1c6e2d

Start implementing Session class WIP

ecc7b2e

Expose session_flusher on top level

054fc1b

Test commit

e87fab4

Test commit

5cef255

Test commit

cda6a15

auto_session_tracking config (default true); with_session_tracking hub

6ddfe88

method

Wrap rack middleware in with_session_tracking

e3eeb46

Simplify session class/remove mode switches since only doing aggregates

1b10175

for now

Fix missing require, end_session in ensure

cdb0c2a

Simplify session updates on exception

b40e118

Simpler hub logic

a265820

Record aggregates

d177116

Envelope abstraction for sessions (WEBBACKEND-85)

9cf5cf7

Move session update in capture_event to hub due to scope dup

aced0ba

Need to make envelope outside background worker

2eeb07c

Remove useless require

5730c24

Specs for SessionFlusher

917edfb

Rake middleware sessions specs

c22f630

Remove rate-limit change because will do it separately

9528b17

Some docs + cleanup

51f5263

Base automatically changed from ref-envelope-rate-limit to master February 22, 2022 17:35

Merge remote-tracking branch 'origin/master' into sessions

b3036f3

sl0thentr0py mentioned this pull request Feb 26, 2022

Remove timeout from TimerTask ruby-concurrency/concurrent-ruby#926

Merged

Merge remote-tracking branch 'origin/master' into sessions

97d62a4

antonpirker approved these changes Mar 1, 2022

View reviewed changes

sentry-ruby/lib/sentry/session.rb Outdated Show resolved Hide resolved

st0012 added this to the 5.2.0 milestone Mar 1, 2022

st0012 reviewed Mar 5, 2022

View reviewed changes

sl0thentr0py added 4 commits March 7, 2022 12:06

Merge remote-tracking branch 'origin/master' into sessions

3c564bd

Move session update from capture_event to capture_exception

1aa86cb

Code style

fbd0968

Add spec for only one thread

2f624fc

Remove aggregates_payload

ea76666

sl0thentr0py and others added 4 commits March 7, 2022 15:34

Rewrite #flush test

6e89778

Partial changelog

3e528c7

Wrong changelog..

fcc3c49

Add screenshot

f0d049c

st0012 reviewed Mar 7, 2022

View reviewed changes

CHANGELOG.md Outdated Show resolved Hide resolved

Changelog fix

11fc4dc

st0012 approved these changes Mar 7, 2022

View reviewed changes

st0012 merged commit e727167 into master Mar 7, 2022

5.x automation moved this from In progress to Done Mar 7, 2022

st0012 deleted the sessions branch March 7, 2022 15:20

st0012 reviewed Mar 9, 2022

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat(sessions): Implement automatic session tracking #1715

feat(sessions): Implement automatic session tracking #1715

sl0thentr0py commented Feb 9, 2022 •

edited

Loading

codecov-commenter commented Feb 9, 2022 •

edited

Loading

sl0thentr0py commented Feb 28, 2022 •

edited

Loading

antonpirker commented Mar 1, 2022 •

edited

Loading

sl0thentr0py commented Mar 1, 2022

sl0thentr0py commented Mar 1, 2022 •

edited

Loading

st0012 left a comment

sl0thentr0py commented Mar 7, 2022

st0012 commented Mar 7, 2022

sl0thentr0py commented Mar 7, 2022

st0012 left a comment

st0012 Mar 9, 2022

feat(sessions): Implement automatic session tracking #1715

feat(sessions): Implement automatic session tracking #1715

Conversation

sl0thentr0py commented Feb 9, 2022 • edited Loading

References

Implementation progress

codecov-commenter commented Feb 9, 2022 • edited Loading

Codecov Report

sl0thentr0py commented Feb 28, 2022 • edited Loading

antonpirker commented Mar 1, 2022 • edited Loading

sl0thentr0py commented Mar 1, 2022

sl0thentr0py commented Mar 1, 2022 • edited Loading

st0012 left a comment

Choose a reason for hiding this comment

sl0thentr0py commented Mar 7, 2022

st0012 commented Mar 7, 2022

sl0thentr0py commented Mar 7, 2022

st0012 left a comment

Choose a reason for hiding this comment

st0012 Mar 9, 2022

Choose a reason for hiding this comment

sl0thentr0py commented Feb 9, 2022 •

edited

Loading

codecov-commenter commented Feb 9, 2022 •

edited

Loading

sl0thentr0py commented Feb 28, 2022 •

edited

Loading

antonpirker commented Mar 1, 2022 •

edited

Loading

sl0thentr0py commented Mar 1, 2022 •

edited

Loading