• MIS2 Logging

    From Avon@21:1/101 to g00r00 on Saturday, September 02, 2017 15:31:09

    ---------- Mystic v1.12 A35 Sat, Sep 02 2017 (loglevel 3)
    + 14:40:40 MANAGER Starting 1 server(s)
    + 14:40:40 BINKP Listening on IPV6 port 24556 using interface "::"
    + 15:18:13 BINKP Connect on slot 1/10
    + 15:18:13 BINKP 1-Addr: 2001:0DF1:CC00::0E23:3CDA
    + 15:18:13 BINKP 1-Host: Unknown
    + 15:18:13 BINKP 1-GDS Size:25 Actual:25
    + 15:18:13 BINKP 1-Recv: NUL SYS Dragon's Claw FTN HUB
    + 15:18:13 BINKP 1-Authorization State: 0 HH:1 NH:0
    + 15:18:13 BINKP 1-GDS Size:25 Actual:25
    + 15:18:13 BINKP 1-System: Dragon's Claw FTN HUB
    + 15:18:13 BINKP 1-Sent: NUL OPT CRAM-MD5-edbc4bc8d04deda8b5bf7e1778ce42df
    + 15:18:13 BINKP 1-GDS Size:17 Actual:17
    + 15:18:13 BINKP 1-Recv: NUL ZYZ Stephen Walsh
    + 15:18:13 BINKP 1-Authorization State: 1 HH:1 NH:0
    + 15:18:13 BINKP 1-GDS Size:17 Actual:17
    + 15:18:13 BINKP 1-SysOp: Stephen Walsh
    + 15:18:13 BINKP 1-Sent: NUL SYS
    + 15:18:13 BINKP 1-Sent: NUL ZYZ
    + 15:18:13 BINKP 1-Sent: NUL VER Mystic/1.12A35 binkp/1.0
    + 15:18:13 BINKP 1-Sent: ADR
    + 15:18:13 BINKP 1-GDS Size:24 Actual:24
    + 15:18:13 BINKP 1-Recv: NUL LOC Melbourne, Australia
    + 15:18:13 BINKP 1-Authorization State: 3 HH:1 NH:0
    + 15:18:13 BINKP 1-GDS Size:24 Actual:24
    + 15:18:13 BINKP 1-GDS Size:14 Actual:14
    + 15:18:13 BINKP 1-Recv: NUL NDL ICM,XX,IBN
    + 15:18:13 BINKP 1-GDS Size:14 Actual:14
    + 15:18:13 BINKP 1-GDS Size:36 Actual:36
    + 15:18:13 BINKP 1-Recv: NUL TIME Sat, 02 Sep 2017 13:18:21 +1000
    + 15:18:13 BINKP 1-GDS Size:36 Actual:36
    + 15:18:13 BINKP 1-GDS Size:46 Actual:46
    + 15:18:13 BINKP 1-Recv: NUL VER mbcico/1.0.6.15/GNU/Linux-x86_64 binkp/1.1
    + 15:18:13 BINKP 1-GDS Size:46 Actual:46
    + 15:18:13 BINKP 1-GDS Size:18 Actual:18
    + 15:18:13 BINKP 1-Recv: NUL PHN ftn.vk3heg.net
    + 15:18:13 BINKP 1-GDS Size:18 Actual:18
    + 15:18:13 BINKP 1-GDS Size:21 Actual:21
    + 15:18:13 BINKP 1-Recv: NUL OPT EXTCMD GZ PLZ CRC
    + 15:18:13 BINKP 1-GDS Size:21 Actual:21
    + 15:18:13 BINKP 1-Received challenge (edbc4bc8d04deda8b5bf7e1778ce42df)
    + 15:18:13 BINKP 1-GDS Size:105 Actual:105
    + 15:18:13 BINKP 1-Recv: ADR 21:1/195@fsxnet 3:633/280@fidonet 3:633/0@fidonet 39:901/280@amiganet 39:901/0@amiganet 46:3/101@agoranet
    + 15:18:13 BINKP 1-GDS Size:105 Actual:105
    + 15:18:13 BINKP 1-Authorization State: 4 HH:0 NH:1
    + 15:18:14 BINKP 1-GDS Size:14 Actual:14
    + 15:18:14 BINKP 1-Recv: BSY All aka's busy
    + 15:18:14 BINKP 1-Authorization State: 4 HH:1 NH:0
    + 15:18:14 BINKP 1-Authorization State: 4 HH:0 NH:1
    + 15:18:16 BINKP 1-Invalid data frame
    + 15:18:16 BINKP 1-GDS Size:10467 Actual:105
    + 15:18:16 BINKP 1-Recv: BSY All aka's busyt 3:633/280@fidonet 3:633/0@fidonet 39:901/280@amiganet 39:901/0@amiganet 46:3/101@agoranet
    + 15:18:16 BINKP 1-Remote disconnect

    Via IPv6, AFAIK nothing has changed here, only my use of the a newer MIS2
    using v2 of A35

    Best, Paul

    --- Mystic BBS v1.12 A35 (Windows/32)
    * Origin: Agency BBS | telnet://agency.bbs.geek.nz (21:1/101)
  • From g00r00@21:1/108 to Avon on Saturday, September 02, 2017 11:04:57
    + 15:18:14 BINKP 1-Recv: BSY All aka's busy

    It looks like the system is just telling you its busy, which is a message
    that comes from their side.

    In either case, the latest has significant BINKP changes so that is the one
    to test.

    --- Mystic BBS v1.12 A35 (Windows/32)
    * Origin: Sector 7 [Mystic BBS WHQ] (21:1/108)
  • From Avon@21:1/101 to g00r00 on Sunday, September 03, 2017 20:25:06
    On 09/02/17, g00r00 pondered and said...

    In either case, the latest has significant BINKP changes so that is the one to test.

    ..and it seems to have fixed the issue, IPv6 nodes are talking to 1/100 again
    - thanks :)

    [snip]

    + 20:18:10 BINKP Connect on slot 1/10
    + 20:18:10 BINKP 1-Addr: 2001:0DF1:CC00::0E23:3CDA
    + 20:18:10 BINKP 1-Host: Unknown
    + 20:18:10 BINKP 1-GDS Size:25 Actual:25
    + 20:18:10 BINKP 1-Recv: NUL SYS Dragon's Claw FTN HUB
    + 20:18:10 BINKP 1-Authorization State: 0 HH:1 NH:0
    + 20:18:10 BINKP 1-GDS Size:25 Actual:25
    + 20:18:10 BINKP 1-System: Dragon's Claw FTN HUB
    + 20:18:10 BINKP 1-Sent: NUL OPT CRAM-MD5-cf65dfd5f552998d80dc076f8dca3ef9
    + 20:18:10 BINKP 1-GDS Size:17 Actual:17
    + 20:18:10 BINKP 1-Recv: NUL ZYZ Stephen Walsh
    + 20:18:10 BINKP 1-Authorization State: 1 HH:1 NH:0
    + 20:18:10 BINKP 1-GDS Size:17 Actual:17
    + 20:18:10 BINKP 1-SysOp: Stephen Walsh
    + 20:18:10 BINKP 1-Sent: NUL SYS fsxHUB [fsxNet WHQ]
    + 20:18:10 BINKP 1-Sent: NUL ZYZ Paul Hayton
    + 20:18:10 BINKP 1-Sent: NUL VER Mystic/1.12A35 binkp/1.0
    + 20:18:10 BINKP 1-Sent: ADR 21:1/100@fsxnet 21:1/3@fsxnet 21:1/2@fsxnet 21:1/0@fsxnet 21:0/0@fsxnet
    + 20:18:10 BINKP 1-GDS Size:24 Actual:24
    + 20:18:10 BINKP 1-Recv: NUL LOC Melbourne, Australia
    + 20:18:10 BINKP 1-Authorization State: 3 HH:1 NH:0
    + 20:18:10 BINKP 1-GDS Size:24 Actual:24
    + 20:18:10 BINKP 1-GDS Size:14 Actual:14
    + 20:18:10 BINKP 1-Recv: NUL NDL ICM,XX,IBN
    + 20:18:10 BINKP 1-GDS Size:14 Actual:14
    + 20:18:10 BINKP 1-GDS Size:36 Actual:36
    + 20:18:10 BINKP 1-Recv: NUL TIME Sun, 03 Sep 2017 18:18:20 +1000
    + 20:18:10 BINKP 1-GDS Size:36 Actual:36
    + 20:18:10 BINKP 1-GDS Size:46 Actual:46
    + 20:18:10 BINKP 1-Recv: NUL VER mbcico/1.0.6.15/GNU/Linux-x86_64 binkp/1.1
    + 20:18:10 BINKP 1-GDS Size:46 Actual:46
    + 20:18:10 BINKP 1-GDS Size:18 Actual:18
    + 20:18:10 BINKP 1-Recv: NUL PHN ftn.vk3heg.net
    + 20:18:10 BINKP 1-GDS Size:18 Actual:18
    + 20:18:10 BINKP 1-GDS Size:21 Actual:21
    + 20:18:10 BINKP 1-Recv: NUL OPT EXTCMD GZ PLZ CRC
    + 20:18:10 BINKP 1-GDS Size:21 Actual:21
    + 20:18:10 BINKP 1-Received challenge (cf65dfd5f552998d80dc076f8dca3ef9)
    + 20:18:10 BINKP 1-GDS Size:105 Actual:105
    + 20:18:10 BINKP 1-Recv: ADR 21:1/195@fsxnet 3:633/280@fidonet 3:633/0@fidonet 39:901/280@amiganet 39:901/0@amiganet 46:3/101@agoranet
    + 20:18:10 BINKP 1-GDS Size:105 Actual:105
    + 20:18:10 BINKP 1-Authorization State: 4 HH:0 NH:1
    + 20:18:12 BINKP 1-GDS Size:41 Actual:41
    + 20:18:12 BINKP 1-Recv: PWD CRAM-MD5-6ee1179f460c2085bbb2226e15f45029
    + 20:18:12 BINKP 1-Authorization State: 4 HH:1 NH:0
    + 20:18:12 BINKP 1-Received PWD frame
    + 20:18:12 BINKP 1-GDS Size:41 Actual:41
    + 20:18:12 BINKP 1-Remote: MD5=1 AKA=21:1/195@fsxnet 3:633/280@fidonet 3:633/0@fidonet 39:901/280@amiganet 39:901/0@amiganet 46:3/101@agoranet
    + 20:18:12 BINKP 1-Looking for matching AKA in EchoNodes
    + 20:18:12 BINKP 1-Match=FALSE EchoNode:21:1/112@fsxnet Remote:21:1/195@fsxnet
    + 20:18:12 BINKP 1-Match=FALSE EchoNode:21:1/112@fsxnet Remote:3:633/280@fidonet
    + 20:18:12 BINKP 1-Match=FALSE EchoNode:21:1/112@fsxnet Remote:3:633/0@fidonet
    + 20:18:12 BINKP 1-Match=FALSE EchoNode:21:1/112@fsxnet Remote:39:901/280@amiganet
    + 20:18:12 BINKP 1-Match=FALSE EchoNode:21:1/112@fsxnet Remote:39:901/0@amiganet
    + 20:18:12 BINKP 1-Match=FALSE EchoNode:21:1/112@fsxnet Remote:46:3/101@agoranet
    + 20:18:12 BINKP 1-No match in clients address list for 21:1/112@fsxnet

    [snip]

    removed a big chunk of logging

    [snip]

    + 20:18:12 BINKP 1-Match=FALSE EchoNode:21:1/199@fsxnet Remote:46:3/101@agoranet
    + 20:18:12 BINKP 1-State RxS:1 TxS:1 HH:0 NH:1
    + 20:18:12 BINKP 1-Sending: 02369a62.pkt (3,495 bytes)
    + 20:18:12 BINKP 1-Sent: FILE 02369a62.pkt 3495 1504468130 0
    + 20:18:12 BINKP 1-State RxS:1 TxS:2 HH:0 NH:1
    + 20:18:12 BINKP 1-Sent: Data 3,495
    + 20:18:12 BINKP 1-State RxS:1 TxS:3 HH:0 NH:1
    + 20:18:13 BINKP 1-GDS Size:7 Actual:7
    + 20:18:13 BINKP 1-Recv: NUL TRF 0 0
    + 20:18:13 BINKP 1-GDS Size:0 Actual:0
    + 20:18:13 BINKP 1-Recv: EOB
    + 20:18:13 BINKP 1-State RxS:1 TxS:3 HH:1 NH:0
    + 20:18:13 BINKP 1-State RxS:3 TxS:3 HH:0 NH:1
    + 20:18:14 BINKP 1-GDS Size:28 Actual:28
    + 20:18:14 BINKP 1-Recv: GOT 02369a62.pkt 3495 1504468130
    + 20:18:14 BINKP 1-State RxS:3 TxS:3 HH:1 NH:0
    + 20:18:14 BINKP 1-State RxS:3 TxS:1 HH:0 NH:1
    + 20:18:14 BINKP 1-Sending: 023703be.pkt (2,693 bytes)
    + 20:18:14 BINKP 1-Sent: FILE 023703be.pkt 2693 1504468400 0
    + 20:18:14 BINKP 1-State RxS:3 TxS:2 HH:0 NH:1
    + 20:18:14 BINKP 1-Sent: Data 2,693
    + 20:18:14 BINKP 1-State RxS:3 TxS:3 HH:0 NH:1
    + 20:18:15 BINKP 1-GDS Size:28 Actual:28
    + 20:18:15 BINKP 1-Recv: GOT 023703be.pkt 2693 1504468400
    + 20:18:15 BINKP 1-State RxS:3 TxS:3 HH:1 NH:0
    + 20:18:15 BINKP 1-State RxS:3 TxS:1 HH:0 NH:1
    + 20:18:15 BINKP 1-Sent: EOB
    + 20:18:15 BINKP 1-Session complete (2 sent, 0 rcvd, 0 skip)


    [snip]

    Best, Paul

    --- Mystic BBS v1.12 A35 (Windows/32)
    * Origin: Agency BBS | telnet://agency.bbs.geek.nz (21:1/101)
  • From Avon@21:1/101 to g00r00 on Tuesday, September 05, 2017 22:01:37
    Seems light on date info for the BinkP logging using MIS2 for IPv6 BinkP

    How do I set logging levels etc for MIS2.TXT? I'm picking I can't at the moment.

    Logging looks like

    [snip]

    + 21:26:04 BINKP 1-Match=FALSE EchoNode:21:1/162@fsxnet Remote:24:400/101@sportnet
    + 21:26:04 BINKP 1-Match=FALSE EchoNode:21:1/163@fsxnet Remote:24:400/101@sportnet
    + 21:26:04 BINKP 1-Match=FALSE EchoNode:21:1/164@fsxnet Remote:24:400/101@sportnet

    [snip]

    I have a mis2.1.txt logfile of 1025kb and saw a 0kb mis2.txt file that was written to and jumped to 53kb when I shut down MIS2

    Was trying to track an incoming packet from a suspected IPv6 node tonight but seem unable to find a record of the packet arriving via BinkP logging in
    either MIS server_binkp.txt logs or the mis2.txt logs... that's despite
    knowing when the packet was tossed in by checking the MUTIL logs... weired..
    I can only guess it was something to do with the MIS2 logging and the connection made by the echonode was IPv6 .. not 100% sure on that have
    emailed sysop to confirm.

    Best, Paul

    --- Mystic BBS v1.12 A35 (Windows/32)
    * Origin: Agency BBS | telnet://agency.bbs.geek.nz (21:1/101)
  • From g00r00@21:1/108 to Avon on Tuesday, September 05, 2017 17:24:08
    Logging looks like

    [snip]

    Yes this is intentional. BINKP debug logging is stuck on for these test versions.

    --- Mystic BBS v1.12 A35 (Windows/32)
    * Origin: Sector 7 [Mystic BBS WHQ] (21:1/108)
  • From Avon@21:1/101 to g00r00 on Thursday, September 07, 2017 08:01:09
    On 09/05/17, g00r00 pondered and said...

    Yes this is intentional. BINKP debug logging is stuck on for these test versions.

    Yep understood, all good. I think the caching of what is logged and when to mis2.txt may need some attention.

    --- Mystic BBS v1.12 A35 (Windows/32)
    * Origin: Agency BBS | telnet://agency.bbs.geek.nz (21:1/101)