Actions
Idea #10473
closed
[Keepstore] Log requests in JSON format
Added by Tom Morris about 8 years ago. Updated almost 8 years ago.
Start date:
11/07/2016
Due date:
Story points:
0.5
Description
Switch request logging log format to JSON to allow easier parsing and post-processing.
This line in source:services/keepstore/logging_router.go#L75
log.Printf("[%s] %s %s %d %.6fs %.6fs %.6fs %d %d \"%s\"", req.RemoteAddr, req.Method, req.URL.Path[1:], req.ContentLength, tTotal.Seconds(), tLatency.Seconds(), tResponse.Seconds(), resp.Status, resp.Length, statusText)
...should log some JSON to a logger that doesn't use a prefix.
Add an RFC3339 timestamp, too.
Updated by Tom Morris about 8 years ago
- Subject changed from [Keepstore] Log in JSON format to [Keepstore] Log requests in JSON format
- Description updated (diff)
Updated by Tom Clegg about 8 years ago
- Description updated (diff)
- Target version set to 2016-11-23 sprint
- Story points set to 0.5
Updated by Tom Clegg about 8 years ago
{"level":"info","msg":"MaxRequests \u003c1 or not specified; defaulting to MaxBuffers * 2 == 256","time":"2016-11-18T01:50:13.076684599-05:00"}
{"level":"info","msg":"Trash/delete features are enabled. WARNING: this has not been extensively tested. You should disable this unless you can afford to lose data.","time":"2016-11-18T01:50:13.076945734-05:00"}
{"level":"info","msg":"Using volume [UnixVolume /tmp/tmp8QP0gC] (writable=true)","time":"2016-11-18T01:50:13.076994544-05:00"}
{"level":"info","msg":"keepstore starting, pid 9806","time":"2016-11-18T01:50:13.077041863-05:00"}
{"level":"info","msg":"listening at [::]:43565","time":"2016-11-18T01:50:13.07874017-05:00"}
{"RemoteAddr":"127.0.0.1:45914","ReqBytes":5,"ReqMethod":"PUT","ReqPath":"5d41402abc4b2a76b9719d911017c592","RequestID":"b8n9wci6xman","X-Forwarded-For":"","level":"info","msg":"request","time":"2016-11-18T01:50:13.652684422-05:00"}
{"RemoteAddr":"127.0.0.1:45914","ReqBytes":5,"ReqMethod":"PUT","ReqPath":"5d41402abc4b2a76b9719d911017c592","RequestID":"b8n9wci6xman","RespBytes":86,"RespStatus":"OK","RespStatusCode":200,"TimeToStatus":0.004525797000000001,"TimeTotal":0.004546931000000001,"TimeWriteBody":2.1134e-05,"X-Forwarded-For":"","level":"info","msg":"response","time":"2016-11-18T01:50:13.657214151-05:00"}
{"RemoteAddr":"127.0.0.1:35563","ReqBytes":0,"ReqMethod":"GET","ReqPath":"4b2e16edaa549c34282fbfd9da3edba2+10000000+Af5be9395d58442fa5a92cb69dd6c1d0b80b2a736@5841941c","RequestID":"b8nl0fiw73is","X-Forwarded-For":"","level":"info","msg":"request","time":"2016-11-18T10:32:45.891099881-05:00"}
{"RemoteAddr":"127.0.0.1:35563","ReqBytes":0,"ReqMethod":"GET","ReqPath":"4b2e16edaa549c34282fbfd9da3edba2+10000000+Af5be9395d58442fa5a92cb69dd6c1d0b80b2a736@5841941c","RequestID":"b8nl0fiw73is","RespBytes":10000000,"RespStatus":"OK","RespStatusCode":200,"TimeToStatus":0.039436971,"TimeTotal":0.052046873,"TimeWriteBody":0.012609902000000001,"X-Forwarded-For":"","level":"info","msg":"response","time":"2016-11-18T10:32:45.943142116-05:00"}
{"RemoteAddr":"127.0.0.1:35563","ReqBytes":0,"ReqMethod":"GET","ReqPath":"4b2e16edaa549c34282fbfd9da3edba2+10000000+Af5be9395d58442fa5a92cb69dd6c1d0b80b2a736@5841941c","RequestID":"b8nl0fjwqyq5","X-Forwarded-For":"","level":"info","msg":"request","time":"2016-11-18T10:32:45.952496494-05:00"}
{"RemoteAddr":"127.0.0.1:35563","ReqBytes":0,"ReqMethod":"GET","ReqPath":"4b2e16edaa549c34282fbfd9da3edba2+10000000+Af5be9395d58442fa5a92cb69dd6c1d0b80b2a736@5841941c","RequestID":"b8nl0fjwqyq5","RespBytes":10000000,"RespStatus":"OK","RespStatusCode":200,"TimeToStatus":0.039105081,"TimeTotal":0.052075242,"TimeWriteBody":0.012970161000000001,"X-Forwarded-For":"","level":"info","msg":"response","time":"2016-11-18T10:32:46.004565604-05:00"}
{"RemoteAddr":"127.0.0.1:35563","ReqBytes":0,"ReqMethod":"GET","ReqPath":"4b2e16edaa549c34282fbfd9da3edba2+10000000+Af5be9395d58442fa5a92cb69dd6c1d0b80b2a736@5841941c","RequestID":"b8nl0fkxflxe","X-Forwarded-For":"","level":"info","msg":"request","time":"2016-11-18T10:32:46.014109884-05:00"}
{"RemoteAddr":"127.0.0.1:35563","ReqBytes":0,"ReqMethod":"GET","ReqPath":"4b2e16edaa549c34282fbfd9da3edba2+10000000+Af5be9395d58442fa5a92cb69dd6c1d0b80b2a736@5841941c","RequestID":"b8nl0fkxflxe","RespBytes":10000000,"RespStatus":"OK","RespStatusCode":200,"TimeToStatus":0.039018950000000004,"TimeTotal":0.05190115,"TimeWriteBody":0.012882200000000002,"X-Forwarded-For":"","level":"info","msg":"response","time":"2016-11-18T10:32:46.066007639-05:00"}
Updated by Tom Clegg almost 8 years ago
{"RequestID":"b8oz570nnb0p","level":"info","msg":"response","remoteAddr":"127.0.0.1:50507","reqBytes":0,"reqForwardedFor":"","reqMethod":"HEAD","reqPath":"acbd18db4cc2f85cedef654fccc4a4d8","respBytes":10,"respStatus":"Not Found","respStatusCode":404,"time":"2016-11-20T01:49:54.705792391-05:00","timeToStatus":0.015461,"timeTotal":0.015512,"timeWriteBody":0.000052}
{"RequestID":"b8oz5717qj4u","level":"info","msg":"response","remoteAddr":"127.0.0.1:50507","reqBytes":0,"reqForwardedFor":"","reqMethod":"GET","reqPath":"acbd18db4cc2f85cedef654fccc4a4d8","respBytes":10,"respStatus":"Not Found","respStatusCode":404,"time":"2016-11-20T01:49:54.739671119-05:00","timeToStatus":0.015510,"timeTotal":0.015647,"timeWriteBody":0.000138}
{"RequestID":"b8oz571ru06s","level":"info","msg":"response","remoteAddr":"127.0.0.1:50507","reqBytes":3,"reqForwardedFor":"","reqMethod":"PUT","reqPath":"acbd18db4cc2f85cedef654fccc4a4d8","respBytes":86,"respStatus":"OK","respStatusCode":200,"time":"2016-11-20T01:49:54.781639396-05:00","timeToStatus":0.023855,"timeTotal":0.023871,"timeWriteBody":0.000017}
{"RequestID":"b8oz5726z2y3","level":"info","msg":"response","remoteAddr":"127.0.0.1:50507","reqBytes":0,"reqForwardedFor":"","reqMethod":"HEAD","reqPath":"acbd18db4cc2f85cedef654fccc4a4d8+3+A2caf8474af102314c5b2ff0ff0d6a232b38e8457@5843bc92","respBytes":3,"respStatus":"OK","respStatusCode":200,"time":"2016-11-20T01:49:54.798639859-05:00","timeToStatus":0.015402,"timeTotal":0.015430,"timeWriteBody":0.000028}
(at 927db6616baa78420a7ffccc59ef784fe57f6668 on 10473-keepstore-logrus)
Updated by Radhika Chippada almost 8 years ago
Just one question: Do we want id_generator.go in sdk/go/httpserver, or move it into “sdk/go/arvados” in case we want to use it for other purposes in future?
LGTM
Updated by Tom Clegg almost 8 years ago
- Status changed from New to Resolved
- % Done changed from 50 to 100
Applied in changeset arvados|commit:372a67d4364d4776aaa8a5ae9a4dd0ac16a0c524.
Actions