Lab 7: ERRO 041 [allarewelcome] Got error &{FORBIDDEN}

koakh

(my encounter and escape from ERRO 041

when I try to get config (genesis block) for peer0.org2 I have above error, on second use, first time it works without error

# fetch genesis block
$ peer channel fetch 0 Org2AddedConfig.block -c allarewelcome -o orderer.example.com:7050
2019-11-09 18:31:20.732 UTC [channelCmd] InitCmdFactory -> INFO 001 Endorser and orderer connections initialized
2019-11-09 18:31:20.735 UTC [cli.common] readBlock -> INFO 002 Got status: &{FORBIDDEN}
Error: can\'t read the block: &{FORBIDDEN}

first time I send update to the network for approval with

$ peer channel update -f org2SubmitReady.pb -c allarewelcome -o orderer.example.com:7050

it works, if I try to do the same, always have above error

$ peer channel update -f org2SubmitReady.pb -c allarewelcome -o orderer.example.com:7050
2019-11-09 19:09:01.721 UTC [channelCmd] InitCmdFactory -> INFO 001 Endorser and orderer connections initialized
Error: got unexpected status: BAD_REQUEST -- error authorizing update: error validating ReadSet: readset expected key [Group]  /Channel/Application/Org1MSP at version 1, but got version 0

the problem is when I try to join org2 to channel and always have above errors

$ PEER=peer0
$ export CORE_PEER_LOCALMSPID=Org2MSP
$ export CORE_PEER_ADDRESS=$PEER.org2.example.com:7051
$ export CORE_PEER_MSPCONFIGPATH=/opt/gopath/src/github.com/hyperledger/fabric/peer/crypto/peerOrganizations/org2.example.com/users/Admin@org2.example.com/msp
$ peer channel fetch 0 Org2AddedConfig.block -c allarewelcome -o orderer.example.com:7050
2019-11-09 19:13:27.559 UTC [channelCmd] InitCmdFactory -> INFO 001 Endorser and orderer connections initialized
2019-11-09 19:13:27.561 UTC [cli.common] readBlock -> INFO 002 Got status: &{FORBIDDEN}
Error: can't read the block: &{FORBIDDEN}

I can see in peer0.org2.example.com logs

peer0.org2.example.com    | 2019-11-09 19:06:54.126 UTC [ConnProducer] DisableEndpoint -> WARN 04a Only 1 endpoint remained, will not black-list it
peer0.org2.example.com    | 2019-11-09 19:06:54.137 UTC [blocksProvider] DeliverBlocks -> ERRO 04b [allarewelcome] Got error &{FORBIDDEN}
peer0.org2.example.com    | 2019-11-09 19:06:56.344 UTC [gossip.gossip] Gossip -> WARN 04c Failed obtaining gossipChannel of [97 108 108 97 114 101 119 101 108 99 111 109 101] aborting
peer0.org2.example.com    | 2019-11-09 19:07:01.347 UTC [gossip.gossip] Gossip -> WARN 04d Failed obtaining gossipChannel of [97 108 108 97 114 101 119 101 108 99 111 109 101] aborting
peer0.org2.example.com    | 2019-11-09 19:07:04.138 UTC [ConnProducer] DisableEndpoint -> WARN 04e Only 1 endpoint remained, will not black-list it
peer0.org2.example.com    | 2019-11-09 19:07:04.150 UTC [blocksProvider] DeliverBlocks -> ERRO 04f [allarewelcome] Got error &{FORBIDDEN}
peer0.org2.example.com    | 2019-11-09 19:07:06.349 UTC [gossip.gossip] Gossip -> WARN 050 Failed obtaining gossipChannel of [97 108 108 97 114 101 119 101 108 99 111 109 101] aborting
peer0.org2.example.com    | 2019-11-09 19:07:11.352 UTC [gossip.gossip] Gossip -> WARN 051 Failed obtaining gossipChannel of [97 108 108 97 114 101 119 101 108 99 111 109 101] aborting
peer0.org2.example.com    | 2019-11-09 19:07:14.151 UTC [ConnProducer] DisableEndpoint -> WARN 052 Only 1 endpoint remained, will not black-list it
peer0.org2.example.com    | 2019-11-09 19:07:14.165 UTC [blocksProvider] DeliverBlocks -> ERRO 053 [allarewelcome] Got error &{FORBIDDEN}
peer0.org2.example.com    | 2019-11-09 19:07:14.165 UTC [blocksProvider] DeliverBlocks -> ERRO 054 [allarewelcome] Wrong statuses threshold passed, stopping block provider
peer0.org2.example.com    | 2019-11-09 19:07:14.165 UTC [gossip.election] stopBeingLeader -> INFO 055 faee1653f635f823d0735d4a03f133f4d3142dd2a5f9a4b63e030c3c8b335dab Stopped being a leader
peer0.org2.example.com    | 2019-11-09 19:07:14.166 UTC [gossip.service] func1 -> INFO 056 Renounced leadership, stopping delivery service for channel allarewelcome

in orderer.example.com logs

orderer.example.com       | 2019-11-09 19:14:24.240 UTC [comm.grpc.server] 1 -> INFO 0ea streaming call completed {"grpc.start_time": "2019-11-09T19:14:24.24Z", "grpc.service": "orderer.AtomicBroadcast", "grpc.method": "Deliver", "grpc.peer_address": "172.20.0.10:37290", "grpc.code": "OK", "grpc.call_duration": "713.077µs"}
orderer.example.com       | 2019-11-09 19:14:34.248 UTC [cauthdsl] deduplicate -> ERRO 0eb Principal deserialization failure (MSP Org2MSP is unknown) for identity 0
orderer.example.com       | 2019-11-09 19:14:34.249 UTC [cauthdsl] deduplicate -> ERRO 0ec Principal deserialization failure (MSP Org2MSP is unknown) for identity 0
orderer.example.com       | 2019-11-09 19:14:34.249 UTC [common.deliver] deliverBlocks -> WARN 0ed [channel: allarewelcome] Client authorization revoked for deliver request from 172.20.0.10:37292: Failed to reach implicit threshold of 1 sub-policies, required 1 remaining: permission denied
orderer.example.com       | 2019-11-09 19:14:34.249 UTC [comm.grpc.server] 1 -> INFO 0ee streaming call completed {"grpc.start_time": "2019-11-09T19:14:34.248Z", "grpc.service": "orderer.AtomicBroadcast", "grpc.method": "Deliver", "grpc.peer_address": "172.20.0.10:37292", "grpc.code": "OK", "grpc.call_duration": "1.669571ms"}

seems related with Principal deserialization failure (MSP Org2MSP is unknown) for identity 0

FINAL FIX: after some debug, I re-start generate ALL files to add org2 to network, start in section Adding a New Organization to Our Channel

# inside cli container, grab latest configuration definition from the network
$ peer channel fetch config blockFetchedConfig.pb -o orderer.example.com:7050 -c allarewelcome
.....follow docs, creating files until we have reach line
# send update to the network for approval
$ peer channel update -f org2SubmitReady.pb -c allarewelcome -o orderer.example.com:7050

now after re-send the send update to the network for approval, with

$ peer channel update -f org2SubmitReady.pb -c allarewelcome -o orderer.example.com:7050

the running peer0.org2.example.com container crash, and stop, I delete it, and re-start it, and it start to work

I don't know if the solution is deleting the container or re-create the files and send the network update to approval?
maybe some expert can clarify me.....or next time I try first drop container, but I don't want to drop containers, in this case I dont any choice it crash

# start and check it all works well
$ docker-compose up -d peer0.org2.example.com 
$ docker-compose logs -f peer0.org2.example.com

now I can get config/genesis block again and join channel with peer0.org2

# fetch genesis block
$ peer channel fetch 0 Org2AddedConfig.block -c allarewelcome -o orderer.example.com:7050
2019-11-09 19:29:56.112 UTC [channelCmd] InitCmdFactory -> INFO 001 Endorser and orderer connections initialized
2019-11-09 19:29:56.114 UTC [cli.common] readBlock -> INFO 002 Received block: 0
# join channel
$ peer channel join -b Org2AddedConfig.block
# list channel
$ peer channel list
Channels peers has joined: 
allarewelcome
# do the same for peer1.org2
$ PEER=peer0
$ export CORE_PEER_ADDRESS=$PEER.org2.example.com:7051
$ peer channel join -b Org2AddedConfig.block
Channels peers has joined: 
allarewelcome
# list channel
$ peer channel list

done problem solved, I can continue my HL adventure

btaadmin

Are the CORE_PEER_LOCALMSPID and CORE_PEER_MSPCONFIGPATH environment variables set correctly?