cita 节点在接收到合约交易是chain微服务退出

flyq · 2020年11月05日03:39

节点运行着，突然节点服务退出了，一排查：

$ ./bin/cita top test-new-energy-chain/1
root      2058     0  0 18:43 ?        00:00:00 cita-forever
root      2086  2058  0 18:43 ?        00:00:07 cita-auth -c auth.toml
root      2065  2058  0 18:43 ?        00:00:02 cita-bft -c consensus.toml -p privkey
root      2080  2058  0 18:43 ?        00:00:02 cita-executor -c executor.toml
root      2082  2058  0 18:43 ?        00:00:05 cita-jsonrpc -c jsonrpc.toml
root      2072  2058  0 18:43 ?        00:00:14 cita-network -c network.toml

没有了chain这个微服务

2020-11-04 - 23:16:36 | core::libchain::chai - 1356  | INFO  - new chain status height 513853, hash cd4e2bee7efc080f27745a7f731decc8a4da97f6f5508b6b605d123d8d042f31
2020-11-04 - 23:16:39 | panic_hook           - 59    | ERROR - 
============================
stack backtrace:
   0:     0x7fc72b0724ed - backtrace::backtrace::trace::h427274634b26cc90
   1:     0x7fc72b0720d2 - <backtrace::capture::Backtrace as core::default::Default>::default::h094442244fd75184
   2:     0x7fc72b0713e4 - panic_hook::panic_hook::h49ebbf6f4135f29c
   3:     0x7fc72b071118 - core::ops::function::Fn::call::h4af4df279732d685
   4:     0x7fc72b52f358 - rust_panic_with_hook
                        at src/libstd/panicking.rs:482
   5:     0x7fc72af94b74 - std::panicking::begin_panic::h02f3cdf15ae90cdb
   6:     0x7fc72af753b8 - core::libchain::chain::Chain::get_rich_receipt::hef8bd138b8162c43
   7:     0x7fc72aef32b4 - cita_chain::forward::Forward::reply_request::hcaadbf09f3e93fe9
   8:     0x7fc72aef08f4 - cita_chain::forward::Forward::dispatch_msg::hd3a7f57ea5cbdef4
   9:     0x7fc72af069f4 - cita_chain::main::{{closure}}::h28fcd68681e80c23
  10:     0x7fc72af0370d - std::sys_common::backtrace::__rust_begin_short_backtrace::h1c1878ddddb2e41f
  11:     0x7fc72aed152d - std::panicking::try::do_call::h48bc8208049f9304
  12:     0x7fc72b533889 - __rust_maybe_catch_panic
                        at src/libpanic_unwind/lib.rs:87
  13:     0x7fc72af050ae - <F as alloc::boxed::FnBox<A>>::call_box::hb5ac7e1bd40f359a
  14:     0x7fc72b532c8d - call_once<(),()>
                        at /rustc/6c2484dc3c532c052f159264e970278d8b77cdc9/src/liballoc/boxed.rs:759
                         - start_thread
                        at src/libstd/sys_common/thread.rs:14
                         - thread_start
                        at src/libstd/sys/unix/thread.rs:81
  15:     0x7fc72a2516da - start_thread
  16:     0x7fc729d6288e - __clone
  17:                0x0 - <unknown>

position:
Thread <unnamed> panicked at arithmetic operation overflow, /opt/.cargo/registry/src/github.com-1ecc6299db9ec823/ethereum-types-0.4.2/src/uint.rs:32

This is a bug. Please report it at:

    https://github.com/cryptape/cita/issues/new?labels=bug&template=bug_report.md

============================

flyq · 2020年11月09日02:40

https://github.com/citahub/cita/blob/develop/cita-chain/core/src/libchain/chain.rs#L942-L1000
看log，是这个get_rich_receipt这里导致了panic

yuitta · 2020年11月09日02:31

position:
Thread <unnamed> panicked at arithmetic operation overflow, /opt/.cargo/registry/src/github.com-1ecc6299db9ec823/ethereum-types-0.4.2/src/uint.rs:32

检查下所有u256运算的结果,
我怀疑是该处

github.com

citahub/cita/blob/763c7866e6ea59ff96de085b4c72665f4e2f69ba/cita-chain/core/src/libchain/chain.rs#L974


    }
    _ => None,
};


let receipt = RichReceipt {
    transaction_hash: tx_hash,
    transaction_index: tx_index,
    block_hash,
    block_number,
    cumulative_quota_used: last_receipt.quota_used,
    quota_used: last_receipt.quota_used - prior_quota_used,
    contract_address,
    logs: last_receipt
        .logs
        .into_iter()
        .enumerate()
        .map(|(i, log)| LocalizedLog {
            log,
            block_hash,
            block_number,
            transaction_hash: tx_hash,

chenhao · 2020年11月09日02:55

请我下，接下来我们要怎么做？是合约代码的问题，还是调用合约的问题，还是cita代码的问题？

flyq · 2020年11月09日03:14

quota_used: last_receipt.quota_used - prior_quota_used
这句代码我理解为，最新交易使用掉的quota，减去上一笔交易的使用掉的quota，没理解前后笔交易的quota会有关联
不过这么理解也不对，因为其他测试链即使前后交易quota变小也没问题

环境是 centos 7.2，这个和操作系统有关系吗？

其他的可疑点是我把测试链的AQL，BQL都设置的比较大，SDK里面上链代码quota限制为一千万，链为Quota模式。

rink1969 · 2020年11月09日04:05

receipt.quota_used是一个累加值，参见： https://github.com/citahub/cita/blob/develop/cita-executor/core/src/libexecutor/block.rs#L271
所以这里取当前交易的receipt里的quota_used减去上一个交易的这个值，得到的才是查询的交易实际使用的quota值。
但是这里的值都是u256的，正常情况应该不会溢出的。
你查询的这笔交易是合约调用吗？
能提供一下这笔交易的信息吗？getTransactionByHash的结果

flyq · 2020年11月09日05:25

感谢对 quota_used 的回答，确实是这样的。

有合约交易，但是不确定是哪笔导致。因为在最后一笔交易之后，还生产了将近千把个块。

情况大概是这样的，首先链运行起来后，前端部署并调用了合约(基于js sdk)，然后一直没问题。然后用java sdk 调用合约之后，就出现以上现象，即节点1的chain这个微服务挂了。

然后重启节点，又用Java sdk 调用合约后（这次调用成功执行），过了七八个小时，节点1这个chain微服务又挂了。节点0的没问题。这段时间，没有其他交易。后续又重启节点，Java sdk调用合约之后还是容易挂。

一笔合约调用就搞挂节点的是：

$ cita-cli rpc getTransaction --hash 0xd8934bff51b456dc4a6ced5899bb5e3f3b1f6dc7693d13a533d9af6c7945d6f5 --url http://47.116.72.248:1337
{
  "id": 1,
  "jsonrpc": "2.0",
  "result": {
    "blockHash": "0x3d2ea2a564955631a930655ef91d444c15ba8c493e45fb7001ca4e0e47a81a05",
    "blockNumber": "0x7d402",
    "content": "0x0ac0011213373738383837303031343238343533373338311880ade20420e1a81f2a4440c10f190000000000000000000000003a991c9df6994871605aa244cea645bdf4034f7200000000000000000000000000000000000000000000000000000000000027103220000000000000000000000000000000000000000000000000000000000000000040024a146633856bdada0a642596141f255ffaae3f06b7b7522000000000000000000000000000000000000000000000000000000000000000011241b5a585e2b3d4389ecabf2a29432e6902edae254c741c4ccc99a689b399d89f4570b270c570a4bdeb8aca18ecc5773d9c10827534f47738de0fea22db36e4d1b600",
    "from": "0x3a991c9df6994871605aa244cea645bdf4034f72",
    "hash": "0xd8934bff51b456dc4a6ced5899bb5e3f3b1f6dc7693d13a533d9af6c7945d6f5",
    "index": "0x0"
  }
}

http://139.196.57.229/#/transaction/hash/0xd8934bff51b456dc4a6ced5899bb5e3f3b1f6dc7693d13a533d9af6c7945d6f5

rink1969 · 2020年11月09日06:07

这笔交易看起来没什么问题，交易中设置的quota确实是1000万。
现在就是只要一查这笔交易的receipt，chain就会panic吗？

yuitta · 2020年11月09日06:31

SDK 里面把quota限制改为 34255 再发一次交易看 cita-chain 会不会挂掉

chenhao · 2020年11月09日06:52

不是发起交易和查询交易立马引起panic，没有外部调用的情况下就会挂掉

rink1969 · 2020年11月09日07:41

我通过你们的浏览器拿到了合约的字节码，在我本地部署，并重试了上面的交易，没有复现这里说的问题。
你们用的cita版本是多少？

yuitta · 2020年11月09日08:00

贴一下所有节点的cita版本

flyq · 2020年11月09日08:21

$ wget https://github.com/citahub/cita/releases/download/v20.2.0/cita_secp256k1_sha3.tar.gz

flyq · 2020年11月09日08:32

嗯，有次在凌晨

rink1969 · 2020年11月09日09:31

最开始贴的panic信息里，chain微服务是panic在 get_rich_receipt 这个函数就对应rpc接口getTransactionReceipt。cita本身是不会调用这个函数的。
这个问题只要出现一次，就肯定是必现的，因为相关的数据已经写在数据库里了，应该每次查询都会panic。
你们提到的不是发起交易和查询交易立马引起panic，没有外部调用的情况下就会挂掉有可能不是你们主动调用的getTransactionReceipt，而是缓存服务或者浏览器端发起的。

前面提到的0xd8934bff51b456dc4a6ced5899bb5e3f3b1f6dc7693d13a533d9af6c7945d6f5这笔交易，我已经通过浏览器拿到相关的调用数据了，再本地复现不了。应该不是这笔交易触发的panic。

@yuitta 怀疑是否你们的节点存在软件版本不一致的情况？这个可以检查一下
另外触发panic的交易比较大的可能是Revert之类没有正常执行的交易，这种情况下可能会有quota计算不一致的情况。你们可以主动调用getTransactionReceipt试试几个可疑的交易。
另外还有一个比较粗暴的方法是，你们可以取到对应版本的源码，在这个函数里加一些调试打印，等问题复现之后可以看下到底是哪个交易触发的。

flyq · 2020年11月09日09:45

软件版本是一致的，因为在一个节点生成配置文件后copy配置+可执行文件过去的。

这个确实很有可能，因为之前测试合约的时候，他们故意测试了一些不满足require的函数调用。然后后面就偶尔会挂

flyq · 2020年11月09日09:53

我把缓存服务连接到另外一个节点，目前来看就很稳定了

rain · 2020年11月11日02:32

是否有归纳出可稳定复现问题的合约用例？

flyq · 2020年11月11日04:48

还没有，最近发现缓存服务re-birth连接到哪个节点，那个节点就挂了。

尝试 getTransactionReceipt 几笔交易，都又没问题

chenhao · 2020年11月16日03:34

仍然频繁的挂掉，cita-chain进程异常退出，相同的问题。麻烦再帮忙看下，谢谢！

2020-11-15 - 10:31:35 | panic_hook - 59 | ERROR -
============================
stack backtrace:
0: 0x7f85228d64ed - backtrace::backtrace::trace::h427274634b26cc90
1: 0x7f85228d60d2 - <backtrace::capture::Backtrace as core::default::Default>::default::h094442244fd75184
2: 0x7f85228d53e4 - panic_hook::panic_hook::h49ebbf6f4135f29c
3: 0x7f85228d5118 - core::ops::function::Fn::call::h4af4df279732d685
4: 0x7f8522d93358 - rust_panic_with_hook
at src/libstd/panicking.rs:482
5: 0x7f85227f8b74 - std::panicking::begin_panic::h02f3cdf15ae90cdb
6: 0x7f85227d93b8 - core::libchain::chain::Chain::get_rich_receipt::hef8bd138b8162c43
7: 0x7f85227572b4 - cita_chain::forward::Forward::reply_request::hcaadbf09f3e93fe9
8: 0x7f85227548f4 - cita_chain::forward::Forward::dispatch_msg::hd3a7f57ea5cbdef4
9: 0x7f852276a9f4 - cita_chain::main::{{closure}}::h28fcd68681e80c23
10: 0x7f852276770d - std::sys_common::backtrace::__rust_begin_short_backtrace::h1c1878ddddb2e41f
11: 0x7f852273552d - std::panicking::try::do_call::h48bc8208049f9304
12: 0x7f8522d97889 - __rust_maybe_catch_panic
at src/libpanic_unwind/lib.rs:87
13: 0x7f85227690ae - <F as alloc::boxed::FnBox>::call_box::hb5ac7e1bd40f359a
14: 0x7f8522d96c8d - call_once<(),()>
at /rustc/6c2484dc3c532c052f159264e970278d8b77cdc9/src/liballoc/boxed.rs:759
- start_thread
at src/libstd/sys_common/thread.rs:14
- thread_start
at src/libstd/sys/unix/thread.rs:81
15: 0x7f8521ab56da - start_thread
16: 0x7f85215c688e - __clone
17: 0x0 -

position:
Thread panicked at arithmetic operation overflow, /opt/.cargo/registry/src/github.com-1ecc6299db9ec823/ethereum-types-0.4.2/src/uint.rs:32

This is a bug. Please report it at:
https://github.com/cryptape/cita/issues/new?labels=bug&template=bug_report.md
============================