Project Helios: Machine Learning-assisted Testing for Cosmos SDK (Progress Updates and Discussion)

[cytsai]

Helios is a Vector Institute research project funded by the ICF, aiming to improve the test coverage of the SDK using ML algorithms. The project is currently being carried out by myself (@cytsai, Technical AI Scientist, Vector Institute) and Prof. Graham Taylor (@gwtaylor). Following @ebuchman's suggestion, we'll start to use this page to share our progress and discuss with the community about the project and the testing of the SDK.

The approach we've decided upon for the first iteration of the project is to use deep reinforcement learning (RL) to guide the RNG of the generative testing procedures (e.g. cosmos-sdk/x/*/simulation/*.go) of the SDK to increase its test coverage and bug discovery, inspired by the RLCheck paper published last year (paper, video, slides).

Updates
(October 2021) https://tinyurl.com/559chrvk

[cytsai]

I've cleaned up and open-sourced my edits to the v0.42.4 SDK under https://github.com/cytsai/cosmos-sdk, which can be used with the additional -Guide argument to reproduce some potential bugs I've encountered so far.

More specifically, one should be able to reproduce my results with go test ./simapp/ -run TestFullAppSimulation -Enabled -Commit -v -cover -coverpkg=./... -NumBlocks=2 -BlockSize=100 -Seed=42 -Guide=/path/to/uuid.data.

All FAIL cases (FAIL_052021.zip) are either due to division by zero or invalid argument to Int63n (calling Int63n(n) with n == 0). The reason leading to the TIMEOUT cases (TIMEOUT_052021.zip) is however unclear to me.

[ebuchman]

Thanks Kenyon!

So the files contain the random numbers that were produced by some external thing to be used as input into the simulator? So the rand is basically just reading out those numbers?

And do you have any info on where these panics are coming from ? Do they seem like legitimate bugs or is it possible they're artifacts of the testing? Is it just because we're providing 0 as a random number when we shouldn't be ?

Also any idea where that TIMEOUT comes from ?

I will try to play around a bit before the meeting tomorrow.

[cytsai]

yes Ethan, the random numbers were generated externally by an RL algorithm and simapp/rand simply reads them out if a static guide file is provided.

unfortunately I have no clue about the origin(s) of the panics of the FAIL cases, although I would guess they're probably just hitting some unlikely corner cases of the testing procedure. however they're not artifacts or bugs due to simapp/rand, because simapp/rand doesn't generate anything that can't be generated by math/rand (which was checked during the generation of the guide file), meaning that given sufficient amount of time, the original testing procedure using math/rand will also hit the same bugs (e.g. providing 0s, even when the code calling the RNG probably shouldn't take 0s and should instead call RandIntBetween).

the TIMEOUT cases are even more puzzling to me (perhaps because I have very limited knowledge about the rest of the SDK). they seem to be hanging (running indefinitely) on certain operation(s) mid testing, and when ctrl+\'ed, stopping at different locations of the SDK.

[ebuchman]

Interesting thanks. Looking at a few of the panics, they seem to contain the following line:

        /Users/ethanbuchman/programming/goApps/src/github.com/cytsai/cosmos-sdk/x/simulation/simulate.go:82 +0x5f8

Which corresponds to

	validators, genesisTimestamp, accs, chainID := initChain(r, params, accs, app, appStateFn, config, cdc)

Which means the simulator doesn't even manage to get started because we're failing during initialization. I guess maybe something about the initial params or some of the other arguments are invalid and we should probably validate them and regenerate if they're invalid before trying to initialize! Probably some values that should not be 0 are being generated as 0 like you say

[ebuchman]

These timeouts are definitely more interesting. If I send kill -6 <pid> to get a stack trace, it looks like its hanging in the level db iterator. Hard to say what's causing that or if its spurious but maybe someone wants to take a look cc @robert-zaremba

[robert-zaremba]

I haven't look at it yet. Did anyone solve the issue?

[robert-zaremba]

Is there a summary of findings and bugs discovered?

[cytsai]

hi @robert-zaremba, below is a short summary we use for documentation on our side. let me know if you need additional information or clarification.

1. invalid initialization (the FAIL cases)

--- FAIL: TestFullAppSimulation (0.07s)
panic: invalid argument to Int63n [recovered]
panic: invalid argument to Int63n

2. unusual timeout (the TIMEOUT cases)

panic: test timed out after 1m0s
goroutine 29 [select]:
github.com/syndtr/goleveldb/leveldb/util.(*BufferPool).drain(0xc00117c000)
/home/cytsai/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/util/buffer_pool.go:209 +0x105
created by github.com/syndtr/goleveldb/leveldb/util.NewBufferPool
/home/cytsai/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/util/buffer_pool.go:240 +0x18c

I agree with Ethan that the first type of bugs is not very interesting, likely just corner cases where rand.Int63n(n) is incorrectly called with n==0 (n<=0 is invalid) and RandIntBetween should be used instead. unfortunately I don't have any insight about the second type of bugs, except that the -NumBlocks=2 -BlockSize=100 test configuration probably shouldn't run so long (I believe longer than 10 minutes, the longest I've waited before). below is a full stack trace for -timeout=1m for your reference.

(click to expand)

go test ./simapp/ -run TestFullAppSimulation -Enabled -Commit -v -cover -coverpkg=./... -NumBlocks=2 -BlockSize=100 -Seed=42 -Guide=/home/cytsai/research/icf/cosmos-sdk/bugs/time/212de191a4a74712b35ac16953f5fc2b.data -timeout=1m
=== RUN   TestFullAppSimulation
Starting SimulateFromSeed with randomness created with seed 42
Randomized simulation params:
{}
Selected randomly generated parameters for simulated genesis:
{
  stake_per_account: "480390429496",
  initially_bonded_validators: "0"
}
Selected randomly generated auth parameters:
{
 "max_memo_characters": 199,
 "tx_sig_limit": 11,
 "tx_size_cost_per_byte": 5,
 "sig_verify_cost_ed25519": 999,
 "sig_verify_cost_secp256k1": 635
}
Selected randomly generated bank parameters:
{
 "send_enabled": [
  {
   "denom": "stake",
   "enabled": true
  }
 ],
 "default_send_enabled": true
}
Selected randomly generated capability parameters:
{
 "index": 259,
 "owners": null
}
Selected randomly generated governance parameters:
{
 "deposits": null,
 "votes": null,
 "proposals": null,
 "deposit_params": {
  "min_deposit": [
   {
    "denom": "stake",
    "amount": "1"
   }
  ],
  "max_deposit_period": 345599000000000
 },
 "voting_params": {
  "voting_period": 345599000000000
 },
 "tally_params": {
  "quorum": "0.338000000000000000",
  "threshold": "0.450000000000000000",
  "veto_threshold": "0.250000000000000000"
 }
}
Selected randomly generated minting parameters:
{
 "minter": {
  "inflation": "0.000000000000000000",
  "annual_provisions": "0.000000000000000000"
 },
 "params": {
  "mint_denom": "stake",
  "inflation_rate_change": "0.980000000000000000",
  "inflation_max": "0.200000000000000000",
  "inflation_min": "0.070000000000000000",
  "goal_bonded": "0.670000000000000000",
  "blocks_per_year": 6311520
 }
}
Selected randomly generated staking parameters:
{
 "unbonding_time": 60000000000,
 "max_validators": 1,
 "max_entries": 7,
 "bond_denom": "stake"
}
Selected randomly generated distribution parameters:
{
 "params": {
  "community_tax": "0.300000000000000000",
  "base_proposer_reward": "0.300000000000000000",
  "bonus_proposer_reward": "0.010000000000000000"
 },
 "fee_pool": {
  "community_pool": []
 },
 "delegator_withdraw_infos": null,
 "outstanding_rewards": null,
 "validator_accumulated_commissions": null,
 "validator_historical_rewards": null,
 "validator_current_rewards": null,
 "delegator_starting_infos": null,
 "validator_slash_events": null
}
Selected randomly generated slashing parameters:
{
 "params": {
  "signed_blocks_window": 10,
  "min_signed_per_window": "0.000000000000000000",
  "downtime_jail_duration": 60000000000,
  "slash_fraction_double_sign": "0.020000000000000000",
  "slash_fraction_downtime": "0.018867924528301887"
 },
 "signing_infos": [],
 "missed_blocks": []
}
Selected randomly generated evidence parameters:
{}
Selected randomly generated ibc parameters:
{
 "client_genesis": {
  "clients": [],
  "clients_consensus": [],
  "clients_metadata": null,
  "params": {
   "allowed_clients": [
    "06-solomachine",
    "07-tendermint"
   ]
  }
 },
 "connection_genesis": {
  "connections": [],
  "client_connection_paths": []
 },
 "channel_genesis": {
  "channels": [],
  "acknowledgements": [],
  "commitments": [],
  "receipts": [],
  "send_sequences": [],
  "recv_sequences": [],
  "ack_sequences": []
 }
}
Selected randomly generated transfer parameters:
{
 "port_id": "nbagmwudzfememgbqnzn",
 "denom_traces": [],
 "params": {
  "send_enabled": true,
  "receive_enabled": true
 }
}
Selected randomly generated consensus parameters:
{
 "block": {
  "max_bytes": 29999999,
  "max_gas": -1
 },
 "evidence": {
  "max_age_num_blocks": 10,
  "max_age_duration": 60000000000
 },
 "validator": {
  "pub_key_types": [
   "ed25519"
  ]
 }
}
Starting the simulation from time Mon Feb  1 19:48:17 UTC 9999 (unixtime 253373514497)
Simulating... block 1/2, operation 250/399. coverage: 9.7% of statements in ./...
panic: test timed out after 1m0s

goroutine 52 [running]:
testing.(*M).startAlarm.func1()
        /home/cytsai/miniconda3/envs/icf/go/src/testing/testing.go:1618 +0xe5
created by time.goFunc
        /home/cytsai/miniconda3/envs/icf/go/src/time/sleep.go:167 +0x45

goroutine 1 [chan receive, 1 minutes]:
testing.(*T).Run(0xc000102f00, 0x1984d67, 0x15, 0x1bc3138, 0x49a901)
        /home/cytsai/miniconda3/envs/icf/go/src/testing/testing.go:1169 +0x2da
testing.runTests.func1(0xc000102a80)
        /home/cytsai/miniconda3/envs/icf/go/src/testing/testing.go:1439 +0x78
testing.tRunner(0xc000102a80, 0xc000d7bda8)
        /home/cytsai/miniconda3/envs/icf/go/src/testing/testing.go:1123 +0xef
testing.runTests(0xc000e79200, 0x2937c40, 0x8, 0x8, 0xc048a6a79e46cb27, 0xdf993862c, 0x294f340, 0x40f510)
        /home/cytsai/miniconda3/envs/icf/go/src/testing/testing.go:1437 +0x2fe
testing.(*M).Run(0xc00005a780, 0x0)
        /home/cytsai/miniconda3/envs/icf/go/src/testing/testing.go:1345 +0x1eb
main.main()
        _testmain.go:2661 +0x1d8

goroutine 23 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x7f94915e2f58, 0x72, 0x1000)
        /home/cytsai/miniconda3/envs/icf/go/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc0004fe698, 0x72, 0x0, 0x10, 0xc00063ac20)
        /home/cytsai/miniconda3/envs/icf/go/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
        /home/cytsai/miniconda3/envs/icf/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).ReadMsg(0xc0004fe680, 0xc00010ef30, 0x10, 0x10, 0xc00063ac20, 0x1000, 0x1000, 0x0, 0x0, 0x0, ...)
        /home/cytsai/miniconda3/envs/icf/go/src/internal/poll/fd_unix.go:242 +0x246
net.(*netFD).readMsg(0xc0004fe680, 0xc00010ef30, 0x10, 0x10, 0xc00063ac20, 0x1000, 0x1000, 0x41a9de, 0x7f9493f9e200, 0x20300000000000, ...)
        /home/cytsai/miniconda3/envs/icf/go/src/net/fd_posix.go:67 +0x90
net.(*UnixConn).readMsg(0xc000010480, 0xc00010ef30, 0x10, 0x10, 0xc00063ac20, 0x1000, 0x1000, 0xaa, 0x297bc98, 0x7f9490d5aff8, ...)
        /home/cytsai/miniconda3/envs/icf/go/src/net/unixsock_posix.go:115 +0x91
net.(*UnixConn).ReadMsgUnix(0xc000010480, 0xc00010ef30, 0x10, 0x10, 0xc00063ac20, 0x1000, 0x1000, 0xc000509c00, 0x20, 0x18, ...)
        /home/cytsai/miniconda3/envs/icf/go/src/net/unixsock.go:143 +0x9d
github.com/godbus/dbus.(*oobReader).Read(0xc00063ac00, 0xc00010ef30, 0x10, 0x10, 0xc000195df0, 0x40fe78, 0x20)
        /home/cytsai/go/pkg/mod/github.com/godbus/dbus@v0.0.0-20190726142602-4481cbc300e2/transport_unix.go:21 +0x8d
io.ReadAtLeast(0x1d4b480, 0xc00063ac00, 0xc00010ef30, 0x10, 0x10, 0x10, 0xc, 0x21, 0xc)
        /home/cytsai/miniconda3/envs/icf/go/src/io/io.go:314 +0x87
io.ReadFull(...)
        /home/cytsai/miniconda3/envs/icf/go/src/io/io.go:333
github.com/godbus/dbus.(*unixTransport).ReadMessage(0xc000d9e300, 0xc0005a3d10, 0x5, 0xc0005b6101)
        /home/cytsai/go/pkg/mod/github.com/godbus/dbus@v0.0.0-20190726142602-4481cbc300e2/transport_unix.go:91 +0x126
github.com/godbus/dbus.(*Conn).inWorker(0xc00012e360)
        /home/cytsai/go/pkg/mod/github.com/godbus/dbus@v0.0.0-20190726142602-4481cbc300e2/conn.go:294 +0x42
created by github.com/godbus/dbus.(*Conn).Auth
        /home/cytsai/go/pkg/mod/github.com/godbus/dbus@v0.0.0-20190726142602-4481cbc300e2/auth.go:118 +0x65b

goroutine 66 [runnable]:
github.com/cosmos/cosmos-sdk/x/bank/keeper.BaseViewKeeper.IterateAccountBalances(0x1d94040, 0xc000e8c940, 0x1d65460, 0xc000daf490, 0x1d95d40, 0xc00012e240, 0x1d820c0, 0xc0000420d0, 0x1d93ac0, 0xc0004f3500, ...)
        /home/cytsai/research/icf/cosmos-sdk/x/bank/keeper/view.go:121 +0x1b1
github.com/cosmos/cosmos-sdk/x/bank/keeper.BaseViewKeeper.GetAllBalances(0x1d94040, 0xc000e8c940, 0x1d65460, 0xc000daf490, 0x1d95d40, 0xc00012e240, 0x1d820c0, 0xc0000420d0, 0x1d93ac0, 0xc0004f3500, ...)
        /home/cytsai/research/icf/cosmos-sdk/x/bank/keeper/view.go:63 +0x138
github.com/cosmos/cosmos-sdk/x/bank/keeper.BaseViewKeeper.SpendableCoins(0x1d94040, 0xc000e8c940, 0x1d65460, 0xc000daf490, 0x1d95d40, 0xc00012e240, 0x1d820c0, 0xc0000420d0, 0x1d93ac0, 0xc0004f3500, ...)
        /home/cytsai/research/icf/cosmos-sdk/x/bank/keeper/view.go:178 +0xc8
github.com/cosmos/cosmos-sdk/x/bank/simulation.randomSendFields(0xc001d7efa0, 0x1d820c0, 0xc0000420d0, 0x1d93ac0, 0xc0004f3500, 0x0, 0x0, 0x197ca71, 0xe, 0x1, ...)
        /home/cytsai/research/icf/cosmos-sdk/x/bank/simulation/operations.go:310 +0x556
github.com/cosmos/cosmos-sdk/x/bank/simulation.SimulateMsgMultiSend.func1(0xc001d7efa0, 0xc0000cb6c0, 0x1d820c0, 0xc0000420d0, 0x1d93ac0, 0xc0004f3500, 0x0, 0x0, 0x197ca71, 0xe, ...)
        /home/cytsai/research/icf/cosmos-sdk/x/bank/simulation/operations.go:158 +0x2e8
github.com/cosmos/cosmos-sdk/x/simulation.createBlockSimulator.func1(0xc0005cf240, 0xc0000cb6c0, 0x1d820c0, 0xc0000420d0, 0x1d93ac0, 0xc0004f3500, 0x0, 0x0, 0x197ca71, 0xe, ...)
        /home/cytsai/research/icf/cosmos-sdk/x/simulation/simulate.go:298 +0x5e4
github.com/cosmos/cosmos-sdk/x/simulation.SimulateFromSeed(0x1d98f20, 0xc000102f00, 0x1d4cea0, 0xc000010018, 0xc0000cb6c0, 0xc0005cf100, 0x1bc3250, 0xc0004d3980, 0x11, 0x18, ...)
        /home/cytsai/research/icf/cosmos-sdk/x/simulation/simulate.go:188 +0x1603
github.com/cosmos/cosmos-sdk/simapp.TestFullAppSimulation(0xc000102f00)
        /home/cytsai/research/icf/cosmos-sdk/simapp/sim_test.go:75 +0x6c8
testing.tRunner(0xc000102f00, 0x1bc3138)
        /home/cytsai/miniconda3/envs/icf/go/src/testing/testing.go:1123 +0xef
created by testing.(*T).Run
        /home/cytsai/miniconda3/envs/icf/go/src/testing/testing.go:1168 +0x2b3

goroutine 67 [select]:
github.com/syndtr/goleveldb/leveldb/util.(*BufferPool).drain(0xc0001ce380)
        /home/cytsai/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/util/buffer_pool.go:209 +0x128
created by github.com/syndtr/goleveldb/leveldb/util.NewBufferPool
        /home/cytsai/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/util/buffer_pool.go:240 +0x18c

goroutine 68 [select, 1 minutes]:
github.com/syndtr/goleveldb/leveldb.(*session).refLoop(0xc000031e00)
        /home/cytsai/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/session_util.go:189 +0x60f
created by github.com/syndtr/goleveldb/leveldb.newSession
        /home/cytsai/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/session.go:93 +0x2bd

goroutine 69 [select, 1 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).compactionError(0xc000e04380)
        /home/cytsai/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/db_compaction.go:91 +0xd1
created by github.com/syndtr/goleveldb/leveldb.openDB
        /home/cytsai/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/db.go:148 +0x42b

goroutine 70 [select]:
github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain(0xc000e04380)
        /home/cytsai/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/db_state.go:101 +0x105
created by github.com/syndtr/goleveldb/leveldb.openDB
        /home/cytsai/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/db.go:149 +0x44d

goroutine 71 [select, 1 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).tCompaction(0xc000e04380)
        /home/cytsai/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/db_compaction.go:836 +0x265
created by github.com/syndtr/goleveldb/leveldb.openDB
        /home/cytsai/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/db.go:155 +0x5a5

goroutine 72 [select, 1 minutes]:
github.com/syndtr/goleveldb/leveldb.(*DB).mCompaction(0xc000e04380)
        /home/cytsai/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/db_compaction.go:773 +0x145
created by github.com/syndtr/goleveldb/leveldb.openDB
        /home/cytsai/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.1-0.20200815110645-5c35d600f0ca/leveldb/db.go:156 +0x5c7

goroutine 51 [syscall]:
os/signal.signal_recv(0x0)
        /home/cytsai/miniconda3/envs/icf/go/src/runtime/sigqueue.go:147 +0x9d
os/signal.loop()
        /home/cytsai/miniconda3/envs/icf/go/src/os/signal/signal_unix.go:23 +0x25
created by os/signal.Notify.func1.1
        /home/cytsai/miniconda3/envs/icf/go/src/os/signal/signal.go:150 +0x45

goroutine 26 [chan receive]:
github.com/cosmos/cosmos-sdk/x/simulation.SimulateFromSeed.func2(0xc000d4a540, 0x1d4cea0, 0xc000010018, 0xc000d46b00, 0xc000d48508, 0xc0004dd990, 0xc000de4ae0)
        /home/cytsai/research/icf/cosmos-sdk/x/simulation/simulate.go:119 +0x5c
created by github.com/cosmos/cosmos-sdk/x/simulation.SimulateFromSeed
        /home/cytsai/research/icf/cosmos-sdk/x/simulation/simulate.go:118 +0xb27
FAIL    github.com/cosmos/cosmos-sdk/simapp     60.030s
FAIL

[faddat]

This is overall interesting, I'll give e'r a read :).