Digital Man wrote to Gamgee <=-

Re: Re: Sending mail to areafix
By: Gamgee to Digital Man on Sun Jun 07 2026 08:18 am

Naturally, just after sending the above I need to send a followup: I did notice a pattern now after looking more at 'binkstats.ini'. What I saw was that when my system calls out to a MYSTIC board, I get a "callout success" entry - but calling a system using BINKIT or BINKD, I get the "callout failure" entry. Every single time. Got to be something to that...

The corresponding log output for that BinkIt session should provide the reason.

But that's just it - there *is* no reason. The callout is a complete
success, but it's entered in 'binkstats.ini' as a "callout failure".
This happens EVERY SINGLE CALLOUT to a SBBS system, but works every
single time to a MYSTIC system. Here are the log snippets for a callout today:

First is the sbbs.log entry:

Jun 07 17:44:48 palantir synchronet: evnt BINKOUT Attempting callout for 1:135/391@fidonet, file: /sbbs/fido/outbound/00870187.dlo
Jun 07 17:44:48 palantir synchronet: evnt BINKOUT JSBinkP/5 callout to 1:135/391@fidonet started
Jun 07 17:44:48 palantir synchronet: evnt BINKOUT Connecting to 1:135/391@fidonet at vague.ddns.net:24554
Jun 07 17:44:49 palantir synchronet: evnt BINKOUT Will encrypt session.
Jun 07 17:44:49 palantir synchronet: evnt BINKOUT Peer version: BinkIT/2.42,JSBinkP/4,sbbs3.21e/Win32
Jun 07 17:44:49 palantir synchronet: evnt BINKOUT Authentication successful: secure
Jun 07 17:44:49 palantir synchronet: evnt BINKOUT Sending file: /sbbs/fido/outbound/6a25f459.pkt (1.3KB)
Jun 07 17:44:49 palantir synchronet: evnt BINKOUT Sent file: /sbbs/fido/outbound/6a25f459.pkt (1.3KB)
Jun 07 17:44:49 palantir synchronet: evnt BINKOUT Deleted file: /sbbs/fido/outbound/00870187.dlo
Jun 07 17:44:49 palantir synchronet: evnt BINKOUT Deleted file: /sbbs/fido/outbound/6a25f459.pkt

Here is the corresponding entry in binkstats.ini:

[callout failure: 1:135/391@fidonet]
oper = Vague
AKAs = 1:135/391@fidonet
caps = 115200,TCP,BINKP
vers = BinkIT/2.42,JSBinkP/4,sbbs3.21e/Win32
host = vague.ddns.net
port = 24554
info.sys = Vague BBS
info.loc = Largo, FL
info.time = Sun Jun 07 2026 18:44:10 GMT-0400 (Eastern Daylight Time)
localtime = Jun 7 2026 17:44:49
sent_files = /sbbs/fido/outbound/6a25f459.pkt

I see this exact same thing on many different (downlink) versions of
BinkIT, if that means anything. I am using BinkIT v2.42, system last
updated 2-3 weeks ago. My logs show it has been happening for quite a
while.

I realize that it isn't really "hurting" anything, unless one was trying
to analyze/publish connection stats, but something doesn't seem right.




... Gone crazy, be back later, please leave message.
--- MultiMail/Linux v0.52
� Synchronet � Palantir BBS * palantirbbs.ddns.net * Pensacola, FL
* Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)

But that's just it - there *is* no reason. The callout is a complete success, but it's entered in 'binkstats.ini' as a "callout failure".

You and Khronos were both right - it was a bug in BinkIT, not your
configs, and no mail was ever actually lost. It was purely a
stats-recording bug.

In a binkp/1.1 session (what you get with Synchronet, binkd, and most
modern mailers) the two sides exchange a pair of M_EOB ("end of batch")
frames to close out. When your side reached the end by *sending* that
final EOB, the peer would close the connection first, and BinkIT would
then try to send one more EOB onto the already-closed socket. That
harmless send failure was being treated as a failed session - so a fully-successful callout got logged as "[callout failure]" in
binkstats.ini, with the sent file(s) still listed, which is exactly why
it looked so contradictory.

binkp/1.0 peers (Mystic) send only a single EOB each and close
differently, so those were always recorded correctly - matching the MYSTIC-works / SBBS-fails pattern you spotted.

Fixed in git just now: a closing-EOB send failure is ignored once all
of your sent files have been acknowledged. You'll see correct accounting
(and JSBinkP/6 in the vers= field) after your next update + recycle.

Thanks to you both for the clear reports and log snippets - they made
this an easy one to pin down.
--- SBBSecho 3.37-Linux
* Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)

Digital Man wrote to Gamgee <=-

But that's just it - there *is* no reason. The callout is a complete success, but it's entered in 'binkstats.ini' as a "callout failure".

You and Khronos were both right - it was a bug in BinkIT, not your configs, and no mail was ever actually lost. It was purely a stats-recording bug.

In a binkp/1.1 session (what you get with Synchronet, binkd, and most modern mailers) the two sides exchange a pair of M_EOB ("end of batch") frames to close out. When your side reached the end by *sending* that final EOB, the peer would close the connection first, and BinkIT would then try to send one more EOB onto the already-closed socket. That harmless send failure was being treated as a failed session - so a fully-successful callout got logged as "[callout failure]" in binkstats.ini, with the sent file(s) still listed, which is exactly why
it looked so contradictory.

binkp/1.0 peers (Mystic) send only a single EOB each and close differently, so those were always recorded correctly - matching the MYSTIC-works / SBBS-fails pattern you spotted.

Fixed in git just now: a closing-EOB send failure is ignored once all
of your sent files have been acknowledged. You'll see correct
accounting (and JSBinkP/6 in the vers= field) after your next update + recycle.

Thanks to you both for the clear reports and log snippets - they made
this an easy one to pin down.

Excellent! Thank you, DM, as always.



... Gone crazy, be back later, please leave message.
--- MultiMail/Linux v0.52
� Synchronet � Palantir BBS * palantirbbs.ddns.net * Pensacola, FL
* Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)

Re: Re: Sending mail to areafix
By: Digital Man to Gamgee on Sun Jun 07 2026 06:42 pm

But that's just it - there *is* no reason. The callout is a complete success, but it's entered in 'binkstats.ini' as a "callout failure".

You and Khronos were both right - it was a bug in BinkIT, not your
configs, and no mail was ever actually lost. It was purely a stats-recording bug.

In a binkp/1.1 session (what you get with Synchronet, binkd, and most
modern mailers) the two sides exchange a pair of M_EOB ("end of batch") frames to close out. When your side reached the end by *sending* that
final EOB, the peer would close the connection first, and BinkIT would
then try to send one more EOB onto the already-closed socket. That
harmless send failure was being treated as a failed session - so a fully-successful callout got logged as "[callout failure]" in
binkstats.ini, with the sent file(s) still listed, which is exactly why
it looked so contradictory.

binkp/1.0 peers (Mystic) send only a single EOB each and close
differently, so those were always recorded correctly - matching the MYSTIC-works / SBBS-fails pattern you spotted.

Fixed in git just now: a closing-EOB send failure is ignored once all
of your sent files have been acknowledged. You'll see correct accounting (and JSBinkP/6 in the vers= field) after your next update + recycle.

Thanks to you both for the clear reports and log snippets - they made
this an easy one to pin down.

Digital Man - an update on this... It's actually not related to the above context, but I'm now noticing in my logs a "warning" line that wasn't there before the above fix. I'm now using "master/135f08f0f" and seeing the below in logs after every remote system connection here (I'm a Fidonet hub):

Jun 13 09:27:00 palantir synchronet: srvc 0013 BINKP [157.245.114.161] Connection accepted on 192.168.254.70 port 24554 from port 59274
Jun 13 09:27:01 palantir synchronet: srvc 0013 BINKP BinkIT/2.42 invoked with options:
Jun 13 09:27:01 palantir synchronet: srvc 0013 BINKP JSBinkP/6 inbound connection from 157.245.114.161:59274
Jun 13 09:27:01 palantir synchronet: srvc 0013 BINKP Will encrypt session.
Jun 13 09:27:01 palantir synchronet: srvc 0013 BINKP Peer version: BinkIT/2.42,JSBinkP/4,sbbs3.21a/Linux
Jun 13 09:27:01 palantir synchronet: srvc 0013 BINKP Remote addresses: 1:135/260@fidonet
Jun 13 09:27:01 palantir synchronet: srvc 0013 BINKP Inbound session for: 1:135/260@fidonet
Jun 13 09:27:01 palantir synchronet: srvc 0013 BINKP CRAM-MD5 password match for 1:135/260@fidonet
Jun 13 09:27:02 palantir synchronet: srvc 0013 BINKP !JavaScript warning /sbbs/exec/binkit.js line 1268: Disconnected
Jun 13 09:27:02 palantir synchronet: srvc 0013 BINKP [157.245.114.161] JavaScript service thread terminated (0 clients remain, 0 total, 68 served)

Hopefully the long lines didn't make it impossible to read, but the line I'm talking about is the "!JavaScript warning... line 1268: Disconnected".

That didn't used to be there, and now happens on every single inbound poll/connection, whether they transfer any mail packets or not.

Understood that it's "just a warning" but seems odd... Thanks.

---
� Synchronet � Palantir BBS * palantirbbs.ddns.net * Pensacola, FL
* Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)

Re: Re: Sending mail to areafix
By: Gamgee to Digital Man on Sat Jun 13 2026 09:42 am

Re: Re: Sending mail to areafix
By: Digital Man to Gamgee on Sun Jun 07 2026 06:42 pm

But that's just it - there *is* no reason. The callout is a complete success, but it's entered in 'binkstats.ini' as a "callout failure".

You and Khronos were both right - it was a bug in BinkIT, not your configs, and no mail was ever actually lost. It was purely a stats-recording bug.

In a binkp/1.1 session (what you get with Synchronet, binkd, and most modern mailers) the two sides exchange a pair of M_EOB ("end of batch") frames to close out. When your side reached the end by *sending* that final EOB, the peer would close the connection first, and BinkIT would then try to send one more EOB onto the already-closed socket. That harmless send failure was being treated as a failed session - so a fully-successful callout got logged as "[callout failure]" in binkstats.ini, with the sent file(s) still listed, which is exactly why it looked so contradictory.

binkp/1.0 peers (Mystic) send only a single EOB each and close differently, so those were always recorded correctly - matching the MYSTIC-works / SBBS-fails pattern you spotted.

Fixed in git just now: a closing-EOB send failure is ignored once all
of your sent files have been acknowledged. You'll see correct accounting (and JSBinkP/6 in the vers= field) after your next update + recycle.

Thanks to you both for the clear reports and log snippets - they made this an easy one to pin down.

Digital Man - an update on this... It's actually not related to the above context, but I'm now noticing in my logs a "warning" line that wasn't there before the above fix. I'm now using "master/135f08f0f" and seeing the below in logs after every remote system connection here (I'm a Fidonet hub):

Jun 13 09:27:00 palantir synchronet: srvc 0013 BINKP [157.245.114.161] Connection accepted on 192.168.254.70 port 24554 from port 59274
Jun 13 09:27:01 palantir synchronet: srvc 0013 BINKP BinkIT/2.42 invoked with options:
Jun 13 09:27:01 palantir synchronet: srvc 0013 BINKP JSBinkP/6 inbound connection from 157.245.114.161:59274
Jun 13 09:27:01 palantir synchronet: srvc 0013 BINKP Will encrypt session. Jun 13 09:27:01 palantir synchronet: srvc 0013 BINKP Peer version: BinkIT/2.42,JSBinkP/4,sbbs3.21a/Linux
Jun 13 09:27:01 palantir synchronet: srvc 0013 BINKP Remote addresses: 1:135/260@fidonet
Jun 13 09:27:01 palantir synchronet: srvc 0013 BINKP Inbound session for: 1:135/260@fidonet
Jun 13 09:27:01 palantir synchronet: srvc 0013 BINKP CRAM-MD5 password match for 1:135/260@fidonet
Jun 13 09:27:02 palantir synchronet: srvc 0013 BINKP !JavaScript warning /sbbs/exec/binkit.js line 1268: Disconnected
Jun 13 09:27:02 palantir synchronet: srvc 0013 BINKP [157.245.114.161] JavaScript service thread terminated (0 clients remain, 0 total, 68 served)

Hopefully the long lines didn't make it impossible to read, but the line I'm talking about is the "!JavaScript warning... line 1268: Disconnected".

That didn't used to be there, and now happens on every single inbound poll/connection, whether they transfer any mail packets or not.

Understood that it's "just a warning" but seems odd... Thanks.

Digital Man,

I've now uncovered a far more serious issue with this... I noticed that I had a LOT of FTN mail for outbound nodes (downlinks) piling up and not going out. Logs showed it coming in, but the 'FIDOIN' and 'BINKOUT' timed events were not being triggered. I looked at ../exec/binkit.js and saw that the warning above on line 1268 is related to that adjustment you made for the binkstats.ini bug... Apparently binkit.js is EXITING at that failure and therefore... the very last line of binkit.js which is "touch semaphores();" never gets called. That's an issue for FTN operations... ;)

I commented out the binkstats.ini block just above the semaphore line, and the FIDOIN and BINKOUT events now trigger as expected...

---
� Synchronet � Palantir BBS * palantirbbs.ddns.net * Pensacola, FL
* Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)

Apparently binkit.js is EXITING at that failure and therefore... the
very last line of binkit.js which is "touch_semaphores();" never gets
called.

Great detective work - that's exactly it, and it's the same root cause as
the IRC/MRC "Disconnected" warnings from a couple weeks back (#1156), just
a nastier symptom.

A recent change (song-11-earn) had the Services server abort a JavaScript service ~10 callbacks after its client socket disconnects - meant to kill scripts that loop forever after a hang-up. A follow-up (bolt-11-banner) exempted static services (the IRC daemon, MRC connector), but binkit runs
as a normal per-connection service, and it legitimately keeps working after
the binkp peer disconnects: finishing the batch, writing binkstats.ini,
and - as its last act - touching the FIDOIN/BINKOUT semaphores. So the
engine was killing it mid-cleanup (your "line 1268: Disconnected"), and
those semaphores never got touched. Hence the downlink mail piling up.

Your workaround worked because dropping the binkstats block let the script reach touch_semaphores() before the 10-callback abort fired.

Proper fix is in git now (wooden-11-choices): the client-disconnect abort
is a separate, scriptable knob (js.terminate_on_disconnect) decoupled from auto_terminate, and binkit.js sets it false so it's never aborted on disconnect. auto_terminate again governs only server shutdown/recycle.

Pull + rebuild and FIDOIN/BINKOUT will fire normally again - you can revert your binkstats.ini edit. Thanks for the sharp diagnosis and the heads-up.

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

Digital Man wrote to Gamgee <=-

Apparently binkit.js is EXITING at that failure and therefore... the
very last line of binkit.js which is "touch_semaphores();" never gets called.

Great detective work - that's exactly it, and it's the same root cause
as the IRC/MRC "Disconnected" warnings from a couple weeks back
(#1156), just a nastier symptom.

A recent change (song-11-earn) had the Services server abort a
JavaScript service ~10 callbacks after its client socket disconnects - meant to kill scripts that loop forever after a hang-up. A follow-up (bolt-11-banner) exempted static services (the IRC daemon, MRC
connector), but binkit runs as a normal per-connection service, and it legitimately keeps working after the binkp peer disconnects: finishing
the batch, writing binkstats.ini, and - as its last act - touching the FIDOIN/BINKOUT semaphores. So the engine was killing it mid-cleanup
(your "line 1268: Disconnected"), and those semaphores never got
touched. Hence the downlink mail piling up.

Your workaround worked because dropping the binkstats block let the
script reach touch_semaphores() before the 10-callback abort fired.

Proper fix is in git now (wooden-11-choices): the client-disconnect
abort is a separate, scriptable knob (js.terminate_on_disconnect) decoupled from auto_terminate, and binkit.js sets it false so it's
never aborted on disconnect. auto_terminate again governs only server shutdown/recycle.

Pull + rebuild and FIDOIN/BINKOUT will fire normally again - you can revert your binkstats.ini edit. Thanks for the sharp diagnosis and the heads-up.

Welcome, and thank you for the quick fix! I will get updated tomorrow, appreciate it.



... Gone crazy, be back later, please leave message.
--- MultiMail/Linux v0.52
� Synchronet � Palantir BBS * palantirbbs.ddns.net * Pensacola, FL
* Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)