parity-ethereum icon indicating copy to clipboard operation
parity-ethereum copied to clipboard

Weird error message on heavy usage of RPC

Open tjayrush opened this issue 6 years ago • 16 comments

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.

tjayrush avatar Feb 13 '19 11:02 tjayrush

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 avatar Mar 07 '19 11:03 mmhh1910

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.

mmhh1910 avatar Mar 08 '19 12:03 mmhh1910

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

tjayrush avatar Apr 11 '19 09:04 tjayrush

I've also started seeing this.

mewwts avatar May 27 '19 23:05 mewwts

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.

tjayrush avatar May 28 '19 19:05 tjayrush

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.

mmhh1910 avatar Jun 08 '19 12:06 mmhh1910

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.

deanstef avatar Oct 10 '19 15:10 deanstef

@deanstef there has been some movement, and we merged https://github.com/paritytech/parity-ethereum/pull/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 avatar Oct 10 '19 20:10 dvdplm

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?

dvdplm avatar Oct 10 '19 20:10 dvdplm

@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?

deanstef avatar Oct 11 '19 09:10 deanstef

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.

dvdplm avatar Oct 11 '19 09:10 dvdplm

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 ??

deanstef avatar Oct 11 '19 12:10 deanstef

@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.

dvdplm avatar Oct 12 '19 18:10 dvdplm

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

macdasi avatar Jan 09 '20 07:01 macdasi

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?

pstroinski avatar May 25 '20 13:05 pstroinski

Just met the same issue..

ngyam avatar Aug 02 '20 14:08 ngyam