[Samba] db_ctdb_fetch_locked: folder lock contention of over 4 million ms (over an hour)

[Martin Schwenke]

On Fri, 8 Oct 2021 10:27:09 -0700, Isaac Stone <isaac.stone at som.com>
wrote:

> Had the same problem again yesterday, only different.
> 
> - same problem in that there was a single folder no one could access.
> 
> - different in that the errors logged were different
> 
> Instead of db_ctdb_fetch_locked errors in the smbd logs, we only had high
> hopcount errors in the ctdbd logs, and only on two of the nodes
> 
> hopcout was also incredibly high and numerous, logging upwords of 60 times
> a second with hopcounts in excess of 500 thousand.
> 
> The errors were all for the exact same key.
> 
> On node 2:
> 
>  High hopcount 430199 dbid:locking.tdb key:0x5930e2c3 reqid=003ef9ef pnn:3
> src:0 lmaster:4 header->dmaster:2 dst:4
> 
> On node 3:
> 
>  High hopcount 350598 dbid:locking.tdb key:0x5930e2c3 reqid=0e34f704 pnn:4
> src:4 lmaster:4 header->dmaster:3 dst:3
> 
> We fixed the error same as last time - bring down all nodes, wipe the
> /volatile/ directory, and bring the cluster back up.

That's bad.  That indicates that something is getting corrupted
somewhere.  Is there any indication that you're running out of disk
space or memory?

Quite a few years ago there were some races in vacuuming (garbage
collection) where this could happen but they were fixed.  Last time we
saw this sort of thing we audited the code and couldn't find a
(relevant) bug.   For the situation we were looking at I'm quite sure
that we tracked it down to running out of something (disk?  memory?)
and being unable to recover.  If this is happening repeatedly there
should be a common clue in the logs, around the time it starts.

> Questions:
> 
> Is there a way to correlate the key in the "high hopcount" logs to a
> specific file lock? Something like `net tdb locking`?

The key in the high hopcount logs is a hash of the key, so it is one
way.  We really should print the hex key.  If you can guess the key
then you can generate the hash (using
lib/tdb/common/hash.c:tdb_jenkins_hash()) and confirm.

> Is there a way to diagnose and fix these problems without bringing the
> whole cluster down and wiping all locks everywhere? It is effective but
> also causes systemwide service interruptions.

With slightly improved logging that might be possible.  However, there
is a catch-22.  If you shut down all of the nodes then you disconnect
the clients and you don't risk filesystem data corruption.  If you
figure out the key, and figure out how to remove it from the databases
on all nodes (undocumented "ctdb tstore" with empty data *might* do what
you want - I'd have to read code to confirm, but need to sleep instead)
then you'll be alive but you risk filesystem data corruption.  The
simplified reasoning here is that you may have a client that thinks it
has a lock on a file or directory (and is modifying it), you'll
effectively release the lock by deleting the record, and then other
clients will also get access (and also modify it).

> I noticed the `setdbsticky` option in the man page. It says it is
> experimental, but also indicates it may solve this problem. Is there any
> more information on this option? I am hesitant to recommend experimental
> settings for prod.

Hop counts that high indicate some sort of corruption.  It seems very
unlikely that this is just a performance problem.

> I am leaning towards changing fileid:algorithm to fsname_nodirs as a
> solution to this recurring problem, but I want to understand the problem
> better before making that change. Any advice is greatly appreciated.

I'm trying to get an overview of CTDB performance issues here:

  https://wiki.samba.org/index.php/CTDB_Performance

Nobody has fully explained the implications of that option there.  You
have to understand that it breaks lock coherency (i.e. effectively no
locking on directories) and the implications of that.

Sorry I can't be more help right now... busy day, need sleep...

peace & happiness,
martin