Open julianocosta89 opened 1 year ago
@DebajitDas , @kpratyus any thoughts? are headers correlated through fastcgi?
@julianocosta89 would you mind replacing wordpress with a more simple PHP app like the one I use here?
https://github.com/svrnm/otel-webserver-demo/blob/main/apache/index.php
If you additionally dump the headers/context out, we can validate if the issue is with PHP or nginx
hello @svrnm, thanks for taking a look!
I have ran a couple of tests and it looks better, but I'm still missing something. I've pushed a simpler sample in this branch: https://github.com/julianocosta89/Wordpress-FPM_Nginx_OTel/tree/php-fpm
Now I see nginx and php-fpm linked together, but there is no root span. They are all placed on the same level in Jaeger:
This looks weird because I'm manually creating the span in PHP, and I'm explicitly creating the span as a child of the received context. But for some reason the root span is gone.
In Jaeger I can also see the following error message:
invalid parent span IDs=17a43959e992f657; skipping clock skew adjustment
Did I miss anything on the NGINX configuration to actually have the root span?
Also, for each request, I get the following logs:
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: ngx_initialize_opentelemetry: Initializing Agent Core succceeded for process with PID: 34, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: startMonitoringRequest: Starting Request Monitoring for: / HTTP/1.1
nginx | Host, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: startMonitoringRequest: WebServer Context: wpTestNginxServiceNginxServiceId, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: startMonitoringRequest: Request Monitoring begins successfully , client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Starting a new module interaction for: ngx_http_realip_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : tracestate, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : , client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : traceparent, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : 00-085ae7831268bfb1f1d0f2ec902ab501-ea168d2846adbb44-01, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Interaction begin successful, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_stopInteraction: Stopping the Interaction for: ngx_http_realip_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Starting a new module interaction for: ngx_http_rewrite_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : tracestate, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : , client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : traceparent, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : 00-085ae7831268bfb1f1d0f2ec902ab501-3fb2229cced77f8b-01, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Interaction begin successful, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_stopInteraction: Stopping the Interaction for: ngx_http_rewrite_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Starting a new module interaction for: ngx_http_rewrite_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : tracestate, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : , client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : traceparent, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : 00-085ae7831268bfb1f1d0f2ec902ab501-6a0a68a4b64dafa6-01, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Interaction begin successful, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_stopInteraction: Stopping the Interaction for: ngx_http_rewrite_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: ngx_initialize_opentelemetry: Opentelemetry SDK already initialized for process with PID: 34, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Starting a new module interaction for: ngx_http_realip_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : tracestate, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : , client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : traceparent, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : 00-085ae7831268bfb1f1d0f2ec902ab501-43e1cc088f4d85f8-01, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Interaction begin successful, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_stopInteraction: Stopping the Interaction for: ngx_http_realip_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Starting a new module interaction for: ngx_http_limit_req_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : tracestate, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : , client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : traceparent, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : 00-085ae7831268bfb1f1d0f2ec902ab501-b069ccb48cd483a7-01, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Interaction begin successful, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_stopInteraction: Stopping the Interaction for: ngx_http_limit_req_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Starting a new module interaction for: ngx_http_limit_conn_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : tracestate, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : , client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : traceparent, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : 00-085ae7831268bfb1f1d0f2ec902ab501-d7c5f38f32b6817a-01, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Interaction begin successful, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_stopInteraction: Stopping the Interaction for: ngx_http_limit_conn_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Starting a new module interaction for: ngx_http_access_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : tracestate, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : , client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : traceparent, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : 00-085ae7831268bfb1f1d0f2ec902ab501-65fdb5580f59ab98-01, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Interaction begin successful, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_stopInteraction: Stopping the Interaction for: ngx_http_access_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Starting a new module interaction for: ngx_http_auth_basic_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : tracestate, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : , client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : traceparent, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : 00-085ae7831268bfb1f1d0f2ec902ab501-c24cc234e8467133-01, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Interaction begin successful, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_stopInteraction: Stopping the Interaction for: ngx_http_auth_basic_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Starting a new module interaction for: ngx_http_auth_request_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : tracestate, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : , client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : traceparent, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : 00-085ae7831268bfb1f1d0f2ec902ab501-3f90e85dc70afa23-01, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Interaction begin successful, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_stopInteraction: Stopping the Interaction for: ngx_http_auth_request_module, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Starting a new module interaction for: ngx_http_otel_try_files_handler, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : tracestate, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : , client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Key : traceparent, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_payload_decorator: Value : 00-085ae7831268bfb1f1d0f2ec902ab501-f162d36b4f132b84-01, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: Interaction begin successful, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: It is not a main Request, not starting interaction, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: It is not a main Request, not starting interaction, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: It is not a main Request, not starting interaction, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: It is not a main Request, not starting interaction, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: It is not a main Request, not starting interaction, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: It is not a main Request, not starting interaction, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: It is not a main Request, not starting interaction, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: It is not a main Request, not starting interaction, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: It is not a main Request, not starting interaction, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
nginx | 2023/04/24 09:21:01 [error] 34#34: *7 mod_opentelemetry: otel_startInteraction: It is not a main Request, not starting interaction, client: 10.201.3.1, server: $host, request: "GET / HTTP/1.1", host: "localhost:8080"
phpfpm | 10.201.3.4 - 24/Apr/2023:09:21:01 +0000 "GET /index.php" 200
nginx | 10.201.3.1 - - [24/Apr/2023:09:21:01 +0000] "GET / HTTP/1.1" 200 311 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/112.0.0.0 Safari/537.36" "-"
Hi @julianocosta89 I ran your example, but swapped out jaeger for the otel collector with some logging enabled. It looks like something's not right in nginx:
The collector output from my test run: nginx-php-collector-traces.txt
Hello @brettmc, thank very much for taking a look! Yes, that's exactly the same behavior I noted.
Maybe it is indeed an issue with the NGINX instrumentation. @DebajitDas , @kpratyus any ideas?
Similar problem here with Apache and php-fpm
Describe your environment
Hello all, I was following this blog post: https://opentelemetry.io/blog/2022/instrument-nginx/ But trying the latest version of OTel Nginx instrumentation.
I'm using Nginx to serve fastcgi requests to a wordpress FPM backend. I'm not sure if my Nginx configuration is wrong, or if the instrumentation is not working. Would someone be able to give me a hand?
I was expecting Nginx spans to be linked with Wordpress spans, but at the moment they are all orphaned.
I've put together a sample, to make it easier to reproduce.
Steps to reproduce Just clone this repo: https://github.com/julianocosta89/Wordpress-FPM_Nginx_OTel
and run:
What is the expected behavior? I expected to see the context being propagated from Nginx to Wordpress.
What is the actual behavior? I got traces from Nginx and from Wordpress, but not linked together.