Skip to content

Commit

Permalink
Problem: tests fail randomly on CI
Browse files Browse the repository at this point in the history 
Problem: migration tests curl times out on CI sometimes

Solution: provide option to skip tests with env variable
set in .travis.yml

Problem: downloader_test is unpredictable

Solution: copy EF's implementation (shameless!)

Problem: non idiomatic range loop

Solution: make idiomatic

Problem: peer test fails sometimes (times out)

Solution: remove done channel  and create
errProtocolReturn error (per EF)

Rel ethereumproject#245
  • Loading branch information
@whilei
whilei committed Jun 5, 2017
1 parent 402c170 commit d49adb8
Show file tree
Hide file tree
Showing 10 changed files with 93 additions and 62 deletions.
10 changes: 10 additions & 0 deletions cmd/geth/migrate_datadir.bats
View file
Expand Up @@ -5,6 +5,16 @@

setup() {

# Optionally skip migration tests.
# These depend on curl download various geth versions, which sometimes times out
# in the CI env. If changes are made to or around migration-related code, this
# env variable should NOT be set. However, if these tests have run and passed
# consistently multiple times in the CI environment, it may be considered safe
# to skip them to avoid CI false negatives.
if [ "$SKIP_MIGRATION_TESTS" ]; then
skip "skipping 3.4 migration change tests for CI environment"
fi

# A temporary place to hold current test datadir.
DATA_DIR=`mktemp -d`

Expand Down
3 changes: 2 additions & 1 deletion eth/api.go
View file
Expand Up @@ -159,7 +159,8 @@ func (s *PublicEthereumAPI) Hashrate() *rpc.HexNumber {
// - pulledStates: number of state entries processed until now
// - knownStates: number of known state entries that still need to be pulled
func (s *PublicEthereumAPI) Syncing() (interface{}, error) {
origin, current, height, pulled, known := s.e.Downloader().Progress()
prog := s.e.Downloader().Progress()
origin, current, height, pulled, known := prog.StartingBlock, prog.CurrentBlock, prog.HighestBlock, prog.PulledStates, prog.KnownStates

// Return not syncing if the synchronisation already completed
if current >= height {
Expand Down
3 changes: 2 additions & 1 deletion eth/downloader/api.go
View file
Expand Up @@ -55,7 +55,8 @@ func (api *PublicDownloaderAPI) run() {
switch event.Data.(type) {
case StartEvent:
result := &SyncingResult{Syncing: true}
result.Status.Origin, result.Status.Current, result.Status.Height, result.Status.Pulled, result.Status.Known = api.d.Progress()
prog := api.d.Progress()
result.Status.Origin, result.Status.Current, result.Status.Height, result.Status.Pulled, result.Status.Known = prog.StartingBlock, prog.CurrentBlock, prog.HighestBlock, prog.PulledStates, prog.KnownStates
notification = result
case DoneEvent, FailedEvent:
notification = false
Expand Down
10 changes: 8 additions & 2 deletions eth/downloader/downloader.go
View file
Expand Up @@ -225,7 +225,7 @@ func New(stateDb ethdb.Database, mux *event.TypeMux, hasHeader headerCheckFn, ha
// In addition, during the state download phase of fast synchronisation the number
// of processed and the total number of known states are also returned. Otherwise
// these are zero.
func (d *Downloader) Progress() (uint64, uint64, uint64, uint64, uint64) {
func (d *Downloader) Progress() SyncProgress {
// Fetch the pending state count outside of the lock to prevent unforeseen deadlocks
pendingStates := uint64(d.queue.PendingNodeData())

Expand All @@ -242,7 +242,13 @@ func (d *Downloader) Progress() (uint64, uint64, uint64, uint64, uint64) {
case LightSync:
current = d.headHeader().Number.Uint64()
}
return d.syncStatsChainOrigin, current, d.syncStatsChainHeight, d.syncStatsStateDone, d.syncStatsStateDone + pendingStates
return SyncProgress{
StartingBlock: d.syncStatsChainOrigin,
CurrentBlock: current,
HighestBlock: d.syncStatsChainHeight,
PulledStates: d.syncStatsStateDone,
KnownStates: d.syncStatsStateDone + pendingStates,
}
}

// Synchronising returns whether the downloader is currently retrieving blocks.
Expand Down
99 changes: 50 additions & 49 deletions eth/downloader/downloader_test.go
View file
Expand Up @@ -1405,8 +1405,8 @@ func testSyncProgress(t *testing.T, protocol int, mode SyncMode) {
<-progress
}
// Retrieve the sync progress and ensure they are zero (pristine sync)
if origin, current, latest, _, _ := tester.downloader.Progress(); origin != 0 || current != 0 || latest != 0 {
t.Fatalf("Pristine progress mismatch: have %v/%v/%v, want %v/%v/%v", origin, current, latest, 0, 0, 0)
if progress := tester.downloader.Progress(); progress.StartingBlock != 0 || progress.CurrentBlock != 0 || progress.HighestBlock != 0 {
t.Fatalf("Pristine progress mismatch: have %v/%v/%v, want %v/%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, 0, 0, 0)
}
// Synchronise half the blocks and check initial progress
tester.newPeer("peer-half", protocol, hashes[targetBlocks/2:], headers, blocks, receipts)
Expand All @@ -1420,8 +1420,8 @@ func testSyncProgress(t *testing.T, protocol int, mode SyncMode) {
}
}()
<-starting
if origin, current, latest, _, _ := tester.downloader.Progress(); origin != 0 || current != 0 || latest != uint64(targetBlocks/2+1) {
t.Fatalf("Initial progress mismatch: have %v/%v/%v, want %v/%v/%v", origin, current, latest, 0, 0, targetBlocks/2+1)
if progress := tester.downloader.Progress(); progress.StartingBlock != 0 || progress.CurrentBlock != 0 || progress.HighestBlock != uint64(targetBlocks/2+1) {
t.Fatalf("Initial progress mismatch: have %v/%v/%v, want %v/%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, 0, 0, targetBlocks/2+1)
}
progress <- struct{}{}
pending.Wait()
Expand All @@ -1437,18 +1437,15 @@ func testSyncProgress(t *testing.T, protocol int, mode SyncMode) {
}
}()
<-starting
if origin, current, latest, _, _ := tester.downloader.Progress(); origin != uint64(targetBlocks/2+1) || current != uint64(targetBlocks/2+1) || latest != uint64(targetBlocks) {
t.Fatalf("Completing progress mismatch: have %v/%v/%v, want %v/%v/%v", origin, current, latest, targetBlocks/2+1, targetBlocks/2+1, targetBlocks)
if progress := tester.downloader.Progress(); progress.StartingBlock != uint64(targetBlocks/2+1) || progress.CurrentBlock != uint64(targetBlocks/2+1) || progress.HighestBlock != uint64(targetBlocks) {
t.Fatalf("Completing progress mismatch: have %v/%v/%v, want %v/%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, targetBlocks/2+1, targetBlocks/2+1, targetBlocks)
}
progress <- struct{}{}
pending.Wait()

// Wait to make sure all data is set after sync
time.Sleep(400 * time.Millisecond)

// Check final progress after successful sync
if origin, current, latest, _, _ := tester.downloader.Progress(); origin != uint64(targetBlocks/2+1) || current != uint64(targetBlocks) || latest != uint64(targetBlocks) {
t.Fatalf("Final progress mismatch: have %v/%v/%v, want %v/%v/%v", origin, current, latest, targetBlocks/2+1, targetBlocks, targetBlocks)
if progress := tester.downloader.Progress(); progress.StartingBlock != uint64(targetBlocks/2+1) || progress.CurrentBlock != uint64(targetBlocks) || progress.HighestBlock != uint64(targetBlocks) {
t.Fatalf("Final progress mismatch: have %v/%v/%v, want %v/%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, targetBlocks/2+1, targetBlocks, targetBlocks)
}
}

Expand Down Expand Up @@ -1481,8 +1478,8 @@ func testForkedSyncProgress(t *testing.T, protocol int, mode SyncMode) {
<-progress
}
// Retrieve the sync progress and ensure they are zero (pristine sync)
if origin, current, latest, _, _ := tester.downloader.Progress(); origin != 0 || current != 0 || latest != 0 {
t.Fatalf("Pristine progress mismatch: have %v/%v/%v, want %v/%v/%v", origin, current, latest, 0, 0, 0)
if progress := tester.downloader.Progress(); progress.StartingBlock != 0 || progress.CurrentBlock != 0 || progress.HighestBlock != 0 {
t.Fatalf("Pristine progress mismatch: have %v/%v/%v, want %v/%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, 0, 0, 0)
}
// Synchronise with one of the forks and check progress
tester.newPeer("fork A", protocol, hashesA, headersA, blocksA, receiptsA)
Expand All @@ -1496,8 +1493,8 @@ func testForkedSyncProgress(t *testing.T, protocol int, mode SyncMode) {
}
}()
<-starting
if origin, current, latest, _, _ := tester.downloader.Progress(); origin != 0 || current != 0 || latest != uint64(len(hashesA)-1) {
t.Fatalf("Initial progress mismatch: have %v/%v/%v, want %v/%v/%v", origin, current, latest, 0, 0, len(hashesA)-1)
if progress := tester.downloader.Progress(); progress.StartingBlock != 0 || progress.CurrentBlock != 0 || progress.HighestBlock != uint64(len(hashesA)-1) {
t.Fatalf("Initial progress mismatch: have %v/%v/%v, want %v/%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, 0, 0, len(hashesA)-1)
}
progress <- struct{}{}
pending.Wait()
Expand All @@ -1516,18 +1513,15 @@ func testForkedSyncProgress(t *testing.T, protocol int, mode SyncMode) {
}
}()
<-starting
if origin, current, latest, _, _ := tester.downloader.Progress(); origin != uint64(common) || current != uint64(len(hashesA)-1) || latest != uint64(len(hashesB)-1) {
t.Fatalf("Forking progress mismatch: have %v/%v/%v, want %v/%v/%v", origin, current, latest, common, len(hashesA)-1, len(hashesB)-1)
if progress := tester.downloader.Progress(); progress.StartingBlock != uint64(common) || progress.CurrentBlock != uint64(len(hashesA)-1) || progress.HighestBlock != uint64(len(hashesB)-1) {
t.Fatalf("Forking progress mismatch: have %v/%v/%v, want %v/%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, common, len(hashesA)-1, len(hashesB)-1)
}
progress <- struct{}{}
pending.Wait()

// Wait to make sure all data is set after sync
time.Sleep(400 * time.Millisecond)

// Check final progress after successful sync
if origin, current, latest, _, _ := tester.downloader.Progress(); origin != uint64(common) || current != uint64(len(hashesB)-1) || latest != uint64(len(hashesB)-1) {
t.Fatalf("Final progress mismatch: have %v/%v/%v, want %v/%v/%v", origin, current, latest, common, len(hashesB)-1, len(hashesB)-1)
if progress := tester.downloader.Progress(); progress.StartingBlock != uint64(common) || progress.CurrentBlock != uint64(len(hashesB)-1) || progress.HighestBlock != uint64(len(hashesB)-1) {
t.Fatalf("Final progress mismatch: have %v/%v/%v, want %v/%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, common, len(hashesB)-1, len(hashesB)-1)
}
}

Expand Down Expand Up @@ -1560,8 +1554,8 @@ func testFailedSyncProgress(t *testing.T, protocol int, mode SyncMode) {
<-progress
}
// Retrieve the sync progress and ensure they are zero (pristine sync)
if origin, current, latest, _, _ := tester.downloader.Progress(); origin != 0 || current != 0 || latest != 0 {
t.Fatalf("Pristine progress mismatch: have %v/%v/%v, want %v/%v/%v", origin, current, latest, 0, 0, 0)
if progress := tester.downloader.Progress(); progress.StartingBlock != 0 || progress.CurrentBlock != 0 || progress.HighestBlock != 0 {
t.Fatalf("Pristine progress mismatch: have %v/%v/%v, want %v/%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, 0, 0, 0)
}
// Attempt a full sync with a faulty peer
tester.newPeer("faulty", protocol, hashes, headers, blocks, receipts)
Expand All @@ -1580,8 +1574,8 @@ func testFailedSyncProgress(t *testing.T, protocol int, mode SyncMode) {
}
}()
<-starting
if origin, current, latest, _, _ := tester.downloader.Progress(); origin != 0 || current != 0 || latest != uint64(targetBlocks) {
t.Fatalf("Initial progress mismatch: have %v/%v/%v, want %v/%v/%v", origin, current, latest, 0, 0, targetBlocks)
if progress := tester.downloader.Progress(); progress.StartingBlock != 0 || progress.CurrentBlock != 0 || progress.HighestBlock != uint64(targetBlocks) {
t.Fatalf("Initial progress mismatch: have %v/%v/%v, want %v/%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, 0, 0, targetBlocks)
}
progress <- struct{}{}
pending.Wait()
Expand All @@ -1597,18 +1591,15 @@ func testFailedSyncProgress(t *testing.T, protocol int, mode SyncMode) {
}
}()
<-starting
if origin, current, latest, _, _ := tester.downloader.Progress(); origin != 0 || current > uint64(targetBlocks/2) || latest != uint64(targetBlocks) {
t.Fatalf("Completing progress mismatch: have %v/%v/%v, want %v/0-%v/%v", origin, current, latest, 0, targetBlocks/2, targetBlocks)
if progress := tester.downloader.Progress(); progress.StartingBlock != 0 || progress.CurrentBlock > uint64(targetBlocks/2) || progress.HighestBlock != uint64(targetBlocks) {
t.Fatalf("Completing progress mismatch: have %v/%v/%v, want %v/0-%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, 0, targetBlocks/2, targetBlocks)
}
progress <- struct{}{}
pending.Wait()

// Wait to make sure all data is set after sync
time.Sleep(500 * time.Millisecond)

// Check final progress after successful sync
if origin, current, latest, _, _ := tester.downloader.Progress(); origin > uint64(targetBlocks/2) || current != uint64(targetBlocks) || latest != uint64(targetBlocks) {
t.Fatalf("Final progress mismatch: have %v/%v/%v, want 0-%v/%v/%v", origin, current, latest, targetBlocks/2, targetBlocks, targetBlocks)
if progress := tester.downloader.Progress(); progress.StartingBlock > uint64(targetBlocks/2) || progress.CurrentBlock != uint64(targetBlocks) || progress.HighestBlock != uint64(targetBlocks) {
t.Fatalf("Final progress mismatch: have %v/%v/%v, want 0-%v/%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, targetBlocks/2, targetBlocks, targetBlocks)
}
}

Expand Down Expand Up @@ -1640,8 +1631,8 @@ func testFakedSyncProgress(t *testing.T, protocol int, mode SyncMode) {
<-progress
}
// Retrieve the sync progress and ensure they are zero (pristine sync)
if origin, current, latest, _, _ := tester.downloader.Progress(); origin != 0 || current != 0 || latest != 0 {
t.Fatalf("Pristine progress mismatch: have %v/%v/%v, want %v/%v/%v", origin, current, latest, 0, 0, 0)
if progress := tester.downloader.Progress(); progress.StartingBlock != 0 || progress.CurrentBlock != 0 || progress.HighestBlock != 0 {
t.Fatalf("Pristine progress mismatch: have %v/%v/%v, want %v/%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, 0, 0, 0)
}
// Create and sync with an attacker that promises a higher chain than available
tester.newPeer("attack", protocol, hashes, headers, blocks, receipts)
Expand All @@ -1661,8 +1652,8 @@ func testFakedSyncProgress(t *testing.T, protocol int, mode SyncMode) {
}
}()
<-starting
if origin, current, latest, _, _ := tester.downloader.Progress(); origin != 0 || current != 0 || latest != uint64(targetBlocks+3) {
t.Fatalf("Initial progress mismatch: have %v/%v/%v, want %v/%v/%v", origin, current, latest, 0, 0, targetBlocks+3)
if progress := tester.downloader.Progress(); progress.StartingBlock != 0 || progress.CurrentBlock != 0 || progress.HighestBlock != uint64(targetBlocks+3) {
t.Fatalf("Initial progress mismatch: have %v/%v/%v, want %v/%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, 0, 0, targetBlocks+3)
}
progress <- struct{}{}
pending.Wait()
Expand All @@ -1678,19 +1669,15 @@ func testFakedSyncProgress(t *testing.T, protocol int, mode SyncMode) {
}
}()
<-starting
if origin, current, latest, _, _ := tester.downloader.Progress(); origin != 0 || current > uint64(targetBlocks) || latest != uint64(targetBlocks) {
t.Fatalf("Completing progress mismatch: have %v/%v/%v, want %v/0-%v/%v", origin, current, latest, 0, targetBlocks, targetBlocks)
if progress := tester.downloader.Progress(); progress.StartingBlock != 0 || progress.CurrentBlock > uint64(targetBlocks) || progress.HighestBlock != uint64(targetBlocks) {
t.Fatalf("Completing progress mismatch: have %v/%v/%v, want %v/0-%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, 0, targetBlocks, targetBlocks)
}
progress <- struct{}{}

pending.Wait()

// Wait to make sure all data is set after sync
time.Sleep(400 * time.Millisecond)

// Check final progress after successful sync
if origin, current, latest, _, _ := tester.downloader.Progress(); origin > uint64(targetBlocks) || current != uint64(targetBlocks) || latest != uint64(targetBlocks) {
t.Fatalf("Final progress mismatch: have %v/%v/%v, want 0-%v/%v/%v", origin, current, latest, targetBlocks, targetBlocks, targetBlocks)
if progress := tester.downloader.Progress(); progress.StartingBlock > uint64(targetBlocks) || progress.CurrentBlock != uint64(targetBlocks) || progress.HighestBlock != uint64(targetBlocks) {
t.Fatalf("Final progress mismatch: have %v/%v/%v, want 0-%v/%v/%v", progress.StartingBlock, progress.CurrentBlock, progress.HighestBlock, targetBlocks, targetBlocks, targetBlocks)
}
}

Expand Down Expand Up @@ -1764,28 +1751,42 @@ func testFastCriticalRestarts(t *testing.T, protocol int) {
}
tester.downloader.dropPeer = func(id string) {} // We reuse the same "faulty" peer throughout the test

// Remove all possible pivot state roots and slow down replies (test failure resets later)
for i := 0; i < fsPivotInterval; i++ {
tester.peerMissingStates["peer"][headers[hashes[fsMinFullBlocks+i]].Root] = true
}

// Synchronise with the peer a few times and make sure they fail until the retry limit
for i := 0; i < fsCriticalTrials; i++ {
// Attempt a sync and ensure it fails properly
if err := tester.sync("peer", nil, FastSync); err == nil {
t.Fatalf("failing fast sync succeeded: %v", err)
}
time.Sleep(800 * time.Millisecond) // Make sure no in-flight requests remain
time.Sleep(150 * time.Millisecond) // Make sure no in-flight requests remain

// If it's the first failure, pivot should be locked => reenable all others to detect pivot changes
if i == 0 {
if tester.downloader.fsPivotLock == nil {
time.Sleep(400 * time.Millisecond) // Make sure the first huge timeout expires too
t.Fatalf("pivot block not locked in after critical section failure")
}
tester.lock.Lock()
tester.peerHeaders["peer"][hashes[fsMinFullBlocks-1]] = headers[hashes[fsMinFullBlocks-1]]
tester.peerMissingStates["peer"] = map[common.Hash]bool{tester.downloader.fsPivotLock.Root: true}
tester.downloader.peers.peers["peer"].getNodeData = tester.peerGetNodeDataFn("peer", 0)
tester.lock.Unlock()
}
}

// Wait to make sure all data is set after sync
time.Sleep(400 * time.Millisecond)
time.Sleep(150 * time.Millisecond) // Make sure no in-flight requests remain

// Retry limit exhausted, downloader will switch to full sync, should succeed
if err := tester.sync("peer", nil, FastSync); err != nil {
t.Fatalf("failed to synchronise blocks in slow sync: %v", err)
}
assertOwnChain(t, tester, targetBlocks+1)
// Note, we can't assert the chain here because the test asserter assumes sync
// completed using a single mode of operation, whereas fast-then-slow can result
// in arbitrary intermediate state that's not cleanly verifiable.
//assertOwnChain(t, tester, targetBlocks+1)
}

10 changes: 10 additions & 0 deletions eth/downloader/types.go
View file
Expand Up @@ -118,3 +118,13 @@ type statePack struct {
func (p *statePack) PeerId() string { return p.peerId }
func (p *statePack) Items() int { return len(p.states) }
func (p *statePack) Stats() string { return fmt.Sprintf("%d", len(p.states)) }

// SyncProgress gives progress indications when the node is synchronising with
// the Ethereum network.
type SyncProgress struct {
StartingBlock uint64 // Block number where sync began
CurrentBlock uint64 // Current block number where sync is at
HighestBlock uint64 // Highest alleged block number in the chain
PulledStates uint64 // Number of state trie entries already downloaded
KnownStates uint64 // Total number os state trie entries known about
}
4 changes: 1 addition & 3 deletions eth/handler.go
View file
Expand Up @@ -278,9 +278,7 @@ func (pm *ProtocolManager) handle(p *peer) error {
pm.syncTransactions(p)

// Drop connections on opposite side of network split
var fork *core.Fork
for i := range pm.chainConfig.Forks {
fork = pm.chainConfig.Forks[i]
for _, fork := range pm.chainConfig.Forks {
if _, height := p.Head(); height.Cmp(fork.Block) < 0 {
break
}
Expand Down
3 changes: 1 addition & 2 deletions p2p/peer.go
View file
Expand Up @@ -17,7 +17,6 @@
package p2p

import (
"errors"
"fmt"
"io"
"net"
Expand Down Expand Up @@ -303,7 +302,7 @@ func (p *Peer) startProtocols(writeStart <-chan struct{}, writeErr chan<- error)
err := proto.Run(p, proto)
if err == nil {
glog.V(logger.Detail).Infof("%v: Protocol %s/%d returned\n", p, proto.Name, proto.Version)
err = errors.New("protocol returned")
err = errProtocolReturned
} else if err != io.EOF {
glog.V(logger.Detail).Infof("%v: Protocol %s/%d error: %v\n", p, proto.Name, proto.Version, err)
}
Expand Down
6 changes: 6 additions & 0 deletions p2p/peer_error.go
View file
Expand Up @@ -18,6 +18,7 @@ package p2p

import (
"fmt"
"errors"
)

const (
Expand Down Expand Up @@ -51,6 +52,8 @@ func (self *peerError) Error() string {
return self.message
}

var errProtocolReturned = errors.New("protocol returned")

type DiscReason uint

const (
Expand Down Expand Up @@ -100,6 +103,9 @@ func discReasonForError(err error) DiscReason {
if reason, ok := err.(DiscReason); ok {
return reason
}
if err == errProtocolReturned {
return DiscQuitting
}
peerError, ok := err.(*peerError)
if ok {
switch peerError.code {
Expand Down

0 comments on commit d49adb8

Please sign in to comment.