Merge pull request #4853 from Pandrex247/FISH-389

FISH-389 Add Transaction ID as Span Baggage Item

appserver/ejb/ejb-container/pom.xml

@@ -40,7 +40,7 @@
     holder.
 
 -->
-<!--"Portions Copyright [2016-2019] [Payara Foundation and/or its affiliates]" -->
+<!--"Portions Copyright [2016-2020] [Payara Foundation and/or its affiliates]" -->
 
 <project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/maven-v4_0_0.xsd"> <modelVersion>4.0.0</modelVersion>
 
@@ -247,5 +247,16 @@
             <artifactId>payara-api</artifactId>
             <version>${project.version}</version>
         </dependency>
+        <dependency>
+            <groupId>fish.payara.server.internal.payara-modules</groupId>
+            <artifactId>opentracing-adapter</artifactId>
+            <version>${project.version}</version>
+            <scope>provided</scope>
+        </dependency>
+        <dependency>
+            <groupId>io.opentracing</groupId>
+            <artifactId>opentracing-api</artifactId>
+            <scope>provided</scope>
+        </dependency>
     </dependencies>
 </project>

appserver/ejb/ejb-container/src/main/java/com/sun/ejb/containers/BaseContainer.java

@@ -89,7 +89,6 @@
 
 import fish.payara.cluster.DistributedLockType;
 import fish.payara.notification.requesttracing.RequestTraceSpanLog;
-import fish.payara.nucleus.requesttracing.RequestTracingService;
 
 import java.io.Serializable;
 import java.lang.reflect.Constructor;
@@ -122,6 +121,10 @@
 import javax.transaction.Transaction;
 import javax.transaction.UserTransaction;
 
+import fish.payara.nucleus.requesttracing.RequestTracingService;
+import fish.payara.opentracing.OpenTracingService;
+import io.opentracing.Span;
+import io.opentracing.Tracer;
 import org.glassfish.api.invocation.ComponentInvocation;
 import org.glassfish.api.invocation.InvocationManager;
 import org.glassfish.api.naming.GlassfishNamingManager;
@@ -235,7 +238,8 @@ public enum ContainerType {
 
     protected ContainerType containerType;
 
-    private final RequestTracingService requestTracing;
+    private final RequestTracingService requestTracingService;
+    private final OpenTracingService openTracingService;
 
     // constants for EJB(Local)Home/EJB(Local)Object methods,
     // used in authorizeRemoteMethod and authorizeLocalMethod
@@ -570,7 +574,8 @@ protected BaseContainer(ContainerType type, EjbDescriptor ejbDesc, ClassLoader l
     {
         this.containerType = type;
         this.securityManager = sm;
-        this.requestTracing = Globals.getDefaultHabitat().getService(RequestTracingService.class);
+        this.requestTracingService = Globals.getDefaultHabitat().getService(RequestTracingService.class);
+        this.openTracingService = Globals.getDefaultHabitat().getService(OpenTracingService.class);
 
         try {
             this.loader = loader;
@@ -4159,11 +4164,8 @@ final void onEjbMethodStart(String method_sig) {
                 callFlowInfo.getModuleName(),
                 callFlowInfo.getComponentName(),
                 method_sig);
-        if (requestTracing.isRequestTracingEnabled()) {
-            RequestTraceSpanLog spanLog = constructEjbMethodSpanLog(callFlowInfo, true);
-            requestTracing.addSpanLog(spanLog);
-        }
-        //callFlowAgent.ejbMethodStart(callFlowInfo);
+
+        addEjbMethodTraceLog(callFlowInfo, true);
     }
 
     final void onEjbMethodEnd(String method_sig, Throwable th) {
@@ -4173,10 +4175,29 @@ final void onEjbMethodEnd(String method_sig, Throwable th) {
                 callFlowInfo.getComponentName(),
                 th,
                 method_sig);
-        //callFlowAgent.ejbMethodEnd(callFlowInfo);
-        if (requestTracing.isRequestTracingEnabled()) {
-            RequestTraceSpanLog spanLog = constructEjbMethodSpanLog(callFlowInfo, false);
-            requestTracing.addSpanLog(spanLog);
+        addEjbMethodTraceLog(callFlowInfo, false);
+    }
+
+    private void addEjbMethodTraceLog(CallFlowInfo info, boolean callEnter) {
+        if (openTracingService.isEnabled()) {
+            Tracer tracer = openTracingService.getTracer(openTracingService.getApplicationName(invocationManager));
+            RequestTraceSpanLog spanLog = constructEjbMethodSpanLog(info, callEnter);
+
+            if (tracer != null) {
+                Span span = tracer.activeSpan();
+
+                if (span != null) {
+                    span.log(spanLog.getTimeMillis(), spanLog.getLogEntries());
+                } else {
+                    // Traces started in the pre-OpenTracing style won't have an active span, so just attempt to add as
+                    // is to thread local trace if there is one
+                    requestTracingService.addSpanLog(spanLog);
+                }
+            } else {
+                // If we couldn't get a tracer here, it's because we couldn't get a name from the invocation manager.
+                // In such a case, just try to add the span log to the currently active thread local request trace
+                requestTracingService.addSpanLog(spanLog);
+            }
         }
     }
 

appserver/tests/payara-samples/samples/remote-ejb-tracing/remote-ejb-tracing-client/src/test/java/fish/payara/samples/remote/ejb/tracing/RemoteEjbClientIT.java

@@ -76,7 +76,7 @@ public void executeRemoteEjbMethodIT() {
                 span.setBaggageItem("Wibbles", "Wobbles");
                 String baggageItems = ejb.annotatedMethod();
                 Assert.assertTrue("Baggage items didn't match, received: " + baggageItems,
-                        baggageItems.equals("\nWibbles : Wobbles\n"));
+                        baggageItems.contains("\nWibbles : Wobbles\n"));
 
                 span.setBaggageItem("Nibbles", "Nobbles");
                 baggageItems = ejb.nonAnnotatedMethod();
@@ -102,5 +102,28 @@ public void executeRemoteEjbMethodIT() {
         }
     }
 
+    @Test
+    public void transactionIdAddedAsBaggageIT() {
+        Properties contextProperties = new Properties();
+        contextProperties.setProperty(Context.INITIAL_CONTEXT_FACTORY, "com.sun.enterprise.naming.SerialInitContextFactory");
+        contextProperties.setProperty("org.omg.CORBA.ORBInitialHost", "localhost");
+        contextProperties.setProperty("org.omg.CORBA.ORBInitialPort", "3700");
+
+        try {
+            Context context = new InitialContext(contextProperties);
+            EjbRemote ejb = (EjbRemote) context.lookup("java:global/remote-ejb-tracing-server/Ejb");
+
+            Tracer tracer = GlobalTracer.get();
+
+            try (Scope scope = tracer.buildSpan("ExecuteEjb").startActive(true)) {
+                String baggageItems = ejb.annotatedMethod();
+                Assert.assertTrue("Baggage items didn't contain transaction ID, received: " + baggageItems,
+                        baggageItems.contains("TX-ID"));
+            }
+        } catch (NamingException ne) {
+            Assert.fail("Failed performing lookup:\n" + ne.getMessage());
+        }
+    }
+
 
 }

appserver/transaction/jta/pom.xml

@@ -141,8 +141,14 @@
         </dependency>
         <dependency>
             <groupId>fish.payara.server.internal.payara-modules</groupId>
-            <artifactId>requesttracing-core</artifactId>
+            <artifactId>opentracing-adapter</artifactId>
             <version>${project.version}</version>
+            <scope>provided</scope>
+        </dependency>
+        <dependency>
+            <groupId>io.opentracing</groupId>
+            <artifactId>opentracing-api</artifactId>
+            <scope>provided</scope>
         </dependency>
     </dependencies>
 </project>

appserver/transaction/jta/src/main/java/com/sun/enterprise/transaction/JavaEETransactionManagerSimplified.java

@@ -38,7 +38,7 @@
  * holder.
  */
 
-// Portions Copyright [2016-2019] [Payara Foundation and/or its affiliates.]
+// Portions Copyright [2016-2020] [Payara Foundation and/or its affiliates.]
 
 package com.sun.enterprise.transaction;
 
@@ -59,6 +59,9 @@
 import com.sun.logging.LogDomains;
 import fish.payara.notification.requesttracing.RequestTraceSpanLog;
 import fish.payara.nucleus.requesttracing.RequestTracingService;
+import fish.payara.opentracing.OpenTracingService;
+import io.opentracing.Span;
+import io.opentracing.Tracer;
 import org.glassfish.api.admin.ServerEnvironment;
 import org.glassfish.api.invocation.ComponentInvocation;
 import org.glassfish.api.invocation.InvocationException;
@@ -112,6 +115,8 @@ public class JavaEETransactionManagerSimplified
 
     @Inject protected InvocationManager invMgr;
 
+    @Inject private Provider<OpenTracingService> openTracingServiceProvider;
+
     @Inject private Provider<RequestTracingService> requestTracing;
 
     private JavaEETransactionManagerDelegate delegate;
@@ -198,6 +203,16 @@ public void postConstruct() {
         initProperties();
     }
 
+    private OpenTracingService getOpenTracing() {
+        OpenTracingService openTracingService = openTracingServiceProvider.get();
+        if (openTracingService == null) {
+            _logger.log(Level.INFO, "Error retrieving OpenTracing "
+                    + "service during initialisation of "
+                    + "JavaEETransactionManagerSimplified - NullPointerException");
+        }
+        return openTracingService;
+    }
+
     private RequestTracingService getRequestTracing() {
         RequestTracingService requestTracingService = requestTracing.get();
         if (requestTracingService == null) {
@@ -662,11 +677,12 @@ private JavaEETransactionImpl initJavaEETransaction(int timeout) {
 
         setCurrentTransaction(tx);
 
-        if (requestTracing != null && getRequestTracing().isRequestTracingEnabled()) {
-            RequestTraceSpanLog spanLog = constructJTABeginSpanLog(tx);
-            getRequestTracing().addSpanLog(spanLog);
+        if (openTracingServiceProvider != null) {
+            OpenTracingService openTracingService = getOpenTracing();
+            if (openTracingService != null && openTracingService.isEnabled()) {
+                addJtaEventTraceLog(constructJTABeginSpanLog(tx), tx, openTracingService);
+            }
         }
-
         return tx;
     }
 
@@ -954,9 +970,11 @@ public void commit() throws RollbackException,
                 }
             }
 
-            if (requestTracing != null && tx != null && getRequestTracing().isRequestTracingEnabled()) {
-                RequestTraceSpanLog spanLog = constructJTAEndSpanLog(tx);
-                getRequestTracing().addSpanLog(spanLog);
+            if (openTracingServiceProvider != null) {
+                OpenTracingService openTracingService = getOpenTracing();
+                if (openTracingService != null && openTracingService.isEnabled()) {
+                    addJtaEventTraceLog(constructJTAEndSpanLog(tx), tx, openTracingService);
+                }
             }
         } finally {
             setCurrentTransaction(null); // clear current thread's tx
@@ -992,9 +1010,11 @@ public void rollback() throws IllegalStateException, SecurityException,
                 }
             }
 
-            if (requestTracing != null && tx != null && getRequestTracing().isRequestTracingEnabled()) {
-                RequestTraceSpanLog spanLog = constructJTAEndSpanLog(tx);
-                getRequestTracing().addSpanLog(spanLog);
+            if (openTracingServiceProvider != null) {
+                OpenTracingService openTracingService = getOpenTracing();
+                if (openTracingService != null && openTracingService.isEnabled()) {
+                    addJtaEventTraceLog(constructJTAEndSpanLog(tx), tx, openTracingService);
+                }
             }
         } finally {
             setCurrentTransaction(null); // clear current thread's tx
@@ -1716,6 +1736,32 @@ public JavaEETransaction createImportedTransaction(TransactionInternal jtsTx)
         return tx;
     }
 
+    private void addJtaEventTraceLog(RequestTraceSpanLog spanLog, JavaEETransaction tx,
+            OpenTracingService openTracingService) {
+        Tracer tracer = openTracingService.getTracer(openTracingService.getApplicationName(invMgr));
+
+        if (tracer != null) {
+            Span span = tracer.activeSpan();
+
+            if (span != null) {
+                span.log(spanLog.getTimeMillis(), spanLog.getLogEntries());
+
+                // Add transaction ID as baggage item
+                if (tx != null) {
+                    if (tx.getClass().equals(JavaEETransactionImpl.class)) {
+                        span.setBaggageItem("TX-ID", ((JavaEETransactionImpl) tx).getTransactionId());
+                    } else {
+                        span.setBaggageItem("TransactionInfo", tx.toString());
+                    }
+                }
+            }
+        } else {
+            // If we couldn't get a tracer here, it's because we couldn't get a name from the invocation manager.
+            // In such a case, just try to add the span log to the currently active thread local request trace
+            getRequestTracing().addSpanLog(spanLog);
+        }
+    }
+
     private RequestTraceSpanLog constructJTABeginSpanLog(JavaEETransactionImpl transaction) {
         RequestTraceSpanLog spanLog = new RequestTraceSpanLog("jtaContextBeginEvent");
 

nucleus/payara-modules/opentracing-adapter/src/main/java/fish/payara/opentracing/OpenTracingService.java

@@ -113,6 +113,10 @@ public void event(Event<?> event) {
      * @return The Tracer instance for the given application
      */
     public synchronized Tracer getTracer(String applicationName) {
+        if (applicationName == null) {
+            return null;
+        }
+
         // Get the tracer if there is one
         Tracer tracer = tracers.get(applicationName);