Parity-ethereum: RPC threads dying w/ "Too many open files"

[XertroV]

I'm running:

• Which Parity version?: 1.10.9 (observed on 1.10.8 too, though haven't dug through logs)
• Which operating system?: Linux
• How installed?: binaries
• Are you fully synchronized?: yes
• Which network are you connected to?: ethereum
• Did you try to restart the node?: yes (workaround)

pretty self explanatory - all RCP threads die simultaneously, but everything else keeps working (including websockets according to netstat; RPC ports disappear but websocket ports don't)

(Most of those requests are 2x eth-stats running via pm2)

Logs:

Jul 11 12:16:35 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:16:35 UTC   39/50 peers    978 MiB chain   92 MiB db  0 bytes queue  270 KiB sync  RPC:  0 conn, 15 req/s,  42 µs
Jul 11 12:17:14 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:17:14 UTC Imported #5944667 2191…9c17 (201 txs, 7.99 Mgas, 577.74 ms, 28.41 KiB)
Jul 11 12:17:23 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:17:23 UTC Imported #5944668 8712…a45d (225 txs, 8.00 Mgas, 401.54 ms, 32.90 KiB)
Jul 11 12:17:23 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:17:23 UTC   40/50 peers    979 MiB chain   93 MiB db  0 bytes queue  270 KiB sync  RPC:  0 conn, 15 req/s, 200849 µs
Jul 11 12:17:34 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:17:34 UTC Imported #5944652 e9ce…5142 (158 txs, 7.98 Mgas, 530.73 ms, 27.99 KiB)
Jul 11 12:17:43 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:17:43 UTC Imported #5944669 3f6e…aa3e (123 txs, 7.98 Mgas, 319.24 ms, 23.49 KiB)
Jul 11 12:17:57 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:17:57 UTC Imported #5944670 00f2…1fc4 (141 txs, 7.96 Mgas, 525.96 ms, 30.61 KiB)
Jul 11 12:18:06 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:18:06 UTC Imported #5944671 2a2c…dc79 (180 txs, 7.98 Mgas, 295.11 ms, 31.91 KiB)
Jul 11 12:18:16 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:18:16 UTC Imported #5944672 ad08…bc85 (91 txs, 7.98 Mgas, 467.72 ms, 18.07 KiB)
Jul 11 12:18:25 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:18:25 UTC Imported #5944672 7141…18b3 (128 txs, 7.99 Mgas, 300.18 ms, 29.26 KiB)
Jul 11 12:18:26 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:18:26 UTC   41/50 peers    979 MiB chain   93 MiB db  0 bytes queue  270 KiB sync  RPC:  0 conn, 13 req/s, 85801 µs
Jul 11 12:18:42 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:18:42 UTC Imported #5944673 cdc2…490a (178 txs, 7.97 Mgas, 334.38 ms, 29.28 KiB)
Jul 11 12:18:52 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:18:52 UTC Imported #5944674 1312…9ce7 (161 txs, 7.98 Mgas, 402.45 ms, 27.58 KiB)
Jul 11 12:19:01 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:19:01 UTC Imported #5944675 b50d…d2ea (151 txs, 7.97 Mgas, 288.44 ms, 29.28 KiB)
Jul 11 12:19:09 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:19:09 UTC Imported #5944676 6751…fcd2 (110 txs, 8.00 Mgas, 185.48 ms, 23.90 KiB)
Jul 11 12:19:13 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:19:13 UTC   44/50 peers    979 MiB chain   93 MiB db  0 bytes queue  270 KiB sync  RPC:  0 conn, 15 req/s, 4483 µs
Jul 11 12:19:42 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:19:42 UTC Imported #5944677 03a4…19ab (109 txs, 7.98 Mgas, 309.37 ms, 23.08 KiB)
Jul 11 12:19:46 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:19:46 UTC   42/50 peers    979 MiB chain   93 MiB db  0 bytes queue  270 KiB sync  RPC:  0 conn, 18 req/s, 2073 µs
Jul 11 12:25:31 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:31 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:25:31 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:31 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:25:31 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:31 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:25:31 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:31 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:25:31 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:31 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:25:31 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:31 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:25:31 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:31 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:25:32 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:32 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:25:32 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:32 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:25:32 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:32 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:25:32 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:32 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:25:32 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:32 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:25:32 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:32 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:25:33 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:33 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:25:33 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:25:33 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 11 12:27:18 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:27:18 UTC Syncing #5944677 03a4…19ab     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #5944678   41/50 peers    979 MiB chain   93 MiB db  0 bytes queue  270 KiB sync  RPC:  0 conn,  0 req/s, 108293215 µs
Jul 11 12:27:18 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:27:18 UTC Syncing #5944677 03a4…19ab     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #5944678   35/50 peers    979 MiB chain   93 MiB db 776 bytes queue  270 KiB sync  RPC:  0 conn,  0 req/s, 108293215 µs
Jul 11 12:27:28 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:27:28 UTC Imported #5944679 0c6c…52bf (164 txs, 8.00 Mgas, 315.46 ms, 30.88 KiB)
Jul 11 12:27:46 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:27:46 UTC Syncing #5944679 0c6c…52bf     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #5944678    2/50 peers    979 MiB chain   93 MiB db  0 bytes queue  295 KiB sync  RPC:  0 conn,  0 req/s, 108293215 µs
Jul 11 12:27:46 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:27:46 UTC Reorg to #5944680 9ada…5d2d (0c6c…52bf #5944678 73c0…4c05 ff48…870c)
Jul 11 12:28:04 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:28:04 UTC Syncing #5944717 cdcd…0071     3 blk/s  576 tx/s  30 Mgas/s      0+    0 Qed  #5944717    3/50 peers    979 MiB chain   94 MiB db  0 bytes queue  270 KiB sync  RPC:  0 conn,  0 req/s, 108293215 µs
Jul 11 12:28:04 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:28:04 UTC Syncing #5944717 cdcd…0071     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #5944717    3/50 peers    979 MiB chain   94 MiB db  0 bytes queue  271 KiB sync  RPC:  0 conn,  0 req/s, 108293215 µs
Jul 11 12:28:11 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:28:11 UTC Syncing #5944718 a475…6508     0 blk/s   22 tx/s   1 Mgas/s      0+    0 Qed  #5944718    4/50 peers    979 MiB chain   94 MiB db  0 bytes queue  270 KiB sync  RPC:  0 conn,  0 req/s, 108293215 µs
Jul 11 12:28:21 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:28:21 UTC Imported #5944720 e519…b8fd (157 txs, 7.94 Mgas, 291.49 ms, 21.24 KiB) + another 3 block(s) containing 248 tx(s)
Jul 11 12:28:31 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:28:31 UTC Imported #5944721 f565…2c7d (76 txs, 7.99 Mgas, 292.40 ms, 26.64 KiB)
Jul 11 12:28:47 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:28:47 UTC    6/50 peers    980 MiB chain   94 MiB db  0 bytes queue  270 KiB sync  RPC:  0 conn,  0 req/s, 108293215 µs
Jul 11 12:28:47 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:28:47 UTC    6/50 peers    980 MiB chain   94 MiB db  0 bytes queue  270 KiB sync  RPC:  0 conn,  0 req/s, 108293215 µs
Jul 11 12:28:58 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:28:58 UTC Imported #5944721 f876…f4b7 (90 txs, 7.99 Mgas, 478.49 ms, 16.77 KiB)
Jul 11 12:29:08 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:29:08 UTC Imported #5944722 6608…88b0 (85 txs, 7.97 Mgas, 288.22 ms, 26.36 KiB)
Jul 11 12:29:12 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:29:12 UTC Reorg to #5944723 f887…a9ab (9879…957e #5944721 f565…2c7d 6608…88b0)
Jul 11 12:29:21 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:29:21 UTC Imported #5944724 f254…0257 (44 txs, 7.98 Mgas, 630.93 ms, 9.78 KiB) + another 1 block(s) containing 146 tx(s)
Jul 11 12:29:22 eth-aws-nv-node-03 parity[11186]: 2018-07-11 12:29:22 UTC    5/50 peers    980 MiB chain   94 MiB db  0 bytes queue  270 KiB sync  RPC:  0 conn,  0 req/s, 108293215 µs

[Tbaut]

Is it something that you were able to reproduce? Any way to give us more logs (-l debug could probably give us a hint ).

[ascjones]

Related: https://github.com/paritytech/parity/issues/8123 and https://github.com/paritytech/parity/issues/8813. It might be fixed in 1.11.5?

[XertroV]

@Tbaut - not sure how to reproduce except to leave nodes running long term. Will add -l debug and see if that captures some more interesting detail.

As an aside, I've looked before for how to increase the log level and it wasn't easy to find (well, at least when I looked I didn't find anything). Might be worth adding a wiki page on debugging / increased logging.

@ascjones I think the above issues were different for a few reasons:

• when I had RPC issues before in #8813 I had LOTS of RPC requests coming in, and haven't noticed that this time.
• The log outputs are different this time - all the RPC threads die simultaneously, but this isn't consistent with what I experienced with #8813. Particularly the node itself keeps running fine atm; it's just RPC that fails, whereas before it was a complete panic and node-restart.

So unless something particularly significant changed between 1.10.6 and 1.10.9 I suspect it's a different issue.

[XertroV]

Happened to another node a few hours ago - just checked.

A thing I noticed:

Jul 12 04:31:05 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:31:05 UTC Imported #5948726 19c5…bca6 (129 txs, 7.99 Mgas, 386.64 ms, 24.63 KiB)
Jul 12 04:36:50 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:50 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }

There are ~5-6 minutes between those two log lines. 🤔

Jul 12 04:29:06 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:29:06 UTC Imported #5948724 3731…6aa7 (173 txs, 7.98 Mgas, 74.41 ms, 28.90 KiB)
Jul 12 04:29:10 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:29:10 UTC   49/50 peers    340 MiB chain   20 MiB db  0 bytes queue   50 KiB sync  RPC:  0 conn, 18 req/s, 3544 µs
Jul 12 04:29:10 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:29:10 UTC   49/50 peers    340 MiB chain   20 MiB db  0 bytes queue   50 KiB sync  RPC:  0 conn, 18 req/s, 3544 µs
Jul 12 04:29:46 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:29:46 UTC Imported #5948725 15cb…f4d9 (41 txs, 7.98 Mgas, 204.38 ms, 13.59 KiB)
Jul 12 04:29:48 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:29:48 UTC   50/50 peers    340 MiB chain   20 MiB db  0 bytes queue   50 KiB sync  RPC:  0 conn, 13 req/s, 126805 µs
Jul 12 04:29:48 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:29:48 UTC   50/50 peers    340 MiB chain   20 MiB db  0 bytes queue   50 KiB sync  RPC:  0 conn, 13 req/s, 126805 µs
Jul 12 04:30:20 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:30:20 UTC   52/500 peers    340 MiB chain   20 MiB db  0 bytes queue   50 KiB sync  RPC:  0 conn, 17 req/s,  60 µs
Jul 12 04:30:51 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:30:51 UTC Imported #5948726 e81f…991b (43 txs, 4.79 Mgas, 208.14 ms, 9.81 KiB)
Jul 12 04:30:52 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:30:52 UTC   51/500 peers    341 MiB chain   20 MiB db  0 bytes queue   50 KiB sync  RPC:  0 conn, 13 req/s, 541023 µs
Jul 12 04:30:52 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:30:52 UTC   51/500 peers    341 MiB chain   20 MiB db  0 bytes queue   51 KiB sync  RPC:  0 conn, 13 req/s, 140738 µs
Jul 12 04:31:05 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:31:05 UTC Imported #5948726 19c5…bca6 (129 txs, 7.99 Mgas, 386.64 ms, 24.63 KiB)
Jul 12 04:36:50 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:50 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:36:50 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:50 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:36:50 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:50 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:36:50 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:50 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:36:50 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:50 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:36:50 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:50 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:36:50 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:50 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:36:50 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:50 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:36:50 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:50 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:36:51 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:51 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:36:51 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:51 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:36:51 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:51 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:36:52 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:52 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:36:52 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:52 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:36:53 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:36:53 UTC Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }
Jul 12 04:37:36 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:37:36 UTC Reorg to #5948728 1d2d…d6e1 (f4eb…9717 #5948726 e81f…991b f330…5f8b)
Jul 12 04:37:42 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:37:42 UTC Imported #5948727 f330…5f8b (208 txs, 7.98 Mgas, 286.16 ms, 36.06 KiB)
Jul 12 04:37:50 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:37:50 UTC Imported #5948728 1d2d…d6e1 (166 txs, 7.98 Mgas, 401.44 ms, 28.28 KiB) + another 1 block(s) containing 124 tx(s)
Jul 12 04:38:02 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:38:02 UTC    2/50 peers    341 MiB chain   20 MiB db  0 bytes queue   50 KiB sync  RPC:  0 conn,  0 req/s, 40488942 µs
Jul 12 04:38:02 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:38:02 UTC    2/50 peers    341 MiB chain   20 MiB db  0 bytes queue   50 KiB sync  RPC:  0 conn,  0 req/s, 40488942 µs
Jul 12 04:38:08 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:38:08 UTC Syncing #5948732 a20b…a53c     0 blk/s   59 tx/s   6 Mgas/s      0+   21 Qed  #5948753    5/50 peers    341 MiB chain   20 MiB db    2 MiB queue   50 KiB sync  RPC:  0 conn,  0 req/s, 40488942 µs
Jul 12 04:38:08 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:38:08 UTC Syncing #5948732 a20b…a53c     0 blk/s    0 tx/s   0 Mgas/s      0+   21 Qed  #5948753    5/50 peers    341 MiB chain   20 MiB db    2 MiB queue   50 KiB sync  RPC:  0 conn,  0 req/s, 40488942 µs
Jul 12 04:38:21 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:38:21 UTC Imported #5948753 4194…840d (92 txs, 8.01 Mgas, 161.89 ms, 21.29 KiB)
Jul 12 04:38:40 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:38:40 UTC    5/50 peers    341 MiB chain   20 MiB db  0 bytes queue   50 KiB sync  RPC:  0 conn,  0 req/s, 40488942 µs
Jul 12 04:38:50 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:38:50 UTC Syncing #5948753 4194…840d     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #5948752    8/50 peers    341 MiB chain   20 MiB db  0 bytes queue   50 KiB sync  RPC:  0 conn,  0 req/s, 40488942 µs
Jul 12 04:39:00 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:39:00 UTC Syncing #5948753 4194…840d     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #5948752   10/50 peers    341 MiB chain   20 MiB db  0 bytes queue   57 KiB sync  RPC:  0 conn,  0 req/s, 40488942 µs
Jul 12 04:39:10 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:39:10 UTC Syncing #5948753 4194…840d     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #5948752   14/50 peers    341 MiB chain   20 MiB db  0 bytes queue   57 KiB sync  RPC:  0 conn,  0 req/s, 40488942 µs
Jul 12 04:39:20 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:39:20 UTC Syncing #5948761 33d3…a147     0 blk/s   72 tx/s   6 Mgas/s      0+    2 Qed  #5948764   17/50 peers    341 MiB chain   20 MiB db  219 KiB queue   50 KiB sync  RPC:  0 conn,  0 req/s, 40488942 µs
Jul 12 04:39:44 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:39:44 UTC Imported #5948765 fadc…cb14 (111 txs, 7.98 Mgas, 428.37 ms, 21.68 KiB) + another 2 block(s) containing 203 tx(s)
Jul 12 04:39:55 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:39:55 UTC Imported #5948766 1a68…e067 (101 txs, 7.05 Mgas, 318.83 ms, 22.62 KiB)
Jul 12 04:40:04 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:40:04 UTC   16/50 peers    341 MiB chain   20 MiB db  0 bytes queue   50 KiB sync  RPC:  0 conn,  0 req/s, 40488942 µs
Jul 12 04:40:04 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:40:04 UTC Imported #5948767 c3a4…5f00 (15 txs, 4.34 Mgas, 54.35 ms, 6.80 KiB)
Jul 12 04:40:13 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:40:13 UTC Imported #5948766 06bf…d6c6 (108 txs, 7.99 Mgas, 268.07 ms, 20.53 KiB)
Jul 12 04:40:24 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:40:24 UTC Imported #5948771 0e13…6167 (66 txs, 7.98 Mgas, 619.36 ms, 19.76 KiB) + another 2 block(s) containing 135 tx(s)
Jul 12 04:40:35 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:40:35 UTC Imported #5948772 af5c…c366 (94 txs, 7.97 Mgas, 87.97 ms, 19.50 KiB)
Jul 12 04:40:37 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:40:37 UTC   14/50 peers    342 MiB chain   21 MiB db  0 bytes queue   50 KiB sync  RPC:  0 conn,  0 req/s, 40488942 µs
Jul 12 04:41:03 eth-aws-syd-node-02 parity[5414]: 2018-07-12 04:41:03 UTC Imported #5948773 2884…a3ac (93 txs, 7.99 Mgas, 166.64 ms, 19.20 KiB)

[Tbaut]

As an aside, I've looked before for how to increase the log level and it wasn't easy to find (well, at least when I looked I didn't find anything). Might be worth adding a wiki page on debugging / increased logging.

What keyword did you use? it's here: https://wiki.parity.io/FAQ.html#how-can-i-make-parity-to-write-logs

[XertroV]

What keyword did you use? it's here: https://wiki.parity.io/FAQ.html#how-can-i-make-parity-to-write-logs

I think I must have just derped pretty hard. Some vague memories: might have been before the current wiki (was it on github before?) and I think I used google more than searching a particular site. In any case thanks for linking me.

[XertroV]

@Tbaut - so good news! 2 of my nodes seem to have lost RPC again. I'll try and get those logs up later today (though they might be large) and filter through for anything relevant I can find.

[XertroV]

okay so seems like they actually didn't lose RPC - was just that the log files clobbered the little AWS / partition and eth-stats stopped working. Logging to a file on SSD now so shouldn't be an issue anymore, but no news on the RPC worker threads dying. Also seems like I only got a few hours of logs so no particularly good deets

[debris]

@XertroV are you using rpc over http or ipc?

[XertroV]

@debris HTTP - the nodes are all remote (publicly accessible) and don't run anything else on them besides stats, healthcheck, etc. Didn't check if IPC was affected, and haven't been able to replicate. Actually just disabled debug logging because the log files were about 20GB

[vogelito]

RPC in one of our parity nodes stopped working for us a few hours ago. The following log entry lines up perfectly with our software being unable to talk to parity:

2018-07-20 08:14:10 UTC  WARN jsonrpc_http_server  Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }

We had never seen this issue before and not entirely sure that it is related to @XertroV's problems but wanted to post it here. This node had been running for a month:

2018-07-20 03:12:15 UTC main INFO parity::run  Starting Parity/v1.10.6-unstable-bc0d134-20180605/x86_64-linux-gnu/rustc1.25.0

We're currently upgrading to v1.11.7 and will restart our node.

[AyushyaChitransh]

Facing this issue in v1.11.7(latest stable version). As is the case of other users, I too am running parity along with its monitoring via pm2 using eth-net-intelligenceAPI. So they are the onlyRPC connections to my parity node.

[uluhonolulu]

@Tbaut we're still experiencing this problem. We're doing stress tests over IPC, but sometimes need to check something over HTTP, and then we discover that RPC won't respond.

Our version is v2.0.7-stable-db3a989-20181010/x86_64-linux-gnu/rustc1.29.0

Here's a piece of the log. You can see that there was only one RPC connection just before the server stopped responding.

Oct 18 21:01:10 dev.prime.galaxias.io parity[19121]: 2018-10-18 21:01:10  Imported #534283 0xb0e8…6648 (0 txs, 0.00 Mgas, 6 ms, 0.53 KiB) + another 1 block(s) containing 0 tx(s)
Oct 18 21:01:36 dev.prime.galaxias.io parity[19121]: 2018-10-18 21:01:36     3/25 peers      7 MiB chain   86 MiB db  0 bytes queue   22 KiB sync  RPC:  2 conn,  631 req/s,  260 µs
Oct 18 21:02:11 dev.prime.galaxias.io parity[19121]: 2018-10-18 21:02:11     3/25 peers      2 KiB chain   86 MiB db  0 bytes queue   22 KiB sync  RPC:  1 conn,  604 req/s,  225 µs
Oct 18 21:02:28 dev.prime.galaxias.io parity[19121]: 2018-10-18 21:02:28  Incoming streams error, closing sever: Os { code: 24, kind: Other, message: "Too many open files" }

[Tbaut]

The PR that fixes the problem (https://github.com/paritytech/jsonrpc/pull/321) has not been used in any Parity-Ethereum release yet. You can see in the cargo.toml that the jsonrpc branch used is still old. You need to wait until this is included before testing.

[uluhonolulu]

@Tbaut as far as I understood, #9786 added this fix to the 2.0.9. Is that correct?

[Tbaut]

Yes, the list of commits from jsonrpc v1.11 branch includes the fix, this same branch was used and back ported to stable.