named on OpenBSD sometimes logs ‘error sending response: not enough free resources’ under load
I recently repaved my OpenBSD firewall/router to upgrade to OpenBSD 4.4 and more importantly to load the OS and config files onto a CompactFlash drive, after I started noticing the telltale ‘clunk’ sound coming from its hard drive. Not wanting to lose Internet access at an inopportune time, I switched to 4GB of cheap, solid-state storage.
However, during the reconfiguration I started to get alot of messages like this, particularly during heavy network loads:
Feb 21 23:54:33 boromir named[11546]: client 192.168.1.127#50805: error sending response: not enough free resources
I googled around, and noticed a number of people reporting this problem with named, on OpenBSD, FreeBSD, and some Linux flavors. For me, I can make it happen by downloading a well-seeded BitTorrent and thereby saturating my network pipe. Others also reported the issue being correlated with heavy network loads of one sort or another.
The usual suspects have already been eliminated. Here’s what top says:
load averages: 0.08, 0.08, 0.08
28 processes: 27 idle, 1 on processor
CPU states: 0.2% user, 0.0% nice, 0.2% system, 22.9% interrupt, 76.8% idle
Memory: Real: 26M/55M act/tot Free: 95M Swap: 0K/516M used/tot
As you can see, it’s not simply a problem of low memory. I’ve got plenty of physical free, and haven’t even touched swap.
So, maybe mbufs, right? No:
# netstat -m
105 mbufs in use:
97 mbufs allocated to data
2 mbufs allocated to packet headers
6 mbufs allocated to socket names and addresses
96/376/6144 mbuf clusters in use (current/peak/max)
852 Kbytes allocated to network (25% in use)
0 requests for memory denied
0 requests for memory delayed
0 calls to protocol drain routines
I also tried mucking about with some network-related sysctls. I found a list here that I tried (only the ‘net’ stuff), to no avail.
Then I pulled a copy of the source code for OpenBSD’s named implementation. If you’re interested, its on any OpenBSD AnonCVS mirror under src/usr.sbin/bind. The WebCVS interface is here. Under bin/named in client.c, is this:
static void
client_senddone(isc_task_t *task, isc_event_t *event) {
ns_client_t *client;
isc_socketevent_t *sevent = (isc_socketevent_t *) event;
REQUIRE(sevent != NULL);
REQUIRE(sevent->ev_type == ISC_SOCKEVENT_SENDDONE);
client = sevent->ev_arg;
REQUIRE(NS_CLIENT_VALID(client));
REQUIRE(task == client->task);
REQUIRE(sevent == client->sendevent);
UNUSED(task);
CTRACE("senddone");
if (sevent->result != ISC_R_SUCCESS)
ns_client_log(client, NS_LOGCATEGORY_CLIENT,
NS_LOGMODULE_CLIENT, ISC_LOG_WARNING,
"error sending response: %s",
isc_result_totext(sevent->result));
INSIST(client->nsends > 0);
client->nsends--;
if (client->tcpbuf != NULL) {
INSIST(TCP_CLIENT(client));
isc_mem_put(client->mctx, client->tcpbuf, TCP_BUFFER_SIZE);
client->tcpbuf = NULL;
}
if (exit_check(client))
return;
ns_client_next(client, ISC_R_SUCCESS);
}
Note the part in bold. So this is where the “error sending response” bit comes from. I’m no expert in BIND code, but I’ve done a good bit of socket programming, and this routine appears to handle the asynchronous (or, in socket terms, ‘non-blocking’) completion of a send call, writing a response back to the DNS client. The send has failed, so it’s writing out this message to the log. However, what of the other part? What of not enough free resources?
Well, notice what is provided for the %s placeholder: the results of isc_result_totext(sevent->result). So isc_result_totext is getting some sort of error code and converting it into the “not enough free resources” message. But what code?
I then greped the whole bind tree for the text “not enough free resources”. I found this line in lib/isc/include/isc/result.h:
#define ISC_R_NORESOURCES 13 /*%< not enough free resources */
There’s also a corresponding result.c that implements the isc_result_totext function. So, what causes the ISC_R_NORESOURCES error?
I did some more grep work for that error code, and found lots of instances, mostly in lib/isc/unix/socket.c. Upon reviewing all the instances, it appears that error is almost always a result of a ENOBUFS errno from a socket operation.
So off we go to the send manpage. According to that, a return value of ENOBUFS denotes one of two things:
- “The system was unable to allocate an internal buffer. The operation may succeed when buffers become available.”
- “The output queue for a network interface was full. This generally indicates that the interface has stopped sending, but may be caused by transient congestion.”
If ‘internal buffer’ means ‘mbuf’, then I doubt that’s the problem, as I’ve got plenty of room there. It was the output queue that struck me. This is happening during heavy load, when the internal network interface would be getting alot of traffic. But what determines the size of its output queue, and how do you grow it?
I rummaged around alot on this, and I could not find an answer. I looked for driver configuration options for the fxp driver, and found nothing. So then I started poking around the source code for the fxp driver, and found this:
IFQ_SET_MAXLEN(&ifp->if_snd, FXP_NTXCB - 1);
FXP_NTXCB is defined in the header file, and is hard-coded to 128:
/* * Number of transmit control blocks. This determines the number * of transmit buffers that can be chained in the CB list. * This must be a power of two. */ #define FXP_NTXCB 128
It appears from this reading that the interface’s send queue is hard-coded. In order to lift this limit I would either have to do a custom kernel build, or find a network adapter with a larger and/or configurable send queue. That just doesn’t make sense, as OpenBSD isn’t supposed to be that lame. It’s entirely possible I’m misunderstanding the cause of the problem, especially since users have reported this under FreeBSD and Linux as well, but damned if I know what to do about it.
Ultimately this isn’t a huge issue. Apart from the aversion I have to a bunch of errors in my syslog, UDP in general and DNS in particular are designed to handle dropped responses by retransmitting the requests, but it does result in a perceptible lag during DNS resolution which I’d really like to fix.