On 10/22/17, g00r00 said the following...
What would help me figure out where it is locking up is figuring out
what the user was last doing when they disconnected on that node that
gets "stuck".
Yes, but what I have is a hole in the logs. I've looked at 8 or more logs so far and nothing but a hole where it hung. It was Sept 8 between 12:30pm and 1:17pm when I took down the system for reboot. Even after that I had to fight with it to get it working, it stayed hung. Finally found the tasks and did
the kill -9 and then all the mis and mis2 tasks finally stopped, then I found
I had to kill a mystic task as well. Then restart mystic and it was up
finally. There was no activity in nodes1-4, mis, mis2, Looking at
fidopoll.log now for Sep 08 12:30:00 hmm E486 pattern not found.
Sep 08 13:33:50 Polled 5 nodes
Sep 08 14:09:25 FIDOPOLL Version 1.12 A35
Sep 08 14:09:25 Scanning 21:1/100
...
Sep 08 13:33:50 Polled 5 nodes
Sep 08 14:09:25 FIDOPOLL Version 1.12 A35
Sep 08 14:09:25 Scanning 21:1/100
The above may appear normal, but it's messing a poll between 12:28 and
13:33, there should have been one about 1pm that didn't happen as the system was hung. You can see that after 13:33 the next is 14:09, they happen at 40 minute intervals I think it was set for, but there's the gap. Those are the three lines from the log in order:
Sep 08 12:28:26 Polled 5 nodes
Sep 08 13:33:41 FIDOPOLL Version 1.12 A35
Sep 08 13:33:41 Scanning 21:1/145.2
Showing the gap in time of more than an hour instead of 40 minutes or so. That's what I've been seeing, just a lack of data for that time.
mis log shows:
Sep 08 11:07:05 MIS received SIGTERM; shutting down
Sep 08 13:17:28 MIS received SIGTERM; shutting down
mis2 log shows only hours so I don't know then 09.08 was in it. It goes from:
+ 23:57:07 TELNET 1-Closed terminal process
+ 23:57:08 TELNET 3-Closed terminal process
+ 00:00:00 TELNET 2-Closed terminal process
+ 00:06:01 TELNET Blocked connection: 51.15.91.167
+ 00:07:07 TELNET Connect on slot 1/8
+ 00:07:07 TELNET 1-Addr: 45.119.208.34
+ 00:07:07 TELNET 1-Host: Unknown
so unknown dates I could try to track back, but I suspect a gap like all the other logs. Ah, looked only have about 2 days (so the last two 10/23-10/24)
of log there. Out of luck on that one. Mutil has the gap:
+ Sep 08 12:29:37 Results: Linked 0 msgs in 70.72s
+ Sep 08 12:29:37 Shutdown Normal (0)
----------------- MUTIL v1.12 A35 Fri, Sep 08 2017 (loglevel 3)
+ Sep 08 13:33:50 Startup using import.ini
- Sep 08 13:33:50 SKIP Import_FIDONET.NA
node5 looks a little better:
------------------- Node 5 (Mystic v1.12 A35)
2017.09.08 12:38:44 Connect from 177.238.98.192 (177.238.98.192.cable.dyn.cableonline.com.mx)
------------------- Node 5 (Mystic v1.12 A35)
2017.09.08 13:11:32 Connect from 177.64.117.211 (b14075d3.virtua.com.br) Narrows the time frame better than the rest so far 12:38-13:11 so that node
did something (logged a connection) before I took it down at 13:17.
Node6:
2017.09.08 12:31:11 Connect from 123.145.31.217 (Unknown)
------------------- Node 6 (Mystic v1.12 A35)
2017.09.11 07:13:27 Connect from 179.232.241.2 (b3e8f102.virtua.com.br)
Node7 not in the logs till:
------------------- Node 7 (Mystic v1.12 A35)
2017.09.12 12:34:53 Connect from 81.215.206.231 (81.215.206.231.dynamic.ttnet.com.tr)
Node8 starts with:
------------------- Node 8 (Mystic v1.12 A35)
2017.09.13 03:27:33 Connect from 144.178.139.203 (static.masmovil.com) binkp.log shows normal operations at 12:45 and 13:20.
Sep 08 12:45:55 1 Session complete (0 sent, 0 rcvd, 0 skip)
Sep 08 13:20:03 0 Connection from United States
Events shows the gap:
Sep 08 12:28:26 Command line: ./mutil import.ini
Sep 08 12:29:37 Process result 0
Sep 08 13:33:41 Executing "Poll echomail"
Sep 08 13:33:41 Command line: ./fidopoll forced
Sep 08 13:33:50 Process result 0
server_ftp.log
Sep 08 11:37:40 1 S:220 Mystic FTP server ready
Sep 08 11:37:50 1 C:QUIT Data:
Sep 08 11:37:50 1 S:221 Goodbye
Sep 08 16:07:52 0 Connection from Austria
Sep 08 16:07:52 0 Connect: 80.110.13.205 (mail.beaufort.at)
Sep 08 16:07:52 1 S:220 Mystic FTP server ready
Sep 08 16:07:52 1 C:USER Data: anonymous
Sep 08 16:07:52 1 C:PASS
Sep 08 16:07:52 1 S:530 No account
A bigger gap.
server_nntp.log
Sep 10 02:39:02 0 Connection from Germany
Sep 10 02:39:02 0 Connect: 138.201.169.234 (static.234.169.201.138.clients.your-server.de)
Sep 10 02:39:02 1 S:200 Mystic BBS NNTP server ready
Sep 10 02:39:02 1 C:^C^@^@+&à^@^@^@^@^@Cookie: mstshash=hello
Sep 10 02:39:02 1 S:500 Unknown command
Sep 11 14:21:25 0 Connection from Germany
Sep 11 14:21:25 0 Connect: 138.201.169.234 (static.234.169.201.138.clients.your-server.de)
Sep 11 14:21:25 1 S:200 Mystic BBS NNTP server ready
Sep 11 14:21:25 1 C:^C^@^@+&à^@^@^@^@^@Cookie: mstshash=hello
Sep 11 14:21:25 1 S:500 Unknown command
Sep 12 10:01:37 Shutting down
(then back up again and such)
server_pop3.log
Sep 07 22:41:18 0 Opening socket on 0.0.0.0:110
Sep 08 04:23:36 Shutting down
Sep 08 04:17:27 0 Opening socket on 0.0.0.0:110
Sep 08 09:13:10 Shutting down
Sep 08 09:13:15 0 Opening socket on 0.0.0.0:110
Sep 09 08:07:07 Shutting down
Doesn't seem to show an issue.
server_smtp.log the same as pop3 of course (save port 25)
server_telnet.log
Sep 08 12:59:53 0 Connection from India
Sep 08 12:59:53 0 Connect: 122.162.97.209 (abts-north-dynamic-209.97.162.122.airtelbroadband.in)
Sep 08 13:11:19 0 Connection from Brazil
Sep 08 13:11:19 0 Connect: 177.64.117.211 (b14075d3.virtua.com.br)
Sep 08 13:11:32 0 Connection from Brazil
Sep 08 13:11:32 0 Connect: 177.64.117.211 (b14075d3.virtua.com.br)
Sep 08 13:11:59 0 Connection from Brazil
Sep 08 13:11:59 0 Connect: 177.64.117.211 (b14075d3.virtua.com.br)
Sep 08 13:12:11 0 Connection from Brazil
Sep 08 13:12:11 0 Auto banning IP 177.64.117.211
Gap 12:59-13:11
That's all the logs. Gaps and lack of data in that hang.
--- Mystic BBS v1.12 A35 (Linux/32)
* Origin: BCW Livingroom (21:1/145.5)