search

celo-org / celo-blockchain

Official repository for the golang Celo Blockchain
https://celo.org
GNU Lesser General Public License v3.0
552 stars 196 forks source link

p2p: move ping handling into pingLoop goroutine #2280

Closed palango closed 4 months ago

palango commented 4 months ago

Moving the response sending there allows tracking all peer goroutines in the peer WaitGroup.

github-actions[bot] commented 4 months ago

Coverage from tests in ./e2e_test/... for ./consensus/istanbul/... at commit ad77fb4d7c55eb0111025613453128066692f29a

coverage: 48.9% of statements across all listed packages 
coverage:  63.0% of statements in consensus/istanbul
coverage:  40.1% of statements in consensus/istanbul/announce
coverage:  54.6% of statements in consensus/istanbul/backend
coverage:   0.0% of statements in consensus/istanbul/backend/backendtest
coverage:  24.3% of statements in consensus/istanbul/backend/internal/replica
coverage:  61.1% of statements in consensus/istanbul/core
coverage:  45.0% of statements in consensus/istanbul/db
coverage:   0.0% of statements in consensus/istanbul/proxy
coverage:  64.2% of statements in consensus/istanbul/uptime
coverage:  51.8% of statements in consensus/istanbul/validator
coverage:  79.2% of statements in consensus/istanbul/validator/random
github-actions[bot] commented 4 months ago

5880 passed, 2 failed, 44 skipped

Test failures:
  TestPriorityClient: geth

Failed
    les_test.go:121: Initializing geth: [--networkid=42 init ./testdata/clique.json] 
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.010] Maximum peer count                       ETH=175 LES=0 total=175
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.011] Set global gas inflation rate            rate=1.300
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.011] Set global gas cap                       cap=25,000,000
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.011] Allocated cache and file handles         database=/tmp/geth-test4127938684/celo/chaindata cache=16.00MiB handles=16
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.021] Writing custom genesis block 
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.022] Persisted trie from memory database      nodes=4 size=566.00B time="74.322µs" gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=-82.00B
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.023] Successfully wrote genesis state         database=chaindata                               hash=9195f2..122dcd
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.023] Allocated cache and file handles         database=/tmp/geth-test4127938684/celo/lightchaindata cache=16.00MiB handles=16
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.041] Writing custom genesis block 
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.041] Persisted trie from memory database      nodes=4 size=566.00B time="36.559µs" gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=-82.00B
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.042] Successfully wrote genesis state         database=lightchaindata                          hash=9195f2..122dcd
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.042] Allocated cache and file handles         database=/tmp/geth-test4127938684/celo/lightestchaindata cache=16.00MiB handles=16
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.051] Writing custom genesis block 
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.051] Persisted trie from memory database      nodes=4 size=566.00B time="36.609µs" gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=-82.00B
    test_cmd.go:262: (stderr:31) INFO [03-12|13:49:24.052] Successfully wrote genesis state         database=lightestchaindata                       hash=9195f2..122dcd
    les_test.go:130: Importing keys to geth
    test_cmd.go:262: (stderr:32) INFO [03-12|13:49:24.083] Maximum peer count                       ETH=175 LES=0 total=175
    test_cmd.go:262: (stderr:32) INFO [03-12|13:49:24.084] Set global gas inflation rate            rate=1.300
    test_cmd.go:262: (stderr:32) INFO [03-12|13:49:24.084] Set global gas cap                       cap=25,000,000
    les_test.go:99: Starting lightserver with rpc: [--networkid=42 --port=0 --ipcpath geth-1.ipc --allow-insecure-unlock --datadir /tmp/geth-test4127938684 --password ./testdata/password.txt --unlock 0x02f0d131f1f97aef08aec6e3291b957d9efe7105 --mine --miner.validator 0x02f0d131f1f97aef08aec6e3291b957d9efe7105 --tx-fee-recipient 0x02f0d131f1f97aef08aec6e3291b957d9efe7105 --light.serve=100 --light.maxpeers=1 --nodiscover --nat=extip:127.0.0.1 --verbosity=4]
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.298] Maximum peer count                       ETH=175 LES=1 total=176
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.299] FS scan times                            list="68.468µs" set="3.07µs" diff="2.678µs"
    test_cmd.go:262: (stderr:33) WARN [03-12|13:49:24.299] LES server cannot serve old transaction status and cannot connect below les/4 protocol version if transaction lookup index is limited 
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.299] Sanitizing Go's GC trigger               percent=100
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.299] Set global gas inflation rate            rate=1.300
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.299] Set global gas cap                       cap=25,000,000
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.300] Allocated trie memory caches             clean=154.00MiB dirty=256.00MiB
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.300] Allocated cache and file handles         database=/tmp/geth-test4127938684/celo/chaindata cache=512.00MiB handles=524,288
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.340] Chain freezer table opened               database=/tmp/geth-test4127938684/celo/chaindata/ancient table=diffs items=0 size=0.00B
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.342] Chain freezer table opened               database=/tmp/geth-test4127938684/celo/chaindata/ancient table=headers items=0 size=0.00B
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.344] Chain freezer table opened               database=/tmp/geth-test4127938684/celo/chaindata/ancient table=hashes  items=0 size=0.00B
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.346] Chain freezer table opened               database=/tmp/geth-test4127938684/celo/chaindata/ancient table=bodies  items=0 size=0.00B
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.348] Chain freezer table opened               database=/tmp/geth-test4127938684/celo/chaindata/ancient table=receipts items=0 size=0.00B
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.348] Opened ancient database                  database=/tmp/geth-test4127938684/celo/chaindata/ancient readonly=false
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.348] Initialised chain configuration          config="{ChainID: 15 Homestead: 0 DAO: <nil> DAOSupport: false EIP150: 0 EIP155: 0 EIP158: 0 Byzantium: 0 Constantinople: 0 Petersburg: 0 Istanbul: <nil> Churrito: <nil>, Donut: <nil>, Espresso: <nil>, Gingerbread: <nil>, Gingerbread P2: <nil>, Engine: istanbul}"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.349] Setting up Istanbul consensus engine 
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.349] Current full block not old enough        number=0 hash=9195f2..122dcd delay=90000
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.373] Initialising Ethereum protocol           versions=[67] network=42 dbversion=<nil>
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.374] Loading Last State: 0 
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.374] Loaded most recent local header          number=0 hash=9195f2..122dcd td=1 age=54y11mo3w
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.374] Loaded most recent local full block      number=0 hash=9195f2..122dcd td=1 age=54y11mo3w
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.374] Loaded most recent local fast block      number=0 hash=9195f2..122dcd td=1 age=54y11mo3w
    test_cmd.go:262: (stderr:33) WARN [03-12|13:49:24.374] Failed to load snapshot, regenerating    err="missing or corrupted snapshot"
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.374] Rebuilding state snapshot 
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.374] Journalled generator progress            progress=empty
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.375] Start snapshot generation                root=8a7a77..f86ff6
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.375] Resuming state snapshot generation       root=8a7a77..f86ff6 accounts=0 slots=0 storage=0.00B elapsed="263.674µs"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.375] Regenerated state range                  kind=storage prefix=0x6fc8292a2675fd2df398d2f757c44afe1b96e4c7ba26dac7ed67cdef77799ef404 root=09f508..8cb885 last=0x count=1 created=1 updated=0 untouched=0 deleted=0
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.375] Regenerated state range                  kind=account prefix=0x61 root=8a7a77..f86ff6 last=0x count=2 created=2 updated=0 untouched=0 deleted=0
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.375] Journalled generator progress            progress=done
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.375] Generated state snapshot                 accounts=2 slots=1 storage=230.00B elapsed="696.26µs"
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.375] Error invoking evm function: EVM call failure to=0x000000000000000000000000000000000000ce10 method=getAddressFor input=0xdd9272338b91d837e1684f7353d73b6197230894243cf869282f722841df96b441303f37 maxgas=100,000 err="execution reverted"            message="No Implementation set"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.375] Registry contract not yet deployed       function=blockGasLimit registryId=0x8b91d837e1684f7353d73b6197230894243cf869282f722841df96b441303f37
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.375] Error calling blockGasLimit              err="Registry not deployed"         contract=0x8b91d837e1684f7353d73b6197230894243cf869282f722841df96b441303f37
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.375] Error invoking evm function: EVM call failure to=0x000000000000000000000000000000000000ce10 method=getAddressFor input=0xdd92723348766a30bcca8b3c8b03b4e4b1f6510aee73f7b41aa6c7578a97040d20334f42 maxgas=100,000 err="execution reverted"            message="No Implementation set"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.375] Registry contract not yet deployed       function=gasPriceMinimumFloor registryId=0x48766a30bcca8b3c8b03b4e4b1f6510aee73f7b41aa6c7578a97040d20334f42
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.375] Error invoking evm function: EVM call failure to=0x000000000000000000000000000000000000ce10 method=getAddressFor input=0xdd9272338b91d837e1684f7353d73b6197230894243cf869282f722841df96b441303f37 maxgas=100,000 err="execution reverted"            message="No Implementation set"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.375] Registry contract not yet deployed       function=intrinsicGasForAlternativeFeeCurrency registryId=0x8b91d837e1684f7353d73b6197230894243cf869282f722841df96b441303f37
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.375] Error invoking evm function: EVM call failure to=0x000000000000000000000000000000000000ce10 method=getAddressFor input=0xdd9272338f897d9543fdc9082789208180c3e3d11f7473aaef3e249ab0020ea0c761c1b6 maxgas=100,000 err="execution reverted"            message="No Implementation set"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.375] Registry contract not yet deployed       function=getWhitelist                          registryId=0x8f897d9543fdc9082789208180c3e3d11f7473aaef3e249ab0020ea0c761c1b6
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.375] getWhitelist invocation failed           err="Registry not deployed"
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.375] Error invoking evm function: EVM call failure to=0x000000000000000000000000000000000000ce10 method=getAddressFor input=0xdd927233d7e89ade8430819f08bf97a087285824af3351ee12d72a2d132b0c6c0687bfaf maxgas=100,000 err="execution reverted"            message="No Implementation set"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.375] Reinjecting stale transactions           count=0
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.376] Regenerated local transaction journal    transactions=0 accounts=0
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.388] Allocated fast sync bloom                size=512.00MiB
    test_cmd.go:262: (stderr:33) WARN [03-12|13:49:24.388] Error reading unclean shutdown markers   error="leveldb: not found"
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.388] Allocated cache and file handles         database=/tmp/geth-test4127938684/celo/les.server cache=16.00MiB  handles=16
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.388] Initialized state bloom                  items=5 errorrate=0.000 elapsed="322.348µs"
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.416] Checkpoint oracle is not enabled 
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.416] Starting peer-to-peer node               instance=celo/v1.8.2-unstable/linux-amd64/go1.19.13
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.428] TCP listener up                          addr=[::]:32889
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.428] Mapped network port                      proto=tcp extport=32889 intport=32889 interface=ExtIP(127.0.0.1)
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.430] IPCs registered                          namespaces=admin,debug,web3,eth,txpool,personal,istanbul,miner,net,les
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.430] IPC endpoint opened                      url=/tmp/geth-test4127938684/geth-1.ipc
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.430] New local node record                    seq=1,710,251,364,429 id=65777318fbd7c3f1 ip=127.0.0.1 udp=0 tcp=32889
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.430] Started P2P networking                   self="enode://d8fa97b64e0ce2060ce7c44e5f68f2333edf35f754f6a4d01562b96232f6d469409dc0ebab87ad63d7d098005a423bb08bb4be9a6087506a9d35e9789c819869@127.0.0.1:32889?discport=0" maxdialed=58 maxinbound=118
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.430] Error invoking evm function: EVM call failure to=0x000000000000000000000000000000000000ce10 method=getAddressFor input=0xdd927233235a6f54090e9b94aa4e585a699c4375a2ff8f572c68114d138f0ed121527849 maxgas=100,000 err="execution reverted"            message="No Implementation set"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.430] Registry contract not yet deployed       function=getElectableValidators                registryId=0x235a6f54090e9b94aa4e585a699c4375a2ff8f572c68114d138f0ed121527849
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.430] Snapshot is nil, creating from genesis 
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.527] Unlocked account                         address=0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.527] Starting istanbul.Engine validating 
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.527] Open roundstate db                       func=newRoundStateDB type=roundStateDB rsdb_path=/tmp/geth-test4127938684/celo/roundstates
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.527] Allocated cache and file handles         database=/tmp/geth-test4127938684/celo/roundstates cache=512.00MiB handles=500
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.527] NewWork called, acquiring core lock      func=NewWork
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.538] Creating new RoundState                  address=0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105 func=createRoundState cur_seq=0 cur_epoch=0 cur_round=-1 des_round=-1 state="Accept request" address=0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105 reason="No storedView found"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.539] Posting FinalCommittedEvent              func=NewWork
    test_cmd.go:262: (stderr:33) WARN [03-12|13:49:24.539] New sequence should be larger than current sequence address=0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105 func=startNewSequence tag=stateTransition head_block=0 head_block_hash=9195f2..122dcd cur_seq=1 cur_epoch=1 cur_round=0  des_round=0  state="Accept request" address=0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.539] Error invoking evm function: EVM call failure to=0x000000000000000000000000000000000000ce10 method=getAddressFor input=0xdd9272338b91d837e1684f7353d73b6197230894243cf869282f722841df96b441303f37 maxgas=100,000 err="execution reverted"            message="No Implementation set"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.539] Registry contract not yet deployed       function=blockGasLimit                         registryId=0x8b91d837e1684f7353d73b6197230894243cf869282f722841df96b441303f37
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.539] Error calling blockGasLimit              err="Registry not deployed"         contract=0x8b91d837e1684f7353d73b6197230894243cf869282f722841df96b441303f37
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.539] Error invoking evm function: EVM call failure to=0x000000000000000000000000000000000000ce10 method=getAddressFor input=0xdd9272338b91d837e1684f7353d73b6197230894243cf869282f722841df96b441303f37 maxgas=100,000 err="execution reverted"            message="No Implementation set"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.539] Registry contract not yet deployed       function=intrinsicGasForAlternativeFeeCurrency registryId=0x8b91d837e1684f7353d73b6197230894243cf869282f722841df96b441303f37
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.539] Error invoking evm function: EVM call failure to=0x000000000000000000000000000000000000ce10 method=getAddressFor input=0xdd9272338f897d9543fdc9082789208180c3e3d11f7473aaef3e249ab0020ea0c761c1b6 maxgas=100,000 err="execution reverted"            message="No Implementation set"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.539] Registry contract not yet deployed       function=getWhitelist                          registryId=0x8f897d9543fdc9082789208180c3e3d11f7473aaef3e249ab0020ea0c761c1b6
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.539] getWhitelist invocation failed           err="Registry not deployed"
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.539] Error invoking evm function: EVM call failure to=0x000000000000000000000000000000000000ce10 method=getAddressFor input=0xdd927233d7e89ade8430819f08bf97a087285824af3351ee12d72a2d132b0c6c0687bfaf maxgas=100,000 err="execution reverted"            message="No Implementation set"
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.539] Error invoking evm function: EVM call failure to=0x000000000000000000000000000000000000ce10 method=getAddressFor input=0xdd92723302dfe2d0485b616b61db1800f30f4a14b26754b328fa09ba4ec73ee7276766cc maxgas=100,000 err="execution reverted"            message="No Implementation set"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.539] Registry address lookup failed           err="Registry not deployed"         contract=0x02dfe2d0485b616b61db1800f30f4a14b26754b328fa09ba4ec73ee7276766cc
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.539] Error invoking evm function: EVM call failure to=0x000000000000000000000000000000000000ce10 method=getAddressFor input=0xdd927233d7e89ade8430819f08bf97a087285824af3351ee12d72a2d132b0c6c0687bfaf maxgas=100,000 err="execution reverted"            message="No Implementation set"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.539] Registry contract not yet deployed       function=totalSupply                           registryId=0xd7e89ade8430819f08bf97a087285824af3351ee12d72a2d132b0c6c0687bfaf
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.539] Error invoking evm function: EVM call failure to=0x000000000000000000000000000000000000ce10 method=getAddressFor input=0xdd9272338b91d837e1684f7353d73b6197230894243cf869282f722841df96b441303f37 maxgas=100,000 err="execution reverted"            message="No Implementation set"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.539] Registry contract not yet deployed       function=blockGasLimit                         registryId=0x8b91d837e1684f7353d73b6197230894243cf869282f722841df96b441303f37
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.539] Error calling blockGasLimit              err="Registry not deployed"         contract=0x8b91d837e1684f7353d73b6197230894243cf869282f722841df96b441303f37
    test_cmd.go:262: (stderr:33) ERROR[03-12|13:49:24.539] Error invoking evm function: EVM call failure to=0x000000000000000000000000000000000000ce10 method=getAddressFor input=0xdd92723348766a30bcca8b3c8b03b4e4b1f6510aee73f7b41aa6c7578a97040d20334f42 maxgas=100,000 err="execution reverted"            message="No Implementation set"
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.539] Registry contract not yet deployed       function=updateGasPriceMinimum                 registryId=0x48766a30bcca8b3c8b03b4e4b1f6510aee73f7b41aa6c7578a97040d20334f42
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:24.539] Finalized                                func=Finalize         block=1 epochSize=30000 duration="166.004µs" lastInEpoch=false
    test_cmd.go:262: (stderr:33) WARN [03-12|13:49:24.539] Block sealing failed                     err="not an elected validator"
    test_cmd.go:262: (stderr:33) INFO [03-12|13:49:24.539] Commit new mining work                   number=1 txs=0 gas=0 fees=0 elapsed="834.752µs"
    les_test.go:121: Initializing geth: [--networkid=42 init ./testdata/clique.json] 
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.796] Maximum peer count                       ETH=175 LES=0 total=175
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.797] Set global gas inflation rate            rate=1.300
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.797] Set global gas cap                       cap=25,000,000
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.797] Allocated cache and file handles         database=/tmp/geth-test4014003058/celo/chaindata cache=16.00MiB handles=16
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.867] Writing custom genesis block 
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.868] Persisted trie from memory database      nodes=4 size=566.00B time="68.465µs" gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=-82.00B
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.868] Successfully wrote genesis state         database=chaindata                               hash=9195f2..122dcd
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.868] Allocated cache and file handles         database=/tmp/geth-test4014003058/celo/lightchaindata cache=16.00MiB handles=16
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.894] Writing custom genesis block 
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.895] Persisted trie from memory database      nodes=4 size=566.00B time="30.305µs" gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=-82.00B
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.895] Successfully wrote genesis state         database=lightchaindata                          hash=9195f2..122dcd
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.895] Allocated cache and file handles         database=/tmp/geth-test4014003058/celo/lightestchaindata cache=16.00MiB handles=16
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.902] Writing custom genesis block 
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.903] Persisted trie from memory database      nodes=4 size=566.00B time="29.461µs" gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=-82.00B
    test_cmd.go:262: (stderr:34) INFO [03-12|13:49:24.903] Successfully wrote genesis state         database=lightestchaindata                       hash=9195f2..122dcd
    les_test.go:99: Starting freeCli with rpc: [--networkid=42 --port=0 --ipcpath geth-2.ipc --datadir /tmp/geth-test4014003058 --nodiscover --syncmode=light --nat=extip:127.0.0.1 --verbosity=4]
    test_cmd.go:262: (stderr:35) INFO [03-12|13:49:24.939] Dropping default light client cache      provided=1024 updated=128
    test_cmd.go:262: (stderr:35) INFO [03-12|13:49:24.941] Maximum peer count                       ETH=0 LES=10 total=175
    test_cmd.go:262: (stderr:35) DEBUG[03-12|13:49:24.942] FS scan times                            list="48.687µs" set=393ns diff=910ns
    test_cmd.go:262: (stderr:35) DEBUG[03-12|13:49:24.942] Sanitizing Go's GC trigger               percent=100
    test_cmd.go:262: (stderr:35) INFO [03-12|13:49:24.942] Set global gas inflation rate            rate=1.300
    test_cmd.go:262: (stderr:35) INFO [03-12|13:49:24.942] Set global gas cap                       cap=25,000,000
    test_cmd.go:262: (stderr:35) INFO [03-12|13:49:24.942] Allocated cache and file handles         database=/tmp/geth-test4014003058/celo/lightchaindata cache=64.00MiB handles=524,288
    test_cmd.go:262: (stderr:35) INFO [03-12|13:49:24.994] Allocated cache and file handles         database=/tmp/geth-test4014003058/celo/les.client cache=16.00MiB handles=16
    test_cmd.go:262: (stderr:35) INFO [03-12|13:49:25.005] Initialised chain configuration          config="{ChainID: 15 Homestead: 0 DAO: <nil> DAOSupport: false EIP150: 0 EIP155: 0 EIP158: 0 Byzantium: 0 Constantinople: 0 Petersburg: 0 Istanbul: <nil> Churrito: <nil>, Donut: <nil>, Espresso: <nil>, Gingerbread: <nil>, Gingerbread P2: <nil>, Engine: istanbul}"
    test_cmd.go:262: (stderr:35) DEBUG[03-12|13:49:25.005] Setting up Istanbul consensus engine 
    test_cmd.go:262: (stderr:35) INFO [03-12|13:49:25.025] Loaded most recent local header          number=0 hash=9195f2..122dcd td=1 age=54y11mo3w
    test_cmd.go:262: (stderr:35) INFO [03-12|13:49:25.025] Checkpoint oracle is not enabled 
    test_cmd.go:262: (stderr:35) WARN [03-12|13:49:25.025] Error reading unclean shutdown markers   error="leveldb: not found"
    test_cmd.go:262: (stderr:35) INFO [03-12|13:49:25.026] Starting peer-to-peer node               instance=celo/v1.8.2-unstable/linux-amd64/go1.19.13
    test_cmd.go:262: (stderr:35) INFO [03-12|13:49:25.034] Mapped network port                      proto=tcp extport=45863 intport=45863 interface=ExtIP(127.0.0.1)
    test_cmd.go:262: (stderr:35) DEBUG[03-12|13:49:25.034] TCP listener up                          addr=[::]:45863
    test_cmd.go:262: (stderr:35) DEBUG[03-12|13:49:25.036] IPCs registered                          namespaces=admin,debug,web3,eth,txpool,personal,istanbul,les,net,vflux
    test_cmd.go:262: (stderr:35) INFO [03-12|13:49:25.036] IPC endpoint opened                      url=/tmp/geth-test4014003058/geth-2.ipc
    test_cmd.go:262: (stderr:35) WARN [03-12|13:49:25.036] Light client mode is an experimental feature 
    test_cmd.go:262: (stderr:35) INFO [03-12|13:49:25.036] New local node record                    seq=1,710,251,365,035 id=966a2ac065644803 ip=127.0.0.1 udp=0 tcp=45863
    test_cmd.go:262: (stderr:35) INFO [03-12|13:49:25.036] Started P2P networking                   self="enode://3ede65c6e8632fbe0b56f8252f2be28820fa106f8c40c1a691b4ca77c5a0f350d3a1d8f2b39514b3fb7f73ef66ed1f1504e1e89f903c0f00c97c6a55ab5ba28b@127.0.0.1:45863?discport=0" maxdialed=58 maxinbound=117
    les_test.go:37: freeCli.addPeer(lightserver)
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:25.407] Served admin_nodeInfo                    reqid=1 t="387.421µs"
    test_cmd.go:262: (stderr:35) DEBUG[03-12|13:49:25.408] Served admin_subscribe                   reqid=1 t="58.67µs"
    test_cmd.go:262: (stderr:35) DEBUG[03-12|13:49:25.409] Served admin_addPeer                     reqid=2 t="150.956µs"
    test_cmd.go:262: (stderr:35) DEBUG[03-12|13:49:25.411] Adding p2p peer                          peercount=1 id=65777318fbd7c3f1 conn=staticdial addr=127.0.0.1:32889 name=celo/v1.8.2-unstable...
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:25.411] Adding p2p peer                          peercount=1 id=966a2ac065644803 conn=inbound addr=127.0.0.1:39424 name=celo/v1.8.2-unstable...
    test_cmd.go:262: (stderr:35) DEBUG[03-12|13:49:25.411] Light Ethereum peer connected            id=65777318fbd7c3f1 conn=staticdial name=celo/v1.8.2-unstable...
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:25.411] Light Ethereum peer connected            id=966a2ac065644803 conn=inbound name=celo/v1.8.2-unstable...
    test_cmd.go:262: (stderr:35) DEBUG[03-12|13:49:25.411] Node entered                             set=connected id=65777318fbd7c3f1 count=1
    test_cmd.go:262: (stderr:35) DEBUG[03-12|13:49:25.412] Requesting etherbase for peer            id=65777318fbd7c3f1 conn=staticdial enode=65777318fbd7c3f1db1bc7a963ddb0da3b0a771ae6129aa2ccc7b8684ca4f371
    test_cmd.go:262: (stderr:35) DEBUG[03-12|13:49:25.412] Received new announce                    peer=65777318fbd7c3f1 number=0 hash=9195f2..122dcd reorg=0
    les_test.go:50: freeCli received event: type=add, peer=65777318fbd7c3f1db1bc7a963ddb0da3b0a771ae6129aa2ccc7b8684ca4f371
    test_cmd.go:262: (stderr:35) DEBUG[03-12|13:49:25.412] Served admin_unsubscribe                 reqid=3 t="45.144µs"
    les_test.go:121: Initializing geth: [--networkid=42 init ./testdata/clique.json] 
    test_cmd.go:262: (stderr:35) DEBUG[03-12|13:49:25.412] Served admin_peers                       reqid=4 t="182.737µs"
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:25.449] Maximum peer count                       ETH=175 LES=0 total=175
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:25.450] Set global gas inflation rate            rate=1.300
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:25.450] Set global gas cap                       cap=25,000,000
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:25.450] Allocated cache and file handles         database=/tmp/geth-test1482377665/celo/chaindata cache=16.00MiB handles=16
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:27.589] Writing custom genesis block 
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:27.590] Persisted trie from memory database      nodes=4 size=566.00B time="58.569µs" gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=-82.00B
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:27.590] Successfully wrote genesis state         database=chaindata                               hash=9195f2..122dcd
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:27.590] Allocated cache and file handles         database=/tmp/geth-test1482377665/celo/lightchaindata cache=16.00MiB handles=16
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:27.597] Writing custom genesis block 
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:27.597] Persisted trie from memory database      nodes=4 size=566.00B time="24.453µs" gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=-82.00B
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:27.598] Successfully wrote genesis state         database=lightchaindata                          hash=9195f2..122dcd
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:27.598] Allocated cache and file handles         database=/tmp/geth-test1482377665/celo/lightestchaindata cache=16.00MiB handles=16
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:27.656] Writing custom genesis block 
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:27.671] Persisted trie from memory database      nodes=4 size=566.00B time="51.184µs" gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=-82.00B
    test_cmd.go:262: (stderr:36) INFO [03-12|13:49:27.671] Successfully wrote genesis state         database=lightestchaindata                       hash=9195f2..122dcd
    les_test.go:99: Starting prioCli with rpc: [--networkid=42 --port=0 --ipcpath geth-3.ipc --datadir /tmp/geth-test1482377665 --nodiscover --syncmode=light --nat=extip:127.0.0.1 --verbosity=4]
    test_cmd.go:262: (stderr:37) INFO [03-12|13:49:27.700] Dropping default light client cache      provided=1024 updated=128
    test_cmd.go:262: (stderr:37) INFO [03-12|13:49:27.702] Maximum peer count                       ETH=0 LES=10 total=175
    test_cmd.go:262: (stderr:37) DEBUG[03-12|13:49:27.703] FS scan times                            list="31.136µs" set=329ns diff=962ns
    test_cmd.go:262: (stderr:37) DEBUG[03-12|13:49:27.703] Sanitizing Go's GC trigger               percent=100
    test_cmd.go:262: (stderr:37) INFO [03-12|13:49:27.703] Set global gas inflation rate            rate=1.300
    test_cmd.go:262: (stderr:37) INFO [03-12|13:49:27.703] Set global gas cap                       cap=25,000,000
    test_cmd.go:262: (stderr:37) INFO [03-12|13:49:27.703] Allocated cache and file handles         database=/tmp/geth-test1482377665/celo/lightchaindata cache=64.00MiB handles=524,288
    test_cmd.go:262: (stderr:37) INFO [03-12|13:49:30.721] Allocated cache and file handles         database=/tmp/geth-test1482377665/celo/les.client cache=16.00MiB handles=16
    test_cmd.go:262: (stderr:37) INFO [03-12|13:49:32.387] Initialised chain configuration          config="{ChainID: 15 Homestead: 0 DAO: <nil> DAOSupport: false EIP150: 0 EIP155: 0 EIP158: 0 Byzantium: 0 Constantinople: 0 Petersburg: 0 Istanbul: <nil> Churrito: <nil>, Donut: <nil>, Espresso: <nil>, Gingerbread: <nil>, Gingerbread P2: <nil>, Engine: istanbul}"
    test_cmd.go:262: (stderr:37) DEBUG[03-12|13:49:32.387] Setting up Istanbul consensus engine 
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:32.542] Timed out, trying to wait for next round address=0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105 func=handleTimeoutAndMoveToNextRound timed_out_seq=1 timed_out_round=0 cur_seq=1 cur_epoch=1 cur_round=0  des_round=0  state="Accept request" address=0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:32.542] Round Change: Waiting for desired round  address=0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105 func=waitForDesiredRound             new_desired_round=1 cur_seq=1 cur_epoch=1 cur_round=0  des_round=0  state="Accept request" address=0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:32.543] Failed to decode message from payload    address=0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105 func=handleMsg                       cur_seq=1 cur_epoch=1 cur_round=0  des_round=1  state="Waiting for new round" address=0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105 err="not an elected validator 0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105"
    test_cmd.go:262: (stderr:33) WARN [03-12|13:49:32.543] Error in handling istanbul message       address=0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105 func=handleEvents                    cur_seq=1 cur_epoch=1 cur_round=0  des_round=1  state="Waiting for new round" address=0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105 err="not an elected validator 0x02F0d131F1f97aef08aEc6E3291B957d9Efe7105"
    les_test.go:115: prioCli rpc connect to /tmp/geth-test1482377665/geth-3.ipc: dial unix /tmp/geth-test1482377665/geth-3.ipc: connect: no such file or directory
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:32.685] Light Ethereum message handling failed   id=966a2ac065644803 conn=inbound err=EOF
    test_cmd.go:262: (stderr:33) DEBUG[03-12|13:49:32.685] Removing p2p peer                        peercount=0 id=966a2ac065644803 duration=7.273s      req=false err=EOF
  TestMiner: miner
Failed
/runner/_work/celo-blockchain/celo-blockchain/consensus/consensustest/mockprotocol.go:384 +0x181
/runner/_work/celo-blockchain/celo-blockchain/miner/worker.go:466 +0xb3
/runner/_work/celo-blockchain/celo-blockchain/miner/worker.go:308 +0x515
/runner/_work/celo-blockchain/celo-blockchain/miner/worker.go:410 +0x3b
/runner/_work/celo-blockchain/celo-blockchain/miner/worker.go:409 +0x1aa
This test report was produced by the test-summary action.  Made with ❤️ in Cambridge.