Laravel fail to send trace to opentelemetry collector

[TuanVu2504]

Describe your environment

PHP 8.2.0
Laravel 9.19

php --ri=opentelemetry
opentelemetry
opentelemetry hooks => enabled
extension version => 1.0.0
Directive => Local Value => Master Value
opentelemetry.conflicts => no value => no value
opentelemetry.validate_hook_functions => On => On

php --ri openswoole
openswoole
Open Swoole => enabled
Author => Open Swoole Group <hello@openswoole.com>
Version => 22.0.0
Built => Dec 21 2022 21:53:14
coroutine => enabled with boost asm context
epoll => enabled
eventfd => enabled
signalfd => enabled
spinlock => enabled
rwlock => enabled
sockets => enabled
openssl => OpenSSL 1.1.1s  1 Nov 2022
dtls => enabled
http2 => enabled
hook-curl => enabled
pcre => enabled
zlib => 1.2.12
brotli => E16777225/D16777225
mutex_timedlock => enabled
pthread_barrier => enabled
futex => enabled
mysqlnd => enabled
postgresql => enabled
Directive => Local Value => Master Value
openswoole.enable_coroutine => On => On
openswoole.enable_preemptive_scheduler => Off => Off
openswoole.display_errors => On => On
openswoole.unixsock_buffer_size => 8388608 => 838860

My repo: https://github.com/TuanVu2504/laravel-opentelemetry

Steps to reproduce

git clone https://github.com/TuanVu2504/laravel-opentelemetry
cd laravel-opentelemetry
docker build -t test-otel-php .
cd compose
docker compose up -d
browse to http://localhost/test

When I set OTEL_TRACES_EXPORTER to console, the trace is generated and printed on the stdout of the laravel container. When I set OTEL_TRACES_EXPORTER to otlp, some php commands while the app starting like

php artisan event:cache
php artisan config:cache

generate the trace and send to otel collector successfully. But if I browse to the http://localhost/test. There is no trace sent to otel collector. I know that the opentelemetry generated the trace but unable to send trace to the otel collector. But there are some trace still able to send to the collector container successfully.

How do I make Laravel with octane be able to send trace otel collector.

[brettmc]

Thanks for providing @TuanVu2504 thanks for providing a reproduction. I needed up modify Dockerfile so that it didn't put the vendor dir contents into the root: COPY --chown=www-data:www-data --from=deps vendor ./vendor, and also docker build -t test-otel-php . is different to the name in docker-compose.yaml. Once I'd fixed those, I got the following error on startup:

laravel-1  | Fatal error: Uncaught ReflectionException: Class "App\Console\Kernel" does not exist in /var/www/html/vendor/laravel/framework/src/Illuminate/Container/Container.php:889
laravel-1  | Stack trace:
laravel-1  | #0 /var/www/html/vendor/laravel/framework/src/Illuminate/Container/Container.php(889): ReflectionClass->__construct('App\\Console\\Ker...')
laravel-1  | #1 /var/www/html/vendor/laravel/framework/src/Illuminate/Container/Container.php(770): Illuminate\Container\Container->build('App\\Console\\Ker...')
laravel-1  | #2 /var/www/html/vendor/laravel/framework/src/Illuminate/Foundation/Application.php(856): Illuminate\Container\Container->resolve('App\\Console\\Ker...', Array, false)
laravel-1  | #3 /var/www/html/vendor/laravel/framework/src/Illuminate/Container/Container.php(295): Illuminate\Foundation\Application->resolve('App\\Console\\Ker...', Array, false)
laravel-1  | #4 /var/www/html/vendor/laravel/framework/src/Illuminate/Container/Container.php(885): Illuminate\Container\Container->Illuminate\Container\{closure}(Object(Illuminate\Foundation\Application), Array)
laravel-1  | #5 /var/www/html/vendor/laravel/framework/src/Illuminate/Container/Container.php(770): Illuminate\Container\Container->build(Object(Closure))
laravel-1  | #6 /var/www/html/vendor/laravel/framework/src/Illuminate/Foundation/Application.php(856): Illuminate\Container\Container->resolve('Illuminate\\Cont...', Array, true)
laravel-1  | #7 /var/www/html/vendor/laravel/framework/src/Illuminate/Container/Container.php(706): Illuminate\Foundation\Application->resolve('Illuminate\\Cont...', Array)
laravel-1  | #8 /var/www/html/vendor/laravel/framework/src/Illuminate/Foundation/Application.php(841): Illuminate\Container\Container->make('Illuminate\\Cont...', Array)
laravel-1  | #9 /var/www/html/artisan(33): Illuminate\Foundation\Application->make('Illuminate\\Cont...')
laravel-1  | #10 {main}

Can you fix that please?

[TuanVu2504]

Hi @brettmc ,

I fixed the image name in the docker-compose file to match the name from the docker build command and the issue you mentioned above.

You can pull the repo and run it again.

[brettmc]

Progress - how do I fix Illuminate\Encryption\MissingAppKeyException No application encryption key has been specified. error next?

[TuanVu2504]

My bad, .gitignore has ignored file .env when I push my local repo to github, so the value of APP_KEY is null.

I updated the .gitignore. Can you please check it again.

[ChrisLightfootWild]

I was curious if this was related to long running processes again, as has been mentioned separately.

I've just had a go with Laravel Octane locally exporting to Zipkin, rather than otel-collector, which did appear to work as expected.

Will look at setting otel-collector up on this machine tomorrow to see if I encounter any blips myself also.

[TuanVu2504]

hi @ChrisLightfootWild @brettmc

Have you had a chance to review this issue.

[brettmc]

@TuanVu2504 it looks like this is using swoole as the runtime, yes? If that's true, then the problem might be that you have not installed https://packagist.org/packages/open-telemetry/context-swoole ? Without that, context won't work (and it might explain why the first artisan commands generate traces, but not the http requests, which probably run in a coroutine).

Note from the readme that you will need to configure context storage. It currently needs to be done manually, but if you can get it to work by manually configuring storage, we can investigate making it easier to use.

[TuanVu2504]

great!!! @brettmc

yes, Im using swoole and the context-swoole is not installed. I will follow your suggestion and update the result back.

[TuanVu2504]

Hi @brettmc ,

I updated my repository to include swoole-context.

I added opentelemetry instrumentation to public/index.php

Inside compose/docker-compose.yml I set OTEL_PHP_AUTOLOAD_ENABLED to false I set OTEL_TRACES_EXPORTER to otlp

I mapped route /test to TelemetryController which will retrieve tracert object and use it inside function index()

Inside compose/supervisor.conf If I set program:php command to php artisan serve --host=0.0.0.0 --port=9000, trace will be sent to otel-collector. If I set program:php command to php -d variables_order=EGPCS /var/www/html/artisan octane:start --server=swoole --host=0.0.0.0 --port=9000 ..., there will be nothing appears.

Can you please spend your time to look at this.

[brettmc]

@TuanVu2504 OTEL_PHP_AUTOLOAD_ENABLED should be set to true. Also, in your index file (say, immediately after include 'vendor/autoload.php), did you add code to configure swoole context storage? eg

Context::setStorage(new SwooleContextStorage(new ContextStorage()));

[TuanVu2504]

@brettmc

Also, in your index file (say, immediately after include 'vendor/autoload.php), did you add code to configure swoole context storage? eg

Context::setStorage(new SwooleContextStorage(new ContextStorage()));

Sure, it's already added to index file.

I also set OTEL_PHP_AUTOLOAD_ENABLED to true. It does not help.

[brettmc]

ok, can you update your reproduction git repo, and I'll take a look :)

[TuanVu2504]

yes, my git repo is already updated @brettmc

git clone https://github.com/TuanVu2504/laravel-opentelemetry
cd laravel-opentelemetry
docker build -t test-otel-php .
cd compose
docker compose up -d
browse to http://localhost/test

[brettmc]

ok, I had a play around, and I got something working! I installed xdebug so that I could see what was going on, and I discovered that when using octane+swoole, the index.php file is never used. From the call stack, it doesn't look like there is any code that is user controllable where you could configure swoole context (except for autoload->files), but it turns out that you don't need swoole context anyway. I assume that's because octane isn't using any coroutines, and just uses a worker to process one query at a time.

So, context-swoole can be removed from your dependencies.

Secondly, I think the issue might be with gRPC. If you use OTEL_EXPORTER_OTLP_ENDPOINT: "http://otel:4318" and OTEL_EXPORTER_OTLP_PROTOCOL: http/protobuf, then it starts exporting traces for each request.

Lastly, take note that the batch exporter only periodically exports (and flushes on shutdown), so you might not see a trace in the collector logs until you've made a couple of requests over a couple of seconds (depending on the batch delay setting). You could change the exporter from batch to simple, ie OTEL_PHP_TRACES_PROCESSOR: simple so that it immediately exports traces, although I wouldn't recommend it for production usage!

edit: lastly, it would have been a lot easier to work with if you used volume mounting, so that code changes are instantly available in the container, rather than having to change+rebuild all the time!

[TuanVu2504]

awesome @brettmc . Thanks for your time. I can temporally use http/protobuf on my system to collect traces.

Secondly, I think the issue might be with gRPC

As I mentioned before, there are still some traces sent to otel-collector while the application is booting. I think grpc is still work correctly somehow. I really want to use grpc in this case.

edit: lastly, it would have been a lot easier to work with if you used volume mounting, so that code changes are instantly available in the container, rather than having to change+rebuild all the time!

Sorry for that, brettmc. I will try to improve it. ;)

[brettmc]

As I mentioned before, there are still some traces sent to otel-collector while the application is booting. I think grpc is still work correctly somehow. I really want to use grpc in this case.

I agree that gRPC works in the initial artisan commands. But perhaps not gRPC in a swoole worker? I also noticed that with gRPC in your test-case it would sometimes take a really long time to process a request, which hints at something blocked or timing out. There's a current known issue with gRPC related to "thread pool hanging", so maybe that's related?

[bobstrecansky]

More context on that issue: https://github.com/grpc/grpc/issues/31772

[TuanVu2504]

Many thanks @brettmc, @bobstrecansky.

I think I should close this ticket here. I will use http/protobuf for my system traces at this time.