RFR: 1552: Log relevant timer numbers

Erik Joelsson erikj at openjdk.org
Tue Aug 23 23:27:59 UTC 2022

This is a pretty big patch, but it shouldn't be too scary as it's only supposed to change logging, mainly by adding more logging (and also removing some now redundant log calls).

The main focus here is to add structured timing data to some log messages. To do this, I'm using the optional `parameters` `Object[]` that you can supply to the logger from `java.util.logging`. If the LogstashHandler finds a `Duration` instance in that array, it will add it as a "duration" field in the logstash log document. In the BotRunner, we were already using parameters for a different purpose, so it got a little bit messy, but I think it's ok.

There are two kinds of timings I'm adding logging for. The obvious one is timing external HTTP calls and running processes, as well as total running/pending/scheduled times for WorkItems and getPeriodicItems in the BotRunner. The other kind are more complex as I'm trying to measure the user perceived latency from when a PR or bug is updated to when the bot actually reacts with a response to that update. This is of course tricky to get right and needs to be carefully implemented for each instance, but I believe I have at least added some reasonably relevant approximations that will make sense to measure and track. To generate these, I had to introduce a new field in various WorkItems that stores the timestamp from the external change that triggered it (e.g. `prUpdatedAt`).

In addition to this, there are a ton more regular log messages, mostly on info level, that detail actions performed by various WorkItems. This is something I have been missing a lot when browsing logs.


Commit messages:
 - Better field name
 - Command name in latency log
 - Log latency when PR command successful
 - Adjusted CheckRun comments
 - SKARA-1552

Changes: https://git.openjdk.org/skara/pull/1361/files
 Webrev: https://webrevs.openjdk.org/?repo=skara&pr=1361&range=00
  Issue: https://bugs.openjdk.org/browse/SKARA-1552
  Stats: 286 lines in 28 files changed: 194 ins; 14 del; 78 mod
  Patch: https://git.openjdk.org/skara/pull/1361.diff
  Fetch: git fetch https://git.openjdk.org/skara pull/1361/head:pull/1361

PR: https://git.openjdk.org/skara/pull/1361

More information about the skara-dev mailing list