Improving structured logging #73
Description
Looking at JBI logs, it is very hard to debug/troubleshoot a use-case.
When filtering the logs on jsonPayload.Type!="request.summary" or jsonPayload.Type="ignored-requests" we obtain this sort of entry:
{
"insertId": "1vxv4qutgqc8iupq",
"jsonPayload": {
"Fields": {
"msg": "request: {\"webhook_id\": 22, \"webhook_name\": \"JBI-PROD-InfrastructureAndOperations\", \"event\": {\"action\": \"modify\", \"time\": \"2022-06-30T15:05:07\", \"user\": {\"id\": yyyyyy, \"login\": \"[email protected]\", \"real_name\": \"XXXXX\"}, \"changes\": [{\"field\": \"flag.needinfo\", \"removed\": \"\", \"added\": \"? ([email protected])\"}], \"target\": \"bug\", \"routing_key\": \"bug.modify:flag.needinfo\"}, \"bug\": {\"id\": XXXX, \"is_private\": false, \"type\": \"task\", \"product\": \"Infrastructure & Operations\", \"component\": \"Infrastructure: LDAP\", \"whiteboard\": \"\", \"keywords\": [], \"flags\": [{\"id\": 2114317, \"name\": \"needinfo\", \"requestee\": {\"id\": yyyyy, \"login\": \"xxxxxxxxxx\", \"real_name\": \"XXX XXXX\"}, \"value\": \"?\"}], \"status\": \"ASSIGNED\", \"resolution\": \"\", \"see_also\": [], \"summary\": \"Restore Commit Access (Level 3) for XXXXX\", \"severity\": \"--\", \"priority\": \"\", \"creator\": \"[email protected]\", \"assigned_to\": \"[email protected]\", \"comment\": null}}"
},
"Hostname": "jbi-prod-jbi-app-1-6799547446-xlnf4",
"Severity": 6,
"Logger": "jbi",
"Type": "src.jbi.router",
"EnvVersion": "2.0",
"Pid": 11,
"Timestamp": 1656601536174810000
},
}
I propose that we use structured logs better:
msg: a short human messageoperation: an enum of predefined actions (eg.create,update,comment,ignore...)action: the matching configured action and its parametersrequestBody: the input JSONresponseBody: the output JSON
This way we could track bug numbers better with log queries like:
jsonPayload.Type="ignored-requests"
jsonPayload.Fields.requestBody.bug.id=12345678