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

Jump to bottom

No transport of payments, after expiration, Raiden Client cannot restart #2437

Closed
BCsRock opened this issue Sep 11, 2018 · 17 comments · Fixed by #2451
Closed

No transport of payments, after expiration, Raiden Client cannot restart #2437

BCsRock opened this issue Sep 11, 2018 · 17 comments · Fixed by #2451
Assignees
@hackaugusto @andrevmatos
Labels
Severity / Medium
Milestone
Red Eyes Testnet 9

Comments

@BCsRock
Copy link

BCsRock commented Sep 11, 2018

Problem Definition

Using version 0.8.0, I registered a new token, namely 0x857f67519691Ef449156aadbcCaC71284D6194A7 which was successful.
Link to Etherscan.

I created a channel between two clients.
Open Channel

Deposit of Client 1 into the channel successful
Approve, Deposit

Deposit of Client 2 into the channel successful
Approve, Deposit.

So the interaction with Blockchain was fine and working.

Then I tried to perform off-chain payments by using curl:

Using Client 1 I called curl -i -X POST http://localhost:5001/api/1/payments/0x857f67519691Ef449156aadbcCaC71284D6194A7/0x007Adc0051DD33Bb6640bdF855F6Fe30C2b8634a -H 'Content-Type: application/json' --data-raw '{"amount": 11}'

and then, simply nothing happened. On the Raiden Client 1 Output, the output was:

2018-09-11 13:20:09 [info     ] SEND ASYNC                     [raiden.network.transport.matrix] current_user=@0x000e4f8181c7c9138662d3a442aa3f62423782c5:transport03.raiden.network message=<LockedTransfer [chainid:3 msgid:1834342666909409392 paymentid:1080509321786039909 token_network:8af9a3c9 channel_identifier:1 nonce:1 transferred_amount:0 locked_amount:11 locksroot:cca53e6d hash:b9b200d3 secrethash:8e824cdb expiration:4018868 amount:11]> node=000e4f81 queue_identifier=<QueueIdentifier recipient:007adc00 channel_identifier:1> receiver_address=007adc00

while the output of Raiden Client 2 was not showing any update.

I tried to re-send 11 tokens and than waited until both payment got expired (LockExpired).

Raiden Client 1 output was

2018-09-11 13:23:32 [info     ] SEND ASYNC                     [raiden.network.transport.matrix] current_user=@0x000e4f8181c7c9138662d3a442aa3f62423782c5:transport03.raiden.network message=<LockedTransfer [chainid:3 msgid:18023149619132892077 paymentid:11520075481743338053 token_network:8af9a3c9 channel_identifier:1 nonce:2 transferred_amount:0 locked_amount:22 locksroot:07c51ec3 hash:edbcc363 secrethash:8a68b263 expiration:4018881 amount:11]> node=000e4f81 queue_identifier=<QueueIdentifier recipient:007adc00 channel_identifier:1> receiver_address=007adc00
2018-09-11 13:24:54 [info     ] missed blocks                  [raiden.tasks] current_block=4018871 missed_blocks=1
2018-09-11 13:25:05 [info     ] SEND ASYNC                     [raiden.network.transport.matrix] current_user=@0x000e4f8181c7c9138662d3a442aa3f62423782c5:transport03.raiden.network message=<LockExpired [chainid:3 token_network_address:8af9a3c9 msg_id:16094856046645788168 channel_identifier:1 nonce:3 transferred_amount:0 locked_amount:11 locksroot:6b3c34e0 secrethash:8e824cdb]> node=000e4f81 queue_identifier=<QueueIdentifier recipient:007adc00 channel_identifier:1> receiver_address=007adc00
2018-09-11 13:25:06 [info     ] missed blocks                  [raiden.tasks] current_block=4018875 missed_blocks=1
2018-09-11 13:27:17 [info     ] missed blocks                  [raiden.tasks] current_block=4018887 missed_blocks=1
2018-09-11 13:27:19 [info     ] SEND ASYNC                     [raiden.network.transport.matrix] current_user=@0x000e4f8181c7c9138662d3a442aa3f62423782c5:transport03.raiden.network message=<LockExpired [chainid:3 token_network_address:8af9a3c9 msg_id:4502909836444505275 channel_identifier:1 nonce:3 transferred_amount:0 locked_amount:0 locksroot:00000000 secrethash:8a68b263]> node=000e4f81 queue_identifier=<QueueIdentifier recipient:007adc00 channel_identifier:1> receiver_address=007adc00

while Raiden Client 2 did not show any update.

After that I decided to restart Client 2, which was ok, but did not change anything.
Then I restarted Client 1, which tries to re-send the expired payments and then crashes with error message

2018-09-11 14:11:46 [info     ] Automatically selecting matrix homeserver based on RTT [raiden.network.transport.matrix] homeserver=https://transport01.raiden.network rtt=0.024299666666666664
2018-09-11 14:11:46 [info     ] Lock 140404904254824 acquired on /home/ki/.raiden/node_000e4f81/netid_3/network_f2a175a5/.lock [filelock]
2018-09-11 14:12:15 [info     ] LOGIN                          [raiden.network.transport.matrix] current_user=@0x000e4f8181c7c9138662d3a442aa3f62423782c5:transport01.raiden.network homeserver=transport01.raiden.network node=000e4f81 server_url=https://transport01.raiden.network username=0x000e4f8181c7c9138662d3a442aa3f62423782c5
2018-09-11 14:12:18 [info     ] SEND ASYNC                     [raiden.network.transport.matrix] current_user=@0x000e4f8181c7c9138662d3a442aa3f62423782c5:transport01.raiden.network message=<LockedTransfer [chainid:3 msgid:1834342666909409392 paymentid:1080509321786039909 token_network:8af9a3c9 channel_identifier:1 nonce:1 transferred_amount:0 locked_amount:11 locksroot:cca53e6d hash:b9b200d3 secrethash:8e824cdb expiration:4018868 amount:11]> node=000e4f81 queue_identifier=<QueueIdentifier recipient:007adc00 channel_identifier:1> receiver_address=007adc00
2018-09-11 14:12:18 [info     ] SEND ASYNC                     [raiden.network.transport.matrix] current_user=@0x000e4f8181c7c9138662d3a442aa3f62423782c5:transport01.raiden.network message=<LockedTransfer [chainid:3 msgid:18023149619132892077 paymentid:11520075481743338053 token_network:8af9a3c9 channel_identifier:1 nonce:2 transferred_amount:0 locked_amount:22 locksroot:07c51ec3 hash:edbcc363 secrethash:8a68b263 expiration:4018881 amount:11]> node=000e4f81 queue_identifier=<QueueIdentifier recipient:007adc00 channel_identifier:1> receiver_address=007adc00
Traceback (most recent call last):
  File "raiden-script.py", line 2, in <module>
  File "site-packages/raiden/__main__.py", line 11, in main
  File "site-packages/click/core.py", line 722, in __call__
  File "site-packages/click/core.py", line 697, in main
  File "site-packages/click/core.py", line 1043, in invoke
  File "site-packages/click/core.py", line 895, in invoke
  File "site-packages/click/core.py", line 535, in invoke
  File "site-packages/click/decorators.py", line 17, in new_func
  File "site-packages/raiden/ui/cli.py", line 1105, in run
  File "site-packages/raiden/ui/cli.py", line 938, in run
  File "site-packages/raiden/ui/cli.py", line 956, in _run_app
  File "site-packages/raiden/ui/cli.py", line 775, in run_app
  File "site-packages/raiden/app.py", line 134, in start
  File "site-packages/raiden/raiden_service.py", line 326, in start
  File "site-packages/raiden/network/transport/matrix.py", line 208, in start
  File "site-packages/raiden/network/transport/matrix.py", line 684, in _send_queued_messages
  File "site-packages/raiden/network/transport/matrix.py", line 1089, in _event_to_message
TypeError: Event type <class 'raiden.transfer.mediated_transfer.events.SendLockExpired'> is not supported.
[18922] Failed to execute script raiden-script

The last line indicates it could have to do with trying to send LockExpired transfers. (A bug maybe?)

So finally I have two problems:

  1. Raiden Clients could not exchange messages between each other. Eventually, the payment got expired. Something to do with Matrix Transport servers?
  2. One of the Raiden client cannot restart after payments got expired.

System Description

Ubuntu 16.04 LTS (both clients)
Infura Endpoint using Geth (both clients)
raiden-v0.8.0-linux binary from github release page
@LefterisJP
Copy link
Contributor

Hey @BCsRock.

Thanks a bunch for testing Raiden!
The issue you describe sounds similar to #2419 which is now fixed in latest master thanks to #2420

@BCsRock
Copy link
Author

BCsRock commented Sep 11, 2018

Awesome :-)

But do you think it can fix both of the above issues?
(1. no message exchange, 2. no restart)

@LefterisJP
Copy link
Contributor

So the no restart message is due to the crash right? So that should be fixed.

For the problem of no exchange of messages we would have to see the logs of both the nodes. The only reason this can happen if somehow they can't see each other.

@BCsRock
Copy link
Author

BCsRock commented Sep 12, 2018

I tried to use the night-builds from 11/09 and 12/09

raiden-nightly-2018.09.12-linux.tar.gz
raiden-nightly-2018.09.11-linux.tar.gz

However, using both I immediately get the error when starting the client:

Traceback (most recent call last):
  File "site-packages/pkg_resources/__init__.py", line 2619, in requires
KeyError: 'tester'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "raiden-script.py", line 2, in <module>
  File "site-packages/raiden/__main__.py", line 11, in main
  File "site-packages/click/core.py", line 722, in __call__
  File "site-packages/click/core.py", line 697, in main
  File "site-packages/click/core.py", line 1043, in invoke
  File "site-packages/click/core.py", line 895, in invoke
  File "site-packages/click/core.py", line 535, in invoke
  File "site-packages/click/decorators.py", line 17, in new_func
  File "site-packages/raiden/ui/cli.py", line 1110, in run
  File "site-packages/raiden/ui/cli.py", line 891, in run
  File "site-packages/raiden/ui/cli.py", line 880, in _welcome_string
  File "site-packages/raiden/utils/__init__.py", line 192, in get_system_spec
  File "site-packages/pkg_resources/__init__.py", line 895, in require
  File "site-packages/pkg_resources/__init__.py", line 789, in resolve
  File "site-packages/pkg_resources/__init__.py", line 2622, in requires
pkg_resources.UnknownExtra: web3 4.6.0 has no such extra feature 'tester'
[3116] Failed to execute script raiden-script

Is that a bug inside the nightly builds related to web3?

@ulope
Copy link
Collaborator

ulope commented Sep 12, 2018

@BCsRock yes, there was a dependency conflict in web3 4.6.0 they have now released 4.7.1 which fixes this issue. Tomorrow’s build should be fine.

@BCsRock
Copy link
Author

BCsRock commented Sep 12, 2018

I deleted all .raiden folders and tried again.
Messages won't reach the other client. The funny thing is, it doesn't even matter if both clients are on the same matrix transport server or on different.

Is there some strategy to test the connectivity with the Transport Server?

Client 1 Output when connecting to Matrix Server

Enter the password to unlock 0x00F664B452aF2EE98b85096C83117DDaabfF7851:
Checking if the ethereum node is synchronized

You are connected to the 'ropsten' network and the DB path is: /home/vagrant/.raiden/node_00f664b4/netid_3/network_f2a175a5/v1_log.db
2018-09-12 13:59:03 [info     ] Automatically selecting matrix homeserver based on RTT [raiden.network.transport.matrix] homeserver=https://transport03.raiden.network rtt=0.04006033333333334
2018-09-12 13:59:04 [info     ] Lock 140657318243464 acquired on /home/vagrant/.raiden/node_00f664b4/netid_3/network_f2a175a5/.lock [filelock]
2018-09-12 14:02:45 [info     ] missed blocks                  [raiden.tasks] current_block=4025491 missed_blocks=18
2018-09-12 14:02:47 [info     ] LOGIN                          [raiden.network.transport.matrix] current_user=@0x00f664b452af2ee98b85096c83117ddaabff7851:transport03.raiden.network homeserver=transport03.raiden.network node=00f664b4 server_url=https://transport03.raiden.network username=0x00f664b452af2ee98b85096c83117ddaabff7851
2018-09-12 14:02:49 [info     ] TRANSPORT STARTED              [raiden.network.transport.matrix] config={'available_servers': ['https://transport01.raiden.network', 'https://transport02.raiden.network', 'https://transport03.raiden.network'], 'discovery_room': {'alias_fragment': 'discovery', 'server': 'transport01.raiden.network'}, 'retries_before_backoff': 5, 'retry_interval': 5.0, 'server': 'auto'} current_user=@0x00f664b452af2ee98b85096c83117ddaabff7851:transport03.raiden.network node=00f664b4
The Raiden API RPC server is now running at http://127.0.0.1:5001/.

Client 2 Output when connecting to Matrix Server

Enter the password to unlock 0x00a9C96a2875F135abad6bb872C3D7890BaA4d53:
Checking if the ethereum node is synchronized

You are connected to the 'ropsten' network and the DB path is: /home/vagrant/.raiden/node_00a9c96a/netid_3/network_f2a17
2018-09-12 13:31:25 [info     ] Automatically selecting matrix homeserver based on RTT [raiden.network.transport.matrix]3.raiden.network rtt=0.046147
2018-09-12 13:31:26 [info     ] Lock 140604881668808 acquired on /home/vagrant/.raiden/node_00a9c96a/netid_3/network_f2a
2018-09-12 13:36:47 [info     ] missed blocks                  [raiden.tasks] current_block=4025335 missed_blocks=19
2018-09-12 13:36:51 [info     ] LOGIN                          [raiden.network.transport.matrix] current_user=@0x00a9c96a2875f135abad6bb872c3d7890baa4d53:transport03.raiden.network homeserver=transport03.raiden.network node=00a9c96a server_url=https://transport03.raiden.network username=0x00a9c96a2875f135abad6bb872c3d7890baa4d53
2018-09-12 13:36:55 [info     ] TRANSPORT STARTED              [raiden.network.transport.matrix] config={'available_servers': ['https://transport01.raiden.network', 'https://transport02.raiden.network', 'https://transport03.raiden.network'], 'discovery_room': {'alias_fragment': 'discovery', 'server': 'transport01.raiden.network'}, 'retries_before_backoff': 5, 'retry_interval': 5.0, 'server': 'auto'} current_user=@0x00a9c96a2875f135abad6bb872c3d7890baa4d53:transport03.raiden.network node=00a9c96a
The Raiden API RPC server is now running at http://127.0.0.1:5002/.

@LefterisJP
Copy link
Contributor

@BCsRock This seems like it's an actual issue. Can you edit it into the initial issue description? We will investigate and fix it.

@LefterisJP LefterisJP added this to the Red Eyes Testnet 9 milestone Sep 12, 2018
@andrevmatos andrevmatos mentioned this issue Sep 12, 2018
Merged
@andrevmatos
Copy link
Contributor

The communication issue was caused by a concurrency bug: the rooms the node should listen on are populated on initial matrix sync, but that didn't complete at the time we listed these rooms, so we didn't listen on rooms that we joined before. #2451 fix this by waiting for the initial sync.

@BCsRock
Copy link
Author

BCsRock commented Sep 12, 2018 •
edited

@LefterisJP and @andrevmatos I figured something new out!

I re-used accounts basically which I used from version 0.5.0 up to 0.7.0. and then encountered the above transport problem.

Now I have just made 2 fresh ethereum addresses with fresh ETH and KIRDN Token (my ERC20) and et voila it works again.

Observation so far:
During the upgrade from (probably) version 0.7.0 to 0.8.0 old addresses registered within the Matrix Transport Severs cannot be re-used.

Edit: Changed "Conclusion" into "Observation"

@andrevmatos
Copy link
Contributor

@BCsRock no, it did work on new addresses because new rooms were created (with new addresses) and INVITEs for these new rooms made it work on the first session. If you restart some or all the dones, you may experience it anyway, it's not the new accounts which made it work, but new/invited rooms.

@BCsRock
Copy link
Author

BCsRock commented Sep 12, 2018

Ok, then what needs to be done in order to get the old addresses useable again?

@LefterisJP
Copy link
Contributor

Use the latest release which will include the fix introduced by @andrevmatos in #2451 or attempt to use latest master.

@ulope
Copy link
Collaborator

ulope commented Sep 12, 2018

Also tonight’s nightly build will include both fixes.

@BCsRock
Copy link
Author

BCsRock commented Sep 13, 2018

Guys, thank you! Awesome work. Eager to try it out!

@BCsRock
Copy link
Author

BCsRock commented Sep 13, 2018

Tested with the nightly build raiden-nightly-2018.09.13-linux.tar.gz

Raiden Client crashes immediately, with web3 error :-/

ki@raiden:~$ ./raiden-v0.8.1.dev71+g34708f1b-linux --eth-rpc-endpoint "https://ropsten.infura.io/gwO9HkTplkGaR2q7Du7N:8545" --keystore-path ~/.keys/test/ --listen-address 0.0.0.0:40001 --api-address 0.0.0.0:5001
Traceback (most recent call last):
  File "site-packages/pkg_resources/__init__.py", line 2619, in requires
KeyError: 'tester'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "raiden-script.py", line 2, in <module>
  File "site-packages/raiden/__main__.py", line 11, in main
  File "site-packages/click/core.py", line 722, in __call__
  File "site-packages/click/core.py", line 697, in main
  File "site-packages/click/core.py", line 1043, in invoke
  File "site-packages/click/core.py", line 895, in invoke
  File "site-packages/click/core.py", line 535, in invoke
  File "site-packages/click/decorators.py", line 17, in new_func
  File "site-packages/raiden/ui/cli.py", line 1110, in run
  File "site-packages/raiden/ui/cli.py", line 891, in run
  File "site-packages/raiden/ui/cli.py", line 880, in _welcome_string
  File "site-packages/raiden/utils/__init__.py", line 192, in get_system_spec
  File "site-packages/pkg_resources/__init__.py", line 895, in require
  File "site-packages/pkg_resources/__init__.py", line 789, in resolve
  File "site-packages/pkg_resources/__init__.py", line 2622, in requires
pkg_resources.UnknownExtra: web3 4.7.1 has no such extra feature 'tester'
[4514] Failed to execute script raiden-script

@LefterisJP
Copy link
Contributor

@BCsRock this seems to be another error. Latest master works fine from source but not the released binary. I can reproduce your problem only with the nightly binary. Will make a different issue

@LefterisJP
Copy link
Contributor

And here is the issue

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@hackaugusto hackaugusto

@andrevmatos andrevmatos

Labels
Severity / Medium
Projects
None yet
Milestone
Red Eyes Testnet 9
Development

Successfully merging a pull request may close this issue.

Wait for initial sync to complete on matrix andrevmatos/raiden
5 participants
@ulope @hackaugusto @andrevmatos @LefterisJP @BCsRock