Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

endpoint: force wallet resync #1268

Merged
merged 9 commits into from
Jan 16, 2020
Merged

endpoint: force wallet resync #1268

merged 9 commits into from
Jan 16, 2020

Conversation

KtorZ
Copy link
Member

@KtorZ KtorZ commented Jan 15, 2020

Issue Number

#1146

Overview

  • 92c2aa0
    extend swagger specification with 'forceResync'
    As an extreme measure to force re-sync the wallet

  • 206affc
    extend API with 'forceResync' operation

    • Added a 'forceResync' link
  • Extended the servant Client

  • Provide an initial straightforward implementation re-using 'rollbackBlocks'

  • 3d9bc77
    implement 'forceResync' handler properly
    Taking care of concurrent workers possibly acting on the database
    at the same time as well as restarting the restoration worker at
    the right point

  • 4b06845
    add integration test for the 'forceResync' endpoint
    Doesn't pass currently because of the in-memory sqlite implementation.
    It works like a charm with the file database though:

(Right before making the request, observe the thread id #142)
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.54 UTC] bdb212cc: In sync with the node.

(Upon receiving the request)
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:04.97 UTC] [RequestId 10] [DELETE] /v2/wallets/bdb212ccd1d556b62a59f4a4a1de0cff29f61ac1/utxos

(Turning off the worker, rolling back, and switching the worker back on)
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.97 UTC] bdb212cc: Worker has exited: main action is over.
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:04.98 UTC] bdb212cc: Try rolling back to 0.0
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:05.00 UTC] bdb212cc: Rolled back to 0.0

(Responding to the request)
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:05.01 UTC] [RequestId 10] 204 No Content in 0.044038928s

(And later, the worker restarted, applying blocks from the start, new thread id #528).
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Applying blocks [1136063.1 ... 1144130.1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Creating checkpoint at feb1b2c2-[1136063.1#1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 8920cbb4-[1136063.2#2]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 73a21e9f-[1136063.3#3]

[...]

(Eventually, reaches the tip)
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: MyWallet, created at 2020-01-15 10:35:28.24351865 UTC, not delegating
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: syncProgress: restored
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: discovered 0 new transaction(s)
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: local tip: 8b9aba60-[1144130.1#100]
  • d196fd1
    preserve in-memory database states between calls
    For the in-memory Sqlite database, we do actually preserve the database
    after the 'action' is done. This allows for calling 'withDatabase'
    several times within the same execution and get back the same database.
    The memory is only cleaned up when calling 'removeDatabase', to mimic
    the way the file database works!

Without this, code like:

  Registry.remove re wid
  registerWorker ctx wid

would lead to weird behavior where the wallet wid which existed when
the worker was stopped didn't exist anymore when register the worker
again. This was because, killing the worker closes the connection
to the database and re-opening the "same" connection on the in-memory
database actually yield a completely different memory representation!

  • 423296b
    revise 'expectResponseCode' to give more details on failure
    It was kinda hard to understand what was going on from the error message.
    This is now slightly better and at least, allow some reasonning

  • 5eae1fa
    re-generate nix machinery

  • fab6e17
    fix database closing error handling

    • Added some additional log messages
  • Added an extra exception handler

  • Swapped worker removal with database closing

  • Reviewed how the in-memory database got cleaned up to avoid race condition

  • 9babcc2
    use on-disk database in integration tests

Comments

Screenshot from 2020-01-15 16-50-37

@KtorZ KtorZ self-assigned this Jan 15, 2020
@KtorZ KtorZ changed the title Ktor z/force resync endpoint: force wallet resync Jan 15, 2020
-- 3. The wallet eventually re-sync
eventually $ do
v <- request @wallet ctx (Link.getWallet @style w) Default Empty
verify v [ expectFieldSatisfy @IO #state (== (ApiT Ready)) ]
Copy link
Contributor

@paweljakubas paweljakubas Jan 15, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we are fine here to check only ApiWallet's state field, right? If there is no point 2 we are obviously satisfying point 3. It would be nice (although I do not know if it is easy) to show in point 2 upon forcing that state is Syncing ... so something happens as a result of force resync.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It would be nice (although I do not know if it is easy) to show in point 2 upon forcing that state is Syncing ...

that would be great. +1

Also I think that it would be nice to assert for few other stuff (maybe as separate scenarios):

  • balance (total, available, rewards?)
  • delegation status (if it the wallet was delegating is should be delegating still)
  • addresses (if it makes sense ?)
  • transaction history (whatever it should be after resync)

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I 100% agree with you guys and I actually thought of this. The main problem I have here is .... race-conditions.

Technically speaking, right after force-resyncing a wallet, your tip should be at genesis. But, by the time you make the request to produce some assertion... your wallet might as well have restored itself :| ... So, it's kinda hard to come up with reliable assertions that still make it possible to assess the behavior, precisely because this endpoint is meant to be used in situations where something went wrong / wasn't supposed to happen.

So here, the scenario is much more about exercising the endpoint and making sure that, nothing wrong really happen, whereas the real confirmation that it works come from the logging output.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I understand that race conditions are the preventing the addition of the "Syncing" assertion? But checking for the balance, delegation, addresses, transaction history should be doable right? (That would also add confidence that nothing wrong happened with the wallet after resync and it is still usable... perhaps making transaction after resync could be also a test that's nice to have )

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've added a few tests but, nothing really satisfactory in terms of testing states. If you guys have ideas, I'll happily do this in another PR (merging as is).

df = ctx ^. dbFactory @s @k
-- NOTE Safe because it happens without any worker running.
safeRollback = do
let tr' = Registry.transformTrace wid tr
Copy link
Contributor

@paweljakubas paweljakubas Jan 15, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we will have log as coming from withLogging about request..I wonder if we do not want to say more here. although we will have also additional logs from rollbackBlocks below. But maybe removing Registry is worth logging

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

logs look as follows:

[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:04.97 UTC] [RequestId 10] [DELETE] /v2/wallets/bdb212ccd1d556b62a59f4a4a1de0cff29f61ac1/utxos
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.97 UTC] bdb212cc: Worker has exited: main action is over.
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:04.98 UTC] bdb212cc: Try rolling back to 0.0
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:05.00 UTC] bdb212cc: Rolled back to 0.0
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:05.01 UTC] [RequestId 10] 204 No Content in 0.044038928s
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Applying blocks [1136063.1 ... 1144130.1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Creating checkpoint at feb1b2c2-[1136063.1#1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 8920cbb4-[1136063.2#2]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 73a21e9f-[1136063.3#3]
[...]

I think it's quite sufficient here 🤔

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

indeed, logs looks good. Worker has exited... logs removing of registry. and as expected there are logs from rollbackBlocks

-- after the 'action' is done. This allows for calling 'withDatabase'
-- several times within the same execution and get back the same
-- database. The memory is only cleaned up when calling
-- 'removeDatabase', to mimic the way the file database works!
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

💯

Copy link
Contributor

@paweljakubas paweljakubas left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I left some comments/questions.

What about adding the test that shows that when using force resync any incoming transaction will be erased whereas outgoing transactions will be put back as pending?

-- ^ Creates a new or use an existing database, maintaining an open
-- connection so long as necessary

, removeDatabase :: WalletId -> IO ()
-- ^ Erase any trace of the database
} deriving (Generic)
}
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

{-# LANGUAGE DeriveGeneric #-}

not needed after this change

-- 3. The wallet eventually re-sync
eventually $ do
v <- request @wallet ctx (Link.getWallet @style w) Default Empty
verify v [ expectFieldSatisfy @IO #state (== (ApiT Ready)) ]
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It would be nice (although I do not know if it is easy) to show in point 2 upon forcing that state is Syncing ...

that would be great. +1

Also I think that it would be nice to assert for few other stuff (maybe as separate scenarios):

  • balance (total, available, rewards?)
  • delegation status (if it the wallet was delegating is should be delegating still)
  • addresses (if it makes sense ?)
  • transaction history (whatever it should be after resync)


Force the wallet to rewind back to the genesis block and sync again with the chain.
Any incoming transaction will be erased whereas outgoing transactions will be put back
as pending. This action should only be taken as an extreme measure to resolve potential
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't understand this part. Is it for all the transactions, even if they are in ledger?

Why I'm asking: when you delete a wallet and create it again you have your transaction history available... My understanding and expectation of the forceResync would be to be an equivalent of delete and create (but without the need of deleting and creating a wallet again), am I wrong? (I bet I am...)

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@piotr-iohk force-resync is not equivalent to deleting and re-creating the wallet. It's actually equivalent to (and is a) rollback to the genesis block. So, after this, some transaction will be put back in pending such that, users can still track them.
The annoying part with deleting and re-creating your wallet is also that you completely loose track of your wallet history. If you attempted to made a payment, it won't show up unless visible in the ledger. But you may still have transaction floating around in mempools that don't show up in your wallet. Whereas, by using force resync here, you'll still see them.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Any incoming transaction will be erased whereas outgoing transactions will be put back as pending.

I think this statement may be somewhat misleading. After reading it I thought that after doing force resync all my incoming txs will be erased and not visible at all and outgoing will become pending. And it will be a finite state. But if they are in the ledger they will be discovered again and visible again. Hence the first comment, cause it was a bit surprising to me.

@KtorZ KtorZ force-pushed the KtorZ/force-resync branch 2 times, most recently from 0ca057d to 1577706 Compare January 15, 2020 15:49
@KtorZ
Copy link
Member Author

KtorZ commented Jan 15, 2020

bors r+

iohk-bors bot added a commit that referenced this pull request Jan 15, 2020
1268: endpoint: force wallet resync r=KtorZ a=KtorZ

# Issue Number

<!-- Put here a reference to the issue this PR relates to and which requirements it tackles -->

#1146 

# Overview

<!-- Detail in a few bullet points the work accomplished in this PR -->
- 06ee934
  extend swagger specification with 'forceResync'
  As an extreme measure to force re-sync the wallet

- 0938999
  extend API with 'forceResync' operation
  - Added a 'forceResync' link
- Extended the servant Client
- Provide an initial straightforward implementation re-using 'rollbackBlocks'

- 8f2b197
  implement 'forceResync' handler properly
  Taking care of concurrent workers possibly acting on the database
at the same time as well as restarting the restoration worker at
the right point

- 7d3e281
  add integration test for the 'forceResync' endpoint
  Doesn't pass currently because of the in-memory sqlite implementation.
It works like a charm with the file database though:

```
(Right before making the request, observe the thread id #142)
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.54 UTC] bdb212cc: In sync with the node.

(Upon receiving the request)
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:04.97 UTC] [RequestId 10] [DELETE] /v2/wallets/bdb212ccd1d556b62a59f4a4a1de0cff29f61ac1/utxos

(Turning off the worker, rolling back, and switching the worker back on)
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.97 UTC] bdb212cc: Worker has exited: main action is over.
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:04.98 UTC] bdb212cc: Try rolling back to 0.0
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:05.00 UTC] bdb212cc: Rolled back to 0.0

(Responding to the request)
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:05.01 UTC] [RequestId 10] 204 No Content in 0.044038928s

(And later, the worker restarted, applying blocks from the start, new thread id #528).
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Applying blocks [1136063.1 ... 1144130.1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Creating checkpoint at feb1b2c2-[1136063.1#1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 8920cbb4-[1136063.2#2]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 73a21e9f-[1136063.3#3]

[...]

(Eventually, reaches the tip)
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: MyWallet, created at 2020-01-15 10:35:28.24351865 UTC, not delegating
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: syncProgress: restored
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: discovered 0 new transaction(s)
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: local tip: 8b9aba60-[1144130.1#100]
```

- e134d52
  preserve in-memory database states between calls
  For the in-memory Sqlite database, we do actually preserve the database
after the 'action' is done. This allows for calling 'withDatabase'
several times within the same execution and get back the same database.
The memory is only cleaned up when calling 'removeDatabase', to mimic
the way the file database works!

Without this, code like:

```hs
  Registry.remove re wid
  registerWorker ctx wid
```

would lead to weird behavior where the wallet `wid` which existed when
the worker was stopped didn't exist anymore when register the worker
again. This was because, killing the worker closes the connection
to the database and re-opening the "same" connection on the in-memory
database actually yield a completely different memory representation!

- 1577706
  revise 'expectResponseCode' to give more details on failure
  It was kinda hard to understand what was going on from the error message.
This is now slightly better and at least, allow some reasonning

# Comments

<!-- Additional comments or screenshots to attach if any -->

![Screenshot from 2020-01-15 16-50-37](https://user-images.githubusercontent.com/5680256/72448387-3373ee80-37b7-11ea-962d-60c507ea4617.png)

<!-- 
Don't forget to:

 ✓ Self-review your changes to make sure nothing unexpected slipped through
 ✓ Assign yourself to the PR
 ✓ Assign one or several reviewer(s)
 ✓ Once created, link this PR to its corresponding ticket
 ✓ Assign the PR to a corresponding milestone
 ✓ Acknowledge any changes required to the Wiki
-->


Co-authored-by: KtorZ <[email protected]>
@iohk-bors
Copy link
Contributor

iohk-bors bot commented Jan 15, 2020

Build failed

As an extreme measure to force re-sync the wallet
- Added a 'forceResync' link
- Extended the servant Client
- Provide an initial straightforward implementation re-using 'rollbackBlocks'
Taking care of concurrent workers possibly acting on the database
at the same time as well as restarting the restoration worker at
the right point
Doesn't pass currently because of the in-memory sqlite implementation.
It works like a charm with the file database though:

```
(Right before making the request, observe the thread id #142)
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.54 UTC] bdb212cc: In sync with the node.

(Upon receiving the request)
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:04.97 UTC] [RequestId 10] [DELETE] /v2/wallets/bdb212ccd1d556b62a59f4a4a1de0cff29f61ac1/utxos

(Turning off the worker, rolling back, and switching the worker back on)
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.97 UTC] bdb212cc: Worker has exited: main action is over.
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:04.98 UTC] bdb212cc: Try rolling back to 0.0
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:05.00 UTC] bdb212cc: Rolled back to 0.0

(Responding to the request)
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:05.01 UTC] [RequestId 10] 204 No Content in 0.044038928s

(And later, the worker restarted, applying blocks from the start, new thread id #528).
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Applying blocks [1136063.1 ... 1144130.1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Creating checkpoint at feb1b2c2-[1136063.1#1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 8920cbb4-[1136063.2#2]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 73a21e9f-[1136063.3#3]

[...]

(Eventually, reaches the tip)
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: MyWallet, created at 2020-01-15 10:35:28.24351865 UTC, not delegating
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: syncProgress: restored
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: discovered 0 new transaction(s)
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: local tip: 8b9aba60-[1144130.1#100]
```
For the in-memory Sqlite database, we do actually preserve the database
after the 'action' is done. This allows for calling 'withDatabase'
several times within the same execution and get back the same database.
The memory is only cleaned up when calling 'removeDatabase', to mimic
the way the file database works!

Without this, code like:

```hs
  Registry.remove re wid
  registerWorker ctx wid
```

would lead to weird behavior where the wallet `wid` which existed when
the worker was stopped didn't exist anymore when register the worker
again. This was because, killing the worker closes the connection
to the database and re-opening the "same" connection on the in-memory
database actually yield a completely different memory representation!
It was kinda hard to understand what was going on from the error message.
This is now slightly better and at least, allow some reasonning
@KtorZ
Copy link
Member Author

KtorZ commented Jan 15, 2020

bors r+

iohk-bors bot added a commit that referenced this pull request Jan 15, 2020
1268: endpoint: force wallet resync r=KtorZ a=KtorZ

# Issue Number

<!-- Put here a reference to the issue this PR relates to and which requirements it tackles -->

#1146 

# Overview

<!-- Detail in a few bullet points the work accomplished in this PR -->
- 06ee934
  extend swagger specification with 'forceResync'
  As an extreme measure to force re-sync the wallet

- 0938999
  extend API with 'forceResync' operation
  - Added a 'forceResync' link
- Extended the servant Client
- Provide an initial straightforward implementation re-using 'rollbackBlocks'

- 8f2b197
  implement 'forceResync' handler properly
  Taking care of concurrent workers possibly acting on the database
at the same time as well as restarting the restoration worker at
the right point

- 7d3e281
  add integration test for the 'forceResync' endpoint
  Doesn't pass currently because of the in-memory sqlite implementation.
It works like a charm with the file database though:

```
(Right before making the request, observe the thread id #142)
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.54 UTC] bdb212cc: In sync with the node.

(Upon receiving the request)
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:04.97 UTC] [RequestId 10] [DELETE] /v2/wallets/bdb212ccd1d556b62a59f4a4a1de0cff29f61ac1/utxos

(Turning off the worker, rolling back, and switching the worker back on)
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.97 UTC] bdb212cc: Worker has exited: main action is over.
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:04.98 UTC] bdb212cc: Try rolling back to 0.0
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:05.00 UTC] bdb212cc: Rolled back to 0.0

(Responding to the request)
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:05.01 UTC] [RequestId 10] 204 No Content in 0.044038928s

(And later, the worker restarted, applying blocks from the start, new thread id #528).
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Applying blocks [1136063.1 ... 1144130.1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Creating checkpoint at feb1b2c2-[1136063.1#1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 8920cbb4-[1136063.2#2]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 73a21e9f-[1136063.3#3]

[...]

(Eventually, reaches the tip)
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: MyWallet, created at 2020-01-15 10:35:28.24351865 UTC, not delegating
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: syncProgress: restored
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: discovered 0 new transaction(s)
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: local tip: 8b9aba60-[1144130.1#100]
```

- e134d52
  preserve in-memory database states between calls
  For the in-memory Sqlite database, we do actually preserve the database
after the 'action' is done. This allows for calling 'withDatabase'
several times within the same execution and get back the same database.
The memory is only cleaned up when calling 'removeDatabase', to mimic
the way the file database works!

Without this, code like:

```hs
  Registry.remove re wid
  registerWorker ctx wid
```

would lead to weird behavior where the wallet `wid` which existed when
the worker was stopped didn't exist anymore when register the worker
again. This was because, killing the worker closes the connection
to the database and re-opening the "same" connection on the in-memory
database actually yield a completely different memory representation!

- 1577706
  revise 'expectResponseCode' to give more details on failure
  It was kinda hard to understand what was going on from the error message.
This is now slightly better and at least, allow some reasonning

# Comments

<!-- Additional comments or screenshots to attach if any -->

![Screenshot from 2020-01-15 16-50-37](https://user-images.githubusercontent.com/5680256/72448387-3373ee80-37b7-11ea-962d-60c507ea4617.png)

<!-- 
Don't forget to:

 ✓ Self-review your changes to make sure nothing unexpected slipped through
 ✓ Assign yourself to the PR
 ✓ Assign one or several reviewer(s)
 ✓ Once created, link this PR to its corresponding ticket
 ✓ Assign the PR to a corresponding milestone
 ✓ Acknowledge any changes required to the Wiki
-->


Co-authored-by: KtorZ <[email protected]>
@iohk-bors
Copy link
Contributor

iohk-bors bot commented Jan 15, 2020

Build failed

@KtorZ
Copy link
Member Author

KtorZ commented Jan 16, 2020

bors r+

iohk-bors bot added a commit that referenced this pull request Jan 16, 2020
1268: endpoint: force wallet resync r=KtorZ a=KtorZ

# Issue Number

<!-- Put here a reference to the issue this PR relates to and which requirements it tackles -->

#1146 

# Overview

<!-- Detail in a few bullet points the work accomplished in this PR -->
- 06ee934
  extend swagger specification with 'forceResync'
  As an extreme measure to force re-sync the wallet

- 0938999
  extend API with 'forceResync' operation
  - Added a 'forceResync' link
- Extended the servant Client
- Provide an initial straightforward implementation re-using 'rollbackBlocks'

- 8f2b197
  implement 'forceResync' handler properly
  Taking care of concurrent workers possibly acting on the database
at the same time as well as restarting the restoration worker at
the right point

- 7d3e281
  add integration test for the 'forceResync' endpoint
  Doesn't pass currently because of the in-memory sqlite implementation.
It works like a charm with the file database though:

```
(Right before making the request, observe the thread id #142)
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.54 UTC] bdb212cc: In sync with the node.

(Upon receiving the request)
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:04.97 UTC] [RequestId 10] [DELETE] /v2/wallets/bdb212ccd1d556b62a59f4a4a1de0cff29f61ac1/utxos

(Turning off the worker, rolling back, and switching the worker back on)
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.97 UTC] bdb212cc: Worker has exited: main action is over.
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:04.98 UTC] bdb212cc: Try rolling back to 0.0
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:05.00 UTC] bdb212cc: Rolled back to 0.0

(Responding to the request)
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:05.01 UTC] [RequestId 10] 204 No Content in 0.044038928s

(And later, the worker restarted, applying blocks from the start, new thread id #528).
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Applying blocks [1136063.1 ... 1144130.1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Creating checkpoint at feb1b2c2-[1136063.1#1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 8920cbb4-[1136063.2#2]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 73a21e9f-[1136063.3#3]

[...]

(Eventually, reaches the tip)
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: MyWallet, created at 2020-01-15 10:35:28.24351865 UTC, not delegating
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: syncProgress: restored
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: discovered 0 new transaction(s)
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: local tip: 8b9aba60-[1144130.1#100]
```

- e134d52
  preserve in-memory database states between calls
  For the in-memory Sqlite database, we do actually preserve the database
after the 'action' is done. This allows for calling 'withDatabase'
several times within the same execution and get back the same database.
The memory is only cleaned up when calling 'removeDatabase', to mimic
the way the file database works!

Without this, code like:

```hs
  Registry.remove re wid
  registerWorker ctx wid
```

would lead to weird behavior where the wallet `wid` which existed when
the worker was stopped didn't exist anymore when register the worker
again. This was because, killing the worker closes the connection
to the database and re-opening the "same" connection on the in-memory
database actually yield a completely different memory representation!

- 1577706
  revise 'expectResponseCode' to give more details on failure
  It was kinda hard to understand what was going on from the error message.
This is now slightly better and at least, allow some reasonning

# Comments

<!-- Additional comments or screenshots to attach if any -->

![Screenshot from 2020-01-15 16-50-37](https://user-images.githubusercontent.com/5680256/72448387-3373ee80-37b7-11ea-962d-60c507ea4617.png)

<!-- 
Don't forget to:

 ✓ Self-review your changes to make sure nothing unexpected slipped through
 ✓ Assign yourself to the PR
 ✓ Assign one or several reviewer(s)
 ✓ Once created, link this PR to its corresponding ticket
 ✓ Assign the PR to a corresponding milestone
 ✓ Acknowledge any changes required to the Wiki
-->


Co-authored-by: KtorZ <[email protected]>
- Added some additional log messages
- Added an extra exception handler
- Swapped worker removal with database closing
- Reviewed how the in-memory database got cleaned up to avoid race condition
@iohk-bors
Copy link
Contributor

iohk-bors bot commented Jan 16, 2020

Canceled

@KtorZ
Copy link
Member Author

KtorZ commented Jan 16, 2020

bors r+

iohk-bors bot added a commit that referenced this pull request Jan 16, 2020
1268: endpoint: force wallet resync r=KtorZ a=KtorZ

# Issue Number

<!-- Put here a reference to the issue this PR relates to and which requirements it tackles -->

#1146 

# Overview

<!-- Detail in a few bullet points the work accomplished in this PR -->

- 92c2aa0
  extend swagger specification with 'forceResync'
  As an extreme measure to force re-sync the wallet

- 206affc
  extend API with 'forceResync' operation
  - Added a 'forceResync' link
- Extended the servant Client
- Provide an initial straightforward implementation re-using 'rollbackBlocks'

- 3d9bc77
  implement 'forceResync' handler properly
  Taking care of concurrent workers possibly acting on the database
at the same time as well as restarting the restoration worker at
the right point

- 4b06845
  add integration test for the 'forceResync' endpoint
  Doesn't pass currently because of the in-memory sqlite implementation.
It works like a charm with the file database though:

```
(Right before making the request, observe the thread id #142)
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.54 UTC] bdb212cc: In sync with the node.

(Upon receiving the request)
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:04.97 UTC] [RequestId 10] [DELETE] /v2/wallets/bdb212ccd1d556b62a59f4a4a1de0cff29f61ac1/utxos

(Turning off the worker, rolling back, and switching the worker back on)
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.97 UTC] bdb212cc: Worker has exited: main action is over.
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:04.98 UTC] bdb212cc: Try rolling back to 0.0
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:05.00 UTC] bdb212cc: Rolled back to 0.0

(Responding to the request)
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:05.01 UTC] [RequestId 10] 204 No Content in 0.044038928s

(And later, the worker restarted, applying blocks from the start, new thread id #528).
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Applying blocks [1136063.1 ... 1144130.1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Creating checkpoint at feb1b2c2-[1136063.1#1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 8920cbb4-[1136063.2#2]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 73a21e9f-[1136063.3#3]

[...]

(Eventually, reaches the tip)
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: MyWallet, created at 2020-01-15 10:35:28.24351865 UTC, not delegating
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: syncProgress: restored
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: discovered 0 new transaction(s)
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: local tip: 8b9aba60-[1144130.1#100]
```

- d196fd1
  preserve in-memory database states between calls
  For the in-memory Sqlite database, we do actually preserve the database
after the 'action' is done. This allows for calling 'withDatabase'
several times within the same execution and get back the same database.
The memory is only cleaned up when calling 'removeDatabase', to mimic
the way the file database works!

Without this, code like:

```hs
  Registry.remove re wid
  registerWorker ctx wid
```

would lead to weird behavior where the wallet `wid` which existed when
the worker was stopped didn't exist anymore when register the worker
again. This was because, killing the worker closes the connection
to the database and re-opening the "same" connection on the in-memory
database actually yield a completely different memory representation!

- 423296b
  revise 'expectResponseCode' to give more details on failure
  It was kinda hard to understand what was going on from the error message.
This is now slightly better and at least, allow some reasonning

- 5eae1fa
  re-generate nix machinery
  
- fab6e17
  fix database closing error handling
  - Added some additional log messages
- Added an extra exception handler
- Swapped worker removal with database closing
- Reviewed how the in-memory database got cleaned up to avoid race condition

- 9babcc2
  use on-disk database in integration tests

# Comments

<!-- Additional comments or screenshots to attach if any -->

![Screenshot from 2020-01-15 16-50-37](https://user-images.githubusercontent.com/5680256/72448387-3373ee80-37b7-11ea-962d-60c507ea4617.png)

<!-- 
Don't forget to:

 ✓ Self-review your changes to make sure nothing unexpected slipped through
 ✓ Assign yourself to the PR
 ✓ Assign one or several reviewer(s)
 ✓ Once created, link this PR to its corresponding ticket
 ✓ Assign the PR to a corresponding milestone
 ✓ Acknowledge any changes required to the Wiki
-->


Co-authored-by: KtorZ <[email protected]>
@iohk-bors
Copy link
Contributor

iohk-bors bot commented Jan 16, 2020

Build failed

@KtorZ
Copy link
Member Author

KtorZ commented Jan 16, 2020

bors retry

iohk-bors bot added a commit that referenced this pull request Jan 16, 2020
1268: endpoint: force wallet resync r=KtorZ a=KtorZ

# Issue Number

<!-- Put here a reference to the issue this PR relates to and which requirements it tackles -->

#1146 

# Overview

<!-- Detail in a few bullet points the work accomplished in this PR -->

- 92c2aa0
  extend swagger specification with 'forceResync'
  As an extreme measure to force re-sync the wallet

- 206affc
  extend API with 'forceResync' operation
  - Added a 'forceResync' link
- Extended the servant Client
- Provide an initial straightforward implementation re-using 'rollbackBlocks'

- 3d9bc77
  implement 'forceResync' handler properly
  Taking care of concurrent workers possibly acting on the database
at the same time as well as restarting the restoration worker at
the right point

- 4b06845
  add integration test for the 'forceResync' endpoint
  Doesn't pass currently because of the in-memory sqlite implementation.
It works like a charm with the file database though:

```
(Right before making the request, observe the thread id #142)
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.54 UTC] bdb212cc: In sync with the node.

(Upon receiving the request)
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:04.97 UTC] [RequestId 10] [DELETE] /v2/wallets/bdb212ccd1d556b62a59f4a4a1de0cff29f61ac1/utxos

(Turning off the worker, rolling back, and switching the worker back on)
[cardano-wallet.wallet-engine:Info:142] [2020-01-15 10:38:04.97 UTC] bdb212cc: Worker has exited: main action is over.
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:04.98 UTC] bdb212cc: Try rolling back to 0.0
[cardano-wallet.wallet-engine:Info:526] [2020-01-15 10:38:05.00 UTC] bdb212cc: Rolled back to 0.0

(Responding to the request)
[cardano-wallet.api-server:Info:526] [2020-01-15 10:38:05.01 UTC] [RequestId 10] 204 No Content in 0.044038928s

(And later, the worker restarted, applying blocks from the start, new thread id #528).
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Applying blocks [1136063.1 ... 1144130.1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.03 UTC] bdb212cc: Creating checkpoint at feb1b2c2-[1136063.1#1]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 8920cbb4-[1136063.2#2]
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.04 UTC] bdb212cc: Creating checkpoint at 73a21e9f-[1136063.3#3]

[...]

(Eventually, reaches the tip)
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: MyWallet, created at 2020-01-15 10:35:28.24351865 UTC, not delegating
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: syncProgress: restored
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: discovered 0 new transaction(s)
[cardano-wallet.wallet-engine:Info:528] [2020-01-15 10:38:05.18 UTC] bdb212cc: local tip: 8b9aba60-[1144130.1#100]
```

- d196fd1
  preserve in-memory database states between calls
  For the in-memory Sqlite database, we do actually preserve the database
after the 'action' is done. This allows for calling 'withDatabase'
several times within the same execution and get back the same database.
The memory is only cleaned up when calling 'removeDatabase', to mimic
the way the file database works!

Without this, code like:

```hs
  Registry.remove re wid
  registerWorker ctx wid
```

would lead to weird behavior where the wallet `wid` which existed when
the worker was stopped didn't exist anymore when register the worker
again. This was because, killing the worker closes the connection
to the database and re-opening the "same" connection on the in-memory
database actually yield a completely different memory representation!

- 423296b
  revise 'expectResponseCode' to give more details on failure
  It was kinda hard to understand what was going on from the error message.
This is now slightly better and at least, allow some reasonning

- 5eae1fa
  re-generate nix machinery
  
- fab6e17
  fix database closing error handling
  - Added some additional log messages
- Added an extra exception handler
- Swapped worker removal with database closing
- Reviewed how the in-memory database got cleaned up to avoid race condition

- 9babcc2
  use on-disk database in integration tests

# Comments

<!-- Additional comments or screenshots to attach if any -->

![Screenshot from 2020-01-15 16-50-37](https://user-images.githubusercontent.com/5680256/72448387-3373ee80-37b7-11ea-962d-60c507ea4617.png)

<!-- 
Don't forget to:

 ✓ Self-review your changes to make sure nothing unexpected slipped through
 ✓ Assign yourself to the PR
 ✓ Assign one or several reviewer(s)
 ✓ Once created, link this PR to its corresponding ticket
 ✓ Assign the PR to a corresponding milestone
 ✓ Acknowledge any changes required to the Wiki
-->


Co-authored-by: KtorZ <[email protected]>
@KtorZ
Copy link
Member Author

KtorZ commented Jan 16, 2020

CI is stuck with "Check Cabal Reconfigure" for I am not sure what the reason is but I don't think it's remotely related to the PR, so merging all-the-same :|

@KtorZ KtorZ merged commit 2681d91 into master Jan 16, 2020
@KtorZ KtorZ deleted the KtorZ/force-resync branch January 16, 2020 17:18
@iohk-bors
Copy link
Contributor

iohk-bors bot commented Jan 16, 2020

Timed out

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants