Howdy,

I'm getting errors reading 1 sub, and its a sub that is only getting mailing list mail.

chksmb and fixsmb both error with the same error when trying to read it:

FIXSMB v2.10-Linux (rev 1.46) SMBLIB 2.61 - Rebuild Synchronet Message Base

Opening ml_luvtalk
smb_open returned -202: smb_locksmbhdr timeout locking message base

In lieu of blowing it away, is there anything else I can do? Would you want any debugging to see if there is something that needs to be fixed?

This is a file list:
root@alterant:/opt/sbbs/data/subs# ls -al ml_luvtalk*
-rw------- 1 root root 13952 Feb 1 15:01 ml_luvtalk.hash
-rw-r--r-- 1 root root 21 Aug 13 11:49 ml_luvtalk.ini
-rw------- 1 root root 0 Aug 13 11:50 ml_luvtalk.list.sub
-rw-r--r-- 1 root root 4 Feb 2 16:32 ml_luvtalk.listgate.ptr
-rw------- 1 root root 2802 Feb 1 15:01 ml_luvtalk.sda
-rw-r--r-- 1 root root 358656 Feb 1 15:01 ml_luvtalk.sdt
-rw------- 1 root root 2257 Feb 1 15:01 ml_luvtalk.sha
-rw-r--r-- 1 root root 577824 Feb 1 15:01 ml_luvtalk.shd
-rw-r--r-- 1 root root 2140 Feb 1 15:01 ml_luvtalk.sid
...deon


... Get too many irons in your fire and you'll put it out.

---
þ Synchronet þ Alterant | an SBBS in Docker on Pi!

El 3/2/20 a las 22:37, Alter Ego escribi¢:

Howdy,

I'm getting errors reading 1 sub, and its a sub that is only getting mailing list mail.

chksmb and fixsmb both error with the same error when trying to read it:

FIXSMB v2.10-Linux (rev 1.46) SMBLIB 2.61 - Rebuild Synchronet Message Base

Opening ml_luvtalk
smb_open returned -202: smb_locksmbhdr timeout locking message base

In lieu of blowing it away, is there anything else I can do? Would you want any debugging to see if there is something that needs to be fixed?

This is a file list:
root@alterant:/opt/sbbs/data/subs# ls -al ml_luvtalk*
-rw------- 1 root root 13952 Feb 1 15:01 ml_luvtalk.hash
-rw-r--r-- 1 root root 21 Aug 13 11:49 ml_luvtalk.ini
-rw------- 1 root root 0 Aug 13 11:50 ml_luvtalk.list.sub
-rw-r--r-- 1 root root 4 Feb 2 16:32 ml_luvtalk.listgate.ptr
-rw------- 1 root root 2802 Feb 1 15:01 ml_luvtalk.sda
-rw-r--r-- 1 root root 358656 Feb 1 15:01 ml_luvtalk.sdt
-rw------- 1 root root 2257 Feb 1 15:01 ml_luvtalk.sha
-rw-r--r-- 1 root root 577824 Feb 1 15:01 ml_luvtalk.shd
-rw-r--r-- 1 root root 2140 Feb 1 15:01 ml_luvtalk.sid
....deon

file permissions? are you run sbbs as root or another use?

---
þ Synchronet þ Dock Sud BBS TLD 24 HS - bbs.docksud.com.ar

Re: Re: smb_locksmbhdr timeout locking message base
By: Ragnarok to Alter Ego on Mon Feb 03 2020 11:32 pm

file permissions? are you run sbbs as root or another use?

Not a permission issue - SBBS runs as root.
...deon


... A city is a large community where people are lonesome together

---
þ Synchronet þ Alterant | an SBBS in Docker on Pi!

Re: smb_locksmbhdr timeout locking message base
By: Alter Ego to Digital Man on Tue Feb 04 2020 12:37 pm

Howdy,

I'm getting errors reading 1 sub, and its a sub that is only getting mailing list mail.

chksmb and fixsmb both error with the same error when trying to read it:

FIXSMB v2.10-Linux (rev 1.46) SMBLIB 2.61 - Rebuild Synchronet Message Base

Opening ml_luvtalk
smb_open returned -202: smb_locksmbhdr timeout locking message base

In lieu of blowing it away, is there anything else I can do?

I would close all processes that could have the *.shd file open and locked. You could use lsof or other tools to find out exactly which process that is or just close any/all BBS-related processes.

If that doesn't work, I would just reboot. The type of lock that smb_locksmbhdr is referring to is managed by the file system drivers, so it should disappear when the process that had the lock is closed. If not, then the file system drivers are themselves acting up and rebooting should clear that up.

Would you want
any debugging to see if there is something that needs to be fixed?

Unless you discover a Synchronet process running in an infinite loop (say, jsexec maybe?), I can't think of any Synchronet cause. Even if a program crashes whil having a message base header locked, that lock should get released automatically by the file system when the file is closed.

This is a file list:
root@alterant:/opt/sbbs/data/subs# ls -al ml_luvtalk*
-rw------- 1 root root 13952 Feb 1 15:01 ml_luvtalk.hash
-rw-r--r-- 1 root root 21 Aug 13 11:49 ml_luvtalk.ini
-rw------- 1 root root 0 Aug 13 11:50 ml_luvtalk.list.sub
-rw-r--r-- 1 root root 4 Feb 2 16:32 ml_luvtalk.listgate.ptr -rw------- 1 root root 2802 Feb 1 15:01 ml_luvtalk.sda
-rw-r--r-- 1 root root 358656 Feb 1 15:01 ml_luvtalk.sdt
-rw------- 1 root root 2257 Feb 1 15:01 ml_luvtalk.sha
-rw-r--r-- 1 root root 577824 Feb 1 15:01 ml_luvtalk.shd
-rw-r--r-- 1 root root 2140 Feb 1 15:01 ml_luvtalk.sid

That all looks fine and normal to me.

digital man

Synchronet/BBS Terminology Definition #13:
CP437 = Code Page 437 (so-called IBM Extended ASCII)
Norco, CA WX: 49.6øF, 15.0% humidity, 2 mph SSW wind, 0.00 inches rain/24hrs

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

Re: smb_locksmbhdr timeout locking message base
By: Digital Man to Alter Ego on Mon Feb 03 2020 08:55 pm

I would close all processes that could have the *.shd file open and locked. You could use lsof or other tools to find out exactly which process that is or just close any/all BBS-related processes.

Hmm, ok.

I ran lsof, and grep "luv" (I have 3 subs that have that in their name) - and it showed many many lines (100's?) - so I did a gree on just luvtalk.shd - and it showed this:

[deon@d-1-2 ~]$ sudo lsof -n |grep luvtalk.shd
sbbs 9643 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/smtp 9643 3889 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/smtp 9643 3948 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/sigH 9643 9698 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/stat 9643 9699 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/term 9643 9701 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/mail 9643 9702 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/serv 9643 9703 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/jsRT 9643 9708 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/pass 9643 22552 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/term 9643 22553 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/term 9643 22554 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/term 9643 22555 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/term 9643 22556 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/send 9643 22851 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/jsSt 9643 22865 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/jsSt 9643 22866 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/jsSt 9643 22867 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/jsBa 9643 22868 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/jsSt 9643 22869 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/jsBa 9643 22870 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/jsSt 9643 22871 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/jsBa 9643 22872 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/jsSt 9643 22873 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/jsBa 9643 22874 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/term 9643 28294 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/term 9643 30743 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/even 9643 30744 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs/even 9643 30745 root 57uW REG 0,42 577824 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd

The 4th one down caught my eye - it looks like SigH (sighandler? sighalt), and perhaps is the start of something not right.

Anyway, I restart of the docker container, now shows NO open files with the "luv" in it - and I'm logged in and did a new scan in that group (and read some new mail in that group).

So I'm leading to think something went astray, I'll report if I see it again... ...deon


... I like a man who grins when he fights.

---
þ Synchronet þ Alterant | an SBBS in Docker on Pi!

Alter Ego wrote to Ragnarok <=-

Re: Re: smb_locksmbhdr timeout locking message base
By: Ragnarok to Alter Ego on Mon Feb 03 2020 11:32 pm

file permissions? are you run sbbs as root or another use?

Not a permission issue - SBBS runs as root.

Ugh. Why?



... Computer Hacker wanted. Must have own axe.
--- MultiMail/Linux v0.52
þ Synchronet þ Palantir BBS * palantirbbs.ddns.net * Pensacola, FL

Re: smb_locksmbhdr timeout locking message base
By: Alter Ego to Digital Man on Tue Feb 04 2020 05:22 pm

Hey DM,

I would close all processes that could have the *.shd file open and
locked. You could use lsof or other tools to find out exactly which
process that is or just close any/all BBS-related processes.

Within 12 hrs of restarting SBBS, I had the same problem again.

Given that its been running for weeks (to months) without a problem, I think something is amiss here.

The message sub in question receives list serv emails - so I'm wondering if a bad email is causing an abend of some sort - resulting in the SMTP server trying again and again and again until file handles are exausted for this sub? (Dunno, just throwing ideas.)

It probably was pretty quiet, but I've seen some activity in the last few days - so I think that is related.

How can I diagnose this?
...deon


... What's the speed of dark?

---
þ Synchronet þ Alterant | an SBBS in Docker on Pi!

Re: smb_locksmbhdr timeout locking message base
By: Alter Ego to Digital Man on Fri Feb 07 2020 11:13 am

Re: smb_locksmbhdr timeout locking message base
By: Alter Ego to Digital Man on Tue Feb 04 2020 05:22 pm

Hey DM,

I would close all processes that could have the *.shd file open and
locked. You could use lsof or other tools to find out exactly which
process that is or just close any/all BBS-related processes.

Within 12 hrs of restarting SBBS, I had the same problem again.

Given that its been running for weeks (to months) without a problem, I think something is amiss here.

The message sub in question receives list serv emails - so I'm wondering if a bad email is causing an abend of some sort - resulting in the SMTP server trying again and again and again until file handles are exausted for this sub? (Dunno, just throwing ideas.)

It probably was pretty quiet, but I've seen some activity in the last few days - so I think that is related.

How can I diagnose this?

Process of elimination is one path. Closely examining all log output (including debug-level messages) would be another.

digital man

Synchronet "Real Fact" #68:
Robert D. Bouman, the author of SyncEdit, died in the mid to late 1990's. Norco, CA WX: 62.5øF, 31.0% humidity, 9 mph ESE wind, 0.00 inches rain/24hrs

---
þ Synchronet þ Vertrauen þ Home of Synchronet þ [vert/cvs/bbs].synchro.net

Re: smb_locksmbhdr timeout locking message base
By: Digital Man to Alter Ego on Thu Feb 06 2020 04:24 pm

Process of elimination is one path. Closely examining all log output (including debug-level messages) would be another.

OK, I'll go down that route...

While the logging WAS informational, here is what I saw:

* Listgate ran at 16:32 successfully,

2/2 16:32:33 evnt Running timed event: LISTGATE
2/2 16:32:33 evnt LISTGATE Synchronet Mailing List Gateway 1.4 session started 2/2 16:32:33 evnt LISTGATE Scanning 2 message bases...
2/2 16:32:33 evnt LISTGATE sub: ML_LUVMAIN
2/2 16:32:33 evnt LISTGATE sub: ML_LUVTALK
2/2 16:32:33 evnt LISTGATE Synchronet Mailing List Gateway 1.4 session complete (0 exported)
2/2 16:32:33 evnt Timed event: LISTGATE returned 0

* An SMTP mail can in at 16:43 and was processed successfully
2/2 16:43:48 mail 0054 SMTP Connection accepted on port 25 from: 10.1.3.11 port 60690
2/2 16:43:48 mail 0054 SMTP Hostname: ldap.leenooks.vpn [10.1.3.11]
2/2 16:44:03 mail 0054 SMTPS Receiving mail message from: <luv-talk-bounces@luv.asn.au> to luv-talk@bbs...
2/2 16:44:06 mail 0054 SMTPS End of message (body: 7430 lines, 573502 bytes, header: 104 lines, 5499 bytes)
2/2 16:44:06 mail 0054 SMTPS Executing external mail processor: MailAuth

* Listgate ran again at 17:02 and failed on the ML_LUVTALK sub
2/2 17:02:33 evnt Running timed event: LISTGATE
2/2 17:02:33 evnt LISTGATE Synchronet Mailing List Gateway 1.4 session started 2/2 17:02:33 evnt LISTGATE Scanning 2 message bases...
2/2 17:03:03 evnt LISTGATE !ERROR smb_locksmbhdr timeout locking message base opening msgbase: ML_LUVTALK
2/2 17:03:03 evnt LISTGATE Synchronet Mailing List Gateway 1.4 session complete (0 exported)

Leading up to this time point, the following messages were received by each sub from when SBBS was started on the 2nd Jan:
1 1/2 luv-main@bbs...
2 1/6 luv-main@bbs...
1 1/6 luv-talk@bbs...
1 1/10 luv-main@bbs...
3 1/11 luv-main@bbs...
2 1/12 luv-main@bbs...
2 1/13 luv-main@bbs...
8 1/15 luv-main@bbs...
2 1/16 luv-main@bbs...
4 1/17 luv-main@bbs...
9 1/18 luv-main@bbs...
6 1/19 luv-main@bbs...
3 1/20 luv-main@bbs...
1 1/21 luv-talk@bbs...
1 1/24 luv-main@bbs...
1 1/27 luv-main@bbs...
2 1/28 luv-main@bbs...
10 1/28 luv-talk@bbs...
2 1/29 luv-talk@bbs...
2 1/30 luv-main@bbs...
4 1/30 luv-talk@bbs...
2 1/31 luv-main@bbs...
2 1/31 luv-talk@bbs...
2 2/1 luv-talk@bbs...
7 2/2 luv-talk@bbs...

And subsequently...

24 2/3 luv-talk@bbs...
6 2/4 luv-main@bbs...
44 2/4 luv-talk@bbs...
24 2/5 luv-talk@bbs...
23 2/6 luv-talk@bbs...
23 2/7 luv-talk@bbs...

Which will explain why it fell over 12 hrs later after restarting..

I've set up a debug log, that will count the open files every minute and Ive set SBBS to debugging - I'll see if it captures anything more...
...deon


... Diogenes is still searching.

---
þ Synchronet þ Alterant | an SBBS in Docker on Pi!

Re: smb_locksmbhdr timeout locking message base
By: Digital Man to Alter Ego on Thu Feb 06 2020 04:24 pm

DM,

So I restarted SBBS (14:04), and had a debug log running that basically does lsof -n |grep LUV, logging to a file every minute.

Here is that result:
Sat Feb 8 14:16:59 AEDT 2020
1
Sat Feb 8 14:18:01 AEDT 2020
1
Sat Feb 8 14:19:03 AEDT 2020
1
Sat Feb 8 14:20:05 AEDT 2020
1
Sat Feb 8 14:21:07 AEDT 2020
1
Sat Feb 8 14:22:09 AEDT 2020
113
Sat Feb 8 14:23:11 AEDT 2020
113
Sat Feb 8 14:24:14 AEDT 2020
113
Sat Feb 8 14:25:16 AEDT 2020
113
Sat Feb 8 14:26:18 AEDT 2020
113
Sat Feb 8 14:27:21 AEDT 2020
121

Between 14:21:07 and 14:22:09, one message came in - it appears to be 7400 lines (yup, usual...)
2/8 14:21:40 mail 0049 SMTPS Receiving mail message from: <luv-talk-bounces@luv.asn.au> to luv-talk@bbs...
...
2/8 14:21:42 mail 0049 SMTPS End of message (body: 7430 lines, 573502 bytes, header: 104 lines, 5499 bytes)
2/8 14:21:42 mail 0049 SMTPS Executing external mail processor: MailAuth
2/8 14:21:42 mail 0049 SMTPS JavaScript: Creating runtime: 8388608 bytes
2/8 14:21:42 mail 0049 SMTPS JavaScript: Initializing context (stack: 16384 bytes)
2/8 14:21:42 mail 0049 SMTPS Executing: mailauth.js

An lsof -n |grep luv now shows only sub ml_luvtalk with open file handles. IE: these 4 lines repeated for multiple unique process names and pids:
[root@d-1-2 sbbs]# lsof -n |grep luv
sbbs 24603 root 52uw REG 0,42 595232 4750361 /opt/sbbs/data/subs/ml_luvtalk.shd
sbbs 24603 root 53u REG 0,42 361728 4750362 /opt/sbbs/data/subs/ml_luvtalk.sdt
sbbs 24603 root 54u REG 0,42 2200 4750363 /opt/sbbs/data/subs/ml_luvtalk.sid
sbbs 24603 root 55uW REG 0,42 14336 4750366 /opt/sbbs/data/subs/ml_luvtalk.hash

Why are those files remaining open?
...deon


... Spring---an experience in immoratality.


---
þ Synchronet þ Alterant | an SBBS in Docker on Pi!

Re: smb_locksmbhdr timeout locking message base
By: Alter Ego to Digital Man on Sat Feb 08 2020 02:37 pm

Between 14:21:07 and 14:22:09, one message came in - it appears to be 7400 lines (yup, usual...)

So it appears that that mail doesnt successfully get delivered, I found it in the queue, and can make it available if it is of interest:

-rw-r----- 1 root 103 566073 Feb 2 16:43 df0125hQSH006392
-rw-r----- 1 root 103 5888 Feb 8 14:41 qf0125hQSH006392

It appers to never be deleted because SMTP is returning a 452 to the upstream SMTP server:

* Previous attempt

Feb 8 13:22:00 d-1-1 sendmail[6674]: 0125hQSH006392: to=<luv-talk@bbs...>, delay=5+20:38:21, xdelay=00:00:46, mailer=relay, pri=13074150, relay=d-1-2.ipv4.leenooks.vpn. [10.1.3.12], dsn=4.0.0, stat=Deferred: 452 ERROR -202 (smb_locksmbhdr timeout locking message base) posting message

* Current attempt

Feb 8 14:21:40 d-1-1 sendmail[6675]: STARTTLS=client, relay=d-1-2.ipv4.leenooks.vpn., version=TLSv1.2, verify=FAIL, cipher=DHE-RSA-AES128-SHA256, bits=128/128
Feb
...
Feb 8 14:41:33 d-1-1 sendmail[6675]: 0125hQSH006392: to=<luv-talk@bbs...>, delay=5+21:57:54, xdelay=00:20:19, mailer=relay, pri=13164150, relay=d-1-2.ipv4.leenooks.vpn. [10.1.3.12], dsn=4.0.0, stat=Deferred

Took 21 mins to bomb out?
...deon


... If you can't learn to do it well, learn to enjoy doing it badly.

---
þ Synchronet þ Alterant | an SBBS in Docker on Pi!

Re: smb_locksmbhdr timeout locking message base
By: Alter Ego to Digital Man on Sat Feb 08 2020 14:37:20

[...] does lsof -n |grep LUV, logging to a file every minute.

FWIW: you really should put a space after your pipe signs so we can read what you wrote without triggering pipe code color translations or dropping characters when the pipe code processor eats them as an invalid pipe code ;)

requoted and edited...

[...] does lsof -n | grep LUV, logging to a file every minute.

there... that's easier to read and there's nothing turned green :)


)\/(ark

---
þ Synchronet þ The SouthEast Star Mail HUB - SESTAR

Re: smb_locksmbhdr timeout locking message base
By: Alter Ego to Digital Man on Fri Feb 07 2020 11:13:02

The message sub in question receives list serv emails - so I'm wondering if a bad email is causing an abend of some sort - resulting in the SMTP server trying again and again and again until file handles are exausted for this sub? (Dunno, just throwing ideas.)

Are you running Windows? May need to exclude the directory from AV scanning... not sure if that's your issue or not.

--
Michael J. Ryan
+o roughneckbbs.com
bbs@tracker1.dev

---
þ Synchronet þ Roughneck BBS - coming back 2/2/20

Re: smb_locksmbhdr timeout locking message base
By: Tracker1 to Alter Ego on Sun Feb 09 2020 04:08 am

Are you running Windows? May need to exclude the directory from AV scanning... not sure if that's your issue or not.

Thanks for the idea - but no, not windows, and not file processing related.

This is inbound SMTP directly into a sub...
...deon


... What happens if you're scared half to death twice?

---
þ Synchronet þ Alterant | an SBBS in Docker on Pi!