lemmy icon indicating copy to clipboard operation
lemmy copied to clipboard
verified publisher icon LemmyNet

Repeated deadlock detected warning in lemmy backend log after 0.18.0 update

Open slash-zero opened this issue 2 years ago • 9 comments

Requirements

  • [X] Is this a bug report? For questions or discussions use https://lemmy.ml/c/lemmy_support
  • [X] Did you check to see if this issue already exists?
  • [X] Is this only a single bug? Do not put multiple bugs in one issue.
  • [X] Is this a backend issue? Use the lemmy-ui repo for UI / frontend issues.

Summary

WARN Error encountered while processing the incoming HTTP request: lemmy_server::root_span_builder: deadlock detected

Steps to Reproduce

  1. Update to lemmy 0.18.0 and start services
  2. Watch lemmy backend log

Technical Details

The following WARNing message repeats in the lemmy backend logs.

2023-06-24T02:30:03.438065Z  WARN Error encountered while processing the incoming HTTP request: lemmy_server::root_span_builder: deadlock detected
   0: lemmy_apub::objects::comment::from_json
             at crates/apub/src/objects/comment.rs:155
   1: lemmy_apub::fetcher::post_or_comment::from_json
             at crates/apub/src/fetcher/post_or_comment.rs:80
   2: lemmy_apub::activities::voting::vote::verify
             at crates/apub/src/activities/voting/vote.rs:57
   3: lemmy_apub::activities::community::announce::receive
             at crates/apub/src/activities/community/announce.rs:141
   4: lemmy_server::root_span_builder::HTTP request
           with http.method=POST http.scheme="http" http.host=SITE_URL_REDACTED http.target=/inbox otel.kind="server" request_id=a763a55c-277a-4393-9de7-884e9d5bce12 http.status_code=400 otel.status_code="OK"
             at src/root_span_builder.rs:16
LemmyError { message: None, inner: deadlock detected, context: SpanTrace [{ target: "lemmy_apub::objects::comment", name: "from_json", file: "crates/apub/src/objects/comment.rs", line: 155 }, { target: "lemmy_apub::fetcher::post_or_comment", name: "from_json", file: "crates/apub/src/fetcher/post_or_comment.rs", line: 80 }, { target: "lemmy_apub::activities::voting::vote", name: "verify", file: "crates/apub/src/activities/voting/vote.rs", line: 57 }, { target: "lemmy_apub::activities::community::announce", name: "receive", file: "crates/apub/src/activities/community/announce.rs", line: 141 }, { target: "lemmy_server::root_span_builder", name: "HTTP request", fields: "\u{1b}[3mhttp.method\u{1b}[0m\u{1b}[2m=\u{1b}[0mPOST \u{1b}[3mhttp.scheme\u{1b}[0m\u{1b}[2m=\u{1b}[0m\"http\" \u{1b}[3mhttp.host\u{1b}[0m\u{1b}[2m=\u{1b}[0mSITE_URL_REDACTED \u{1b}[3mhttp.target\u{1b}[0m\u{1b}[2m=\u{1b}[0m/inbox \u{1b}[3motel.kind\u{1b}[0m\u{1b}[2m=\u{1b}[0m\"server\" \u{1b}[3mrequest_id\u{1b}[0m\u{1b}[2m=\u{1b}[0ma763a55c-277a-4393-9de7-884e9d5bce12 \u{1b}[3mhttp.status_code\u{1b}[0m\u{1b}[2m=\u{1b}[0m400 \u{1b}[3motel.status_code\u{1b}[0m\u{1b}[2m=\u{1b}[0m\"OK\"", file: "src/root_span_builder.rs", line: 16 }] }

Version

0.18.0

Lemmy Instance URL

No response

slash-zero avatar Jun 24 '23 02:06 slash-zero

There are many other errors as well:

2023-06-24T02:56:56.035219Z  WARN Error encountered while processing the incoming HTTP request: lemmy_server::root_span_builder: Other errors which are not explicitly handled
   0: lemmy_server::root_span_builder::HTTP request
           with http.method=POST http.scheme="http" http.host=SERVER_URL_REDACTED http.target=/inbox otel.kind="server" request_id=a5625ea7-998f-47f8-b956-93ca932e5d37 http.status_code=400 otel.status_code="OK"
             at src/root_span_builder.rs:16
LemmyError { message: None, inner: Other errors which are not explicitly handled

Caused by:
    Http Signature is expired, checked Date header, checked at Sat, 24 Jun 2023 02:56:56 GMT, expired at Sat, 24 Jun 2023 02:56:03 GMT, context: SpanTrace [{ target: "lemmy_server::root_span_builder", name: "HTTP request", fields: "\u{1b}[3mhttp.method\u{1b}[0m\u{1b}[2m=\u{1b}[0mPOST \u{1b}[3mhttp.scheme\u{1b}[0m\u{1b}[2m=\u{1b}[0m\"http\" \u{1b}[3mhttp.host\u{1b}[0m\u{1b}[2m=\u{1b}[0mSERVER_URL_REDACTED  \u{1b}[3mhttp.target\u{1b}[0m\u{1b}[2m=\u{1b}[0m/inbox \u{1b}[3motel.kind\u{1b}[0m\u{1b}[2m=\u{1b}[0m\"server\" \u{1b}[3mrequest_id\u{1b}[0m\u{1b}[2m=\u{1b}[0ma5625ea7-998f-47f8-b956-93ca932e5d37 \u{1b}[3mhttp.status_code\u{1b}[0m\u{1b}[2m=\u{1b}[0m400 \u{1b}[3motel.status_code\u{1b}[0m\u{1b}[2m=\u{1b}[0m\"OK\"", file: "src/root_span_builder.rs", line: 16 }] }

2023-06-24T02:58:46.048069Z  WARN Error encountered while processing the incoming HTTP request: lemmy_server::root_span_builder: Request error: error sending request for url (http://pictrs:8080/image/process.webp?src=c80c77d6-3cc7-4b1c-9d6b-42d1a874331c.webp&thumbnail=96): error trying to connect: dns error: failed to lookup address information: Try again
Reqwest(reqwest::Error { kind: Request, url: Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("pictrs")), port: Some(8080), path: "/image/process.webp", query: Some("src=c80c77d6-3cc7-4b1c-9d6b-42d1a874331c.webp&thumbnail=96"), fragment: None }, source: hyper::Error(Connect, ConnectError("dns error", Custom { kind: Uncategorized, error: "failed to lookup address information: Try again" })) })

slash-zero avatar Jun 24 '23 02:06 slash-zero

Duplicate of #3076

sunaurus avatar Jun 24 '23 11:06 sunaurus

file: "crates/apub/src/fetcher/post_or_comment.rs", line: 80

Seems like a federation (Active Pub, "apub") peer to peer server failure to me. As in #3101 where comments (post_or_comment.rs) aren't making it to peers.

RocketDerp avatar Jun 25 '23 00:06 RocketDerp

There are some variants of this error as well:

2023-06-24T02:56:56.035219Z  WARN Error encountered while processing the incoming HTTP request: lemmy_server::root_span_builder: Other errors which are not explicitly handled
   0: lemmy_server::root_span_builder::HTTP request
           with http.method=POST http.scheme="http" http.host=hakbox.social http.target=/inbox otel.kind="server" request_id=a5625ea7-998f-47f8-b956-93ca932e5d37 http.status_code=400 otel.status_code="OK"
             at src/root_span_builder.rs:16
LemmyError { message: None, inner: Other errors which are not explicitly handled

Caused by:
    Http Signature is expired, checked Date header, checked at Sat, 24 Jun 2023 02:56:56 GMT, expired at Sat, 24 Jun 2023 02:56:03 GMT, context: SpanTrace [{ target: "lemmy_server::root_span_builder", name: "HTTP request", fields: "\u{1b}[3mhttp.method\u{1b}[0m\u{1b}[2m=\u{1b}[0mPOST \u{1b}[3mhttp.scheme\u{1b}[0m\u{1b}[2m=\u{1b}[0m\"http\" \u{1b}[3mhttp.host\u{1b}[0m\u{1b}[2m=\u{1b}[0mhakbox.social \u{1b}[3mhttp.target\u{1b}[0m\u{1b}[2m=\u{1b}[0m/inbox \u{1b}[3motel.kind\u{1b}[0m\u{1b}[2m=\u{1b}[0m\"server\" \u{1b}[3mrequest_id\u{1b}[0m\u{1b}[2m=\u{1b}[0ma5625ea7-998f-47f8-b956-93ca932e5d37 \u{1b}[3mhttp.status_code\u{1b}[0m\u{1b}[2m=\u{1b}[0m400 \u{1b}[3motel.status_code\u{1b}[0m\u{1b}[2m=\u{1b}[0m\"OK\"", file: "src/root_span_builder.rs", line: 16 }] }

2023-06-24T02:58:46.048069Z  WARN Error encountered while processing the incoming HTTP request: lemmy_server::root_span_builder: Request error: error sending request for url (http://pictrs:8080/image/process.webp?src=c80c77d6-3cc7-4b1c-9d6b-42d1a874331c.webp&thumbnail=96): error trying to connect: dns error: failed to lookup address information: Try again
Reqwest(reqwest::Error { kind: Request, url: Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("pictrs")), port: Some(8080), path: "/image/process.webp", query: Some("src=c80c77d6-3cc7-4b1c-9d6b-42d1a874331c.webp&thumbnail=96"), fragment: None }, source: hyper::Error(Connect, ConnectError("dns error", Custom { kind: Uncategorized, error: "failed to lookup address information: Try again" })) })

I'm getting this error. Lemmy-ui displays nothing but a server error message. My instance is running with docker.

desigi avatar Jun 25 '23 00:06 desigi

Http Signature is expired

I opened an issue about a similar problem in my server, a parameter was changed in 0.18.0

https://github.com/LemmyNet/activitypub-federation-rust/issues/46

checked at Sat, 24 Jun 2023 02:56:56 GMT, expired at Sat, 24 Jun 2023 02:56:03 GMT

But now we are into signatures having short-lived timeouts. Missed by 53 seconds on that one!

I'm seeing problems on every major Lemmy server (with lots of data in the database), what I'm not seeing is the big guys giving error reports. Thank you for sharing yours.

RocketDerp avatar Jun 25 '23 00:06 RocketDerp

Short term you can set the site’s image icon to null directly in the database and your site will load again.

slash-zero avatar Jun 25 '23 01:06 slash-zero

This issue is really difficult to read, as there are several different and unrelated errors reported here 😅. I will try to summarize:

  1. The deadlock error reported in the original issue is a duplicate of #3076 (and seems to be fixed according to my testing in #3175)
  2. The second issue about HTTP signatures being expired is a duplicate of https://github.com/LemmyNet/activitypub-federation-rust/issues/46 (as mentioned by @RocketDerp)
  3. The third error about pictrs not being accessible is a docker DNS resolution issue, which is a duplicate of https://github.com/LemmyNet/lemmy-ansible/issues/96

TL;DR: This report contains 3 duplicate reports, all of which already have PRs with fixes. I realize you're just trying to get help with your problems, but: the issue tracker is not a support forum, and creating combined issues for your particular problems is not super productive.

sunaurus avatar Jun 25 '23 12:06 sunaurus

For some reason, the Lemmy community leadership seems to not like using several different communities in Lemmy to organize a support forum. Reddit is more active as a Lemmy support forum than Lemmy.

I've been reporting nginx 500 errors to lemmy.ml meta community for weeks that were ignored and never have any of the big Lemmy server operators opened Github issues about the massive "blue screen of death" level of faults in code that causes a nginx 500 error on the website.

Where are their server logs?! These big servers are making the whole project a disaster by not sharing their application logs and organizing support forums on Lemmy.

GitHub can host discussions if they won't bother to actually link Lemmy postings here.

RocketDerp avatar Jun 25 '23 12:06 RocketDerp

Is there going to be an official hot fix release for any of these issues?

I see folks manually implementing fixes on their instances, but would rather install an official 0.18.1 build.

slash-zero avatar Jun 25 '23 12:06 slash-zero