Page MenuHomePhabricator

Reduce logstash logs from machine learning infra
Closed, ResolvedPublic

Assigned To
Authored By
Ladsgroup
Feb 3 2026, 6:29 PM
Referenced Files
F79812231: Screenshot 2026-05-05 at 15.57.26.png
May 5 2026, 2:00 PM
F72829296: Screenshot From 2026-03-13 08-56-42.png
Mar 13 2026, 7:57 AM
F72504419: Screenshot From 2026-03-04 15-15-32.png
Mar 4 2026, 2:30 PM
F72503325: Screenshot From 2026-03-04 14-39-28.png
Mar 4 2026, 1:39 PM
F72206235: pod-name-3.png
Feb 20 2026, 11:16 AM
F72206231: pod-name-2.png
Feb 20 2026, 11:16 AM
F72206229: pod-name-1.png
Feb 20 2026, 11:16 AM

Description

See T390215: Logstash is still overwhelmed (since March 2025), we are having a lot of trouble with the sheer number of logs being ingested by our logstash infra. I did a quick check and around half of all of the logs are from ML infra: https://logstash.wikimedia.org/goto/1a2483a4a3958f77ea6df119d7b16a22 this is currently emitting around 1,000,000 logs per minute.

E.g. maybe for access requests, implement a sampling for anything that's 200?

Also a much simpler mitigation: I'm seeing that majority of the logs have empty message and empty log: https://logstash.wikimedia.org/app/discover#/doc/logstash-*/logstash-ml-1-7.0.0-1-2026.02.03?id=Cii-JJwBVE0pYbVvI1fq

Thank you!

Event Timeline

Also if you check UA, most logs are simply from "MediaWiki/1.46.0-wmf.13" or "ChangePropagation/WMF". Can we sample these?

I can see that most logs have "kubernetes.pod_name" values like:
"controller-..."
"webhook-..."
"kserve-controller-manager-..."
"istio-ingressgateway-..."
These are system logs generated by kserve, which seem to be the majority.
@DPogorzelski-WMF Is there a way to reduce the system logs from kserve?
@elukey sorry to ping you, but maybe you have some insights here

pod-name-1.png (1,588×1,444 px, 307 KB)

pod-name-2.png (1,612×1,434 px, 337 KB)

pod-name-3.png (1,664×1,450 px, 334 KB)

I think that the best course of action is to split logs by namespace:

I think we should focus to find config options for knative and kserve at the moment, it should reduce the firehose by a lot. Most of those logs are something that we don't need, they are emitted by those pods by default IIRC.

Change #1247995 had a related patch set uploaded (by Elukey; author: Elukey):

[operations/deployment-charts@master] admin_ng: reduce logs emitted by knative components on ml-serve

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

Tested staging and the knative traffic volume dropped:

Screenshot From 2026-03-04 14-39-28.png (2,994×572 px, 94 KB)

Change #1247995 merged by Elukey:

[operations/deployment-charts@master] admin_ng: reduce logs emitted by knative components on ml-serve

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

Knative should be good now:

Screenshot From 2026-03-04 15-15-32.png (5,044×762 px, 279 KB)

For the kserve controller we sadly cannot do much from what I can see, since we'd need https://github.com/kserve/kserve/commit/5e7207ca0870e37e72e119845f7f8933ad57ca6a that is available from 0.12 onward (and we have 0.11.2). We could backport it to our image, so after that we'll have all the zap-logging options to use.

@DPogorzelski-WMF @klausman we already have kserve 0.13 in production-images, so in theory we could simply upgrade the control plane + helm chart to include the above commit and reduce the spam to logstash considerably. Lemme know how you want to proceed :)

Change #1250573 had a related patch set uploaded (by Elukey; author: Elukey):

[operations/puppet@production] profile::logstash: drop kserve-controller's logs

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

Change #1250573 merged by Cwhite:

[operations/puppet@production] profile::logstash: drop kserve-controller's logs

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

Kserve's logs look really better now:

Screenshot From 2026-03-13 08-56-42.png (5,030×830 px, 307 KB)

I think we are out of the woods, we have around ~20k/minute logs now mostly coming from the inference-service pods (kserve-container). I think that we could definitely improve things there:

  1. The logs are not emitted using json or ECS so in case of errors, like Python stacktraces, we get one log for each line. It is a waste on the logstash side, but also not really great for human readers that need to investigate an outage the day afterwards. If the logs are not on the pods because of rotation, getting a complete stacktrace from logstash is really really tedious.
  1. We have a mixture of kserve traces, unicorn access logs, latency timings etc.. Do we need all of them?

@DPogorzelski-WMF @klausman @achou - this may be something to keep in mind if/when we'll upgrade kserve.

I think we are out of the woods, we have around ~20k/minute logs now mostly coming from the inference-service pods (kserve-container). I think that we could definitely improve things there:

  1. The logs are not emitted using json or ECS so in case of errors, like Python stacktraces, we get one log for each line. It is a waste on the logstash side, but also not really great for human readers that need to investigate an outage the day afterwards. If the logs are not on the pods because of rotation, getting a complete stacktrace from logstash is really really tedious.
  1. We have a mixture of kserve traces, unicorn access logs, latency timings etc.. Do we need all of them?

Unstructured logging is bad for logstash. A single unstructured stack trace can turn into hundreds of individual events. At scale, a small outage where all instances are emitting stack traces has multiplicative effect and can easily overwhelm the pipeline.

I suggest we drop the kserve-container logs if they cannot be made into structured logs. Stack traces split up across individual events are considered useless for discovery and readability.

  1. The logs are not emitted using json or ECS so in case of errors, like Python stacktraces, we get one log for each line. It is a waste on the logstash side, but also not really great for human readers that need to investigate an outage the day afterwards. If the logs are not on the pods because of rotation, getting a complete stacktrace from logstash is really really tedious.
  1. We have a mixture of kserve traces, unicorn access logs, latency timings etc.. Do we need all of them?

To address the issues above:

  1. Log format
    • Emit single-line json with fields like ts, level, logger, message, request_id, model_name.
    • Serialize exceptions into one field (exception) so stack traces stay in one log event, not N lines.
  1. Mixed framework logs (uvicorn, kserve, etc.)
    • Look into upstream KServe logging.py and see how to customize it to better suit our needs (Thank @elukey for the pointer!)

Also, I roughly checked log volumes from kserve-container:

  • revscoring_model ~50%
  • revertrisk ~25%

We'll start with these two (~75% of total logs) to maximize impact.

Change #1270917 had a related patch set uploaded (by AikoChou; author: AikoChou):

[machinelearning/liftwing/inference-services@main] revscoring: add threshold to elapsed_time logging

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

Change #1270939 had a related patch set uploaded (by AikoChou; author: AikoChou):

[machinelearning/liftwing/inference-services@main] python/logging_utils: add configurable framework logger level overrides

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

I dug deeper into the logs from kserve-container and identified a few opportunities to reduce log volume.

KServe / Uvicorn logs (framework-level)

Current logs sent to Logstash:

  • kserve, uvicorn.error -> lifecycle logs (startup/shutdown)
INFO:kserve:Starting uvicorn with ...
INFO:uvicorn.error:Started server process ...
INFO:uvicorn.error:Waiting for application startup.
INFO:kserve:Starting gRPC server ...
INFO:uvicorn.error:Finished server process ...
  • uvicorn.access, kserve.trace -> per-request logs
# metrics requests (~every minute)

uvicorn.access INFO:     127.0.0.6:41873 1 - "GET /metrics HTTP/1.1" 200 OK
kserve.trace kserve.io.kserve.protocol.rest.server.metrics_handler: 0.0008749961853027344 ['http_status:200', 'http_method:GET', 'time:wall']
kserve.trace kserve.io.kserve.protocol.rest.server.metrics_handler: 0.0008700000000771979 ['http_status:200', 'http_method:GET', 'time:cpu']

# prediction requests

uvicorn.access INFO:     127.0.0.6:0 1 - "POST /v1/models/enwiki-drafttopic%3Apredict HTTP/1.1" 200 OK
kserve.trace requestId: bf1161af-0419-4fa9-8ed3-d7bf8a498be8, preprocess_ms: 835.281610489, explain_ms: 0, predict_ms: 19.635438919, postprocess_ms: 0.012397766
kserve.trace kserve.io.kserve.protocol.rest.v1_endpoints.predict: 0.007927999999083113

I've prepared a patch to support configurable framework logger level overrides.

Proposal:

  • Keep lifecycle loggers (kserve, uvicorn.error) at INFO
  • Downgrade high-volume per-request loggers:
    • uvicorn.access, kserve.trace -> WARNING

My current thinking is that per-request logs may not be very useful in Logstash, since we usually rely on Grafana for latency and response metrics. That said, if prediction request logging is useful, we could look into whether it's possible to assign different logging levels for metrics and prediction requests.

Application logs

Revscoring models

Current logging:

  • elapsed_time (per-request) for:
    • get_revscoring_extractor_cache
    • fetch_features
  • Payload logging (per-request) for:
    • rev_id requests
    • event-based requests

Proposal:

  • Only log slow requests for elapsed_time (e.g. > 5s)
  • Restrict payload logging to on-demand (rev_id) requests only
    • This remains useful for debugging specific cases
    • Event-based requests are high-volume (triggered for every revision via the revision-create stream)

Revertrisk models

Current logging:

  • Batch instance count (per-request)

Proposal:

  • Remove this log entirely
KServe InvalidInput logging behavior

Using InvalidInput from kserve.errors produces large tracebacks, and each line is ingested as a separate log entry in Logstash.

For expected client validation errors, we can instead use:

  • HTTPException(400, ...)

This avoids noisy tracebacks and keeps logs clean.

Change #1270939 merged by jenkins-bot:

[machinelearning/liftwing/inference-services@main] python/logging_utils: add configurable framework logger level overrides

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

Change #1275820 had a related patch set uploaded (by AikoChou; author: AikoChou):

[operations/deployment-charts@master] ml-services: update revertrisk-language-agnostic image

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

Change #1275867 had a related patch set uploaded (by AikoChou; author: AikoChou):

[machinelearning/liftwing/inference-services@main] revertrisk: improve logging levels and replace InvalidInput with HTTPException

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

Change #1275867 merged by jenkins-bot:

[machinelearning/liftwing/inference-services@main] revertrisk: improve logging levels and replace InvalidInput with HTTPException

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

Change #1275820 merged by jenkins-bot:

[operations/deployment-charts@master] ml-services: update revertrisk-language-agnostic image

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

Change #1276618 had a related patch set uploaded (by AikoChou; author: AikoChou):

[operations/deployment-charts@master] ml-services: update revertrisk-language-agnostic image

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

Change #1276618 merged by jenkins-bot:

[operations/deployment-charts@master] ml-services: update revertrisk-language-agnostic image

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

Change #1276644 had a related patch set uploaded (by AikoChou; author: AikoChou):

[machinelearning/liftwing/inference-services@main] revertrisk: suppress FastAPIDeprecationWarning from upstream KServe

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

Change #1276755 had a related patch set uploaded (by AikoChou; author: AikoChou):

[machinelearning/liftwing/inference-services@main] revscoring: fix SudachiPy 0.5.2 build

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

Change #1276644 merged by jenkins-bot:

[machinelearning/liftwing/inference-services@main] revertrisk: suppress FastAPIDeprecationWarning from upstream KServe

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

Change #1276755 merged by jenkins-bot:

[machinelearning/liftwing/inference-services@main] revscoring: fix SudachiPy 0.5.2 build

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

Change #1270917 merged by jenkins-bot:

[machinelearning/liftwing/inference-services@main] revscoring: add threshold to elapsed_time logging

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

Change #1281528 had a related patch set uploaded (by AikoChou; author: AikoChou):

[operations/deployment-charts@master] ml-services: update staging image for RRLA and revscoring model

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

Change #1281528 merged by jenkins-bot:

[operations/deployment-charts@master] ml-services: update staging image for RRLA and revscoring model

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

Change #1282922 had a related patch set uploaded (by AikoChou; author: AikoChou):

[operations/deployment-charts@master] ml-services: update production image for RRLA and revscoring model

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

Change #1282922 merged by jenkins-bot:

[operations/deployment-charts@master] ml-services: update production image for RRLA and revscoring model

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

The changes have been deployed to RRLA and revscoring models on production.

We are getting less logs from kserve-container:

Screenshot 2026-05-05 at 15.57.26.png (2,090×512 px, 57 KB)

That's amazing <3 thank you Aiko!