Skip to content

[TEMP] Custom build to investigate missing spans + Test calling DB commit/rollback in shutdown function #1376

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
wants to merge 10 commits into
base: main
Choose a base branch
from
Draft

[TEMP] Custom build to investigate missing spans + Test calling DB commit/rollback in shutdown function #1376

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
10 commits
Select commit Hold shift + click to select a range
1fa81a2
Log interceptRegistrationId on elasticApmInterceptCallsToInternalMeth…
SergeyKleyman Oct 13, 2025
70b8418
Test calling DB commit/rollback in shutdown function
SergeyKleyman Oct 13, 2025
633f81c
Fixed $callEndTxInShutdownFunction not assigned
SergeyKleyman Oct 13, 2025
165b26d
Prepend interceptRegistration when logging
SergeyKleyman Oct 13, 2025
527f571
Log pre/post hooks at DEBUG level
SergeyKleyman Oct 13, 2025
4ef8600
Merge branch 'Log_interceptRegistrationId_in_elasticApmInterceptCalls…
SergeyKleyman Oct 13, 2025
b9eeb05
Fixed failing tests
SergeyKleyman Oct 13, 2025
40d60a6
Merge branch 'Custom_build_SDH' into z_TEMP_Custom_build_and_Test
SergeyKleyman Oct 13, 2025
c4ce7c8
Merge branch 'main' into Test_span_in_function_on_shutdown
SergeyKleyman Oct 14, 2025
78d7aa3
Merge branch 'Test_span_in_function_on_shutdown' into z_TEMP_Custom_b…
SergeyKleyman Oct 14, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 4 additions & 2 deletions agent/native/ext/lifecycle.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -400,6 +400,8 @@ auto buildPeriodicTaskExecutor() {
return periodicTaskExecutor;
}

static const char* gs_custom_build_log_msg_str = "(CUSTOM BUILD 2025-10-13)";

void elasticApmRequestInit()
{
if (!ELASTICAPM_G(globals)->sapi_.isSupported()) {
Expand Down Expand Up @@ -442,7 +444,7 @@ void elasticApmRequestInit()

g_pidOnRequestInit = getCurrentProcessId();

ELASTIC_APM_LOG_DEBUG_FUNCTION_ENTRY_MSG( "parent PID: %d", (int)(getParentProcessId()) );
ELASTIC_APM_LOG_DEBUG_FUNCTION_ENTRY_MSG( "%s parent PID: %d", gs_custom_build_log_msg_str, (int)(getParentProcessId()) );

ResultCode resultCode;

Expand Down Expand Up @@ -560,7 +562,7 @@ void elasticApmRequestShutdown()
return;
}

ELASTIC_APM_LOG_DEBUG_FUNCTION_ENTRY();
ELASTIC_APM_LOG_DEBUG_FUNCTION_ENTRY_MSG( "%s", gs_custom_build_log_msg_str );

Tracer* const tracer = getGlobalTracer();
const ConfigSnapshot* const config = getTracerCurrentConfigSnapshot( tracer );
Expand Down
32 changes: 16 additions & 16 deletions agent/php/ElasticApm/Impl/AutoInstrument/InterceptionManager.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -97,24 +97,24 @@ public function internalFuncCallPreHook(
'interceptedCallArgs' => $this->logger->possiblySecuritySensitive($interceptedCallArgs),
]
);
$loggerProxyTrace = $localLogger->ifTraceLevelEnabledNoLine(__FUNCTION__);
$loggerProxy = $localLogger->ifDebugLevelEnabledNoLine(__FUNCTION__);

$loggerProxyTrace && $loggerProxyTrace->log(__LINE__, 'Entered');
$loggerProxy && $loggerProxy->log(__LINE__, 'Entered');

$interceptRegistration = ArrayUtil::getValueIfKeyExistsElse($interceptRegistrationId, $this->interceptedCallRegistrations, null);
if ($interceptRegistration === null) {
($loggerProxy = $localLogger->ifErrorLevelEnabled(__LINE__, __FUNCTION__))
&& $loggerProxy->log('There is no registration with the given interceptRegistrationId');
($loggerProxyError = $localLogger->ifErrorLevelEnabled(__LINE__, __FUNCTION__))
&& $loggerProxyError->log('There is no registration with the given interceptRegistrationId');
return false;
}
$localLogger->prependAllToContext(compact('interceptRegistration'));

$loggerProxyTrace && $loggerProxyTrace->log(__LINE__, 'Calling preHook...');
$loggerProxy && $loggerProxy->log(__LINE__, 'Calling preHook...');
try {
$preHookRetVal = ($interceptRegistration->preHook)($thisObj, $interceptedCallArgs);
} catch (Throwable $throwable) {
($loggerProxy = $localLogger->ifErrorLevelEnabled(__LINE__, __FUNCTION__))
&& $loggerProxy->logThrowable(
($loggerProxyError = $localLogger->ifErrorLevelEnabled(__LINE__, __FUNCTION__))
&& $loggerProxyError->logThrowable(
$throwable,
'preHook has let a Throwable to escape'
);
Expand All @@ -128,7 +128,7 @@ public function internalFuncCallPreHook(
$this->interceptedCallInProgressPreHookRetVal = $preHookRetVal;
}

$loggerProxyTrace && $loggerProxyTrace->log(__LINE__, 'preHook completed successfully', ['shouldCallPostHook' => $shouldCallPostHook]);
$loggerProxy && $loggerProxy->log(__LINE__, 'preHook completed successfully', ['shouldCallPostHook' => $shouldCallPostHook]);
return $shouldCallPostHook;
}

Expand All @@ -149,28 +149,28 @@ public function internalFuncCallPostHook(
'interceptRegistration' => $this->interceptedCallInProgressRegistration,
]
);
$loggerProxyTrace = $localLogger->ifTraceLevelEnabledNoLine(__FUNCTION__);
$loggerProxyTrace && $loggerProxyTrace->log(__LINE__, 'Entered');
$loggerProxy = $localLogger->ifDebugLevelEnabledNoLine(__FUNCTION__);
$loggerProxy && $loggerProxy->log(__LINE__, 'Entered');

if ($this->interceptedCallInProgressRegistrationId === null) {
($loggerProxy = $this->logger->ifErrorLevelEnabled(__LINE__, __FUNCTION__))
&& $loggerProxy->log('There is no intercepted call in progress');
($loggerProxyError = $this->logger->ifErrorLevelEnabled(__LINE__, __FUNCTION__))
&& $loggerProxyError->log('There is no intercepted call in progress');
return;
}
assert($this->interceptedCallInProgressRegistration !== null);
assert($this->interceptedCallInProgressPreHookRetVal !== null);

$loggerProxyTrace && $loggerProxyTrace->log(__LINE__, 'Calling postHook...');
$loggerProxy && $loggerProxy->log(__LINE__, 'Calling postHook...');
try {
($this->interceptedCallInProgressPreHookRetVal)(
$numberOfStackFramesToSkip + 1,
$hasExitedByException,
$returnValueOrThrown
);
$loggerProxyTrace && $loggerProxyTrace->log(__LINE__, 'postHook completed without throwing');
$loggerProxy && $loggerProxy->log(__LINE__, 'postHook completed without throwing');
} catch (Throwable $throwable) {
($loggerProxy = $localLogger->ifErrorLevelEnabled(__LINE__, __FUNCTION__))
&& $loggerProxy->logThrowable($throwable, 'postHook has thrown');
($loggerProxyError = $localLogger->ifErrorLevelEnabled(__LINE__, __FUNCTION__))
&& $loggerProxyError->logThrowable($throwable, 'postHook has thrown');
}

$this->interceptedCallInProgressRegistrationId = null;
Expand Down
26 changes: 18 additions & 8 deletions tests/ElasticApmTests/ComponentTests/MySQLiAutoInstrumentationTest.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -323,14 +323,16 @@ public static function extractSharedArgs(
?string &$workDbName /* <- out */,
?string &$queryKind /* <- out */,
?bool &$wrapInTx /* <- out */,
?bool &$rollback /* <- out */
?bool &$rollback /* <- out */,
?bool &$callEndTxInShutdownFunction /* <- out */
): void {
$isOOPApi = $args->getBool(self::IS_OOP_API_KEY);
$connectDbName = $args->getNullableString(self::CONNECT_DB_NAME_KEY);
$workDbName = $args->getString(self::WORK_DB_NAME_KEY);
$queryKind = $args->getString(self::QUERY_KIND_KEY);
$wrapInTx = $args->getBool(DbAutoInstrumentationUtilForTests::WRAP_IN_TX_KEY);
$rollback = $args->getBool(DbAutoInstrumentationUtilForTests::ROLLBACK_KEY);
$callEndTxInShutdownFunction = $args->getBool(DbAutoInstrumentationUtilForTests::CALL_END_TX_IN_SHUTDOWN_FUNCTION_KEY);
}

public static function appCodeForTestAutoInstrumentation(MixedMap $appCodeArgs): void
Expand All @@ -342,7 +344,8 @@ public static function appCodeForTestAutoInstrumentation(MixedMap $appCodeArgs):
/* out */ $workDbName,
/* out */ $queryKind,
/* out */ $wrapInTx,
/* out */ $rollback
/* out */ $rollback,
/* out */ $callEndTxInShutdownFunction
);
$host = $appCodeArgs->getString(DbAutoInstrumentationUtilForTests::HOST_KEY);
$port = $appCodeArgs->getInt(DbAutoInstrumentationUtilForTests::PORT_KEY);
Expand Down Expand Up @@ -397,12 +400,18 @@ public static function appCodeForTestAutoInstrumentation(MixedMap $appCodeArgs):
}
$queryResult->close();

if ($wrapInTx) {
self::assertTrue($rollback ? $mySQLi->rollback() : $mySQLi->commit());
$endTxCallFunc = function () use ($wrapInTx, $rollback, $mySQLi, $queryKind) {
if ($wrapInTx) {
self::assertTrue($rollback ? $mySQLi->rollback() : $mySQLi->commit());
}
self::resetDbState($mySQLi, $queryKind);
self::assertTrue($mySQLi->close());
};
if ($callEndTxInShutdownFunction) {
register_shutdown_function($endTxCallFunc);
} else {
$endTxCallFunc();
}

self::resetDbState($mySQLi, $queryKind);
self::assertTrue($mySQLi->close());
}

/**
Expand Down Expand Up @@ -436,7 +445,8 @@ private function implTestAutoInstrumentation(MixedMap $testArgs): void
/* out */ $workDbName,
/* out */ $queryKind,
/* out */ $wrapInTx,
/* out */ $rollback
/* out */ $rollback,
/* out */ $callEndTxInShutdownFunction
);

$testCaseHandle = $this->getTestCaseHandle();
Expand Down
24 changes: 15 additions & 9 deletions tests/ElasticApmTests/ComponentTests/PDOAutoInstrumentationTest.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -181,21 +181,24 @@ public function dataProviderForTestAutoInstrumentation(): iterable
* @param ?string &$dbName
* @param ?bool &$wrapInTx
* @param ?bool &$rollback
* @param ?bool &$callEndTxInShutdownFunction
*
* @param-out string $dbName
* @param-out bool $wrapInTx
* @param-out bool $rollback
* @param-out bool $callEndTxInShutdownFunction
*/
public static function extractSharedArgs(MixedMap $args, /* out */ ?string &$dbName, /* out */ ?bool &$wrapInTx, /* out */ ?bool &$rollback): void
public static function extractSharedArgs(MixedMap $args, /* out */ ?string &$dbName, /* out */ ?bool &$wrapInTx, /* out */ ?bool &$rollback, /* out */ ?bool &$callEndTxInShutdownFunction): void
{
$dbName = $args->getString(DbAutoInstrumentationUtilForTests::DB_NAME_KEY);
$wrapInTx = $args->getBool(DbAutoInstrumentationUtilForTests::WRAP_IN_TX_KEY);
$rollback = $args->getBool(DbAutoInstrumentationUtilForTests::ROLLBACK_KEY);
$callEndTxInShutdownFunction = $args->getBool(DbAutoInstrumentationUtilForTests::CALL_END_TX_IN_SHUTDOWN_FUNCTION_KEY);
}

public static function appCodeForTestAutoInstrumentation(MixedMap $appCodeArgs): void
{
self::extractSharedArgs($appCodeArgs, /* out */ $dbName, /* out */ $wrapInTx, /* out */ $rollback);
self::extractSharedArgs($appCodeArgs, /* out */ $dbName, /* out */ $wrapInTx, /* out */ $rollback, /* out */ $callEndTxInShutdownFunction);

$pdo = new PDO(self::buildConnectionString($dbName));
self::assertTrue($pdo->setAttribute(PDO::ATTR_ERRMODE, PDO::ERRMODE_EXCEPTION));
Expand Down Expand Up @@ -226,7 +229,15 @@ public static function appCodeForTestAutoInstrumentation(MixedMap $appCodeArgs):
}

if ($wrapInTx) {
self::assertTrue($rollback ? $pdo->rollback() : $pdo->commit());
$endTxCallFunc = function () use ($rollback, $pdo) {
self::assertTrue($rollback ? $pdo->rollBack() : $pdo->commit());
};

if ($callEndTxInShutdownFunction) {
register_shutdown_function($endTxCallFunc);
} else {
$endTxCallFunc();
}
}
}

Expand All @@ -248,12 +259,7 @@ private function implTestAutoInstrumentation(MixedMap $testArgs): void
$disableInstrumentationsOptVal = $testArgs->getString(AutoInstrumentationUtilForTests::DISABLE_INSTRUMENTATIONS_KEY);
$isInstrumentationEnabled = $testArgs->getBool(AutoInstrumentationUtilForTests::IS_INSTRUMENTATION_ENABLED_KEY);

self::extractSharedArgs(
$testArgs,
/* out */ $dbNameArg,
/* out */ $wrapInTx,
/* out */ $rollback
);
self::extractSharedArgs($testArgs, /* out */ $dbNameArg, /* out */ $wrapInTx, /* out */ $rollback, /* out */ $callEndTxInShutdownFunction);

$testCaseHandle = $this->getTestCaseHandle();

Expand Down
20 changes: 12 additions & 8 deletions tests/ElasticApmTests/ComponentTests/Util/DbAutoInstrumentationUtilForTests.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -36,9 +36,9 @@ final class DbAutoInstrumentationUtilForTests
public const PASSWORD_KEY = 'PASSWORD';

public const DB_NAME_KEY = 'DB_NAME';
public const USE_SELECT_DB_KEY = 'USE_SELECT_DB';
public const WRAP_IN_TX_KEY = 'WRAP_IN_TX';
public const ROLLBACK_KEY = 'ROLLBACK';
public const CALL_END_TX_IN_SHUTDOWN_FUNCTION_KEY = 'CALL_END_TX_IN_SHUTDOWN_FUNCTION';

/**
* @return callable(array<mixed>): iterable<array<mixed>>
Expand All @@ -53,14 +53,18 @@ public static function wrapTxRelatedArgsDataProviderGenerator(): callable
return function (array $resultSoFar): iterable {
foreach (IterableUtilForTests::ALL_BOOL_VALUES as $wrapInTx) {
$rollbackValues = $wrapInTx ? [false, true] : [false];
$callEndTxInShutdownFunctionValues = $wrapInTx ? [false, true] : [false];
foreach ($rollbackValues as $rollback) {
yield array_merge(
$resultSoFar,
[
self::WRAP_IN_TX_KEY => $wrapInTx,
self::ROLLBACK_KEY => $rollback,
]
);
foreach ($callEndTxInShutdownFunctionValues as $callEndTxInShutdownFunction) {
yield array_merge(
$resultSoFar,
[
self::WRAP_IN_TX_KEY => $wrapInTx,
self::ROLLBACK_KEY => $rollback,
self::CALL_END_TX_IN_SHUTDOWN_FUNCTION_KEY => $callEndTxInShutdownFunction,
]
);
}
}
}
};
Expand Down