From c6ac5232db3ce0bc561f4c3713a768d104e783de Mon Sep 17 00:00:00 2001 From: Alexander Reelsen Date: Tue, 19 Mar 2019 12:51:11 +0100 Subject: [PATCH 1/2] Properly measure request time using Time.monotonic --- src/kemal/log_handler.cr | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/kemal/log_handler.cr b/src/kemal/log_handler.cr index 6d04281..4ecd81f 100644 --- a/src/kemal/log_handler.cr +++ b/src/kemal/log_handler.cr @@ -5,10 +5,10 @@ module Kemal end def call(context : HTTP::Server::Context) - time = Time.now + time = Time.monotonic call_next(context) - elapsed_text = elapsed_text(Time.now - time) - @io << time << ' ' << context.response.status_code << ' ' << context.request.method << ' ' << context.request.resource << ' ' << elapsed_text << '\n' + elapsed_text = elapsed_text(Time.monotonic - time) + @io << Time.now << ' ' << context.response.status_code << ' ' << context.request.method << ' ' << context.request.resource << ' ' << elapsed_text << '\n' context end From 14ed2aa8bf23426ee98a17e53b577e7bfb169fd4 Mon Sep 17 00:00:00 2001 From: Alexander Reelsen Date: Wed, 20 Mar 2019 08:39:36 +0100 Subject: [PATCH 2/2] improvement: use Time.measure --- src/kemal/log_handler.cr | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/src/kemal/log_handler.cr b/src/kemal/log_handler.cr index 4ecd81f..517857a 100644 --- a/src/kemal/log_handler.cr +++ b/src/kemal/log_handler.cr @@ -5,9 +5,8 @@ module Kemal end def call(context : HTTP::Server::Context) - time = Time.monotonic - call_next(context) - elapsed_text = elapsed_text(Time.monotonic - time) + elapsed_time = Time.measure { call_next(context) } + elapsed_text = elapsed_text(elapsed_time) @io << Time.now << ' ' << context.response.status_code << ' ' << context.request.method << ' ' << context.request.resource << ' ' << elapsed_text << '\n' context end