WordPress instrumentation performance investigation

agent/native/ext/ConfigManager.cpp

@@ -962,7 +962,7 @@ static void initOptionsMetadata( OptionMetadata* optsMeta )
             buildBoolOptionMetadata,
             astProcessEnabled,
             ELASTIC_APM_CFG_OPT_NAME_AST_PROCESS_ENABLED,
-            /* defaultValue: */ true );
+            /* defaultValue: */ false );
 
     ELASTIC_APM_INIT_METADATA(
             buildBoolOptionMetadata,

agent/native/ext/lifecycle.cpp

@@ -500,6 +500,23 @@ static void unregisterErrorAndExceptionHooks() {
 
 }
 
+void logImportantAgentInfo( const ConfigSnapshot* config, String calledFromFunc )
+{
+    ELASTIC_APM_LOG_INFO(
+        "Custom build based on version: %s"
+        "; Custom changes:"
+        " * span stack trace disabled by default (stack_trace_min_duration: -1)"
+        " * WordPress instrumentation disabled by default (ast_process_enabled: false)"
+        "; config->enabled: %s."
+        "; SAPI module name: %s"
+        "; Called from: %s"
+        , PHP_ELASTIC_APM_VERSION
+        , boolToString( config->enabled )
+        , getPhpSapiModuleName()
+        , calledFromFunc
+    );
+}
+
 void elasticApmModuleInit( int moduleType, int moduleNumber )
 {
     ELASTIC_APM_LOG_DIRECT_DEBUG( "%s entered: moduleType: %d, moduleNumber: %d, parent PID: %d", __FUNCTION__, moduleType, moduleNumber, (int)(getParentProcessId()) );
@@ -526,10 +543,11 @@ void elasticApmModuleInit( int moduleType, int moduleNumber )
     ELASTIC_APM_CALL_IF_FAILED_GOTO( ensureLoggerInitialConfigIsLatest( tracer ) );
     ELASTIC_APM_CALL_IF_FAILED_GOTO( ensureAllComponentsHaveLatestConfig( tracer ) );
 
-    logSupportabilityInfo( logLevel_debug );
-
     config = getTracerCurrentConfigSnapshot( tracer );
 
+    logImportantAgentInfo( config, __FUNCTION__ );
+    logSupportabilityInfo( logLevel_debug );
+
     if ( ! config->enabled )
     {
         resultCode = resultSuccess;
@@ -580,6 +598,8 @@ void elasticApmModuleShutdown( int moduleType, int moduleNumber )
     Tracer* const tracer = getGlobalTracer();
     const ConfigSnapshot* const config = getTracerCurrentConfigSnapshot( tracer );
 
+    logImportantAgentInfo( config, __FUNCTION__ );
+
     if ( ! config->enabled )
     {
         resultCode = resultSuccess;

agent/native/ext/util_for_PHP.cpp

@@ -275,6 +275,11 @@ ResultCode callPhpFunctionRetZval( StringView phpFunctionName, uint32_t argsCoun
     return callPhpFunction( phpFunctionName, argsCount, args, consumeZvalRetVal, retVal );
 }
 
+String getPhpSapiModuleName()
+{
+    return sapi_module.name;
+}
+
 bool isPhpRunningAsCliScript()
 {
     return strcmp( sapi_module.name, "cli" ) == 0;

agent/native/ext/util_for_PHP.h

@@ -85,6 +85,7 @@ ResultCode callPhpFunctionRetZval( StringView phpFunctionName, uint32_t argsCoun
 
 void getArgsFromZendExecuteData( zend_execute_data *execute_data, size_t dstArraySize, zval dstArray[], uint32_t* argsCount );
 
+String getPhpSapiModuleName();
 bool isPhpRunningAsCliScript();
 bool detectOpcachePreload();
 bool isScriptRestricedByOpcacheAPI();

agent/php/ElasticApm/Impl/Config/AllOptionsMetadata.php

@@ -82,7 +82,7 @@ public static function get(): array
         /** @var array<string, OptionMetadata<mixed>> $value */
         $value = [
             OptionNames::API_KEY                                    => new NullableStringOptionMetadata(),
-            OptionNames::AST_PROCESS_ENABLED                        => new BoolOptionMetadata(/* defaultValue: */ true),
+            OptionNames::AST_PROCESS_ENABLED                        => new BoolOptionMetadata(OptionDefaultValues::AST_PROCESS_ENABLED),
             OptionNames::AST_PROCESS_DEBUG_DUMP_CONVERTED_BACK_TO_SOURCE
                                                                     => new BoolOptionMetadata(/* defaultValue: */ true),
             OptionNames::AST_PROCESS_DEBUG_DUMP_FOR_PATH_PREFIX     => new NullableStringOptionMetadata(),

agent/php/ElasticApm/Impl/Config/OptionDefaultValues.php

@@ -34,7 +34,8 @@ final class OptionDefaultValues
 {
     use StaticClassTrait;
 
-    public const SPAN_STACK_TRACE_MIN_DURATION = 5;
+    public const AST_PROCESS_ENABLED = false;
+    public const SPAN_STACK_TRACE_MIN_DURATION = -1;
     public const STACK_TRACE_LIMIT = 50;
     public const TRANSACTION_MAX_SPANS = 500;
 }

tests/ElasticApmTests/ComponentTests/Util/ComponentTestCaseBase.php

@@ -24,6 +24,7 @@
 namespace ElasticApmTests\ComponentTests\Util;
 
 use Elastic\Apm\Impl\AutoInstrument\AutoInstrumentationBase;
+use Elastic\Apm\Impl\Config\OptionDefaultValues;
 use Elastic\Apm\Impl\Config\OptionNames;
 use Elastic\Apm\Impl\GlobalTracerHolder;
 use Elastic\Apm\Impl\Log\Level as LogLevel;
@@ -197,7 +198,8 @@ protected static function implTestIsAutoInstrumentationEnabled(string $instrClas
         $actualNames = $instr->keywords();
         $actualNames[] = $instr->name();
         self::assertEqualAsSets($expectedNames, $actualNames);
-        self::assertTrue($instr->isEnabled());
+        $isEnabledByDefault = OptionDefaultValues::AST_PROCESS_ENABLED || (!$instr->requiresUserlandCodeInstrumentation()); // @phpstan-ignore-line
+        self::assertSame($isEnabledByDefault, $instr->isEnabled());
 
         /**
          * @param string $name
@@ -238,7 +240,7 @@ protected static function implTestIsAutoInstrumentationEnabled(string $instrClas
             $dbgCtx->clearCurrentSubScope(['disableInstrumentationsOptVal' => $disableInstrumentationsOptVal]);
             $tracer = self::buildTracerForTests()->withConfig(OptionNames::DISABLE_INSTRUMENTATIONS, $disableInstrumentationsOptVal)->build();
             $instr = new $instrClassName($tracer);
-            self::assertTrue($instr->isEnabled());
+            self::assertSame($isEnabledByDefault, $instr->isEnabled());
         }
         $dbgCtx->popSubScope();
 

tests/ElasticApmTests/UnitTests/InferredSpansBuilderTest.php

@@ -143,6 +143,17 @@ private function helperForTestOneStackTrace(InferredSpansBuilder $builder): arra
         return $stackTrace;
     }
 
+    public function isSpanStackTraceEnabled(SpanDto $span): bool
+    {
+        $dummyTx = $this->tracer->beginTransaction('dummy_temp_TX_name', 'dummy_temp_TX_type');
+        $result =
+            $dummyTx instanceof Transaction
+            && $dummyTx->shouldCollectStackTraceForSpanDuration($span->duration)
+            && (StackTraceUtil::convertLimitConfigToMaxNumberOfFrames($dummyTx->getStackTraceLimitConfig()) !== 0);
+        $dummyTx->discard();
+        return $result;
+    }
+
     public function testOneStackTrace(): void
     {
         AssertMessageStack::newScope(/* out */ $dbgCtx);
@@ -190,8 +201,12 @@ function (InferredSpansBuilder $builder) use (&$expectedStackTrace, $expectedTim
         TraceValidator::validate(new TraceActual($this->mockEventSink->idToTransaction(), $this->mockEventSink->idToSpan()));
 
         $expectedStackTraceConvertedToApm = StackTraceUtil::convertClassicToApmFormat($expectedStackTrace, /* maxNumberOfFrames */ null);
-        self::assertNotNull($span->stackTrace);
-        StackTraceExpectations::fromFrames($expectedStackTraceConvertedToApm)->assertMatches($span->stackTrace);
+        if ($this->isSpanStackTraceEnabled($span)) {
+            self::assertNotNull($span->stackTrace);
+            StackTraceExpectations::fromFrames($expectedStackTraceConvertedToApm)->assertMatches($span->stackTrace);
+        } else {
+            self::assertNull($span->stackTrace);
+        }
     }
 
     private function charDiagramFuncNameToStackTraceFrame(string $funcName): ClassicFormatStackTraceFrame
@@ -1358,22 +1373,24 @@ function (InferredSpansBuilder $builder) use ($stackDepthVariants): void {
                 TestCaseBase::assertNull($span->stackTrace);
                 continue;
             }
-            TestCaseBase::assertNotNull($span->stackTrace);
-
-            if ($expectedMaxNumberOfFrames !== null) {
-                TestCaseBase::assertLessThanOrEqual($expectedMaxNumberOfFrames, count($span->stackTrace));
-            }
-
-            $dbgCtx->pushSubScope();
-            foreach (RangeUtil::generateUpTo(count($span->stackTrace)) as $stackFrameIndex) {
-                $dbgCtx->add(['stackFrameIndex' => $stackFrameIndex]);
-                $currentExpectedClassicFormatFrame = self::genFrameForSpanWithStackDepth($spanIndex, $stackFrameIndex, $stackDepth);
-                $dbgCtx->add(['currentExpectedClassicFormatFrame' => $currentExpectedClassicFormatFrame]);
-                $prevExpectedClassicFormatFrame = $stackFrameIndex === 0 ? null : self::genFrameForSpanWithStackDepth($spanIndex, $stackFrameIndex - 1, $stackDepth);
-                $dbgCtx->add(['prevExpectedClassicFormatFrame' => $prevExpectedClassicFormatFrame]);
-                StackTraceFrameExpectations::fromClassicFormat($currentExpectedClassicFormatFrame, $prevExpectedClassicFormatFrame)->assertMatches($span->stackTrace[$stackFrameIndex]);
+            if ($this->isSpanStackTraceEnabled($span)) {
+                self::assertNotNull($span->stackTrace);
+                if ($expectedMaxNumberOfFrames !== null) {
+                    TestCaseBase::assertLessThanOrEqual($expectedMaxNumberOfFrames, count($span->stackTrace));
+                }
+                $dbgCtx->pushSubScope();
+                foreach (RangeUtil::generateUpTo(count($span->stackTrace)) as $stackFrameIndex) {
+                    $dbgCtx->add(['stackFrameIndex' => $stackFrameIndex]);
+                    $currentExpectedClassicFormatFrame = self::genFrameForSpanWithStackDepth($spanIndex, $stackFrameIndex, $stackDepth);
+                    $dbgCtx->add(['currentExpectedClassicFormatFrame' => $currentExpectedClassicFormatFrame]);
+                    $prevExpectedClassicFormatFrame = $stackFrameIndex === 0 ? null : self::genFrameForSpanWithStackDepth($spanIndex, $stackFrameIndex - 1, $stackDepth);
+                    $dbgCtx->add(['prevExpectedClassicFormatFrame' => $prevExpectedClassicFormatFrame]);
+                    StackTraceFrameExpectations::fromClassicFormat($currentExpectedClassicFormatFrame, $prevExpectedClassicFormatFrame)->assertMatches($span->stackTrace[$stackFrameIndex]);
+                }
+                $dbgCtx->popSubScope();
+            } else {
+                self::assertNull($span->stackTrace);
             }
-            $dbgCtx->popSubScope();
         }
         $dbgCtx->popSubScope();
     }