Skip to content

Commit

Permalink
Wrap request handler in Log.with_context (#9494)
Browse files Browse the repository at this point in the history
* Wrap request handler in `Log.with_context`

* Ensure exceptions are logged within the same context as handler
  • Loading branch information
Blacksmoke16 authored Jun 17, 2020
1 parent c41640f commit 9dffad3
Show file tree
Hide file tree
Showing 2 changed files with 32 additions and 3 deletions.
33 changes: 31 additions & 2 deletions spec/std/http/server/request_processor_spec.cr
Original file line number Diff line number Diff line change
Expand Up @@ -268,9 +268,9 @@ describe HTTP::Server::RequestProcessor do
logs.entry.exception.should be_a(IO::Error)
end

it "catches raised error on handler" do
it "catches raised error on handler and retains context from handler" do
exception = Exception.new "OH NO"
processor = HTTP::Server::RequestProcessor.new { raise exception }
processor = HTTP::Server::RequestProcessor.new { Log.context.set foo: "bar"; raise exception }
input = IO::Memory.new("GET / HTTP/1.1\r\n\r\n")
output = IO::Memory.new
logs = Log.capture("http.server") do
Expand All @@ -286,6 +286,7 @@ describe HTTP::Server::RequestProcessor do

logs.check(:error, "Unhandled exception on HTTP::Handler")
logs.entry.exception.should eq(exception)
logs.entry.context[:foo].should eq "bar"
end

it "doesn't respond with error when headers were already sent" do
Expand Down Expand Up @@ -320,4 +321,32 @@ describe HTTP::Server::RequestProcessor do
client_response.status_code.should eq(200)
client_response.body.should eq("Hello world")
end

it "does not bleed Log::Context between requests" do
processor = HTTP::Server::RequestProcessor.new do |context|
Log.info { "before" }
Log.context.set foo: "bar"
Log.info { "after" }

context.response.content_type = "text/plain"
context.response.print "Hello world"
end

logs = Log.capture do
processor.process(
IO::Memory.new("GET / HTTP/1.1\r\n\r\nGET / HTTP/1.1\r\n\r\n"),
IO::Memory.new,
)
end

logs.check :info, "before"
logs.entry.context.should be_empty
logs.check :info, "after"
logs.entry.context[:foo].should eq "bar"

logs.check :info, "before"
logs.entry.context.should be_empty
logs.check :info, "after"
logs.entry.context[:foo].should eq "bar"
end
end
2 changes: 1 addition & 1 deletion src/http/server/request_processor.cr
Original file line number Diff line number Diff line change
Expand Up @@ -46,7 +46,7 @@ class HTTP::Server::RequestProcessor
response.headers["Connection"] = "keep-alive" if request.keep_alive?
context = Context.new(request, response)

begin
Log.with_context do
@handler.call(context)
rescue ex : ClientError
Log.debug(exception: ex.cause) { ex.message }
Expand Down

0 comments on commit 9dffad3

Please sign in to comment.