open https://gitlab.synchro.net/main/sbbs/-/issues/1157

Synchronet version: 3.21f
Platform tested: Windows
Protocol tested: Telnet and RLogin
Client(s) tested: SyncTerm 1.8, SyncTerm 1.6, Netrunner, netcat/nc
File involved: text/nonodes.txt

Issue:

When all nodes are full and a new caller connects, Synchronet logs !No nodes available for login. and appears to attempt to print text/nonodes.txt, but the caller does not always see the contents before being disconnected.

The issue is intermittent. In repeated testing, SyncTerm often disconnects too quickly for the message to be visible. Netrunner appeared to show the message every time during testing. Netcat/nc showed the message almost every time, but if connections were made repeatedly/quickly, the message could still fail to appear.

Example log entries from a failed display case:
6/5 05:14:44p 2068 Telnet [192.168.1.12] !No nodes available for login. 6/5 05:14:44p Terminal Server Printing file: d:\sbbs\TEXT\NONODES.TXT 6/5 05:14:44p Terminal Server !ERROR 58 (Error 122 getting error description) sending on socket 2068

This occurred even when the client did not visibly display nonodes.txt.

Testing notes:

* Telnet with SyncTerm 1.8: intermittent; roughly about a 30% chance of seeing the no-nodes message during initial testing.
* RLogin: appeared similar to Telnet.
* SSH: disconnects without displaying the message; this was expected/not considered the same issue.
* SyncTerm 1.6: same behavior as newer SyncTerm versions.
* Netrunner: displayed nonodes.txt every time during testing.
* Netcat/nc: displayed nonodes.txt almost every time, but rapid repeated attempts could reproduce missing output.
* Remote test: another user tested 12 rapid attempts from outside the LAN; only 1 attempt failed to show nonodes.txt.

DMs theory from IRC:

The server may be waiting for the ringbuffer containing nonodes.txt to empty before disconnecting, but the ringbuffer contents are moved to a linear buffer in output_thread. There may be a race condition where Synchronet disconnects before or during that linear buffer being sent to the client.

Possible workaround discussed:

A short delay after flushing the ringbuffer would likely make the issue disappear, but not sure if this is the correct method.

Additional notes:

1) SyncTerm displays a disconnected popup after the disconnect, which can (does) obscure the nonodes.txt text even when it was displayed.
2) Had a sysop friend test so its not just me on my LAN and 99% of the time it DID show nonodes.txt.
--- SBBSecho 3.37-Linux
* Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)

https://gitlab.synchro.net/main/sbbs/-/issues/1157#note_9263

<DigitalMan> I think the issue is that we're waiting for the ringbuffer that contains the nonodes.txt contents to empty (be sent) before disconnecting. But the ringbuffer is actually moved to a linear buffer (in output_thread) and there's a race condition whereby we disconnect before/during that linear buffer is being sent to the client
<DigitalMan> A short delay after flushing the ringbuffer would likely just make the problem disappear
<DigitalMan> but that's kind of hacky
--- SBBSecho 3.37-Linux
* Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)

https://gitlab.synchro.net/main/sbbs/-/issues/1157#note_9267

Fixed in 9cf170c02.

Thanks @xbit — your write-up nailed it, and the cross-client testing (the contrast between netcat/Netrunner almost always showing it vs. SyncTerm intermittently dropping it under rapid reconnects) pointed straight at a thread-scheduling race rather than anything protocol-specific. The IRC theory was correct too.

**Root cause:** the no-nodes path printed `nonodes.txt` then called `flush_output()`, which waits on the output ring buffer's `empty_event`. But that event fires when `output_thread` moves the ring-buffer contents into its *linear* buffer (`RingBufRead`), **not** when those bytes are actually sent over the socket. So `flush_output()` returned in the window between the ring→linear hand-off and the `sendsocket()`, the listener closed the socket, and `output_thread`'s send then failed on the closed descriptor — exactly the `!ERROR ... sending on socket` line in your log. With the message still sitting unsent in the linear buffer, the client never saw it.

**Fix:** a new `WaitForOutbufDrained()` that waits for the ring buffer to empty *and* for `output_thread`'s linear buffer to be fully transmitted (tracked via an `output_thread_busy` flag set before the ring read and cleared only after the bytes are sent). It replaces `flush_output()` at both `nonodes.txt` disconnect sites and in `trashcan_msg()`, so the same race is fixed for `badip.msg`/`badhost.msg` shown to blocked clients as well. No fixed/"hacky" delay involved — it waits exactly as long as the data takes to go out.

If you're able to rebuild from master, a re-test against your rapid-reconnect setup would be appreciated as final confirmation.

— *Authored by Claude (Claude Code), on behalf of @rswindell*
--- SBBSecho 3.37-Linux
* Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)

close https://gitlab.synchro.net/main/sbbs/-/issues/1157
--- SBBSecho 3.37-Linux
* Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)

https://gitlab.synchro.net/main/sbbs/-/issues/1157#note_9269

Updated and tested on test lab bbs. 100% works as intended now - issue is gone.

6/6 05:13:19a 0684 Telnet [192.168.1.12] !No nodes available for login.
6/6 05:13:19a Terminal Server Printing file: d:\sbbs\text\NONODES.TXT
6/6 05:13:19a 1688 Telnet [192.168.1.12] Connection accepted on 192.168.1.12 port 23 from port 50659
6/6 05:13:19a 1688 Telnet [192.168.1.12] Hostname: host.docker.internal
6/6 05:13:19a 1688 Telnet [192.168.1.12] !No nodes available for login.
6/6 05:13:19a Terminal Server Printing file: d:\sbbs\text\NONODES.TXT
6/6 05:13:19a 1756 Telnet [192.168.1.12] Connection accepted on 192.168.1.12 port 23 from port 50660
6/6 05:13:19a 1756 Telnet [192.168.1.12] Hostname: host.docker.internal
6/6 05:13:19a 1756 Telnet [192.168.1.12] !No nodes available for login.
6/6 05:13:19a Terminal Server Printing file: d:\sbbs\text\NONODES.TXT
6/6 05:13:20a 1716 Telnet [192.168.1.12] Connection accepted on 192.168.1.12 port 23 from port 50661
6/6 05:13:20a 1716 Telnet [192.168.1.12] Hostname: host.docker.internal
6/6 05:13:20a 1716 Telnet [192.168.1.12] !No nodes available for login.
6/6 05:13:20a Terminal Server Printing file: d:\sbbs\text\NONODES.TXT
--- SBBSecho 3.37-Linux
* Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)

https://gitlab.synchro.net/main/sbbs/-/issues/1157#note_9270

Just FYI: Tested placing a @PAUSE@ at the end of nonodes.txt in hopes it would require the caller to press enter giving them time to read the text before being passed back to the connecting system via rlogin or getting the pop-up form syncterm if connected via telnet. Sync shows the [press a key] correctly but the disconnect hits regardless. Again, just FYI as the nightly update worked.

{width=600 height=600}
--- SBBSecho 3.37-Linux
* Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)