Spans not sent if span is dropped manually or exec is called?

[zmitchell]

Environment

What version are you running? Etc.

• Environment: SaaS, sentry.io
• OS: macOS (not tested on others)
• Version: 0.32.2, tracing feature enabled

Steps to Reproduce

This code is open source, so you can peek through it.

1. I've used the tracing::instrument macro to instrument different commands in our CLI. Here's an example of a working command (install command).
2. For our "activate" command we either print a script for the shell to source, or we exec a user's shell.
3. Thinking that I didn't want to record time spent inside a user's shell, I thought that rather than using the instrument macro I would create a span manually so that I could drop it at the appropriate time.
4. I do that here: activate command.
5. No spans are sent for this command, unexpectedly.
6. In a local checkout I've also tried switching back to the instrument macro in case there's some cleanup that I'm not performing (I also removed the manual drops), but there are still no spans sent for this command. I'm thinking that somehow a transaction isn't getting finished?
7. I'm able to see the tracing logs in my terminal, so the activate span is getting created, but it's not getting reported.

Expected Result

I would expect spans to be reported for this command like all the others.

Actual Result

Sentry is initialized:

2024-03-21T21:08:25.972199Z DEBUG flox::utils::init::sentry: Initializing Sentry with DSN: <DSN>
2024-03-21T21:08:25.975892Z DEBUG sentry: enabled sentry client for DSN <DSN>

For commands that do work you later see logs like this:

2024-03-21T21:32:21.223920Z DEBUG sentry: dropping client guard -> disposing client
2024-03-21T21:32:21.224003Z DEBUG sentry: client close; request transport to shut down
...hyper/reqwest logs
2024-03-21T21:32:21.401103Z DEBUG sentry: Get response: `{"id":"1965f0595eba42109a6d6cca86bfb0ad"}`

For this activate command the second set of logs is missing.

[Swatinem]

I think the problem here is that you are using exec. Per documentation, this function never returns, and the docs also state that this means no destructors (guards) are run: https://doc.rust-lang.org/std/os/unix/process/trait.CommandExt.html#tymethod.exec AFAIK, execvp just replaces the current process with another one. So the original process does not exist anymore as such, and there is no way to flush anything afterwards.

I believe you have three choices to go from here:

1. Spawn the shell as a child process, so you can both time it properly and flush the spans. The disadvantage is that the parent runs for the whole duration of the child.
2. Spawn the shell as a child process and detach it from its parent, so the parent can flush the spans and then exit to not waste resources.
3. Flush the span before calling exec. Disadvantage is that you now have a potentially slow flush operation in your critical path.

I believe 2. provides the best tradeoffs here, but the choice is yours :-)

[zmitchell]

Unfortunately we need to call exec there. I've tried calling flush via Hub->get the client (current and main)->flush and that didn't do the trick. Is there some other way to flush the span?

[zmitchell]

Hi, just checking back, how do you manually do option 3? As I mentioned above the method I tried didn't work.

[Swatinem]

Finishing the span (and the root transaction) would submit those to the transport. Then you would have to flush the transport. I don’t know enough about your usecase to fully answer this I’m afraid.