[why] current taskqueue show 4 lines for 1 debug message - empty line for split: - end user request ip:port, request body: 172.17.0.1:48956 {"domain":"..."} - response body: <-- - kemal frame log: 2020-10... 200 POST /add?queue=... 710.15µs
cut it 2 line, and duplicate information - kemal frame log has time in {2020-10...} and span {710.15us}
examples: before <<<
2020-10-19 02:40:06 UTC --> 172.17.0.1:48956 {"domain":"compass-ci","lab":"z9"} 2020-10-19 02:40:06 UTC <-- {"id":"z9.134780"} 2020-10-19 02:40:06 UTC 200 POST /add?queue=sched%2Ftaishan200-2280-2s64p-256g--a9 710.15µs
after <<< from: {172.17.0.1:37444} <-- ack: {"domain":"compass-ci","lab":"crystal","id":"crystal.104640"} 2020-10-19 08:12:20 UTC 200 PUT /consume?queue=extract_stats 1.01ms
Signed-off-by: Tong Qunfeng taxcom@tom.com --- src/taskqueue/taskqueue.cr | 20 +++++++++++++------- 1 file changed, 13 insertions(+), 7 deletions(-)
diff --git a/src/taskqueue/taskqueue.cr b/src/taskqueue/taskqueue.cr index c5c202d..98c5623 100644 --- a/src/taskqueue/taskqueue.cr +++ b/src/taskqueue/taskqueue.cr @@ -18,16 +18,22 @@ class TaskQueue @@rate_limiter.bucket(:l1pms, 1_u32, 0.001.seconds) @@rate_limiter.bucket(:l100pms, 1_u32, 0.00001.seconds)
+ # logs example: + # from: {172.17.0.1:6952} body {"domain":"compass-ci"} <-- ack: {"id":"z9.134780"} + # | from: {172.17.0.1:6952} <-- ack: {} + # 2020-10-19 03:25:01 UTC 201 PUT /consume?queue=sched%2Fdc-2g%2Fidle 356.51µs + # + # "from" is puts by this debug_message + # "2020-10..." auto puts by kemal frame, time in {2020-10-19 03:25:01 UTC} and span {356.51us} def debug_message(env, response, time_in) - puts("\n") + logs = "from: {#{env.request.remote_address}}"
- from_message = "#{time_in} --> #{env.request.remote_address}" - if env.request.body != nil - from_message += " #{env.request.body}" - end - puts(from_message) + logs += " body: #{env.request.body}" if env.request.body + + logs += " <-- ack: " + logs += response ? "#{response}" : "{}"
- puts("#{Time.utc} <-- #{response}") + puts(logs) end
def run