fix: improve logging structure

[kangmingtay]

What kind of change does this PR introduce?

• Remove unformatted logs which do not confirm to JSON
• Previously, we were logging both time (not UTC) and timestamp (in UTC) which is redundant. I've opted to remove timestamp and just log the UTC time as the time field, which is supported by logrus
• Previously, the request_id was not being logged because it was unable to retrieve the context properly. Now, the request_id field is added to every log entry, which allows us to filter by request_id to see the entire lifecycle of the request
• Previously, panics weren't being handled properly and they were just logged as text instead of JSON. The server would return an empty reply, which leads to ugly responses like "Unexpected token < in JSON..." if using fetch in JS. Now, the server returns a proper 500 error response: {"code":500,"error_code":"unexpected_failure","msg":"Internal Server Error"}
• Added tests for recoverer and NewStructuredLogger to prevent regression
• Remove "request started" log since the request_id can be used to keep track of the entire request lifecycle. This cuts down on the noise to signal ratio as well.

Log format

• Panics are now logged like this (note the additional fields like panic and stack - which is a dump of the stack trace):

{
  "component":"api",
  "duration":6065700500,
  "level":"info",
  "method":"GET",
  "msg":"request completed",
  "panic":"test panic",
  "path":"/panic",
  "referer":"http://localhost:3001",
  "remote_addr":"127.0.0.1",
  "request_id":"4cde5f20-2c3c-4645-bc75-52d6231e22e2",
  "stack":"goroutine 82 [running]:...rest of stack trace omitted for brevity",
  "status":500,
  "time":"2024-05-15T09:37:42Z"
}

• Requests that call NewAuditLogEntry will be logged with the auth_event payload in this format (note that the timestamp field no longer exists)

{
  "auth_event": {
    "action": "token_refreshed",
    "actor_id": "733fb34d-a6f2-43e1-976a-8e6a456b6889",
    "actor_name": "Kang Ming Tay",
    "actor_username": "kang.ming1996@gmail.com",
    "actor_via_sso": false,
    "log_type": "token"
  },
  "component": "api",
  "duration": 75945042,
  "level": "info",
  "method": "POST",
  "msg": "request completed",
  "path": "/token",
  "referer": "http://localhost:3001",
  "remote_addr": "127.0.0.1",
  "request_id": "08c7e47b-42f4-44dc-a39b-7275ef5bbb45",
  "status": 200,
  "time": "2024-05-15T09:40:09Z"
}

[coveralls]

Pull Request Test Coverage Report for Build 9111276456

Details

• 97 of 111 (87.39%) changed or added relevant lines in 14 files are covered.
• 8 unchanged lines in 4 files lost coverage.
• Overall coverage increased (+0.4%) to 65.836%

---

Changes Missing Coverage	Covered Lines	Changed/Added Lines	%
internal/api/auth.go	1	2	50.0%
internal/api/samlacs.go	0	1	0.0%
internal/api/token.go	0	1	0.0%
internal/api/verify.go	1	2	50.0%
internal/api/middleware.go	2	4	50.0%
internal/api/token_oidc.go	0	2	0.0%
internal/api/errors.go	17	20	85.0%
internal/utilities/context.go	9	12	75.0%

Files with Coverage Reduction	New Missed Lines	%
internal/api/api.go	1	86.28%
internal/api/verify.go	1	73.33%
internal/hooks/auth_hooks.go	3	45.45%
internal/models/errors.go	3	45.59%

Totals
Change from base Build 9065702589:	0.4%
Covered Lines:	8423
Relevant Lines:	12794

---

💛 - Coveralls