Page MenuHomePhabricator

Add Gravy [Orchestrator|Processor] structured logs layer
Open, Needs TriagePublic

Description

  • Create GravyApiTimingTrait
  • Update Gravy Api.php to use new trait
  • Add GravyApiTimingTraitTest
  • Detect backend processor in $response
  • Update Log format: [gravy|adyen|cc|authorize|request|time]
  • Handle empty backend processor with || for consistent parsing

Storymap https://storymaps.io/rhkshlde

image.png (1×1 px, 195 KB)

Event Timeline

Change #1236844 had a related patch set uploaded (by Jgleeson; author: Jgleeson):

[wikimedia/fundraising/SmashPig@master] Add orchestrator|backend_processor layer to Gravy API timing logs

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

I also need to add a small update to the existing log tag builder to indicate an empty first cell for the non-gravy API calls, e.g. [|adyen|cc|authorize|request|time] 1.234567s

@Jgreen, can you confirm that's what you're expecting?

Change #1237503 had a related patch set uploaded (by Jgleeson; author: Jgleeson):

[wikimedia/fundraising/SmashPig@master] Add empty orchestrator placeholder to non-Gravy timing log tags

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

@Jgreen, @Dwisehaupt, one question here, let me lay out the context before asking:

Context:
Current format changes from:
[gravy|cc|authorize|request|time] 1.234567s
To:
[gravy|adyen|cc|authorize|request|time] 1.234567s

When the backend processor is not available (e.g., report/session calls), the segment is left empty for consistent parsing:
[gravy||cc|createSession|request|time] 0.278910s

We also now prepend an empty first segment to non-Gravy direct processor calls to produce
[|adyen|cc|authorize|request|time] 1.234567s

matching the 6-segment format for consistent log parsing across all API calls.

Question:
For that last one. do you want
[|adyen|cc|authorize|request|time] 1.234567s
or
[||adyen|cc|authorize|request|time] 1.234567s

There should always be the same number of '|' delimiters. From the collection side it doesn't matter if there's a value between them. The regex is just looking for delimiters and capturing the values (including null) between them.

Also the values are labelled by position in the string:

'\(APITimings\) \[(?<orchestrator>[^\|]*)\|(?<processor>[^\|]*)\|(?<type>[^\|]*)\|(?<method>[^\|]*)\|(?<request>[^\|]*)\|(?<unit>[^\|]*)\] (?<value>[\d\.])+s?'

For example, whatever is between '[' and the first '|' will always become the value for 'orchestrator' label, whatever's between the first two '|' becomes 'processor'.

@Jgreen after one small tweak to your regex, I think we're good! https://regex101.com/r/XFOLHG/1

(?<value>[\d\.])+s? needed to be (?<value>[\d\.]+)s?

@Jgreen after one small tweak to your regex, I think we're good! https://regex101.com/r/XFOLHG/1

(?<value>[\d\.])+s? needed to be (?<value>[\d\.]+)s?

Ahh, yeah, good catch! I'll deploy this today.

@jgleeson this is deployed, it should start collecting once the 6th field is added

Change #1236844 merged by jenkins-bot:

[wikimedia/fundraising/SmashPig@master] Add orchestrator|backend_processor layer to Gravy API timing logs

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

Change #1237503 merged by jenkins-bot:

[wikimedia/fundraising/SmashPig@master] Add empty orchestrator placeholder to non-Gravy timing log tags

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