Cannot communicate from Fabric peer1 to orderer in a docker swarm network on multiple hosts

302 Views Asked by At

I have successfully set up a Hyperledger Fabric network on our cloud VMs. So far, we have no issues bringing up peers on a localhost configuration (all peers brought up on localhost).

However, I tried to switch to a multi-host configuration using this tutorial: Hyperledger Fabric on Multiple Hosts

The docker swarm is set up correctly

# docker node ls
ID                            HOSTNAME                      STATUS              AVAILABILITY        MANAGER STATUS      ENGINE VERSION
jyb1rt9orples917um4xyq17t     sd-cfd1-0319   Ready               Active              Reachable           18.09.7
3za3zddpe9tuy9v44vs2yapvu *   sd-d5d8-da85   Ready               Active              Leader              18.09.7

The configuration is this:

Host 1: Orderer, Peer0, Couch DB for Peer0 Host 2: Peer 1 and Couch DB for Peer1

Our configuration:

> Docker version: 18.09.7 

> OS: RHEL 7.7 (Maipo) 

> Peer:   
>Version: 1.4.2
>Commit SHA: c6cc550  
>Go version: go1.11.5  
>OS/Arch: linux/amd64

> Chaincode:   
> Base Image Version: 0.4.15   
> Base Docker Namespace: hyperledger   
> Base Docker Label: org.hyperledger.fabric   
> Docker Namespace: hyperledger

Issues:

When I start peer1, I immediately start seeing these messages:

2020-02-24 21:03:20.715 UTC [gossip.discovery] func1 -> WARN 09b Could not connect to Endpoint: peer0.org1.example.com:7051, InternalEndpoint: peer0.org1.example.com:7051, PKI-ID: <nil>, Metadata:  : context deadline exceeded

Furthermore, I start a cli container using this command (as provided in the tutorial):

docker run --rm -it --network="syndichain" \
     --name cli \
     --link orderer.example.com:orderer.example.com \
     --link peer0.org1.example.com:peer0.org1.example.com \
     --link peer1.org1.example.com:peer1.org1.example.com \
     -p 12051:7051 \
     -p 12053:7053 \
     -e GOPATH=/opt/gopath \
     -e CORE_PEER_LOCALMSPID=Org1MSP \
     -e CORE_PEER_TLS_ENABLED=false \
     -e CORE_VM_ENDPOINT=unix:///host/var/run/docker.sock \
     -e FABRIC_LOGGING_SPEC=debug \
     -e CORE_PEER_ID=cli \
     -e CORE_PEER_ADDRESS=peer0.org1.example.com:7051 \
     -e CORE_PEER_NETWORKID=cli \
     -e CORE_PEER_MSPCONFIGPATH=/opt/gopath/src/github.com/hyperledger/fabric/peer/crypto/peerOrganizations/org1.example.com/users/[email protected]/msp \
     -e GODEBUG=netdns=go \
     -e CORE_VM_DOCKER_HOSTCONFIG_NETWORKMODE=syndichain  \
     -v /var/run/:/host/var/run/ \
     -v $(pwd)/chaincode/:/opt/gopath/src/github.com/hyperledger/fabric/examples/chaincode/go \
     -v $(pwd)/crypto-config:/opt/gopath/src/github.com/hyperledger/fabric/peer/crypto/ \
     -v $(pwd)/scripts:/opt/gopath/src/github.com/hyperledger/fabric/peer/scripts/ \
     -v $(pwd)/channel-artifacts:/opt/gopath/src/github.com/hyperledger/fabric/peer/channel-artifacts \
     -w /opt/gopath/src/github.com/hyperledger/fabric/peer \ 
     hyperledger/fabric-tools /bin/bash -c './scripts/script.sh'

This results in the following error:

Build multi host network (BMHN) end-to-end test

Channel name : mychannel
Creating channel...
CORE_PEER_NETWORKID=cli
CORE_PEER_LOCALMSPID=Org1MSP
CORE_VM_ENDPOINT=unix:///host/var/run/docker.sock
CORE_PEER_TLS_ENABLED=false
CORE_PEER_MSPCONFIGPATH=/opt/gopath/src/github.com/hyperledger/fabric/peer/crypto/peerOrganizations/org1.example.com/users/[email protected]/msp
CORE_VM_DOCKER_HOSTCONFIG_NETWORKMODE=syndichain
CORE_PEER_ID=cli
CORE_PEER_ADDRESS=peer0.org1.example.com:7051
Error: failed to create deliver client: orderer client failed to connect to orderer.example.com:7050: failed to create new connection: context deadline exceeded
!!!!!!!!!!!!!!! Channel creation failed !!!!!!!!!!!!!!!!
========= ERROR !!! FAILED to execute End-2-End Scenario ===========

This led me to think that there is either an issue with communicating from one VM to another, or there is a docker configuration issue.

It did a netcat from both VMs and found all the relevant ports reachable. The error I suspect most at this point is the

"shim reaped"

error when I try to bring up the cli container. From what is evident to me, the containers can communicate with each other as the heartbeat requests all seem to be successful. Furthermore, it appears that the IP addresses assigned by docker networking appears to be resolvable (from Host 2, orderer.example.com is successfully resolved to 10.0.0.17) which tells me that at least the IPs are being correctly associated to the FQDNs.

I then traced the syslog and it is being produced below.

Feb 24 14:29:26      dockerd[8562]: time="2020-02-24T14:29:26.969001873-05:00" level=debug msg="Calling GET /_ping"
Feb 24 14:29:26      dockerd[8562]: time="2020-02-24T14:29:26.970578171-05:00" level=debug msg="Calling POST /v1.39/containers/create?name=cli"
Feb 24 14:29:26      dockerd[8562]: time="2020-02-24T14:29:26.971055389-05:00" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":true,\"AttachStdout\":true,\"Cmd\":[\"/bin/bash\",\"-c\",\"./scripts/script.sh\"],\"Domainname\":\"\",\"Entrypoint\":null,\"Env\":[\"GOPATH=/opt/gopath\",\"CORE_VM_ENDPOINT=unix:///host/var/run/docker.sock\",\"FABRIC_LOGGING_SPEC=debug\",\"CORE_PEER_ADDRESS=peer0.org1.example.com:7051\",\"CORE_PEER_MSPCONFIGPATH=/opt/gopath/src/github.com/hyperledger/fabric/peer/crypto/peerOrganizations/org1.example.com/users/[email protected]/msp\",\"GODEBUG=netdns=go\",\"CORE_VM_DOCKER_HOSTCONFIG_NETWORKMODE=syndichain\",\"CORE_PEER_LOCALMSPID=Org1MSP\",\"CORE_PEER_TLS_ENABLED=false\",\"CORE_PEER_ID=cli\",\"CORE_PEER_NETWORKID=cli\"],\"ExposedPorts\":{\"7051/tcp\":{},\"7053/tcp\":{}},\"HostConfig\":{\"AutoRemove\":true,\"Binds\":[\"/usr/local/fabric/Build-Multi-Host-Network-Hyperledger-master/channel-artifacts:/opt/gopath/src/github.com/hyperledger/fabric/peer/channel-artifacts\",\"/var/run/:/host/var/run/\",\"/usr/local/fabric/Build-Multi-Host-Network-Hyperledger-master/chaincode/:/opt/gopath/src/github.com/hyperledger/fabric/examples/chaincode/go\",\"/usr/local/fabric/Build-Multi-Host-Network-Hyperledger-master/crypto-config:/opt/gopath/src/github.com/hyperledger/fabric/peer/crypto/\",\"/usr/local/fabric/Build-Multi-Host-Network-Hyperledger-master/scripts:/opt/gopath/src/github.com/hyperledger/fabric/peer/scripts/\"],\"BlkioDeviceReadBps\":null,\"BlkioDeviceReadIOps\":null,\"BlkioDeviceWriteBps\":null,\"BlkioDeviceWriteIOps\":null,\"BlkioWeight\":0,\"BlkioWeightDevice\":[],\"CapAdd\":null,\"CapDrop\":null,\"Cgroup\":\"\",\"CgroupParent\":\"\",\"ConsoleSize\":[0,0],\"ContainerIDFile\":\"\",\"CpuCount\":0,\"CpuPercent\":0,\"CpuPeriod\":0,\"CpuQuota\":0,\"CpuRealtimePeriod\":0,\"CpuRealtimeRuntime\":0,\"CpuShares\":0,\"CpusetCpus\":\"\",\"CpusetMems\":\"\",\"DeviceCgroupRules\":null,\"Devices\":[],\"DiskQuota\":0,\"Dns\":[],\"DnsOptions\":[],\"DnsSearch\":[],\"ExtraHosts\":null,\"GroupAdd\":null,\"IOMaximumBandwidth\":0,\"IOMaximumIOps\":0,\"IpcMode\":\"\",\"Isolation\":\"\",\"KernelMemory\":0,\"Links\":[\"orderer.example.com:orderer.example.com\",\"peer0.org1.example.com:peer0.org1.example.com\",\"peer1.org1.example.com:peer1.org1.example.com\"],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"MaskedPaths\":null,\"Memory\":0,\"MemoryReservation\":0,\"MemorySwap\":0,\"MemorySwappiness\":-1,\"NanoCpus\":0,\"NetworkMode\":\"syndichain\",\"OomKillDisable\":false,\"OomScoreAdj\":0,\"PidMode\":\"\",\"PidsLimit\":0,\"PortBindings\":{\"7051/tcp\":[{\"HostIp\":\"\",\"HostPort\":\"12051\"}],\"7053/tcp\":[{\"HostIp\":\"\",\"HostPort\":\"12053\"}]},\"Privileged\":false,\"PublishAllPorts\":false,\"ReadonlyPaths\":null,\"ReadonlyRootfs\":false,\"RestartPolicy\":{\"MaximumRetryCount\":0,\"Name\":\"no\"},\"SecurityOpt\":null,\"ShmSize\":0,\"UTSMode\":\"\",\"Ulimits\":null,\"UsernsMode\":\"\",\"VolumeDriver\":\"\",\"VolumesFrom\":null},\"Hostname\":\"\",\"Image\":\"hyperledger/fabric-tools\",\"Labels\":{},\"NetworkingConfig\":{\"EndpointsConfig\":{\"syndichain\":{\"Aliases\":null,\"DriverOpts\":null,\"EndpointID\":\"\",\"Gateway\":\"\",\"GlobalIPv6Address\":\"\",\"GlobalIPv6PrefixLen\":0,\"IPAMConfig\":null,\"IPAddress\":\"\",\"IPPrefixLen\":0,\"IPv6Gateway\":\"\",\"Links\":[\"orderer.example.com:orderer.example.com\",\"peer0.org1.example.com:peer0.org1.example.com\",\"peer1.org1.example.com:peer1.org1.example.com\"],\"MacAddress\":\"\",\"NetworkID\":\"\"}}},\"OnBuild\":null,\"OpenStdin\":true,\"StdinOnce\":true,\"Tty\":true,\"User\":\"\",\"Volumes\":{},\"WorkingDir\":\"/opt/gopath/src/github.com/hyperledger/fabric/peer\"}"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.001089774-05:00" level=debug msg="container mounted via layerStore: &{/var/lib/docker/overlay2/3b7b4672e86f3eb81bc408cab956ff5bc3d68b2f2ed35ee8214fe6a3f27ee6a7/merged 0x55ca8b813920 0x55ca8b813920}"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.001866350-05:00" level=debug msg="Probing all drivers for volume with name: 96e3de7c589125587d0f3572a320cdaf5b9c4ea12cbfe0376cc2dfe8af0c5d09"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.001938186-05:00" level=debug msg="Registering new volume reference: driver \"local\", name \"96e3de7c589125587d0f3572a320cdaf5b9c4ea12cbfe0376cc2dfe8af0c5d09\""
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.011129500-05:00" level=debug msg="copying image data from 2a440d686d3f11606dc7cd12f7a51d8758fa748dc27ce0ab5e4ac553ded407f2:/etc/hyperledger/fabric, to 96e3de7c589125587d0f3572a320cdaf5b9c4ea12cbfe0376cc2dfe8af0c5d09"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.026911359-05:00" level=debug msg="Calling POST /v1.39/containers/2a440d686d3f11606dc7cd12f7a51d8758fa748dc27ce0ab5e4ac553ded407f2/attach?stderr=1&stdin=1&stdout=1&stream=1"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.027086926-05:00" level=debug msg="attach: stdout: begin"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.027072995-05:00" level=debug msg="attach: stdin: begin"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.027125267-05:00" level=debug msg="attach: stderr: begin"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.029198399-05:00" level=debug msg="Calling POST /v1.39/containers/2a440d686d3f11606dc7cd12f7a51d8758fa748dc27ce0ab5e4ac553ded407f2/wait?condition=removed"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.030661039-05:00" level=debug msg="Calling POST /v1.39/containers/2a440d686d3f11606dc7cd12f7a51d8758fa748dc27ce0ab5e4ac553ded407f2/start"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.032019464-05:00" level=debug msg="container mounted via layerStore: &{/var/lib/docker/overlay2/3b7b4672e86f3eb81bc408cab956ff5bc3d68b2f2ed35ee8214fe6a3f27ee6a7/merged 0x55ca8b813920 0x55ca8b813920}"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.039037283-05:00" level=debug msg="Successfully attached to network syndichain with task id jdqg0liqovtjyhc5f6ee38e6t"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.195527468-05:00" level=debug msg="(*worker).Update" len(assignments)=1 module=node/agent node.id=jyb1rt9orples917um4xyq17t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.195585749-05:00" level=debug msg="(*worker).reconcileSecrets" len(removedSecrets)=0 len(updatedSecrets)=0 module=node/agent node.id=jyb1rt9orples917um4xyq17t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.195603346-05:00" level=debug msg="(*worker).reconcileConfigs" len(removedConfigs)=0 len(updatedConfigs)=0 module=node/agent node.id=jyb1rt9orples917um4xyq17t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.195622233-05:00" level=debug msg="(*worker).reconcileTaskState" len(removedTasks)=0 len(updatedTasks)=1 module=node/agent node.id=jyb1rt9orples917um4xyq17t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.195649236-05:00" level=debug msg=assigned module=node/agent node.id=jyb1rt9orples917um4xyq17t task.desiredstate=RUNNING task.id=jdqg0liqovtjyhc5f6ee38e6t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.195769188-05:00" level=debug msg="state changed" module=node/agent node.id=jyb1rt9orples917um4xyq17t service.id= state.desired=RUNNING state.transition="ASSIGNED->ACCEPTED" task.id=jdqg0liqovtjyhc5f6ee38e6t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.195870244-05:00" level=debug msg="(*Agent).UpdateTaskStatus" module=node/agent node.id=jyb1rt9orples917um4xyq17t task.id=jdqg0liqovtjyhc5f6ee38e6t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.195981721-05:00" level=debug msg="state changed" module=node/agent/taskmanager node.id=jyb1rt9orples917um4xyq17t service.id= state.desired=RUNNING state.transition="ASSIGNED->ACCEPTED" task.id=jdqg0liqovtjyhc5f6ee38e6t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.202590284-05:00" level=debug msg="task status reported" module=node/agent node.id=jyb1rt9orples917um4xyq17t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.202631085-05:00" level=debug msg="(*Agent).UpdateTaskStatus" module=node/agent node.id=jyb1rt9orples917um4xyq17t task.id=jdqg0liqovtjyhc5f6ee38e6t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.203459167-05:00" level=debug msg="task status reported" module=node/agent node.id=jyb1rt9orples917um4xyq17t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.203608322-05:00" level=debug msg="state changed" module=node/agent/taskmanager node.id=jyb1rt9orples917um4xyq17t service.id= state.desired=RUNNING state.transition="ACCEPTED->PREPARING" task.id=jdqg0liqovtjyhc5f6ee38e6t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.203757287-05:00" level=debug msg="(*Agent).UpdateTaskStatus" module=node/agent node.id=jyb1rt9orples917um4xyq17t task.id=jdqg0liqovtjyhc5f6ee38e6t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.204655881-05:00" level=debug msg="task status reported" module=node/agent node.id=jyb1rt9orples917um4xyq17t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.205666947-05:00" level=debug msg="state changed" module=node/agent/taskmanager node.id=jyb1rt9orples917um4xyq17t service.id= state.desired=RUNNING state.transition="PREPARING->READY" task.id=jdqg0liqovtjyhc5f6ee38e6t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.205817186-05:00" level=debug msg="(*Agent).UpdateTaskStatus" module=node/agent node.id=jyb1rt9orples917um4xyq17t task.id=jdqg0liqovtjyhc5f6ee38e6t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.206767533-05:00" level=debug msg="task status reported" module=node/agent node.id=jyb1rt9orples917um4xyq17t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.207450224-05:00" level=debug msg="state changed" module=node/agent/taskmanager node.id=jyb1rt9orples917um4xyq17t service.id= state.desired=RUNNING state.transition="READY->STARTING" task.id=jdqg0liqovtjyhc5f6ee38e6t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.207606890-05:00" level=debug msg="(*Agent).UpdateTaskStatus" module=node/agent node.id=jyb1rt9orples917um4xyq17t task.id=jdqg0liqovtjyhc5f6ee38e6t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.208708093-05:00" level=debug msg="task status reported" module=node/agent node.id=jyb1rt9orples917um4xyq17t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.209319384-05:00" level=debug msg="state changed" module=node/agent/taskmanager node.id=jyb1rt9orples917um4xyq17t service.id= state.desired=RUNNING state.transition="STARTING->RUNNING" task.id=jdqg0liqovtjyhc5f6ee38e6t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.209363722-05:00" level=debug msg="Successfully allocated resources on network syndichain for task id jdqg0liqovtjyhc5f6ee38e6t"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.209747416-05:00" level=debug msg="Assigning addresses for endpoint cli's interface on network syndichain"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.209777453-05:00" level=debug msg="RequestAddress(LocalDefault/10.0.0.0/24, 10.0.0.44, map[])"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.209817098-05:00" level=debug msg="Request address PoolID:10.0.0.0/24 App: ipam/default/data, ID: LocalDefault/10.0.0.0/24, DBIndex: 0x0, Bits: 256, Unselected: 250, Sequence: (0xc0000000, 1)->(0x61000000, 1)->(0x0, 5)->(0x1, 1)->end Curr:0 Serial:false PrefAddress:10.0.0.44 "
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.210085285-05:00" level=debug msg="(*Agent).UpdateTaskStatus" module=node/agent node.id=jyb1rt9orples917um4xyq17t task.id=jdqg0liqovtjyhc5f6ee38e6t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.211078165-05:00" level=debug msg="task status reported" module=node/agent node.id=jyb1rt9orples917um4xyq17t
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.211601399-05:00" level=debug msg="Assigning addresses for endpoint cli's interface on network syndichain"
Feb 24 14:29:27      NetworkManager[1227]: <info>  [1582572567.2160] manager: (veth06813cb): new Veth device (/org/freedesktop/NetworkManager/Devices/990)
Feb 24 14:29:27      NetworkManager[1227]: <info>  [1582572567.2173] manager: (veth1f1359f): new Veth device (/org/freedesktop/NetworkManager/Devices/991)
Feb 24 14:29:27      kernel: br0: port 5(veth10) entered blocking state
Feb 24 14:29:27      kernel: br0: port 5(veth10) entered disabled state
Feb 24 14:29:27      kernel: device veth10 entered promiscuous mode
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.235156076-05:00" level=debug msg="checkEncryption(rxku2qr, <nil>, 4097, true)"
Feb 24 14:29:27      kernel: IPv6: ADDRCONF(NETDEV_UP): veth10: link is not ready
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.236274348-05:00" level=debug msg="Assigning addresses for endpoint gateway_2f46b2b31757's interface on network docker_gwbridge"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.236308754-05:00" level=debug msg="RequestAddress(LocalDefault/172.24.0.0/16, <nil>, map[])"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.236336173-05:00" level=debug msg="Request address PoolID:172.24.0.0/16 App: ipam/default/data, ID: LocalDefault/172.24.0.0/16, DBIndex: 0x0, Bits: 65536, Unselected: 65530, Sequence: (0xf8000000, 1)->(0x0, 2046)->(0x1, 1)->end Curr:6 Serial:false PrefAddress:<nil> "
Feb 24 14:29:27      kernel: docker_gwbridge: port 4(veth4c475b3) entered blocking state
Feb 24 14:29:27      kernel: docker_gwbridge: port 4(veth4c475b3) entered disabled state
Feb 24 14:29:27      kernel: device veth4c475b3 entered promiscuous mode
Feb 24 14:29:27      kernel: IPv6: ADDRCONF(NETDEV_UP): veth4c475b3: link is not ready
Feb 24 14:29:27      kernel: docker_gwbridge: port 4(veth4c475b3) entered blocking state
Feb 24 14:29:27      kernel: docker_gwbridge: port 4(veth4c475b3) entered forwarding state
Feb 24 14:29:27      NetworkManager[1227]: <info>  [1582572567.2424] manager: (vethea13ea8): new Veth device (/org/freedesktop/NetworkManager/Devices/992)
Feb 24 14:29:27      NetworkManager[1227]: <info>  [1582572567.2454] manager: (veth4c475b3): new Veth device (/org/freedesktop/NetworkManager/Devices/993)
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.255822577-05:00" level=debug msg="Assigning addresses for endpoint gateway_2f46b2b31757's interface on network docker_gwbridge"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.266166481-05:00" level=debug msg="Programming external connectivity on endpoint gateway_2f46b2b31757 (f92d8b825f4c614d7f871c79b51c982094c22c9dcb6066c09fdcce8caef48380)"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.266279703-05:00" level=debug msg="/usr/sbin/iptables, [--wait -t nat -C DOCKER -p tcp -d 0/0 --dport 12053 -j DNAT --to-destination 172.24.0.5:7053 ! -i docker_gwbridge]"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.269246668-05:00" level=debug msg="/usr/sbin/iptables, [--wait -t nat -A DOCKER -p tcp -d 0/0 --dport 12053 -j DNAT --to-destination 172.24.0.5:7053 ! -i docker_gwbridge]"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.271738008-05:00" level=debug msg="/usr/sbin/iptables, [--wait -t filter -C DOCKER ! -i docker_gwbridge -o docker_gwbridge -p tcp -d 172.24.0.5 --dport 7053 -j ACCEPT]"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.273744453-05:00" level=debug msg="/usr/sbin/iptables, [--wait -t filter -A DOCKER ! -i docker_gwbridge -o docker_gwbridge -p tcp -d 172.24.0.5 --dport 7053 -j ACCEPT]"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.275818001-05:00" level=debug msg="/usr/sbin/iptables, [--wait -t nat -C POSTROUTING -p tcp -s 172.24.0.5 -d 172.24.0.5 --dport 7053 -j MASQUERADE]"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.277945120-05:00" level=debug msg="/usr/sbin/iptables, [--wait -t nat -A POSTROUTING -p tcp -s 172.24.0.5 -d 172.24.0.5 --dport 7053 -j MASQUERADE]"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.284601335-05:00" level=debug msg="/usr/sbin/iptables, [--wait -t nat -C DOCKER -p tcp -d 0/0 --dport 12051 -j DNAT --to-destination 172.24.0.5:7051 ! -i docker_gwbridge]"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.289499523-05:00" level=debug msg="/usr/sbin/iptables, [--wait -t nat -A DOCKER -p tcp -d 0/0 --dport 12051 -j DNAT --to-destination 172.24.0.5:7051 ! -i docker_gwbridge]"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.291659801-05:00" level=debug msg="/usr/sbin/iptables, [--wait -t filter -C DOCKER ! -i docker_gwbridge -o docker_gwbridge -p tcp -d 172.24.0.5 --dport 7051 -j ACCEPT]"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.293763256-05:00" level=debug msg="/usr/sbin/iptables, [--wait -t filter -A DOCKER ! -i docker_gwbridge -o docker_gwbridge -p tcp -d 172.24.0.5 --dport 7051 -j ACCEPT]"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.295949232-05:00" level=debug msg="/usr/sbin/iptables, [--wait -t nat -C POSTROUTING -p tcp -s 172.24.0.5 -d 172.24.0.5 --dport 7051 -j MASQUERADE]"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.297853175-05:00" level=debug msg="/usr/sbin/iptables, [--wait -t nat -A POSTROUTING -p tcp -s 172.24.0.5 -d 172.24.0.5 --dport 7051 -j MASQUERADE]"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.305700828-05:00" level=debug msg="EnableService 2a440d686d3f11606dc7cd12f7a51d8758fa748dc27ce0ab5e4ac553ded407f2 START"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.305734533-05:00" level=debug msg="addServiceInfoToCluster START for  64d46972c8e964a4ec93c74464ca8f30876dbf1aebcfae8eb76c534b1ffcfc9c"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.305767414-05:00" level=debug msg="addContainerNameResolution 64d46972c8e964a4ec93c74464ca8f30876dbf1aebcfae8eb76c534b1ffcfc9c cli"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.305785345-05:00" level=debug msg="64d46972c8e964a4ec93c74464ca8f30876dbf1aebcfae8eb76c534b1ffcfc9c (rxku2qr).addSvcRecords(cli, 10.0.0.44, <nil>, true) addServiceInfoToCluster sid:64d46972c8e964a4ec93c74464ca8f30876dbf1aebcfae8eb76c534b1ffcfc9c"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.305814829-05:00" level=debug msg="64d46972c8e964a4ec93c74464ca8f30876dbf1aebcfae8eb76c534b1ffcfc9c (rxku2qr).addSvcRecords(2a440d686d3f, 10.0.0.44, <nil>, true) addServiceInfoToCluster sid:64d46972c8e964a4ec93c74464ca8f30876dbf1aebcfae8eb76c534b1ffcfc9c"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.305863022-05:00" level=debug msg="addServiceInfoToCluster END for  64d46972c8e964a4ec93c74464ca8f30876dbf1aebcfae8eb76c534b1ffcfc9c"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.305874153-05:00" level=debug msg="EnableService 2a440d686d3f11606dc7cd12f7a51d8758fa748dc27ce0ab5e4ac553ded407f2 DONE"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.309269799-05:00" level=debug msg="bundle dir created" bundle=/var/run/docker/containerd/2a440d686d3f11606dc7cd12f7a51d8758fa748dc27ce0ab5e4ac553ded407f2 module=libcontainerd namespace=moby root=/var/lib/docker/overlay2/3b7b4672e86f3eb81bc408cab956ff5bc3d68b2f2ed35ee8214fe6a3f27ee6a7/merged
Feb 24 14:29:27      containerd[1600]: time="2020-02-24T14:29:27.319949327-05:00" level=info msg="shim containerd-shim started" address="/containerd-shim/moby/2a440d686d3f11606dc7cd12f7a51d8758fa748dc27ce0ab5e4ac553ded407f2/shim.sock" debug=false pid=37295
Feb 24 14:29:27      kernel: IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Feb 24 14:29:27      kernel: docker_gwbridge: port 4(veth4c475b3) entered disabled state
Feb 24 14:29:27      kernel: IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Feb 24 14:29:27      kernel: IPv6: ADDRCONF(NETDEV_CHANGE): veth10: link becomes ready
Feb 24 14:29:27      kernel: br0: port 5(veth10) entered blocking state
Feb 24 14:29:27      kernel: br0: port 5(veth10) entered forwarding state
Feb 24 14:29:27      kernel: IPv6: ADDRCONF(NETDEV_CHANGE): veth4c475b3: link becomes ready
Feb 24 14:29:27      kernel: docker_gwbridge: port 4(veth4c475b3) entered blocking state
Feb 24 14:29:27      kernel: docker_gwbridge: port 4(veth4c475b3) entered forwarding state
Feb 24 14:29:27      NetworkManager[1227]: <info>  [1582572567.7109] device (veth4c475b3): carrier: link connected
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.725939909-05:00" level=debug msg="sandbox set key processing took 228.381194ms for container 2a440d686d3f11606dc7cd12f7a51d8758fa748dc27ce0ab5e4ac553ded407f2"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.783594995-05:00" level=debug msg=event module=libcontainerd namespace=moby topic=/tasks/create
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.840978637-05:00" level=debug msg=event module=libcontainerd namespace=moby topic=/tasks/start
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.876313824-05:00" level=debug msg="Calling POST /v1.39/containers/2a440d686d3f11606dc7cd12f7a51d8758fa748dc27ce0ab5e4ac553ded407f2/resize?h=28&w=216"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.935933779-05:00" level=debug msg="Name To resolve: orderer.example.com."
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.936012903-05:00" level=debug msg="[resolver] lookup name orderer.example.com. present without IPv6 address"
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.935892877-05:00" level=debug msg="Name To resolve: orderer.example.com."
Feb 24 14:29:27      dockerd[8562]: time="2020-02-24T14:29:27.936089763-05:00" level=debug msg="[resolver] lookup for orderer.example.com.: IP [10.0.0.17]"
Feb 24 14:29:28      dockerd[8562]: time="2020-02-24T14:29:28.516127879-05:00" level=debug msg="
Feb 24 14:29:28      dockerd[8562]: time="2020-02-24T14:29:28.516180395-05:00" level=debug msg="
Feb 24 14:29:28      dockerd[8562]: time="2020-02-24T14:29:28.519142475-05:00" level=debug msg="memberlist: Stream connection from=169.192.215.74:57840"
Feb 24 14:29:28      dockerd[8562]: time="2020-02-24T14:29:28.519843146-05:00" level=debug msg="
Feb 24 14:29:30      dockerd[8562]: time="2020-02-24T14:29:30.884279736-05:00" level=debug msg="memberlist: Initiating push/pull sync with: 169.192.215.74:7946"
Feb 24 14:29:31      dockerd[8562]: time="2020-02-24T14:29:31.007382713-05:00" level=debug msg=event module=libcontainerd namespace=moby topic=/tasks/exit
Feb 24 14:29:31      containerd[1600]: time="2020-02-24T14:29:31.075186958-05:00" level=info msg="shim reaped" id=2a440d686d3f11606dc7cd12f7a51d8758fa748dc27ce0ab5e4ac553ded407f2
Feb 24 14:29:31      dockerd[8562]: time="2020-02-24T14:29:31.085065205-05:00" level=debug msg=event module=libcontainerd namespace=moby topic=/tasks/delete
Feb 24 14:29:31      dockerd[8562]: time="2020-02-24T14:29:31.085099171-05:00" level=info msg="ignoring event" module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Feb 24 14:29:31      dockerd[8562]: time="2020-02-24T14:29:31.085152872-05:00" level=debug msg="attach: stdin: end"
Feb 24 14:29:31      dockerd[8562]: time="2020-02-24T14:29:31.085152209-05:00" level=debug msg="attach: stdout: end"
Feb 24 14:29:31      dockerd[8562]: time="2020-02-24T14:29:31.085181048-05:00" level=debug msg="attach: stderr: end"
Feb 24 14:29:31      dockerd[8562]: time="2020-02-24T14:29:31.085195981-05:00" level=debug msg="attach done"
Feb 24 14:29:31      dockerd[8562]: time="2020-02-24T14:29:31.085257280-05:00" level=debug msg="Closing buffered stdin pipe"

I greatly appreciate any help as I am stuck on this issue for the past few days.

Thank you.

0

There are 0 best solutions below