Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Addresses #858 - Update logging example to use released version of log/slog #864

Closed
wants to merge 1 commit into from
Closed

Addresses #858 - Update logging example to use released version of log/slog #864

wants to merge 1 commit into from

Conversation

ydarb
Copy link
Contributor

@ydarb ydarb commented Oct 19, 2023 •
edited

chore: Update logging example to use released version of log/slog

Adds bool to flip example between a TextHandler and a JSONHandler. Update Panic() to pretty print stack trace if log handler is a TextHandler, otherwise it will log the stack trace as a JSON value string with a key of "stack".

Ref: #858

Example TextHandler log messages for each endpoint:

/
level=INFO msg="request started" ts="Thu, 19 Oct 2023 07:00:40 UTC" req_id=host.local/duevLL4tFS-000001 http_scheme=http http_proto=HTTP/1.1 http_method=GET remote_addr=127.0.0.1:51360 user_agent=curl/8.1.2 uri=http://localhost:3333/ level=INFO msg="request complete" ts="Thu, 19 Oct 2023 07:00:40 UTC" req_id=host.local/duevLL4tFS-000001 http_scheme=http http_proto=HTTP/1.1 http_method=GET remote_addr=127.0.0.1:51360 user_agent=curl/8.1.2 uri=http://localhost:3333/ resp_status=200 resp_byte_length=7 resp_elapsed_ms=0.008208
/wait
level=INFO msg="request started" ts="Thu, 19 Oct 2023 07:01:11 UTC" req_id=host.local/duevLL4tFS-000002 http_scheme=http http_proto=HTTP/1.1 http_method=GET remote_addr=127.0.0.1:51361 user_agent=curl/8.1.2 uri=http://localhost:3333/wait level=INFO msg="request complete" ts="Thu, 19 Oct 2023 07:01:11 UTC" req_id=host.local/duevLL4tFS-000002 http_scheme=http http_proto=HTTP/1.1 http_method=GET remote_addr=127.0.0.1:51361 user_agent=curl/8.1.2 uri=http://localhost:3333/wait wait=true resp_status=200 resp_byte_length=2 resp_elapsed_ms=1001.1815
/panic
level=INFO msg="request started" ts="Thu, 19 Oct 2023 07:02:14 UTC" req_id=host.local/duevLL4tFS-000004 http_scheme=http http_proto=HTTP/1.1 http_method=GET remote_addr=127.0.0.1:51363 user_agent=curl/8.1.2 uri=http://localhost:3333/panic

panic: oops

-> main.main.func3
-> /home/user/workspace/github.com/ydarb/chi/_examples/logging/main.go:49

net/http.HandlerFunc.ServeHTTP
  /home/user/sdk/go1.21.3/src/net/http/server.go:2136
github.com/go-chi/chi/v5.(*Mux).routeHTTP
  /home/user/workspace/github.com/ydarb/chi/mux.go:443
net/http.HandlerFunc.ServeHTTP
  /home/user/sdk/go1.21.3/src/net/http/server.go:2136
github.com/go-chi/chi/v5/middleware.Recoverer.func1
  /home/user/workspace/github.com/ydarb/chi/middleware/recoverer.go:45
net/http.HandlerFunc.ServeHTTP
  /home/user/sdk/go1.21.3/src/net/http/server.go:2136
main.main.NewStructuredLogger.RequestLogger.func6.1
  /home/user/workspace/github.com/ydarb/chi/middleware/logger.go:54
net/http.HandlerFunc.ServeHTTP
  /home/user/sdk/go1.21.3/src/net/http/server.go:2136
github.com/go-chi/chi/v5/middleware.RequestID.func1
  /home/user/workspace/github.com/ydarb/chi/middleware/request_id.go:76
net/http.HandlerFunc.ServeHTTP
  /home/user/sdk/go1.21.3/src/net/http/server.go:2136
github.com/go-chi/chi/v5.(*Mux).ServeHTTP
  /home/user/workspace/github.com/ydarb/chi/mux.go:90
net/http.serverHandler.ServeHTTP
  /home/user/sdk/go1.21.3/src/net/http/server.go:2938
net/http.(*conn).serve
  /home/user/sdk/go1.21.3/src/net/http/server.go:2009
created by net/http.(*Server).Serve in goroutine 1
  /home/user/sdk/go1.21.3/src/net/http/server.go:3086

level=INFO msg="request complete" ts="Thu, 19 Oct 2023 07:02:14 UTC" req_id=host.local/duevLL4tFS-000004 http_scheme=http http_proto=HTTP/1.1 http_method=GET remote_addr=127.0.0.1:51363 user_agent=curl/8.1.2 uri=http://localhost:3333/panic resp_status=500 resp_byte_length=0 resp_elapsed_ms=1.102334

/add_fields
level=INFO msg="request started" ts="Thu, 19 Oct 2023 07:01:40 UTC" req_id=host.local/duevLL4tFS-000003 http_scheme=http http_proto=HTTP/1.1 http_method=GET remote_addr=127.0.0.1:51362 user_agent=curl/8.1.2 uri=http://localhost:3333/add_fields level=INFO msg="request complete" ts="Thu, 19 Oct 2023 07:01:40 UTC" req_id=host.local/duevLL4tFS-000003 http_scheme=http http_proto=HTTP/1.1 http_method=GET remote_addr=127.0.0.1:51362 user_agent=curl/8.1.2 uri=http://localhost:3333/add_fields foo=bar bar=foo resp_status=0 resp_byte_length=0 resp_elapsed_ms=0.01025

Example JSONHandler log messages for each endpoint:

/
{"level":"INFO","msg":"request started","ts":"Thu, 19 Oct 2023 06:53:59 UTC","req_id":"host.local/bcrS9QYbWA-000001","http_scheme":"http","http_proto":"HTTP/1.1","http_method":"GET","remote_addr":"127.0.0.1:51351","user_agent":"curl/8.1.2","uri":"http://localhost:3333/"} {"level":"INFO","msg":"request complete","ts":"Thu, 19 Oct 2023 06:53:59 UTC","req_id":"host.local/bcrS9QYbWA-000001","http_scheme":"http","http_proto":"HTTP/1.1","http_method":"GET","remote_addr":"127.0.0.1:51351","user_agent":"curl/8.1.2","uri":"http://localhost:3333/","resp_status":200,"resp_byte_length":7,"resp_elapsed_ms":0.008083}
/wait
{"level":"INFO","msg":"request started","ts":"Thu, 19 Oct 2023 06:55:28 UTC","req_id":"host.local/nI9MmaOJqA-000001","http_scheme":"http","http_proto":"HTTP/1.1","http_method":"GET","remote_addr":"127.0.0.1:51354","user_agent":"curl/8.1.2","uri":"http://localhost:3333/wait"} {"level":"INFO","msg":"request complete","ts":"Thu, 19 Oct 2023 06:55:28 UTC","req_id":"host.local/nI9MmaOJqA-000001","http_scheme":"http","http_proto":"HTTP/1.1","http_method":"GET","remote_addr":"127.0.0.1:51354","user_agent":"curl/8.1.2","uri":"http://localhost:3333/wait","wait":true,"resp_status":200,"resp_byte_length":2,"resp_elapsed_ms":1001.277084}
/panic
{"level":"INFO","msg":"request started","ts":"Thu, 19 Oct 2023 06:55:59 UTC","req_id":"host.local/nI9MmaOJqA-000002","http_scheme":"http","http_proto":"HTTP/1.1","http_method":"GET","remote_addr":"127.0.0.1:51355","user_agent":"curl/8.1.2","uri":"http://localhost:3333/panic"} {"level":"ERROR","msg":"oops","ts":"Thu, 19 Oct 2023 06:55:59 UTC","req_id":"host.local/nI9MmaOJqA-000002","http_scheme":"http","http_proto":"HTTP/1.1","http_method":"GET","remote_addr":"127.0.0.1:51355","user_agent":"curl/8.1.2","uri":"http://localhost:3333/panic","stack":"goroutine 34 [running]:\nruntime/debug.Stack()\n\t/home/user/sdk/go1.21.3/src/runtime/debug/stack.go:24 +0x64\ngithub.com/go-chi/chi/v5/middleware.Recoverer.func1.1()\n\t/home/user/workspace/github.com/ydarb/chi/middleware/recoverer.go:34 +0x88\npanic({0x10519f1c0?, 0x105201430?})\n\t/home/user/sdk/go1.21.3/src/runtime/panic.go:914 +0x218\nmain.main.func3({0x1400011ad20?, 0x14000116ed0?}, 0x1050fbff3?)\n\t/home/user/workspace/github.com/ydarb/chi/_examples/logging/main.go:49 +0x2c\nnet/http.HandlerFunc.ServeHTTP(0x1051b0460?, {0x10c142958?, 0x140000b2140?}, 0x140000b4004?)\n\t/home/user/sdk/go1.21.3/src/net/http/server.go:2136 +0x38\ngithub.com/go-chi/chi/v5.(*Mux).routeHTTP(0x14000126180, {0x10c142958, 0x140000b2140}, 0x140000b0300)\n\t/home/user/workspace/github.com/ydarb/chi/mux.go:443 +0x270\nnet/http.HandlerFunc.ServeHTTP(0x140001898d8?, {0x10c142958?, 0x140000b2140?}, 0x1050f529c?)\n\t/home/user/sdk/go1.21.3/src/net/http/server.go:2136 +0x38\ngithub.com/go-chi/chi/v5/middleware.Recoverer.func1({0x10c142958?, 0x140000b2140?}, 0x14000189900?)\n\t/home/user/workspace/github.com/ydarb/chi/middleware/recoverer.go:45 +0x78\nnet/http.HandlerFunc.ServeHTTP(0x140000b0200?, {0x10c142958?, 0x140000b2140?}, 0x104eb0894?)\n\t/home/user/sdk/go1.21.3/src/net/http/server.go:2136 +0x38\nmain.main.NewStructuredLogger.RequestLogger.func6.1({0x105204680, 0x140000bc000}, 0x140000b0200)\n\t/home/user/workspace/github.com/ydarb/chi/middleware/logger.go:54 +0x120\nnet/http.HandlerFunc.ServeHTTP(0x105204d40?, {0x105204680?, 0x140000bc000?}, 0x10517b628?)\n\t/home/user/sdk/go1.21.3/src/net/http/server.go:2136 +0x38\ngithub.com/go-chi/chi/v5/middleware.RequestID.func1({0x105204680, 0x140000bc000}, 0x140000b0100)\n\t/home/user/workspace/github.com/ydarb/chi/middleware/request_id.go:76 +0x214\nnet/http.HandlerFunc.ServeHTTP(0x105204d78?, {0x105204680?, 0x140000bc000?}, 0x1053bd310?)\n\t/home/user/sdk/go1.21.3/src/net/http/server.go:2136 +0x38\ngithub.com/go-chi/chi/v5.(*Mux).ServeHTTP(0x14000126180, {0x105204680, 0x140000bc000}, 0x140000b0000)\n\t/home/user/workspace/github.com/ydarb/chi/mux.go:90 +0x2bc\nnet/http.serverHandler.ServeHTTP({0x14000092090?}, {0x105204680?, 0x140000bc000?}, 0x6?)\n\t/home/user/sdk/go1.21.3/src/net/http/server.go:2938 +0xbc\nnet/http.(*conn).serve(0x14000096000, {0x105204d40, 0x140001170b0})\n\t/home/user/sdk/go1.21.3/src/net/http/server.go:2009 +0x518\ncreated by net/http.(*Server).Serve in goroutine 1\n\t/home/user/sdk/go1.21.3/src/net/http/server.go:3086 +0x4cc\n"} {"level":"INFO","msg":"request complete","ts":"Thu, 19 Oct 2023 06:55:59 UTC","req_id":"host.local/nI9MmaOJqA-000002","http_scheme":"http","http_proto":"HTTP/1.1","http_method":"GET","remote_addr":"127.0.0.1:51355","user_agent":"curl/8.1.2","uri":"http://localhost:3333/panic","resp_status":500,"resp_byte_length":0,"resp_elapsed_ms":1.621458}
/add_fields
{"level":"INFO","msg":"request started","ts":"Thu, 19 Oct 2023 06:57:44 UTC","req_id":"host.local/nI9MmaOJqA-000003","http_scheme":"http","http_proto":"HTTP/1.1","http_method":"GET","remote_addr":"127.0.0.1:51356","user_agent":"curl/8.1.2","uri":"http://localhost:3333/add_fields"} {"level":"INFO","msg":"request complete","ts":"Thu, 19 Oct 2023 06:57:44 UTC","req_id":"host.local/nI9MmaOJqA-000003","http_scheme":"http","http_proto":"HTTP/1.1","http_method":"GET","remote_addr":"127.0.0.1:51356","user_agent":"curl/8.1.2","uri":"http://localhost:3333/add_fields","foo":"bar","bar":"foo","resp_status":0,"resp_byte_length":0,"resp_elapsed_ms":0.01525}

@ydarb
chore: Update logging example to use released version of log/slog
19398c6 
Adds bool to flip example between a TextHandler and a JSONHandler.
Update Panic() to pretty print stack trace if log handler is a
TextHandler, otherwise it will log the stack trace as a JSON value
string with a key of "stack".

Ref: go-chi#858
alexandear
alexandear reviewed Oct 19, 2023
View reviewed changes
_examples/logging/main.go
"time"

"golang.org/x/exp/slog"
"log/slog"
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This won't compile on Go 1.20 and below. Should we add a compiler directive for the file?

@pkieltyka
Copy link
Member

See go-chi/httplog#17 for a complete slog http logger PR

@pkieltyka
Copy link
Member

thanks for the PR, I will review as well here to get the example updated

@pkieltyka
Copy link
Member

Please see https://github.com/go-chi/httplog/releases/tag/v2.0.0

@pkieltyka pkieltyka closed this Oct 21, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@alexandear alexandear alexandear left review comments

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.

None yet
3 participants
@ydarb @pkieltyka @alexandear