search

planetarium / Corvette

An EVM event monitoring and indexing service.
GNU Lesser General Public License v2.1
1 stars 2 forks source link

fetch error seldomly causes deno panic.... #60

Open eseiker opened 1 year ago

eseiker commented 1 year ago 
[2023-08-18 13:02:05 WARN][observer] Emit lock expired, re-publishing to emit queue, blockNumber: 17935509  logIndex: 173
[2023-08-18 13:02:05 WARN][observer] Emit lock expired, re-publishing to emit queue, blockNumber: 17935554  logIndex: 171
[2023-08-18 13:02:05 WARN][observer] Emit lock expired, re-publishing to emit queue, blockNumber: 17935571  logIndex: 99
[2023-08-18 13:02:05 DBUG][emitter] Received event message, blockNumber: 17935509  logIndex: 173  delivery tag: 0.
[2023-08-18 13:02:05 DBUG][emitter] Received event message, blockNumber: 17935554  logIndex: 171  delivery tag: 0.
[2023-08-18 13:02:05 DBUG][emitter] Received event message, blockNumber: 17935571  logIndex: 99  delivery tag: 0.
[2023-08-18 13:02:05 INFO][emitter] Queueing event for emit, blockNumber: 17935554  logIndex: 171.
[2023-08-18 13:02:05 DBUG][emitter] Acknowledging AMQP message for event, blockNumber: 17935554  logIndex: 171  delivery tag: 0.
[2023-08-18 13:02:05 INFO][emitter] Posting event destination: http://localhost:4000  blockNumber: 17935554  logIndex: 171.
[2023-08-18 13:02:05 EROR][emitter] Event emit POST request failed with an exception, blockNumber: 17935554  logIndex: 171  url: http://localhost:4000: TypeError: error sending request for url (http://localhost:4000/): error trying to connect: tcp connect error: Connection refused (os error 61)
    at async mainFetch (ext:deno_fetch/26_fetch.js:276:12)
    at async fetch (ext:deno_fetch/26_fetch.js:500:7)
    at async file:///Users/mizuki/Projects/Corvette/emitter.ts:290:34
    at async Promise.all (index 0)
    at async file:///Users/mizuki/Projects/Corvette/emitter.ts:283:36
    at async Promise.all (index 0)
    at async file:///Users/mizuki/Projects/Corvette/emitter.ts:265:22
    at async doMutex (file:///Users/mizuki/Projects/Corvette/concurrencyUtils.ts:19:16)
    at async emitEvents (file:///Users/mizuki/Projects/Corvette/emitter.ts:262:7)
[2023-08-18 13:02:05 INFO][emitter] Event post failed for some webhook URLs, will retry on next event observed or after 60s, blockNumber: 17935554  logIndex: 171  destinations: http://localhost:4000.
[2023-08-18 13:02:05 INFO][emitter] Queueing event for emit, blockNumber: 17935509  logIndex: 173.
[2023-08-18 13:02:05 INFO][emitter] Queueing event for emit, blockNumber: 17935571  logIndex: 99.
[2023-08-18 13:02:05 DBUG][emitter] Acknowledging AMQP message for event, blockNumber: 17935509  logIndex: 173  delivery tag: 0.
[2023-08-18 13:02:05 DBUG][emitter] Acknowledging AMQP message for event, blockNumber: 17935571  logIndex: 99  delivery tag: 0.
[2023-08-18 13:02:05 INFO][emitter] Retry posting event destination: http://localhost:4000  blockNumber: 17935554  logIndex: 171.
[2023-08-18 13:02:05 EROR][emitter] Event emit POST request failed with an exception, blockNumber: 17935554  logIndex: 171  url: http://localhost:4000: TypeError: error sending request for url (http://localhost:4000/): error trying to connect: tcp connect error: Connection refused (os error 61)
    at async mainFetch (ext:deno_fetch/26_fetch.js:276:12)
    at async fetch (ext:deno_fetch/26_fetch.js:500:7)
    at async file:///Users/mizuki/Projects/Corvette/emitter.ts:290:34
    at async Promise.all (index 0)
    at async file:///Users/mizuki/Projects/Corvette/emitter.ts:283:36
    at async Promise.all (index 0)
    at async file:///Users/mizuki/Projects/Corvette/emitter.ts:265:22
    at async doMutex (file:///Users/mizuki/Projects/Corvette/concurrencyUtils.ts:19:16)
    at async emitEvents (file:///Users/mizuki/Projects/Corvette/emitter.ts:262:7)

============================================================
Deno has panicked. This is a bug in Deno. Please report this
at https://github.com/denoland/deno/issues/new.
If you can reliably reproduce this panic, include the
reproduction steps and re-run with the RUST_BACKTRACE=1 env
var set and include the backtrace in your report.

Platform: macos aarch64
Version: 1.36.1
Args: ["deno", "run", "--allow-read", "--allow-write", "--allow-env", "--allow-run", "--allow-net", "--allow-ffi", "/Users/mizuki/Projects/Corvette/app.ts", "--main"]

thread '<unnamed>' panicked at 'called `Result::unwrap()` on an `Err` value: TrySendError { kind: Disconnected }', cli/napi/threadsafe_functions.rs:113:40
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

Error occurred during query execution: ConnectorError(ConnectorError { user_facing_error: None, kind: ConnectionError(Timed out during query execution.), transient: false }) at Rn.handleRequestError (file:///Users/mizuki/Projects/Corvette/generated/client/runtime/library.js:174:7499) at Rn.handleAndLogRequestError (file:///Users/mizuki/Projects/Corvette/generated/client/runtime/library.js:174:6754) at Rn.request (file:///Users/mizuki/Projects/Corvette/generated/client/runtime/library.js:174:6344) at async file:///Users/mizuki/Projects/Corvette/emitter.ts:310:13 at async Promise.all (index 0) at async file:///Users/mizuki/Projects/Corvette/emitter.ts:265:22 at async doMutex (file:///Users/mizuki/Projects/Corvette/concurrencyUtils.ts:19:16) at async emitEvents (file:///Users/mizuki/Projects/Corvette/emitter.ts:262:7)

Akamig commented 1 year ago

So I scanned other code bases reporting similar issue,

First I can safely conclude two of each bugs are seperated issue.

About the first one, "thread '<unnamed>' panicked at 'calledResult::unwrap()on anErrvalue: TrySendError { kind: Disconnected }',

In this instance, if we look at that line of threadsafe_functions.rs, that line is ominously commented as "this call should not fail", which actually failed in our case.

There was a long babble about what unbound_send() even means, but simply put it's the process of inter-thread communication, and as it try to 'unwrap' the 'unbounded_send(call)',

As far as I deduct, it expects "Err" and unwrap the actual error, but because of unsafe call_js_cb, which calls callback as it's name, possibly callback function being async function, and since await is not used before unwrap that thing, so it panics while try to unwrap some asynchronous function call instead of bubbling up it's error.

On contrary, since this caused while handling result of unbound_send(), which is inter-thread operation, so call stack couldn't be properly given because of, y'know, multi-threaded execution flow thingy.

In short, it seems bug in Deno as that log says. Damn.

Akamig commented 1 year ago

Possibly Relevant Issues: https://github.com/denoland/deno/issues/5334 https://github.com/paritytech/jsonrpsee/issues/284 https://github.com/microsoft/demikernel/issues/246

As the error message states, the unbound_send always fails because the receiver is disconnected. So we always panic here. As you can see the receiver is immediately dropped. So I don't see how this code is every supposed to not fail. Or what is the point of it since it doesn't seem to do anything?

And I personally think this is very crucial observation. It even also commented in threadsafe_functions.rs this reciever might have already dropped. So I guess this panic happends when reciever dropped before unbound_send able to do anything.

https://github.com/denoland/deno/issues/19177

Akamig commented 1 year ago

Anyway, sadly this is barely comprehensible for me, I have no single idea to mitigate this issue.

At least we know it happens when we tries to unwrap the content of fetch error, can we just ignore error temporarily and prevent that thing from getting executed?