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

When outbound FTN mail is created, sbbsecho is correctly placing the .?lo file in the zone oubound dir, and triggering binkit to send it.

It seems when binkit calls the remote, when it goes to open the .?lo file to see what to send, its gone. I can re-produce this pretty easily, its happening for all my FTN networks.

As a consequence, no mail gets sent.

Here is an except from syslog:

```
Jun 02 15:42:47 ? local1.info synchronet: evnt FIDOOUT Running native timed event: /opt/sbbs/exec/sbbsecho -ni
Jun 02 15:42:49 ? local1.info synchronet: evnt FIDOOUT Timed event: '/opt/sbbs/exec/sbbsecho -ni' returned 0
Jun 02 15:42:50 ? local1.info synchronet: evnt BBS Events Semaphore signaled for Timed Event: BINKOUT
Jun 02 15:42:50 ? local1.info synchronet: evnt BINKOUT Running native timed event: ?binkit
Jun 02 15:42:50 ? local1.info synchronet: evnt BINKOUT BinkIT/2.41 invoked with options:
Jun 02 15:42:51 ? local1.info synchronet: evnt BINKOUT Attempting callout for 12:1/1@dovenet, file: /opt/sbbs/fido/outbound.00c/00010001.dlo
Jun 02 15:42:51 ? local1.info synchronet: evnt BINKOUT JSBinkP/4 callout to 12:1/1@dovenet started
Jun 02 15:42:51 ? local1.info synchronet: evnt BINKOUT Connecting to 12:1/1@dovenet at clrghouz.bbs.dege.au:24554
Jun 02 15:43:00 ? local1.info synchronet: evnt BINKOUT Will encrypt session. Jun 02 15:43:00 ? local1.info synchronet: evnt BINKOUT Authentication successful: secure
Jun 02 15:43:28 ? local1.err synchronet: evnt BINKOUT Error 11 opening FLO file: /opt/sbbs/fido/outbound.00c/00010001.dlo
Jun 02 15:43:31 ? local1.info synchronet: evnt BINKOUT Timed event: '?binkit' returned 0
```

After this session, flow file `/opt/sbbs/fido/outbound.00c/00010001.dlo` is no longer there - and the packets that it would have been sending still are. The remote hasnt got the packets.

I recently moved to aarch64 from x86_64, so wondering if this is related.

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7291

Background notes:
* SBBS was built on 02 June.
* In DOVE you mentioned:

```
/usr/include/asm-generic/errno-base.h:#define EAGAIN 11 /* Try again */

I'm guessing that means the file was opened for exclusive access or the file system was doing something with the file. It's not saying the file "is gone".
```

This is running on a ceph file system, in a docker container. If you are doing any system calls to get the exclusive locks, then it might be possible that those calls are blocked - but that shouldnt lead to the .?lo file being deleted.

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7291

Background notes:
* SBBS was built on 02 June.
* In DOVE you mentioned:

```
/usr/include/asm-generic/errno-base.h:#define EAGAIN 11 /* Try again */

I'm guessing that means the file was opened for exclusive access or the file system was doing something with the file. It's not saying the file "is gone".
```

This is running on a ceph file system, in a docker container. If you are doing any system calls to get the exclusive locks, then it might be possible that those calls are blocked - but that shouldnt lead to the .?lo file being deleted.

* If I recreate the .?lo file, and send it interactively with `jsexec`, then the mail is transferred successfully, the ?.flo file is removed after the session and no ERROR 11 is reported.

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7292

Do you see the "Deleted file:" log message, in either case?

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7293

When I run it on the command line, yes, but from syslog no. My syslog has no mention of any "Deleted file:" messages (from this session or others).

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7293

When I run it on the command line, yes, but from syslog (when the event manager runs it) no. My syslog has no mention of any "Deleted file:" messages (from this session or others).

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7294

I added some debugging to binkit.js

```
--- exec/binkit.js 2025-06-02 09:33:36.000000000 +1000
+++ mods/binkit.js 2025-06-03 10:58:29.028137259 +1000
@@ -231,11 +231,13 @@
case '.flo':
case '.hlo':
case '.ilo':
+ log(LOG_INFO,"Hello debugging mode - opening flo file.")
flo = new File(file);
if (!flo.open("r")) {
log(LOG_ERROR, "Error " + flo.error + " opening FLO file: " + flo.name);
break;
}
+ log(LOG_INFO,"Hello debugging mode - stepped past open, it must have worked?")
if (bp.cb_data.binkit_flow_contents[flo.name] === undefined)
bp.cb_data.binkit_flow_contents[flo.name] = [];
while((line = flo.readln(2048))) {
@@ -292,6 +294,8 @@
log(LOG_WARNING, "Unsupported flow file type '"+file+"'.");
break;
}
+
+ log(LOG_INFO,"Hello debugging mode - stepped past open, we either break'ed or got here naturally?")
});
}
if(bp.cb_data.binkitcfg.node[addr] === undefined
```

And this is the result:

```
│Jun 03 11:00:53 ⋮ local1.info synchronet: evnt BINKOUT Hello debugging mode - opening flo file. │
│Jun 03 11:01:22 ⋮ local1.err synchronet: evnt BINKOUT Error 11 opening FLO file: /opt/sbbs/fido/outbound.00a/00010001.flo │
│Jun 03 11:01:22 ⋮ local1.info synchronet: evnt BINKOUT Hello debugging mode - stepped past open, we either break'ed or got here naturally? ┤
│Jun 03 11:01:23 ⋮ local1.info synchronet: evnt BINKOUT Timed event: '?binkit' returned 0 │
```
---
ï¿­ Synchronet ï¿­ Vertrauen ï¿­ Home of Synchronet ï¿­ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7295

OK, possibly two issues?

* `new File(file)` is generating the `ERROR 11`
* The `.?lo` file is being deleted by the function `unlock_flow`, by the statement `locks.bsy.remove()`.

Some debugging shows that `unlock_flow(locks)` has the `.?lo` file listed in the `locks` array:

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7296

OK, for the 2nd part of the problem, where `.?lo` is in the locks array, it looks like the regex in `lock_file(file)`, is being passed a `.?lo` file, and should return a `.bsy` file - but its not working:

```
log(LOG_INFO,"START lock_flow: "+file)
log(LOG_INFO,JSON.stringify(file.replace(/\.[^\.]*?$/, '.bsy')));
```

Returns:

```
│Jun 03 13:31:36 ⋮ local1.info synchronet: evnt BINKOUT START lock_flow: /opt/sbbs/fido/outbound.00a/00010001.flo │
│Jun 03 13:31:36 ⋮ local1.info synchronet: evnt BINKOUT "/opt/sbbs/fido/outbound.00a/00010001.flo" ┤
```

However later, an actual call doesnt have a suffix:

```
│Jun 03 13:31:45 ⋮ local1.info synchronet: evnt BINKOUT START lock_flow: /opt/sbbs/fido/outbound.00a/00010001. │
│Jun 03 13:31:45 ⋮ local1.info synchronet: evnt BINKOUT "/opt/sbbs/fido/outbound.00a/00010001.bsy" │
```

Retsulting in the correct lock file being returned.

The regex should probably be replaced with:

`file.replace(/\.[^\.]*$/, '.bsy')`

(Note the removal of the question mark.)

---
ï¿­ Synchronet ï¿­ Vertrauen ï¿­ Home of Synchronet ï¿­ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7297

And FWIW, I changed the regex, and the 1st issue disappeared? Was the flow file locked by the original call to lock_file?

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7298

Maybe log the _name_ of the file that was successfully opened (in your "Hello debugging mode" log message) and then we can tell if the flo file is being opened more than once by BinkIt.

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7299

I dont think that is where the problem is - and yes, the call to `new File(file)` was only attempting to open the file once to the best of my knowledge. (I added heaps of logging to find that regex.)

I think the problem started in `add_outbound_files`, specifically in the loop `addrs.forEach` at the call `lock_flow`.

lock_flow received a `.?lo` file as an argument, and (based on what I think the regex was trying to do), should have created a `.bsy` file as a lock file. Except it was locking the `.?lo` file.

Then the call to flo.open('r') was failing, because the file was locked.

Then later the `bsy` file was deleted as part of unlocking (excepted it was the `.?lo` file).

Make sense?

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7300

What I dont understand, is why the event server couldnt open the file, but `jsexec` could.

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7302

Wanting Deuce's input on this one .

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7311

OK, thought I'd share my test:

```js
var files = [
'/opt/sbbs/fido/outbound.00a/00010001.flo', '/opt/sbbs/fido/outbound.00a/00010001.bsy', '/opt/sbbs/fido/outbound.00a/00010001.',
];

files.forEach(function(file) {
var oldregex = file;
var newregex = file;

writeln("FILE:"+file);
writeln("OLDREGEX:"+oldregex.replace(/\.[^\.]*?$/, '.bsy'));
writeln("NEWREGEX:"+newregex.replace(/\.[^\.]*$/, '.bsy'));
writeln("-");
});
```

Result:
```
FILE:/opt/sbbs/fido/outbound.00a/00010001.flo OLDREGEX:/opt/sbbs/fido/outbound.00a/00010001.flo NEWREGEX:/opt/sbbs/fido/outbound.00a/00010001.bsy
-
FILE:/opt/sbbs/fido/outbound.00a/00010001.bsy OLDREGEX:/opt/sbbs/fido/outbound.00a/00010001.bsy NEWREGEX:/opt/sbbs/fido/outbound.00a/00010001.bsy
-
FILE:/opt/sbbs/fido/outbound.00a/00010001. OLDREGEX:/opt/sbbs/fido/outbound.00a/00010001.bsy NEWREGEX:/opt/sbbs/fido/outbound.00a/00010001.bsy
```

Seems that regex ungreedy is not working (at least for me on aarch64).

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7314

Are you building Spidermonkey from the source in the repo, or are you using some 3rd-party build? It looks like regexps are broken on your system.

There should be no difference in behaviour between those two regexps, but there's a _lot_ of regexps that will be subtly broken if using a ? makes them not match at all.

---
ï¿­ Synchronet ï¿­ Vertrauen ï¿­ Home of Synchronet ï¿­ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7315

For what it's worth, here's that same test executed with a supported version of SpiderMonkey:

```
$ jsexec regextest

JSexec v3.21a-Linux master/dd0e146a0 Debug - Execute Synchronet JavaScript Module
Compiled May 28 2025 21:56 with GCC 12.2.0

Loading configuration files from /sbbs/ctrl
JavaScript-C 1.8.5 2011-03-31
JavaScript: Creating runtime: 167772160 bytes

Reading script from /sbbs/exec/regextest.js
/sbbs/exec/regextest.js compiled in 0.00 seconds FILE:/opt/sbbs/fido/outbound.00a/00010001.flo OLDREGEX:/opt/sbbs/fido/outbound.00a/00010001.bsy NEWREGEX:/opt/sbbs/fido/outbound.00a/00010001.bsy
-
FILE:/opt/sbbs/fido/outbound.00a/00010001.bsy OLDREGEX:/opt/sbbs/fido/outbound.00a/00010001.bsy NEWREGEX:/opt/sbbs/fido/outbound.00a/00010001.bsy
-
FILE:/opt/sbbs/fido/outbound.00a/00010001. OLDREGEX:/opt/sbbs/fido/outbound.00a/00010001.bsy NEWREGEX:/opt/sbbs/fido/outbound.00a/00010001.bsy
-
/sbbs/exec/regextest.js executed in 0.00 seconds
```

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7316

I'm building everything (same as I have always done).

The build script is here: https://gitea.dege.au/bbs/sbbs/src/branch/master/docker/Dockerfile#L25, and the build output for this run is here: https://gitea.dege.au/bbs/sbbs/actions/runs/8

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7318

Looks like Darwin-x86 passes that test though, so the issue does seem to be tracking ARM/aarch64 builds.

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7319

To be clear, the ? can be removed from that regex with no problem.

---
ï¿­ Synchronet ï¿­ Vertrauen ï¿­ Home of Synchronet ï¿­ [vert/cvs/bbs].synchro.net

close https://gitlab.synchro.net/main/sbbs/-/issues/936

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

https://gitlab.synchro.net/main/sbbs/-/issues/936#note_7352

Since we have a work-around with the changed regex, I'll close this issue.

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net