• A36_w32 debug

    From Skuz@21:1/105 to g00r00 on Friday, November 10, 2017 17:21:32
    I've disabled the irex NR mode and MD-5 mode.. log read as follows.

    ---------- Mystic v1.12 A36 2017/11/10 Fri, Nov 10 2017 (loglevel 3)
    + 16:47:08 MANAGER Starting event system
    + 16:47:08 MANAGER Starting 4 server(s)
    + 16:47:08 TELNET Listening on IPV4 port 23 using interface "0.0.0.0"
    + 16:47:08 SSH Listening on IPV4 port 2222 using interface "0.0.0.0"
    + 16:47:08 RLOGIN Listening on IPV4 port 513 using interface "0.0.0.0"
    + 16:47:08 EVENT Starting 7 event(s)
    + 16:47:08 BINKP Listening on IPV4 port 24554 using interface "0.0.0.0"
    + 16:49:25 BINKP > Connect on slot 1/6
    + 16:49:25 BINKP 1-Address 192.168.1.1
    + 16:49:25 BINKP 1-HostName Unknown
    + 16:49:25 BINKP 1-Begin receive command frame: NUL (Size=6)
    + 16:49:25 BINKP 1-Recv Frame: (6) NUL OPT MB
    + 16:49:25 BINKP 1-Auth State:SendChallenge Have:True Need:False
    + 16:49:25 BINKP 1-Received challenge ()
    + 16:49:25 BINKP 1-Sent Frame (32814): NUL OPT CRAM-MD5-59dd5ebf8d646dca02ea7cb8fdc113a8
    + 16:49:25 BINKP 1-Begin receive command frame: NUL (Size=18)
    + 16:49:25 BINKP 1-Recv Frame: (18) NUL SYS Cosmo's Castle
    + 16:49:25 BINKP 1-Auth State:SendWelcome Have:True Need:False
    + 16:49:25 BINKP 1-System Cosmo's Castle
    + 16:49:25 BINKP 1-Sent Frame (32778): NUL SYS flupH
    + 16:49:25 BINKP 1-Sent Frame (32785): NUL ZYZ Leslie Given
    + 16:49:25 BINKP 1-Sent Frame (32797): NUL VER Mystic/1.12A36 binkp/1.0
    + 16:49:25 BINKP 1-Sent Frame (32920): ADR 1:275/91@fidonet
    46:1/102@agoranet 21:1/105@fsxnet 911:1304/0@zeronet 44:100/2@dorenet 9:91/1@survnet 9:91/0@survnet 77:1/172@scinet 411:411/8@combatnt
    + 16:49:25 BINKP 1-Begin receive command frame: NUL (Size=18)
    + 16:49:25 BINKP 1-Recv Frame: (18) NUL ZYZ Martin Nickell
    + 16:49:25 BINKP 1-Auth State:WaitAddress Have:True Need:False
    + 16:49:25 BINKP 1-SysOp Martin Nickell
    + 16:49:25 BINKP 1-Begin receive command frame: NUL (Size=15)
    + 16:49:25 BINKP 1-Recv Frame: (15) NUL LOC Elkview, Wv
    + 16:49:25 BINKP 1-Location Elkview, Wv
    + 16:49:25 BINKP 1-Begin receive command frame: NUL (Size=21)
    + 16:49:25 BINKP 1-Recv Frame: (21) NUL NDL CM,XA,IBN,ITN,TFT
    + 16:49:25 BINKP 1-Info NDL CM,XA,IBN,ITN,TFT
    + 16:49:25 BINKP 1-Begin receive command frame: NUL (Size=30)
    + 16:49:25 BINKP 1-Recv Frame: (30) NUL TIME 2017/11/10 16:49:18 -5:00
    + 16:49:25 BINKP 1-Info TIME 2017/11/10 16:49:18 -5:00
    + 16:49:25 BINKP 1-Begin receive command frame: NUL (Size=39)
    + 16:49:25 BINKP 1-Recv Frame: (39) NUL VER Internet Rex 2.29 Win32 (binkp/1.1)
    + 16:49:25 BINKP 1-Mailer Internet Rex 2.29 Win32 (binkp/1.1)
    + 16:49:25 BINKP 1-Begin receive command frame: ADR (Size=132)
    + 16:49:25 BINKP 1-Recv Frame: (132) ADR 1:275/91.5@fidonet
    9:91/1.5@survnet 21:1/105.5@fsxnet 44:100/2.5@dorenet 46:1/102.5@agoranet 77:1/172.5@scinet 911:1304/1.0@zeronet
    + 16:49:25 BINKP 1-Auth State:WaitPW Have:False Need:True
    + 16:49:25 BINKP 1-Begin receive command frame: PWD (Size=41)
    + 16:49:25 BINKP 1-Recv Frame: Password
    + 16:49:25 BINKP 1-Auth State:WaitPW Have:True Need:False
    + 16:49:25 BINKP 1-Looking for matching address in Echomail nodes:
    + 16:49:25 BINKP 1-Authenticating 21:1/105.5@fsxnet by CRAM-MD5
    + 16:49:25 BINKP 1-Sent Frame (32775): OK secure
    + 16:49:25 BINKP 1-Queued 2 files for 1:275/91.5@fidonet
    + 16:49:25 BINKP 1-Queued 1 files for 9:91/1.5@survnet
    + 16:49:25 BINKP 1-Queued 0 files for 21:1/105.5@fsxnet
    + 16:49:25 BINKP 1-Queued 0 files for 44:100/2.5@dorenet
    + 16:49:25 BINKP 1-Queued 2 files for 46:1/102.5@agoranet
    + 16:49:25 BINKP 1-Queued 0 files for 911:1304/1@zeronet
    + 16:49:25 BINKP 1-Begin receive command frame: EOB (Size=0)
    + 16:49:25 BINKP 1-Recv Frame: (0) EOB
    + 16:49:25 BINKP 1-State R:WaitFile T:NextFile Have:True Need:False
    + 16:49:25 BINKP 1-Sending: 00000005.th1 (9,681 bytes)
    + 16:49:25 BINKP 1-Sent Frame (32799): FILE 00000005.th1 9681 1510270084 0
    + 16:49:25 BINKP 1-State R:Done T:SendData Have:False Need:True
    + 16:49:25 BINKP 1-Sent Data Frame (9681): 9,681
    + 16:49:25 BINKP 1-State R:Done T:GetEOF Have:False Need:True
    + 16:49:25 BINKP 1-Begin receive command frame: GOT (Size=28)
    + 16:49:25 BINKP 1-Recv Frame: (28) GOT 00000005.th1 9681 1510270084
    + 16:49:25 BINKP 1-State R:Done T:GetEOF Have:True Need:False
    + 16:49:25 BINKP 1-State R:Done T:NextFile Have:False Need:True
    + 16:49:25 BINKP 1-Sending: 00000005.fr0 (36,163 bytes)
    + 16:49:25 BINKP 1-Sent Frame (32800): FILE 00000005.fr0 36163 1510327664 0
    + 16:49:25 BINKP 1-Connection lost
    + 16:49:25 BINKP 1-Session complete (1 sent, 0 rcvd, 0 skip)
    + 16:49:53 BINKP > Connect on slot 1/6
    + 16:49:53 BINKP 1-Address 192.168.1.1
    + 16:49:53 BINKP 1-HostName Unknown
    + 16:49:53 BINKP 1-Begin receive command frame: NUL (Size=6)
    + 16:49:53 BINKP 1-Recv Frame: (6) NUL OPT MB
    + 16:49:53 BINKP 1-Auth State:SendChallenge Have:True Need:False
    + 16:49:53 BINKP 1-Received challenge ()
    + 16:49:53 BINKP 1-Sent Frame (32814): NUL OPT CRAM-MD5-88aac22156eb3e98f434a2ef2aa41013
    + 16:49:53 BINKP 1-Begin receive command frame: NUL (Size=18)
    + 16:49:53 BINKP 1-Recv Frame: (18) NUL SYS Cosmo's Castle
    + 16:49:53 BINKP 1-Auth State:SendWelcome Have:True Need:False
    + 16:49:53 BINKP 1-System Cosmo's Castle
    + 16:49:53 BINKP 1-Sent Frame (32778): NUL SYS flupH
    + 16:49:53 BINKP 1-Sent Frame (32785): NUL ZYZ Leslie Given
    + 16:49:53 BINKP 1-Sent Frame (32797): NUL VER Mystic/1.12A36 binkp/1.0
    + 16:49:53 BINKP 1-Sent Frame (32920): ADR 1:275/91@fidonet
    46:1/102@agoranet 21:1/105@fsxnet 911:1304/0@zeronet 44:100/2@dorenet 9:91/1@survnet 9:91/0@survnet 77:1/172@scinet 411:411/8@combatnt
    + 16:49:53 BINKP 1-Begin receive command frame: NUL (Size=18)
    + 16:49:53 BINKP 1-Recv Frame: (18) NUL ZYZ Martin Nickell
    + 16:49:53 BINKP 1-Auth State:WaitAddress Have:True Need:False
    + 16:49:53 BINKP 1-SysOp Martin Nickell
    + 16:49:53 BINKP 1-Begin receive command frame: NUL (Size=15)
    + 16:49:53 BINKP 1-Recv Frame: (15) NUL LOC Elkview, Wv
    + 16:49:53 BINKP 1-Location Elkview, Wv
    + 16:49:53 BINKP 1-Begin receive command frame: NUL (Size=21)
    + 16:49:53 BINKP 1-Recv Frame: (21) NUL NDL CM,XA,IBN,ITN,TFT
    + 16:49:53 BINKP 1-Info NDL CM,XA,IBN,ITN,TFT
    + 16:49:53 BINKP 1-Begin receive command frame: NUL (Size=30)
    + 16:49:53 BINKP 1-Recv Frame: (30) NUL TIME 2017/11/10 16:49:46 -5:00
    + 16:49:53 BINKP 1-Info TIME 2017/11/10 16:49:46 -5:00
    + 16:49:53 BINKP 1-Begin receive command frame: NUL (Size=39)
    + 16:49:53 BINKP 1-Recv Frame: (39) NUL VER Internet Rex 2.29 Win32 (binkp/1.1)
    + 16:49:53 BINKP 1-Mailer Internet Rex 2.29 Win32 (binkp/1.1)
    + 16:49:53 BINKP 1-Begin receive command frame: ADR (Size=132)
    + 16:49:53 BINKP 1-Recv Frame: (132) ADR 1:275/91.5@fidonet
    9:91/1.5@survnet 21:1/105.5@fsxnet 44:100/2.5@dorenet 46:1/102.5@agoranet 77:1/172.5@scinet 911:1304/1.0@zeronet
    + 16:49:53 BINKP 1-Auth State:WaitPW Have:False Need:True
    + 16:49:53 BINKP 1-Begin receive command frame: PWD (Size=41)
    + 16:49:53 BINKP 1-Recv Frame: Password
    + 16:49:53 BINKP 1-Auth State:WaitPW Have:True Need:False
    + 16:49:53 BINKP 1-Looking for matching address in Echomail nodes:
    + 16:49:53 BINKP 1-Authenticating 21:1/105.5@fsxnet by CRAM-MD5
    + 16:49:53 BINKP 1-Sent Frame (32775): OK secure
    + 16:49:53 BINKP 1-Queued 1 files for 1:275/91.5@fidonet
    + 16:49:53 BINKP 1-Queued 1 files for 9:91/1.5@survnet
    + 16:49:53 BINKP 1-Queued 0 files for 21:1/105.5@fsxnet
    + 16:49:53 BINKP 1-Queued 0 files for 44:100/2.5@dorenet
    + 16:49:53 BINKP 1-Queued 2 files for 46:1/102.5@agoranet
    + 16:49:53 BINKP 1-Queued 0 files for 911:1304/1@zeronet
    + 16:49:53 BINKP 1-Begin receive command frame: EOB (Size=0)
    + 16:49:53 BINKP 1-Recv Frame: (0) EOB
    + 16:49:53 BINKP 1-State R:WaitFile T:NextFile Have:True Need:False
    + 16:49:53 BINKP 1-Sending: 00000005.fr0 (36,163 bytes)
    + 16:49:53 BINKP 1-Sent Frame (32800): FILE 00000005.fr0 36163 1510327664 0
    + 16:49:53 BINKP 1-State R:Done T:SendData Have:False Need:True
    + 16:49:53 BINKP 1-Sent Data Frame (16384): 16,384
    + 16:49:53 BINKP 1-Sent Data Frame (16384): 16,384
    + 16:49:53 BINKP 1-Sent Data Frame (3395): 3,395
    + 16:49:53 BINKP 1-Begin receive command frame: GOT (Size=29)
    + 16:49:53 BINKP 1-Recv Frame: (29) GOT 00000005.fr0 36163 1510327664
    + 16:49:53 BINKP 1-State R:Done T:GetEOF Have:True Need:False
    + 16:49:53 BINKP 1-State R:Done T:NextFile Have:False Need:True
    + 16:49:53 BINKP 1-Sending: 00000005.fr0 (1,823 bytes)
    + 16:49:53 BINKP 1-Sent Frame (32799): FILE 00000005.fr0 1823 1510312242 0
    + 16:49:53 BINKP 1-Connection lost
    + 16:49:53 BINKP 1-Session complete (1 sent, 0 rcvd, 0 skip)

    Outcome looks the same, only sends 1 file per connection. Also when I
    disabled the CRAM-MD5 like Zazz said he uses. I get the same outcome.
    I don't have any file boxes setup for any of these point systems that I have running because I'm only doing mail without any file distribution.

    ---------- Internet Rex 2.29 (Win95/NT 32-bit), Fri Nov 10 16:49:17 2017.
    + 16:49:17 Command line: -fs b 1:275/91
    - 16:49:17 Performing inbound mail scan.
    * 16:49:17 Received 0 files (0K)
    % 16:49:17 System: BETWEEN.BAT
    % 16:49:17 Starting rescan...
    % 16:49:17 Done rescan
    % 16:49:17 Starting thread 0 (8, 0, 406670)
    % 16:49:17 Connecting to BinkP site fluph.darktech.org...
    % 16:49:22 BinkP: OPT CRAM-MD5-59dd5ebf8d646dca02ea7cb8fdc113a8
    % 16:49:22 BinkP: SYS flupH
    % 16:49:22 BinkP: ZYZ Leslie Given
    % 16:49:22 BinkP: VER Mystic/1.12A36 binkp/1.0
    % 16:49:22 BinkP: 1:275/91@fidonet 46:1/102@agoranet 21:1/105@fsxnet 911:1304/0@zeronet 44:100/2@dorenet 9:91/1@survnet 9:91/0@survnet 77:1/172@scinet 411:411/8@combatnt
    * 16:49:22 Received from 1:275/91: 00000005.th1, (9681 bytes)
    ? 16:49:22 BinkP error: remote dropped connection.
    % 16:49:22 Task 0 is done.
    * 16:49:22 Received 1 files (9K)
    * 16:49:22 Sent 0 files (0K)
    % 16:49:22 System: BETWEEN.BAT
    % 16:49:23 Starting rescan...
    % 16:49:23 Done rescan
    * 16:49:23 Sent 0 files (0K)
    % 16:49:23 Internet Rex shutdown successfully.
    ---------- Internet Rex 2.29 (Win95/NT 32-bit), Fri Nov 10 16:49:46 2017.
    + 16:49:45 Command line: -fs b 1:275/91
    - 16:49:45 Performing inbound mail scan.
    * 16:49:45 Received 0 files (0K)
    % 16:49:45 System: BETWEEN.BAT
    % 16:49:45 Starting rescan...
    % 16:49:45 Done rescan
    % 16:49:45 Starting thread 0 (8, 0, 406670)
    % 16:49:45 Connecting to BinkP site fluph.darktech.org...
    % 16:49:50 BinkP: OPT CRAM-MD5-88aac22156eb3e98f434a2ef2aa41013
    % 16:49:50 BinkP: SYS flupH
    % 16:49:50 BinkP: ZYZ Leslie Given
    % 16:49:50 BinkP: VER Mystic/1.12A36 binkp/1.0
    % 16:49:50 BinkP: 1:275/91@fidonet 46:1/102@agoranet 21:1/105@fsxnet 911:1304/0@zeronet 44:100/2@dorenet 9:91/1@survnet 9:91/0@survnet 77:1/172@scinet 411:411/8@combatnt
    * 16:49:50 Received from 1:275/91: 00000005.fr0, (36163 bytes)
    ? 16:49:50 BinkP error: remote dropped connection.
    % 16:49:50 Task 0 is done.
    * 16:49:51 Received 1 files (35K)
    * 16:49:51 Sent 0 files (0K)
    % 16:49:51 System: BETWEEN.BAT
    % 16:49:51 Starting rescan...
    % 16:49:51 Done rescan
    * 16:49:51 Sent 0 files (0K)
    % 16:49:51 Internet Rex shutdown successfully.

    --- Mystic BBS v1.12 A36 2017/11/09 (Windows/32)
    * Origin: flupH | fluph.darktech.org (21:1/105)
  • From g00r00@21:1/108 to Skuz on Friday, November 10, 2017 19:44:51
    + 16:49:53 BINKP 1-State R:WaitFile T:NextFile Have:True Need:False
    + 16:49:53 BINKP 1-Sending: 00000005.fr0 (36,163 bytes)
    + 16:49:53 BINKP 1-Sent Frame (32800): FILE 00000005.fr0 36163
    1510327664 0 + 16:49:53 BINKP 1-State R:Done T:SendData Have:False Need:True + 16:49:53 BINKP 1-Sent Data Frame (16384): 16,384
    + 16:49:53 BINKP 1-Sent Data Frame (16384): 16,384
    + 16:49:53 BINKP 1-Sent Data Frame (3395): 3,395
    + 16:49:53 BINKP 1-Begin receive command frame: GOT (Size=29)
    + 16:49:53 BINKP 1-Recv Frame: (29) GOT 00000005.fr0 36163 1510327664
    + 16:49:53 BINKP 1-State R:Done T:GetEOF Have:True Need:False
    + 16:49:53 BINKP 1-State R:Done T:NextFile Have:False Need:True
    + 16:49:53 BINKP 1-Sending: 00000005.fr0 (1,823 bytes)
    + 16:49:53 BINKP 1-Sent Frame (32799): FILE 00000005.fr0 1823
    1510312242 0 + 16:49:53 BINKP 1-Connection lost
    + 16:49:53 BINKP 1-Session complete (1 sent, 0 rcvd, 0 skip)

    Outcome looks the same, only sends 1 file per connection. Also when I

    Unfortunately the logging isn't proving to be very helpful here. Everything Mystic is doing in BINKP is "by the book" and correct. IREX just stops responding and it has horrible logging so its difficult to see what it's doing.

    The one thing I do notice that is strange to me is that the two filenames are the same (both are 00000005.fr0). I wonder if IREX gets confused by that (also why/how are there two files of the same name?)

    + 16:49:53 BINKP 1-Sending: 00000005.fr0 (36,163 bytes)
    + 16:49:53 BINKP 1-Sending: 00000005.fr0 (1,823 bytes)

    How is this possible ^^

    --- Mystic BBS v1.12 A36 2017/11/10 (Windows/32)
    * Origin: Sector 7 [Mystic BBS WHQ] (21:1/108)
  • From Skuz@21:1/105 to g00r00 on Friday, November 10, 2017 23:30:37
    On 11/10/17, g00r00 said the following...

    confused by that (also why/how are there two files of the same name?)

    + 16:49:53 BINKP 1-Sending: 00000005.fr0 (36,163 bytes)
    + 16:49:53 BINKP 1-Sending: 00000005.fr0 (1,823 bytes)

    How is this possible ^^

    Good question, since mystic created the files.. could it be from a friday one week early that wasn't ever sent out? This is very puzzling.

    --- Mystic BBS v1.12 A36 2017/11/09 (Windows/32)
    * Origin: flupH | fluph.darktech.org (21:1/105)
  • From g00r00@21:1/108 to Skuz on Saturday, November 11, 2017 00:14:22
    + 16:49:53 BINKP 1-Sending: 00000005.fr0 (36,163 bytes)
    + 16:49:53 BINKP 1-Sending: 00000005.fr0 (1,823 bytes)

    Good question, since mystic created the files.. could it be from a
    friday one week early that wasn't ever sent out? This is very puzzling.

    Well its not possible for two files of the exact name to be in the same directory, so one would have had to be in a filebox or you are sending multiple networks at once. Either that or something else very wrong is going on.

    I'll get it figured out.

    --- Mystic BBS v1.12 A36 2017/11/10 (Windows/32)
    * Origin: Sector 7 [Mystic BBS WHQ] (21:1/108)