Skip to content

binkd unexpectedly closes the connection #42

@wvvelzen

Description

@wvvelzen

First a little background: Since a couple of months my Fido system generates a file with the same name 3 or 4 times a day, and hatches this file to my point system. So when my point doesn't poll for a couple of days, there are multiple lines in the .flo file for the same file. Since this is the case it seems to trigger a possible bug in binkp connections.

Here's the log where it's happening on the system side (I'm leaving out some lines which I think are not relevant):

+ 24 Mar 08:22:24 [2751] incoming session with ***
- 24 Mar 08:22:24 [2751] SYS Wilfreds Point System

- 24 Mar 08:22:24 [2751] TIME Mon, 24 Mar 2025 08:22:29 +0100
- 24 Mar 08:22:24 [2751] VER binkd/1.1a-113/Win64 binkp/1.1

- 24 Mar 08:22:24 [2751] OPT NDA EXTCMD CRYPT GZ BZ2
+ 24 Mar 08:22:24 [2751] Remote supports asymmetric ND mode
+ 24 Mar 08:22:24 [2751] Remote supports EXTCMD mode
+ 24 Mar 08:22:24 [2751] Remote requests CRYPT mode
+ 24 Mar 08:22:24 [2751] Remote supports GZ mode
+ 24 Mar 08:22:24 [2751] Remote supports BZ2 mode
- 24 Mar 08:22:24 [2751] TRF 0 0
+ 24 Mar 08:22:24 [2751] Remote has 0b of mail and 0b of files for us
+ 24 Mar 08:22:24 [2751] pwd protected session (MD5)
- 24 Mar 08:22:24 [2751] session in CRYPT mode

+ 24 Mar 08:22:25 [2751] sending /home/fido/fileareas/zadaily/zadaily.081 as zadaily.081 (118379)
  24 Mar 08:22:25 [2751] bzip2 mode is on for zadaily.081
+ 24 Mar 08:22:25 [2751] remote already has zadaily.081
+ 24 Mar 08:22:25 [2751] sending /home/fido/tic/nb20u8l8.tic as nb20u8l8.tic (436)
+ 24 Mar 08:22:25 [2751] sent: /home/fido/tic/nb1z3an8.tic (436, 436.00 CPS, 2:280/464.112@fidonet)
  24 Mar 08:22:25 [2751] Compressed 100788 bytes to 29470 for nb20u8l8.tic, ratio 29.2%

Here's the first odd thing: It reports compressing a file, that was much smaller: 436 bytes, then it reports, that wouldn't get compressed because of it's size anyway. And there isn't a "bzip mode is on" line for it anyway.

+ 24 Mar 08:22:25 [2751] sending /home/fido/fileareas/zadaily/zadaily.082 as zadaily.082 (118394)
  24 Mar 08:22:25 [2751] bzip2 mode is on for zadaily.082

  24 Mar 08:22:26 [2751] Compressed 118394 bytes to 34714 for zadaily.082, ratio 29.3%
+ 24 Mar 08:22:26 [2751] sending /home/fido/tic/nb20xey8.tic as nb20xey8.tic (436)

+ 24 Mar 08:22:26 [2751] sending /home/fido/tic/nb20xkt9.tic as nb20xkt9.tic (902)
+ 24 Mar 08:22:26 [2751] sending /home/fido/fileareas/zadaily/zadaily.082 as zadaily.082 (118394)
  24 Mar 08:22:26 [2751] bzip2 mode is on for zadaily.082

+ 24 Mar 08:22:26 [2751] sent: /home/fido/fileareas/zadaily/zadaily.081 (118379, 118379.00 CPS, 2:280/464.112@fidonet)
? 24 Mar 08:22:26 [2751] recv: Connection reset by peer
+ 24 Mar 08:22:26 [2751] done (from 2:280/464.112@fidonet, failed, S/R: 34/0 (989324/0 bytes))
  24 Mar 08:22:26 [2751] Purge compress buffers
  24 Mar 08:22:26 [2751] session closed, quitting...

And there is the unexpected close of the connection.

And some lines from the log of the same session from the point system:

  24 Mar 08:22:29 [8724] BEGIN standalone, binkd/1.1a-113/Win64 -pP 2:280/464 \com\binkd\binkd.cfg
...
- 24 Mar 08:22:32 [10912] receiving zadaily.081 (118379 byte(s), off 0)
  24 Mar 08:22:32 [10912] bzip2 mode is on for zadaily.081
  24 Mar 08:22:32 [10912] File zadaily.081 compressed size 34725 bytes, compress ratio 29.3%
+ 24 Mar 08:22:32 [10912] zadaily.081 -> c:\com\inbound\zadaily.081
+ 24 Mar 08:22:32 [10912] rcvd: zadaily.081 (118379, 118379.00 CPS, 2:280/464@fidonet)
+ 24 Mar 08:22:32 [10912] already have zadaily.081 (c:\com\inbound\zadaily.081, 118379 byte(s))
- 24 Mar 08:22:32 [10912] receiving nb20u8l8.tic (436 byte(s), off 0)
? 24 Mar 08:22:32 [10912] rcvd 3660 extra bytes!
+ 24 Mar 08:22:32 [10912] done (to 2:280/464@fidonet, failed, S/R: 0/34 (0/989324 bytes))
  24 Mar 08:22:32 [10912] restoring poll with `d' flavour
? 24 Mar 08:22:32 [10912] receiving of nb20u8l8.tic interrupted at 4096
  24 Mar 08:22:32 [10912] session closed, quitting...

So this reproduces. I can probably create, if needed, a data set (upload files, and .flo file) that reproduces it every time...

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions