Timeout on MacOS after making ~16384 RPC calls

[casey]

I originally hit this while using rust-bitcoincore-rpc, but was able to narrow it down to this crate.

The error is:

Transport(SocketError(Error { kind: TimedOut, message: "connection timed out" }))

I uploaded a repo containing a self-contained reproduction here: https://github.com/casey/bitcoind-rpc-timeout/blob/master/src/main.rs

The issue was introduced some time between 0.11 and 0.12 and is still present on master. I tried to bisect it down, but there was a lot of flux in the crate, which made it impossible to track down a specific revision.

While debugging, I would sometimes get this error:

Transport(SocketError(Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" }))

Which makes me think it's related to this issue: rust-bitcoin/rust-bitcoincore-rpc#211
And this issue: bitcoin/bitcoin#25724 (comment)

Although I wouldn't necessarily bet on it.

[tcharding]

That repo crate should hit the bug when running using cargo run, right? Just posting here to confirm the MacOS in the title, on Ubuntu 20.04 the bug does not appear to be triggered.

[casey]

That repo crate should hit the bug when running using cargo run, right? Just posting here to confirm the MacOS in the title, on Ubuntu 20.04 the bug does not appear to be triggered.

Yup, that's right. I also tried it on an Ubuntu 21.10 server, and wasn't able to reproduce it there.

[casey]

For reference, I added a GitHub actions workflow that passes on Ubuntu and fails on MacOS.

[tcharding]

Good bug reporting effort bro, thanks!

[apoelstra]

Between 0.11 and 0.12 we completely replaced hyper with a homebrew http transport. Probably we are leaking some resource.

[casey]

It's always around 16384 which seems suspicious. Possibly the resource being leaked is a socket or file handle?

[apoelstra]

Yep -- those are my guesses. I'll try to poke at this later today, although I don't have a Mac so it might be a bit annoying.

On your Mac could you try running your test in strace and see if there's some particular syscall (like open on a socket?) which is timing out?

[casey]

On your Mac could you try running your test in strace and see if there's some particular syscall (like open on a socket?) which is timing out?

I actually tried to, but I'm on a recent mac OS with security features that prevent dtrace (the strace equivalent available on macos) from running, unless I reboot into recovery mode and run some scary commands. I have another mac that I can do this on, but I'd need to wipe it first.

[apoelstra]

After reading the code (and using strace) I'm fairly confident there are no resource leaks. I suspect that on Mac you just aren't allowed to open 2^16 sockets even if you close the old ones (at least, you can't do this in very rapid succession).

The previous code used Hyper, which just maintained a socket pool. We should probably do the same (well, we'd have a single socket rather than a pool .. but still we should cache it).

The reason we didn't do this in the past is that TCP sockets suck -- they can go stale and you can't tell they're dead until you actually try sending and then you've gotta re-try, so you better not have handed ownership over any objects to the serialization code. None of this is a big deal but we were trying to go for maximal simplicity.

I don't think this'll be too hard to fix, especially as we have the old hyper code lying around which tells us which particular io errors mean "broken pipe, just try again" and which ones are real errors.

[casey]

After reading the code (and using strace) I'm fairly confident there are no resource leaks. I suspect that on Mac you just aren't allowed to open 2^16 sockets even if you close the old ones (at least, you can't do this in very rapid succession).

This sounds right. It might have to do with open ports, since each outgoing socket will allocate a local ephemeral port.

The previous code used Hyper, which just maintained a socket pool. We should probably do the same (well, we'd have a single socket rather than a pool .. but still we should cache it).

Another option to consider making the back-end pluggable. My application already uses hyper, so there aren't any additional security/bloat considerations if I use it in a dependency.

All this makes me wish that Bitcoin Core had a simple binary RPC API over a local FIFO, so that if you didn't need remote access, you didn't have to think about HTTP, security, ports, sockets.

[casey]

More digging, and it looks like it's the ephemeral port range that's being exhausted. MacOS's ephemeral port range is 49152 to 65535, which is 16383 ports. If reusing the socket is hard and annoying, then reusing the port might be a lower impact option.

[apoelstra]

The back-end is actually pluggable -- we have a Transport trait that you can implement using Hyper if you want (and I think we'd accept a PR to use hyper if you wanted to upstream it here, though it would need to be feature gated).

But I think just reusing the socket would be easier/not too bad. It's on my list.

[gwillen]

I suggest trying to set SO_REUSEADDR on the sockets, and possibly also disable SO_LINGER -- this may help if the issue is you're trying to reuse ports too fast, while the old socket is still in TIME_WAIT (closed but not fully cleaned up yet.) I don't know why it's only seen on mac -- one possibility is that Linux only applies this to sockets bound to a specific port, and mac is also applying it to ephemeral ones. (Or maybe the mac just has a much smaller legal range for ephemeral ports.)

(Obviously just reusing the socket is better, if you're making a ton of calls in rapid succession. But this might be a lot easier to try.)

[apoelstra]

@casey are you able to try this locally? I don't have a Mac to play with.