1. Forum
  2. FidoNet
  3. MYSTIC

  • qwkpoll issues

    From Lance Vavricka@1:106/987 to g00r00 on Monday, November 23, 2020 14:54:41
    I'm having a problem getting a QWK packet probably 98% of the time. There were reports of others having this issue as well but they upgraded to A46 which claims to have resolved their problem, I don't know if they ever upgraded to A47 like I have, this was posted on fsxNet. Below are from logs and other output, it is also at https://pastebin.com/B3mkEELv if that is easier to read.

    [Mystic]
    unable to open data connection, doesn't get the qwk packet:

    Nov 23 11:02:02 QWKPOLL Startup (v1.12 A47 Linux/64 Compiled 2020/10/23 21:23:46)
    Nov 23 11:02:02 Exchanging Mail for DOVE-Net
    Nov 23 11:02:02 Exported @athel.rep -> 0 msgs
    Nov 23 11:02:02 Connecting via FTP to athel.synchro.net
    Nov 23 11:02:03 R:220-Athelstan BBS (athelstan.org)
    Nov 23 11:02:03 Connected
    Nov 23 11:02:03 Local IP is 138.124.183.99
    Nov 23 11:02:03 S:USER DESTINY
    Nov 23 11:02:03 R:331 User name okay, need password.
    Nov 23 11:02:03 S:PASS <not shown>
    Nov 23 11:02:03 R:230-DESTINY logged in.
    Nov 23 11:02:03 S:TYPE I
    Nov 23 11:02:03 R:200 All files sent in BINARY mode.
    Nov 23 11:02:03 S:MODE S
    Nov 23 11:02:03 R:200 STREAM mode.
    Nov 23 11:02:03 Logged in as DESTINY
    Nov 23 11:02:03 Downloading QWK packet
    Nov 23 11:02:03 S:PASV
    Nov 23 11:02:03 R:227 Entering Passive Mode (107,161,31,121,4,0)
    Nov 23 11:02:03 S:RETR athel.qwk
    Nov 23 11:02:13 Unable to open data connection

    It does work sometimes, here's the last time it did and what the qwkpoll.log looks like:

    Nov 23 00:31:20 QWKPOLL Startup (v1.12 A47 Linux/64 Compiled 2020/10/23 21:23:4>
    Nov 23 00:31:20 Exchanging Mail for DOVE-Net
    Nov 23 00:31:20 Exported @athel.rep -> 0 msgs
    Nov 23 00:31:20 Connecting via FTP to athel.synchro.net
    Nov 23 00:31:21 R:220-Athelstan BBS (athelstan.org)
    Nov 23 00:31:21 Connected
    Nov 23 00:31:21 Local IP is 138.124.183.99
    Nov 23 00:31:21 S:USER DESTINY
    Nov 23 00:31:21 R:331 User name okay, need password.
    Nov 23 00:31:21 S:PASS <not shown>
    Nov 23 00:31:21 R:230-DESTINY logged in.
    Nov 23 00:31:21 S:TYPE I
    Nov 23 00:31:21 R:200 All files sent in BINARY mode.
    Nov 23 00:31:21 S:MODE S
    Nov 23 00:31:21 R:200 STREAM mode.
    Nov 23 00:31:21 Logged in as DESTINY
    Nov 23 00:31:21 Downloading QWK packet
    Nov 23 00:31:21 S:PASV
    Nov 23 00:31:21 R:227 Entering Passive Mode (107,161,31,121,4,0)
    Nov 23 00:31:21 S:RETR athel.qwk
    Nov 23 00:31:29 R:150 Opening BINARY mode data connection for file transfer. Nov 23 00:31:29 R:226 Download complete (100554 cps).
    Nov 23 00:31:29 OK: athel.qwk (50,277 bytes)
    Nov 23 00:31:29 Importing QWK packet:
    Nov 23 00:31:29 Imported 158 messages (0 failed)

    Mystic Event-
    Active : Yes
    Event Type : Interval
    Exec Hour : 2
    Exec Min : 0
    Shell : ./qwkpoll all
    Sun-Sat : Yes


    [Synchronet] - QWK HUB
    Nov 23 11:02:02 nemesis sbbs: 11/23 11:02:02 ftp 0075 CTRL connection accepted from: 138.124.183.99 port 40520
    Nov 23 11:02:03 nemesis sbbs: 11/23 11:02:03 ftp 0075 Hostname: nyx.zirak.org [138.124.183.99]
    Nov 23 11:02:03 nemesis sbbs: 11/23 11:02:03 ftp 0075 <DESTINY> logged in (7 today, 383 total)
    Nov 23 11:02:03 nemesis sbbs: 11/23 11:02:03 ftp 0075 <DESTINY> creating QWK packet...
    Nov 23 11:02:13 nemesis sbbs: 11/23 11:02:13 ftp 0075 <DESTINY> downloading QWK packet (22171 bytes) in passive mode
    Nov 23 11:02:13 nemesis sbbs: 11/23 11:02:13 ftp 0075 <DESTINY> DATA Transfer successful: 22171 bytes sent in 0 seconds (44342 cps)
    Nov 23 11:02:13 nemesis sbbs: 11/23 11:02:13 ftp 0075 <DESTINY> logged off
    Nov 23 11:02:13 nemesis sbbs: 11/23 11:02:13 ftp 0075 CTRL thread terminated (0 clients and 1 threads remain, 111 served)

    I tried from the same host, using my test user account and this way worked but letting the mystic even run, or even running ./qwkpoll all ends up with the Unable to make data connection, leading me to believe this to be a Mystic problem. From the Mystic bbs, right above to my test user below, both appear successful to Synchronet.

    Nov 23 14:11:21 nemesis sbbs: 11/23 14:11:21 ftp 0075 CTRL connection accepted from: 138.124.183.99 port 40544
    Nov 23 14:11:21 nemesis sbbs: 11/23 14:11:21 ftp 0075 Hostname: nyx.zirak.org [138.124.183.99]
    Nov 23 14:11:28 nemesis sbbs: 11/23 14:11:28 ftp 0075 <baumellex> logged in (2 today, 27 total)
    Nov 23 14:12:16 nemesis sbbs: 11/23 14:12:16 ftp 0075 <baumellex> creating QWK packet...
    Nov 23 14:12:46 nemesis sbbs: 11/23 14:12:46 ftp 0075 <baumellex> downloading QWK packet (4742385 bytes) in passive mode
    Nov 23 14:12:46 nemesis sbbs: 11/23 14:12:46 ftp 0075 <baumellex> DATA Transfer successful: 4742385 bytes sent in 0 seconds (9484770 cps)
    Nov 23 14:12:54 nemesis sbbs: 11/23 14:12:54 ftp 0075 <baumellex> logged off Nov 23 14:12:54 nemesis sbbs: 11/23 14:12:54 ftp 0075 CTRL thread terminated (0 clients and 1 threads remain, 161 served)

    here's from running ftp on the mystic server side:

    passive
    Passive mode on.
    get athel.qwk
    local: athel.qwk remote: athel.qwk
    227 Entering Passive Mode (107,161,31,121,4,0)
    150 Opening BINARY mode data connection for file transfer.
    226 Download complete (9484770 cps).
    4742385 bytes received in 0.87 secs (5.2010 MB/s)
    quit
    221 Goodbye. Closing control connection.
    mystic@nyx:/mystic/logs$ ls -alh athel.qwk
    -rw-rw-r-- 1 mystic mystic 4.6M Nov 23 14:12 athel.qwk

    If there's anything else needed, let me know.
    --- SBBSecho 3.11-Linux
    * Origin: Athelstan - athelstan.org (1:106/987)
  • From g00r00@1:129/215 to Lance Vavricka on Monday, November 23, 2020 16:53:25
    I'm having a problem getting a QWK packet probably 98% of the time.
    There were reports of others having this issue as well but they upgraded to A46 which claims to have resolved their problem, I don't know if they ever upgraded to A47 like I have, this was posted on fsxNet. Below are from logs and other output, it is also at https://pastebin.com/B3mkEELv
    if that is easier to read.

    What is happening is that when Synchronet takes a while to generate the QWK packet the FTP data connection times out while waiting. If you notice in the Synchronet log it takes Synchronet 30 seconds to generate the QWK packet, and in that time the connection will be lost.

    I have tried to update this once before and I did some more work again on it today to increase it to 60 seconds.

    I'll continue to fine tune this but in the meantime if you upgrade to the very latest version (I am compiling it right now so if you download A47 after reading this) the version of QWKPOLL in this build should be a little more understanding in terms of long waits. If you try it please let me know how it works out for you.

    Thank you for the logs particularly representing both sides of the transfer, that was very helpful!

    --- Mystic BBS v1.12 A47 2020/11/23 (Windows/64)
    * Origin: Sector 7 | Mystic WHQ (1:129/215)
  • From Lance Vavricka@1:106/987 to g00r00 on Monday, November 23, 2020 21:23:12
    Re: Re: qwkpoll issues
    By: g00r00 to Lance Vavricka on Mon Nov 23 2020 04:53 pm

    I have tried to update this once before and I did some more work again on it today to increase it to 60 seconds.

    I'll continue to fine tune this but in the meantime if you upgrade to the very latest version (I am compiling it right now so if you download A47 after reading this) the version of QWKPOLL in this build should be a little more understanding in terms of long waits. If you try it please let me know how it works out for you.

    I've updated and the system has since run two qwkpoll events successfully, grabbing the packet and importing.

    Thank you for the logs particularly representing both sides of the transfer, that was very helpful!

    No problem, thanks for the updated A47.
    --- SBBSecho 3.11-Linux
    * Origin: Athelstan - athelstan.org (1:106/987)