findNewNode lookup 가 반복되며 싱크가 시작되지 않습니다

한국어🇰🇷 클레이튼
1

안녕하세요.
계속 운영중이었던 EN에서 다른 설정 변경 없이 88126758 블록에서 싱크가 중단된 상태입니다.
재시작해도 싱크가 시작되지 않으며 findNewNode와 lookup start 가 반복됩니다.
DEBUG log 첨부합니다.

DEBUG[04/18,05:51:22 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=2
DEBUG[04/18,05:51:22 Z] [33] [Dial] Add new discoverTypedStaticTask    name=PN
DEBUG[04/18,05:51:22 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=ac26a45b768755e4 targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:22 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:22 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=2e5c09626e30e5ac targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:22 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:22 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=38a94d599870a6c2 targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:22 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:22 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=f9c0b04e29eb951c targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:22 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:22 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:26 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=aaa0e7a74362e8bc targetNodeType=EN refreshIfEmpty=true
DEBUG[04/18,05:51:26 Z] [34] lookup                                    Discover=Simple   StorageName=PN targetId=0000000000000000 targetType=PN
DEBUG[04/18,05:51:26 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=2
DEBUG[04/18,05:51:26 Z] [33] [Dial] Add new discoverTypedStaticTask    name=PN
DEBUG[04/18,05:51:26 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=ac26a45b768755e4 targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:26 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:26 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=5613ce6c6da3e9ab targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:26 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:26 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=339a12c6d96edae3 targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:26 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:26 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=b10571601dcfdb46 targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:26 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:26 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:30 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=28d58625457feb21 targetNodeType=EN refreshIfEmpty=true
DEBUG[04/18,05:51:30 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=ac26a45b768755e4 targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:30 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:30 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=b3e9deabd14274c5 targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:30 Z] [34] lookup                                    Discover=Simple   StorageName=PN targetId=0000000000000000 targetType=PN
DEBUG[04/18,05:51:30 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=2
DEBUG[04/18,05:51:30 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:30 Z] [33] [Dial] Add new discoverTypedStaticTask    name=PN
DEBUG[04/18,05:51:30 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=4eaf8c7b707afe82 targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:30 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:30 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=0e6bf359c4be78bd targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:30 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:30 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:32 Z] [28] Recalculated downloader QoS values        rtt=20s confidence=1.000 ttl=1m0s
DEBUG[04/18,05:51:34 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=7947bf6d834e3f46 targetNodeType=EN refreshIfEmpty=true
DEBUG[04/18,05:51:34 Z] [34] lookup                                    Discover=Simple   StorageName=PN targetId=0000000000000000 targetType=PN
DEBUG[04/18,05:51:34 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=2
DEBUG[04/18,05:51:34 Z] [33] [Dial] Add new discoverTypedStaticTask    name=PN
DEBUG[04/18,05:51:34 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=ac26a45b768755e4 targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:34 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:34 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=f5c8a516e2863298 targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:34 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:34 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=0b408fa96c285270 targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:34 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:34 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=13c6e5b48d75da3d targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:34 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:34 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:38 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=884cf22704326967 targetNodeType=EN refreshIfEmpty=true
DEBUG[04/18,05:51:38 Z] [34] lookup                                    Discover=Simple   StorageName=PN targetId=0000000000000000 targetType=PN
DEBUG[04/18,05:51:38 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=2
DEBUG[04/18,05:51:38 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=ac26a45b768755e4 targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:38 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:38 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=71baae1973c17a3c targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:38 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:38 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=a8135f2a0406c17a targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:38 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:38 Z] [33] [Dial] Add new discoverTypedStaticTask    name=PN
DEBUG[04/18,05:51:38 Z] [34] lookup start                              Discover=Kademlia StorageName=EN targetID=9bc7c65d8ae27ad7 targetNodeType=EN refreshIfEmpty=false
DEBUG[04/18,05:51:38 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3
DEBUG[04/18,05:51:38 Z] [34] findNewNode: found nodes                  Discover=Table    length=0 nodeType=3

ipc

> net.peerCount
0
2

포트(UDP 32323) 열려있습니다.

3

노드 버전은 v1.8.2 사용중입니다.

4

no discovery 1 로 설정하고 static node 추가했을 때 에러 메시지입니다.

DEBUG[04/19,01:59:07 Z] [28] Recalculated downloader QoS values        rtt=20s confidence=1.000 ttl=1m0s
DEBUG[04/19,01:59:27 Z] [28] Recalculated downloader QoS values        rtt=20s confidence=1.000 ttl=1m0s
DEBUG[04/19,01:59:47 Z] [28] Recalculated downloader QoS values        rtt=20s confidence=1.000 ttl=1m0s
DEBUG[04/19,01:59:57 Z] [40] Adding static node                        node="kni://###@[::]:32323?ntype=en"
INFO[04/19,01:59:57 Z] [33] [Dial] Add dial candidate from static nodes  id=### NodeType=3 ip=:: mainPort=32323 port=[32323]
DEBUG[04/19,01:59:57 Z] [33] [Dial] Dialing node                       id=### addr=[::]:32323
DEBUG[04/19,01:59:57 Z] [33] [Dial] Failed dialing                     task="staticdial ### :::32323" err=EOF
DEBUG[04/19,02:00:07 Z] [28] Recalculated downloader QoS values        rtt=20s confidence=1.000 ttl=1m0s
INFO[04/19,02:00:27 Z] [33] [Dial] Add dial candidate from static nodes  id=### NodeType=3 ip=:: mainPort=32323 port=[32323]
DEBUG[04/19,02:00:27 Z] [33] [Dial] Dialing node                       id=### addr=[::]:32323
DEBUG[04/19,02:00:27 Z] [33] [Dial] Failed dialing                     task="staticdial ### :::32323" err=EOF
DEBUG[04/19,02:00:27 Z] [28] Recalculated downloader QoS values        rtt=20s confidence=1.000 ttl=1m0s
DEBUG[04/19,02:00:47 Z] [28] Recalculated downloader QoS values        rtt=20s confidence=1.000 ttl=1m0s

kni와 id 마스킹했습니다.

5

블록 싱크 중단된 시점의 로그입니다.

INFO[04/15,10:11:41 Z] [5] Inserted a new block                      number=88126750 hash=11ba3f…ba69c6 txs=4     gas=459685    elapsed=55m53.462s processTxs=55m53.226s finalize=66.798ms  validateState=66.843µs  totalWrite=168.966696ms trieWrite=160.016781ms
INFO[04/15,10:11:41 Z] [5] Imported new chain segment                number=88126750 hash=11ba3f…ba69c6 blocks=3  txs=14    elapsed=55m54.603s trieDBSize=31.61kB mgas=1.319    mgasps=0.000   age=55m52s605ms
INFO[04/15,10:11:42 Z] [5] Inserted a new block                      number=88126751 hash=7a0389…50ad4a txs=8     gas=866315    elapsed=616.056ms  processTxs=590.296ms  finalize=3.639ms   validateState=272.497µs totalWrite=21.217468ms  trieWrite=20.655943ms
INFO[04/15,10:11:42 Z] [5] Inserted a new block                      number=88126752 hash=06f083…32ac12 txs=6     gas=1201589   elapsed=114.942ms  processTxs=98.924ms   finalize=4.222ms   validateState=347.042µs totalWrite=10.680315ms  trieWrite=10.120966ms
INFO[04/15,10:11:43 Z] [5] Inserted a new block                      number=88126753 hash=b7aeb7…fca4c6 txs=9     gas=1936448   elapsed=868.795ms  processTxs=837.323ms  finalize=7.867ms   validateState=239.387µs totalWrite=22.84623ms   trieWrite=22.449054ms
INFO[04/15,10:11:43 Z] [5] Inserted a new block                      number=88126754 hash=d99d37…9a609a txs=8     gas=945066    elapsed=183.100ms  processTxs=173.037ms  finalize=2.963ms   validateState=196.037µs totalWrite=6.420218ms   trieWrite=6.011671ms
INFO[04/15,10:11:43 Z] [5] Inserted a new block                      number=88126755 hash=484794…05a31a txs=0     gas=0         elapsed=3.155ms    processTxs=236ns      finalize=560.769µs validateState=7.649µs   totalWrite=2.163285ms   trieWrite=1.934114ms
INFO[04/15,10:11:43 Z] [5] Inserted a new block                      number=88126756 hash=69e09b…46a358 txs=7     gas=347816    elapsed=227.553ms  processTxs=220.452ms  finalize=1.650ms   validateState=59.39µs   totalWrite=4.912404ms   trieWrite=4.546478ms
INFO[04/15,10:11:43 Z] [5] Inserted a new block                      number=88126757 hash=be2f80…b98736 txs=5     gas=502059    elapsed=48.718ms   processTxs=39.077ms   finalize=2.569ms   validateState=108.202µs totalWrite=6.482272ms   trieWrite=6.120685ms
INFO[04/15,10:11:43 Z] [18] Got interrupt, shutting down...
INFO[04/15,10:11:43 Z] [40] WebSocket endpoint closed                 url=ws://0.0.0.0:8552
INFO[04/15,10:11:43 Z] [40] HTTP endpoint closed                      url=http://0.0.0.0:8551
INFO[04/15,10:11:43 Z] [40] IPC endpoint closed                       endpoint=/data/kend/data/klay.ipc
INFO[04/15,10:11:43 Z] [41] Stopping Klaytn protocol
WARN[04/15,10:11:43 Z] [33] ProtocolManager failed to read msg        id=a0404af62fcc442f conn=trusted-staticdial err=EOF
WARN[04/15,10:11:43 Z] [33] ProtocolManager failed to read msg        id=a0404af62fcc442f conn=trusted-staticdial err=EOF
INFO[04/15,10:11:43 Z] [33] Disconnected a multichannel P2P Peer      id=a0404af62fcc442f conn=trusted-staticdial peerID=a0404af62fcc442f peerName=Klaytn/v1.8.2/linux-amd64/go1.15.7            err=EOF
WARN[04/15,10:11:43 Z] [33] ProtocolManager failed to read msg        id=56692ae9309f8c07 conn=trusted-staticdial err=EOF
WARN[04/15,10:11:43 Z] [33] ProtocolManager failed to read msg        id=56692ae9309f8c07 conn=trusted-staticdial err=EOF
INFO[04/15,10:11:43 Z] [33] Disconnected a multichannel P2P Peer      id=56692ae9309f8c07 conn=trusted-staticdial peerID=56692ae9309f8c07 peerName=Klaytn/v1.8.2/linux-amd64/go1.15.7            err=EOF
INFO[04/15,10:11:43 Z] [41] Klaytn protocol stopped
INFO[04/15,10:11:43 Z] [5] Transaction pool stopped
INFO[04/15,10:11:44 Z] [5] Inserted a new block                      number=88126758 hash=7c3457…b8e1aa txs=10    gas=701807    elapsed=504.756ms  processTxs=495.069ms  finalize=2.577ms   validateState=118.571µs totalWrite=6.485898ms   trieWrite=6.122436ms
INFO[04/15,10:11:44 Z] [28] Downloader queue stats                    receiptTasks=0 blockTasks=0  itemSize=5.95kB   throttle=8192
INFO[04/15,10:11:44 Z] [29] Terminated insertWorker
panic: sync: WaitGroup is reused before previous Wait has returned

goroutine 368013586 [running]:
sync.(*WaitGroup).Wait(0xc000393700)
	/usr/local/go/src/sync/waitgroup.go:132 +0xae
github.com/klaytn/klaytn/blockchain.(*BlockChain).Stop(0xc000393400)
	/ext-go/1/src/github.com/klaytn/klaytn/blockchain/blockchain.go:995 +0xca
github.com/klaytn/klaytn/node/cn.(*CN).Stop(0xc000223c20, 0xc000c6cf90, 0xc033eb1f48)
	/ext-go/1/src/github.com/klaytn/klaytn/node/cn/backend.go:673 +0xc6
github.com/klaytn/klaytn/node.(*Node).Stop(0xc000b1e600, 0x0, 0x0)
	/ext-go/1/src/github.com/klaytn/klaytn/node/node.go:590 +0x3a3
created by github.com/klaytn/klaytn/cmd/utils.StartNode.func1
	/ext-go/1/src/github.com/klaytn/klaytn/cmd/utils/cmd.go:55 +0x14a
6 
DEBUG[04/19,08:27:30 Z] [35] Couldn't add port mapping                 protobuf=tcp extport=32323 intport=32323 interface="UPnP or NAT-PMP" err="no UPnP or NAT-PMP router discovered"
DEBUG[04/19,08:27:30 Z] [35] Couldn't add port mapping                 protobuf=tcp extport=32324 intport=32324 interface="UPnP or NAT-PMP" err="no UPnP or NAT-PMP router discovered"

노드 시작 시 메세지입니다.