Log message consistency nitpicks
Problem Description
The field level
is a pretty decent standard, and usually has the text error
or info
pending the result of processing a request. During an unrelated investigation, I found a few odd instances where these do not appear to align very well.
Examples:
A request completes unsuccessfully:
Log Message
Modified for brevity:
{
"component": "gitaly.StreamServerInterceptor",
"error": null
"level": "error",
"msg": "fatal: Not a valid object name main\n",
"time": "2024-04-05T14:02:03.706Z",
"user_id": "1",
"username": "root"
}
}
Notice the following:
-
level
is of typeerror
-
msg
indicates that this was a fatal problem to this request -
error
is not populated
A request completes successfully, this looks similar to that of an HTTP404 (analogy):
Log Message
Modified for brevity:
{
"component": "gitaly.StreamServerInterceptor",
"error": "tree entry not found",
"error_metadata": {
"path": ".gitlab-ci.yml"
},
"level": "info",
"msg": "finished streaming call with code NotFound",
"time": "2024-04-05T14:08:11.085Z",
"user_id": "1",
"username": "root"
}
}
Notice the following:
-
level
of typeinfo
-
error
is populated with similar information to that ofmsg
Proposed Solution
My nitpick is about consistency across calls and ensuring that we are indicating the correct level
with the request being handled and populating relevant fields. I am not asking that we look into these target calls to determine what went wrong, these are normal everyday operations that Gitaly is subject to. I'm simply asking for a solid and clean UX to our logging. The two above examples seem to be in conflict where a failed request is noted as not a big issue, where as the request that was handled and is indicated as informational, contains an error
field which would indicate a problem.