dd-trace-php

dd-trace-php copied to clipboard

Describe the bug Traces don't seem to be collected from static method calls. I have a class Configuration loaded into global namespace via composer and a dd_trace wrapper like so:

dd_trace("Configuration", "testTracing", function (...$args) {
    // Start a new span
    $scope = \DDTrace\GlobalTracer::get()->startActiveSpan('Configuration.testTracing');
    $span = $scope->getSpan();

    // Access object members via $this
    $span->setTag(\DDTrace\Tag::RESOURCE_NAME, 'testTracing');

    try {
        // Execute the original method. Note: dd_trace_forward_call() - handles any parameters automatically
        $result = dd_trace_forward_call();

        return $result;
    } catch (Exception $e) {
        // Inform the tracer that there was an exception thrown
        $span->setError($e);
        // Bubble up the exception
        throw $e;
    } finally {
        // Close the span
        $span->finish();
    }
});

This is done immediately after loading the composer autoloader. When the method is called (Configuration::testTracing()), no spans appear in addition to the web.request Manually starting a span and finishing it works as expected.

However, the documentation is slightly confusing:

1. https://docs.datadoghq.com/tracing/manual_instrumentation/php/

• this creates a span, gets it, forwards the method call and eventually closes the span.

2. https://docs.datadoghq.com/tracing/guide/instrument_custom_method/?tab=php

• this gets the scope, forwards the call and then closes the scope - slightly different than the above.

Should either/any of the methods work with static functions?

Thanks!

PHP Info

• PHP 7.4.4 / Xdebug v2.9.4

[PHP Modules]
amqp
ast
bcmath
Core
ctype
curl
date
ddtrace
dom
exif
fileinfo
filter
ftp
gd
gettext
hash
iconv
igbinary
intl
json
libxml
mbstring
mysqli
mysqlnd
openssl
pcre
PDO
pdo_mysql
pdo_sqlite
Phar
posix
readline
redis
Reflection
session
SimpleXML
soap
sockets
sodium
SPL
sqlite3
standard
tokenizer
xdebug
xml
xmlreader
xmlwriter
Zend OPcache
zip
zlib

[Zend Modules]
Xdebug
Zend OPcache

OS Info

• Debian GNU/Linux 10 (buster)

Hello, @andrei-dascalu. We definitely support static methods! I haven't been able to reproduce your issue with the information provided; the trace always appears and has the Configuration.testTracing span. My index.php file is like this:

<?php
require __DIR__ . '/vendor/autoload.php';

dd_trace("Configuration", "testTracing", function (...$args) {
    // << integration as you posted here >>
});

Configuration::testTracing();

My composer.json is like this:

{
  "autoload": {
    "files": ["src/Configuration.php"]
  }
}

Is this the same structure as your code?

Hi,

In essence yes, that's the structure. I'm not sure how to debug this on my side. Is there anything that might interfere with either the extension or the dd-trace library that wouldn't result in an error/exception?

Thanks

@andrei-dascalu Sorry for the lapse in communication. I highly recommend upgrading to xdebug 2.9.5. This release of xdebug has a fix that is necessary for our tracer to work alongside of it.

Aside from that, there is another user who is reporting issues on PHP 7.4 with opcache enabled. Are you willing to try disabling opcache to see if it affects your issue? I have been unable to reproduce your issue and theirs.

@morrisonlevi I am having the same issue, static method calls are not triggering my \DDTrace\trace_method() setup. I've tried installing and updating xdebug, removing xdebug entirely, enabling/disabling opcache etc - no change.

@silvervest can you provide a snippet to reproduce your specific issue? Static methods are expected to be traced.

As an example, on PHP 7.3 with the latest tracer, the following snippet:

<?php

namespace Some\Library;

use DDTrace\SpanData;

echo "Hello!\n";

class Service
{
    public static function handle()
    {
        \usleep(5000);
    }
}

\DDTrace\trace_method('Some\Library\Service', 'handle', function (SpanData $span) {
    $span->service = 'my-static-service';
});

Service::handle();

Is expected to generate the following trace

Also, are you calling trace_method before its target is called? For example, it's required that trace_method('Some\Library\Service', 'handle') is called before Some\Library\Service::handle() is called. This is a somewhat recent requirement, and in the future it may be required to call trace_method before the the target is even compiled.

@morrisonlevi Yes, our tracing is setup as early as possible, after autoloading but just prior to our application's bootstrapping.

@labbati Your example code does work, which lead me to more digging without our app framework, and I think I have uncovered the issue. While the method being called is static, it appears that the framework is using call_user_func_array to call it, and I can confirm that this is what is not triggering the trace, using the following snippet:

<?php

namespace Some\Library;

use DDTrace\SpanData;

class Service
{
    public static function handle()
    {
        echo "handle\n";
        \usleep(5000);
    }
}

\DDTrace\trace_method('Some\Library\Service', 'handle', function (SpanData $span) {
    $span->service = 'my-static-service';
    echo "hook\n";
});

echo "static\n";
Service::handle();

echo "called\n";
call_user_func_array(['Some\Library\Service', 'handle'], []);

Correct me if I'm wrong here, but the output expected would be static handle hook called handle hook, but in my case I am seeing static handle hook called handle showing the method being called twice but the trace_method only firing on the static call specifically.

Additionally, if I remove the static-ness of this and just use a regular method call, the call_user_func_array call is still not being hooked by trace_method

I have just noticed that I did not escape the namespace for my call to call_user_func_array and when doing so it works as expected. Thus, this is an issue with our app framework and not an issue with ddtrace and/or statics.

However, after doing even more digging, I've now found an area of the framework where it's using Reflection to make the method call and this is not tracing either, like so:

$class = new \ReflectionClass('Some\Library\Service');
$method = $class->getMethod('handle');
$method->invokeArgs(null, []);

This is a partial duplicate of #443: call_user_func and call_user_func_array don't work correctly with Namespace.

I don't think we have had a report of the Reflection defect before. Do you mind if we change the title of this ticket to Methods invoked by Reflection are not traced or something like that and track it here? I suspect the implementation would be different enough from the call_user_func cases it ought to be tracked separately.

This isn't my original ticket, and I'm not sure if OP's issue here is still relevant, though I think my issue has deviated from the OP's issue significantly now. I don't mind, but it's your issue tracker :)

Re: call_user_func_array, thanks I didn't see that ticket. Will keep an eye on it, but we can also patch our framework to be compatible here so that's not a huge issue for now.

Hey @andrei-dascalu, do you still relate to this issue?

Otherwise, as mentioned in #443, methods invoked by reflection are now traced since version 0.76.0 😃