search

tmm1 / stackprof

a sampling call-stack profiler for ruby 2.2+
MIT License
2.08k stars 128 forks source link

Weird timestamp deltas with puma #201

Closed sl0thentr0py closed 1 year ago

sl0thentr0py commented 1 year ago

Hey!

Disclaimer: I'm the current https://github.com/getsentry/sentry-ruby maintainer and work at Sentry. We're trying to integrate stackprof into our Profiling offering.

While trying out stackprof with puma, I'm noticing some weird raw_timestamp_deltas (notice the 0/1 values) in :wall mode. This happens even with threads 1,1 in the puma config since puma seems to start a bunch of other threads anyway.

(byebug) results[:raw_timestamp_deltas]
[25384, 0, 18747, 10003, 1, 13448, 16142, 0, 9880, 10042, 27776, 12881, 4665, 5273, 10685, 8772, 16603, 2831, 11990, 8337, 19352, 0, 20402, 0, 19602, 1, 19892, 19693, 9976, 9666, 10161, 9407, 10375, 9666, 1, 19603, 0, 19520, 10319, 9775, 9439, 9925, 9913, 10259, 9381, 10011, 10640, 9008, 9799, 9808, 10555, 9280, 10112]

These do not appear in single threaded unicorn.

(byebug) results[:raw_timestamp_deltas]
[9981, 10853, 18936, 10715, 19736, 9113, 9766, 9826, 10507, 9328, 10687, 9620, 9564, 9683, 9617, 10621, 9550, 9242, 9838, 10466, 9116, 10407, 9514, 9489, 9701, 9730, 9760, 10176, 9855, 10512, 9795, 9801, 9311, 9952, 9087, 11022, 9155, 10395, 8895, 10721, 9376, 9757, 9613, 10001, 10217, 8941, 10298, 9255, 10686, 9850, 9206, 10142, 10391, 9677, 8958, 10700, 9797, 9850, 9193, 9548, 10668, 9288, 10000]

Could anyone guide me into investigating why this could happen? Is this because of the signal forwarding to target_thread here that could somehow result in these weird timestamps?

tenderlove commented 1 year ago

@sl0thentr0py these could be because of GC samples. GC samples have odd delta calculations.

Can you match those samples up with their stack frame?

sl0thentr0py commented 1 year ago

alright yea I missed that logic, thanks for the pointer! that would make sense, I will close this. If I get time to confirm the hypothesis later, I can update this issue.