[Bug]: seeing host-unparsable-host and "CURL request failure" in apm in curl_multi_exec context

[skranz-codi]

Bug report

I was waiting for the fix for #1156 since some time and was happy to try out 0.95 and later 0.96. while the problem described in #1156 looks fixed now, i see the following in dd-apm now even if the curl calls work fine like before as far as i can tell:

going back to pre 0.91.2 (the version i used before) brings back the old behavior (no curl_exec spans but also no errors in dd).
the guzzle transfer span right before the curl multi spans looks good, btw (no problem with the hostname):


the actual curl request url looks something like that: https://foo.bar.eu:8443/foo/bar/baz .
this code runs locally inside a docker container via docker-compose with configured extra-hosts like that:
foo.bar.eu: 172.xxx.xxx.xxx

sadly i was not able to find where the ddtrace code brakes while debugging this issue. i did not find any other issue regarding this topic so i created this issue. do you need more info from my side?

thx in advance!

PHP version

8.1.21

Tracer or profiler version

0.95.0 and 0.96.0

Installed extensions

[PHP Modules]
apcu
bcmath
Core
ctype
curl
date
ddappsec
ddtrace
dom
fileinfo
filter
ftp
gd
hash
iconv
json
libxml
mbstring
mysqlnd
openssl
pcntl
pcre
PDO
pdo_mysql
pdo_sqlite
pdo_sqlsrv
Phar
posix
readline
redis
Reflection
session
SimpleXML
sodium
SPL
sqlite3
sqlsrv
standard
tokenizer
xdebug
xml
xmlreader
xmlwriter
Zend OPcache
zip
zlib

[Zend Modules]
Xdebug
Zend OPcache
ddappsec
ddtrace

Output of phpinfo()

Upgrading from

0.91.2

[PROFeNoM]

Hi @skranz-codi !

After doing some testing on my side, using guzzle, I may have been able to reproduce your issue:

I'd have what I call "dummy curl_exec spans", most notably with host-unparsable-host. I tried some changes in a branch of mine that aims to address some cases.

Could please try out this artifact (CI job)? To use the artifact, you can simply replace the datadog-setup.php link you are using when installing the tracer with the one from the artifact.

[skranz-codi]

hi @PROFeNoM and thx for the response!
I tried your version, but the issue sadly is still there:

i checked the build pipe and i am quite sure i am now using your version when installing the extension:

One thing I never fully understood: I have to install the extension AND add the dependency via composer ("datadog/dd-trace": "0.96.0"), right? While testing your version i still have the 0.96.0 composer lib installed. Is this ok?

Thx again for your effort!

[PROFeNoM]

Hi @skranz-codi !

Alright, I'll try to reproduce it further. Can I please know how are you making these requests (the essence of the code that is running)? What I was trying was to do some getAsync and wait for them (as you may see in this draft test file).

If you have this information, I'd be interested to know what status code you expect from these requests (so that I can try to reproduce it with the same type of request).

Thanks

I have to install the extension AND add the dependency via composer ("datadog/dd-trace": "0.96.0"), right? While testing your version i still have the 0.96.0 composer lib installed.

You don't have to. Only the extension is required.

Is this ok?

It shouldn't be a problem; it isn't required for common use cases.

[skranz-codi]

Hi @PROFeNoM ,
i try to list all the pieces from the "outside" to the "inside":

$results = Utils::unwrap([ 
'foo' => $fooService->getFoo($id),
'bar' => $barService->getBar($id),
'baz' => $bazService->getBaz($id),
]);

inside those service calls:

return $this->client->getAsync('/foo/bar/baz' , $options + ['http_errors' => false,]);

this is how the client is build:

$guzzleClient = new HttpClient([
'base_uri' => $config->get('foo.client.base_uri'),
'auth' => [ 
$config->get('foo.client.auth.username'), 
$config->get('foo.client.auth.password')
],
'verify' => $config->get('foo.client.verify'),
'timeout' => $config->get('foo.client.timeout'),
'allow_redirects' => false,
'handler' => $handlerStack,
'headers' => [ 
'Accept' => 'application/json', 
'Accept-Encoding' => 'gzip, deflate', 
'foo-statistics' => $this->getFooHeaderValue($config),
],
]);

and here the handlerstack:

$this->app->singleton(HttpFooHandlerStack::class, static function (Application $app) {
    $handlerStack = HttpFooHandlerStack::create($app->make(CurlMultiHandler::class));
    $handlerStack->push($app->make(FooErrorHandlingMiddleware::class)->__invoke());
    $handlerStack->before('http_errors', $app->make(HttpLoggingMiddleware::class)->__invoke());
    return $handlerStack;
});

the middlewares look kind of like this:

public function __invoke(): callable{
    return function (callable $handler) {
        return function (RequestInterface $request, array $options) use ($handler) {
            return $handler($request, $options)->then($this->handleResponse($request));
        };
    }
;}

 private function handleResponse(RequestInterface $request): callable
{
        return function (ResponseInterface $response) use ($request) {
            ...
        }
}

and

public function __invoke(){
    return function (callable $handler) {
        return function (RequestInterface $request, array $options) use ($handler) {
            $id = Uuid::uuid4()->toString();
            $request = $this->handleRequest($request, $id);
            $start = microtime(true);
            return $this
                ->getPromise($request, $options, $handler)
                ->then(
                    $this->handleResponse($request, $start, $id),
                    $this->handleRejection($id)
                );
        };
    };
}

private function getPromise(RequestInterface $request, array $options, callable $next): PromiseInterface
{
        return $next($request, $options);
}

private function handleRequest(RequestInterface $request, string $guzzleRequestId): RequestInterface
{
...
}

private function handleResponse(RequestInterface $request, float $start, string $guzzleRequestId)
{
        return function (ResponseInterface $response) use ($request, $start, $guzzleRequestId) {
            return $response;
        };
}

While checking this out i made some more tests and found out, that leaving out the second and third call from the unwrap, the error is gone and the first request will be displayed correctly in the dd ui:

$results = Utils::unwrap([ 
'foo' => $fooService->getFoo($id),
]);

Hope this helps. Let me know if i can give you more infos.

[PROFeNoM]

Hi @skranz-codi!

Thanks for your fantastic description.

This time I've made another artifact (CI Job - Branch) that should cover some additional cases, especially when considering non-erroneous requests (which is your case) 🤞

[skranz-codi]

i only had 5 minutes but this looks really promising:

thx so far.

[PROFeNoM]

Hey @skranz-codi 👋

FYI, the 0.97.0 release was made yesterday, which includes the PR #2460 :)

[skranz-codi]

hi, i am already testing it and it still looks very good 👍 thx again for the fix!