Tidy up log

[jirenius]

Issue

The log output from Resgate needs tidying up.

The scope of this issue includes:

Trace/Debug level

Current debug flag should be split into both trace and debug, where trace activates log of subjects being subscribed/unsubscribed and messages being sent/received, both from NATS and from clients.

Output format

Update output format to include:

• date
• time
• microseconds
• log level ([INF], [TRC], [DEB], [ERR])

Improved request logging

Logging output should be improved to allow easier tracing.

Example output

2019/10/01 09:28:00.123457 [INF] Starting resgate version 1.2.2
2019/10/01 09:28:01.123457 [INF] Connecting to NATS at nats://127.0.0.1:4222
2019/10/01 09:28:02.123457 [DBG] Starting HTTP server
2019/10/01 09:28:03.123457 [INF] Listening on http://0.0.0.0:8080
2019/10/01 09:34:00.123457 [TRC] [bm9gakt8smgitf7lc2kg] Connected 127.0.0.1:51234
2019/10/01 09:34:05.123457 [TRC] [bm9gakt8smgitf7lc2kg] --> {"id":1,"method":"subscribe.library.book.2"}
2019/10/01 09:36:05.123789 [TRC] <== (PDBAv) access.library.book.2: {"token":null,"cid":"bm9gakt8smgitf7lc2kg"}
2019/10/01 09:36:05.123799 [TRC] <== (PDAzi) get.library.book.2: {}
2019/10/01 09:36:05.234567 [TRC] ==> (PDBAv) {"result":{"get":true,"call":"*"}}
2019/10/01 09:36:05.237901 [TRC] ==> (PDAZi) {"result":{"model":{"id":1,"title":"Animal Farm","author":"George Orwell"}}}
2019/10/01 09:36:05.238901 [TRC] [bm9g7qt8smgitf7lc2k0] <-- {"result":{"models":{"library.book.2":{"author":"Aldous Huxley","id":2,"title":"Brave New World"}}},"id":1}
2019/10/01 09:36:15.234567 [TRC] =>> event.library.book.1.change: {"values":{"title":"Animal Farming"}}
2019/10/01 09:36:15.234567 [TRC] [bm9g7qt8smgitf7lc2k0] <<- {"event":"library.book.1.change","data":{"values":{"title":"Animal Farming"}}}

• IP:port should be logged together with connection ID on client connect
• The values in paranthesis, eg. (PDAzi) are the last 5 characters of the request inbox.
• Events are marked with =>> if coming from NATS or <<- if going to the client.

[jirenius]

Resolved in #122