elastic / elastic/apm-agent-php

A single trigger_error() call gets reported multiple times with auto instrumentation

Open
#1,205 4 comments 1 reaction 1 assignee Claimed by @intuibase View on GitHub
agent-php bug
Dominant language
PHP
Stars
268
Forks
86
PR merge metrics
No merged PRs in 30d

Description

**Describe the bug**
A single trigger_error() call gets reported multiple times to the APM server if autoinstrumentation is enabled.
**To Reproduce**
Steps to reproduce the behavior:
Following code snippet will report 13 number of user deprecated errors to the server.

- PHP:
- Version: 8.3.10, 8.2.11 (could reproduce with both)
- OS: Alpine Linux v3.20.2, Ubuntu 22.04.3 LTS (could reproduce with both)
- Code
```
prepare("insert into trigger_test (data) values (?)");
$statement->execute([$random]);
}

echo "trigger_test";
```
- Dockerfile:
```
FROM php:8.3-fpm-alpine

ADD --chmod=0755 https://github.com/mlocati/docker-php-extension-installer/releases/latest/download/install-php-extensions /usr/local/bin/

RUN install-php-extensions pdo_mysql

ADD --chmod=0755 https://github.com/elastic/apm-agent-php/releases/download/v1.13.0/apm-agent-php_1.13.0_x86_64.apk /root
RUN apk add --allow-untrusted /root/apm-agent-php_1.13.0_x86_64.apk

COPY . /var/www/html
```
- APM
- Agent version: 1.13.0
- Agent config:
```
[elastic]
elastic_apm.enabled = true
elastic_apm.secret_token = "{{REPLACE_ME}}"
elastic_apm.server_url = "{{REPLACE_ME}}"
elastic_apm.environment = "local"
elastic_apm.log_level = "DEBUG"
elastic_apm.log_level_stderr = "DEBUG"
elastic_apm.server_timeout = "30s"
elastic_apm.service_name = "trigger_test"
elastic_apm.service_version = "v1"
elastic_apm.transaction_max_spans = 500
elastic_apm.transaction_sample_rate = 1.0
elastic_apm.verify_server_cert = true
elastic_apm.dev_internal_backend_comm_log_verbose = true
elastic_apm.profiling_inferred_spans_enabled = true
```
- Results in kibana:
![image](https://github.com/user-attachments/assets/7ecbb6c0-da54-4b16-8936-520b5b222e4f)
- Notes:
- Based on a quick investigation what I can see is that \elastic_apm_get_last_php_error() will return the last triggered error every time in PhpPartFacade::ensureHaveLastPhpError() called through both internalFuncCallPreHook() and internalFuncCallPostHook(). This creates 2 error event on every autoinstrument captured call. This results in a total of 13 errors (1 original on the trigger, 2 on $pdo->prepare() and 2 on $statement->execute() executed 3 times in the for cycle for a total of 12 [3 * 2 * 2])
![image](https://github.com/user-attachments/assets/f610bc28-8a83-47cb-bdd0-591edc336220)
![image](https://github.com/user-attachments/assets/f5301a42-ba89-4913-9be7-2c83a06f2635)

**Expected behavior**
Auto instrumented calls should not report earlier triggered errors. So in above scenario I would like to only see 1 error event.

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.