踩坑之chaincode无法实例化-"container exited with 0"

背景

希望在本地以可执行文件的形式启动peer和orderer，方便修改和调试。编译完成后，以ip为127.0.0.1启动了orderer和peer，channel创建，chaincode安装都没问题，但是到实例化这一步就卡住了。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

现象

实例化之前的步骤省略，在chaincode实例化时，命令行提示：

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

与此同时，peer端的信息如下：


实例化chaincode的peer端

使用docker ps发现没有container，但是docker images可以看见chaincode镜像已经生成了。

查看docker容器和镜像

解决

1.修改endorser日志级别为debug
观察日志发现，报错为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

再次尝试实例化，日志并没有显示更多有价值的信息


endorser开启debug

但是观察错误信息，其中error: container exited with 0，结合chaincode image已经生成的事实，推测其实container应该也生成了，或许是因为非正常退出被删除了。。

2.日志级别全部设为debug
修改peer启动环境变量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

再次尝试实例化，这回果然发现了很多有意思的地方，我省略了日志中msp和gossip的一些无关信息。

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

日志中可以看到完整的过程：首先验证tx发起人的身份，确认这个tx是发往channel ac的，然后开始执行lscc，可以看到传给chaincode的启动参数，其中值得注意的是-peer.address=127.0.0.1:7052；lscc不管三七二十一先把已经存在的同名container删掉（如果存在的话），接下来新建image并启动container，但是container启动没有成功，就把container删掉了（见上面日志中第DEBU 24a至DEBU 24f条），果然如此！

3.验证
到这里，我突然想起docker是有自己的网络的，而传给chaincode container的启动参数中，peer的地址是127.0.0.1，肯定是连接不上的，官方和网上的资料，大多数都是使用docker容器的方式部署网络，绑定了域名，自然不会存在我遇到的问题。应该是八九不离十了，照例还是需要验证一下，怎么验证呢？想办法在peer删除container之前将其截获。
于是再次执行实例化操作，盯紧了peer日志，抓好时机kill掉peer，然后我找到了container的身体。。

截获的chaincode容器

查看chaincode容器日志，发现docker容器果然是无法连接peer


chaincode容器日志

4.修改peer启动地址
明确了原因就简单多了，通过ifconfig查看本机ip，然后指定peer address为此ip即可。

chaincode实例化成功

当然在/etc/hosts中绑定一个域名也可以，如添加10.100.110.54 peer1.org1.net

注意更改背书策略，否则CLI发送写tx会失败


修改背书策略

最终结果


最终结果
最后编辑于 ：
©著作权归作者所有,转载或内容合作请联系作者
  • 人面猴
    序言：七十年代末，一起剥皮案震惊了整个滨河市，随后出现的几起案子，更是在滨河造成了极大的恐慌，老刑警刘岩，带你破解...
    沈念sama阅读 215,723评论 6赞 498
  • 死咒
    序言：滨河连续发生了三起死亡事件，死亡现场离奇诡异，居然都是意外死亡，警方通过查阅死者的电脑和手机，发现死者居然都...
    沈念sama阅读 92,003评论 3赞 391
  • 救了他两次的神仙让他今天三更去死
    文/潘晓璐 我一进店门，熙熙楼的掌柜王于贵愁眉苦脸地迎上来，“玉大人，你说我怎么就摊上这事。” “怎么了？”我有些...
    开封第一讲书人阅读 161,512评论 0赞 351
  • 道士缉凶录：失踪的卖姜人
    文/不坏的土叔 我叫张陵，是天一观的道长。 经常有香客问我，道长，这世上最难降的妖魔是什么？ 我笑而不...
    开封第一讲书人阅读 57,825评论 1赞 290
  • 港岛之恋（遗憾婚礼）
    正文 为了忘掉前任，我火速办了婚礼，结果婚礼上，老公的妹妹穿的比我还像新娘。我一直安慰自己，他们只是感情好，可当我...
    茶点故事阅读 66,874评论 6赞 388
  • 恶毒庶女顶嫁案：这布局不是一般人想出来的
    文/花漫 我一把揭开白布。 她就那样静静地躺着，像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上，一...
    开封第一讲书人阅读 50,841评论 1赞 295
  • 城市分裂传说
    那天，我揣着相机与录音，去河边找鬼。 笑死，一个胖子当着我的面吹牛，可吹牛的内容都是我干的。 我是一名探鬼主播，决...
    沈念sama阅读 39,812评论 3赞 416
  • 双鸳鸯连环套：你想象不到人心有多黑
    文/苍兰香墨 我猛地睁开眼，长吁一口气：“原来是场噩梦啊……” “哼！你这毒妇竟也来了？” 一声冷哼从身侧响起，我...
    开封第一讲书人阅读 38,582评论 0赞 271
  • 万荣杀人案实录
    序言：老挝万荣一对情侣失踪，失踪者是张志新（化名）和其女友刘颖，没想到半个月后，有当地人在树林里发现了一具尸体，经...
    沈念sama阅读 45,033评论 1赞 308
  • 护林员之死
    正文 独居荒郊野岭守林人离奇死亡，尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,309评论 2赞 331
  • 白月光启示录
    正文 我和宋清朗相恋三年，在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,450评论 1赞 345
  • 活死人
    序言：一个原本活蹦乱跳的男人离奇死亡，死状恐怖，灵堂内的尸体忽然破棺而出，到底是诈尸还是另有隐情，我是刑警宁泽，带...
    沈念sama阅读 35,158评论 5赞 341
  • 日本核电站爆炸内幕
    正文 年R本政府宣布，位于F岛的核电站，受9级特大地震影响，放射性物质发生泄漏。R本人自食恶果不足惜，却给世界环境...
    茶点故事阅读 40,789评论 3赞 325
  • 男人毒药：我在死后第九天来索命
    文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹，春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,409评论 0赞 21
  • 一桩弑父案，背后竟有这般阴谋
    文/苍兰香墨 我抬头看了看天上的太阳。三九已至，却和暖如春，着一层夹袄步出监牢的瞬间，已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,609评论 1赞 268
  • 情欲美人皮
    我被黑心中介骗来泰国打工， 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留，地道东北人。 一个月前我还...
    沈念sama阅读 47,440评论 2赞 368
  • 代替公主和亲
    正文 我出身青楼，却偏偏与公主长得像，于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子，可洞房花烛夜当晚...
    茶点故事阅读 44,357评论 2赞 352

推荐阅读更多精彩内容