sentry-java icon indicating copy to clipboard operation
sentry-java copied to clipboard

Is there a way to enable tracing across multiple threads?

Open sbrattla opened this issue 3 years ago • 11 comments

Problem Statement

I've got a quite simple Java application where the main thread at some point kicks off 10 worker threads, and wait for those threads to finish. The hub from the main thread gets passed to each worker thread, so that each worker thread can attach spans to the main transaction.

The issue I'm facing though is that once each worker thread starts creating new spans, the "current" span for the hub is set by the workers. Thus, when the next worker gets the current span and starts a new child span from it - the child span gets added to a span from another worker thread.

Ideally, I assume each worker thread should have it's own hub - but each hub should have the same transaction in common. Is it somehow possible for hubs to have a transaction in common, but have spans being local to each thread and thus not get mixed up across threads?

I know I can achieve this by passing ISpan instances around, but I can't do that for e.g. sentry-jdbc which always will do ISpan parent = hub.getSpan();.

Example

        ITransaction trans = Sentry.getCurrentHub().startTransaction("test", "test", true);
        ISpan main = trans.startChild("main");

        for (int i = 0; i < 10; i++) {
            Worker w = new Worker(Sentry.getCurrentHub().clone(), i);
            Thread t = new Thread(w);
            t.start();
        }

        try {
            Thread.sleep(2000);
        } catch (Exception e) {
            e.printStackTrace();
        }

        main.finish();
        trans.finish();

I'm passing a clone of the current hub to each thread, because I want to be able to attach spans in each worker thread to the transaction started in the main thread.

The Worker class

    private static class Worker implements Runnable {

        IHub hub;
        int idx;

        public Worker(IHub hub, int idx) {
            this.hub = hub;
            this.idx = idx;
        }

        @Override
        public void run() {
            ISpan parent = hub.getSpan();
            ISpan child = parent != null ? parent.startChild("worker " + idx) : null;

            try {
                Thread.sleep(1000);

            } catch (Exception ex) {
                ex.printStackTrace();

            } finally {
                if (child != null) {
                    child.finish();
                }
            }
        }

    }

Solution Brainstorm

No response

sbrattla avatar Nov 07 '22 09:11 sbrattla

If I'm understanding correctly, you'd like the child spans to be attached to the root transaction instead of the latest child span, right? This is currently a flaw of how the getSpan method works, and we're planning to change it with #1827, however, do it only for mobile (globalHubMode), so it won't affect your case.

I think you can still retrieve the root transaction though, by using configureScope, e.g.

ITransaction root = null;
hub.configureScope(
  scope -> {
    root = scope.getTransaction();
  }
);

and the start children using the root ref.

Let me know if that helps

romtsn avatar Nov 07 '22 10:11 romtsn

When I start a new thread, I cannot pass an existing hub from the current thread to the new thread. This will eventually lead to unpredictable results.

Whenever you invoke hub.getSpan().startChild("newspan"), the new span will attach to the most recent span for the hub - regardless of which thread an invocation of hub.getSpan() originates from. If you have a few threads all creating new spans from hub.getSpan().startChild([...]) - your spans will attach to whichever span was most recently created. So, a span created by thread 7 may attach to a span created by thread 2.

Ideally, doing a hub.clone() should "freeze" the most recent span. This would allow me to pass that cloned hub to another thread, and set the cloned hub as the "thread local" hub using Sentry.setCurrentHub(hub). Then, from there doing hub.getSpan() would return the most recently created span for the current thread.

sbrattla avatar Nov 08 '22 11:11 sbrattla

Thing is, that the hub is already ThreadLocal in the Sentry singleton (if not instantiated with the globalHubMode) -> https://github.com/getsentry/sentry-java/blob/a04f78887caef1e188c16867cf2f068dd98e3017/sentry/src/main/java/io/sentry/Sentry.java#L25-L26 ~so if you'd retrieve its instance on a new thread, the main hub will be cloned, the getSpan method will return the latest known span from the main hub, but all subsequent spans will be scoped only to the current thread and should not affect getSpan when its called from the other threads.~

I guess I'm not quite understanding your problem - if you want to attach child spans to the main transaction, you can retrieve its instance via configureScope as shown above

romtsn avatar Nov 08 '22 12:11 romtsn

I may be wrong in my memory / assumptions, but I'm using the sentry-spring-boot-starter and I believe it sets globalHubMode to false ?

If I clone the hub on the main thread, and pass the hub clone into each new thread (via the constructor), should new spans then be scoped to the current thread only?

sbrattla avatar Nov 08 '22 12:11 sbrattla

Looking at SentryTracingFilter seems to confirm that globalHubMode is set to false for Spring Boot - bindToScope(true).

    final TransactionOptions transactionOptions = new TransactionOptions();
    transactionOptions.setCustomSamplingContext(customSamplingContext);
    transactionOptions.setBindToScope(true);

    return hub.startTransaction(
        new TransactionContext(name, TransactionNameSource.URL, "http.server"), transactionOptions);
  }

Consider the below piece of code. A main thread starts 10 worker thread. Each worker thread gets a Sentry.getCurrentHub().clone() via its constructor. The constructor sets that hub via Sentry.setCurrentHub(hub);.


import io.sentry.IHub;
import io.sentry.ISpan;
import io.sentry.ITransaction;
import io.sentry.Sentry;
import io.sentry.TransactionContext;
import io.sentry.TransactionOptions;
import io.sentry.protocol.TransactionNameSource;

public class ThreadTest {

    public static void main(String[] args) {

        Sentry.init(options -> {
            options.setDsn("{dsn});
            // Set tracesSampleRate to 1.0 to capture 100% of transactions for performance monitoring.
            // We recommend adjusting this value in production.
            options.setTracesSampleRate(1.0);
            // When first trying Sentry it's good to see what the SDK is doing:
            options.setDebug(true);
        });

        final TransactionContext transactionContext = new TransactionContext("name", TransactionNameSource.URL, "http.server");
        final TransactionOptions transactionOptions = new TransactionOptions();
        transactionOptions.setBindToScope(true);
        
        ITransaction trans = Sentry.getCurrentHub().startTransaction(transactionContext, transactionOptions);
        ISpan main = trans.startChild("main");

        for (int i = 0; i < 10; i++) {
            Worker w = new Worker(Sentry.getCurrentHub().clone(), i);
            Thread t = new Thread(w);
            t.start();
        }

        try {
            Thread.sleep(5000);
        } catch (Exception e) {
            e.printStackTrace();
        }

        main.finish();
        trans.finish();
    }

    private static class Worker implements Runnable {

        IHub hub;
        int idx;

        public Worker(IHub hub, int idx) {
            this.hub = hub;
            this.idx = idx;
        }

        @Override
        public void run() {
            Sentry.setCurrentHub(hub);
            ISpan child = hub.getSpan().startChild("worker-" + idx);

            try {
                Thread.sleep(1000);
                ISpan leaf = hub.getSpan().startChild("worker-" + idx + "-leaf");
                Thread.sleep(500);
                leaf.finish();

            } catch (Exception ex) {
                ex.printStackTrace();

            } finally {
                if (child != null) {
                    child.finish();
                }
            }
        }
    }
}

Each thread starts a new span off hub.getSpan(). My understanding from the answers above, new spans created in new threads should be thread local as long as bindToScope = true / globalHubMode = false.

The result from this can be seen below. Spans do not seem to be thread local considering how they all get attached to the same parent span.

Have I misunderstood anything / done something wrong to end up with this result?

image

sbrattla avatar Nov 10 '22 12:11 sbrattla

Okay, I double-checked and the problem is that we're actually not making a deep-copy of Scope when cloning, sorry for the wrong info!

Or rather we're doing a mixed copy here - some of the fields are deep-copied and some are not: https://github.com/getsentry/sentry-java/blob/c1b740d9b4d5665d44550acf71043591e696e377/sentry/src/main/java/io/sentry/Scope.java#L84-L137

@marandaneto @bruno-garcia do you know if there was a reason for not making a deep-copy of transaction and session, or we just missed that? (PR for the reference #1496)

romtsn avatar Nov 10 '22 22:11 romtsn

It was by design

bruno-garcia avatar Nov 11 '22 04:11 bruno-garcia

@romtsn @bruno-garcia would it be possible to somehow change this, so that spans created on a cloned IHub becomes thread local?

Spans which covers multiple threads may not be very common in web applications (each request is usually a single thread), but they do happen. On the other hand, it is very common for e.g. background processes to use multiple threads. I use Sentry in many background processes, and the only way to use Sentry in other threads is to pass instances of ISpan into the constructor of those threads.

For the sentry provided sentry-jdbc I do not have this option, and database queries will by default be scattered all over the place and attached to random spans when multiple threads are involved.

sbrattla avatar Nov 11 '22 07:11 sbrattla

Sorry for the short reply above, it was late here.

By default, Hub is thread local. This is how on Spring Boot for example, each request has it's own Hub/Scope/Transaction, etc. We change that in what we call Global Mode hub. Which we use in Mobile/Desktop apps, where a single user is logged in 'in the whole process' And any tags/crumbs you add, for example when you call a backend service, you expect to be in any event/crash regardless of what thread that came from.

bruno-garcia avatar Nov 11 '22 13:11 bruno-garcia

@bruno-garcia I understand that, but does this mean that - in the case of globalHubMode = false - it will not be possible to simply clone the thread local hub and expect threads to only work on a span tree local to that thread?

Would you consider to add functionality which allows for the scenario described in this thread?

sbrattla avatar Nov 11 '22 14:11 sbrattla

Hello @sbrattla, I've expanded on your sample code by starting a new transaction from the existing transaction. It seems to work but you will get different transactions for the workers so you'll have to look at the trace to navigate between them.

Here's the code I added to the Worker you posted above (pardon the ugliness, this hasn't been optimized for use by others outside of Sentry yet):

NOTE: I just slapped this together without guarding against any potential exceptions.

  private static class Worker implements Runnable {

    IHub hub;
    int idx;

    public Worker(IHub hub, int idx) {
      this.hub = hub;
      this.idx = idx;
    }

    @Override
    public void run() {
      Sentry.setCurrentHub(hub);

      String baggageString = Sentry.getCurrentHub().getSpan().toBaggageHeader(Collections.emptyList()).getValue();
      Baggage baggage = Baggage.fromHeader(baggageString, Sentry.getCurrentHub().getOptions().getLogger());
      TransactionContext txCtx = TransactionContext.fromSentryTrace("transaction-" + idx, TransactionNameSource.CUSTOM, "txop-" + idx, Sentry.traceHeaders(), baggage);
      ITransaction transactionB = Sentry.startTransaction(txCtx, true);

      ISpan child = hub.getSpan().startChild("worker-" + idx);

      try {
        try {
          Thread.sleep(1000);
          ISpan leaf = hub.getSpan().startChild("worker-" + idx + "-leaf");
          Thread.sleep(500);
          leaf.finish();

        } catch (Exception ex) {
          ex.printStackTrace();

        } finally {
          if (child != null) {
            child.finish();
          }
        }
      } finally {
        if (transactionB != null) {
          transactionB.finish();
        }
      }
    }
  }

Regarding the feature to allow this without creating separate transactions - this sounds like a good feature to me. I can think of two ways to (somewhat) achieve that:

  • A config option to always attach spans to the transaction instead of the latest span (which could then default to on for globalHubMode). You'd be losing the hierarchy of spans - timeline should still be helpful though.
  • We could improve how we keep track of a transactions child spans. Currently this is a simple list of spans. If we were to instead store them as a tree with information about the thread attached, we could then return the current span based on that thread info.
    • look for the latest unfinished span of the current thread
    • fall back to the parent of the latest finished span from the current thread
    • return the transaction in case none of the above could be found
    • this can surely be improved, just the first thing that came to mind

Sadly we can't give a timeline for adding this functionality at the moment. An alternative would be to fork the SDK and do these changes yourself if you need them soon.

NOTE: I haven't given this a lot of thought so I'm not sure what follow up problems we'd create.

adinauer avatar Nov 15 '22 11:11 adinauer