Skip to content

Commit

Permalink
Log poller on demand streamlining (#11231)
Browse files Browse the repository at this point in the history
* move workflow to correct directory

* streamline on-demand values a bit

* get RPC urls and private keys from secrets

* download and run from inside the test folder

* checkout repo before running tests

* get inputs and mask them

* fix step ordering in workflow

* fix default image tag

* use latest pumba@CTF

* run one test

* fix directory name

* run on powerful runner

* add guide explaining how to use log poller tests

* update LP readme
  • Loading branch information
Tofel authored Nov 8, 2023
1 parent b5191f1 commit c3e889f
Show file tree
Hide file tree
Showing 6 changed files with 235 additions and 33 deletions.
71 changes: 46 additions & 25 deletions .github/workflows/on-demand-log-poller.yml
Original file line number Diff line number Diff line change
Expand Up @@ -24,43 +24,64 @@ on:
required: true
chainlinkVersion:
description: Chainlink version to use
default: "v2.7.0-beta0"
default: "2.7.0-beta1"
required: true
selectedNetworks:
description: Network to use (only Sepolia or Mumbai)
default: "Sepolia"
required: true
fundingKey:
description: Private key used to fund the contracts (must have sufficient ETH and LINK!)
required: true
rpcURL:
description: RPC URL to use
type: choice
options:
- "SIMULATED"
- "SEPOLIA"
- "MUMBAI"
fundingPrivateKey:
description: Private funding key (Skip for Simulated)
required: true
type: string
wsURL:
description: WS URL to use
description: WS URL for the network (Skip for Simulated)
required: true
type: string
httpURL:
description: HTTP URL for the network (Skip for Simulated)
required: true
type: string

jobs:
test:
runs-on: ubuntu-latest
env:
CONTRACTS: ${{ inputs.contracts }}
EVENTS_PER_TX: ${{ inputs.eventsPerTx }}
LOAD_DURATION: ${{ inputs.loadDuration }}
USE_FINALITY_TAG: ${{ inputs.useFinalityTag }}
CHAINLINK_IMAGE: ${{ inputs.chainlinkImage }}
CHAINLINK_VERSION: ${{ inputs.chainlinkVersion }}
SELECTED_NETWORKS: ${{ inputs.selectedNetworks }}
REF_NAME: ${{ github.head_ref || github.ref_name }}
runs-on: ubuntu20.04-8cores-32GB
steps:
- uses: actions/checkout@v3
- name: Get Inputs
run: |
EVM_URLS=$(jq -r '.inputs.wsURL' $GITHUB_EVENT_PATH)
EVM_HTTP_URLS=$(jq -r '.inputs.httpURL' $GITHUB_EVENT_PATH)
EVM_KEYS=$(jq -r '.inputs.fundingPrivateKey' $GITHUB_EVENT_PATH)
echo ::add-mask::$EVM_URLS
echo ::add-mask::$EVM_HTTP_URLS
echo ::add-mask::$EVM_KEYS
echo EVM_URLS=$EVM_URLS >> $GITHUB_ENV
echo EVM_HTTP_URLS=$EVM_HTTP_URLS >> $GITHUB_ENV
echo EVM_KEYS=$EVM_KEYS >> $GITHUB_ENV
- name: Checkout the repo
uses: actions/checkout@b4ffde65f46336ab88eb53be808477a3936bae11 # v4.1.1
with:
ref: ${{ env.REF_NAME }}
- name: Setup Go
uses: actions/setup-go@v3
with:
go-version-file: "integration-tests/go.mod"
cache: true
- name: Show overrides
env:
CONTRACTS: ${{ inputs.contracts }}
EVENTS_PER_TX: ${{ inputs.eventsPerTx }}
LOAD_DURATION: ${{ inputs.loadDuration }}
USE_FINALITY_TAG: ${{ inputs.useFinalityTag }}
CHAINLINK_IMAGE: ${{ inputs.chainlinkImage }}
CHAINLINK_VERSION: ${{ inputs.chainlinkVersion }}
SELECTED_NETWORKS: ${{ inputs.selectedNetworks }}
EVM_KEYS: ${{ inputs.fundingKey }}
EVM_HTTP_URLS: ${{ inputs.rpcURL }}
EVM_URLS: ${{ inputs.wsURL }}
- name: Run tests
run: |
go test -v -timeout 5h -run=TestLogPollerFromEnv integration-tests/reorg/log_poller_maybe_reorg_test.go
cd integration-tests
go mod download
go test -v -timeout 5h -v -count=1 -run ^TestLogPollerFromEnv$ ./reorg/log_poller_maybe_reorg_test.go
163 changes: 163 additions & 0 deletions integration-tests/LOG_POLLER.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,163 @@
# How to run Log Poller's tests

## Limitations
* currently they can only be run in Docker, not in Kubernetes
* when using `looped` runner it's not possible to directly control execution time
* WASP's `gun` implementation is imperfect in terms of generated load

## Configuration
Due to unfinished migration to TOML config tests use a mixed configuration approach:
* network, RPC endpoints, funding keys, etc need to be provided by env vars
* test-specific configuration can be provided by TOML file or via a `Config` struct (to which TOML is parsed anyway) additionally some of it can be overridden by env vars (for ease of use in CI)
** smoke tests use the programmatical approach
** load test uses the TOML approach

## Approximated test scenario
Different tests might have slightly modified scenarios, but generally they follow this pattern:
* start CL nodes
* setup OCR
* upload Automation Registry 2.1
* deploy UpKeep Consumers
* deploy test contracts
* register filters for test contracts
* make sure all CL nodes have filters registered
* emit test logs
* wait for log poller to finalise last block in which logs were emitted
** block number is determined either by finality tag or fixed finality depth depending on network configuration
* wait for all CL nodes to have expected log count
* compare logs that present in the EVM node with logs in CL nodes

All of the checks use fluent waits.

### Required env vars
* `CHAINLINK_IMAGE`
* `CHAINLINK_VERSION`
* `SELECTED_NETWORKS`

### Env vars required for live testnet tests
* `EVM_WS_URL` -- RPC websocket
* `EVM_HTTP_URL` -- RPC HTTP
* `EVM_KEYS` -- private keys used for funding

Since on live testnets we are using existing and canonical LINK contracts funding keys need to contain enough LINK to pay for the test. There's an automated check that fails during setup if there's not enough LINK. Approximately `9 LINK` is required for each UpKeep contract test uses to register a `LogTrigger`. Test contract emits 3 types of events and unless configured otherwise (programmatically!) all of them will be used, which means that due to Automation's limitation we need to register a separate `LogTrigger` for each event type for each contract. So if you want to test with 100 contracts, then you'd need to register 300 UpKeep contracts and thus your funding address needs to have at least 2700 LINK.

### Programmatical config
There are two load generators available:
* `looped` -- it's a simple generator that just loops over all contracts and emits events at random intervals
* `wasp` -- based on WASP load testing tool, it's more sophisticated and allows to control execution time

#### Looped config
```
cfg := logpoller.Config{
General: &logpoller.General{
Generator: logpoller.GeneratorType_Looped,
Contracts: 2, # number of test contracts to deploy
EventsPerTx: 4, # number of events to emit in a single transaction
UseFinalityTag: false, # if set to true then Log Poller will use finality tag returned by chain, when determining last finalised block (won't work on a simulated network, it requires eth2)
},
LoopedConfig: &logpoller.LoopedConfig{
ContractConfig: logpoller.ContractConfig{
ExecutionCount: 100, # number of times each contract will be called
},
FuzzConfig: logpoller.FuzzConfig{
MinEmitWaitTimeMs: 200, # minimum number of milliseconds to wait before emitting events
MaxEmitWaitTimeMs: 500, # maximum number of milliseconds to wait before emitting events
},
},
}
eventsToEmit := []abi.Event{}
for _, event := range logpoller.EmitterABI.Events { # modify that function to emit only logs you want
eventsToEmit = append(eventsToEmit, event)
}
cfg.General.EventsToEmit = eventsToEmit
```

Remember that final number of events emitted will be `Contracts * EventsPerTx * ExecutionCount * len(eventToEmit)`. And that that last number by default is equal to `3` (that's because we want to emit different event types, not just one). You can change that by overriding `EventsToEmit` field.

#### WASP config
```
cfg := logpoller.Config{
General: &logpoller.General{
Generator: logpoller.GeneratorType_Looped,
Contracts: 2,
EventsPerTx: 4,
UseFinalityTag: false,
},
Wasp: &logpoller.WaspConfig{
Load: &logpoller.Load{
RPS: 10, # requests per second
LPS: 0, # logs per second
RateLimitUnitDuration: models.MustNewDuration(5 * time.Minutes), # for how long the load should be limited (ramp-up period)
Duration: models.MustNewDuration(5 * time.Minutes), # how long to generate the load for
CallTimeout: models.MustNewDuration(5 * time.Minutes), # how long to wait for a single call to finish
},
},
}
eventsToEmit := []abi.Event{}
for _, event := range logpoller.EmitterABI.Events {
eventsToEmit = append(eventsToEmit, event)
}
cfg.General.EventsToEmit = eventsToEmit
```

Remember that you cannot specify both `RPS` and `LPS`. If you want to use `LPS` then omit `RPS` field. Also remember that depending on the events you decide to emit RPS might mean 1 request or might mean 3 requests (if you go with the default `EventsToEmit`).

For other nuances do check [gun.go][integration-tests/universal/log_poller/gun.go].

### TOML config
That config follows the same structure as programmatical config shown above.

Sample config: [config.toml](integration-tests/load/log_poller/config.toml)

Use this snippet instead of creating the `Config` struct programmatically:
```
cfg, err := lp_helpers.ReadConfig(lp_helpers.DefaultConfigFilename)
require.NoError(t, err)
```

And remember to add events you want emit:
```
eventsToEmit := []abi.Event{}
for _, event := range lp_helpers.EmitterABI.Events {
eventsToEmit = append(eventsToEmit, event)
}
cfg.General.EventsToEmit = eventsToEmit
```

### Timeouts
Various checks inside the tests have hardcoded timeouts, which might not be suitable for your execution parameters, for example if you decided to emit 1M logs, then waiting for all of them to be indexed for `1m` might not be enough. Remember to adjust them accordingly.

Sample snippet:
```
gom.Eventually(func(g gomega.Gomega) {
logCountMatches, err := clNodesHaveExpectedLogCount(startBlock, endBlock, testEnv.EVMClient.GetChainID(), totalLogsEmitted, expectedFilters, l, coreLogger, testEnv.ClCluster)
if err != nil {
l.Warn().Err(err).Msg("Error checking if CL nodes have expected log count. Retrying...")
}
g.Expect(logCountMatches).To(gomega.BeTrue(), "Not all CL nodes have expected log count")
}, "1m", "30s").Should(gomega.Succeed()) # 1m is the timeout for all nodes to have expected log count
```

## Tests
* [Load](integration-tests/load/log_poller/log_poller_test.go)
* [Smoke](integration-tests/smoke/log_poller/log_poller_test.go)

## Running tests
After setting all the environment variables you can run the test with:
```
# run in the root folder of chainlink repo
go test -v -test.timeout=2700s -run TestLogPollerReplay integration-tests/smoke/log_poller_test.go
```

Remember to adjust test timeout accordingly to match expected duration.


## Github Actions
If all of that seems too complicated use this [on-demand workflow](https://github.com/smartcontractkit/chainlink/actions/workflows/on-demand-log-poller.yml).

Execution time here is an approximation, so depending on network conditions it might be slightly longer or shorter.
17 changes: 17 additions & 0 deletions integration-tests/docker/test_env/test_env.go
Original file line number Diff line number Diff line change
Expand Up @@ -187,6 +187,8 @@ func (te *CLClusterTestEnv) Cleanup() error {
return fmt.Errorf("chainlink nodes are nil, unable cleanup chainlink nodes")
}

te.logWhetherAllContainersAreRunning()

// TODO: This is an imperfect and temporary solution, see TT-590 for a more sustainable solution
// Collect logs if the test fails, or if we just want them
if te.t.Failed() || os.Getenv("TEST_LOG_COLLECT") == "true" {
Expand Down Expand Up @@ -216,6 +218,21 @@ func (te *CLClusterTestEnv) Cleanup() error {
return nil
}

func (te *CLClusterTestEnv) logWhetherAllContainersAreRunning() {
for _, node := range te.ClCluster.Nodes {
isCLRunning := node.Container.IsRunning()
isDBRunning := node.PostgresDb.Container.IsRunning()

if !isCLRunning {
te.l.Warn().Str("Node", node.ContainerName).Msg("Chainlink node was not running, when test ended")
}

if !isDBRunning {
te.l.Warn().Str("Node", node.ContainerName).Msg("Postgres DB is not running, when test ended")
}
}
}

// collectTestLogs collects the logs from all the Chainlink nodes in the test environment and writes them to local files
func (te *CLClusterTestEnv) collectTestLogs() error {
te.l.Info().Msg("Collecting test logs")
Expand Down
4 changes: 2 additions & 2 deletions integration-tests/reorg/log_poller_maybe_reorg_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -20,8 +20,8 @@ func TestLogPollerFromEnv(t *testing.T) {
ExecutionCount: 100,
},
FuzzConfig: logpoller.FuzzConfig{
MinEmitWaitTimeMs: 800,
MaxEmitWaitTimeMs: 1200,
MinEmitWaitTimeMs: 400,
MaxEmitWaitTimeMs: 600,
},
},
}
Expand Down
11 changes: 6 additions & 5 deletions integration-tests/universal/log_poller/config.go
Original file line number Diff line number Diff line change
Expand Up @@ -112,11 +112,12 @@ func (c *Config) OverrideFromEnv() error {
if c.General.Generator == GeneratorType_WASP {
c.Wasp.Load.Duration = &d
} else {
// make the looped generator approximately run for desired duration
// on average we will emit 1 event per second
c.LoopedConfig.FuzzConfig.MinEmitWaitTimeMs = 900
c.LoopedConfig.FuzzConfig.MaxEmitWaitTimeMs = 1100
c.LoopedConfig.ContractConfig.ExecutionCount = int(d.Duration().Seconds())
// this is completely arbitrary and practice shows that even with this values
// test executes much longer than specified, probably due to network latency
c.LoopedConfig.FuzzConfig.MinEmitWaitTimeMs = 400
c.LoopedConfig.FuzzConfig.MaxEmitWaitTimeMs = 600
// divide by 4 based on past runs, but we should do it in a better way
c.LoopedConfig.ContractConfig.ExecutionCount = int(d.Duration().Seconds() / 4)
}
}

Expand Down
2 changes: 1 addition & 1 deletion integration-tests/universal/log_poller/scenarios.go
Original file line number Diff line number Diff line change
Expand Up @@ -309,7 +309,7 @@ func ExecuteLogPollerReplay(t *testing.T, cfg *Config, consistencyTimeout string
require.Equal(t, "Replay started", response.Data.Attributes.Message, "Unexpected response message from log poller's replay")
}

l.Warn().Str("Duration", consistencyTimeout).Msg("Waiting for logs to be processed by all nodes and for chain to advance beyond finality")
l.Warn().Str("Duration", consistencyTimeout).Msg("Waiting for replay logs to be processed by all nodes")

gom.Eventually(func(g gomega.Gomega) {
logCountMatches, err := clNodesHaveExpectedLogCount(startBlock, endBlock, testEnv.EVMClient.GetChainID(), totalLogsEmitted, expectedFilters, l, coreLogger, testEnv.ClCluster)
Expand Down

0 comments on commit c3e889f

Please sign in to comment.