HI @akosiaris! Although we have questions about why this doesn't show all of the requests immediately for wikifunctions service, but we do have tracing set up for our services. When I filter for the function-orchestrator service, it seems to show more of the recent requests but anyway these more or less exist--

IIRC there was mention during our sync this earlier this week about this not being found 🤔 ? Maybe I am missing smth else you might have been referring to? TY!

Updated backend telemetry config:

• orch
• eval

However, after deploy today, both services can no longer be found in the list of 'Service' dropdown to even select from on [[ Jaeger UI | https://trace.wikimedia.org/ ]] (they formerly existed).

Change #1145242 had a related patch set uploaded (by CDanis; author: CDanis):

[operations/deployment-charts@master] wikifunctions: send traces to the collector

https://gerrit.wikimedia.org/r/1145242

Change #1145242 merged by jenkins-bot:

[operations/deployment-charts@master] wikifunctions: send traces to the collector

https://gerrit.wikimedia.org/r/1145242

Hey, missed this task, sorry. I suppose that @CDanis's finding should resolve this, but in case it doesn't, I 'll be paying closer attention to this task, please do ping me.

https://gerrit.wikimedia.org/r/c/operations/deployment-charts/+/1145242 is now deployed but I don't know if it had the intended effect.

• The "wikifunctions" service both before and after deploy shows up with hits to /_info, e.g. https://trace.wikimedia.org/trace/41f7199f5d6093ca4a6dd4522e730d9b?uiFind=f2e6b0eca71d43c8
  • Before deploy they were timed at ~30ms, afterwards they're now deployed at ~1.5ms.
  • Other kinds of traces aren't shown.
  • These only seem to cover hits to GET https://wikifunctions.svc.eqiad.wmnet/_info, i.e. the orchestrator, and not the evaluator. There's also not a split of "orchestrator" vs. "evaluator".

• The "mw-wikifunctions" service before and after is showing many MW traces (good!). None of the traces link through to tag the "wikifunctions" service, however.

In T390753#10822669, @Jdforrester-WMF wrote:

https://gerrit.wikimedia.org/r/c/operations/deployment-charts/+/1145242 is now deployed but I don't know if it had the intended effect.

I don't think it did tbh. I see only component=proxy stuff still. And I haven't found yet a good way of excluding spans matching a tag on jaeger.

• The "wikifunctions" service both before and after deploy shows up with hits to /_info, e.g. https://trace.wikimedia.org/trace/41f7199f5d6093ca4a6dd4522e730d9b?uiFind=f2e6b0eca71d43c8
  • Before deploy they were timed at ~30ms, afterwards they're now deployed at ~1.5ms.

Arguably still true, at least per https://trace.wikimedia.org/trace/968783e04dd84f906bdcf24b617cbbc0. Although I think that indeed the rate has dropped.

• Other kinds of traces aren't shown.

They are. The Jaeger UI is a bit clunky, but you can filter on the search box with the various filtering mechanisms. Here's the usual ones I mess with in a pic

• These only seem to cover hits to GET https://wikifunctions.svc.eqiad.wmnet/_info, i.e. the orchestrator, and not the evaluator. There's also not a split of "orchestrator" vs. "evaluator".

https://trace.wikimedia.org/trace/2b57c0207e908f66a681513f89565b32 seems to have 2 spans for the orchestrator, the POST http://wikifunctions.discovery.wmnet/1/v1/evaluate/ ones and one for the python evaluator, the POST https://function-evaluator-python-evaluator-tls-service.wikifunctions.svc.cluster.local:4970/1/v1/evaluate/. There is a good question why there are 2 spans for the orchestrator ofc.

• The "mw-wikifunctions" service before and after is showing many MW traces (good!). None of the traces link through to tag the "wikifunctions" service, however.

I think the above trace does.

In T390753#10822976, @akosiaris wrote:

Arguably still true, at least per https://trace.wikimedia.org/trace/968783e04dd84f906bdcf24b617cbbc0. Although I think that indeed the rate has dropped.

https://grafana.wikimedia.org/goto/29y0JdaHR?orgId=1 says that no, although those numbers seem wrong (they are off by an order of magnitude?)

In T390753#10823059, @akosiaris wrote:

In T390753#10822976, @akosiaris wrote:

Arguably still true, at least per https://trace.wikimedia.org/trace/968783e04dd84f906bdcf24b617cbbc0. Although I think that indeed the rate has dropped.

https://grafana.wikimedia.org/goto/29y0JdaHR?orgId=1 says that no, although those numbers seem wrong (they are off by an order of magnitude?)

Yup, something's off here. Repro:

$ docker-compose restart function-orchestrator 
$ curl -s http://localhost:9100 |grep expr
# HELP express_router_request_duration_seconds request duration handled by router in seconds
# TYPE express_router_request_duration_seconds histogram
$ # So 0 metrics. Now send 100 requests in sequence
$ curl -s -o /dev/null http://localhost:6254/_info?ts={1..100}
$ curl -s http://localhost:9100 |grep expr
express_router_request_duration_seconds_sum{service="function-orchestrator",path="/_info",method="GET",status="200"} 0.013436579999999993
express_router_request_duration_seconds_count{service="function-orchestrator",path="/_info",method="GET",status="200"} 100

When the time for a single request is 1-3 ms, the sum for 100 should be 0.1 to 0.3, not 0.013.

I 'll file this under a separate task though.

In T390753#10823112, @akosiaris wrote:

In T390753#10823059, @akosiaris wrote:

In T390753#10822976, @akosiaris wrote:

Arguably still true, at least per https://trace.wikimedia.org/trace/968783e04dd84f906bdcf24b617cbbc0. Although I think that indeed the rate has dropped.

https://grafana.wikimedia.org/goto/29y0JdaHR?orgId=1 says that no, although those numbers seem wrong (they are off by an order of magnitude?)

Yup, something's off here. Repro:

$ docker-compose restart function-orchestrator 
$ curl -s http://localhost:9100 |grep expr
# HELP express_router_request_duration_seconds request duration handled by router in seconds
# TYPE express_router_request_duration_seconds histogram
$ # So 0 metrics. Now send 100 requests in sequence
$ curl -s -o /dev/null http://localhost:6254/_info?ts={1..100}
$ curl -s http://localhost:9100 |grep expr
express_router_request_duration_seconds_sum{service="function-orchestrator",path="/_info",method="GET",status="200"} 0.013436579999999993
express_router_request_duration_seconds_count{service="function-orchestrator",path="/_info",method="GET",status="200"} 100

When the time for a single request is 1-3 ms, the sum for 100 should be 0.1 to 0.3, not 0.013.

I 'll file this under a separate task though.

This code comes from service-utils https://gitlab.wikimedia.org/repos/data-engineering/service-utils/-/blob/main/src/express.ts?ref_type=heads#L22 — https://gitlab.wikimedia.org/repos/data-engineering/service-utils/-/blob/main/src/metric/prometheus.ts?ref_type=heads#L123 looks right. Is startTime getting set too late?

Thanks both for looking into this and @akosiaris ~ would you mind linking that separate task?

In T390753#10801695, @ecarg wrote:

Updated backend telemetry config:

• orch
• eval

However, after deploy today, both services can no longer be found in the list of 'Service' dropdown to even select from on [[ Jaeger UI | https://trace.wikimedia.org/ ]] (they formerly existed).

It seems those commits updated package.json to load the instrumentation wiring prior to running server.js, but the blubber spec isn't loading this file. It might need to do the same.

In T390753#10846175, @mszabo wrote:

In T390753#10801695, @ecarg wrote:

Updated backend telemetry config:

• orch
• eval

However, after deploy today, both services can no longer be found in the list of 'Service' dropdown to even select from on [[ Jaeger UI | https://trace.wikimedia.org/ ]] (they formerly existed).

It seems those commits updated package.json to load the instrumentation wiring prior to running server.js, but the blubber spec isn't loading this file. It might need to do the same.

That's not needed, as we copy the whole of the base repo for the orchestrator (unlike the evaluator, where we have to manually tell blubber to copy it:

$ docker run --rm -it -w /srv/service --entrypoint /bin/bash docker-registry.wikimedia.org/repos/abstract-wiki/wikifunctions/function-orchestrator:latest

runuser@1503d2237ac0:/srv/service$ ls -l instrumentTelemetry.js
-rw-rw-rw- 1 somebody somebody 822 May  6 14:30 instrumentTelemetry.js

$ docker run --rm -it -w /srv/service --entrypoint /bin/bash docker-registry.wikimedia.org/repos/abstract-wiki/wikifunctions/function-evaluator/wasm-javascript-all:latest

runuser@1f304f891068:/srv/service$ ls -l instrumentTelemetry.js
-rw-rw-rw- 1 somebody somebody 822 May  7 00:42 instrumentTelemetry.js

$ docker run --rm -it -w /srv/service --entrypoint /bin/bash docker-registry.wikimedia.org/repos/abstract-wiki/wikifunctions/function-evaluator/wasm-python3-all:latest

runuser@a156aae36c4e:/srv/service$ ls -l instrumentTelemetry.js
-rw-rw-rw- 1 somebody somebody 822 May  7 00:42 instrumentTelemetry.js

In T390753#10848235, @Jdforrester-WMF wrote:

In T390753#10846175, @mszabo wrote:

In T390753#10801695, @ecarg wrote:

Updated backend telemetry config:

• orch
• eval

However, after deploy today, both services can no longer be found in the list of 'Service' dropdown to even select from on [[ Jaeger UI | https://trace.wikimedia.org/ ]] (they formerly existed).

It seems those commits updated package.json to load the instrumentation wiring prior to running server.js, but the blubber spec isn't loading this file. It might need to do the same.

That's not needed, as we copy the whole of the base repo for the orchestrator (unlike the evaluator, where we have to manually tell blubber to copy it:

$ docker run --rm -it -w /srv/service --entrypoint /bin/bash docker-registry.wikimedia.org/repos/abstract-wiki/wikifunctions/function-orchestrator:latest

runuser@1503d2237ac0:/srv/service$ ls -l instrumentTelemetry.js
-rw-rw-rw- 1 somebody somebody 822 May  6 14:30 instrumentTelemetry.js

$ docker run --rm -it -w /srv/service --entrypoint /bin/bash docker-registry.wikimedia.org/repos/abstract-wiki/wikifunctions/function-evaluator/wasm-javascript-all:latest

runuser@1f304f891068:/srv/service$ ls -l instrumentTelemetry.js
-rw-rw-rw- 1 somebody somebody 822 May  7 00:42 instrumentTelemetry.js

$ docker run --rm -it -w /srv/service --entrypoint /bin/bash docker-registry.wikimedia.org/repos/abstract-wiki/wikifunctions/function-evaluator/wasm-python3-all:latest

runuser@a156aae36c4e:/srv/service$ ls -l instrumentTelemetry.js
-rw-rw-rw- 1 somebody somebody 822 May  7 00:42 instrumentTelemetry.js

But server.js doesn't require this file, npm start only loads it because it's passed as an argument to --require. The blubber CMD needs to match what the NPM command is doing.

ecarg opened https://gitlab.wikimedia.org/repos/abstract-wiki/wikifunctions/function-orchestrator/-/merge_requests/373

Draft: move instrument to server.js

ecarg opened https://gitlab.wikimedia.org/repos/abstract-wiki/wikifunctions/function-evaluator/-/merge_requests/348

Draft: move instrument to server.js

Thank you @mszabo ! I've opened a couple of MR's that requires instrumentTelemetry.js inside server.js so that it gets run when server.js does. Perhaps we can do this instead of updating the blubber file? I wasn't able to add you as a reviewer so I tagged @akosiaris! However would love your thoughts!

In T390753#10862115, @ecarg wrote:

Thank you @mszabo ! I've opened a couple of MR's that requires instrumentTelemetry.js inside server.js so that it gets run when server.js does. Perhaps we can do this instead of updating the blubber file? I wasn't able to add you as a reviewer so I tagged @akosiaris! However would love your thoughts!

Thanks! I've left some comments.

Thanks @ecarg. I 'll defer to @mszabo for reviewing. He is definitely better equipped currently than I to review.

jforrester merged https://gitlab.wikimedia.org/repos/abstract-wiki/wikifunctions/function-orchestrator/-/merge_requests/373

run oTel in server.js

jforrester merged https://gitlab.wikimedia.org/repos/abstract-wiki/wikifunctions/function-evaluator/-/merge_requests/348

run oTel in server.js

we are seeing orchestrator and evaluator traces now 🎉 https://trace.wikimedia.org/trace/a6888d33d82273f9a31d26f4c158adad
...but it's disconnected from mw-wikifunctions 😞

Change #1155661 had a related patch set uploaded (by Jforrester; author: Jforrester):

[operations/deployment-charts@master] wikifunctions: Update evaluators from 2025-06-03-205630 to 2025-06-09-163022

https://gerrit.wikimedia.org/r/1155661

Change #1155662 had a related patch set uploaded (by Jforrester; author: Jforrester):

[operations/deployment-charts@master] wikifunctions: Update orchestrator from 2025-06-04-185118 to 2025-06-10-144243

https://gerrit.wikimedia.org/r/1155662

Change #1155661 merged by jenkins-bot:

[operations/deployment-charts@master] wikifunctions: Update evaluators from 2025-06-03-205630 to 2025-06-09-163022

https://gerrit.wikimedia.org/r/1155661

Change #1155662 merged by jenkins-bot:

[operations/deployment-charts@master] wikifunctions: Update orchestrator from 2025-06-04-185118 to 2025-06-10-144243

https://gerrit.wikimedia.org/r/1155662

In T390753#10901894, @ecarg wrote:

we are seeing orchestrator and evaluator traces now 🎉 https://trace.wikimedia.org/trace/a6888d33d82273f9a31d26f4c158adad
...but it's disconnected from mw-wikifunctions 😞

Both spans in a6888d3 are coming from Envoy, not from your application code. You can tell this in the attributes a few ways: component=proxy, the upstream_cluster (an Envoy-ism) tag exists, etc. So there's still something not working here.

As for being disconnected from mw-wikifunctions, what I suspect is that your Mediawiki extension code isn't passing a Tracer object as the TelemetryHeadersInterface argument of whatever HTTP client it is using. In most Mediawiki app code contexts all you need to do is call getTracer() on your MediaWikiServices object. This is already done for the default HttpRequestFactory: https://gerrit.wikimedia.org/r/c/mediawiki/core/+/1109717

In T390753#10905068, @CDanis wrote:

In T390753#10901894, @ecarg wrote:

we are seeing orchestrator and evaluator traces now 🎉 https://trace.wikimedia.org/trace/a6888d33d82273f9a31d26f4c158adad
...but it's disconnected from mw-wikifunctions 😞

Both spans in a6888d3 are coming from Envoy, not from your application code. You can tell this in the attributes a few ways: component=proxy, the upstream_cluster (an Envoy-ism) tag exists, etc. So there's still something not working here.

Yes, the deploy that should have made this work just finished at 14:19Z (https://sal.toolforge.org/log/jcJcX5cBvg159pQrDk7F) but I don't see anything in the Jæger UI for us yet.

As for being disconnected from mw-wikifunctions, what I suspect is that your Mediawiki extension code isn't passing a Tracer object as the TelemetryHeadersInterface argument of whatever HTTP client it is using. In most Mediawiki app code contexts all you need to do is call getTracer() on your MediaWikiServices object. This is already done for the default HttpRequestFactory: https://gerrit.wikimedia.org/r/c/mediawiki/core/+/1109717

That code (T396167) is rolling out in the train this week.

Change #1174768 had a related patch set uploaded (by CDanis; author: CDanis):

[operations/deployment-charts@master] mesh: networkpolicy: also allow egress to 4318 (http)

https://gerrit.wikimedia.org/r/1174768

Change #1174772 had a related patch set uploaded (by CDanis; author: CDanis):

[operations/deployment-charts@master] wikifunctions: allow egress to otelcol port 4318 (http)

https://gerrit.wikimedia.org/r/1174772

Change #1174768 merged by jenkins-bot:

[operations/deployment-charts@master] mesh: networkpolicy: also allow egress to 4318 (http)

https://gerrit.wikimedia.org/r/1174768

Change #1174772 merged by jenkins-bot:

[operations/deployment-charts@master] wikifunctions: allow egress to otelcol port 4318 (http)

https://gerrit.wikimedia.org/r/1174772