问题:重新启动HyperledgerExplorer报错
昨日部署好了fabric和HyperledgerExplorer,启动了一次,一切正常。今日再次启动,却发现怎么也启动不起来,docker-compose logs显示错误:
2021-07-08T08:08:14.461Z - error: [DiscoveryService]: send[mychannel] - Channel:mychannel received discovery error:access denied
explorer.mynetwork.com | [2021-07-08T08:08:14.461] [ERROR] FabricClient - Error: DiscoveryService: mychannel error: access denied
explorer.mynetwork.com | at DiscoveryService.send (/opt/explorer/node_modules/fabric-common/lib/DiscoveryService.js:363:11)
explorer.mynetwork.com | at processTicksAndRejections (internal/process/task_queues.js:97:5)
explorer.mynetwork.com | at async NetworkImpl._initializeInternalChannel (/opt/explorer/node_modules/fabric-network/lib/network.js:279:13)
explorer.mynetwork.com | at async NetworkImpl._initialize (/opt/explorer/node_modules/fabric-network/lib/network.js:231:9)
explorer.mynetwork.com | at async Gateway.getNetwork (/opt/explorer/node_modules/fabric-network/lib/gateway.js:330:9)
接入被拒绝了,明显是鉴权问题,将explorer down掉,重新copy organizations文件夹再试,试了很多次,还是不行。
排查
既然是explorer报的鉴权问题,那fabric这边应该会有日志打印,docker logs peer0.org1.example.com查看org1.peer0的日志(因为explorer这边鉴权用的就是org1的身份信息),果然其中有错,蓝色的一片INFO日志中赫然几条黄色的WARN在列:
2021-07-08 07:34:53.173 UTC [policies] SignatureSetToValidIdentities -> WARN 048 invalid identity: certificate subject=CN=org1admin,OU=admin,O=Hyperledger,ST=North Carolina,C=US serialnumber=406667895762504197446585402379494299487974961868 error="the supplied identity is not valid: x509: certificate signed by unknown authority (possibly because of \"x509: ECDSA verification failure\" while trying to verify candidate authority certificate \"ca.org1.example.com\")"
2021-07-08 07:34:53.185 UTC [policies] SignatureSetToValidIdentities -> WARN 049 invalid identity: certificate subject=CN=org1admin,OU=admin,O=Hyperledger,ST=North Carolina,C=US serialnumber=406667895762504197446585402379494299487974961868 error="the supplied identity is not valid: x509: certificate signed by unknown authority (possibly because of \"x509: ECDSA verification failure\" while trying to verify candidate authority certificate \"ca.org1.example.com\")"
2021-07-08 07:34:53.185 UTC [discovery] processQuery -> WARN 04a got query for channel mychannel from 172.21.0.10:54952 but it isn't eligible: implicit policy evaluation failed - 0 sub-policies were satisfied, but this policy requires 1 of the 'Writers' sub-policies to be satisfied
2021-07-08 07:34:53.185 UTC [discovery] processQuery -> WARN 04b got query for channel mychannel from 172.21.0.10:54952 but it isn't eligible: implicit policy evaluation failed - 0 sub-policies were satisfied, but this policy requires 1 of the 'Writers' sub-policies to be satisfied
通过日志信息可以知晓,确实是证书验证失败了,无论失败的原因为何,目前的基本猜想还是explorer所用证书与fabric本身生成的证书不一致。于是去查看ca_org1的日志打印,docker logs ca_org1,其中确实有登记的用户信息,每个用户信息都有一个serial number:
2021/07/08 07:23:11 [DEBUG] DB: Getting identity org1admin
2021/07/08 07:23:11 [DEBUG] DB: Login user org1admin with max enrollments of -1 and state of 0
2021/07/08 07:23:11 [DEBUG] DB: identity org1admin successfully logged in
2021/07/08 07:23:11 [DEBUG] DB: Getting identity org1admin
2021/07/08 07:23:11 [DEBUG] Requested expiry '0001-01-01 00:00:00 +0000 UTC' is before the CA certificate expiry '2021-07-08 07:18:00 +0000 UTC'. Will use CA cert expiry
2021/07/08 07:23:11 [DEBUG] Processing sign request: id=org1admin, CommonName=org1admin, Subject=<nil>
2021/07/08 07:23:11 [DEBUG] Request is not for a CA signing certificate
2021/07/08 07:23:11 [DEBUG] Checking CSR fields to make sure that they do not exceed maximum character limits
2021/07/08 07:23:11 [DEBUG] Finished processing sign request
2021/07/08 07:23:11 [DEBUG] DB: Getting identity org1admin
2021/07/08 07:23:11 [DEBUG] Attribute extension being added to certificate is: &{ID:[1 2 3 4 5 6 7 8 1] Critical:false Value:7b226174747273223a7b2268662e416666696c696174696f6e223a22222c2268662e456e726f6c6c6d656e744944223a226f72673161646d696e222c2268662e54797065223a2261646d696e227d7d}
2021/07/08 07:23:11 [DEBUG] Adding attribute extension to CSR: &{ID:[1 2 3 4 5 6 7 8 1] Critical:false Value:7b226174747273223a7b2268662e416666696c696174696f6e223a22222c2268662e456e726f6c6c6d656e744944223a226f72673161646d696e222c2268662e54797065223a2261646d696e227d7d}
2021/07/08 07:23:11 [INFO] signed certificate with serial number 162545685429543058387565196719933387105108052303
2021/07/08 07:23:11 [DEBUG] DB: Insert Certificate
2021/07/08 07:23:11 [DEBUG] Saved serial number as hex 1c78ccf56eb27fe2cbc986331c6208d19741494f
2021/07/08 07:23:11 [DEBUG] saved certificate with serial number 162545685429543058387565196719933387105108052303
2021/07/08 07:23:11 [DEBUG] Successfully incremented state for identity org1admin to 1
2021/07/08 07:23:11 [INFO] 172.21.0.1:50902 POST /enroll 201 0 "OK"
而peer0的log信息中也有同样的serial number,可以根据此判断是否为同一用户,根据以上信息可以推断,explorer传递过来的证书应该是错误的,organizations应该是相同的,考虑explorer在用其他证书。
explorer也是fabric的用户,fabric的用户有自己的wallet,浏览配置文件发现explorer的docker果然是挂载了volume用来存放wallet的:
explorer.mynetwork.com:
image: hyperledger/explorer:latest
container_name: explorer.mynetwork.com
hostname: explorer.mynetwork.com
environment:
- DATABASE_HOST=explorerdb.mynetwork.com
- DATABASE_DATABASE=fabricexplorer
- DATABASE_USERNAME=hppoc
- DATABASE_PASSWD=password
- LOG_LEVEL_APP=debug
- LOG_LEVEL_DB=debug
- LOG_LEVEL_CONSOLE=info
- LOG_CONSOLE_STDOUT=true
- DISCOVERY_AS_LOCALHOST=false
volumes:
- ./config.json:/opt/explorer/app/platform/fabric/config.json
- ./connection-profile:/opt/explorer/app/platform/fabric/connection-profile
- ./organizations:/tmp/crypto
- walletstore:/opt/explorer/wallet
ports:
- 8080:8080
depends_on:
explorerdb.mynetwork.com:
condition: service_healthy
networks:
- mynetwork.com
马上执行docker volume ls查看,果然是有wallet残留:
local explorer_pgdata
local explorer_walletstore
所以explorer再次启动后用的还是之前的身份,这就可以解释为什么会鉴权失败了,因为重新启动了fabric,重新生成了身份,所以用旧的身份肯定是不行的,而新拷贝的organization也是没有用到的。
那为什么会有volume残留呢?难道是docker-compose down不支持清除volume?检索后发现原来是没有加-v选项,而查看explorer官方文档,其中也是说明了-v才会清除volume的:
In the docker-compose.yaml, two named volumes are allocated for persistent data (for Postgres data and user wallet), if you would like to clear these named volumes up, run the following:
$ docker-compose down -v
真是太马虎大意了。。。
解决
执行命令删除残留的volume:
docker volume rm explorer_pgdata
docker volume rm explorer_walletstore
重新启动HyperledgerExplorer,一切恢复正常。