Enable 100 wallet scenario in latency benchmark

[Anviking]

Issue Number

ADP-469, ADP-473

Overview

• Simply enable Latencies for 100 fixture wallets
• Delete all wallets in between all latency scenarios
• Rename DSL helper tearDown to deleteAllWallets, and re-use it more

Comments

$ stack bench cardano-wallet
Benchmark latency: RUNNING...
    Non-cached run
        getNetworkInfo      - 20.7 ms
    Latencies for 2 fixture wallets scenario
        listWallets         - 1.4 ms
        getWallet           - 0.5 ms
        getUTxOsStatistics  - 0.4 ms
        listAddresses       - 1.0 ms
        listTransactions    - 2.2 ms
        postTransactionFee  - 86.4 ms
        listStakePools      - 1.2 ms
        getNetworkInfo      - 0.0 ms
    Latencies for 10 fixture wallets scenario
        listWallets         - 4.8 ms
        getWallet           - 0.4 ms
        getUTxOsStatistics  - 0.3 ms
        listAddresses       - 0.9 ms
        listTransactions    - 2.0 ms
        postTransactionFee  - 93.2 ms
        listStakePools      - 1.3 ms
        getNetworkInfo      - 0.0 ms
    Latencies for 100 fixture wallets
        listWallets         - 59.9 ms
        getWallet           - 0.5 ms
        getUTxOsStatistics  - 0.4 ms
        listAddresses       - 1.2 ms
        listTransactions    - 2.6 ms
        postTransactionFee  - 139.2 ms
        listStakePools      - 1.1 ms
        getNetworkInfo      - 0.0 ms
    Latencies for 2 fixture wallets with 10 txs scenario
        listWallets         - 1.1 ms
        getWallet           - 0.5 ms
        getUTxOsStatistics  - 0.4 ms
        listAddresses       - 0.9 ms
        listTransactions    - 3.8 ms
        postTransactionFee  - 104.2 ms
        listStakePools      - 1.3 ms
        getNetworkInfo      - 0.1 ms
    Latencies for 2 fixture wallets with 20 txs scenario
        listWallets         - 1.1 ms
        getWallet           - 0.5 ms
        getUTxOsStatistics  - 0.4 ms
        listAddresses       - 1.0 ms
        listTransactions    - 5.5 ms
        postTransactionFee  - 97.0 ms
        listStakePools      - 1.2 ms
        getNetworkInfo      - 0.1 ms
    Latencies for 2 fixture wallets with 100 txs scenario
        listWallets         - 1.1 ms
        getWallet           - 0.5 ms
        getUTxOsStatistics  - 0.4 ms
        listAddresses       - 1.0 ms
        listTransactions    - 14.5 ms
        postTransactionFee  - 95.1 ms
        listStakePools      - 1.7 ms
        getNetworkInfo      - 0.1 ms
    Latencies for 10 fixture wallets with 10 txs scenario
        listWallets         - 4.4 ms
        getWallet           - 0.5 ms
        getUTxOsStatistics  - 0.3 ms
        listAddresses       - 0.9 ms
        listTransactions    - 4.3 ms
        postTransactionFee  - 106.6 ms
        listStakePools      - 1.3 ms
        getNetworkInfo      - 0.0 ms
    Latencies for 10 fixture wallets with 20 txs scenario
        listWallets         - 4.2 ms
        getWallet           - 0.4 ms
        getUTxOsStatistics  - 0.3 ms
        listAddresses       - 0.9 ms
        listTransactions    - 4.5 ms
        postTransactionFee  - 106.6 ms
        listStakePools      - 1.3 ms
        getNetworkInfo      - 0.1 ms
    Latencies for 10 fixture wallets with 100 txs scenario
        listWallets         - 4.5 ms
        getWallet           - 0.5 ms
        getUTxOsStatistics  - 0.4 ms
        listAddresses       - 0.9 ms
        listTransactions    - 15.8 ms
        postTransactionFee  - 96.8 ms
        listStakePools      - 1.6 ms
        getNetworkInfo      - 0.1 ms
    Latencies for 2 fixture wallets with 100 utxos scenario
        listWallets         - 1.7 ms
        getWallet           - 0.5 ms
        getUTxOsStatistics  - 0.4 ms
        listAddresses       - 1.0 ms
        listTransactions    - 12.2 ms
        postTransactionFee  - 95.9 ms
        listStakePools      - 1.4 ms
        getNetworkInfo      - 0.0 ms
    Latencies for 2 fixture wallets with 200 utxos scenario
        listWallets         - 1.7 ms
        getWallet           - 0.5 ms
        getUTxOsStatistics  - 0.4 ms
        listAddresses       - 1.0 ms
        listTransactions    - 25.1 ms
        postTransactionFee  - 96.6 ms
        listStakePools      - 1.4 ms
        getNetworkInfo      - 0.1 ms
    Latencies for 2 fixture wallets with 500 utxos scenario
        listWallets         - 1.6 ms
        getWallet           - 0.5 ms
        getUTxOsStatistics  - 0.4 ms
        listAddresses       - 1.0 ms
        listTransactions    - 69.7 ms
        postTransactionFee  - 87.9 ms
        listStakePools      - 1.5 ms
        getNetworkInfo      - 0.0 ms
    Latencies for 2 fixture wallets with 1000 utxos scenario

[Anviking]

Seems a bit low:

 Latencies for 100 fixture wallets
        listWallets         - 59.9 ms
        getWallet           - 0.5 ms
        getUTxOsStatistics  - 0.4 ms
        listAddresses       - 1.2 ms
        listTransactions    - 2.6 ms
        postTransactionFee  - 139.2 ms
        listStakePools      - 1.1 ms
        getNetworkInfo      - 0.0 ms

I wondered if ensuring the wallets were actively restoring (by replacing fixtureWallet with emptyWallet, which doesn't wait for funds to be available, so should be quicker), and it did get a bit slower:

    Latencies for 100 fixture wallets
        listWallets         - 71.0 ms
        getWallet           - 0.5 ms
        getUTxOsStatistics  - 0.4 ms
        listAddresses       - 0.7 ms
        listTransactions    - 0.1 ms
        postTransactionFee  - 263.6 ms
        listStakePools      - 1.3 ms
        getNetworkInfo      - 0.1 ms

I want to test on mainnet though.

[Anviking]

Btw, it's in the context of this (estimate fees taking minutes with 100 wallets)

that sub-second results seem suspicious.

[KtorZ]

It's oddly long, especially for wallets that are empty. If you want to spend some time investigating this, please do. Don't spend too much time on this however (max 1 day). It you can't find anything conclusive, then we'll allocate some extra time where finding the root cause and fixing it will be the actual task / goal.

[Anviking]

The benchmark took 8 minutes for me to run. When we create 100 wallets we repeatedly run postWallet >> waitForFunds, instead of first running all postWallet and then waiting for all wallets to have balance concurrently.

Changing to the latter approach would probably speed it up a bit, but I'm not sure how important it is that we do.

[paweljakubas]

lgtm!

would be worth always to trigger benchmark in CI (besides local trigger) and show results BEFORE/AFTER
https://buildkite.com/input-output-hk/cardano-wallet-nightly

[Anviking]

This: https://buildkite.com/input-output-hk/cardano-wallet-nightly/builds/666#3793e343-0460-450a-9a1c-ff1a66a917d2
Previously: https://buildkite.com/input-output-hk/cardano-wallet-nightly/builds/665#634d287a-f8e5-4090-a36d-6eb9bdfb324f

bors r+

[iohk-bors]

Canceled.

[Anviking]

bors r+

[iohk-bors]

Build failed:

• ci/hydra-build:required

src/Test/Integration/Scenario/API/Shelley/StakePools.hs:659:9:
  1) API Specifications, SHELLEY_STAKE_POOLS, STAKE_POOLS_LIST_01 - List stake pools, has non-zero saturation & stake
       uncaught exception: IOException of type UserError
       user error (Waited longer than 90s (more than 2 epochs) for an action to resolve. Action: "list pools returns non-empty list". Error condition: Just user error (Quantity {getQuantity = Percentage {getPercentage = 0 % 1}} does not satisfy (> Quantity {getQuantity = Percentage {getPercentage = 0 % 1}})))

  To rerun use: --match "/API Specifications/SHELLEY_STAKE_POOLS/STAKE_POOLS_LIST_01 - List stake pools/has non-zero saturation & stake/"

#2224

[Anviking]

bors r+

[iohk-bors]

Build failed:

• ci/hydra-build:required

 src/Test/Integration/Scenario/API/Shelley/Transactions.hs:1219:13:
  1) API Specifications, SHELLEY_TRANSACTIONS, TRANS_EXTERNAL_03 - Single Output Transaction with Byron witness, Byron wallet
       expected: Status {statusCode = 202, statusMessage = "Accepted"}
        but got: Status {statusCode = 403, statusMessage = "Forbidden"}

       from the following response: Left (DecodeFailure "Error in $: parsing Cardano.Wallet.Api.Types.ApiFee(ApiFee) failed, key \"estimated_min\" not found: Response {responseStatus = Status {statusCode = 403, statusMessage = \"Forbidden\"}, responseVersion = HTTP/1.1, responseHeaders = [(\"Transfer-Encoding\",\"chunked\"),(\"Date\",\"Thu, 08 Oct 2020 21:14:58 GMT\"),(\"Server\",\"Warp/3.3.5\")], responseBody = \"{\\\"code\\\":\\\"not_enough_money\\\",\\\"message\\\":\\\"I can't process this payment because there's not enough UTxO available in the wallet. The total UTxO sums up to 0 Lovelace, but I need 1000000 Lovelace (excluding fee amount) in order to proceed  with the payment.\\\"}\", responseCookieJar = CJ {expose = []}, responseClose' = ResponseClose}")

  To rerun use: --match "/API Specifications/SHELLEY_TRANSACTIONS/TRANS_EXTERNAL_03 - Single Output Transaction with Byron witness/Byron wallet/"

#2232

[Anviking]

bors r+

[iohk-bors]

Build failed (retrying...):

• buildkite/cardano-wallet

#2224

src/Test/Integration/Scenario/API/Shelley/StakePools.hs:659:9:
--
  | 1) API Specifications, SHELLEY_STAKE_POOLS, STAKE_POOLS_LIST_01 - List stake pools, has non-zero saturation & stake
  | uncaught exception: IOException of type UserError
  | user error (Waited longer than 90s (more than 2 epochs) for an action to resolve. Action: "list pools returns non-empty list". Error condition: Just user error (Quantity {getQuantity = Percentage {getPercentage = 0 % 1}} does not satisfy (> Quantity {getQuantity = Percentage {getPercentage = 0 % 1}})))
  |  
  | To rerun use: --match "/API Specifications/SHELLEY_STAKE_POOLS/STAKE_POOLS_LIST_01 - List stake pools/has non-zero saturation & stake/"
  |  
  | Randomized with seed 96553692

[iohk-bors]

Timed out.

It says timed out, but there were also a bunch of hydra errors I think:

  Logging Middleware
    GET, 200, no query FAILED [1]
    GET, 200, with query FAILED [2]
    GET, 200, not json FAILED [3]
    POST, 201, with sensitive fields FAILED [4]
    POST, 400, invalid payload (not json) FAILED [5]
    DELETE, 202, no query FAILED [6]
    GET, 400 FAILED [7]
    GET, 500 FAILED [8]
    GET, 503 FAILED [9]
    different request ids FAILED [10]
    correct time measures FAILED [11]

Failures:

  test/unit/Network/Wai/Middleware/LoggingSpec.hs:119:5:
  1) Network.Wai.Middleware.Logging, Logging Middleware, GET, 200, no query
       uncaught exception: HttpException
       HttpExceptionRequest Request {
         host                 = "localhost"
         port                 = 62128
         secure               = False
         requestHeaders       = []
         path                 = "/get"
         queryString          = ""
         method               = "GET"
         proxy                = Nothing
         rawBody              = False
         redirectCount        = 10
         responseTimeout      = ResponseTimeoutDefault
         requestVersion       = HTTP/1.1
       }
        ConnectionTimeout

Looks like
#2217

[Anviking]

bors r+

[iohk-bors]

This PR was included in a batch that timed out, it will be automatically retried

[iohk-bors]

Timed out.

#duplicate

[Anviking]

bors r+
🎲 🙄

[iohk-bors]

Build failed:

• ci/hydra-build:required

#duplicate

Failures:

  test/unit/Network/Wai/Middleware/LoggingSpec.hs:119:5:
  1) Network.Wai.Middleware.Logging, Logging Middleware, GET, 200, no query
       uncaught exception: HttpException
       HttpExceptionRequest Request {
         host                 = "localhost"
         port                 = 57577
         secure               = False
         requestHeaders       = []
         path                 = "/get"
         queryString          = ""
         method               = "GET"
         proxy                = Nothing
         rawBody              = False
         redirectCount        = 10
         responseTimeout      = ResponseTimeoutDefault
         requestVersion       = HTTP/1.1
       }
        ConnectionTimeout

  To rerun use: --match "/Network.Wai.Middleware.Logging/Logging Middleware/GET, 200, no query/"

[Anviking]

bors r+

[iohk-bors]

Build failed:

• ci/hydra-build:required

#duplicate

Cached failure of the above. Integration test results are not cached but unit test results are.

[rvl]

I restarted the failing unit test.

bors r+

[iohk-bors]

Build failed:

• ci/hydra-build:required

#2233 on macos.

Failures:

  src/Test/Integration/Scenario/API/Shelley/Transactions.hs:949:5:
  1) API Specifications, SHELLEY_TRANSACTIONS, TRANS_EXTERNAL_02 - Multiple Outputs Transaction - Shelley witnesses
       uncaught exception: IOException of type UserError
       user error (Waited longer than 90s (more than 2 epochs) for an action to resolve. Action: "wFaucet and wSrc balances are as expected". Error condition: Just (HUnitFailure (Just (SrcLoc {srcLocPackage = "cardano-wallet-core-integration-2020.9.30-8S5x2S8YoF48Q0OmGSe0jU", srcLocModule = "Test.Integration.Scenario.API.Shelley.Transactions", srcLocFile = "src/Test/Integration/Scenario/API/Shelley/Transactions.hs", srcLocStartLine = 1024, srcLocStartCol = 18, srcLocEndLine = 1024, srcLocEndCol = 67})) (ExpectedButGot Nothing "Quantity {getQuantity = 999989843200}" "Quantity {getQuantity = 999989843100}")))

  To rerun use: --match "/API Specifications/SHELLEY_TRANSACTIONS/TRANS_EXTERNAL_02 - Multiple Outputs Transaction - Shelley witnesses/"

Randomized with seed 2146329132

Finished in 1715.9644 seconds
662 examples, 1 failure, 6 pending

[Anviking]

bors r+

[iohk-bors]

Build failed:

• ci/hydra-build:required

#2230

 src/Test/Integration/Scenario/API/Shelley/StakePools.hs:530:5: 
  1) API Specifications, SHELLEY_STAKE_POOLS, STAKE_POOLS_JOIN_05 - Can join when stake key already exists
       uncaught exception: RequestException
       DecodeFailure "{\"code\":\"network_unreachable\",\"message\":\"The node backend is unreachable at the moment. Trying again in a bit might work.\"}"

  To rerun use: --match "/API Specifications/SHELLEY_STAKE_POOLS/STAKE_POOLS_JOIN_05 - Can join when stake key already exists/"

Randomized with seed 955139569

[Anviking]

questions life choices

bors+

[Anviking]

bors r+

[Anviking]

While de-duplicating tearDown code, it seems this PR adds status204 checks. I wonder if that has any effect. If that's the cause, that might be pretty interesting as we've still seen the "normal" failures here, just more often.

[iohk-bors]

Build succeeded:

• ci/hydra-build:required
• buildkite/cardano-wallet