github.com/decred/dcrlnd@v0.7.6/chanfitness/chanevent_test.go (about)

     1  package chanfitness
     2  
     3  import (
     4  	"testing"
     5  	"time"
     6  
     7  	"github.com/decred/dcrd/wire"
     8  	"github.com/decred/dcrlnd/clock"
     9  	"github.com/stretchr/testify/require"
    10  )
    11  
    12  // TestPeerLog tests the functionality of the peer log struct.
    13  func TestPeerLog(t *testing.T) {
    14  	clock := clock.NewTestClock(testNow)
    15  	peerLog := newPeerLog(clock, 0, nil)
    16  
    17  	// assertFlapCount is a helper that asserts that our peer's flap count
    18  	// and timestamp is set to expected values.
    19  	assertFlapCount := func(expectedCount int, expectedTs *time.Time) {
    20  		flapCount, flapTs := peerLog.getFlapCount()
    21  		require.Equal(t, expectedCount, flapCount)
    22  		require.Equal(t, expectedTs, flapTs)
    23  	}
    24  
    25  	require.Zero(t, peerLog.channelCount())
    26  	require.False(t, peerLog.online)
    27  	assertFlapCount(0, nil)
    28  
    29  	// Test that looking up an unknown channel fails.
    30  	_, _, err := peerLog.channelUptime(wire.OutPoint{Index: 1})
    31  	require.Error(t, err)
    32  
    33  	lastFlap := clock.Now()
    34  
    35  	// Add an offline event, since we have no channels, we do not expect
    36  	// to have any online periods recorded for our peer. However, we should
    37  	// increment our flap count for the peer.
    38  	peerLog.onlineEvent(false)
    39  	require.Len(t, peerLog.getOnlinePeriods(), 0)
    40  	assertFlapCount(1, &lastFlap)
    41  
    42  	// Bump our test clock's time by an hour so that we can create an online
    43  	// event with a distinct time.
    44  	lastFlap = testNow.Add(time.Hour)
    45  	clock.SetTime(lastFlap)
    46  
    47  	// Likewise, if we have an online event, nothing beyond the online state
    48  	// of our peer log should change, but our flap count should change.
    49  	peerLog.onlineEvent(true)
    50  	require.Len(t, peerLog.getOnlinePeriods(), 0)
    51  	assertFlapCount(2, &lastFlap)
    52  
    53  	// Add a channel and assert that we have one channel listed. Since this
    54  	// is the first channel we track for the peer, we expect an online
    55  	// event to be added, however, our flap count should not change because
    56  	// this is not a new online event, we are just copying one into our log
    57  	// for our purposes.
    58  	chan1 := wire.OutPoint{
    59  		Index: 1,
    60  	}
    61  	require.NoError(t, peerLog.addChannel(chan1))
    62  	require.Equal(t, 1, peerLog.channelCount())
    63  	assertFlapCount(2, &lastFlap)
    64  
    65  	// Assert that we can now successfully get our added channel.
    66  	_, _, err = peerLog.channelUptime(chan1)
    67  	require.NoError(t, err)
    68  
    69  	// Bump our test clock's time so that our current time is different to
    70  	// channel open time.
    71  	lastFlap = clock.Now().Add(time.Hour)
    72  	clock.SetTime(lastFlap)
    73  
    74  	// Now that we have added a channel and an hour has passed, we expect
    75  	// our uptime and lifetime to both equal an hour.
    76  	lifetime, uptime, err := peerLog.channelUptime(chan1)
    77  	require.NoError(t, err)
    78  	require.Equal(t, time.Hour, lifetime)
    79  	require.Equal(t, time.Hour, uptime)
    80  
    81  	// Add an offline event for our peer and assert that our flap count is
    82  	// incremented.
    83  	peerLog.onlineEvent(false)
    84  	assertFlapCount(3, &lastFlap)
    85  
    86  	// Now we add another channel to our store and assert that we now report
    87  	// two channels for this peer.
    88  	chan2 := wire.OutPoint{
    89  		Index: 2,
    90  	}
    91  	require.NoError(t, peerLog.addChannel(chan2))
    92  	require.Equal(t, 2, peerLog.channelCount())
    93  
    94  	// Progress our time again, so that our peer has now been offline for
    95  	// two hours.
    96  	now := lastFlap.Add(time.Hour * 2)
    97  	clock.SetTime(now)
    98  
    99  	// Our first channel should report as having been monitored for three
   100  	// hours, but only online for one of those hours.
   101  	lifetime, uptime, err = peerLog.channelUptime(chan1)
   102  	require.NoError(t, err)
   103  	require.Equal(t, time.Hour*3, lifetime)
   104  	require.Equal(t, time.Hour, uptime)
   105  
   106  	// Remove our first channel and check that we can still correctly query
   107  	// uptime for the second channel.
   108  	require.NoError(t, peerLog.removeChannel(chan1))
   109  	require.Equal(t, 1, peerLog.channelCount())
   110  
   111  	// Our second channel, which was created when our peer was offline,
   112  	// should report as having been monitored for two hours, but have zero
   113  	// uptime.
   114  	lifetime, uptime, err = peerLog.channelUptime(chan2)
   115  	require.NoError(t, err)
   116  	require.Equal(t, time.Hour*2, lifetime)
   117  	require.Equal(t, time.Duration(0), uptime)
   118  
   119  	// Finally, remove our second channel and assert that our peer cleans
   120  	// up its in memory set of events but keeps its flap count record.
   121  	require.NoError(t, peerLog.removeChannel(chan2))
   122  	require.Equal(t, 0, peerLog.channelCount())
   123  	require.Len(t, peerLog.onlineEvents, 0)
   124  	assertFlapCount(3, &lastFlap)
   125  
   126  	require.Len(t, peerLog.listEvents(), 0)
   127  	require.Nil(t, peerLog.stagedEvent)
   128  }
   129  
   130  // TestRateLimitAdd tests the addition of events to the event log with rate
   131  // limiting in place.
   132  func TestRateLimitAdd(t *testing.T) {
   133  	// Create a mock clock specifically for this test so that we can
   134  	// progress time without affecting the other tests.
   135  	mockedClock := clock.NewTestClock(testNow)
   136  
   137  	// Create a new peer log.
   138  	peerLog := newPeerLog(mockedClock, 0, nil)
   139  	require.Nil(t, peerLog.stagedEvent)
   140  
   141  	// Create a channel for our peer log, otherwise it will not track online
   142  	// events.
   143  	require.NoError(t, peerLog.addChannel(wire.OutPoint{}))
   144  
   145  	// First, we add an event to the event log. Since we have no previous
   146  	// events, we expect this event to staged immediately.
   147  	peerEvent := &event{
   148  		timestamp: testNow,
   149  		eventType: peerOfflineEvent,
   150  	}
   151  
   152  	peerLog.onlineEvent(false)
   153  	require.Equal(t, peerEvent, peerLog.stagedEvent)
   154  
   155  	// We immediately add another event to our event log. We expect our
   156  	// staged event to be replaced with this new event, because insufficient
   157  	// time has passed since our last event.
   158  	peerEvent = &event{
   159  		timestamp: testNow,
   160  		eventType: peerOnlineEvent,
   161  	}
   162  
   163  	peerLog.onlineEvent(true)
   164  	require.Equal(t, peerEvent, peerLog.stagedEvent)
   165  
   166  	// We get the amount of time that we need to pass before we record an
   167  	// event from our rate limiting tiers. We then progress our test clock
   168  	// to just after this point.
   169  	delta := getRateLimit(peerLog.flapCount)
   170  	newNow := testNow.Add(delta + 1)
   171  	mockedClock.SetTime(newNow)
   172  
   173  	// Now, when we add an event, we expect our staged event to be added
   174  	// to our events list and for our new event to be staged.
   175  	newEvent := &event{
   176  		timestamp: newNow,
   177  		eventType: peerOfflineEvent,
   178  	}
   179  	peerLog.onlineEvent(false)
   180  
   181  	require.Equal(t, []*event{peerEvent}, peerLog.onlineEvents)
   182  	require.Equal(t, newEvent, peerLog.stagedEvent)
   183  
   184  	// Now, we test the case where we add many events to our log. We expect
   185  	// our set of events to be untouched, but for our staged event to be
   186  	// updated.
   187  	nextEvent := &event{
   188  		timestamp: newNow,
   189  		eventType: peerOnlineEvent,
   190  	}
   191  
   192  	for i := 0; i < 5; i++ {
   193  		// We flip the kind of event for each type so that we can check
   194  		// that our staged event is definitely changing each time.
   195  		if i%2 == 0 {
   196  			nextEvent.eventType = peerOfflineEvent
   197  		} else {
   198  			nextEvent.eventType = peerOnlineEvent
   199  		}
   200  
   201  		online := nextEvent.eventType == peerOnlineEvent
   202  
   203  		peerLog.onlineEvent(online)
   204  		require.Equal(t, []*event{peerEvent}, peerLog.onlineEvents)
   205  		require.Equal(t, nextEvent, peerLog.stagedEvent)
   206  	}
   207  
   208  	// Now, we test the case where a peer's flap count is cooled down
   209  	// because it has not flapped for a while. Set our peer's flap count so
   210  	// that we fall within our second rate limiting tier and assert that we
   211  	// are at this level.
   212  	peerLog.flapCount = rateLimitScale + 1
   213  	rateLimit := getRateLimit(peerLog.flapCount)
   214  	require.Equal(t, rateLimits[1], rateLimit)
   215  
   216  	// Progress our clock to the point where we will have our flap count
   217  	// cooled.
   218  	newNow = mockedClock.Now().Add(flapCountCooldownPeriod)
   219  	mockedClock.SetTime(newNow)
   220  
   221  	// Add an online event, and expect it to be staged.
   222  	onlineEvent := &event{
   223  		timestamp: newNow,
   224  		eventType: peerOnlineEvent,
   225  	}
   226  	peerLog.onlineEvent(true)
   227  	require.Equal(t, onlineEvent, peerLog.stagedEvent)
   228  
   229  	// Progress our clock by the rate limit level that we will be on if
   230  	// our flap rate is cooled down to a lower level.
   231  	newNow = mockedClock.Now().Add(rateLimits[0] + 1)
   232  	mockedClock.SetTime(newNow)
   233  
   234  	// Add another event. We expect this event to be staged and our previous
   235  	// event to be flushed to the event log (because our cooldown has been
   236  	// applied).
   237  	offlineEvent := &event{
   238  		timestamp: newNow,
   239  		eventType: peerOfflineEvent,
   240  	}
   241  	peerLog.onlineEvent(false)
   242  	require.Equal(t, offlineEvent, peerLog.stagedEvent)
   243  
   244  	flushedEventIdx := len(peerLog.onlineEvents) - 1
   245  	require.Equal(
   246  		t, onlineEvent, peerLog.onlineEvents[flushedEventIdx],
   247  	)
   248  }
   249  
   250  // TestGetOnlinePeriod tests the getOnlinePeriod function. It tests the case
   251  // where no events present, and the case where an additional online period
   252  // must be added because the event log ends on an online event.
   253  func TestGetOnlinePeriod(t *testing.T) {
   254  	fourHoursAgo := testNow.Add(time.Hour * -4)
   255  	threeHoursAgo := testNow.Add(time.Hour * -3)
   256  	twoHoursAgo := testNow.Add(time.Hour * -2)
   257  
   258  	tests := []struct {
   259  		name           string
   260  		events         []*event
   261  		expectedOnline []*onlinePeriod
   262  	}{
   263  		{
   264  			name: "no events",
   265  		},
   266  		{
   267  			name: "start on online period",
   268  			events: []*event{
   269  				{
   270  					timestamp: threeHoursAgo,
   271  					eventType: peerOnlineEvent,
   272  				},
   273  				{
   274  					timestamp: twoHoursAgo,
   275  					eventType: peerOfflineEvent,
   276  				},
   277  			},
   278  			expectedOnline: []*onlinePeriod{
   279  				{
   280  					start: threeHoursAgo,
   281  					end:   twoHoursAgo,
   282  				},
   283  			},
   284  		},
   285  		{
   286  			name: "start on offline period",
   287  			events: []*event{
   288  				{
   289  					timestamp: fourHoursAgo,
   290  					eventType: peerOfflineEvent,
   291  				},
   292  			},
   293  		},
   294  		{
   295  			name: "end on an online period",
   296  			events: []*event{
   297  				{
   298  					timestamp: fourHoursAgo,
   299  					eventType: peerOnlineEvent,
   300  				},
   301  			},
   302  			expectedOnline: []*onlinePeriod{
   303  				{
   304  					start: fourHoursAgo,
   305  					end:   testNow,
   306  				},
   307  			},
   308  		},
   309  		{
   310  			name: "duplicate online events",
   311  			events: []*event{
   312  				{
   313  					timestamp: fourHoursAgo,
   314  					eventType: peerOnlineEvent,
   315  				},
   316  				{
   317  					timestamp: threeHoursAgo,
   318  					eventType: peerOnlineEvent,
   319  				},
   320  			},
   321  			expectedOnline: []*onlinePeriod{
   322  				{
   323  					start: fourHoursAgo,
   324  					end:   testNow,
   325  				},
   326  			},
   327  		},
   328  		{
   329  			name: "duplicate offline events",
   330  			events: []*event{
   331  				{
   332  					timestamp: fourHoursAgo,
   333  					eventType: peerOfflineEvent,
   334  				},
   335  				{
   336  					timestamp: threeHoursAgo,
   337  					eventType: peerOfflineEvent,
   338  				},
   339  			},
   340  			expectedOnline: nil,
   341  		},
   342  		{
   343  			name: "duplicate online then offline",
   344  			events: []*event{
   345  				{
   346  					timestamp: fourHoursAgo,
   347  					eventType: peerOnlineEvent,
   348  				},
   349  				{
   350  					timestamp: threeHoursAgo,
   351  					eventType: peerOnlineEvent,
   352  				},
   353  				{
   354  					timestamp: twoHoursAgo,
   355  					eventType: peerOfflineEvent,
   356  				},
   357  			},
   358  			expectedOnline: []*onlinePeriod{
   359  				{
   360  					start: fourHoursAgo,
   361  					end:   twoHoursAgo,
   362  				},
   363  			},
   364  		},
   365  		{
   366  			name: "duplicate offline then online",
   367  			events: []*event{
   368  				{
   369  					timestamp: fourHoursAgo,
   370  					eventType: peerOfflineEvent,
   371  				},
   372  				{
   373  					timestamp: threeHoursAgo,
   374  					eventType: peerOfflineEvent,
   375  				},
   376  				{
   377  					timestamp: twoHoursAgo,
   378  					eventType: peerOnlineEvent,
   379  				},
   380  			},
   381  			expectedOnline: []*onlinePeriod{
   382  				{
   383  					start: twoHoursAgo,
   384  					end:   testNow,
   385  				},
   386  			},
   387  		},
   388  	}
   389  
   390  	for _, test := range tests {
   391  		test := test
   392  
   393  		t.Run(test.name, func(t *testing.T) {
   394  			t.Parallel()
   395  
   396  			score := &peerLog{
   397  				onlineEvents: test.events,
   398  				clock:        clock.NewTestClock(testNow),
   399  			}
   400  
   401  			online := score.getOnlinePeriods()
   402  
   403  			require.Equal(t, test.expectedOnline, online)
   404  		})
   405  
   406  	}
   407  }
   408  
   409  // TestUptime tests channel uptime calculation based on its event log.
   410  func TestUptime(t *testing.T) {
   411  	fourHoursAgo := testNow.Add(time.Hour * -4)
   412  	threeHoursAgo := testNow.Add(time.Hour * -3)
   413  	twoHoursAgo := testNow.Add(time.Hour * -2)
   414  	oneHourAgo := testNow.Add(time.Hour * -1)
   415  
   416  	tests := []struct {
   417  		name string
   418  
   419  		// events is the set of event log that we are calculating uptime
   420  		// for.
   421  		events []*event
   422  
   423  		// startTime is the beginning of the period that we are
   424  		// calculating uptime for, it cannot have a zero value.
   425  		startTime time.Time
   426  
   427  		// endTime is the end of the period that we are calculating
   428  		// uptime for, it cannot have a zero value.
   429  		endTime time.Time
   430  
   431  		// expectedUptime is the amount of uptime we expect to be
   432  		// calculated over the period specified by startTime and
   433  		// endTime.
   434  		expectedUptime time.Duration
   435  
   436  		// expectErr is set to true if we expect an error to be returned
   437  		// when calling the uptime function.
   438  		expectErr bool
   439  	}{
   440  		{
   441  			name:      "End before start",
   442  			endTime:   threeHoursAgo,
   443  			startTime: testNow,
   444  			expectErr: true,
   445  		},
   446  		{
   447  			name:      "Zero end time",
   448  			expectErr: true,
   449  		},
   450  		{
   451  			name: "online event and no offline",
   452  			events: []*event{
   453  				{
   454  					timestamp: fourHoursAgo,
   455  					eventType: peerOnlineEvent,
   456  				},
   457  			},
   458  			startTime:      fourHoursAgo,
   459  			endTime:        testNow,
   460  			expectedUptime: time.Hour * 4,
   461  		},
   462  		{
   463  			name: "online then offline event",
   464  			events: []*event{
   465  				{
   466  					timestamp: threeHoursAgo,
   467  					eventType: peerOnlineEvent,
   468  				},
   469  				{
   470  					timestamp: twoHoursAgo,
   471  					eventType: peerOfflineEvent,
   472  				},
   473  			},
   474  			startTime:      fourHoursAgo,
   475  			endTime:        testNow,
   476  			expectedUptime: time.Hour,
   477  		},
   478  		{
   479  			name: "online event before uptime period",
   480  			events: []*event{
   481  				{
   482  					timestamp: threeHoursAgo,
   483  					eventType: peerOnlineEvent,
   484  				},
   485  			},
   486  			startTime:      twoHoursAgo,
   487  			endTime:        testNow,
   488  			expectedUptime: time.Hour * 2,
   489  		},
   490  		{
   491  			name: "offline event after uptime period",
   492  			events: []*event{
   493  				{
   494  					timestamp: fourHoursAgo,
   495  					eventType: peerOnlineEvent,
   496  				},
   497  				{
   498  					timestamp: testNow.Add(time.Hour),
   499  					eventType: peerOfflineEvent,
   500  				},
   501  			},
   502  			startTime:      twoHoursAgo,
   503  			endTime:        testNow,
   504  			expectedUptime: time.Hour * 2,
   505  		},
   506  		{
   507  			name: "all events within period",
   508  			events: []*event{
   509  				{
   510  					timestamp: twoHoursAgo,
   511  					eventType: peerOnlineEvent,
   512  				},
   513  			},
   514  			startTime:      threeHoursAgo,
   515  			endTime:        oneHourAgo,
   516  			expectedUptime: time.Hour,
   517  		},
   518  		{
   519  			name: "multiple online and offline",
   520  			events: []*event{
   521  				{
   522  					timestamp: testNow.Add(time.Hour * -7),
   523  					eventType: peerOnlineEvent,
   524  				},
   525  				{
   526  					timestamp: testNow.Add(time.Hour * -6),
   527  					eventType: peerOfflineEvent,
   528  				},
   529  				{
   530  					timestamp: testNow.Add(time.Hour * -5),
   531  					eventType: peerOnlineEvent,
   532  				},
   533  				{
   534  					timestamp: testNow.Add(time.Hour * -4),
   535  					eventType: peerOfflineEvent,
   536  				},
   537  				{
   538  					timestamp: testNow.Add(time.Hour * -3),
   539  					eventType: peerOnlineEvent,
   540  				},
   541  			},
   542  			startTime:      testNow.Add(time.Hour * -8),
   543  			endTime:        oneHourAgo,
   544  			expectedUptime: time.Hour * 4,
   545  		},
   546  	}
   547  
   548  	for _, test := range tests {
   549  		test := test
   550  
   551  		t.Run(test.name, func(t *testing.T) {
   552  			score := &peerLog{
   553  				onlineEvents: test.events,
   554  				clock:        clock.NewTestClock(testNow),
   555  			}
   556  
   557  			uptime, err := score.uptime(
   558  				test.startTime, test.endTime,
   559  			)
   560  			require.Equal(t, test.expectErr, err != nil)
   561  			require.Equal(t, test.expectedUptime, uptime)
   562  		})
   563  	}
   564  }