Event handler attempts to access invalid WASM memory region

[Jannis]

Do you want to request a feature or report a bug?

Bug

What is the current behavior?

Running the latest adChain subgraph starts fine but eventually hits a trying to access region [59160..177404] in memory [0..65536] error, suggesting that the mapping runtime is trying to reach beyond the memory available to it.

Error and stacktrace:

component: RuntimeHostBuilder
 component: RuntimeHost
  Sep 21 10:13:27.551 INFO Ethereum event received, signature: 0xa7bc…967c
  Sep 21 10:13:27.551 DEBG   Call event handler, signature: _ApplicationWhitelisted(bytes32), name: applicationWhitelist
Sep 21 10:13:27.620 CRIT Node error, location: libcore/result.rs:945, error: called `Result::unwrap()` on an `Err` value: Memory("trying to access region [59160..177404] in memory [0..65536]")
Sep 21 10:13:28.328 CRIT Backtrace, trace: stack backtrace:
   0:        0x104645da4 - backtrace::backtrace::trace::hf82aa61a611a16d1
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.9/src/backtrace/mod.rs:42
   1:        0x104640c9c - backtrace::capture::Backtrace::new_unresolved::h779053951df4648b
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.9/src/capture.rs:88
   2:        0x104640bfe - backtrace::capture::Backtrace::new::h1821685840362425
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.9/src/capture.rs:63
   3:        0x103c208e0 - graph::util::log::register_panic_hook::{{closure}}::he690bf09cf93856e
                        at graph/src/util/log.rs:38
   4:        0x104452298 - sentry::integrations::panic::register_panic_handler::{{closure}}::h1adf2a8d461cbf18
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/sentry-0.3.2/src/integrations/panic.rs:81
   5:        0x104dcd698 - std::panicking::rust_panic_with_hook::h28749c6c929f49fc
                        at libstd/panicking.rs:479
   6:        0x104dcd1ec - std::panicking::continue_panic_fmt::h2b83096170ce8c01
                        at libstd/panicking.rs:390
   7:        0x104dcd0d8 - _rust_begin_unwind
                        at libstd/panicking.rs:325
   8:        0x104e10fe1 - core::panicking::panic_fmt::h014200104cad7730
                        at libcore/panicking.rs:77
   9:        0x103b73c57 - core::result::unwrap_failed::hc28fb9aa0f917a84
                        at /Users/travis/build/rust-lang/rust/src/libcore/macros.rs:26
  10:        0x1032fe68c - <core::result::Result<T, E>>::unwrap::h7aca3cef205475b1
                        at /Users/travis/build/rust-lang/rust/src/libcore/result.rs:782
  11:        0x10334512b - <graph_runtime_wasm::asc_abi::asc_ptr::AscPtr<C>>::read_ptr::h2bcd87b477e1de50
                        at /Users/jannis/Work/graphprotocol/graph-node/runtime/wasm/src/asc_abi/asc_ptr.rs:26
  12:        0x1036a515c - graph_runtime_wasm::asc_abi::AscHeap::asc_get::h3fc702431eacedc0
                        at /Users/jannis/Work/graphprotocol/graph-node/runtime/wasm/src/asc_abi/mod.rs:57
  13:        0x1034f457a - graph_runtime_wasm::to_from::external::<impl graph_runtime_wasm::asc_abi::FromAscObj<graph_runtime_wasm::asc_abi::class::AscUnresolvedContractCall> for graph_runtime_wasm::UnresolvedContractCall>::from_asc_obj::h1d20badae0aaf512
                        at /Users/jannis/Work/graphprotocol/graph-node/runtime/wasm/src/to_from/external.rs:274
  14:        0x1036a520d - graph_runtime_wasm::asc_abi::AscHeap::asc_get::h47339da7569bc03c
                        at /Users/jannis/Work/graphprotocol/graph-node/runtime/wasm/src/asc_abi/mod.rs:57
  15:        0x1036aa0a3 - <graph_runtime_wasm::module::HostExternals<T, L, S>>::ethereum_call::hda71fd466f3c17e1
                        at /Users/jannis/Work/graphprotocol/graph-node/runtime/wasm/src/module.rs:334
  16:        0x1036a30e9 - <graph_runtime_wasm::module::HostExternals<T, L, S> as wasmi::host::Externals>::invoke_index::hec78bad94ae19319
                        at /Users/jannis/Work/graphprotocol/graph-node/runtime/wasm/src/module.rs:605
  17:        0x10360d927 - wasmi::func::FuncInstance::invoke::h09cfa87d7e9d8f6f
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmi-0.3.0/src/func.rs:153
  18:        0x103424aa2 - <wasmi::runner::Interpreter<'a, E>>::run_interpreter_loop::h3ee7cadf2a03b0cb
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmi-0.3.0/src/runner.rs:134
  19:        0x103422afe - <wasmi::runner::Interpreter<'a, E>>::start_execution::hac073c68c96f9009
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmi-0.3.0/src/runner.rs:78
  20:        0x10360d8e2 - wasmi::func::FuncInstance::invoke::h09cfa87d7e9d8f6f
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmi-0.3.0/src/func.rs:148
  21:        0x1033bab87 - wasmi::module::ModuleInstance::invoke_export::h581041670f5bdc50
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/wasmi-0.3.0/src/module.rs:627
  22:        0x1036a784b - <graph_runtime_wasm::module::WasmiModule<T, L, S>>::handle_ethereum_event::h58599053de824258
                        at /Users/jannis/Work/graphprotocol/graph-node/runtime/wasm/src/module.rs:188
  23:        0x10347494b - graph_runtime_wasm::host::RuntimeHost::subscribe_to_events::{{closure}}::h6529ab53e6dd96fb
                        at /Users/jannis/Work/graphprotocol/graph-node/runtime/wasm/src/host.rs:258
  24:        0x103475eb9 - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &'a mut F>::call_once::h04d4c8f6ff86b1b4
                        at /Users/travis/build/rust-lang/rust/src/libcore/ops/function.rs:271
  25:        0x1035e8a5d - <core::option::Option<T>>::map::h7d0a8da1c7c208e7
                        at /Users/travis/build/rust-lang/rust/src/libcore/option.rs:414
  26:        0x103597250 - <futures::stream::map::Map<S, F> as futures::stream::Stream>::poll::h003fe8d49e36adec
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/stream/map.rs:79
  27:        0x103502475 - <futures::stream::map_err::MapErr<S, F> as futures::stream::Stream>::poll::h7650f7cbe0e62b27
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/stream/map_err.rs:78
  28:        0x1036174e8 - <futures::stream::fuse::Fuse<S> as futures::stream::Stream>::poll::ha6fc95d95e487c6d
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/stream/fuse.rs:48
  29:        0x103417aaf - <futures::stream::select::Select<S1, S2> as futures::stream::Stream>::poll::hd808caa48d9bd241
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/stream/select.rs:51
  30:        0x103324d83 - <futures::stream::for_each::ForEach<S, F, U> as futures::future::Future>::poll::h305037bcb8939bf2
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/stream/for_each.rs:45
  31:        0x1036b0664 - <futures::task_impl::Spawn<T>>::poll_future_notify::{{closure}}::h81cfbc4ceec92cec
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/task_impl/mod.rs:289
  32:        0x1036b0eff - <futures::task_impl::Spawn<T>>::enter::{{closure}}::h98c56922466cc67d
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/task_impl/mod.rs:363
  33:        0x10368c208 - futures::task_impl::std::set::hdd650dc0d31c0759
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/task_impl/std/mod.rs:78
  34:        0x1036b0807 - <futures::task_impl::Spawn<T>>::enter::h5e9140981627ecbd
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/task_impl/mod.rs:363
  35:        0x1036b0211 - <futures::task_impl::Spawn<T>>::poll_future_notify::h136348bbd6bd41f7
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/task_impl/mod.rs:289
  36:        0x10368c56b - futures::task_impl::std::<impl futures::task_impl::Spawn<F>>::wait_future::{{closure}}::h3ac531846ac9a0e4
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/task_impl/std/mod.rs:243
  37:        0x10368b894 - futures::task_impl::std::ThreadNotify::with_current::{{closure}}::h6ebb04db9fe0c0f8
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/task_impl/std/mod.rs:506
  38:        0x10333168f - <std::thread::local::LocalKey<T>>::try_with::h1ea4b51ca0ad62e3
                        at /Users/travis/build/rust-lang/rust/src/libstd/thread/local.rs:294
  39:        0x1033313fc - <std::thread::local::LocalKey<T>>::with::hb9526eba1ae7d057
                        at /Users/travis/build/rust-lang/rust/src/libstd/thread/local.rs:248
  40:        0x10368b696 - futures::task_impl::std::ThreadNotify::with_current::h77bc069ab8d17b2f
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/task_impl/std/mod.rs:506
  41:        0x1036b160c - futures::task_impl::std::<impl futures::task_impl::Spawn<F>>::wait_future::h6a020776241b4245
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/task_impl/std/mod.rs:240
  42:        0x103329d64 - futures::future::Future::wait::hf3b34b134f71418d
                        at /Users/jannis/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-0.1.23/src/future/mod.rs:299
  43:        0x103475a64 - graph_runtime_wasm::host::RuntimeHost::new::{{closure}}::h93b1311c42bb5d2c
                        at /Users/jannis/Work/graphprotocol/graph-node/runtime/wasm/src/host.rs:131
  44:        0x1036292c4 - std::sys_common::backtrace::__rust_begin_short_backtrace::h0aadf6a7d7e39f24
                        at /Users/travis/build/rust-lang/rust/src/libstd/sys_common/backtrace.rs:136
  45:        0x10333e234 - std::thread::Builder::spawn::{{closure}}::{{closure}}::hdebcc1b59d4a99b2
                        at /Users/travis/build/rust-lang/rust/src/libstd/thread/mod.rs:409
  46:        0x103577964 - <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h82777b272fe10319
                        at /Users/travis/build/rust-lang/rust/src/libstd/panic.rs:313
  47:        0x1034a87c4 - std::panicking::try::do_call::h2fdb940d34880f69
                        at /Users/travis/build/rust-lang/rust/src/libstd/panicking.rs:310
  48:        0x104dd905e - ___rust_maybe_catch_panic
                        at libpanic_unwind/lib.rs:105
  49:        0x1034a86a3 - std::panicking::try::hd031058de11f75db
                        at /Users/travis/build/rust-lang/rust/src/libstd/panicking.rs:289
  50:        0x1035779b4 - std::panic::catch_unwind::h53cd3e2b27db47ac
                        at /Users/travis/build/rust-lang/rust/src/libstd/panic.rs:392
  51:        0x10333e052 - std::thread::Builder::spawn::{{closure}}::ha3da1bc16b72b278
                        at /Users/travis/build/rust-lang/rust/src/libstd/thread/mod.rs:408
  52:        0x10333e285 - <F as alloc::boxed::FnBox<A>>::call_box::hbe60c5bdbe03ab75
                        at /Users/travis/build/rust-lang/rust/src/liballoc/boxed.rs:642
  53:        0x104dcc547 - std::sys_common::thread::start_thread::hffea5e9f9f11b206
                        at libstd/sys_common/thread.rs:24
  54:        0x104db4b78 - std::sys::unix::thread::Thread::new::thread_start::hce603054d9b5b6fc
                        at libstd/sys/unix/thread.rs:90
  55:     0x7fff5152a6c0 - __pthread_body
  56:     0x7fff5152a56c - __pthread_start

What is the expected behavior?

The adChain subgraph indexes fine and does not hit the memory region error.

[leoyvens]

Couldn't reproduce locally, from looking into this I have no good theory so far. Though 118kb is a suspiciously large memory access for that mapping.

[leoyvens]

After adam reported the same on discord, it became clear that this happens when combining our current release of the cli with the node master (which I could then reproduce).

What happens is that the cli will provide the data structure in a different format than the node expects, and that's something we can't validate at all at that point so the node hapilly reads garbage. This was probably some garbage string length that caused the node to try to read more memory than it allocated.

Closing as "not a bug".

[Jannis]

So it can be reproduced? Which data structure was sent across in an invalid format?

The explanation you provide still sounds a little concerning. 😉

[leoyvens]

The AscUnresolvedContractCall gets read wrong because the CLI is sending it with the block_hash field but the node is reading without it, so the node reads random stuff.

[Jannis]

Ah, and the Graph Node code was updated since to no longer expect the block_hash, right?

[leoyvens]

exactly

[Jannis]

Got it. Just found out that the same happens when you do e.g.

let owner = msg.owner.toHex() // Converts to a string
...
entity.setAddress('owner', owner as Address) // Causes a Memory("trying to access region ... in memory [0..65536]") error