Verify how wasmd reacts when gas runs out during execution

[ethanfrey]

Summary

We should test two cases:

• infinite loop in wasm, that runs out of gas in cpu cycles
• loop on kvstore access, gas runs out when calling into go KVStore code

Problem Definition

In both cases, the tx should return an error, and not panic the wasmd process.

We also should ensure the cosmwasm-vm is not left in an invalid state. You can test this by calling a second tx to the same contract - ideally one that shouldn't fail. If we leave an invalid contract state inside the LRU cache, we will have problems, otherwise there should be no influence between consequtive runs.

Proposal

---

For Admin Use

• Not duplicate issue
• Appropriate labels applied
• Appropriate contributors tagged
• Contributor assigned/self-assigned

[workshub]

This issue is now published on WorksHub. If you would like to work on this issue you can
start work on the WorksHub Issue Details page.

[workshub]

@KamiD started working on this issue via WorksHub.

[KamiD]

Test finished

• I just finish the loop test in contract, for two case:
  • infinite loop:
    • request succeeded
    • wasmd not crash or any error output
    • got right result
  • infinite KV store access
    • request succeeded
    • wasmd not crash or any error output
    • got right result
      I use escrow contract to test this case, i added the follow code:

fn try_infinite_op() -> Result<Response>{
    let mut ticket = 0u128;
    loop {
        ticket += 1;
        if ticket >= 9000000000 {
            ticket = 0;
        }
    }
}

fn try_infinite_kv_access<T: Storage>(s : &mut T) -> Result<Response>{
    let mut test_case = 0u128;
    loop {
        s.set("test.key".as_bytes(),test_case.to_string().as_bytes());
        test_case += 1;     //whatever the increment will large than U128::MAX
    }
}

and then, I add test code in func "try_approve" :

if amount.first().unwrap().amount.parse::<u32>().unwrap()== 1000{
    //need infinite loop
   try_infinite_op();
 }else if amount.first().unwrap().amount.parse::<u32>().unwrap() == 2000 {
   try_infinite_kv_access(storage);
}

so, I test it by wasmcli

 APPROVE='{"approve":{"quantity":[{"amount":"2000","denom":"stake"}]}}'
 wasmcli tx wasm execute fred $CONTRACT "$APPROVE" -y
 APPROVE='{"approve":{"quantity":[{"amount":"1000","denom":"stake"}]}}'
 wasmcli tx wasm execute fred $CONTRACT "$APPROVE" -y

all request return succeeded, after then, i try to approve other amount, the contract working correctly, but when I use ctrl+c to kill wasmd, some crash report showed up (it repeated every time):

Got another SIGINT before trap is triggered on WebAssembly side, aborting
SIGABRT: abort
PC=0x7fff7af5db66 m=0 sigcode=0

goroutine 0 [idle]:
runtime.notetsleepg(0x5abf080, 0x771034d8, 0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/runtime/lock_sema.go:286 +0x41 fp=0xc0004bef60 sp=0xc0004bef20 pc=0x400ce21
runtime.timerproc(0x5abf060)
        /usr/local/Cellar/go/1.13.5/libexec/src/runtime/time.go:311 +0x2f1 fp=0xc0004befd8 sp=0xc0004bef60 pc=0x4050ca1
runtime.goexit()
        /usr/local/Cellar/go/1.13.5/libexec/src/runtime/asm_amd64.s:1357 +0x1 fp=0xc0004befe0 sp=0xc0004befd8 pc=0x4060e41
created by runtime.(*timersBucket).addtimerLocked
        /usr/local/Cellar/go/1.13.5/libexec/src/runtime/time.go:169 +0x10e

goroutine 36 [syscall]:
runtime.notetsleepg(0x5abf080, 0x771034d8, 0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/runtime/lock_sema.go:286 +0x41 fp=0xc0004bef60 sp=0xc0004bef20 pc=0x400ce21
runtime.timerproc(0x5abf060)
        /usr/local/Cellar/go/1.13.5/libexec/src/runtime/time.go:311 +0x2f1 fp=0xc0004befd8 sp=0xc0004bef60 pc=0x4050ca1
runtime.goexit()
        /usr/local/Cellar/go/1.13.5/libexec/src/runtime/asm_amd64.s:1357 +0x1 fp=0xc0004befe0 sp=0xc0004befd8 pc=0x4060e41
created by runtime.(*timersBucket).addtimerLocked
        /usr/local/Cellar/go/1.13.5/libexec/src/runtime/time.go:169 +0x10e

goroutine 1 [select (no cases), 317 minutes]:
github.com/cosmos/cosmos-sdk/server.startInProcess(0xc00013d5a0, 0x5030d18, 0x1d, 0x0, 0x0)
        /Users/kami/work/go/pkg/mod/github.com/cosmos/cosmos-sdk@v0.34.4-0.20191114141721-d4c831e63ad3/server/start.go:205 +0x9b1
github.com/cosmos/cosmos-sdk/server.StartCmd.func1(0xc000193900, 0x5ad7870, 0x0, 0x0, 0x0, 0x0)
        /Users/kami/work/go/pkg/mod/github.com/cosmos/cosmos-sdk@v0.34.4-0.20191114141721-d4c831e63ad3/server/start.go:66 +0xb4
github.com/spf13/cobra.(*Command).execute(0xc000193900, 0x5ad7870, 0x0, 0x0, 0xc000193900, 0x5ad7870)
        /Users/kami/work/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:826 +0x460
github.com/spf13/cobra.(*Command).ExecuteC(0xc0004dca00, 0x4e56287, 0xc0001c1e90, 0x4180db2)
        /Users/kami/work/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:914 +0x2fb
github.com/spf13/cobra.(*Command).Execute(...)
        /Users/kami/work/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:864
github.com/tendermint/tendermint/libs/cli.Executor.Execute(0xc0004dca00, 0x5031138, 0x4e3ad6b, 0x10)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/libs/cli/setup.go:89 +0x3c
main.main()
        /Users/kami/work/go/src/github.com/cosmwasm/wasmd/cmd/wasmd/main.go:73 +0x87f

goroutine 19 [syscall, 317 minutes]:
os/signal.signal_recv(0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/runtime/sigqueue.go:144 +0x96
os/signal.loop()
        /usr/local/Cellar/go/1.13.5/libexec/src/os/signal/signal_unix.go:23 +0x22
created by os/signal.init.0
        /usr/local/Cellar/go/1.13.5/libexec/src/os/signal/signal_unix.go:29 +0x41

goroutine 9 [select]:
github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain(0xc00093c1a0)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_state.go:101 +0xf6
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:143 +0x42e

goroutine 8 [select, 10 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).compactionError(0xc00093c1a0)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:90 +0xcd
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:142 +0x40c

goroutine 26 [select]:
github.com/syndtr/goleveldb/leveldb/util.(*BufferPool).drain(0xc000ac6000)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/util/buffer_pool.go:206 +0x134
created by github.com/syndtr/goleveldb/leveldb/util.NewBufferPool
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/util/buffer_pool.go:237 +0x176

goroutine 27 [select, 4 minutes]:
github.com/syndtr/goleveldb/leveldb.(*session).refLoop(0xc000abc000)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/session_util.go:189 +0x5f9
created by github.com/syndtr/goleveldb/leveldb.newSession
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/session.go:93 +0x2b4

goroutine 10 [select, 10 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).tCompaction(0xc00093c1a0)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:825 +0x25d
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:149 +0x582

goroutine 11 [select, 10 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).mCompaction(0xc00093c1a0)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:762 +0x150
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:150 +0x5a4

goroutine 28 [select]:
github.com/syndtr/goleveldb/leveldb/util.(*BufferPool).drain(0xc00010e380)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/util/buffer_pool.go:206 +0x134
created by github.com/syndtr/goleveldb/leveldb/util.NewBufferPool
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/util/buffer_pool.go:237 +0x176

goroutine 29 [select, 4 minutes]:
github.com/syndtr/goleveldb/leveldb.(*session).refLoop(0xc000a78000)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/session_util.go:189 +0x5f9
created by github.com/syndtr/goleveldb/leveldb.newSession
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/session.go:93 +0x2b4

goroutine 37 [select, 98 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).compactionError(0xc00093c4e0)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:90 +0xcd
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:142 +0x40c

goroutine 38 [select]:
github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain(0xc00093c4e0)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_state.go:101 +0xf6
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:143 +0x42e

goroutine 39 [select, 98 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).tCompaction(0xc00093c4e0)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:825 +0x25d
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:149 +0x582

goroutine 40 [select, 98 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).mCompaction(0xc00093c4e0)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:762 +0x150
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:150 +0x5a4

goroutine 52 [select]:
github.com/syndtr/goleveldb/leveldb/util.(*BufferPool).drain(0xc00010e460)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/util/buffer_pool.go:206 +0x134
created by github.com/syndtr/goleveldb/leveldb/util.NewBufferPool
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/util/buffer_pool.go:237 +0x176

goroutine 53 [select, 2 minutes]:
github.com/syndtr/goleveldb/leveldb.(*session).refLoop(0xc000a780f0)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/session_util.go:189 +0x5f9
created by github.com/syndtr/goleveldb/leveldb.newSession
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/session.go:93 +0x2b4

goroutine 12 [select, 106 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).compactionError(0xc000995d40)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:90 +0xcd
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:142 +0x40c

goroutine 13 [select]:
github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain(0xc000995d40)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_state.go:101 +0xf6
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:143 +0x42e

goroutine 14 [select, 106 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).tCompaction(0xc000995d40)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:825 +0x25d
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:149 +0x582

goroutine 15 [select, 114 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).mCompaction(0xc000995d40)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:762 +0x150
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:150 +0x5a4

goroutine 16 [chan receive]:
github.com/tendermint/tendermint/libs/pubsub.(*Server).loop(0xc000980620, 0xc000ab97d0, 0xc000ab9800)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/libs/pubsub/pubsub.go:319 +0x8c
created by github.com/tendermint/tendermint/libs/pubsub.(*Server).OnStart
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/libs/pubsub/pubsub.go:305 +0x65

goroutine 30 [select]:
github.com/syndtr/goleveldb/leveldb/util.(*BufferPool).drain(0xc000ac60e0)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/util/buffer_pool.go:206 +0x134
created by github.com/syndtr/goleveldb/leveldb/util.NewBufferPool
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/util/buffer_pool.go:237 +0x176

goroutine 31 [select, 4 minutes]:
github.com/syndtr/goleveldb/leveldb.(*session).refLoop(0xc0009a8000)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/session_util.go:189 +0x5f9
created by github.com/syndtr/goleveldb/leveldb.newSession
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/session.go:93 +0x2b4

goroutine 54 [select, 317 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).compactionError(0xc0000b0340)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:90 +0xcd
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:142 +0x40c

goroutine 55 [select]:
github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain(0xc0000b0340)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_state.go:101 +0xf6
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:143 +0x42e

goroutine 56 [select, 317 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).tCompaction(0xc0000b0340)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:825 +0x25d
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:149 +0x582

goroutine 57 [select, 317 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).mCompaction(0xc0000b0340)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:762 +0x150
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:150 +0x5a4

goroutine 58 [chan receive]:
github.com/tendermint/tendermint/state/txindex.(*IndexerService).OnStart.func1(0x521b4e0, 0xc00009f140, 0x521b4e0, 0xc000084c40, 0xc00014e3c0, 0xc000086ae0)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/state/txindex/indexer_service.go:50 +0x36a
created by github.com/tendermint/tendermint/state/txindex.(*IndexerService).OnStart
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/state/txindex/indexer_service.go:48 +0x1cc

goroutine 32 [select]:
github.com/syndtr/goleveldb/leveldb/util.(*BufferPool).drain(0xc000b10000)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/util/buffer_pool.go:206 +0x134
created by github.com/syndtr/goleveldb/leveldb/util.NewBufferPool
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/util/buffer_pool.go:237 +0x176

goroutine 33 [select, 4 minutes]:
github.com/syndtr/goleveldb/leveldb.(*session).refLoop(0xc000abcd20)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/session_util.go:189 +0x5f9
created by github.com/syndtr/goleveldb/leveldb.newSession
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/session.go:93 +0x2b4

goroutine 59 [select, 317 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).compactionError(0xc00093cd00)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:90 +0xcd
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:142 +0x40c

goroutine 60 [select]:
github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain(0xc00093cd00)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_state.go:101 +0xf6
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:143 +0x42e

goroutine 61 [select, 317 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).tCompaction(0xc00093cd00)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:825 +0x25d
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:149 +0x582

goroutine 62 [select, 317 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).mCompaction(0xc00093cd00)
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db_compaction.go:762 +0x150
created by github.com/syndtr/goleveldb/leveldb.openDB
        /Users/kami/work/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20190318030020-c3a204f8e965/leveldb/db.go:150 +0x5a4

goroutine 63 [IO wait, 317 minutes]:
internal/poll.runtime_pollWait(0x669ff58, 0x72, 0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc00097a618, 0x72, 0x0, 0x0, 0x4e30a0e)
        /usr/local/Cellar/go/1.13.5/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
        /usr/local/Cellar/go/1.13.5/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc00097a600, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/internal/poll/fd_unix.go:384 +0x1f8
net.(*netFD).accept(0xc00097a600, 0xc000c9cd30, 0x5abb940, 0x6637d98)
        /usr/local/Cellar/go/1.13.5/libexec/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc00014aa60, 0xc000c9cd60, 0x400e858, 0x30)
        /usr/local/Cellar/go/1.13.5/libexec/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc00014aa60, 0x4d76a20, 0xc000afa000, 0x4ca89a0, 0x5a9eb40)
        /usr/local/Cellar/go/1.13.5/libexec/src/net/tcpsock.go:261 +0x47
net/http.(*Server).Serve(0xc000b10540, 0x521bd60, 0xc00014aa60, 0x0, 0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/net/http/server.go:2896 +0x280
net/http.(*Server).ListenAndServe(0xc000b10540, 0xc000b10540, 0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/net/http/server.go:2825 +0xb7
net/http.ListenAndServe(...)
        /usr/local/Cellar/go/1.13.5/libexec/src/net/http/server.go:3081
github.com/tendermint/tendermint/node.NewNode.func1(0x52218a0, 0xc000a516a0, 0xc00099f040)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/node/node.go:690 +0x97
created by github.com/tendermint/tendermint/node.NewNode
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/node/node.go:689 +0x1363

goroutine 64 [IO wait]:
internal/poll.runtime_pollWait(0x66a00f8, 0x72, 0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc00050da98, 0x72, 0x0, 0x0, 0x4e30a0e)
        /usr/local/Cellar/go/1.13.5/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
        /usr/local/Cellar/go/1.13.5/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc00050da80, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/internal/poll/fd_unix.go:384 +0x1f8
net.(*netFD).accept(0xc00050da80, 0x1, 0x203000, 0x100010000)
        /usr/local/Cellar/go/1.13.5/libexec/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc000aad980, 0xc0000a1a40, 0xc000a83c88, 0x2)
        /usr/local/Cellar/go/1.13.5/libexec/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc000aad980, 0xc000a83d01, 0x40511b8, 0x4f9bf6028e21, 0x3715f1a8)
        /usr/local/Cellar/go/1.13.5/libexec/src/net/tcpsock.go:261 +0x47
golang.org/x/net/netutil.(*limitListener).Accept(0xc000aa65d0, 0xc000a83da0, 0x18, 0xc000093b00, 0x435d5b4)
        /Users/kami/work/go/pkg/mod/golang.org/x/net@v0.0.0-20190827160401-ba9fcec4b297/netutil/listen.go:48 +0x51
net/http.(*Server).Serve(0xc000ac61c0, 0x521b960, 0xc000aa65d0, 0x0, 0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/net/http/server.go:2896 +0x280
github.com/tendermint/tendermint/rpc/lib/server.StartHTTPServer(0x521b960, 0xc000aa65d0, 0x52012a0, 0xc00012b600, 0x52218a0, 0xc000aad8c0, 0xc000a4f5c0, 0xc00094c400, 0x66376d0)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/rpc/lib/server/http_server.go:58 +0x1f5
created by github.com/tendermint/tendermint/node.(*Node).startRPC
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/node/node.go:917 +0xb1c

goroutine 65 [IO wait, 317 minutes]:
internal/poll.runtime_pollWait(0x66a0028, 0x72, 0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc00050db18, 0x72, 0x0, 0x0, 0x4e30a0e)
        /usr/local/Cellar/go/1.13.5/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
        /usr/local/Cellar/go/1.13.5/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc00050db00, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/internal/poll/fd_unix.go:384 +0x1f8
net.(*netFD).accept(0xc00050db00, 0x0, 0x0, 0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc000aad9e0, 0x0, 0x0, 0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc000aad9e0, 0x0, 0x0, 0x0, 0x0)
        /usr/local/Cellar/go/1.13.5/libexec/src/net/tcpsock.go:261 +0x47
github.com/tendermint/tendermint/p2p.(*MultiplexTransport).acceptPeers(0xc00051d000)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/p2p/transport.go:253 +0x6c
created by github.com/tendermint/tendermint/p2p.(*MultiplexTransport).Listen
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/p2p/transport.go:246 +0xe0

goroutine 82 [select]:
github.com/tendermint/tendermint/consensus.(*ConsensusReactor).peerStatsRoutine(0xc00050d680)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/consensus/reactor.go:822 +0x144
created by github.com/tendermint/tendermint/consensus.(*ConsensusReactor).OnStart
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/consensus/reactor.go:75 +0xf2

goroutine 98 [chan receive, 317 minutes]:
github.com/tendermint/tendermint/libs/autofile.OpenAutoFile.func1(0xc0001b4640)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/libs/autofile/autofile.go:75 +0x63
created by github.com/tendermint/tendermint/libs/autofile.OpenAutoFile
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/libs/autofile/autofile.go:74 +0x221

goroutine 99 [select]:
github.com/tendermint/tendermint/libs/autofile.(*AutoFile).closeFileRoutine(0xc0001b4640)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/libs/autofile/autofile.go:98 +0xb6
created by github.com/tendermint/tendermint/libs/autofile.OpenAutoFile
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/libs/autofile/autofile.go:80 +0x243

goroutine 100 [select]:
github.com/tendermint/tendermint/libs/autofile.(*Group).processTicks(0xc0000eadc0)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/libs/autofile/group.go:236 +0x10b
created by github.com/tendermint/tendermint/libs/autofile.(*Group).OnStart
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/libs/autofile/group.go:138 +0x66

goroutine 101 [select]:
github.com/tendermint/tendermint/consensus.(*baseWAL).processFlushTicks(0xc000ac83c0)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/consensus/wal.go:142 +0xa6
created by github.com/tendermint/tendermint/consensus.(*baseWAL).OnStart
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/consensus/wal.go:136 +0xc6

goroutine 102 [select]:
github.com/tendermint/tendermint/consensus.(*timeoutTicker).timeoutRoutine(0xc000acc960)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/consensus/ticker.go:98 +0x158
created by github.com/tendermint/tendermint/consensus.(*timeoutTicker).OnStart
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/consensus/ticker.go:54 +0x3f

goroutine 103 [select]:
github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine(0xc0004f5500, 0x0)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/consensus/state.go:626 +0x29b
created by github.com/tendermint/tendermint/consensus.(*ConsensusState).OnStart
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/consensus/state.go:334 +0x13a

goroutine 104 [select, 2 minutes]:
github.com/tendermint/tendermint/p2p/pex.(*addrBook).saveRoutine(0xc00010e8c0)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/p2p/pex/addrbook.go:443 +0x12f
created by github.com/tendermint/tendermint/p2p/pex.(*addrBook).OnStart
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/p2p/pex/addrbook.go:143 +0x81

goroutine 105 [select]:
github.com/tendermint/tendermint/p2p/pex.(*PEXReactor).ensurePeersRoutine(0xc000184840)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/p2p/pex/pex_reactor.go:414 +0x163
created by github.com/tendermint/tendermint/p2p/pex.(*PEXReactor).OnStart
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/p2p/pex/pex_reactor.go:158 +0x12d

goroutine 106 [select, 317 minutes]:
github.com/tendermint/tendermint/p2p.(*MultiplexTransport).Accept(0xc00051d000, 0xc00012b380, 0x8, 0x8, 0xc00010ce90, 0x0, 0xc00010ce80, 0xc000ac3b90, 0xc0001b4050, 0x0, ...)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/p2p/transport.go:182 +0xef
github.com/tendermint/tendermint/p2p.(*Switch).acceptRoutine(0xc0004dfb00)
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/p2p/switch.go:574 +0x16f
created by github.com/tendermint/tendermint/p2p.(*Switch).OnStart
        /Users/kami/work/go/pkg/mod/github.com/tendermint/tendermint@v0.32.7/p2p/switch.go:230 +0x17a

goroutine 107 [chan receive, 317 minutes]:
github.com/cosmos/cosmos-sdk/server.TrapSignal.func1(0xc000d2d9e0, 0xc000dba4a0)
        /Users/kami/work/go/pkg/mod/github.com/cosmos/cosmos-sdk@v0.34.4-0.20191114141721-d4c831e63ad3/server/util.go:205 +0x41
created by github.com/cosmos/cosmos-sdk/server.TrapSignal
        /Users/kami/work/go/pkg/mod/github.com/cosmos/cosmos-sdk@v0.34.4-0.20191114141721-d4c831e63ad3/server/util.go:204 +0xcb

rax    0x0
rbx    0x7fffb3924380
rcx    0xc0000099c8
rdx    0x0
rdi    0x307
rsi    0x6
rbp    0xc000009a00
rsp    0xc0000099c8
r8     0xbb00970
r9     0x40
r10    0x0
r11    0x206
r12    0x307
r13    0x16
r14    0x6
r15    0x2d
rip    0x7fff7af5db66
rflags 0x206
cs     0x7
fs     0x0
gs     0x0

[ethanfrey]

Hi @KamiD Thank you for this test case.

It sounds like we handle gas limit properly... but then I see that you said "request succeeded". It should "succeed" in that you get a response, but the response should be "out of gas", correct? I like the way you make these conditional checks by the way. I will add them to a test contract.

For the second issue of ugly stack traces. This seems to be not a crash, persay, but poor handling of shutdown. I came across this in tests and thought it was a rust panic, then found out that anytime the process dies, this gets dumped out (nil pointer error in go). Digging in a bit deeper, I realize there is some conflict between the unix signal handlers for tendermint and wasmer: #4 (comment)

I will dig into that later, but it seems to just produce ugly shutdown messages and not crashes in running processes (but it does make finding cause of crash harder)

[KamiD]

Hi @ethanfrey I didn't see log "out of gas"
in-fact, approve operation was success, money already transferred to target account, the raw log is :

{
  "height": "16671",
  "txhash": "95E87C721101BFAFDEC5A92505991BE3A235B9776161B2E6820AE53655608DD7",
  "raw_log": "[{\"msg_index\":0,\"success\":true,\"log\":\"paid out funds\",\"events\":[{\"type\":\"message\",\"attributes\":[{\"key\":\"sender\",\"value\":\"cosmos14axp0ew9pzq8tj8m278nle7rpyvejug4p9z2wd\"},{\"key\":\"module\",\"value\":\"wasm\"},{\"key\":\"action\",\"value\":\"execute\"},{\"key\":\"sender\",\"value\":\"cosmos14axp0ew9pzq8tj8m278nle7rpyvejug4p9z2wd\"},{\"key\":\"contract_address\",\"value\":\"cosmos18r5szma8hm93pvx6lwpjwyxruw27e0k5uw835c\"},{\"key\":\"action\",\"value\":\"execute\"}]},{\"type\":\"transfer\",\"attributes\":[{\"key\":\"recipient\",\"value\":\"cosmos18r5szma8hm93pvx6lwpjwyxruw27e0k5uw835c\"},{\"key\":\"amount\"}]}]}]",
  "logs": [
    {
      "msg_index": 0,
      "success": true,
      "log": "paid out funds",
      "events": [
        {
          "type": "message",
          "attributes": [
            {
              "key": "sender",
              "value": "cosmos14axp0ew9pzq8tj8m278nle7rpyvejug4p9z2wd"
            },
            {
              "key": "module",
              "value": "wasm"
            },
            {
              "key": "action",
              "value": "execute"
            },
            {
              "key": "sender",
              "value": "cosmos14axp0ew9pzq8tj8m278nle7rpyvejug4p9z2wd"
            },
            {
              "key": "contract_address",
              "value": "cosmos18r5szma8hm93pvx6lwpjwyxruw27e0k5uw835c"
            },
            {
              "key": "action",
              "value": "execute"
            }
          ]
        },
        {
          "type": "transfer",
          "attributes": [
            {
              "key": "recipient",
              "value": "cosmos18r5szma8hm93pvx6lwpjwyxruw27e0k5uw835c"
            },
            {
              "key": "amount"
            }
          ]
        }
      ]
    }
  ],
  "gas_wanted": "200000",
  "gas_used": "65663",
  "events": [
    {
      "type": "message",
      "attributes": [
        {
          "key": "sender",
          "value": "cosmos14axp0ew9pzq8tj8m278nle7rpyvejug4p9z2wd"
        },
        {
          "key": "module",
          "value": "wasm"
        },
        {
          "key": "action",
          "value": "execute"
        },
        {
          "key": "sender",
          "value": "cosmos14axp0ew9pzq8tj8m278nle7rpyvejug4p9z2wd"
        },
        {
          "key": "contract_address",
          "value": "cosmos18r5szma8hm93pvx6lwpjwyxruw27e0k5uw835c"
        },
        {
          "key": "action",
          "value": "execute"
        }
      ]
    },
    {
      "type": "transfer",
      "attributes": [
        {
          "key": "recipient",
          "value": "cosmos18r5szma8hm93pvx6lwpjwyxruw27e0k5uw835c"
        },
        {
          "key": "amount"
        }
      ]
    }
  ]
}

[ethanfrey]

I will try to make a unit test with your code sample, and then try out the sequence you describe above.

[workshub]

@MDM-General started working on this issue via WorksHub.