search

hyperledger-archives / iroha

Iroha - A simple, decentralized ledger
http://iroha.tech
Apache License 2.0
988 stars 297 forks source link

SEGFAULT in processTransaction #110

Closed Warchant closed 7 years ago

Warchant commented 7 years ago

Commit: 610302954414957aff29275f3d6bf984cdc1c799

I started a single iroha-main node, sent this request:

bogdan@private ~ $ curl -X POST http://127.0.0.1:1204/account/register -d '{"publicKey":"WdvM/DPabapmtA7ISbTYPywbHxk8gWu2221LzmcmAgw=","alias":"yonezu","timestamp":1482053586}'
{"message":"successful","status":200,"uuid":"1b3cafcf870b43c74f5d918a180b27c896e9f08a29b73911d402d1dae6e90b6e"}
bogdan@private ~ $

Output of iroha:

1483681475 INFO [main] process is :32173
1483681475 INFO [peer with json] load json is {
  "me":{
    "ip":"127.0.0.1",
    "name":"bogdan",
    "publicKey":"Sht5opDIxbyK+oNuEnXUs5rLbrvVgb2GjSPfqIYGFdU=",
    "privateKey":"aGIuSZRhnGfFyeoKNm/NbTylnAvRfMu3KumOEfyT2HPf36jSF22m2JXWrdCmKiDoshVqjFtZPX3WXaNuo9L8WA=="
  },
  "group":[
    {
      "ip":"127.0.0.1",
      "name":"bogdan",
      "publicKey":"Sht5opDIxbyK+oNuEnXUs5rLbrvVgb2GjSPfqIYGFdU="
    }
  ]
}

1483681475[sumeragi] +==ーーーーーーーーー==+
1483681475[sumeragi] |+-ーーーーーーーーー-+|
1483681475[sumeragi] || 　　　　　　　　　 ||
1483681475[sumeragi] || いろは合意形成機構 ||
1483681475[sumeragi] || 　　　すめらぎ　　 ||
1483681475[sumeragi] || 　　　　　　　　　 ||
1483681475[sumeragi] |+-ーーーーーーーーー-+|
1483681475[sumeragi] +==ーーーーーーーーー==+
1483681475[sumeragi] - 起動/setup
1483681475[sumeragi] - 初期設定/initialize
1483681475 INFO [sumeragi] My key is 127.0.0.1
1483681475 INFO [sumeragi] Sumeragi setted
1483681475 INFO [sumeragi] set number of validatingPeer
1483681475 INFO [sumeragi] initialize numValidatingPeers :1
1483681475 INFO [sumeragi] initialize maxFaulty :0
1483681475 INFO [sumeragi] initialize proxyTailNdx :0
1483681475 INFO [sumeragi] initialize panicCount :0
1483681475 INFO [sumeragi] initialize myPublicKey :Sht5opDIxbyK+oNuEnXUs5rLbrvVgb2GjSPfqIYGFdU=
1483681475 INFO [sumeragi] initialize is sumeragi :1
1483681475 INFO [sumeragi] initialize.....  complete!
1483681475 INFO [server] initialize server!
1483681475 INFO [server] start server!
1483681479 INFO [WorldStateRepositoryWithLeveldb] NotFound: 
1483681479 INFO [WorldStateRepositoryWithLeveldb] NotFound: 
1483681479 DEBUG [AccountRepository]  data:
1483681479 INFO [connection] start send
1483681479 INFO [connection] create client
1483681479 INFO [connection] invoke client Operation
1483681479 INFO [connection] size 0
1483681479 INFO [connection] Operation
1483681479 INFO [connection] size: 0
1483681479 INFO [connection] name: 
1483681479 INFO [connection] size: 0
1483681479 INFO [sumeragi] receive!
1483681479 INFO [sumeragi] received message! sig:[0]
1483681479 INFO [connection] response:OK
1483681644 INFO [sumeragi] processTransaction
1483681644 INFO [sumeragi] valied
1483681645 INFO [sumeragi] Add my signature...

Fails on this line: https://github.com/hyperledger/iroha/blob/master/core/consensus/sumeragi.cpp#L272 with segmentation fault.

Debugging says:

event.transaction() = Couldn't find method Event::ConsensusEvent::transaction
MizukiSonoko commented 7 years ago

I try it 

root@2bf642df44b0:/opt/iroha/build# curl -X POST http://127.0.0.1:1204/account/register -d '{"publicKey":"WdvM/DPabapmtA7ISbTYPywbHxk8gWu2221LzmcmAgw=","alias":"yonezu","timestamp":1482053586}'
{"message":"successful","status":200,"uuid":"1b3cafcf870b43c74f5d918a180b27c896e9f08a29b73911d402d1dae6e90b6e"}

But, It is hard to reproduce... I will try a little more. 

root@2bf642df44b0:~/workspace/iroha/build# ./bin/iroha-main
1483688221 INFO [main] process is :577
1483688221 INFO [peer with json] load json is {
  "me":{
    "ip":"172.17.0.2",
    "name":"iorin",
    "publicKey":"Sht5opDIxbyK+oNuEnXUs5rLbrvVgb2GjSPfqIYGFdU=",
    "privateKey":"aGIuSZRhnGfFyeoKNm/NbTylnAvRfMu3KumOEfyT2HPf36jSF22m2JXWrdCmKiDoshVqjFtZPX3WXaNuo9L8WA=="
  },
  "group":[
    {
      "ip":"172.17.0.2",
      "name":"iorin",
      "publicKey":"Sht5opDIxbyK+oNuEnXUs5rLbrvVgb2GjSPfqIYGFdU="
    }
  ]
}

1483688221[sumeragi] +==ーーーーーーーーー==+
1483688221[sumeragi] |+-ーーーーーーーーー-+|
1483688221[sumeragi] || 　　　　　　　　　 ||
1483688221[sumeragi] || いろは合意形成機構 ||
1483688221[sumeragi] || 　　　すめらぎ　　 ||
1483688221[sumeragi] || 　　　　　　　　　 ||
1483688221[sumeragi] |+-ーーーーーーーーー-+|
1483688221[sumeragi] +==ーーーーーーーーー==+
1483688221[sumeragi] - 起動/setup
1483688221[sumeragi] - 初期設定/initialize
1483688221 INFO [sumeragi] My key is 172.17.0.2
1483688221 INFO [sumeragi] Sumeragi setted
1483688221 INFO [sumeragi] set number of validatingPeer
1483688221 INFO [sumeragi] initialize numValidatingPeers :1
1483688221 INFO [sumeragi] initialize maxFaulty :0
1483688221 INFO [sumeragi] initialize proxyTailNdx :0
1483688221 INFO [sumeragi] initialize panicCount :0
1483688221 INFO [sumeragi] initialize myPublicKey :Sht5opDIxbyK+oNuEnXUs5rLbrvVgb2GjSPfqIYGFdU=
1483688221 INFO [sumeragi] initialize is sumeragi :1
1483688221 INFO [sumeragi] initialize.....  complete!
1483688221 INFO [sumeragi] =+=
1483688221 INFO [sumeragi] start main loop
1483688221 INFO [server] initialize server!
1483688221 INFO [server] start server!
1483688331 INFO [WorldStateRepositoryWithLeveldb] NotFound:
1483688331 INFO [WorldStateRepositoryWithLeveldb] NotFound:
1483688331 DEBUG [AccountRepository]  data:
1483688331 INFO [connection] start send
1483688331 INFO [connection] create client
1483688331 INFO [connection] invoke client Operation
1483688331 INFO [connection] size 0
1483688331 INFO [connection] Operation
1483688331 INFO [connection] size: 0
1483688331 INFO [connection] name:
1483688331 INFO [connection] size: 0
1483688331 INFO [sumeragi] receive!
1483688331 INFO [sumeragi] received message! sig:[0]
1483688331 DEBUG [repo::event] event::add
1483688331 DEBUG [repo::event] events size = 1
1483688331 INFO [connection] response:OK
1483688331 INFO [sumeragi] event queue not empty
1483688331 DEBUG [repo::event] events size = 1
1483688331 INFO [sumeragi] sorted 1
1483688331 INFO [sumeragi] evens order:0
1483688331 INFO [sumeragi] processTransaction
1483688331 INFO [sumeragi] valied
1483688331 INFO [sumeragi] Add my signature...
1483688331 INFO [sumeragi] hash:19b031b951308a425390d4f0cd0df57583d96fa23533ee6757e45bc4a07c62fa
1483688331 INFO [sumeragi] pub:Sht5opDIxbyK+oNuEnXUs5rLbrvVgb2GjSPfqIYGFdU=
1483688331 INFO [sumeragi] pro:aGIuSZRhnGfFyeoKNm/NbTylnAvRfMu3KumOEfyT2HPf36jSF22m2JXWrdCmKiDoshVqjFtZPX3WXaNuo9L8WA==
1483688331 INFO [sumeragi] sog:b/g6cK8NK5DF3W/i8K6DfJIunggDLzT8ErLX0VZRemtczagxMGCrPtCPd3+wcaMUmi+0qz82J7P7CGPSAtHqDw==
1483688331 INFO [sumeragi] Signature exists
1483688331[sumeragi] 0--------------------------0
1483688331[sumeragi] +~~~~~~~~~~~~~~~~~~~~~~~~~~+
1483688331[sumeragi] |Would you agree with this?|
1483688331[sumeragi] +~~~~~~~~~~~~~~~~~~~~~~~~~~+
1483688331[sumeragi] 0================================================================0
1483688331[sumeragi] 019b031b951308a425390d4f0cd0df57583d96fa23533ee6757e45bc4a07c62fa0
1483688331[sumeragi] 0================================================================0
1483688331[sumeragi] +-ー-+
1483688331[sumeragi] | 　 |
1483688331[sumeragi] |-承-|
1483688331[sumeragi] | 　 |
1483688331[sumeragi] +-＝-+
1483688331[sumeragi] ==＝==
1483688331[sumeragi] numValidSignatures:1 faulty:1
1483688331[sumeragi] +==ーー==+
1483688331[sumeragi] |+-ーー-+|
1483688331[sumeragi] || 承認 ||
1483688331[sumeragi] |+-ーー-+|
1483688331[sumeragi] +==ーー==+
1483688331[sumeragi] commit
1483688331[sumeragi] commit count:1
1483688331 DEBUG [sumeragi] key[_1483688331]
+-ーーーーーーーーーーーー-+
1483688331 DEBUG [sumeragi] tx:Add
1483688331 DEBUG [sumeragi] exec <Add<Account>>
1483688331 DEBUG [Add<Account>] save publicKey:WdvM/DPabapmtA7ISbTYPywbHxk8gWu2221LzmcmAgw= name:yonezu
1483688331 DEBUG [AccountRepository] Add publicKey:WdvM/DPabapmtA7ISbTYPywbHxk8gWu2221LzmcmAgw= alias:yonezu
1483688331 DEBUG [AccountRepository] Save key:1b3cafcf870b43c74f5d918a180b27c896e9f08a29b73911d402d1dae6e90b6e alias:yonezu
luckychess commented 7 years ago 
{
  "me":{
    "ip": "127.0.0.1",
    "name": "natori",
    "privateKey": "OD56uOAfOGQgYqy4eDpDaaZq66RsweVx/63Sr6jdCkmuTv2rSK0ny5V7SV4X2zf5MhlkcIC/xNvIhiVb8S8Azg==",
    "publicKey": "tT2rkwo/wX3dzzkFnY+vXmfCkWk6Z3nfqI/fTO+nfIs="
  },
  "group":[
    {
      "ip":"127.0.0.1",
      "name":"natori",
      "publicKey":"tT2rkwo/wX3dzzkFnY+vXmfCkWk6Z3nfqI/fTO+nfIs="
    }
  ]
}

Crashes on my machine with this sumeragi.json.

MizukiSonoko commented 7 years ago

Sorry.... I can not reproduce... 🙇 

root@2bf642df44b0:~/workspace/iroha/build# ./bin/iroha-main
1483691385 INFO [main] process is :624
1483691385 INFO [peer with json] load json is {
  "me":{
    "ip": "127.0.0.1",
    "name": "natori",
    "privateKey": "OD56uOAfOGQgYqy4eDpDaaZq66RsweVx/63Sr6jdCkmuTv2rSK0ny5V7SV4X2zf5MhlkcIC/xNvIhiVb8S8Azg==",
    "publicKey": "tT2rkwo/wX3dzzkFnY+vXmfCkWk6Z3nfqI/fTO+nfIs="
  },
  "group":[
    {
      "ip":"127.0.0.1",
      "name":"natori",
      "publicKey":"tT2rkwo/wX3dzzkFnY+vXmfCkWk6Z3nfqI/fTO+nfIs="
    }
  ]
}

1483691385[sumeragi] +==ーーーーーーーーー==+
1483691385[sumeragi] |+-ーーーーーーーーー-+|
1483691385[sumeragi] || 　　　　　　　　　 ||
1483691385[sumeragi] || いろは合意形成機構 ||
1483691385[sumeragi] || 　　　すめらぎ　　 ||
1483691385[sumeragi] || 　　　　　　　　　 ||
1483691385[sumeragi] |+-ーーーーーーーーー-+|
1483691385[sumeragi] +==ーーーーーーーーー==+
1483691385[sumeragi] - 起動/setup
1483691385[sumeragi] - 初期設定/initialize
1483691385 INFO [sumeragi] My key is 127.0.0.1
1483691385 INFO [sumeragi] Sumeragi setted
1483691385 INFO [sumeragi] set number of validatingPeer
1483691385 INFO [sumeragi] initialize numValidatingPeers :1
1483691385 INFO [sumeragi] initialize maxFaulty :0
1483691385 INFO [sumeragi] initialize proxyTailNdx :0
1483691385 INFO [sumeragi] initialize panicCount :0
1483691385 INFO [sumeragi] initialize myPublicKey :tT2rkwo/wX3dzzkFnY+vXmfCkWk6Z3nfqI/fTO+nfIs=
1483691385 INFO [sumeragi] initialize is sumeragi :1
1483691385 INFO [sumeragi] initialize.....  complete!
1483691385 INFO [sumeragi] =+=
1483691385 INFO [sumeragi] start main loop
1483691385 INFO [server] initialize server!
1483691385 INFO [server] start server!
1483691390 DEBUG [AccountRepository]  data:
)dM/DPabapmtA7ISbTYPywbHxk8gWu2221LzmcmAgwyonezu
1483691399 INFO [WorldStateRepositoryWithLeveldb] NotFound:
1483691399 INFO [WorldStateRepositoryWithLeveldb] NotFound:
1483691399 DEBUG [AccountRepository]  data:
1483691399 INFO [connection] start send
1483691399 INFO [connection] create client
1483691399 INFO [connection] invoke client Operation
1483691399 INFO [connection] size 0
1483691399 INFO [connection] Operation
1483691399 INFO [connection] size: 0
1483691399 INFO [connection] name:
1483691399 INFO [connection] size: 0
1483691399 INFO [sumeragi] receive!
1483691399 INFO [sumeragi] received message! sig:[0]
1483691399 DEBUG [repo::event] event::add
1483691399 DEBUG [repo::event] events size = 1
1483691399 INFO [sumeragi] event queue not empty
1483691399 DEBUG [repo::event] events size = 1
1483691399 INFO [sumeragi] sorted 1
1483691399 INFO [sumeragi] evens order:0
1483691399 INFO [sumeragi] processTransaction
1483691399 INFO [sumeragi] valied
1483691399 INFO [sumeragi] Add my signature...
1483691399 INFO [sumeragi] hash:fc67820391dd20564b1745340ff09b70c94f61648447c3845659e96c5db63960
1483691399 INFO [sumeragi] pub:tT2rkwo/wX3dzzkFnY+vXmfCkWk6Z3nfqI/fTO+nfIs=
1483691399 INFO [sumeragi] pro:OD56uOAfOGQgYqy4eDpDaaZq66RsweVx/63Sr6jdCkmuTv2rSK0ny5V7SV4X2zf5MhlkcIC/xNvIhiVb8S8Azg==
1483691399 INFO [connection] response:OK
1483691399 INFO [sumeragi] sog:Q7FbYUars/UckwjNkBYpqqla/81Dh/On/2xDQCcI8llRpSWGKsNDuyKKFLCnEFH+K0yKdZE5ng+mTFtrX4oICQ==
1483691399 INFO [sumeragi] Signature exists
1483691399[sumeragi] 0--------------------------0
1483691399[sumeragi] +~~~~~~~~~~~~~~~~~~~~~~~~~~+
1483691399[sumeragi] |Would you agree with this?|
1483691399[sumeragi] +~~~~~~~~~~~~~~~~~~~~~~~~~~+
1483691399[sumeragi] 0================================================================0
1483691399[sumeragi] 0fc67820391dd20564b1745340ff09b70c94f61648447c3845659e96c5db639600
1483691399[sumeragi] 0================================================================0
1483691399[sumeragi] +-ー-+
1483691399[sumeragi] | 　 |
1483691399[sumeragi] |-承-|
1483691399[sumeragi] | 　 |
1483691399[sumeragi] +-＝-+
1483691399[sumeragi] ==＝==
1483691399[sumeragi] numValidSignatures:1 faulty:1
1483691399[sumeragi] +==ーー==+
1483691399[sumeragi] |+-ーー-+|
1483691399[sumeragi] || 承認 ||
1483691399[sumeragi] |+-ーー-+|
1483691399[sumeragi] +==ーー==+
1483691399[sumeragi] commit
1483691399[sumeragi] commit count:1
1483691399 DEBUG [sumeragi] key[_1483691399]
+-ーーーーーーーーーーーー-+
1483691399 DEBUG [sumeragi] tx:Add
1483691399 DEBUG [sumeragi] exec <Add<Account>>
1483691399 DEBUG [Add<Account>] save publicKey:dM/DPabapmtA7ISbTYPywbHxk8gWu2221LzmcmA name:yonezu
1483691399 DEBUG [AccountRepository] Add publicKey:dM/DPabapmtA7ISbTYPywbHxk8gWu2221LzmcmA alias:yonezu
1483691399 DEBUG [AccountRepository] Save key:53242f456800b439238e13390409e963fa3e635ebdbe7342340d57af87f96f48 alias:yonezu
1483691403 DEBUG [AccountRepository]  data:
'dM/DPabapmtA7ISbTYPywbHxk8gWu2221LzmcmAyonezu
1483691404 DEBUG [AccountRepository]  data:
'dM/DPabapmtA7ISbTYPywbHxk8gWu2221LzmcmAyonezu
Warchant commented 7 years ago

Build docker image using ${IROHA_HOME}/docker/build.sh

I believe build process has a bug related to grpc, but I can not find it

MizukiSonoko commented 7 years ago

But I thinks above bug

Debugging says: event.transaction() = Couldn't find method Event::ConsensusEvent::transaction

So, I think I should add has_transaction() before event.transaction().

MizukiSonoko commented 7 years ago

Ok I try to it on docker image built ${IROHA_HOME}/docker/build.sh

luckychess commented 7 years ago

I did a small investigation: if comment out this piece of code in the sumeragi.cpp:

connection::receive([](const std::string& from, Event::ConsensusEvent& event){
            logger::info("sumeragi", "receive!");
            logger::info("sumeragi", "received message! sig:[" + std::to_string(event.eventsignatures_size()) +"]");

            // send processTransaction(event) as a task to processing pool
            // this returns std::future<void> object
            // (std::future).get() method locks processing until result of processTransaction will be available
            // but processTransaction returns void, so we don't have to call it and wait
            std::function<void()> &&task = std::bind(processTransaction, std::ref(event));
            pool.process(std::move(task));
        });

all works although sumeragi_test still segfaults. The problem is definitely inside grpc (or may be we work with it in a wrong way?). I reinstalled it but it did not help.