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.

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

Initial setup for Request Logging in HTTP in the server side #2849

Merged
merged 4 commits into from
Aug 6, 2020
Merged

Initial setup for Request Logging in HTTP in the server side #2849

merged 4 commits into from
Aug 6, 2020

Conversation

yashrsharma44
Copy link
Contributor

@yashrsharma44 yashrsharma44 commented Jul 7, 2020

  • Initialised a HTTP Middleware to log all details of the request
  • Added options for enabling logging and custom level of logging based on http response status code
  • Added interface and types for the custom options in the logging middleware

Fixes #2844

Signed-off-by: Yash Sharma [email protected]

  • I added CHANGELOG entry for this change.
  • Change is not relevant to the end user.

Changes

The current logging looks like this -

level=debug name=query-0 ts=2020-07-27T08:55:01.712803436Z caller=http.go:45 protocol=http http.component=server  http.start_time="2020-07-27 14:25:01.712671672 +0530 IST m=+7.688823783" msg="started call"
level=debug name=query-0 ts=2020-07-27T08:55:01.715027845Z caller=proxy.go:295 msg="store Addr: 127.0.0.1:10901 LabelSets: [name:\"prometheus\" value:\"prom-0\" ] Mint: 0 Maxt: 9223372036854775807 queried;store Addr: 127.0.0.1:10911 LabelSets: [name:\"prometheus\" value:\"prom-1\" ] Mint: 0 Maxt: 9223372036854775807 queried;store Addr: 127.0.0.1:10921 LabelSets: [name:\"prometheus\" value:\"prom-2\" ] Mint: 0 Maxt: 9223372036854775807 queried"
level=debug name=sidecar-2 ts=2020-07-27T08:55:01.719357148Z caller=prometheus.go:259 msg="started handling ReadRequest_STREAMED_XOR_CHUNKS streamed read response."
level=debug name=sidecar-0 ts=2020-07-27T08:55:01.719529925Z caller=prometheus.go:259 msg="started handling ReadRequest_STREAMED_XOR_CHUNKS streamed read response."
level=debug name=sidecar-2 ts=2020-07-27T08:55:01.71962683Z caller=prometheus.go:335 msg="handled ReadRequest_STREAMED_XOR_CHUNKS request." frames=0 series=0
level=debug name=sidecar-0 ts=2020-07-27T08:55:01.719891905Z caller=prometheus.go:335 msg="handled ReadRequest_STREAMED_XOR_CHUNKS request." frames=0 series=0
level=debug name=sidecar-1 ts=2020-07-27T08:55:01.72048064Z caller=prometheus.go:259 msg="started handling ReadRequest_STREAMED_XOR_CHUNKS streamed read response."
level=debug name=sidecar-1 ts=2020-07-27T08:55:01.720773913Z caller=prometheus.go:335 msg="handled ReadRequest_STREAMED_XOR_CHUNKS request." frames=0 series=0
level=debug name=query-0 ts=2020-07-27T08:55:01.722059Z caller=http.go:35 protocol=http http.component=server http.method=query http.request.id=01EE7QPZAHD8BS1W2CXXQMHFYR http.code=200 http.time_ms=9.363 msg="finished call"

Verification

@yashrsharma44
Copy link
Contributor Author

yashrsharma44 commented Jul 8, 2020

TODO:
Use the query for experimenting the logging -
- [ ] Add a flag to accept the log file/stdout

  • Configure the HTTP API to use the middleware
  • Print the output and discuss whether it is acceptable

pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/interface.go Outdated Show resolved Hide resolved
pkg/logging/interface.go Outdated Show resolved Hide resolved
Copy link
Member

@kakkoyun kakkoyun left a comment

Choose a reason for hiding this comment

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

Let's use everywhere interfaces.

pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/query/api/v1.go Outdated Show resolved Hide resolved
cmd/thanos/query.go Outdated Show resolved Hide resolved
Copy link
Member

@kakkoyun kakkoyun left a comment

Choose a reason for hiding this comment

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

Going great. It'll be good to merge after certain refinements that already mentioned.

pkg/logging/response_writer.go Outdated Show resolved Hide resolved
@yashrsharma44
Copy link
Contributor Author

Currently, the request logger is configured in these components -

  • Rule
  • Query

@yashrsharma44 yashrsharma44 marked this pull request as ready for review July 21, 2020 11:50
Copy link
Member

@bwplotka bwplotka left a comment

Choose a reason for hiding this comment

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

Generally Looks good! Some comments (:

cmd/thanos/query.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/options.go Outdated Show resolved Hide resolved
pkg/query/api/v1.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/options.go Outdated Show resolved Hide resolved
Copy link
Contributor Author

@yashrsharma44 yashrsharma44 left a comment

Choose a reason for hiding this comment

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

For deciders, have tests, else skip else.

@yashrsharma44
Copy link
Contributor Author

yashrsharma44 commented Jul 27, 2020

Here is an example of grpc logging metadata -

msg:"started call"
fields:<github.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/logging_test.testDisposableFields> (length: 9)
"protocol":"grpc"
"grpc.component":"client"
"grpc.service":"grpc_middleware.testpb.TestService"
"grpc.method":"PingError"
"grpc.method_type":"unary"
"grpc.start_time":"2020-07-27T13:40:12+05:30"
"grpc.time_ms":"0.038"
"grpc.request.deadline":"2020-07-27T13:40:14+05:30"
"grpc.code":"OK"
lvl:"debug"

We would want a similar metadata from the logging of http.
Update : Added the missing metadata

Copy link
Member

@kakkoyun kakkoyun left a comment

Choose a reason for hiding this comment

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

LGTM. Just a couple of nits.

pkg/logging/http.go Outdated Show resolved Hide resolved
pkg/logging/http.go Show resolved Hide resolved
pkg/logging/options.go Outdated Show resolved Hide resolved
pkg/logging/options.go Outdated Show resolved Hide resolved
pkg/server/http/utils.go Outdated Show resolved Hide resolved
Copy link
Member

@kakkoyun kakkoyun left a comment

Choose a reason for hiding this comment

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

🥇 LGTM.
If @bwplotka doesn't have any major concerns, I'm happy to merge this as well.

@yashrsharma44
Copy link
Contributor Author

I have changed the Decider function to use ENUM based decision values. More info here - grpc-ecosystem/go-grpc-middleware#311 (review)

Copy link
Member

@kakkoyun kakkoyun left a comment

Choose a reason for hiding this comment

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

🥇

pkg/logging/http.go Outdated Show resolved Hide resolved
Copy link
Member

@bwplotka bwplotka left a comment

Choose a reason for hiding this comment

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

LGTM, just some comments/Changelog suggestions (:

CHANGELOG.md Outdated Show resolved Hide resolved
cmd/thanos/query.go Outdated Show resolved Hide resolved
pkg/logging/http.go Show resolved Hide resolved
Copy link
Member

@kakkoyun kakkoyun left a comment

Choose a reason for hiding this comment

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

Pointed out something about flag naming and the branch needs a rebase.

cmd/thanos/query.go Outdated Show resolved Hide resolved
Review changes
* Rename the logging middleware
* Renamed bunch of files

Signed-off-by: Yash Sharma <[email protected]>

Registered the request logging in query component

Signed-off-by: Yash Sharma <[email protected]>

Modified the middleware to use the go-kit levels
* Also altered the middleware API to use logging when called, rather than at time of registration

Signed-off-by: Yash Sharma <[email protected]>

Remove option to log the request details into a log file

Signed-off-by: Yash Sharma <[email protected]>

Made the logger a part of the logger middleware

Signed-off-by: Yash Sharma <[email protected]>

Added some changes to use logger implicitly

Signed-off-by: Yash Sharma <[email protected]>

Removed logging from the query UI

Signed-off-by: Yash Sharma <[email protected]>

Added Request Logging in rule component
* Removed request logging from the bucket component

Signed-off-by: Yash Sharma <[email protected]>

Fixed a bug of multiple logging
* Due to adding of contextual fields in the implicit logger.
* Now we create a copy of the implicit logger before adding the contextual fields, so that every time we get a fresh set of loggers

Signed-off-by: Yash Sharma <[email protected]>

Suggestions from reviewers
* Renamed response_writer.go to utils.go
* Moved all interfaces to option.go

Signed-off-by: Yash Sharma <[email protected]>

renamed files and added a util file for serving http utilities

Signed-off-by: Yash Sharma <[email protected]>

added copyright headers

Signed-off-by: Yash Sharma <[email protected]>

Added a changelog

Signed-off-by: Yash Sharma <[email protected]>

Added changes as suggested by reviewer
* Rename ServerMiddleware to HTTPServerMiddleware
* Add comments

Signed-off-by: Yash Sharma <[email protected]>

added protocol field and curated the start message

Signed-off-by: Yash Sharma <[email protected]>

nitpickings of request logger

Signed-off-by: Yash Sharma <[email protected]>

added some changes to request logging http

Signed-off-by: Yash Sharma <[email protected]>

nitpickings
* changed the name of package_http to utils
* made the postcall method private

Signed-off-by: Yash Sharma <[email protected]>

More Nitpickings
* Changed the level of logging from Info to Debug
* Used contextual logging as less as possible
* Return the protocol embedded in the constructor itself
* Removed the logging of the request body

Signed-off-by: Yash Sharma <[email protected]>

Added some more fields for making it compatible to grpc logging

Signed-off-by: Yash Sharma <[email protected]>

Nitpickings
* Renamed ResponseWriter with ResponseWriterWithStatus
* Remove an unused function
* nitpickings

Signed-off-by: Yash Sharma <[email protected]>

Modified the Decision function to ENUM based decider
* Currently 3 types of logging is enabled -
* NoLogCall
* LogStartAndFinishCall
* LogFinishCall

Signed-off-by: Yash Sharma <[email protected]>

changelog nits

Signed-off-by: Yash Sharma <[email protected]>

added a flag in querier

Signed-off-by: Yash Sharma <[email protected]>

nitpickings

Signed-off-by: Yash Sharma <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Request/Response Logging for HTTP/gRPC
3 participants