Page MenuHomePhabricator

Investigation: How does Citoid logging deal with parallel requests
Closed, ResolvedPublic

Description

Context

In logstash we saw failing request logged from the Citoid service that refered to URLs including PDFs, logged as 200 with a log level 'Warning'. When testing some of these URLs manually we saw them succeeding in the interface of the Citoid extension though.

Investigation

We assume, that his is happening due to different approaches running in parallel. Some of them might succeed and some not. If one fails including the PDF we'll still see the issue in logstash but on the users end it's fine.

We might figure out a way to make that more transparent in logstash so that we have a more reliable source on how many user request fail.

Example URIs
Further ressoures

Logstash https://logstash.wikimedia.org/app/dashboards#/view/5eaf4e40-f6b6-11eb-85b7-9d1831ce7631?_g=h@c823129&_a=h@c75efd5
Citoid Grafana https://grafana.wikimedia.org/d/NJkCVermz/citoid?orgId=1&refresh=5m&from=now-30m&to=now&timezone=utc&var-dc=000000026

HTTP status panel

https://grafana.wikimedia.org/d/NJkCVermz/citoid?orgId=1&refresh=5m&from=now-30m&to=now&timezone=utc&var-dc=000000026&viewPanel=panel-13

Details

Event Timeline

Yes, the outgoingRequestResult is specifically logging error messages we receive from third party sites only, not our final response. This logging was added to specifically diagnose issues we were having with upstream sites.

This does not mean the final result isn't resolved. We will still show an upstream error even if it was ultimately successful.

Final results aren't logged (I believe it is debug level) at this present time to production. I think historically we wanted to keep the amount of upstream logs to a minimum?

Final results are tallied via metrics instead, not logging: https://grafana.wikimedia.org/d/NJkCVermz/citoid?orgId=1&refresh=5m&from=now-30m&to=now

Sorry, it's a bit confusing!

If you wanted to get an idea on how many pdf links ultimately fail to resolve, then the best way right now is to look at the percentage of 415 errors, though we don't split that by content-type (though it is in the response). Could enhance metrics to do this, though!

Or I guess change logging to log the final result with the outgoingReqResult all in one log.

Change #1318714 had a related patch set uploaded (by WMDE-Fisch; author: WMDE-Fisch):

[mediawiki/services/citoid@master] Add contentType to response for logging

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

Change #1318714 merged by jenkins-bot:

[mediawiki/services/citoid@master] Add contentType to response for logging

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

WMDE-Fisch removed WMDE-Fisch as the assignee of this task.

I think we know enough now for this. I'll create a follow up for the logging of all PDF cases.

lilients_WMDE renamed this task from Investigation: How does Citoid logging deal with parrallel requests to Investigation: How does Citoid logging deal with parallel requests.Wed, Aug 5, 8:10 AM