踩坑之chaincode無法實(shí)例化-"container exited with 0"

背景

希望在本地以可執(zhí)行文件的形式啟動(dòng)peer和orderer，方便修改和調(diào)試。編譯完成后，以ip為127.0.0.1啟動(dòng)了orderer和peer，channel創(chuàng)建，chaincode安裝都沒問題，但是到實(shí)例化這一步就卡住了。peer版本：

peer:
 Version: 1.4.3
 Commit SHA: 05da109eb
 Go version: go1.12.7
 OS/Arch: darwin/amd64
 Chaincode:
  Base Image Version: 0.4.15
  Base Docker Namespace: hyperledger
  Base Docker Label: org.hyperledger.fabric
  Docker Namespace: hyperledger

現(xiàn)象

實(shí)例化之前的步驟省略，在chaincode實(shí)例化時(shí)，命令行提示：

Error: could not assemble transaction, err proposal response was not successful, error code 500, msg chaincode registration failed: container exited with 0
實(shí)例化chaincode的CLI端

與此同時(shí)，peer端的信息如下：


實(shí)例化chaincode的peer端

使用docker ps發(fā)現(xiàn)沒有container，但是docker images可以看見chaincode鏡像已經(jīng)生成了。

查看docker容器和鏡像

解決

1.修改endorser日志級(jí)別為debug
觀察日志發(fā)現(xiàn)，報(bào)錯(cuò)為endorser，所以首先嘗試將endorser的debug打開

CORE_PEER_MSPCONFIGPATH=./crypto-config/peerOrganizations/org1.net/users/Admin@org1.net/msp CORE_PEER_LOCALMSPID="Org1MSP" ./peer1 logging setlevel endorser debug

再次嘗試實(shí)例化，日志并沒有顯示更多有價(jià)值的信息


endorser開啟debug

但是觀察錯(cuò)誤信息，其中error: container exited with 0，結(jié)合chaincode image已經(jīng)生成的事實(shí)，推測(cè)其實(shí)container應(yīng)該也生成了，或許是因?yàn)榉钦Ｍ顺霰粍h除了。。

2.日志級(jí)別全部設(shè)為debug
修改peer啟動(dòng)環(huán)境變量FABRIC_LOGGING_SPEC=DEBUG或者使用如下命令：

CORE_PEER_MSPCONFIGPATH=./crypto-config/peerOrganizations/org1.net/users/Admin@org1.net/msp CORE_PEER_LOCALMSPID="Org1MSP" ./peer1 logging setlogspec debug

再次嘗試實(shí)例化，這回果然發(fā)現(xiàn)了很多有意思的地方，我省略了日志中msp和gossip的一些無關(guān)信息。

2019-08-21 10:26:50.170 CST [protoutils] checkSignatureFromCreator -> DEBU 1f9 begin
2019-08-21 10:26:50.170 CST [msp] GetManagerForChain -> DEBU 1fa Returning existing manager for channel 'ac'
2019-08-21 10:26:50.170 CST [protoutils] checkSignatureFromCreator -> DEBU 1fb creator is &{Org1MSP caca02f0c245f1ca10575f05ce0165b470129d9aa06d11294f3cc89d2e071724}
2019-08-21 10:26:50.170 CST [protoutils] checkSignatureFromCreator -> DEBU 1fc creator is valid
2019-08-21 10:26:50.170 CST [msp.identity] Verify -> DEBU 1fd Verify: digest = 00000000  56 56 82 9b e7 4a 89 9f  ff d2 94 61 b5 b2 e6 67  |VV...J.....a...g|
00000010  6a e2 e9 c3 7f 5e fa 71  3e b8 f9 5b 25 5d cb f8  |j....^.q>..[%]..|
2019-08-21 10:26:50.170 CST [msp.identity] Verify -> DEBU 1fe Verify: sig = 00000000  30 44 02 21 00 fb e6 89  b4 6f fe 46 24 32 59 4d  |0D.!.....o.F$2YM|
00000010  f6 a1 1b 48 10 c5 f3 d2  04 c5 05 0b 02 b5 fd e3  |...H............|
00000020  8c 1e 25 2b 5b 02 1f 3e  33 61 18 b7 cf cc e7 8b  |..%+[..>3a......|
00000030  c4 70 ca be ec f6 21 4c  55 f4 b7 1d a4 61 2d f7  |.p....!LU....a-.|
00000040  d0 85 b5 7b d6 8b                                 |...{..|
2019-08-21 10:26:50.170 CST [protoutils] checkSignatureFromCreator -> DEBU 1ff exits successfully
2019-08-21 10:26:50.170 CST [protoutils] validateChaincodeProposalMessage -> DEBU 200 validateChaincodeProposalMessage starts for proposal 0xc0003d6ee0, header 0xc002b864b0
2019-08-21 10:26:50.170 CST [protoutils] validateChaincodeProposalMessage -> DEBU 201 validateChaincodeProposalMessage info: header extension references chaincode name:"lscc" 
2019-08-21 10:26:50.170 CST [endorser] preProcess -> DEBU 202 [ac][3297cca1] processing txid: 3297cca1db3d971a8c33ec77dacfb6692e53adcbeebc3564d8b716b55452b439
2019-08-21 10:26:50.170 CST [fsblkstorage] retrieveTransactionByID -> DEBU 203 retrieveTransactionByID() - txId = [3297cca1db3d971a8c33ec77dacfb6692e53adcbeebc3564d8b716b55452b439]
2019-08-21 10:26:50.170 CST [lockbasedtxmgr] NewTxSimulator -> DEBU 204 constructing new tx simulator
2019-08-21 10:26:50.170 CST [lockbasedtxmgr] newLockBasedTxSimulator -> DEBU 205 constructing new tx simulator txid = [3297cca1db3d971a8c33ec77dacfb6692e53adcbeebc3564d8b716b55452b439]
2019-08-21 10:26:50.170 CST [endorser] SimulateProposal -> DEBU 206 [ac][3297cca1] Entry chaincode: name:"lscc" 
2019-08-21 10:26:50.170 CST [endorser] callChaincode -> INFO 207 [ac][3297cca1] Entry chaincode: name:"lscc" 
2019-08-21 10:26:50.170 CST [chaincode] Execute -> DEBU 208 Entry
2019-08-21 10:26:50.178 CST [chaincode] handleMessage -> DEBU 209 [3297cca1] Fabric side handling ChaincodeMessage of type: GET_STATE in state ready
2019-08-21 10:26:50.178 CST [chaincode] HandleTransaction -> DEBU 20a [3297cca1] handling GET_STATE from chaincode
2019-08-21 10:26:50.179 CST [chaincode] HandleGetState -> DEBU 20b [3297cca1] getting state for chaincode lscc, key ex02, channel ac
2019-08-21 10:26:50.179 CST [stateleveldb] GetState -> DEBU 20c GetState(). ns=lscc, key=ex02
2019-08-21 10:26:50.179 CST [chaincode] HandleGetState -> DEBU 20d [3297cca1] No state associated with key: ex02. Sending RESPONSE with an empty payload
2019-08-21 10:26:50.179 CST [chaincode] HandleTransaction -> DEBU 20e [3297cca1] Completed GET_STATE. Sending RESPONSE
2019-08-21 10:26:50.179 CST [msp] GetManagerForChain -> DEBU 20f Returning existing manager for channel 'ac'
2019-08-21 10:26:50.179 CST [cauthdsl] func1 -> DEBU 210 0xc0025ceeb0 gate 1566354410179215000 evaluation starts
2019-08-21 10:26:50.179 CST [cauthdsl] func2 -> DEBU 211 0xc0025ceeb0 signed by 0 principal evaluation starts (used [false])
2019-08-21 10:26:50.179 CST [cauthdsl] func2 -> DEBU 212 0xc0025ceeb0 processing identity 0 with bytes of 47012a0
2019-08-21 10:26:50.179 CST [cauthdsl] func2 -> DEBU 213 0xc0025ceeb0 principal matched by identity 0
2019-08-21 10:26:50.179 CST [msp.identity] Verify -> DEBU 214 Verify: digest = 00000000  56 56 82 9b e7 4a 89 9f  ff d2 94 61 b5 b2 e6 67  |VV...J.....a...g|
00000010  6a e2 e9 c3 7f 5e fa 71  3e b8 f9 5b 25 5d cb f8  |j....^.q>..[%]..|
2019-08-21 10:26:50.179 CST [msp.identity] Verify -> DEBU 215 Verify: sig = 00000000  30 44 02 21 00 fb e6 89  b4 6f fe 46 24 32 59 4d  |0D.!.....o.F$2YM|
00000010  f6 a1 1b 48 10 c5 f3 d2  04 c5 05 0b 02 b5 fd e3  |...H............|
00000020  8c 1e 25 2b 5b 02 1f 3e  33 61 18 b7 cf cc e7 8b  |..%+[..>3a......|
00000030  c4 70 ca be ec f6 21 4c  55 f4 b7 1d a4 61 2d f7  |.p....!LU....a-.|
00000040  d0 85 b5 7b d6 8b                                 |...{..|
2019-08-21 10:26:50.179 CST [cauthdsl] func2 -> DEBU 216 0xc0025ceeb0 principal evaluation succeeds for identity 0
2019-08-21 10:26:50.179 CST [cauthdsl] func1 -> DEBU 217 0xc0025ceeb0 gate 1566354410179215000 evaluation succeeds
2019-08-21 10:26:50.179 CST [chaincode] handleMessage -> DEBU 218 [3297cca1] Fabric side handling ChaincodeMessage of type: PUT_STATE in state ready
2019-08-21 10:26:50.179 CST [chaincode] HandleTransaction -> DEBU 219 [3297cca1] handling PUT_STATE from chaincode
2019-08-21 10:26:50.179 CST [chaincode] HandleTransaction -> DEBU 21a [3297cca1] Completed PUT_STATE. Sending RESPONSE
2019-08-21 10:26:50.179 CST [lscc] putChaincodeCollectionData -> DEBU 21b No collection configuration specified
2019-08-21 10:26:50.179 CST [chaincode] handleMessage -> DEBU 21c [3297cca1] Fabric side handling ChaincodeMessage of type: COMPLETED in state ready
2019-08-21 10:26:50.180 CST [chaincode] Notify -> DEBU 21d [3297cca1] notifying Txid:3297cca1db3d971a8c33ec77dacfb6692e53adcbeebc3564d8b716b55452b439, channelID:ac
2019-08-21 10:26:50.180 CST [chaincode] Execute -> DEBU 21e Exit
2019-08-21 10:26:50.196 CST [chaincode] LaunchConfig -> DEBU 21f launchConfig: executable:"chaincode",Args:[chaincode,-peer.address=127.0.0.1:7052],Envs:[CORE_CHAINCODE_LOGGING_LEVEL=debug,CORE_CHAINCODE_LOGGING_SHIM=warning,CORE_CHAINCODE_LOGGING_FORMAT=%{color}%{time:2006-01-02 15:04:05.000 MST} [%{module}] %{shortfunc} -> %{level:.4s} %{id:03x}%{color:reset} %{message},CORE_CHAINCODE_ID_NAME=ex02:v2,CORE_PEER_TLS_ENABLED=false],Files:[]
2019-08-21 10:26:50.196 CST [chaincode] Start -> DEBU 220 start container: ex02:v2
2019-08-21 10:26:50.196 CST [chaincode] Start -> DEBU 221 start container with args: chaincode -peer.address=127.0.0.1:7052
2019-08-21 10:26:50.196 CST [chaincode] Start -> DEBU 222 start container with env:
        CORE_CHAINCODE_LOGGING_LEVEL=debug
        CORE_CHAINCODE_LOGGING_SHIM=warning
        CORE_CHAINCODE_LOGGING_FORMAT=%{color}%{time:2006-01-02 15:04:05.000 MST} [%{module}] %{shortfunc} -> %{level:.4s} %{id:03x}%{color:reset} %{message}
        CORE_CHAINCODE_ID_NAME=ex02:v2
        CORE_PEER_TLS_ENABLED=false
2019-08-21 10:26:50.196 CST [container] lockContainer -> DEBU 223 waiting for container(ex02-v2) lock
2019-08-21 10:26:50.196 CST [container] lockContainer -> DEBU 224 got container (ex02-v2) lock
2019-08-21 10:26:50.196 CST [dockercontroller] stopInternal -> DEBU 225 stopping container id=dev-peer1.org1.net-ex02-v2
2019-08-21 10:26:50.200 CST [dockercontroller] stopInternal -> DEBU 226 stop container result error="No such container: dev-peer1.org1.net-ex02-v2"
2019-08-21 10:26:50.200 CST [dockercontroller] stopInternal -> DEBU 227 killing container id=dev-peer1.org1.net-ex02-v2
2019-08-21 10:26:50.202 CST [dockercontroller] stopInternal -> DEBU 228 kill container result id=dev-peer1.org1.net-ex02-v2 error="No such container: dev-peer1.org1.net-ex02-v2"
2019-08-21 10:26:50.202 CST [dockercontroller] stopInternal -> DEBU 229 removing container id=dev-peer1.org1.net-ex02-v2
2019-08-21 10:26:50.205 CST [dockercontroller] stopInternal -> DEBU 22a remove container result id=dev-peer1.org1.net-ex02-v2 error="No such container: dev-peer1.org1.net-ex02-v2"
2019-08-21 10:26:50.205 CST [dockercontroller] createContainer -> DEBU 22b create container imageID=dev-peer1.org1.net-ex02-v2-01dbdad4fb65c8ec72d110e992de5bad1590c21cdd615da3e489e140f084ad15 containerID=dev-peer1.org1.net-ex02-v2
2019-08-21 10:26:50.205 CST [dockercontroller] getDockerHostConfig -> DEBU 22c docker container hostconfig NetworkMode: host
2019-08-21 10:26:50.357 CST [dockercontroller] createContainer -> DEBU 22d created container imageID=dev-peer1.org1.net-ex02-v2-01dbdad4fb65c8ec72d110e992de5bad1590c21cdd615da3e489e140f084ad15 containerID=dev-peer1.org1.net-ex02-v2
2019-08-21 10:26:50.682 CST [dockercontroller] Start -> DEBU 22e Started container dev-peer1.org1.net-ex02-v2
2019-08-21 10:26:50.683 CST [container] unlockContainer -> DEBU 22f container lock deleted(ex02-v2)
2019-08-21 10:26:50.683 CST [container] lockContainer -> DEBU 230 waiting for container(ex02-v2) lock
2019-08-21 10:26:50.683 CST [container] lockContainer -> DEBU 231 got container (ex02-v2) lock
2019-08-21 10:26:50.683 CST [container] unlockContainer -> DEBU 232 container lock deleted(ex02-v2)

2019-08-21 10:26:53.929 CST [chaincode] Launch -> DEBU 247 stopping due to error while launching: container exited with 0
github.com/hyperledger/fabric/core/chaincode.(*RuntimeLauncher).Launch.func1
        /Users/gnli/gopath/src/github.com/Hyperledger/fabric/core/chaincode/runtime_launcher.go:63
runtime.goexit
        /usr/local/Cellar/go/1.12.7/libexec/src/runtime/asm_amd64.s:1337
chaincode registration failed
2019-08-21 10:26:53.929 CST [container] lockContainer -> DEBU 248 waiting for container(ex02-v2) lock
2019-08-21 10:26:53.929 CST [container] lockContainer -> DEBU 249 got container (ex02-v2) lock
2019-08-21 10:26:53.929 CST [dockercontroller] stopInternal -> DEBU 24a stopping container id=dev-peer1.org1.net-ex02-v2
2019-08-21 10:26:53.932 CST [dockercontroller] stopInternal -> DEBU 24b stop container result error="Container not running: dev-peer1.org1.net-ex02-v2"
2019-08-21 10:26:53.932 CST [dockercontroller] stopInternal -> DEBU 24c killing container id=dev-peer1.org1.net-ex02-v2
2019-08-21 10:26:53.934 CST [dockercontroller] stopInternal -> DEBU 24d kill container result id=dev-peer1.org1.net-ex02-v2 error="Container not running: dev-peer1.org1.net-ex02-v2"
2019-08-21 10:26:53.934 CST [dockercontroller] stopInternal -> DEBU 24e removing container id=dev-peer1.org1.net-ex02-v2
2019-08-21 10:26:53.941 CST [dockercontroller] stopInternal -> DEBU 24f remove container result id=dev-peer1.org1.net-ex02-v2 error=null
2019-08-21 10:26:53.941 CST [container] unlockContainer -> DEBU 250 container lock deleted(ex02-v2)
2019-08-21 10:26:53.941 CST [chaincode] Launch -> DEBU 251 launch complete
2019-08-21 10:26:53.941 CST [chaincode] Deregister -> DEBU 252 deregister handler: ex02:v2
2019-08-21 10:26:53.941 CST [endorser] callChaincode -> INFO 253 [ac][3297cca1] Exit chaincode: name:"lscc"  (3771ms)
2019-08-21 10:26:53.941 CST [endorser] SimulateProposal -> ERRO 254 [ac][3297cca1] failed to invoke chaincode name:"lscc" , error: container exited with 0
github.com/hyperledger/fabric/core/chaincode.(*RuntimeLauncher).Launch.func1
        /Users/gnli/gopath/src/github.com/Hyperledger/fabric/core/chaincode/runtime_launcher.go:63
runtime.goexit
        /usr/local/Cellar/go/1.12.7/libexec/src/runtime/asm_amd64.s:1337
chaincode registration failed
2019-08-21 10:26:53.941 CST [endorser] SimulateProposal -> DEBU 255 [ac][3297cca1] Exit
2019-08-21 10:26:53.941 CST [lockbasedtxmgr] Done -> DEBU 256 Done with transaction simulation / query execution [3297cca1db3d971a8c33ec77dacfb6692e53adcbeebc3564d8b716b55452b439]
2019-08-21 10:26:53.941 CST [endorser] func1 -> DEBU 257 Exit: request from 127.0.0.1:62298
2019-08-21 10:26:53.941 CST [comm.grpc.server] 1 -> INFO 258 unary call completed grpc.service=protos.Endorser grpc.method=ProcessProposal grpc.peer_address=127.0.0.1:62298 grpc.code=OK grpc.call_duration=3.771761635s

日志中可以看到完整的過程：首先驗(yàn)證tx發(fā)起人的身份，確認(rèn)這個(gè)tx是發(fā)往channel ac的，然后開始執(zhí)行lscc，可以看到傳給chaincode的啟動(dòng)參數(shù)，其中值得注意的是-peer.address=127.0.0.1:7052；lscc不管三七二十一先把已經(jīng)存在的同名container刪掉（如果存在的話），接下來新建image并啟動(dòng)container，但是container啟動(dòng)沒有成功，就把container刪掉了（見上面日志中第DEBU 24a至DEBU 24f條），果然如此！

3.驗(yàn)證
到這里，我突然想起docker是有自己的網(wǎng)絡(luò)的，而傳給chaincode container的啟動(dòng)參數(shù)中，peer的地址是127.0.0.1，肯定是連接不上的，官方和網(wǎng)上的資料，大多數(shù)都是使用docker容器的方式部署網(wǎng)絡(luò)，綁定了域名，自然不會(huì)存在我遇到的問題。應(yīng)該是八九不離十了，照例還是需要驗(yàn)證一下，怎么驗(yàn)證呢？想辦法在peer刪除container之前將其截獲。
于是再次執(zhí)行實(shí)例化操作，盯緊了peer日志，抓好時(shí)機(jī)kill掉peer，然后我找到了container的身體。。

截獲的chaincode容器

查看chaincode容器日志，發(fā)現(xiàn)docker容器果然是無法連接peer


chaincode容器日志

4.修改peer啟動(dòng)地址
明確了原因就簡(jiǎn)單多了，通過ifconfig查看本機(jī)ip，然后指定peer address為此ip即可。

chaincode實(shí)例化成功

當(dāng)然在/etc/hosts中綁定一個(gè)域名也可以，如添加10.100.110.54 peer1.org1.net

注意更改背書策略，否則CLI發(fā)送寫tx會(huì)失敗


修改背書策略

最終結(jié)果


最終結(jié)果
最后編輯于 ：
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
【社區(qū)內(nèi)容提示】社區(qū)部分內(nèi)容疑似由AI輔助生成，瀏覽時(shí)請(qǐng)結(jié)合常識(shí)與多方信息審慎甄別。
平臺(tái)聲明：文章內(nèi)容（如有圖片或視頻亦包括在內(nèi)）由作者上傳并發(fā)布，文章內(nèi)容僅代表作者本人觀點(diǎn)，簡(jiǎn)書系信息發(fā)布平臺(tái)，僅提供信息存儲(chǔ)服務(wù)。

相關(guān)閱讀更多精彩內(nèi)容

友情鏈接更多精彩內(nèi)容