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

Don't drop error context when adding a message to errors #1958

Merged
merged 20 commits into from
Dec 6, 2021

Conversation

asonix
Copy link
Collaborator

@asonix asonix commented Nov 24, 2021

  • Replace ApiError references with LemmyError directly
  • Instrument implementations of Perform and PerformCrud with Tracing for more context in errors
  • Instrument Feeds with Tracing
  • Instrument apub with Tracing
  • Respond to requests with LemmyError rather than turning all errors into BadRequest
  • Default LemmyError to respond with Bad Request status code
  • Stop logging new & closing spans
  • Don't pretty-print logs
  • Mark passwords, emails, jwts as "sensitive"
  • Reduce the number of logged HTTP fields
  • Update Actix Web & friends

crates/api/src/comment.rs Outdated Show resolved Hide resolved
crates/utils/src/lib.rs Outdated Show resolved Hide resolved
@dessalines
Copy link
Member

dessalines commented Nov 25, 2021

For some reason the errors aren't propagating correctly as JSON. I tried a should-fail login for the front end, and it gets a JSON parsing error, and the back end shows this:

lemmy_1     |   2021-11-25T20:40:00.200178Z ERROR lemmy_websocket::handlers: Error during message handling NotFound
lemmy_1     |    0: lemmy_api::local_user::perform
lemmy_1     |            with self=Login { username_or_email: "tnhtshnt", password: "nshthnt" }
lemmy_1     |              at crates/api/src/local_user.rs:65
lemmy_1     |     at crates/websocket/src/handlers.rs:78

@Nutomic
Copy link
Member

Nutomic commented Nov 26, 2021

Its still logging stack traces for simple info logs. Could you change that so it only logs the message for info and below, and includes the stack trace only for warn/error? Its just way too verbose this way.

2021-11-26T12:44:58.492814Z  INFO lemmy_apub::activities: Sending activity http://lemmy-alpha:8541/activities/create/14913d80-62c8-4447-a764-0f4f7874dd41
  at crates/apub/src/activities/mod.rs:168
  in lemmy_apub::activities::send_lemmy_activity
  in lemmy_apub::activities::community::send_activity_in_community
  in lemmy_apub::activities::post::create_or_update::send
  in lemmy_api_crud::post::create::perform with , self: CreatePost { name: "test", community_id: CommunityId(2), url:None, body: None, honeypot: None, nsfw: Some(false), auth: "eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOjEsImlzcyI6ImxlbW15LWFscGhhOjg1NDEiLCJpYXQiOjE2Mzc5MzA2OTF9.wqV3c35qjjHXACXzuo0pfkzH55PhN6aX46Gws-f61po" }

And HTTP request params are still logged twice. I think we could skip those completely, as params are already logged for each API call. Though for things which dont go through the API (eg RSS feeds or apub endpoints), it makes sense to log HTTP params. Not sure how complicated this would be though.

2021-11-26T12:46:40.924537Z  WARN tracing_actix_web::middleware: Error encountered while processing the incoming HTTPrequest: LemmyError { message: Some("couldnt_find_post"), inner: NotFound, context: "SpanTrace" }
  at /usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tracing-actix-web-0.5.0-beta.3/src/middleware.rs:256
  in tracing_actix_web::root_span_builder::HTTP request with , http.method: GET, http.route: /api/v3/post, http.flavor: 1.1, http.scheme: http, http.host: lemmy-alpha, http.client_ip: 172.18.0.1, http.user_agent: node-fetch/1.0 (+https://github.com/bitinn/node-fetch), http.target: /api/v3/post?id=3&auth=eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOjEsImlzcyI6ImxlbW15LWFscGhhOjg1NDEiLCJpYXQiOjE2Mzc5MzA2OTF9.wqV3c35qjjHXACXzuo0pfkzH55PhN6aX46Gws-f61po, otel.kind: "server", request_id: 7c6c1697-e662-45e8-8801-b5c58ad0367e, exception.message: couldnt_find_post: NotFound
 0: lemmy_api_crud::post::read::perform
         with self=GetPost { id: PostId(3), auth: Some("eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOjEsImlzcyI6ImxlbW15LWFscGhhOjg1NDEiLCJpYXQiOjE2Mzc5MzA2OTF9.wqV3c35qjjHXACXzuo0pfkzH55PhN6aX46Gws-f61po") }
           at crates/api_crud/src/post/read.rs:30
 1: tracing_actix_web::root_span_builder::HTTP request
         with http.method=GET http.route=/api/v3/post http.flavor=1.1 http.scheme=http http.host=lemmy-alpha http.client_ip=172.18.0.1 http.user_agent=node-fetch/1.0 (+https://github.com/bitinn/node-fetch) http.target=/api/v3/post?id=3&auth=eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOjEsImlzcyI6ImxlbW15LWFscGhhOjg1NDEiLCJpYXQiOjE2Mzc5MzA2OTF9.wqV3c35qjjHXACXzuo0pfkzH55PhN6aX46Gws-f61po otel.kind="server" request_id=7c6c1697-e662-45e8-8801-b5c58ad0367e
           at /usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tracing-actix-web-0.5.0-beta.3/src/root_span_builder.rs:40, exception.details: LemmyError { message: Some("couldnt_find_post"), inner: NotFound, context: "SpanTrace" }, http.status_code: 404, otel.status_code: "OK"

Also, some HTTP endpoints still return a stack trace on error, not sure if thats intended. Not really a problem imo but worth mentioning.

$ curl "http://lemmy-alpha:8541/feeds/c/maina.xml?sort=Active"
NotFound
0: lemmy_api_common::blocking operation
at crates/api_common/src/lib.rs:35
1: tracing_actix_web::root_span_builder::HTTP request
with http.method=GET http.route=default http.flavor=1.1 http.scheme=http http.host=lemmy-alpha:8541 http.client_ip=172.18.0.1:45020 http.user_agent=curl/7.80.0 http.target=/feeds/c/maina.xml?sort=Active otel.kind="server" request_id=33cb82cf-0c96-4050-8e72-3195f2113ca6
at /usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/tracing-actix-web-0.5.0-beta.3/src/root_span_builder.rs:40⏎ 

@dessalines dessalines merged commit 35cbae6 into main Dec 6, 2021
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.

None yet

3 participants