Giter Site home page Giter Site logo

Comments (14)

arkaitzgarro avatar arkaitzgarro commented on July 20, 2024

Hi @rikless,

We will need more information to be able to debug the problem. If this is your local machine, could you change getMessage() with toString() in this line?

from elastic-apm-laravel.

rikless avatar rikless commented on July 20, 2024

@arkaitzgarro it's in production, on Clever Cloud hosting.

I've tried to update with getMessage() but it doesn't changed the error message :(

from elastic-apm-laravel.

arkaitzgarro avatar arkaitzgarro commented on July 20, 2024

It looks like we are sending errors as transactions, and Elastic complains about it. Working on a fix.

from elastic-apm-laravel.

countless-integers avatar countless-integers commented on July 20, 2024

I was trying to understand what's happening, but I'm not sure. What I got so far is that: whenever a job fails, it emits an event JobFailed that our collector listens to. Then it uses the captureThrowable method to transform the exception to a payload line understandable by the intake API. Then sends it to the APM, but gets that error in response. What you don't see in the error log is the document field containing what we're sending (I've made a #58 to dump the full response). Now my best guess at this point is that the payload is invalid, but looking at the expected schema (some references are missing, but you can find them in their repo; also example request is useful) I cannot really pinpoint what's wrong.

from elastic-apm-laravel.

arkaitzgarro avatar arkaitzgarro commented on July 20, 2024

@rikless I published a new version of the package (v1.5.2) that should log the complete error description coming from Elastic. Could you give it a try, and share the error that you get back?

from elastic-apm-laravel.

rikless avatar rikless commented on July 20, 2024

Thank you all for your support !

2020-07-16T22:06:03.551Z: #4 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(246): GuzzleHttp\Promise\TaskQueue->run(true)
2020-07-16T22:06:03.552Z: #5 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(223): GuzzleHttp\Promise\Promise->invokeWaitFn()
2020-07-16T22:06:03.552Z: #9 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/guzzle/src/Client.php(182): GuzzleHttp\Promise\Promise->wait()
2020-07-16T22:06:03.552Z: #16 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Events/Dispatcher.php(226): Illuminate\Events\Dispatcher->Illuminate\Events\{closure}('Illuminate\\Queu...', Array)
2020-07-16T22:06:03.552Z: #6 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(267): GuzzleHttp\Promise\Promise->waitIfPending()
2020-07-16T22:06:03.552Z: #12 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/philkra/elastic-apm-php-agent/src/Agent.php(271): PhilKra\Middleware\Connector->commit()
2020-07-16T22:06:03.552Z: #8 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(62): GuzzleHttp\Promise\Promise->waitIfPending()
2020-07-16T22:06:03.552Z: #15 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Events/Dispatcher.php(381): AG\ElasticApmLaravel\Collectors\JobCollector->AG\ElasticApmLaravel\Collectors\{closure}(Object(Illuminate\Queue\Events\JobProcessed))
2020-07-16T22:06:03.552Z: #14 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/arkaitzgarro/elastic-apm-laravel/src/Collectors/JobCollector.php(42): AG\ElasticApmLaravel\Collectors\JobCollector->send(Object(Illuminate\Queue\Jobs\RedisJob))
2020-07-16T22:06:03.552Z: #13 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/arkaitzgarro/elastic-apm-laravel/src/Collectors/JobCollector.php(115): PhilKra\Agent->send()
2020-07-16T22:06:03.552Z: #19 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(306): Illuminate\Queue\Worker->process('redis', Object(Illuminate\Queue\Jobs\RedisJob), Object(Illuminate\Queue\WorkerOptions))
2020-07-16T22:06:03.552Z: #22 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(96): Illuminate\Queue\Console\WorkCommand->runWorker('redis', 'tube4')
2020-07-16T22:06:03.552Z: #11 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/philkra/elastic-apm-php-agent/src/Middleware/Connector.php(91): GuzzleHttp\Client->__call('post', Array)
2020-07-16T22:06:03.552Z: #24 [internal function]: Laravel\Horizon\Console\WorkCommand->handle()
2020-07-16T22:06:03.552Z: #17 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(526): Illuminate\Events\Dispatcher->dispatch('Illuminate\\Queu...')
2020-07-16T22:06:03.552Z: #21 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(112): Illuminate\Queue\Worker->daemon('redis', 'tube4', Object(Illuminate\Queue\WorkerOptions))
2020-07-16T22:06:03.552Z: #7 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(225): GuzzleHttp\Promise\Promise->invokeWaitList()
2020-07-16T22:06:03.552Z: #18 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(358): Illuminate\Queue\Worker->raiseAfterJobEvent('redis', Object(Illuminate\Queue\Jobs\RedisJob))
2020-07-16T22:06:03.552Z: #23 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/horizon/src/Console/WorkCommand.php(46): Illuminate\Queue\Console\WorkCommand->handle()
2020-07-16T22:06:03.552Z: #20 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(132): Illuminate\Queue\Worker->runJob(Object(Illuminate\Queue\Jobs\RedisJob), 'redis', Object(Illuminate\Queue\WorkerOptions))
2020-07-16T22:06:03.552Z: #10 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/guzzle/src/Client.php(95): GuzzleHttp\Client->request('post', 'apm-server-blc2...', Array)
2020-07-16T22:06:03.553Z: #32 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Console/Command.php(121): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Illuminate\Console\OutputStyle))
2020-07-16T22:06:03.553Z:    {
2020-07-16T22:06:03.553Z: #25 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(37): call_user_func_array(Array, Array)
2020-07-16T22:06:03.553Z: #39 {main} {"api_response":"{
2020-07-16T22:06:03.553Z: #28 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(39): Illuminate\Container\BoundMethod::callBoundMethod(Object(Illuminate\Foundation\Application), Array, Object(Closure))
2020-07-16T22:06:03.553Z:      \"message\": \"did not recognize object type\",
2020-07-16T22:06:03.553Z: #31 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/symfony/console/Command/Command.php(258): Illuminate\Console\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Illuminate\Console\OutputStyle))
2020-07-16T22:06:03.553Z: #38 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/artisan(37): Illuminate\Foundation\Console\Kernel->handle(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:06:03.553Z: #30 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Console/Command.php(134): Illuminate\Container\Container->call(Array)
2020-07-16T22:06:03.553Z: #29 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/Container.php(592): Illuminate\Container\BoundMethod::call(Object(Illuminate\Foundation\Application), Array, Array, NULL)
2020-07-16T22:06:03.553Z: #33 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/symfony/console/Application.php(911): Illuminate\Console\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:06:03.553Z: #37 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(129): Illuminate\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:06:03.553Z:  \"accepted\": 0,
2020-07-16T22:06:03.553Z: #26 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/Util.php(37): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
2020-07-16T22:06:03.553Z:      \"document\": \"{\\\"span\\\":{\\\"id\\\":\\\"ed0e75d311044898\\\",\\\"transaction_id\\\":\\\"34a6f46bda558605\\\",\\\"trace_id\\\":\\\"ba480d067a2be684b0fadb0e4629a879\\\",\\\"parent_id\\\":\\\"34a6f46bda558605\\\",\\\"type\\\":\\\"db.mysql.query\\\",\\\"action\\\":\\\"query\\\",\\\"context\\\":{\\\"custom\\\":[],\\\"labels\\\":[],\\\"db\\\":{\\\"statement\\\":\\\"select * from \\\\\\\"optins\\\\\\\" where \\\\\\\"optins\\\\\\\".\\\\\\\"id\\\\\\\" = ? limit 1\\\",\\\"type\\\":\\\"sql\\\"}},\\\"start\\\":355288.501,\\\"duration\\\":26.95,\\\"name\\\":\\\"SELECT optins\\\",\\\"stacktrace\\\":[],\\\"sync\\\":false,\\\"timestamp\\\":1594937518069464}}\"
2020-07-16T22:06:03.553Z: #27 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(95): Illuminate\Container\Util::unwrapIfClosure(Object(Closure))
2020-07-16T22:06:03.553Z:  \"errors\": [
2020-07-16T22:06:03.553Z: #36 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Console/Application.php(93): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:06:03.553Z: #35 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/symfony/console/Application.php(140): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:06:03.553Z: #34 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/symfony/console/Application.php(264): Symfony\Component\Console\Application->doRunCommand(Object(Laravel\Horizon\Console\WorkCommand), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:06:03.554Z: }
2020-07-16T22:06:03.554Z: "}
2020-07-16T22:06:03.554Z:    }
2020-07-16T22:06:03.554Z:  ]
2020-07-16T22:08:56.621Z: #5 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(223): GuzzleHttp\Promise\Promise->invokeWaitFn()
2020-07-16T22:08:56.621Z:      "message": "did not recognize object type",
2020-07-16T22:08:56.621Z:    {
2020-07-16T22:08:56.621Z: #7 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(225): GuzzleHttp\Promise\Promise->invokeWaitList()
2020-07-16T22:08:56.621Z: #6 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(267): GuzzleHttp\Promise\Promise->waitIfPending()
2020-07-16T22:08:56.621Z: [2020-07-16 22:08:56] production.ERROR: GuzzleHttp\Exception\ClientException: Client error: `POST *******
2020-07-16T22:08:56.621Z:      "document": "{\"span\":{\ (truncated...)
2020-07-16T22:08:56.621Z: #3 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/TaskQueue.php(47): GuzzleHttp\Promise\Promise::GuzzleHttp\Promise\{closure}()
2020-07-16T22:08:56.621Z: #2 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(156): GuzzleHttp\Promise\Promise::callHandler(1, Object(GuzzleHttp\Psr7\Response), Array)
2020-07-16T22:08:56.621Z: Stack trace:
2020-07-16T22:08:56.621Z: #0 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/guzzle/src/Middleware.php(65): GuzzleHttp\Exception\RequestException::create(Object(GuzzleHttp\Psr7\Request), Object(GuzzleHttp\Psr7\Response))
2020-07-16T22:08:56.621Z: in /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/guzzle/src/Exception/RequestException.php:113
2020-07-16T22:08:56.621Z:  "accepted": 0,
2020-07-16T22:08:56.621Z: {
2020-07-16T22:08:56.621Z: #8 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(62): GuzzleHttp\Promise\Promise->waitIfPending()
2020-07-16T22:08:56.621Z:  "errors": [
2020-07-16T22:08:56.621Z: #1 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(203): GuzzleHttp\Middleware::GuzzleHttp\{closure}(Object(GuzzleHttp\Psr7\Response))
2020-07-16T22:08:56.621Z: #4 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(246): GuzzleHttp\Promise\TaskQueue->run(true)
2020-07-16T22:08:56.622Z: #25 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(37): call_user_func_array(Array, Array)
2020-07-16T22:08:56.622Z: #15 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Events/Dispatcher.php(381): AG\ElasticApmLaravel\Collectors\JobCollector->AG\ElasticApmLaravel\Collectors\{closure}(Object(Illuminate\Queue\Events\JobProcessed))
2020-07-16T22:08:56.622Z: #23 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/horizon/src/Console/WorkCommand.php(46): Illuminate\Queue\Console\WorkCommand->handle()
2020-07-16T22:08:56.622Z: #14 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/arkaitzgarro/elastic-apm-laravel/src/Collectors/JobCollector.php(42): AG\ElasticApmLaravel\Collectors\JobCollector->send(Object(Illuminate\Queue\Jobs\RedisJob))
2020-07-16T22:08:56.622Z: #13 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/arkaitzgarro/elastic-apm-laravel/src/Collectors/JobCollector.php(115): PhilKra\Agent->send()
2020-07-16T22:08:56.622Z: #11 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/philkra/elastic-apm-php-agent/src/Middleware/Connector.php(91): GuzzleHttp\Client->__call('post', Array)
2020-07-16T22:08:56.622Z: #27 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(95): Illuminate\Container\Util::unwrapIfClosure(Object(Closure))
2020-07-16T22:08:56.622Z: #21 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(112): Illuminate\Queue\Worker->daemon('redis', 'tube5', Object(Illuminate\Queue\WorkerOptions))
2020-07-16T22:08:56.622Z: #20 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(132): Illuminate\Queue\Worker->runJob(Object(Illuminate\Queue\Jobs\RedisJob), 'redis', Object(Illuminate\Queue\WorkerOptions))
2020-07-16T22:08:56.622Z: #26 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/Util.php(37): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
2020-07-16T22:08:56.622Z: #17 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(526): Illuminate\Events\Dispatcher->dispatch('Illuminate\\Queu...')
2020-07-16T22:08:56.622Z: #10 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/guzzle/src/Client.php(95): GuzzleHttp\Client->request('post', 'apm-server-blc2...', Array)
2020-07-16T22:08:56.622Z: #9 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/guzzle/src/Client.php(182): GuzzleHttp\Promise\Promise->wait()
2020-07-16T22:08:56.622Z: #16 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Events/Dispatcher.php(226): Illuminate\Events\Dispatcher->Illuminate\Events\{closure}('Illuminate\\Queu...', Array)
2020-07-16T22:08:56.622Z: #28 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(39): Illuminate\Container\BoundMethod::callBoundMethod(Object(Illuminate\Foundation\Application), Array, Object(Closure))
2020-07-16T22:08:56.622Z: #22 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(96): Illuminate\Queue\Console\WorkCommand->runWorker('redis', 'tube5')
2020-07-16T22:08:56.622Z: #19 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(306): Illuminate\Queue\Worker->process('redis', Object(Illuminate\Queue\Jobs\RedisJob), Object(Illuminate\Queue\WorkerOptions))
2020-07-16T22:08:56.622Z: #24 [internal function]: Laravel\Horizon\Console\WorkCommand->handle()
2020-07-16T22:08:56.622Z: #12 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/philkra/elastic-apm-php-agent/src/Agent.php(271): PhilKra\Middleware\Connector->commit()
2020-07-16T22:08:56.622Z: #18 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(358): Illuminate\Queue\Worker->raiseAfterJobEvent('redis', Object(Illuminate\Queue\Jobs\RedisJob))
2020-07-16T22:08:56.623Z:  \"errors\": [
2020-07-16T22:08:56.623Z:    }
2020-07-16T22:08:56.623Z: #31 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/symfony/console/Command/Command.php(258): Illuminate\Console\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Illuminate\Console\OutputStyle))
2020-07-16T22:08:56.623Z: #37 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(129): Illuminate\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:08:56.623Z: #34 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/symfony/console/Application.php(264): Symfony\Component\Console\Application->doRunCommand(Object(Laravel\Horizon\Console\WorkCommand), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:08:56.623Z: }
2020-07-16T22:08:56.623Z: #30 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Console/Command.php(134): Illuminate\Container\Container->call(Array)
2020-07-16T22:08:56.623Z:    {
2020-07-16T22:08:56.623Z: #32 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Console/Command.php(121): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Illuminate\Console\OutputStyle))
2020-07-16T22:08:56.623Z:  \"accepted\": 0,
2020-07-16T22:08:56.623Z:      \"message\": \"did not recognize object type\",
2020-07-16T22:08:56.623Z: #29 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/Container.php(592): Illuminate\Container\BoundMethod::call(Object(Illuminate\Foundation\Application), Array, Array, NULL)
2020-07-16T22:08:56.623Z: #33 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/symfony/console/Application.php(911): Illuminate\Console\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:08:56.623Z: #35 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/symfony/console/Application.php(140): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:08:56.623Z:      \"document\": \"{\\\"span\\\":{\\\"id\\\":\\\"da0079c75aaa9233\\\",\\\"transaction_id\\\":\\\"43384cc101432da9\\\",\\\"trace_id\\\":\\\"3bc036230942dfc9d4dd2e568204c3bb\\\",\\\"parent_id\\\":\\\"43384cc101432da9\\\",\\\"type\\\":\\\"db.mysql.query\\\",\\\"action\\\":\\\"query\\\",\\\"context\\\":{\\\"custom\\\":[],\\\"labels\\\":[],\\\"db\\\":{\\\"statement\\\":\\\"select * from \\\\\\\"tenants\\\\\\\" where \\\\\\\"tenants\\\\\\\".\\\\\\\"id\\\\\\\" = ? limit 1\\\",\\\"type\\\":\\\"sql\\\"}},\\\"start\\\":376127.517,\\\"duration\\\":17.7,\\\"name\\\":\\\"SELECT tenants\\\",\\\"stacktrace\\\":[],\\\"sync\\\":false,\\\"timestamp\\\":1594937712627416}}\"
2020-07-16T22:08:56.623Z: #39 {main} {"api_response":"{
2020-07-16T22:08:56.623Z: #38 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/artisan(37): Illuminate\Foundation\Console\Kernel->handle(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:08:56.623Z:  ]
2020-07-16T22:08:56.623Z: #36 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Console/Application.php(93): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:08:56.624Z: "}
2020-07-16T22:09:03.201Z: (bas) CMDOUT (0)
2020-07-16T22:09:04.800Z: DIGEST-MD5 common mech free finished)
2020-07-16T22:10:02.701Z: (bas) CMDOUT (0)
2020-07-16T22:10:04.852Z: DIGEST-MD5 common mech free finished)
2020-07-16T22:10:53.920Z: #11 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/philkra/elastic-apm-php-agent/src/Middleware/Connector.php(91): GuzzleHttp\Client->__call('post', Array)
2020-07-16T22:10:53.920Z: #12 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/philkra/elastic-apm-php-agent/src/Agent.php(271): PhilKra\Middleware\Connector->commit()
2020-07-16T22:10:53.923Z:  \"accepted\": 0,
2020-07-16T22:10:53.923Z:  \"errors\": [
2020-07-16T22:10:53.919Z: in /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/guzzle/src/Exception/RequestException.php:113
2020-07-16T22:10:53.919Z: Stack trace:
2020-07-16T22:10:53.919Z: #0 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/guzzle/src/Middleware.php(65): GuzzleHttp\Exception\RequestException::create(Object(GuzzleHttp\Psr7\Request), Object(GuzzleHttp\Psr7\Response))
2020-07-16T22:10:53.921Z: #20 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(132): Illuminate\Queue\Worker->runJob(Object(Illuminate\Queue\Jobs\RedisJob), 'redis', Object(Illuminate\Queue\WorkerOptions))
2020-07-16T22:10:53.921Z: #21 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(112): Illuminate\Queue\Worker->daemon('redis', 'tube5', Object(Illuminate\Queue\WorkerOptions))
2020-07-16T22:10:53.919Z: {
2020-07-16T22:10:53.919Z:  "accepted": 0,
2020-07-16T22:10:53.919Z:  "errors": [
2020-07-16T22:10:53.919Z:    {
2020-07-16T22:10:53.919Z:      "message": "did not recognize object type",
2020-07-16T22:10:53.919Z:      "document": "{\"span\":{\ (truncated...)
2020-07-16T22:10:53.921Z: #16 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Events/Dispatcher.php(226): Illuminate\Events\Dispatcher->Illuminate\Events\{closure}('Illuminate\\Queu...', Array)
2020-07-16T22:10:53.921Z: #17 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(526): Illuminate\Events\Dispatcher->dispatch('Illuminate\\Queu...')
2020-07-16T22:10:53.921Z: #23 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/horizon/src/Console/WorkCommand.php(46): Illuminate\Queue\Console\WorkCommand->handle()
2020-07-16T22:10:53.921Z: #24 [internal function]: Laravel\Horizon\Console\WorkCommand->handle()
2020-07-16T22:10:53.921Z: #25 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(37): call_user_func_array(Array, Array)
2020-07-16T22:10:53.921Z: #26 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/Util.php(37): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
2020-07-16T22:10:53.923Z: "}
2020-07-16T22:10:53.920Z: #13 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/arkaitzgarro/elastic-apm-laravel/src/Collectors/JobCollector.php(115): PhilKra\Agent->send()
2020-07-16T22:10:53.920Z: #14 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/arkaitzgarro/elastic-apm-laravel/src/Collectors/JobCollector.php(42): AG\ElasticApmLaravel\Collectors\JobCollector->send(Object(Illuminate\Queue\Jobs\RedisJob))
2020-07-16T22:10:53.920Z: #15 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Events/Dispatcher.php(381): AG\ElasticApmLaravel\Collectors\JobCollector->AG\ElasticApmLaravel\Collectors\{closure}(Object(Illuminate\Queue\Events\JobProcessed))
2020-07-16T22:10:53.922Z: #33 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/symfony/console/Application.php(911): Illuminate\Console\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:10:53.922Z: #34 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/symfony/console/Application.php(264): Symfony\Component\Console\Application->doRunCommand(Object(Laravel\Horizon\Console\WorkCommand), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:10:53.922Z: #35 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/symfony/console/Application.php(140): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:10:53.923Z:    {
2020-07-16T22:10:53.923Z:      \"message\": \"did not recognize object type\",
2020-07-16T22:10:53.923Z:      \"document\": \"{\\\"span\\\":{\\\"id\\\":\\\"22d778e0fff986d0\\\",\\\"transaction_id\\\":\\\"a810e7e88614decc\\\",\\\"trace_id\\\":\\\"f26ef789c5eaecbfe8fd87872086c832\\\",\\\"parent_id\\\":\\\"a810e7e88614decc\\\",\\\"type\\\":\\\"db.mysql.query\\\",\\\"action\\\":\\\"query\\\",\\\"context\\\":{\\\"custom\\\":[],\\\"labels\\\":[],\\\"db\\\":{\\\"statement\\\":\\\"select * from \\\\\\\"tenants\\\\\\\" where \\\\\\\"tenants\\\\\\\".\\\\\\\"id\\\\\\\" = ? limit 1\\\",\\\"type\\\":\\\"sql\\\"}},\\\"start\\\":445413.068,\\\"duration\\\":18.49,\\\"name\\\":\\\"SELECT tenants\\\",\\\"stacktrace\\\":[],\\\"sync\\\":false,\\\"timestamp\\\":1594937899084170}}\"
2020-07-16T22:10:53.918Z: [2020-07-16 22:10:53] production.ERROR: GuzzleHttp\Exception\ClientException: Client error: `POST *******
2020-07-16T22:10:53.919Z: #4 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(246): GuzzleHttp\Promise\TaskQueue->run(true)
2020-07-16T22:10:53.920Z: #5 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(223): GuzzleHttp\Promise\Promise->invokeWaitFn()
2020-07-16T22:10:53.920Z: #6 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(267): GuzzleHttp\Promise\Promise->waitIfPending()
2020-07-16T22:10:53.921Z: #27 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(95): Illuminate\Container\Util::unwrapIfClosure(Object(Closure))
2020-07-16T22:10:53.922Z: #28 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(39): Illuminate\Container\BoundMethod::callBoundMethod(Object(Illuminate\Foundation\Application), Array, Object(Closure))
2020-07-16T22:10:53.922Z: #29 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Container/Container.php(592): Illuminate\Container\BoundMethod::call(Object(Illuminate\Foundation\Application), Array, Array, NULL)
2020-07-16T22:10:53.922Z: #36 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Console/Application.php(93): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:10:53.922Z: #37 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(129): Illuminate\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:10:53.922Z: #38 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/artisan(37): Illuminate\Foundation\Console\Kernel->handle(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
2020-07-16T22:10:53.922Z: #39 {main} {"api_response":"{
2020-07-16T22:10:53.920Z: #7 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(225): GuzzleHttp\Promise\Promise->invokeWaitList()
2020-07-16T22:10:53.920Z: #8 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(62): GuzzleHttp\Promise\Promise->waitIfPending()
2020-07-16T22:10:53.920Z: #9 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/guzzle/src/Client.php(182): GuzzleHttp\Promise\Promise->wait()
2020-07-16T22:10:53.920Z: #10 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/guzzle/src/Client.php(95): GuzzleHttp\Client->request('post', 'apm-server-blc2...', Array)
2020-07-16T22:10:53.921Z: #22 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(96): Illuminate\Queue\Console\WorkCommand->runWorker('redis', 'tube5')
2020-07-16T22:10:53.919Z: #1 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(203): GuzzleHttp\Middleware::GuzzleHttp\{closure}(Object(GuzzleHttp\Psr7\Response))
2020-07-16T22:10:53.919Z: #2 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/Promise.php(156): GuzzleHttp\Promise\Promise::callHandler(1, Object(GuzzleHttp\Psr7\Response), Array)
2020-07-16T22:10:53.919Z: #3 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/guzzlehttp/promises/src/TaskQueue.php(47): GuzzleHttp\Promise\Promise::GuzzleHttp\Promise\{closure}()
2020-07-16T22:10:53.923Z:    }
2020-07-16T22:10:53.923Z:  ]
2020-07-16T22:10:53.923Z: }
2020-07-16T22:10:53.921Z: #18 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(358): Illuminate\Queue\Worker->raiseAfterJobEvent('redis', Object(Illuminate\Queue\Jobs\RedisJob))
2020-07-16T22:10:53.921Z: #19 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(306): Illuminate\Queue\Worker->process('redis', Object(Illuminate\Queue\Jobs\RedisJob), Object(Illuminate\Queue\WorkerOptions))
2020-07-16T22:10:53.922Z: #30 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Console/Command.php(134): Illuminate\Container\Container->call(Array)
2020-07-16T22:10:53.922Z: #31 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/symfony/console/Command/Command.php(258): Illuminate\Console\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Illuminate\Console\OutputStyle))
2020-07-16T22:10:53.922Z: #32 /home/bas/app_a5d1fed8-fb86-4fd9-9474-0aee5c2d530a/vendor/laravel/framework/src/Illuminate/Console/Command.php(121): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Illuminate\Console\OutputStyle))


from elastic-apm-laravel.

arkaitzgarro avatar arkaitzgarro commented on July 20, 2024

Hmm ok, so it's a span for DB queries what it's failing for your, not jobs as we thought. I would suggest that until we find out what's the issue, you disable the DB spans. Can you add APM_QUERYLOG=false to your .env file, and confirm that it doesn't show errors?

from elastic-apm-laravel.

rikless avatar rikless commented on July 20, 2024

Thank you @arkaitzgarro .

I'm doing it right now. But just to let you know that all my queries are ok on those jobs.

from elastic-apm-laravel.

rikless avatar rikless commented on July 20, 2024

It's confirmed. Without query logs, no error in logs.

from elastic-apm-laravel.

cykirsch avatar cykirsch commented on July 20, 2024

I think I figured out the cause of this. When I post to apm server manually, I get this error for any transaction or span when metadata is not included as well. I adjusted the logging you did in #58 to also include the request, and when I get the failure it doesn't have the metadata line. I'll look into it a bit more now (no promises beyond that 😅)but if that rings a bell at all let me know.

from elastic-apm-laravel.

cykirsch avatar cykirsch commented on July 20, 2024

@arkaitzgarro I didn't get a chance to really confirm, but at times what I seem to be experiencing is that the first job in a worker will post correctly, but then it doesn't reset the metadata and fails all subsequent jobs. I actually can't really see a good way to set that metadata because of the private nature of the Agent internals.

from elastic-apm-laravel.

arkaitzgarro avatar arkaitzgarro commented on July 20, 2024

Thanks for the investigations @cykirsch, it may be the case looking at the code. The agent puts a metadata event when it's initialised the first time, which only happens once for async workers, and then it does it again under a conditional inside the send method. Since the transaction store is reset after events has been sent, consequent transactions will miss the metadata.

Funny enough, @dstepe was already questioning the reasoning of this behaviour. I think metadata can/should always be set in the send method to make sure is always present, but this is a decision the agent should make, it's not something we will solve in this package.

from elastic-apm-laravel.

dstepe avatar dstepe commented on July 20, 2024

I'll start looking into this on the Agent side. The expectation is that "the first "event" in each ND-JSON stream contains metadata to fold into subsequent events" (https://github.com/elastic/apm/blob/master/specs/agents/metadata.md). Since each Agent::send() call will create a new connection, the metadata should be included each time. It appears that the current send() code is aware of this and attempts to add it if needed, so I'll need to do some testing to determine what's going on.

from elastic-apm-laravel.

dstepe avatar dstepe commented on July 20, 2024

@arkaitzgarro and @cykirsch, I believe I understand the problem, and may have a quick fix for you. The underlying issue is how events are captured. We currently employ two approaches. First, the Agent class records started Transactions and will push them on to the Connector. Second, the Agent::putEvent() method is called to create child Span objects, and pushes them directly on to the Connector.

The problem you have observed manifests when Span objects are added using Agent::putEvent() which occurs before the check for the empty payload and also before Transactions from the Agent are added. The end result is that the payload is never empty in that scenario so the Metadata is never added after the initial creation.

This is another manifestation of what I believe are underlying design problems with the way event collection is being done. I'm already planning to rework event collection in the next major release of the agent package, but that won't help you right now.

I believe there is another potential issue with the EventDataCollector objects. I don't see that they are being reset after sending and my observation is that they accumulate events between jobs and therefore the same event is sent multiple times.

I should have a PR soon that may offer an easy solution for both of these issues as a short term fix.

from elastic-apm-laravel.

Related Issues (20)

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.