Balance shown to the user does not take locked amount into account.

LefterisJP commented 5 years ago

Problem Definition

The balance returned from the API for a channel does not take the locked amount into account. The channel schema returns the balance here and it uses channel.get_balance()

https://github.com/raiden-network/raiden/blob/b757d2c9593116780c0a71fa7127dec1e084d6a2/raiden/transfer/channel.py#L787-L804

That function contains only the finalized balance and completely ignores the locked amount. This is not what a user would expect as his balance -- especially since after settle as per the spec what you get out is minus the locked amount.

S1 = D1 - W1 + T2 - T1 - L1

So settling a channel would give you less than your balance would show in the API which is wrong and creates wrong expectations.

Task

There is already a function that does what we want. It's called get_distributable()

https://github.com/raiden-network/raiden/blob/b757d2c9593116780c0a71fa7127dec1e084d6a2/raiden/transfer/channel.py#L824-L844

So we can simply use this in the API for returning the expected balance.

Still to be discussed: Does having channel.get_balance() with its current implementation make sense? It does not seem to be used anywhere else apart from tests and confuses people as to what a balance is. I think it is semantically wrong.

raiden/transfer/channel.py:787:5:def get_balance(
raiden/transfer/channel.py:837:21:    distributable = get_balance(sender, receiver) - get_amount_locked(sender)
raiden/waiting.py:69:12:        target_balance: typing.TokenAmount,
raiden/waiting.py:91:39:    while balance(channel_state) < target_balance:
raiden/waiting.py:107:12:        target_balance: typing.TokenAmount,
raiden/waiting.py:115:9:    def get_balance(end_state):
raiden/waiting.py:122:41:        balance = lambda channel_state: get_balance(channel_state.partner_state)
raiden/waiting.py:124:41:        balance = lambda channel_state: get_balance(channel_state.our_state)
raiden/waiting.py:135:39:    while balance(channel_state) < target_balance:
raiden/waiting.py:136:61:        log.critical('wait', b=balance(channel_state), t=target_balance)
raiden/tests/integration/test_send_queued_messages.py:110:16:            target_balance=spent_amount,
raiden/tests/integration/test_send_queued_messages.py:120:12:        target_balance=spent_amount,
raiden/tests/integration/api/test_pythonapi.py:112:20:    assert channel.get_balance(channel12.our_state, channel12.partner_state) == deposit
raiden/tests/unit/fuzz/test_state_changes.py:138:35:            our_balance = channel.get_balance(our_state, partner_state)
raiden/tests/unit/fuzz/test_state_changes.py:140:39:            partner_balance = channel.get_balance(partner_state, our_state)
raiden/tests/unit/test_channelstate.py:83:20:    assert channel.get_balance(end_state, partner_state) == model.balance
raiden/tests/utils/transfer.py:112:28:    our_balance0 = channel.get_balance(channel0.our_state, channel0.partner_state)
raiden/tests/utils/transfer.py:113:32:    partner_balance0 = channel.get_balance(channel0.partner_state, channel0.our_state)
raiden/tests/utils/transfer.py:116:28:    our_balance1 = channel.get_balance(channel1.our_state, channel1.partner_state)
raiden/tests/utils/transfer.py:117:32:    partner_balance1 = channel.get_balance(channel1.partner_state, channel1.our_state)
raiden/tests/utils/transfer.py:158:24:    balance0 = channel.get_balance(original.our_state, original.partner_state)
raiden/tests/utils/transfer.py:159:24:    balance1 = channel.get_balance(mirror.partner_state, mirror.our_state)
raiden/tests/utils/transfer.py:200:20:    assert channel.get_balance(from_channel.our_state, from_channel.partner_state) == balance
raiden/api/python.py:438:20:                target_balance=total_deposit,
raiden/api/v1/encoding.py:185:30:    balance = fields.Method('get_balance')
raiden/api/v1/encoding.py:192:9:    def get_balance(self, channel_state):  # pylint: disable=no-self-use

Backstory

We noticed this problem during a settlement scenario where people did not get back as much as their balance was after settle.

Information on that channel follows:

channel: 84 Kelsos (settler + closer): 4d6fa60e64c7e520899a9aedd40cb1e6992027f0 Cosmin: b2c94bbaf307c6dfbf70cc2537385553385a345b

Open channel: https://etherscan.io/tx/0x23935f8b39366cf7af58da73e9418a91ad65bb1f188680cf448b79eb2038d9af#decodetab

Close transaction: https://etherscan.io/tx/0x9f1c2d92e29ede0c19f87456ee3ca341c0b78f97df58b492b243269f5f039c71

0xb2c94bbaf307c6dfbf70cc2537385553385a345b setTotalDeposit 20: https://etherscan.io/tx/0x97195897b702309faa356d43a949b2801fe63782e12e14460c88731bce0a28c0#decodetab

4d6fa60e64c7e520899a9aedd40cb1e6992027f0 setTotalDeposit 50: https://etherscan.io/tx/0x1957ee719cc6ee702ba82a1953839ad97e4d69b231e137c64ced56e7ea4184d0#decodetab

b2c94bbaf307c6dfbf70cc2537385553385a345b setTotalDeposit 30049: https://etherscan.io/tx/0x654270b77a041e344becc8ea380808e5cbce69affd5d00e48f6b1a55ce6e2aa6#decodetab

b2c94bbaf307c6dfbf70cc2537385553385a345b setTotalDeposit 300000000030050: https://etherscan.io/tx/0x5c7f1f2c50dc1dc552e555e3e925b71732a6d50b6626765bbef6c5f12b39f1e6#decodetab

4d6fa60e64c7e520899a9aedd40cb1e6992027f0 closes channel: https://etherscan.io/tx/0x9f1c2d92e29ede0c19f87456ee3ca341c0b78f97df58b492b243269f5f039c71#decodetab

0xb2c94bbaf307c6dfbf70cc2537385553385a345b updates transfer: https://etherscan.io/tx/0x3ffdf9efca9610ab866e77463a000fe5159364ca5844ab0c61a0d9ce2176da99#decodetab

0x4d6fa60e64c7e520899a9aedd40cb1e6992027f0 settles channel: https://etherscan.io/tx/0x1bfd96784e8610866f65a6619a4601c3441ebb4cb553b242a8f3f6211817bde0

From Logs when kelsos closed

2018-12-19 14:57:39.568000  raiden.raiden_service   debug   node=4d6fa60e state_change={"token_network_identifier": "0xa5C9ECf54790334B73E5DfA1ff5668eB425dC474", "channel_identifier": "84", "_type": "raiden.transfer.state_change.ActionChannelClose", "_version": 0}
2018-12-19 14:57:39.658465  raiden.raiden_service   debug   node=4d6fa60e raiden_event={"channel_identifier": "84", "token_address": "0xC02aaA39b223FE8D0A0e5C4F27eAD9083C756Cc2", "token_network_identifier": "0xa5C9ECf54790334B73E5DfA1ff5668eB425dC474", "balance_proof": {"nonce": 1462, "transferred_amount": "660", "locked_amount": "142", "locksroot": "0xba531c7f2735ceb72a1bd8c4776afcea9ac4390ad2b73050033fdd8863984f81", "token_network_identifier": "0xa5C9ECf54790334B73E5DfA1ff5668eB425dC474", "channel_identifier": "84", "message_hash": "0xcab5ca99fe8627d5419f873ea51c38c9f9932ce4e3e8e890937d8aa33a773fd7", "signature": "0xb6ccf049954d51e132beba9a50387d2d3af5da4e3d0c5de949c65c91dc5e88831b3e37e741261c524eaaab0a078d60474652b8a88d45a88a6ac79ced786d9d9f1c", "sender": "0xB2C94bBaf307C6DfBf70Cc2537385553385a345b", "chain_id": 1, "balance_hash": "0x927aeb82c5cbc791939be8b3e7409b3bb12aeffcf6d6f2b3ea2c232da91b6445", "_type": "raiden.transfer.state.BalanceProofSignedState", "_version": 0}, "_type": "raiden.transfer.events.ContractSendChannelClose", "_version": 0}

From logs when Cosmin settled

2018-12-19 15:00:20.196574  raiden.raiden_service   debug   node=b2c94bba greenlet_name=AlarmTask|Greenlet-2 state_change={"transaction_hash": "0x9f1c2d92e29ede0c19f87456ee3ca341c0b78f97df58b492b243269f5f039c71", "transaction_from": "0x4d6FA60E64C7E520899A9aeDD40cB1E6992027F0", "token_network_identifier": "0xa5C9ECf54790334B73E5DfA1ff5668eB425dC474", "channel_identifier": "84", "block_number": "6915468", "_type": "raiden.transfer.state_change.ContractReceiveChannelClosed", "_version": 0}
2018-12-19 15:00:20.253893  raiden.raiden_service   debug   node=b2c94bba greenlet_name=AlarmTask|Greenlet-2 raiden_event={"expiration": "6915968", "channel_identifier": "84", "token_network_identifier": "0xa5C9ECf54790334B73E5DfA1ff5668eB425dC474", "balance_proof": {"nonce": 146, "transferred_amount": "7", "locked_amount": "142", "locksroot": "0xba531c7f2735ceb72a1bd8c4776afcea9ac4390ad2b73050033fdd8863984f81", "token_network_identifier": "0xa5C9ECf54790334B73E5DfA1ff5668eB425dC474", "channel_identifier": "84", "message_hash": "0x6f9e6f9171f5146556cb942ad7c19b8323aa0724270240fba361633b25e4a496", "signature": "0xe9d007e3f94bc0b7ba1018befe7fd9c8344407a0f34edeb4d6d9ee0648536f171eef8962eea4a1a106cb925ba1408d762c2beb4e00916e5e7ebe58d29ab360f41b", "sender": "0x4d6FA60E64C7E520899A9aeDD40cB1E6992027F0", "chain_id": 1, "balance_hash": "0x47453c5698a6df55e0049a788510b2468ad6570d480f9e5cfca880fd160c925e", "_type": "raiden.transfer.state.BalanceProofSignedState", "_version": 0}, "_type": "raiden.transfer.events.ContractSendChannelUpdateTransfer", "_version": 0}

What was further misleading is that the contract code has a link to an issue at whose beginning has a settle spec of a particular git commit. And at that commit the spec shows a wrong amount for S1. S1 = D1 - W1 + T2 - T1

But that is fixed in latest master. Suggestion: Change that comment in issue 188 to point to the latest spec.

rakanalh commented 5 years ago

Follow up to our discussion: Checking unlock: According to the database i have from @kelsos, i can see that his node tried to unlock:

Event: ContractSendChannelBatchUnlock
{'token_address': '0xC02aaA39b223FE8D0A0e5C4F27eAD9083C756Cc2', 'token_network_identifier': '0xa5C9ECf54790334B73E5DfA1ff5668eB425dC474', 'channel_identifier': '84', 'participant': '0xB2C94bBaf307C6DfBf70Cc2537385553385a345b'}

Is generated as an event when handling the ContractReceiveChannelSettled at block 5915982.

Kelsos will share futher details on what happened to the unlock transaction

kelsos commented 5 years ago

After looking at the logs with @rakanalh it seems as he already mentioned that the node tried to unlock but then failed to do so due to the following error:

{
    "event": "Failed to find state/event that match current channel locksroots. token:0xC02aaA39b223FE8D0A0e5C4F27eAD9083C756Cc2 token_network:0xa5C9ECf54790334B73E5DfA1ff5668eB425dC474 channel:84 participant:0xB2C94bBaf307C6DfBf70Cc2537385553385a345b our_locksroot:0xba531c7f2735ceb72a1bd8c4776afcea9ac4390ad2b73050033fdd8863984f81 partner_locksroot:0xba531c7f2      735ceb72a1bd8c4776afcea9ac4390ad2b73050033fdd8863984f81 ",
    "logger": "raiden.raiden_service",
    "level": "error",
    "greenlet_name": "AlarmTask|Greenlet-2",
    "timestamp": "2018-12-19 17:01:46.562389"
}

You can find the full log file here

konradkonrad commented 5 years ago

our_locksroot:0xba531c7f2735ceb72a1bd8c4776afcea9ac4390ad2b73050033fdd8863984f81 
partner_locksroot:0xba531c7f2735ceb72a1bd8c4776afcea9ac4390ad2b73050033fdd8863984f81

same locksroot on both sides?

LefterisJP commented 5 years ago

@konradkonrad

They got the same locked amount too. ~~Assuming they used the same script to send payments and they are all payments of 1 token the merkle tree and thus the root would be identical I suppose.~~

Wait that does not sound right ... let me have a look.

Additional note: As you can see from the logs in the backstory above this is same locksroot Kelsos used at closing and Cosmin at updating. And also same with settle.

Even if the locked amount is the same since the merkle tree contains the lockhashes, so also the secrethashes the hash can not be the same. We got a problem here.

raiden-network / raiden