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

Weird error message on heavy usage of RPC #10342

Open
tjayrush opened this issue Feb 13, 2019 · 16 comments
Open

Weird error message on heavy usage of RPC #10342

tjayrush opened this issue Feb 13, 2019 · 16 comments
Labels
F2-bug 🐞 The client fails to follow expected behavior. M6-rpcapi 📣 RPC API.
Milestone

Comments

@tjayrush
Copy link

Before filing a new issue, please provide the following information.

  • Parity Ethereum version: 0.0.0
Parity-Ethereum/v2.3.2-beta-678138f09-20190203/x86_64-macos/rustc1.32.0
  • Operating system: Windows / MacOS / Linux

Mac

  • Installation: homebrew / one-line installer / built from source

One line installer

  • Fully synchronized: no / yes

yes

  • Network: ethereum / ropsten / kovan / ...

Ethereum mainnet

  • Restarted: no / yes

yes (and rebooted machine)

Your issue description goes here below. Try to include actual vs. expected behavior and steps to reproduce the issue.

I run parity with --tracing on and have been for many months/years with nearly zero problems. This morning, I was running three pretty intensive processes against the Parity RPC (basically using CURL to retrieve transactions and blocks in large quantities) and I got the following error messages. When I tried to quit (after shutting down my processes), it took a very long time to close Parity, but it eventually quit. I then rebooted (without trying to restart Parity) and restarted Parity, and it now seems to be working fine. Thought I'd report the issue because I was advised to do so in the Gitter channel. Cheers.

2019-02-13 05:22:45  Imported #7214790 0xaa90…4cdd (99 txs, 5.27 Mgas, 280 ms, 19.50 KiB)
2019-02-13 05:22:45  Error serving connection: Error { kind: BodyWrite, cause: Some(Os { code: 41, kind: Other, message: "Protocol wrong type for socket" }) }
2019-02-13 05:22:45  Error serving connection: Error { kind: BodyWrite, cause: Some(Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }) }
2019-02-13 05:22:45  Error serving connection: Error { kind: BodyWrite, cause: Some(Os { code: 41, kind: Other, message: "Protocol wrong type for socket" }) }
2019-02-13 05:22:46  Error serving connection: Error { kind: BodyWrite, cause: Some(Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }) }
2019-02-13 05:22:46  Error serving connection: Error { kind: BodyWrite, cause: Some(Os { code: 41, kind: Other, message: "Protocol wrong type for socket" }) }
2019-02-13 05:22:46  Error serving connection: Error { kind: BodyWrite, cause: Some(Os { code: 41, kind: Other, message: "Protocol wrong type for socket" }) }
2019-02-13 05:22:47  Error serving connection: Error { kind: BodyWrite, cause: Some(Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }) }
2019-02-13 05:22:48  Error serving connection: Error { kind: BodyWrite, cause: Some(Os { code: 41, kind: Other, message: "Protocol wrong type for socket" }) }
^C2019-02-13 05:23:00  Finishing work, please wait...
2019-02-13 05:24:00  Shutdown is taking longer than expected.
@jam10o-new jam10o-new added F2-bug 🐞 The client fails to follow expected behavior. M6-rpcapi 📣 RPC API. labels Feb 13, 2019
@jam10o-new jam10o-new added this to the 2.4 milestone Feb 13, 2019
@5chdn 5chdn modified the milestones: 2.4, 2.5 Feb 21, 2019
@mmhh1910
Copy link

mmhh1910 commented Mar 7, 2019

I'm seeing the same problem when putting parity under rpc load:

2019-03-07 11:05:34 UTC Starting Parity-Ethereum/v2.3.5-stable-ebd0fd0-20190227/x86_64-linux-gnu/rustc1.32.0,
2019-03-07 11:05:34 UTC Keys path /root/parity_chain/keys/ethereum,
2019-03-07 11:05:34 UTC DB path /root/parity_chain/chains/ethereum/db/...
2019-03-07 11:05:34 UTC State DB configuration: fast,
2019-03-07 11:05:34 UTC Operating mode: active,
2019-03-07 11:05:34 UTC Configured for Ethereum using Ethash engine,
2019-03-07 11:05:36 UTC Updated conversion rate to Ξ1 = US$137.11 (34730540 wei/gas),
2019-03-07 11:05:41 UTC Public node URL: ...
2019-03-07 11:05:42 UTC Imported #7321793 0x5274…407e (5 txs, 0.64 Mgas, 67 ms, 1.70 KiB),
...
2019-03-07 11:15:58 UTC Imported #7321839 0x174b…a2e7 (115 txs, 3.89 Mgas, 455 ms, 17.19 KiB),
2019-03-07 11:16:09 UTC Imported #7321840 0xf472…7981 (6 txs, 0.37 Mgas, 51 ms, 1.75 KiB),
2019-03-07 11:16:16 UTC   10/25 peers     16 MiB chain   98 MiB db  0 bytes queue   43 KiB sync  RPC:  0 conn,    7 req/s,  126 µs,
2019-03-07 11:16:20 UTC Imported #7321841 0x2974…79c6 (39 txs, 3.12 Mgas, 535 ms, 9.34 KiB),
2019-03-07 11:16:31 UTC Imported #7321842 0x1a91…8f15 (114 txs, 5.31 Mgas, 631 ms, 18.62 KiB),
2019-03-07 11:16:48 UTC   10/25 peers     16 MiB chain   99 MiB db  0 bytes queue   43 KiB sync  RPC:  0 conn,    7 req/s,  433 µs,
2019-03-07 11:16:48 UTC Imported #7321843 0xbe05…521f (47 txs, 5.62 Mgas, 488 ms, 9.94 KiB),
2019-03-07 11:16:56 UTC Imported #7321843 0xdff4…d85d (141 txs, 8.00 Mgas, 965 ms, 27.03 KiB),
2019-03-07 11:17:10 UTC Imported #7321844 0x88a9…fdcc (126 txs, 7.03 Mgas, 513 ms, 23.04 KiB),
2019-03-07 11:17:29 UTC Error serving connection: Error { kind: BodyWrite, cause: Some(Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }) },
2019-03-07 11:17:53 UTC Error serving connection: Error { kind: BodyWrite, cause: Some(Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }) },
2019-03-07 11:18:15 UTC Imported #7321848 0x7e10…f7d0 (62 txs, 7.77 Mgas, 997 ms, 11.49 KiB),
2019-03-07 11:18:16 UTC    8/25 peers     16 MiB chain   98 MiB db  0 bytes queue   44 KiB sync  RPC:  0 conn,    0 req/s,   25 µs,
2019-03-07 11:18:16 UTC Error serving connection: Error { kind: BodyWrite, cause: Some(Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }) },
2019-03-07 11:18:20 UTC Error serving connection: Error { kind: BodyWrite, cause: Some(Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }) },
2019-03-07 11:18:23 UTC Imported #7321850 0x2f2d…e3e3 (51 txs, 2.87 Mgas, 486 ms, 10.41 KiB),
2019-03-07 11:18:47 UTC    3/25 peers     16 MiB chain   97 MiB db  0 bytes queue   43 KiB sync  RPC:  0 conn,    1 req/s,   25 µs,
2019-03-07 11:19:11 UTC Imported #7321855 0xb5af…9cad (72 txs, 6.19 Mgas, 1032 ms, 13.13 KiB),
2019-03-07 11:19:16 UTC    3/25 peers     16 MiB chain   94 MiB db  0 bytes queue   43 KiB sync  RPC:  0 conn,    3 req/s,   28 µs,
2019-03-07 11:19:21 UTC Imported #7321856 0xa742…275d (4 txs, 3.75 Mgas, 370 ms, 1.80 KiB),
2019-03-07 11:19:31 UTC Imported #7321857 0x7d1b…a41e (148 txs, 8.00 Mgas, 861 ms, 27.70 KiB),
2019-03-07 11:19:46 UTC    6/25 peers     16 MiB chain   95 MiB db  0 bytes queue   43 KiB sync  RPC:  0 conn,    1 req/s,  204 µs,
2019-03-07 11:19:46 UTC Imported #7321858 0x316a…200e (111 txs, 6.55 Mgas, 793 ms, 21.51 KiB),
2019-03-07 11:19:58 UTC Imported #7321859 0x0739…6c0c (101 txs, 7.99 Mgas, 973 ms, 22.65 KiB),
2019-03-07 11:20:18 UTC    7/25 peers     17 MiB chain   94 MiB db  0 bytes queue   43 KiB sync  RPC:  0 conn,    5 req/s,  236 µs,
2019-03-07 11:20:31 UTC Imported #7321860 0xf584…053a (105 txs, 7.89 Mgas, 934 ms, 15.46 KiB),
2019-03-07 11:20:45 UTC Imported #7321861 0x98e7…296f (173 txs, 7.99 Mgas, 1157 ms, 32.32 KiB),
2019-03-07 11:20:50 UTC Imported #7321862 0x7411…4d33 (96 txs, 4.42 Mgas, 434 ms, 14.41 KiB),
2019-03-07 11:20:57 UTC   10/25 peers     17 MiB chain   95 MiB db  0 bytes queue   43 KiB sync  RPC:  0 conn,    8 req/s,  378 µs,
2019-03-07 11:21:04 UTC Imported #7321863 0x5938…8492 (64 txs, 3.72 Mgas, 390 ms, 11.21 KiB),

The node also does not manage to keep a decent number of peers. Seems like it's loosing/dropping peers when the error message is seen.

I think the problem is there since the latest RPC related security fixes.

I'm running this in docker with:

"--min-peers=25",`` "--no-ancient-blocks", "--max-peers=40", "--cache-size=1024", "--jsonrpc-interface=0.0.0.0", "--ws-interface=0.0.0.0", "--ws-origins=all"

I've also tried to add

"--jsonrpc-server-threads", "3", "--jsonrpc-threads", "2"

but it shows the same problem.

@mmhh1910
Copy link

mmhh1910 commented Mar 8, 2019

Since 2.3.5. was really unsuable for me, I've updated to v2.4.0-beta and I no longer see any problems.

After some time and RPC load I again see

Error serving connection: Error { kind: BodyWrite, cause: Os { code: 32, kind: BrokenPipe, message: "Broken pipe" } }

and the peer count going down.

@soc1c soc1c modified the milestones: 2.5, 2.6 Apr 2, 2019
@tjayrush
Copy link
Author

Any progress on this? I'm still seeing the same issue:

Error serving connection: Error { kind: BodyWrite, cause: Some(Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }) }

Version:

Parity Ethereum
  version Parity-Ethereum/v2.3.4-beta-0e95db11d-20190220/x86_64-macos/rustc1.32.0
Copyright 2015-2018 Parity Technologies (UK) Ltd.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>.
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.

By Wood/Paronyan/Kotewicz/Drwięga/Volf
   Habermeier/Czaban/Greeff/Gotchac/Redmann

@mewwts
Copy link

mewwts commented May 27, 2019

I've also started seeing this.

@tjayrush
Copy link
Author

tjayrush commented May 28, 2019

Still seeing the same issue: Error serving connection: Error { kind: BodyWrite, cause: Some(Os { code: 41, kind: Other, message: "Protocol wrong type for socket" }) }

Parity version: Parity-Ethereum/v2.3.4-beta-0e95db11d-20190220/x86_64-macos/rustc1.32.0

I'm pretty sure it has to do with the trace_transaction call. I didn't track it down completely, but one possible transaction that shows the problem might be this one: 0xad12dba4153036fe62c86e0204991e2f66036ee3454974974e3a863a4e1b8207

At least it causes the issue when calling through my code (which is C++ and uses Curl). I tried reproducing with a straight call to curl from the command line (using the same tx hash):

curl --data '{"method":"trace_transaction","params":["0xad12dba4153036fe62c86e0204991e2f66036ee3454974974e3a863a4e1b8207"],"id":1,"jsonrpc":"2.0"}' -H "Content-Type: application/json" -X POST localhost:8545

But that doesn't manifest the problem. Hope this helps.

One more note: I'm about 99.9% sure this is one of the Fall 2016 Ddos attack transactions. My guess is that this is deeply related to that. I note that any transaction sent to 0x0c40cf6dd1b74c6edfc4729021a11f57b31e3c27 may be a dDos transaction.

@mmhh1910
Copy link

mmhh1910 commented Jun 8, 2019

I'm running parity in Docker and noticed that once I removed the parameters "--ws-interface=0.0.0.0", "--ws-origins=all", I no longer see the problem.

@ordian ordian modified the milestones: 2.6, 2.7 Jul 12, 2019
@deanstef
Copy link

deanstef commented Oct 10, 2019

Hey guys I am seeing the same error. Any progress ??

I'm running parity in Docker and noticed that once I removed the parameters "--ws-interface=0.0.0.0", "--ws-origins=all", I no longer see the problem.

This didn't work for me.

@dvdplm
Copy link
Collaborator

dvdplm commented Oct 10, 2019

@deanstef there has been some movement, and we merged #11151 today. If anyone could try to compile from master and see if that improves the situation it'd be fantastic. On my end I've seen much smoother performance and less timeouts under heavy load.

@dvdplm
Copy link
Collaborator

dvdplm commented Oct 10, 2019

At least it causes the issue when calling through my code (which is C++ and uses Curl). I tried reproducing with a straight call to curl from the command line (using the same tx hash):

@tjayrush Is the C++ code putting heavy load on the node? Or is a single invocation from your app enough to break the IO pipe?

@deanstef
Copy link

deanstef commented Oct 11, 2019

@deanstef there has been some movement, and we merged #11151 today. If anyone could try to compile from master and see if that improves the situation it'd be fantastic. On my end I've seen much smoother performance and less timeouts under heavy load.

I will try today and I'll let you know. @dvdplm Are you sure this will fix the issue related to high RPC workloads?

@dvdplm
Copy link
Collaborator

dvdplm commented Oct 11, 2019

Are you sure this will fix the issue related to high RPC workloads?

No. I am sure it improves the resource usage but just how much an improvement it turns out to be is hard to tell.

@deanstef
Copy link

Hey @dvdplm I think I understood my problem. I will briefly explain here, maybe is helpful for the others.

I have a client firing hundreds of tx/s toward my 4-nodes Parity network running Aura consensus. Such client does not wait for responses from one request to another and after x minutes it closes the connections.

Parity-side the server keeps the transactions in a queue and it answers the client as soon as possible. However with high loads, the response time increases. In this case, may happen that the connection is closed, client-side, before Parity can process all the queued transactions. This causes the BrokenPipe error.

Now my question is: Will those transactions still in the queue being processed by Parity ??

@dvdplm
Copy link
Collaborator

dvdplm commented Oct 12, 2019

@deanstef parity’s http impl is no worse or better than other http servers and if the client disconnects prematurely without giving notice, BrokenPipe errors are to be expected. If your code submits data but does not wait for a result there is really no way of knowing if the operation was successful or not so I’m not sure I understand the question. Parity does not delete txs that were submitted by misbehaving clients, if that’s what you’re asking.

@macdasi
Copy link

macdasi commented Jan 9, 2020

I have the same problem when load test parity.v 2.6.8 beta

@pstroinski
Copy link

Still having the same issue on version OpenEthereum/v3.0.0-stable-fdf5f67-20200511/x86_64-unknown-linux-gnu/rustc1.43.1. Had it very often on 2.5 and 2.7. Decided to upgrade to OpenEthereum 3.0 but still same issue. It makes the node unusable for some time before it starts syncing again.
It'a a full node running with parameters:
openethereum --no-warp --no-periodic-snapshot --no-secretstore --jsonrpc-interface all --jsonrpc-hosts all --jsonrpc-cors all --jsonrpc-apis net,web3,eth,parity,traces --geth --jsonrpc-port xxxx --port xxxx --pruning-history 1000 --pruning-memory 512 --tx-queue-mem-limit=0 --tx-queue-size=100000 --base-path /var/parity

2020-05-25 12:51:34 UTC 17/25 peers 6 MiB chain 1 GiB db 286 KiB queue 12 MiB sync RPC: 0 conn, 4 req/s, 72 µs
2020-05-25 12:53:33 UTC Imported #10135035 0x3de8…22f0 (88 txs, 9.96 Mgas, 4859 ms, 18.56 KiB)
2020-05-25 12:53:33 UTC Error serving connection: Error(BodyWrite, Os { code: 32, kind: BrokenPipe, message: "Broken pipe" })
2020-05-25 12:53:51 UTC Error serving connection: Error(BodyWrite, Os { code: 32, kind: BrokenPipe, message: "Broken pipe" })
2020-05-25 12:54:00 UTC 7/25 peers 6 MiB chain 1 GiB db 0 bytes queue 12 MiB sync RPC: 0 conn, 9 req/s, 202 µs
2020-05-25 12:54:40 UTC 5/25 peers 3 MiB chain 1 GiB db 0 bytes queue 12 MiB sync RPC: 0 conn, 10 req/s, 48 µs
2020-05-25 12:55:11 UTC 0/25 peers 3 MiB chain 1 GiB db 0 bytes queue 12 MiB sync RPC: 0 conn, 6 req/s, 211 µs

Any news on fixing it?

@ngyam
Copy link
Contributor

ngyam commented Aug 2, 2020

Just met the same issue..

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
F2-bug 🐞 The client fails to follow expected behavior. M6-rpcapi 📣 RPC API.
Projects
None yet
Development

No branches or pull requests