diff --git a/prod/native/extension/code/InternalFunctionInstrumentation.cpp b/prod/native/extension/code/InternalFunctionInstrumentation.cpp index dce91ac..1754159 100644 --- a/prod/native/extension/code/InternalFunctionInstrumentation.cpp +++ b/prod/native/extension/code/InternalFunctionInstrumentation.cpp @@ -435,32 +435,37 @@ zend_observer_fcall_handlers elasticRegisterObserver(zend_execute_data *execute_ ELOGF_TRACE(EAPM_GL(logger_), INSTRUMENTATION, "elasticRegisterObserver hash: 0x%X " PRsv "::" PRsv ", not marked to be instrumented", hash, PRsvArg(cls), PRsvArg(func)); } - auto ce = execute_data->func->common.scope; - if (!ce) { - return {nullptr, nullptr}; - } - // lookup for class interfaces - for (uint32_t i = 0; i < ce->num_interfaces; ++i) { - auto classHash = ZSTR_HASH(ce->interfaces[i]->name); - zend_ulong funcHash = ZSTR_HASH(execute_data->func->common.function_name); - zend_ulong ifaceHash = classHash ^ (funcHash << 1); - - callbacks = reinterpret_cast(EAPM_GL(hooksStorage_).get())->find(ifaceHash); - if (callbacks) { - if (EAPM_GL(logger_)->doesMeetsLevelCondition(LogLevel::logLevel_trace)) { - auto [cls, func] = getClassAndFunctionName(execute_data); - ELOGF_TRACE(EAPM_GL(logger_), INSTRUMENTATION, "elasticRegisterObserver hash: 0x%X " PRsv "::" PRsv ", will be instrumented because interface 0x%X '" PRsv "' was marked to be instrumented", hash, PRsvArg(cls), PRsvArg(func), ifaceHash, PRzsArg(ce->interfaces[i]->name)); - } - // copy callbacks from interface storage hash to implementation hash - for (auto &item : *callbacks) { - reinterpret_cast(EAPM_GL(hooksStorage_).get())->store(hash, AutoZval(item.first.get()), AutoZval(item.second.get())); + auto ce = execute_data->func->common.scope; + if (ce) { + for (uint32_t i = 0; i < ce->num_interfaces; ++i) { + auto classHash = ZSTR_HASH(ce->interfaces[i]->name); + zend_ulong funcHash = ZSTR_HASH(execute_data->func->common.function_name); + zend_ulong ifaceHash = classHash ^ (funcHash << 1); + + callbacks = reinterpret_cast(EAPM_GL(hooksStorage_).get())->find(ifaceHash); + if (callbacks) { + if (EAPM_GL(logger_)->doesMeetsLevelCondition(LogLevel::logLevel_trace)) { + auto [cls, func] = getClassAndFunctionName(execute_data); + ELOGF_TRACE(EAPM_GL(logger_), INSTRUMENTATION, "elasticRegisterObserver hash: 0x%X " PRsv "::" PRsv ", will be instrumented because interface 0x%X '" PRsv "' was marked to be instrumented", hash, PRsvArg(cls), PRsvArg(func), ifaceHash, PRzsArg(ce->interfaces[i]->name)); + } + // copy callbacks from interface storage hash to implementation hash + for (auto &item : *callbacks) { + reinterpret_cast(EAPM_GL(hooksStorage_).get())->store(hash, AutoZval(item.first.get()), AutoZval(item.second.get())); + } + break; } - break; } } } + if (EAPM_GL(config_)->get().debug_instrument_all && EAPM_GL(requestScope_)->isFunctional()) { + std::string_view filename(ZSTR_VAL(execute_data->func->op_array.filename), ZSTR_LEN(execute_data->func->op_array.filename)); + if (!(execute_data->func->common.fn_flags & ZEND_ACC_CLOSURE) && filename.find("/ElasticOTel/") == std::string_view::npos && filename.find("/open-telemetry/") == std::string_view::npos) { + callbacks = reinterpret_cast(EAPM_GL(hooksStorage_).get())->storeFront(hash, AutoZval("Elastic\\OTel\\PhpPartFacade::debugPreHook"sv), AutoZval("Elastic\\OTel\\PhpPartFacade::debugPostHook")); + } + } + if (!callbacks) { return {nullptr, nullptr}; } diff --git a/prod/native/extension/code/ModuleIniEntries.cpp b/prod/native/extension/code/ModuleIniEntries.cpp index 78d517d..847a502 100644 --- a/prod/native/extension/code/ModuleIniEntries.cpp +++ b/prod/native/extension/code/ModuleIniEntries.cpp @@ -65,7 +65,7 @@ ELASTIC_OTEL_INI_ENTRY(EL_STRINGIFY(ELASTIC_OTEL_CFG_OPT_NAME_VERIFY_SERVER_CERT ELASTIC_OTEL_INI_ENTRY(EL_STRINGIFY(ELASTIC_OTEL_CFG_OPT_NAME_DEBUG_DIAGNOSTICS_FILE)) ELASTIC_OTEL_INI_ENTRY(EL_STRINGIFY(ELASTIC_OTEL_CFG_OPT_NAME_MAX_SEND_QUEUE_SIZE)) ELASTIC_OTEL_INI_ENTRY(EL_STRINGIFY(ELASTIC_OTEL_CFG_OPT_NAME_ASYNC_TRANSPORT)) - +ELASTIC_OTEL_INI_ENTRY(EL_STRINGIFY(ELASTIC_OTEL_CFG_OPT_NAME_DEBUG_INSTRUMENT_ALL)) PHP_INI_END() namespace elasticapm::php { diff --git a/prod/native/libcommon/code/ConfigurationManager.h b/prod/native/libcommon/code/ConfigurationManager.h index 5e97b22..0ddc20c 100644 --- a/prod/native/libcommon/code/ConfigurationManager.h +++ b/prod/native/libcommon/code/ConfigurationManager.h @@ -111,7 +111,8 @@ class ConfigurationManager { BUILD_METADATA(ELASTIC_OTEL_CFG_OPT_NAME_VERIFY_SERVER_CERT, OptionMetadata::type::boolean, false), BUILD_METADATA(ELASTIC_OTEL_CFG_OPT_NAME_MAX_SEND_QUEUE_SIZE, OptionMetadata::type::bytes, false), BUILD_METADATA(ELASTIC_OTEL_CFG_OPT_NAME_ASYNC_TRANSPORT, OptionMetadata::type::boolean, false), - BUILD_METADATA(ELASTIC_OTEL_CFG_OPT_NAME_ASYNC_TRANSPORT_SHUTDOWN_TIMEOUT, OptionMetadata::type::duration, false)}; + BUILD_METADATA(ELASTIC_OTEL_CFG_OPT_NAME_ASYNC_TRANSPORT_SHUTDOWN_TIMEOUT, OptionMetadata::type::duration, false), + BUILD_METADATA(ELASTIC_OTEL_CFG_OPT_NAME_DEBUG_INSTRUMENT_ALL, OptionMetadata::type::boolean, false)}; // clang-format on }; diff --git a/prod/native/libcommon/code/ConfigurationSnapshot.h b/prod/native/libcommon/code/ConfigurationSnapshot.h index cac62f7..e951129 100644 --- a/prod/native/libcommon/code/ConfigurationSnapshot.h +++ b/prod/native/libcommon/code/ConfigurationSnapshot.h @@ -38,6 +38,8 @@ #define ELASTIC_OTEL_CFG_OPT_NAME_ASYNC_TRANSPORT async_transport #define ELASTIC_OTEL_CFG_OPT_NAME_ASYNC_TRANSPORT_SHUTDOWN_TIMEOUT async_transport_shutdown_timeout +#define ELASTIC_OTEL_CFG_OPT_NAME_DEBUG_INSTRUMENT_ALL debug_instrument_all + namespace elasticapm::php { using namespace std::string_literals; @@ -56,6 +58,7 @@ struct ConfigurationSnapshot { std::size_t ELASTIC_OTEL_CFG_OPT_NAME_MAX_SEND_QUEUE_SIZE = 2 * 1024 * 1204; bool ELASTIC_OTEL_CFG_OPT_NAME_ASYNC_TRANSPORT = true; std::chrono::milliseconds ELASTIC_OTEL_CFG_OPT_NAME_ASYNC_TRANSPORT_SHUTDOWN_TIMEOUT = std::chrono::seconds(30); + bool ELASTIC_OTEL_CFG_OPT_NAME_DEBUG_INSTRUMENT_ALL = false; uint64_t revision = 0; }; diff --git a/prod/native/libcommon/code/InstrumentedFunctionHooksStorage.h b/prod/native/libcommon/code/InstrumentedFunctionHooksStorage.h index 79319ea..9c3ae36 100644 --- a/prod/native/libcommon/code/InstrumentedFunctionHooksStorage.h +++ b/prod/native/libcommon/code/InstrumentedFunctionHooksStorage.h @@ -42,6 +42,11 @@ class InstrumentedFunctionHooksStorage : public InstrumentedFunctionHooksStorage callbacks_[functionKey].emplace_back(callbacks_t(std::move(callableOnEntry), std::move(callableOnExit))); } + std::list *storeFront(key_t functionKey, callback_t callableOnEntry, callback_t callableOnExit) { + callbacks_[functionKey].emplace_front(callbacks_t(std::move(callableOnEntry), std::move(callableOnExit))); + return &callbacks_[functionKey]; + } + std::list *find(key_t functionKey) { auto found = callbacks_.find(functionKey); if (found == std::end(callbacks_)) { diff --git a/prod/php/ElasticOTel/PhpPartFacade.php b/prod/php/ElasticOTel/PhpPartFacade.php index b42120f..b89993a 100644 --- a/prod/php/ElasticOTel/PhpPartFacade.php +++ b/prod/php/ElasticOTel/PhpPartFacade.php @@ -26,7 +26,14 @@ use Elastic\OTel\Util\HiddenConstructorTrait; use Elastic\OTel\Log\ElasticLogWriter; use Elastic\OTel\HttpTransport\ElasticHttpTransportFactory; +use OpenTelemetry\API\Globals; use OpenTelemetry\SDK\SdkAutoloader; +use OpenTelemetry\API\Trace\Span; +use OpenTelemetry\API\Trace\SpanKind; +use OpenTelemetry\API\Trace\StatusCode; +use OpenTelemetry\Context\Context; +use OpenTelemetry\SemConv\TraceAttributes; +use OpenTelemetry\SemConv\Version; use RuntimeException; use Throwable; @@ -47,6 +54,7 @@ final class PhpPartFacade use HiddenConstructorTrait; private static ?self $singletonInstance = null; + private static bool $rootSpanEnded = false; /** * Called by the extension @@ -98,7 +106,9 @@ public static function bootstrap(string $elasticOTelNativePartVersion, int $maxE return false; } - Traces\ElasticRootSpan::startRootSpan(); + Traces\ElasticRootSpan::startRootSpan(function () { + PhpPartFacade::$rootSpanEnded = true; + }); self::$singletonInstance = new self(); } catch (Throwable $throwable) { @@ -228,4 +238,57 @@ public static function shutdown(): void { self::$singletonInstance = null; } + + /** @phpstan-ignore-next-line */ + public static function debugPreHook(mixed $object, array $params, ?string $class, string $function, ?string $filename, ?int $lineno): void + { + if (self::$rootSpanEnded) { + return; + } + + $tracer = Globals::tracerProvider()->getTracer( + 'co.elastic.edot.php.debug', + null, + Version::VERSION_1_25_0->url(), + ); + + $parent = Context::getCurrent(); + /** @phpstan-ignore-next-line */ + $span = $tracer->spanBuilder($class ? $class . "::" . $function : $function) + ->setSpanKind(SpanKind::KIND_CLIENT) + ->setParent($parent) + ->setAttribute(TraceAttributes::CODE_NAMESPACE, $class) + ->setAttribute(TraceAttributes::CODE_FUNCTION, $function) + ->setAttribute(TraceAttributes::CODE_FILEPATH, $filename) + ->setAttribute(TraceAttributes::CODE_LINENO, $lineno) + ->setAttribute('call.arguments', print_r($params, true)) + ->startSpan(); + + $context = $span->storeInContext($parent); + Context::storage()->attach($context); + } + + /** @phpstan-ignore-next-line */ + public static function debugPostHook(mixed $object, array $params, mixed $retval, ?Throwable $exception): void + { + if (self::$rootSpanEnded) { + return; + } + + $scope = Context::storage()->scope(); + if (!$scope) { + return; + } + + $scope->detach(); + $span = Span::fromContext($scope->context()); + $span->setAttribute('call.return_value', print_r($retval, true)); + + if ($exception) { + $span->recordException($exception, [TraceAttributes::EXCEPTION_ESCAPED => true]); + $span->setStatus(StatusCode::STATUS_ERROR, $exception->getMessage()); + } + + $span->end(); + } } diff --git a/prod/php/ElasticOTel/Traces/ElasticRootSpan.php b/prod/php/ElasticOTel/Traces/ElasticRootSpan.php index 56b3a2f..036384a 100644 --- a/prod/php/ElasticOTel/Traces/ElasticRootSpan.php +++ b/prod/php/ElasticOTel/Traces/ElasticRootSpan.php @@ -46,7 +46,7 @@ class ElasticRootSpan private const DEFAULT_SPAN_NAME_FOR_SCRIPT = '