WSAENOBUFS: Running out of buffer space on Windows

changed milestone to %Tor: unspecified

added component::core tor/tor milestone::Tor: unspecified parent::1753 priority::high reporter::spy1 resolution::worksforme severity::normal status::closed tor-relay type::defect version::0.0.9.4 labels

I did some googling, and I think that isn't a Tor bug. hang on, where's that web page? Read http://www.jsiinc.com/subb/tip0900/rh0914.htm

<spy1> WHICH web page?

> Or http://faq.proxyplus.de/art10002.htm If the advice there works, let me know. if it doesn't work, let me know

<goodell> nickm2: eek. Does this mean that Tor will have to start frobbing Windows registries just to be able to get more than 5000 ephemeral TCP ports?

> Either that, or Tor server operators will. Apparently, windows likes to spell 'ulimit -n 10000' funny

<goodell> Yeah, my thoughts exactly. But at least that answers my question +of whether Windows has an analogous problem.

<spy1> Well. THAT should keep me busy for the rest of the day. Thank you for the links.

> The problem really isn't the number of sockets, though. it's the fact that sockets remain allocated for 240 seconds after the application closes them!

So the solution seems to be: see the suggested fix on those pages works. If so, consider whether Tor should 1) alter the registry entries automatically and/or 2) be more robust against WSAENOBUFS.

Feb 06 00:50:31.002 [notice] circuit_log_path(): circ (length 3, exit rootdown): dizum(open) tongatest(open) rootdown(open) Feb 06 00:58:47.967 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 06 00:59:00.155 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 06 01:53:31.018 [notice] connection_ap_expire_beginning(): Stream is 15 seconds late on address 'www.mynetwatchman.com'. Retrying. Feb 06 01:53:31.018 [notice] circuit_log_path(): circ (length 3, exit rodos): countach(open) wuschelpuschel(open) rodos(open) Feb 06 02:02:19.958 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 06 02:02:36.612 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 06 02:02:37.013 [notice] connection_ap_expire_beginning(): Stream is 15 seconds late on address 'www.mynetwatchman.com'. Retrying. Feb 06 02:02:37.013 [notice] circuit_log_path(): circ (length 3, exit masquerade): gamma(open) tongatest(open) masquerade(open) Feb 06 02:47:39.469 [err] do_main_loop(): poll failed: No buffer space available [WSAENOBUFS ] [10055]

Feb 08 01:31:33.002 [notice] connection_ap_handshake_attach_circuit(): Giving up on unattached conn (61 sec old). Feb 08 01:34:51.727 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 08 01:34:52.498 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 08 01:34:52.568 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 08 01:36:03.761 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 08 01:36:06.174 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 08 01:36:08.688 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 08 01:53:41.001 [notice] connection_ap_expire_beginning(): Stream is 15 seconds late on address 'www.mynetwatchman.com'. Retrying. Feb 08 01:53:41.001 [notice] circuit_log_path(): circ (length 3, exit simonthesourcerer): gamma(open) Tonga(open) simonthesourcerer(open) Feb 08 01:54:23.001 [notice] connection_ap_handshake_attach_circuit(): Giving up on unattached conn (60 sec old). Feb 08 01:59:05.307 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 08 02:17:29.455 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 08 02:17:29.746 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 08 02:17:40.691 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 08 02:44:45.007 [notice] connection_ap_handshake_attach_circuit(): Giving up on unattached conn (60 sec old). Feb 08 02:52:18.479 [err] do_main_loop(): poll failed: No buffer space available [WSAENOBUFS ] [10055]

Feb 08 08:43:20.217 [notice] Tor 0.0.9.4 opening new log file. Feb 08 08:43:27.106 [notice] circuit_send_next_onion_skin(): Tor has successfully opened a circuit. Looks like it's working. Feb 08 08:55:00.002 [notice] connection_ap_expire_beginning(): Stream is 15 seconds late on address 'www.mynetwatchman.com'. Retrying. Feb 08 08:55:00.002 [notice] circuit_log_path(): circ (length 3, exit bmwanon): tor26(open) Tonga(open) bmwanon(open) Feb 08 08:59:37.004 [notice] connection_ap_expire_beginning(): Stream is 15 seconds late on address 'www.mynetwatchman.com'. Retrying. Feb 08 08:59:37.004 [notice] circuit_log_path(): circ (length 3, exit athenathegodess): masquerade(open) Omega(open) athenathegodess(open) Feb 08 09:07:22.003 [notice] connection_ap_expire_beginning(): Stream is 15 seconds late on address 'www.mynetwatchman.com'. Retrying. Feb 08 09:07:22.003 [notice] circuit_log_path(): circ (length 3, exit Omega): datenhalde(open) c3po(open) Omega(open) Feb 08 09:22:39.339 [err] do_main_loop(): poll failed: No buffer space available [WSAENOBUFS ] [10055]

Trac:
Username: spy1

Feb 08 12:08:18.796 [notice] Tor 0.0.9.4 opening new log file. Feb 08 12:08:28.530 [notice] directory_handle_command_get(): Client asked for the mirrored directory, but we don't have a good one yet. Sending 503 Dir not available. Feb 08 12:08:39.025 [notice] circuit_send_next_onion_skin(): Tor has successfully opened a circuit. Looks like it's working. Feb 08 12:08:44.062 [notice] directory_handle_command_get(): Client asked for the mirrored directory, but we don't have a good one yet. Sending 503 Dir not available. Feb 08 12:10:11.117 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 08 12:15:14.333 [notice] directory_handle_command_get(): Client asked for the mirrored directory, but we don't have a good one yet. Sending 503 Dir not available. Feb 08 12:15:55.743 [notice] directory_handle_command_get(): Client asked for the mirrored directory, but we don't have a good one yet. Sending 503 Dir not available. Feb 08 12:17:07.366 [notice] directory_handle_command_get(): Client asked for the mirrored directory, but we don't have a good one yet. Sending 503 Dir not available. Feb 08 12:18:16.866 [err] do_main_loop(): poll failed: No buffer space available [WSAENOBUFS ] [10055]

Well, I don't know what else to do. I'm going to leave it shut down for awhile unless something new developes. Pete

Trac:
Username: spy1

I just did those nine critical updates for WinXp from M$ updates - Tor seems to be running fine and I'll let you know if it has any effect on the Tor shut-down problem I'm having, either good or bad. Pete

Trac:
Username: spy1

To be clear, you still got those errors after the registry fixes, but installing the critical updates made stuff better?

Nick - I don't know yet. I was going to leave the server running when I went to work, but that didn't work out. I've started it up again and I'll check it in the morning. Pete

Trac:
Username: spy1

Well, it ran for about 4 hours or so last night before shutting down:

Feb 10 02:12:45.400 [notice] Tor 0.0.9.4 opening new log file. Feb 10 02:13:07.942 [notice] conn_close_if_marked(): Conn (addr 80.133.132.148, fd 592, type Dir, state 1) is being closed, but there are still 73 bytes we can't write. (Marked at main.c:277) Feb 10 02:13:11.668 [notice] circuit_send_next_onion_skin(): Tor has successfully opened a circuit. Looks like it's working. Feb 10 02:26:46.039 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 02:26:50.295 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 02:27:05.958 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 02:27:06.028 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 02:27:06.038 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 02:27:06.278 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 02:48:58.004 [notice] connection_ap_expire_beginning(): Stream is 15 seconds late on address 'www.mynetwatchman.com'. Retrying. Feb 10 02:48:58.004 [notice] circuit_log_path(): circ (length 3, exit dizum): chaoscomputerclub(open) anorien(open) dizum(open) Feb 10 02:51:42.010 [notice] connection_ap_handshake_attach_circuit(): Giving up on unattached conn (60 sec old). Feb 10 03:13:44.001 [notice] connection_ap_expire_beginning(): Stream is 15 seconds late on address 'www.mynetwatchman.com'. Retrying. Feb 10 03:13:44.001 [notice] circuit_log_path(): circ (length 3, exit chaoscomputerclub): r30(open) rodos(open) chaoscomputerclub(open) Feb 10 03:35:16.189 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 03:35:27.005 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 03:35:38.651 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 03:35:41.465 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 03:38:14.005 [notice] connection_ap_expire_beginning(): Stream is 15 seconds late on address 'www.mynetwatchman.com'. Retrying. Feb 10 03:38:14.005 [notice] circuit_log_path(): circ (length 3, exit dizum): toffolandia(open) balance(open) dizum(open) Feb 10 03:52:30.586 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 03:52:30.656 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 03:53:10.334 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 03:56:39.004 [notice] connection_ap_expire_beginning(): Stream is 15 seconds late on address 'www.mynetwatchman.com'. Retrying. Feb 10 03:56:39.004 [notice] circuit_log_path(): circ (length 3, exit blagtor): nirvana(open) Tonga(open) blagtor(open) Feb 10 03:56:43.009 [notice] connection_ap_handshake_attach_circuit(): Giving up on unattached conn (60 sec old). Feb 10 04:03:22.243 [err] do_main_loop(): poll failed: No buffer space available [WSAENOBUFS ] [10055]

SO, I didn't re-start the computer this morning and re-opened Tor - which closed almost immediately:

Feb 10 09:49:22.265 [notice] Tor 0.0.9.4 opening new log file. Feb 10 09:49:28.163 [notice] circuit_send_next_onion_skin(): Tor has successfully opened a circuit. Looks like it's working. Feb 10 10:14:29.192 [err] do_main_loop(): poll failed: No buffer space available [WSAENOBUFS ] [10055]

which means that whatever type of resource it used up has to be re-established by doing a re-boot, I think. Interesting problem here. Pete

Trac:
Username: spy1

I made the two (actually one since one was already done) registry changes that were suggested to me by nicm on the same day they were suggested. AFAICS, it's managed to gain me about an hours' worth of "uptime" when running the server (since it now stays up for two hours (approx.) rather than just one hour) - but the irritating thing is that, instead of just being able to re-start the server and have another two hours, I actually have to re-boot to release whatever it is the Tor server is exhausting, resource-wise. If I don't the server only stays up a very short time (sometimes only minutes) before it shuts down again.

I'm wide-open for additional things to try here. Pete

Trac:
Username: spy1

I also tried increasing the thread priority of tor.exe to "Realtime: 24" with Sysinternals Process Explorer, but that didn't help (at least not without a re-start):

Feb 10 11:07:04.618 [notice] Tor 0.0.9.4 opening new log file. Feb 10 11:07:07.162 [notice] circuit_send_next_onion_skin(): Tor has successfully opened a circuit. Looks like it's working. Feb 10 11:07:26.790 [notice] conn_close_if_marked(): Conn (addr 195.64.88.140, fd 552, type Dir, state 1) is being closed, but there are still 72 bytes we can't write. (Marked at main.c:277) Feb 10 11:15:47.009 [notice] connection_ap_expire_beginning(): Stream is 15 seconds late on address 'www.mynetwatchman.com'. Retrying. Feb 10 11:15:47.009 [notice] circuit_log_path(): circ (length 3, exit serifos): cyanid(open) dali(open) serifos(open) Feb 10 12:38:04.379 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 12:38:04.719 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 12:38:04.719 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 12:38:04.799 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 12:38:04.799 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 12:38:04.809 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 12:38:15.455 [err] do_main_loop(): poll failed: No buffer space available [WSAENOBUFS ] [10055] Feb 10 13:02:04.510 [notice] Tor 0.0.9.4 opening new log file. Feb 10 13:02:17.188 [notice] circuit_send_next_onion_skin(): Tor has successfully opened a circuit. Looks like it's working. Feb 10 13:09:19.215 [warn] connection_about_to_close_connection(): Harmless bug: Edge connection hasn't sent end yet? Feb 10 13:15:50.007 [notice] connection_ap_expire_beginning(): Stream is 15 seconds late on address 'www.mynetwatchman.com'. Retrying. Feb 10 13:15:50.007 [notice] circuit_log_path(): circ (length 3, exit serifos): nirvana(open) masquerade(open) serifos(open) Feb 10 13:24:56.002 [notice] connection_ap_expire_beginning(): Stream is 15 seconds late on address 'www.mynetwatchman.com'. Retrying. Feb 10 13:24:56.002 [notice] circuit_log_path(): circ (length 3, exit nirvana): gamma(open) datenhalde(open) nirvana(open) Feb 10 13:27:33.007 [notice] connection_ap_handshake_attach_circuit(): Giving up on unattached conn (60 sec old). Feb 10 13:39:21.306 [err] do_main_loop(): poll failed: No buffer space available [WSAENOBUFS ] [10055]

I tried running this little utility: http://www.speedguide.net/read_articles.php?id=1497 , but it tells me that I already have 50 half-open connections available, so it doesn't LOOK like I'd want to reduce it to 10.

Am I the only one I'm driving nutso here? Pete

Trac:
Username: spy1

Have you tried upgrading to 0.1.0.10? Although, I think XP will still run into the same issues, as tcpip.sys hardcodes how many connects/sec it'll allow. I'm assuming this is XP Home/Pro and not server.
I believe Home/Pro are limited on purpose, to avoid people using them as servers instead of W2K3 Server.

is this still a problem with 0.1.0.14 or 0.1.1.5-alpha? I've been unable to replicate this bug.
There are a few things I can think of:

tcpip.sys limits
security policies limiting access to system resources (which ones, I don't know yet, still investigating)
really asynchronous connection causing one way to overload the other (fast downstream, slow upstream for instance)
network card driver having issues with connections/traffic flow (what network card do you have?)
ghosts in the machine
winsock.dll or heap resources running real low

The official Microsoft description is: WSAENOBUFS 10055

No buffer space available. An operation on a socket could not be performed because the system lacked sufficient buffer space or because a queue was full.

Trac:

b8zs memory when tor fails

Someone named b8zs reported this error in 0.1.1.7-alpha under winxp pro running as server.
It occurs roughly 2 hours after starting the process.
Attached PNG image shows that memory looks standard.

I get this same problem on 0117 alpha, on XP SP2. I have shut down my Tor server for the time being, becuase it opens too many ports, crashes, and apparently leave residual services running which kill my CPU.

Trac:
Username: unix_worship

It's been suggested that some people are seeing a problem like this because SP2 introduces a limit on the number of simultaneous half-connections that can be patched around using the "patcher" tool at http://www.lvllord.de/ . I have not verified this, or confirmed the benevolence of this tool.

SP2's behavior seems to be designed to prevent worms from probing multiple systems, and in order to annoy decent programmers like us.

See also http://www.speedguide.net/read_articles.php?id=1497&print=friendly

I suspect that one reason this bug has lasted for so long is that, so far as I can tell, nearly all win32 versions limit TCP sockets, but all of them seem to do it in weird and different ways.

WSAENOBUFS: Running out of buffer space on Windows

Child items 0

Activity