feat: Adds distributed tracing for dial-in/dial-out call setup.

pom.xml

@@ -21,7 +21,7 @@
     <junit.version>5.8.2</junit.version>
     <smack.version>4.4.8-jitsi-4</smack.version>
     <jxmppVersion>1.0.3</jxmppVersion>
-    <jicoco.version>1.1-170-g3f48c50</jicoco.version>
+    <jicoco.version>1.1-178-ga09ed33</jicoco.version>
     <!-- Match jicoco's jetty version. -->
     <jetty.version>12.0.35</jetty.version>
     <oci-sdk.version>3.86.1</oci-sdk.version>
@@ -138,6 +138,11 @@
       <artifactId>jicoco-mucclient</artifactId>
       <version>${jicoco.version}</version>
     </dependency>
+    <dependency>
+      <groupId>${project.groupId}</groupId>
+      <artifactId>jicoco-tracing</artifactId>
+      <version>${jicoco.version}</version>
+    </dependency>
     <dependency>
       <groupId>${project.groupId}</groupId>
       <artifactId>jitsi-android-osgi</artifactId>
@@ -351,7 +356,7 @@
     <dependency>
       <groupId>${project.groupId}</groupId>
       <artifactId>jitsi-xmpp-extensions</artifactId>
-      <version>1.0-95-ge113e35</version>
+      <version>1.0-119-gc67bc81</version>
     </dependency>
     <dependency>
       <groupId>org.slf4j</groupId>

src/main/java/org/jitsi/jigasi/AbstractGateway.java

@@ -147,6 +147,10 @@ public OrderedJsonObject getDebugState()
      */
     void notifyCallEnded(CallContext callContext)
     {
+        // no-op if the setup span already ended (i.e. the call was
+        // established and this is a normal teardown)
+        callContext.failSetupSpan("call ended during setup");
+
         T session;
 
         synchronized (sessions)

src/main/java/org/jitsi/jigasi/CallContext.java

@@ -17,6 +17,7 @@
  */
 package org.jitsi.jigasi;
 
+import io.opentelemetry.api.trace.*;
 import net.java.sip.communicator.util.*;
 import org.apache.commons.lang3.StringUtils;
 import com.google.common.base.*;
@@ -190,6 +191,20 @@ public class CallContext
      */
     private final Map<String, String> extraHeaders = new HashMap<>();
 
+    /**
+     * The tracing span covering the setup of this call (from the dial
+     * request or SIP INVITE until media is established or setup fails).
+     * <tt>null</tt> when tracing is disabled or no span was started.
+     */
+    private volatile Span setupSpan = null;
+
+    /**
+     * Whether {@link #setupSpan} has been ended. Spans must be ended exactly
+     * once, but success and failure paths can race during teardown.
+     */
+    private final java.util.concurrent.atomic.AtomicBoolean setupSpanEnded
+        = new java.util.concurrent.atomic.AtomicBoolean(false);
+
     /**
      * Constructs new CallContext saving the timestamp at which it was created.
      */
@@ -221,6 +236,16 @@ public CallContext(Object source)
         return logger;
     }
 
+    /**
+     * Returns the unique id of this context. Attached to tracing spans so
+     * traces can be correlated with log entries ([ctx=...]).
+     * @return the context id.
+     */
+    public String getCtxId()
+    {
+        return ctxId;
+    }
+
     /**
      * The room MUC bare jid (roomname@conference.tenant.domain.net or roomname@conference.domain.net).
      *
@@ -645,4 +670,64 @@ public void setRequestVisitor(boolean requestVisitor)
     {
         this.requestVisitor = requestVisitor;
     }
+
+    /**
+     * Sets the tracing span covering the setup of this call.
+     * @param span the span to set.
+     */
+    public void setSetupSpan(Span span)
+    {
+        this.setupSpan = span;
+    }
+
+    /**
+     * Returns the tracing span covering the setup of this call, if any.
+     * @return the span or <tt>null</tt>.
+     */
+    public Span getSetupSpan()
+    {
+        return this.setupSpan;
+    }
+
+    /**
+     * Records a milestone event on the call setup span, if one is active.
+     * @param name the event name.
+     */
+    public void traceEvent(String name)
+    {
+        Span span = this.setupSpan;
+        if (span != null && !setupSpanEnded.get())
+        {
+            span.addEvent(name);
+        }
+    }
+
+    /**
+     * Ends the call setup span successfully. Does nothing if the span was
+     * already ended or none was started.
+     */
+    public void endSetupSpan()
+    {
+        Span span = this.setupSpan;
+        if (span != null && setupSpanEnded.compareAndSet(false, true))
+        {
+            span.end();
+        }
+    }
+
+    /**
+     * Ends the call setup span with an error status. Does nothing if the
+     * span was already ended (e.g. the call was established and later hung
+     * up) or none was started.
+     * @param reason a description of the failure.
+     */
+    public void failSetupSpan(String reason)
+    {
+        Span span = this.setupSpan;
+        if (span != null && setupSpanEnded.compareAndSet(false, true))
+        {
+            span.setStatus(StatusCode.ERROR, reason == null ? "" : reason);
+            span.end();
+        }
+    }
 }

src/main/java/org/jitsi/jigasi/JigasiBundleActivator.java

@@ -226,7 +226,10 @@ public void startWithServices(final BundleContext bundleContext)
         {
             if (isSipStartMutedEnabled())
             {
-                MuteIqProvider.registerMuteIqProvider();
+                ProviderManager.addIQProvider(
+                    MuteIq.ELEMENT,
+                    MuteIq.NAMESPACE,
+                    new MuteIqProvider());
             }
 
             // recording status, to detect recording start/stop
@@ -291,6 +294,12 @@ void notifyCallEnded(CallContext callContext)
         // Register Rayo IQs
         new RayoIqProvider().registerRayoIQs();
 
+        // Register the traceparent extension used for distributed tracing.
+        ProviderManager.addExtensionProvider(
+            TraceParent.ELEMENT,
+            TraceParent.NAMESPACE,
+            new TraceParentProvider());
+
         bundleContext.addServiceListener(this);
 
         Collection<ServiceReference<ProtocolProviderService>> refs

src/main/java/org/jitsi/jigasi/JvbConference.java

@@ -17,6 +17,7 @@
  */
 package org.jitsi.jigasi;
 
+import io.opentelemetry.api.trace.Span;
 import net.java.sip.communicator.impl.protocol.jabber.*;
 import net.java.sip.communicator.service.protocol.*;
 import net.java.sip.communicator.service.protocol.event.*;
@@ -1129,6 +1130,8 @@ public void joinConferenceRoom()
                 setPresenceStatus(gatewaySession.getDefaultInitStatus());
             }
 
+            callContext.traceEvent("muc.joined");
+
             gatewaySession.notifyJvbRoomJoined();
 
             if (websocketClient != null)
@@ -1219,6 +1222,8 @@ public void joinConferenceRoom()
 
                                     this.lobby.join();
 
+                                    this.callContext.traceEvent("lobby.joined");
+
                                     this.setLobbyEnabled(true);
 
                                     return;
@@ -1804,6 +1809,7 @@ private synchronized void callStateChangedInternal(CallChangeEvent evt)
             if (jvbCall.getCallState() == CallState.CALL_IN_PROGRESS)
             {
                 logger.info("JVB conference call IN_PROGRESS.");
+                callContext.traceEvent("jvb.call.established");
                 gatewaySession.onJvbCallEstablished();
 
                 AudioModeration avMod = JvbConference.this.getAudioModeration();
@@ -2063,6 +2069,19 @@ private String inviteFocus(final EntityBareJid roomIdentifier)
         ConferenceIq focusInviteIQ = new ConferenceIq();
         focusInviteIQ.setRoom(roomIdentifier);
 
+        // propagate our tracing context so jicofo can join the trace, both
+        // as a traceparent extension and as a conference property in W3C
+        // format (ConferenceIqProvider only parses property children, so
+        // only the property form survives parsing today)
+        Span setupSpan = callContext.getSetupSpan();
+        if (setupSpan != null && setupSpan.getSpanContext().isValid())
+        {
+            TracingUtil.attachTraceParent(focusInviteIQ, setupSpan);
+            focusInviteIQ.addProperty(
+                "traceparent",
+                TracingUtil.toW3CHeader(setupSpan.getSpanContext()));
+        }
+
         if (JigasiBundleActivator.isSipVisitorsEnabled() && !this.isTranscriber)
         {
             focusInviteIQ.addProperty("visitors-version", "1");
@@ -2094,6 +2113,8 @@ private String inviteFocus(final EntityBareJid roomIdentifier)
                 collector = getConnection().createStanzaCollectorAndSend(focusInviteIQ);
                 ConferenceIq res = collector.nextResultOrThrow();
 
+                callContext.traceEvent("focus.invited");
+
                 if (visitorsQueueServiceUrl != null)
                 {
                     String liveValue = res.getPropertiesMap().get("live");

src/main/java/org/jitsi/jigasi/SipGatewaySession.java

@@ -17,6 +17,7 @@
  */
 package org.jitsi.jigasi;
 
+import io.opentelemetry.api.trace.Span;
 import net.java.sip.communicator.impl.protocol.jabber.*;
 import net.java.sip.communicator.service.protocol.*;
 import net.java.sip.communicator.service.protocol.event.*;
@@ -642,6 +643,7 @@ public void callEnded(CallEvent callEvent)
             try
             {
                 this.sipCall = tele.createCall(outboundPrefix + destination);
+                callContext.traceEvent("sip.invite.sent");
                 this.initSipCall();
 
                 if (jvbConferenceCall != null)
@@ -762,6 +764,8 @@ public void onJoinJitsiMeetRequest(
                         .getAccountPropertyString(CallContext.MUC_DOMAIN_PREFIX_PROP, null));
                     callContext.setRequestVisitor(Boolean.parseBoolean(data.get(visitorHeaderName)));
 
+                    startDialInSpan(data);
+
                     joinJvbConference(callContext);
                 }
                 else
@@ -777,6 +781,41 @@ public void onJoinJitsiMeetRequest(
         }
     }
 
+    /**
+     * Starts the tracing span covering this dial-in call setup and stores it
+     * in the call context. If the SIP INVITE carried a W3C trace context
+     * header (<tt>Traceparent</tt> or <tt>X-Traceparent</tt>, e.g. from
+     * VoxImplant or another SIP frontend), the span joins that trace.
+     * A no-op span is used when tracing is disabled.
+     *
+     * @param data the map of headers received with the SIP INVITE.
+     */
+    private void startDialInSpan(Map<String, String> data)
+    {
+        String traceParentValue = null;
+        for (Map.Entry<String, String> entry : data.entrySet())
+        {
+            String name = entry.getKey();
+            if (TracingUtil.TRACEPARENT_HEADER.equalsIgnoreCase(name)
+                || "Traceparent".equalsIgnoreCase(name))
+            {
+                traceParentValue = entry.getValue();
+                break;
+            }
+        }
+
+        Span setupSpan = TracingUtil.getTracer().spanBuilder("dial.in")
+            .setParent(
+                TracingUtil.remoteContextFromW3CHeader(traceParentValue))
+            .setAttribute("room.id",
+                Objects.toString(callContext.getRoomJid()))
+            .setAttribute("ctx.id", callContext.getCtxId())
+            .setAttribute("dial.type", "sip")
+            .startSpan();
+
+        callContext.setSetupSpan(setupSpan);
+    }
+
     /**
      * Received if StartMutedExtension is handled.
      *
@@ -1506,6 +1545,15 @@ void handleCallState(Call call, CallPeerChangeEvent cause)
                 logger.info("Sip call IN_PROGRESS: " + call);
                 logger.info("SIP call format used: " + Util.getFirstPeerMediaFormat(call));
 
+                CallContext ctx = callContext;
+                if (ctx != null)
+                {
+                    // both legs are up (the SIP leg connects last), call
+                    // setup is complete
+                    ctx.traceEvent("sip.call.established");
+                    ctx.endSetupSpan();
+                }
+
                 if (jvbConference.getAudioModeration() != null)
                 {
                     jvbConference.getAudioModeration().maybeProcessStartMuted();

src/main/java/org/jitsi/jigasi/TranscriptionGatewaySession.java

@@ -269,6 +269,16 @@ Exception onConferenceCallStarted(Call jvbConferenceCall)
         return null;
     }
 
+    @Override
+    public void onJvbCallEstablished()
+    {
+        super.onJvbCallEstablished();
+
+        // the transcriber has no SIP leg, setup is complete once the JVB
+        // call is up
+        this.callContext.endSetupSpan();
+    }
+
     @Override
     void onJvbConferenceStopped(JvbConference jvbConference,
                                 int reasonCode, String reason)