Using a logger causes infinite spam logs when file descriptor limit is reached in `HTTP::Server`

[syeopite]

Bug Report

Using the logger to print any kind of message (Log.setup doesn't seem to trigger this) results in the HTTP::Server infinitely spamming logs whenever the file descriptor limit is reached.

require "http/server"

Log.info { "test" }

server = HTTP::Server.new do | context |
  loop do
    context.response.puts ":keepalive #{Time.utc.to_unix}"
    context.response.puts
    context.response.flush

    sleep 2.seconds
  end
end

server.listen 12345

Results in

2025-06-01T19:01:40.364067Z  ERROR - http.server: Error while connecting a new socket
accept: Too many open files (Socket::Error)
...

2025-06-01T19:01:40.364070Z  ERROR - http.server: Error while connecting a new socket
accept: Too many open files (Socket::Error)
...

2025-06-01T19:01:40.364074Z  ERROR - http.server: Error while connecting a new socket
accept: Too many open files (Socket::Error)
...
and so on

When the logger isn't present, the program just crashes instantly and only two exceptions are logged.

Crystal 1.16.0 (2025-04-11)

LLVM: 19.1.7
Default target: x86_64-pc-linux-gnu

Here's a simple script that can trigger this bug in the above code

Simple request to spam request a server to trigger this

require "http"
require "wait_group"

ADDRESS = URI.parse("http://localhost:12345")

def make_client
  client = HTTP::Client.new(ADDRESS)
  client.get("/") do | response |
    until response.body_io.closed?
      response.body_io.gets
    end
  end
ensure
  client.try &.close
end

5.times do
  clients_opened = [] of HTTP::Client
  # Create in batches as to not trigger our own file descriptor limit
  250.times { spawn { make_client } }
end

sleep

[straight-shoota]

Reduced repro:

require "http/server"

Log.info { "test" }

server = HTTP::Server.new {}

server.bind_tcp 12345

lib LibC
  fun setrlimit(resource : Int, rlim : Rlimit*)
end
rlimit = LibC::Rlimit.new(rlim_cur: 0, rlim_max: 0)
LibC.setrlimit(LibC::RLIMIT_NOFILE, pointerof(rlimit))

server.listen

Looks like the logger needs a file descriptor at some point (apparently for reading /etc/localtime) which it opens on first use.
Without the explicit log message, the logger tries to open the file descriptor when the first log message appears - which is exactly caused by not being able to open another file descriptor. And so the logger raises again in the error-handling code of the TCP accept call and thus breaks the loop:

crystal/src/http/server.cr

Lines 466 to 471 in 4a073fa

	io = begin
	socket.accept?
	rescue e
	handle_exception(e)
	next
	end

If we have a logger call first, it has already opened the file descriptor, and later log messages don't fail. Thus, the loop is never broken, and the server continuously tries to accept a socket even though the file descriptor limit is reached.

The same effect can be achieved by replacing the log call with Time::Location.local = Time::Location::UTC. This also prevents opening a new file descriptor for loading the timezone.

[straight-shoota]

I suppose the question is: What should happen when socket.accept? fails? Most likely, it's because of a pretty severe error that won't go away if we just try again.

We could of course try some remedies, such as try cleaning up unused resources (cf. #780).
But ultimately, this should probably result in a hard fail? Or at least not log an error every time we try connecting again.
If we keep trying again, we could store the previous error and skip the reporting if it's the same again. 🤷 Maybe a back-off strategy for retrying? 🤔

[syeopite]

For the too many files open error at least it could theoretically go away given enough time assuming the problem was caused by actual work.

But I feel like silently suppressing the log but still checking over and over again with so little time in-between is just wasting CPU cycles. Some sort of back-off strategy would be nice and it might also allow more time to finish up whatever logic is reserving all the file descriptors in non multi-threaded concurrent code.

But quantifying how quickly to grow the back-off is going to be difficult, and could also mean that the server can take substantial time to resume listening once file descriptors are freed up again.

Would it maybe be possible for socket.accept? to block until file descriptors are available?

[straight-shoota]

Golang net/http uses a back-off strategy as well when accept fails with a temporary error.
https://cs.opensource.google/go/go/+/refs/tags/go1.24.3:src/net/http/server.go;l=3429-3441

It's not quite clear what exactly is temporary, but it seems like they consider timeouts temporary. The net.Error.Timeout() function is declared as deprecated, so not clear what's going on there.
Resource limits probably are not temporary tho and would break the server loop.

[straight-shoota]

I believe the most basic response to an error in accept? is to break the loop and propagate the error. If something unexpected happens, the sane choice is to abort and not just try again over and over.

On top of that default behaviour, we can define scenarios in which an error might not be fatal, and we could consider retrying, possible with some back-off strategy.