Skip to content
This repository has been archived by the owner on Nov 6, 2020. It is now read-only.

[Light client] Disconnect all its peers subsequently to an eth_call #9551

Closed
Tbaut opened this issue Sep 13, 2018 · 11 comments · Fixed by #9591
Closed

[Light client] Disconnect all its peers subsequently to an eth_call #9551

Tbaut opened this issue Sep 13, 2018 · 11 comments · Fixed by #9591
Assignees
@ordian
Labels
F3-annoyance 💩 The client behaves within expectations, however this “expected behaviour” itself is at issue. M4-core ⛓ Core client code / Rust. P2-asap 🌊 No need to stop dead in your tracks, however issue should be addressed as soon as possible.
Milestone
2.2

Comments

@Tbaut
Copy link
Contributor

Tbaut commented Sep 13, 2018 •
edited
Loading

  • Parity Ethereum version:v2.2.0-unstable-6b39131-20180913
  • Operating system: Linux
  • Installation: built from source
  • Fully synchronized: yes
  • Network: kovan
  • Restarted: yes

How to reproduce :
Launching parity with:
parity --light --chain kovan -l on_demand,rpc
and calling the bellow RPC a coupe times (it hapened after 4-5 times), it ends up in a state where all peers have been disconnected.
edit: I sometimes can't reproduce it even after ~20 calls

$ curl --data '{"method":"eth_call","params":[{"to":"0x4a6e6c3868a279e1d9047b42c3fb356ff4680003","data":"0x70a08231000000000000000000000000004702bdcc3c7dbffd943136107e70b827028600"},"latest"],"id":1,"jsonrpc":"2.0"}' -H "Content-Type: application/json" -X POST localhost:8545
{"jsonrpc":"2.0","result":"0x0000000000000000000000000000000000000000019d944653184202a34c0000","id":1}

After getting the above result (all good), I get:

$ curl --data '{"method":"eth_call","params":[{"to":"0x4a6e6c3868a279e1d9047b42c3fb356ff4680003","data":"0x70a08231000000000000000000000000004702bdcc3c7dbffd943136107e70b827028600"},"latest"],"id":1,"jsonrpc":"2.0"}' -H "Content-Type: application/json" -X POST localhost:8545
{"jsonrpc":"2.0","error":{"code":-32065,"message":"Timeout for On-demand query; 1 query attempts remain for query #0"},"id":1}

This makes the light client disconnect to all its peers (from originally 5 to 0), here are the full logs with rpc and on_demand traces
@ordian ordian self-assigned this Sep 13, 2018
@Tbaut Tbaut added P2-asap 🌊 No need to stop dead in your tracks, however issue should be addressed as soon as possible. F3-annoyance 💩 The client behaves within expectations, however this “expected behaviour” itself is at issue. M4-core ⛓ Core client code / Rust. labels Sep 13, 2018
@Tbaut Tbaut added this to the 2.1 milestone Sep 13, 2018
@Tbaut
Copy link
Contributor Author

Tbaut commented Sep 13, 2018

Note that I can not reproduce it all the time :/

@niklasad1
Copy link
Collaborator

I haven't been able to reproduce this yet

@Tbaut
Copy link
Contributor Author

Tbaut commented Sep 13, 2018

One thing that can help reproduce it very quickly:

  • launch a light client as stated above : parity --light --chain kovan -l on_demand,rpc
  • launch/install fether
  • add some accounts, add some tokens (anything like Gavcoin) and navigate around, no need to have eth or token.

Fether sends a lot of requests and I generally I am able to freeze it in 30sec max.
Ask me anything if you can't reproduce.

@niklasad1
Copy link
Collaborator

niklasad1 commented Sep 14, 2018 •
edited
Loading

@Tbaut

Ok, I have no real idea why it is dropping all its peer maybe related to #9526

However the freezing is probably because:

technically every execution request on a non-existent account will end up in a BadProof.
If the the account is not found the provider (full node, runs the execution) will create a default account with zero balance!
Because the provider can't distinguish between different executions (read-only and things that actually changes the state) such as eth_call vs eth_sendTransaction!
The execution will always fail because of zero balance on the account.
and it will always send BadProof (which doesn't say anything about the internal execution error) and the light client waits for a "valid response"until it times out!

So, should we expose a new request type for ReadOnlyExecution, drop the execution request when we get a BadProof or something else?

@Tbaut
Copy link
Contributor Author

Tbaut commented Sep 14, 2018

^ cc @tomaka or @cheme, @ordian what do you think ?

@ordian
Copy link
Collaborator

ordian commented Sep 14, 2018

I agree with @niklasad1, looks like implementation of proved_execution used by call and estimate_gas is incorrect.

@cheme
Copy link
Contributor

cheme commented Sep 14, 2018

About the BadProof I am thinking of a possible race :

  • before ondemand execution send its query (ondemand execution is always readonly), proved_execution store block_id::latest in envinfo, but also fetch the headers of the latest block B1, those are stored in ExecuteParams and in TransactionProof for later use.
  • the ondemand execution query is sent to distant peer, in-between there is a new block
  • distant peer execute on the new block B2 (blockid being 'latest')
  • when we get its values and try to check proof we use previously initialised TransactionProof corresponding to B1 state -> BadProof

This seems like a possibility to me (I may have miss something in my code reading). The log got a block import before failing which means the occurrence of bad proof were close to a new block, it would be interesting to confirm it with other logs.

@niklasad1 niklasad1 mentioned this issue Sep 19, 2018
Merged
@cheme
Copy link
Contributor

cheme commented Sep 19, 2018

I got some positive results, running cheme@39ab72e . So there is probably also the race problem from my previous comment to fix. Not sure about the way to fix it properly (in my branch hacky fix, we may be querying a block before the latest).

@niklasad1
Copy link
Collaborator

@cheme

I'm fairly confident that #9591 solves this issue and it actually matches the behavior that we have in the full-node implementation, see https://github.com/paritytech/parity-ethereum/blob/master/ethcore/src/client/client.rs#L1501 and https://github.com/paritytech/parity-ethereum/blob/master/ethcore/src/client/client.rs#L1244

@5chdn 5chdn modified the milestones: 2.1, 2.2 Sep 19, 2018
@ordian
Copy link
Collaborator

ordian commented Sep 21, 2018

After connecting a light client to a reserved full node (with #9608), it seems like the light client is making too many requests in a loop thus loosing all credits (it doesn't because of #9448):

2018-09-21 17:16:21  IO Worker #3 TRACE pip  Received requests (id: 40421) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Beginning to respond to requests (id: 40421) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Responded to 0/1 requests in packet 40421
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Received requests (id: 40422) from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Beginning to respond to requests (id: 40422) from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Responded to 0/1 requests in packet 40422
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Received requests (id: 40423) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Beginning to respond to requests (id: 40423) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Responded to 0/1 requests in packet 40423
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Received requests (id: 40424) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Beginning to respond to requests (id: 40424) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Responded to 0/1 requests in packet 40424
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Received requests (id: 40425) from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Beginning to respond to requests (id: 40425) from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Responded to 0/1 requests in packet 40425
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Received requests (id: 40426) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Beginning to respond to requests (id: 40426) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Responded to 0/1 requests in packet 40426
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Received requests (id: 40427) from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Beginning to respond to requests (id: 40427) from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Responded to 0/1 requests in packet 40427
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Received requests (id: 40428) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Beginning to respond to requests (id: 40428) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Responded to 0/1 requests in packet 40428
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Received requests (id: 40429) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Beginning to respond to requests (id: 40429) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Responded to 0/1 requests in packet 40429
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Received requests (id: 40430) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Beginning to respond to requests (id: 40430) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Responded to 0/1 requests in packet 40430
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Received requests (id: 40431) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Beginning to respond to requests (id: 40431) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Responded to 0/1 requests in packet 40431
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Received requests (id: 40432) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Beginning to respond to requests (id: 40432) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Responded to 0/1 requests in packet 40432
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Received requests (id: 40433) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Beginning to respond to requests (id: 40433) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Responded to 0/1 requests in packet 40433
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Received requests (id: 40434) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Beginning to respond to requests (id: 40434) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Responded to 0/1 requests in packet 40434
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Received requests (id: 40435) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Beginning to respond to requests (id: 40435) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Responded to 0/1 requests in packet 40435
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Received requests (id: 40436) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Beginning to respond to requests (id: 40436) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Responded to 0/1 requests in packet 40436
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Received requests (id: 40437) from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Beginning to respond to requests (id: 40437) from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Responded to 0/1 requests in packet 40437
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Received requests (id: 40438) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Beginning to respond to requests (id: 40438) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Responded to 0/1 requests in packet 40438
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Received requests (id: 40439) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Beginning to respond to requests (id: 40439) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Responded to 0/1 requests in packet 40439
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Received requests (id: 40440) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Beginning to respond to requests (id: 40440) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Responded to 0/1 requests in packet 40440
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Received requests (id: 40441) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Beginning to respond to requests (id: 40441) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Responded to 0/1 requests in packet 40441
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Received requests (id: 40442) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Beginning to respond to requests (id: 40442) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Responded to 0/1 requests in packet 40442
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Received requests (id: 40443) from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Beginning to respond to requests (id: 40443) from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Responded to 0/1 requests in packet 40443
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Received requests (id: 40444) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Beginning to respond to requests (id: 40444) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Responded to 0/1 requests in packet 40444
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Received requests (id: 40445) from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Beginning to respond to requests (id: 40445) from peer 0
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Responded to 0/1 requests in packet 40445
2018-09-21 17:16:21  IO Worker #1 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Received requests (id: 40446) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Beginning to respond to requests (id: 40446) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Responded to 0/1 requests in packet 40446
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Received requests (id: 40447) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Beginning to respond to requests (id: 40447) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Responded to 0/1 requests in packet 40447
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Received requests (id: 40448) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Beginning to respond to requests (id: 40448) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Responded to 0/1 requests in packet 40448
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Received requests (id: 40449) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Beginning to respond to requests (id: 40449) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Responded to 0/1 requests in packet 40449
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Received requests (id: 40450) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Beginning to respond to requests (id: 40450) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Responded to 0/1 requests in packet 40450
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Received requests (id: 40451) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Beginning to respond to requests (id: 40451) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Responded to 0/1 requests in packet 40451
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Received requests (id: 40452) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Beginning to respond to requests (id: 40452) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Responded to 0/1 requests in packet 40452
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Received requests (id: 40453) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Beginning to respond to requests (id: 40453) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Responded to 0/1 requests in packet 40453
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Received requests (id: 40454) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Beginning to respond to requests (id: 40454) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Responded to 0/1 requests in packet 40454
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Received requests (id: 40455) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Beginning to respond to requests (id: 40455) from peer 0
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Responded to 0/1 requests in packet 40455
2018-09-21 17:16:21  IO Worker #0 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Received requests (id: 40456) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Beginning to respond to requests (id: 40456) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Responded to 0/1 requests in packet 40456
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Received requests (id: 40457) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Beginning to respond to requests (id: 40457) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Responded to 0/1 requests in packet 40457
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Received requests (id: 40458) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Beginning to respond to requests (id: 40458) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Responded to 0/1 requests in packet 40458
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Received requests (id: 40459) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Beginning to respond to requests (id: 40459) from peer 0
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Responded to 0/1 requests in packet 40459
2018-09-21 17:16:21  IO Worker #2 TRACE pip  Peer 0 has 18446744073709551615 credits remaining.
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Incoming packet 2 from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Received requests (id: 40460) from peer 0
2018-09-21 17:16:21  IO Worker #3 TRACE pip  Beginning to respond to requests (id: 40460) from peer 0

@Tbaut
Copy link
Contributor Author

Tbaut commented Sep 24, 2018

I'm not sure it's the reason @ordian.
Here is a pip trace going from 6 peers to 0. And it looks like I still get credits

2018-09-24 11:23:44  IO Worker #1 INFO import     6/50 peers   2 MiB cache 0 bytes queue  RPC:  1 conn,    7 req/s,  152 µs
2018-09-24 11:23:45  IO Worker #3 TRACE pip  Sending status to peer 56
2018-09-24 11:23:45  IO Worker #1 TRACE pip  Peer 56 disconnecting
2018-09-24 11:23:48  IO Worker #2 TRACE pip  Incoming packet 1 from peer 34
2018-09-24 11:23:48  IO Worker #2 TRACE pip  requesting from peer 34. Cost: 1330496; Available: 30000000000
2018-09-24 11:23:48  IO Worker #0 TRACE pip  Incoming packet 1 from peer 47
2018-09-24 11:23:48  IO Worker #3 TRACE pip  Incoming packet 1 from peer 24
2018-09-24 11:23:48  IO Worker #3 TRACE pip  Incoming packet 1 from peer 45
2018-09-24 11:23:48  IO Worker #1 TRACE pip  Incoming packet 1 from peer 19
2018-09-24 11:23:48  IO Worker #2 TRACE pip  Sending status to peer 14
2018-09-24 11:23:48  IO Worker #0 TRACE pip  Peer 14 disconnecting
2018-09-24 11:23:48  IO Worker #0 TRACE pip  Incoming packet 1 from peer 36
2018-09-24 11:23:48  IO Worker #2 TRACE pip  Incoming packet 3 from peer 34
2018-09-24 11:23:48  IO Worker #2 TRACE pip  pre-verifying response for Request #477 from peer 34
2018-09-24 11:23:48  IO Worker #2 TRACE pip  requesting from peer 19. Cost: 26884; Available: 30000000000
2018-09-24 11:23:49  IO Worker #0 TRACE pip  Incoming packet 3 from peer 19
2018-09-24 11:23:49  IO Worker #0 TRACE pip  pre-verifying response for Request #478 from peer 19
2018-09-24 11:23:49  Verifier #0 INFO import  Imported #8838535 0xd5f1…e978 (0.16 Mgas)
2018-09-24 11:23:49  IO Worker #1 TRACE pip  Sending status to peer 7
2018-09-24 11:23:49  IO Worker #1 TRACE pip  Peer 7 disconnecting
2018-09-24 11:23:51  IO Worker #3 TRACE pip  Sending status to peer 7
2018-09-24 11:23:51  IO Worker #3 TRACE pip  Peer 7 disconnecting
2018-09-24 11:23:51  IO Worker #1 TRACE pip  Sending status to peer 26
2018-09-24 11:23:51  IO Worker #2 TRACE pip  Peer 26 disconnecting
2018-09-24 11:23:52  IO Worker #1 TRACE pip  Sending status to peer 26
2018-09-24 11:23:52  IO Worker #0 TRACE pip  Peer 26 disconnecting
2018-09-24 11:23:52  IO Worker #2 TRACE pip  Sending status to peer 46
2018-09-24 11:23:52  IO Worker #3 TRACE pip  Peer 46 disconnecting
2018-09-24 11:23:53  IO Worker #2 TRACE pip  Sending status to peer 17
2018-09-24 11:23:53  IO Worker #0 TRACE pip  Peer 17 disconnecting
2018-09-24 11:23:53  IO Worker #0 TRACE pip  Sending status to peer 61
2018-09-24 11:23:53  IO Worker #2 TRACE pip  Peer 61 disconnecting
2018-09-24 11:23:53  IO Worker #1 TRACE pip  Sending status to peer 28
2018-09-24 11:23:53  IO Worker #3 TRACE pip  Peer 28 disconnecting
2018-09-24 11:23:54  IO Worker #2 TRACE pip  Sending status to peer 3
2018-09-24 11:23:54  IO Worker #0 TRACE pip  Peer 3 disconnecting
2018-09-24 11:23:54   TRACE pip  requesting from peer 34. Cost: 606995; Available: 30000000000
2018-09-24 11:23:54   TRACE pip  requesting from peer 34. Cost: 606995; Available: 29999393005
2018-09-24 11:23:54   TRACE pip  requesting from peer 19. Cost: 502013; Available: 30000000000
2018-09-24 11:23:54  IO Worker #3 TRACE pip  Sending status to peer 37
2018-09-24 11:23:54  IO Worker #2 TRACE pip  Peer 37 disconnecting
2018-09-24 11:23:54  IO Worker #3 TRACE pip  Incoming packet 3 from peer 34
2018-09-24 11:23:54  IO Worker #3 TRACE pip  pre-verifying response for Request #479 from peer 34
2018-09-24 11:23:54   TRACE pip  requesting from peer 34. Cost: 606995; Available: 29998786010
2018-09-24 11:23:54   TRACE pip  requesting from peer 34. Cost: 606995; Available: 29998179015
2018-09-24 11:23:54  IO Worker #2 TRACE pip  Incoming packet 3 from peer 19
2018-09-24 11:23:54  IO Worker #2 TRACE pip  pre-verifying response for Request #481 from peer 19
2018-09-24 11:23:55  IO Worker #1 TRACE pip  Incoming packet 3 from peer 34
2018-09-24 11:23:55  IO Worker #1 TRACE pip  pre-verifying response for Request #480 from peer 34
2018-09-24 11:23:55  IO Worker #2 TRACE pip  Incoming packet 3 from peer 34
2018-09-24 11:23:55  IO Worker #2 TRACE pip  pre-verifying response for Request #482 from peer 34
2018-09-24 11:23:55  IO Worker #1 TRACE pip  Incoming packet 3 from peer 34
2018-09-24 11:23:55  IO Worker #1 TRACE pip  pre-verifying response for Request #483 from peer 34
2018-09-24 11:23:55   TRACE pip  requesting from peer 19. Cost: 950000; Available: 29999497987
2018-09-24 11:23:55  IO Worker #2 TRACE pip  Incoming packet 3 from peer 19
2018-09-24 11:23:55  IO Worker #2 TRACE pip  pre-verifying response for Request #484 from peer 19
2018-09-24 11:23:55   TRACE pip  requesting from peer 47. Cost: 290483; Available: 30000000000
2018-09-24 11:23:55   TRACE pip  requesting from peer 45. Cost: 239504; Available: 30000000000
2018-09-24 11:23:55   TRACE pip  requesting from peer 34. Cost: 606995; Available: 29997572020
2018-09-24 11:23:55   TRACE pip  requesting from peer 45. Cost: 239504; Available: 29999760496
2018-09-24 11:23:55   TRACE pip  requesting from peer 19. Cost: 502013; Available: 29999050000
2018-09-24 11:23:55   TRACE pip  requesting from peer 24. Cost: 718791; Available: 30000000000
2018-09-24 11:23:55  IO Worker #2 TRACE pip  Incoming packet 3 from peer 47
2018-09-24 11:23:55  IO Worker #2 TRACE pip  pre-verifying response for Request #485 from peer 47
2018-09-24 11:23:55  IO Worker #3 TRACE pip  Incoming packet 3 from peer 34
2018-09-24 11:23:55  IO Worker #3 TRACE pip  pre-verifying response for Request #487 from peer 34
2018-09-24 11:23:55   TRACE pip  requesting from peer 34. Cost: 850000; Available: 29999393005
2018-09-24 11:23:55  IO Worker #0 TRACE pip  Incoming packet 3 from peer 24
2018-09-24 11:23:55  IO Worker #0 TRACE pip  pre-verifying response for Request #490 from peer 24
2018-09-24 11:23:55   TRACE pip  requesting from peer 45. Cost: 1150000; Available: 29999520992
2018-09-24 11:23:55  IO Worker #3 TRACE pip  Incoming packet 3 from peer 45
2018-09-24 11:23:55  IO Worker #3 TRACE pip  pre-verifying response for Request #486 from peer 45
2018-09-24 11:23:56  IO Worker #0 TRACE pip  Incoming packet 3 from peer 19
2018-09-24 11:23:56  IO Worker #0 TRACE pip  pre-verifying response for Request #489 from peer 19
2018-09-24 11:23:56  IO Worker #2 TRACE pip  Incoming packet 3 from peer 45
2018-09-24 11:23:56  IO Worker #2 TRACE pip  pre-verifying response for Request #488 from peer 45
2018-09-24 11:23:56   TRACE pip  requesting from peer 47. Cost: 290483; Available: 29999709517
2018-09-24 11:23:56   TRACE pip  requesting from peer 24. Cost: 718791; Available: 29999281209
2018-09-24 11:23:56   TRACE pip  requesting from peer 24. Cost: 718791; Available: 29998562418
2018-09-24 11:23:56   TRACE pip  requesting from peer 36. Cost: 528147; Available: 30000000000
2018-09-24 11:23:56   TRACE pip  requesting from peer 36. Cost: 528147; Available: 29999471853
2018-09-24 11:23:56  IO Worker #3 TRACE pip  Incoming packet 1 from peer 47
2018-09-24 11:23:56  IO Worker #3 TRACE pip  requesting from peer 47. Cost: 4100224; Available: 29999419034
2018-09-24 11:23:56   TRACE pip  requesting from peer 24. Cost: 718791; Available: 29997843627
2018-09-24 11:23:56  IO Worker #1 TRACE pip  Incoming packet 3 from peer 34
2018-09-24 11:23:56  IO Worker #1 TRACE pip  pre-verifying response for Request #491 from peer 34
2018-09-24 11:23:56  IO Worker #1 TRACE pip  Incoming packet 1 from peer 36
2018-09-24 11:23:56  IO Worker #0 TRACE pip  Incoming packet 3 from peer 47
2018-09-24 11:23:56  IO Worker #0 TRACE pip  pre-verifying response for Request #493 from peer 47
2018-09-24 11:23:56  IO Worker #0 TRACE pip  Incoming packet 3 from peer 45
2018-09-24 11:23:56  IO Worker #0 TRACE pip  pre-verifying response for Request #492 from peer 45
2018-09-24 11:23:56  IO Worker #1 TRACE pip  Incoming packet 1 from peer 24
2018-09-24 11:23:56  IO Worker #0 TRACE pip  Incoming packet 3 from peer 36
2018-09-24 11:23:56  IO Worker #0 TRACE pip  pre-verifying response for Request #496 from peer 36
2018-09-24 11:23:56  IO Worker #3 TRACE pip  Incoming packet 1 from peer 34
2018-09-24 11:23:56  IO Worker #1 TRACE pip  Incoming packet 3 from peer 36
2018-09-24 11:23:56  IO Worker #1 TRACE pip  pre-verifying response for Request #497 from peer 36
2018-09-24 11:23:56  IO Worker #0 TRACE pip  Incoming packet 1 from peer 19
2018-09-24 11:23:56  IO Worker #2 TRACE pip  Incoming packet 1 from peer 45
2018-09-24 11:23:56  IO Worker #3 TRACE pip  Incoming packet 3 from peer 24
2018-09-24 11:23:56  IO Worker #3 TRACE pip  pre-verifying response for Request #494 from peer 24
2018-09-24 11:23:56  IO Worker #0 TRACE pip  Incoming packet 3 from peer 24
2018-09-24 11:23:56  IO Worker #0 TRACE pip  pre-verifying response for Request #495 from peer 24
2018-09-24 11:23:56   TRACE pip  requesting from peer 19. Cost: 950000; Available: 29998547987
2018-09-24 11:23:56  IO Worker #3 TRACE pip  Incoming packet 3 from peer 47
2018-09-24 11:23:56  IO Worker #3 TRACE pip  pre-verifying response for Request #498 from peer 47
2018-09-24 11:23:56  IO Worker #3 TRACE pip  requesting from peer 24. Cost: 35934; Available: 29997124836
2018-09-24 11:23:56   TRACE pip  requesting from peer 45. Cost: 239504; Available: 29998370992
2018-09-24 11:23:56   TRACE pip  requesting from peer 24. Cost: 718791; Available: 29997088902
2018-09-24 11:23:56   TRACE pip  requesting from peer 45. Cost: 239504; Available: 29998131488
2018-09-24 11:23:56   TRACE pip  requesting from peer 19. Cost: 502013; Available: 29997597987
2018-09-24 11:23:56   TRACE pip  requesting from peer 36. Cost: 528147; Available: 29999471853
2018-09-24 11:23:56   TRACE pip  requesting from peer 47. Cost: 290483; Available: 29995899776
2018-09-24 11:23:56  IO Worker #1 TRACE pip  Incoming packet 3 from peer 24
2018-09-24 11:23:56  IO Worker #1 TRACE pip  pre-verifying response for Request #499 from peer 24
2018-09-24 11:23:56   TRACE pip  requesting from peer 34. Cost: 850000; Available: 29998543005
2018-09-24 11:23:56  IO Worker #2 TRACE pip  Incoming packet 3 from peer 36
2018-09-24 11:23:56  IO Worker #2 TRACE pip  pre-verifying response for Request #506 from peer 36
2018-09-24 11:23:56  IO Worker #3 TRACE pip  Incoming packet 3 from peer 47
2018-09-24 11:23:56  IO Worker #3 TRACE pip  pre-verifying response for Request #507 from peer 47
2018-09-24 11:23:57   TRACE pip  requesting from peer 47. Cost: 1700000; Available: 29995609293
2018-09-24 11:23:57  IO Worker #1 TRACE pip  Incoming packet 3 from peer 24
2018-09-24 11:23:57  IO Worker #1 TRACE pip  pre-verifying response for Request #501 from peer 24
2018-09-24 11:23:57  Verifier #2 INFO import  Imported #8838537 0xcd9e…3507 (0.11 Mgas)
2018-09-24 11:23:57  IO Worker #2 TRACE pip  Incoming packet 3 from peer 19
2018-09-24 11:23:57  IO Worker #2 TRACE pip  pre-verifying response for Request #500 from peer 19
2018-09-24 11:23:57  IO Worker #3 TRACE pip  Incoming packet 3 from peer 45
2018-09-24 11:23:57  IO Worker #3 TRACE pip  pre-verifying response for Request #502 from peer 45
2018-09-24 11:23:57  IO Worker #0 TRACE pip  Incoming packet 3 from peer 47
2018-09-24 11:23:57  IO Worker #0 TRACE pip  pre-verifying response for Request #509 from peer 47
2018-09-24 11:23:57  IO Worker #3 TRACE pip  Incoming packet 3 from peer 24
2018-09-24 11:23:57  IO Worker #3 TRACE pip  pre-verifying response for Request #503 from peer 24
2018-09-24 11:23:57  IO Worker #1 TRACE pip  Incoming packet 3 from peer 34
2018-09-24 11:23:57  IO Worker #1 TRACE pip  pre-verifying response for Request #508 from peer 34
2018-09-24 11:23:57  IO Worker #1 TRACE pip  Incoming packet 4 from peer 34
2018-09-24 11:23:57  IO Worker #1 TRACE pip  Received an update to request credit params from peer 34
2018-09-24 11:23:57  IO Worker #2 TRACE pip  Incoming packet 3 from peer 45
2018-09-24 11:23:57  IO Worker #2 TRACE pip  pre-verifying response for Request #504 from peer 45
2018-09-24 11:23:57   TRACE pip  requesting from peer 36. Cost: 1350000; Available: 29998943706
2018-09-24 11:23:57  IO Worker #2 TRACE pip  Incoming packet 3 from peer 19
2018-09-24 11:23:57  IO Worker #2 TRACE pip  pre-verifying response for Request #505 from peer 19
2018-09-24 11:23:57  IO Worker #0 TRACE pip  Incoming packet 3 from peer 36
2018-09-24 11:23:57  IO Worker #0 TRACE pip  pre-verifying response for Request #510 from peer 36
2018-09-24 11:23:57  IO Worker #0 TRACE pip  Initiating disable of peer 36
2018-09-24 11:23:57  IO Worker #0 TRACE pip  requesting from peer 47. Cost: 1700000; Available: 29993909293
2018-09-24 11:23:57  IO Worker #1 TRACE pip  Peer 36 disconnecting
2018-09-24 11:23:57  IO Worker #2 TRACE pip  Incoming packet 3 from peer 47
2018-09-24 11:23:57  IO Worker #2 TRACE pip  pre-verifying response for Request #511 from peer 47
2018-09-24 11:23:57  IO Worker #2 TRACE pip  Initiating disable of peer 47
2018-09-24 11:23:57  IO Worker #2 TRACE pip  requesting from peer 24. Cost: 3400000; Available: 29999245275
2018-09-24 11:23:57  IO Worker #0 TRACE pip  Peer 47 disconnecting
2018-09-24 11:23:57  IO Worker #0 TRACE pip  Incoming packet 3 from peer 24
2018-09-24 11:23:57  IO Worker #0 TRACE pip  pre-verifying response for Request #512 from peer 24
2018-09-24 11:23:58  IO Worker #0 TRACE pip  Initiating disable of peer 24
2018-09-24 11:23:58  IO Worker #0 TRACE pip  requesting from peer 24. Cost: 3400000; Available: 29996600000
2018-09-24 11:23:58  IO Worker #3 TRACE pip  Peer 24 disconnecting
2018-09-24 11:23:58  IO Worker #3 TRACE pip  requesting from peer 45. Cost: 1150000; Available: 29999520992
2018-09-24 11:23:58  IO Worker #3 TRACE pip  Incoming packet 3 from peer 45
2018-09-24 11:23:58  IO Worker #3 TRACE pip  pre-verifying response for Request #514 from peer 45
2018-09-24 11:23:58  IO Worker #3 TRACE pip  Initiating disable of peer 45
2018-09-24 11:23:58  IO Worker #3 TRACE pip  requesting from peer 34. Cost: 800000; Available: 30000000000
2018-09-24 11:23:58  IO Worker #2 TRACE pip  Peer 45 disconnecting
2018-09-24 11:23:58  IO Worker #2 TRACE pip  Incoming packet 3 from peer 34
2018-09-24 11:23:58  IO Worker #2 TRACE pip  pre-verifying response for Request #515 from peer 34
2018-09-24 11:23:58  IO Worker #2 TRACE pip  Initiating disable of peer 34
2018-09-24 11:23:58  IO Worker #2 TRACE pip  requesting from peer 34. Cost: 800000; Available: 29999200000
2018-09-24 11:23:58  IO Worker #3 TRACE pip  Peer 34 disconnecting
2018-09-24 11:23:58  IO Worker #3 TRACE pip  requesting from peer 19. Cost: 950000; Available: 30000000000
2018-09-24 11:23:59  IO Worker #3 TRACE pip  Incoming packet 3 from peer 19
2018-09-24 11:23:59  IO Worker #3 TRACE pip  pre-verifying response for Request #517 from peer 19
2018-09-24 11:23:59  IO Worker #3 TRACE pip  Initiating disable of peer 19
2018-09-24 11:23:59  IO Worker #3 TRACE pip  requesting from peer 19. Cost: 950000; Available: 29999050000
2018-09-24 11:23:59  IO Worker #2 TRACE pip  Peer 19 disconnecting
2018-09-24 11:24:01  IO Worker #2 TRACE pip  Sending status to peer 41
2018-09-24 11:24:01  IO Worker #0 TRACE pip  Peer 41 disconnecting
2018-09-24 11:24:19  IO Worker #0 INFO import     0/50 peers   2 MiB cache 0 bytes queue  RPC:  1 conn,    8 req/s,  142 µs

@Tbaut Tbaut mentioned this issue Sep 24, 2018
Closed
@ordian ordian mentioned this issue Sep 27, 2018
Merged
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@ordian ordian

Labels
F3-annoyance 💩 The client behaves within expectations, however this “expected behaviour” itself is at issue. M4-core ⛓ Core client code / Rust. P2-asap 🌊 No need to stop dead in your tracks, however issue should be addressed as soon as possible.
Projects
None yet
Milestone
2.2
Development

Successfully merging a pull request may close this issue.

fix (light/provider) : Make read_only executions read-only openethereum/parity-ethereum
5 participants
@cheme @ordian @niklasad1 @5chdn @Tbaut