Created attachment 19236 [details] .corrupt file Environment ----------- Samba/CTDB: 4.24.5 (both smbd and ctdbd, same build on all nodes) OS: AlmaLinux 9.8, kernel 5.14.0-687.36.1.el9_8.x86_64 Hardware: 2x Intel Xeon Gold 5318Y, 192 GiB RAM, ECC, no swap Cluster: 3 CTDB nodes, clustered Samba over CephFS, recovery lock via ctdb_mutex_ceph_rados_helper (RADOS object lock) Config: [database] volatile database directory = /var/lib/ctdb/volatile-12 persistent database directory = /persistent/ctdb/samba-12/persistent state database directory = /persistent/ctdb/samba-12/state The volatile directory is on the node's root filesystem, which is a read-only squashfs with a RAM (tmpfs) overlay, so volatile TDBs never touch a disk or a network filesystem. The persistent/state directories are on a local ext4 on a per-node RBD image. tdb mutexes: default (not set explicitly). Summary ------- On a node that had been running without interruption for 12 days, a volatile TDB developed a corrupt freelist with no preceding event of any kind. The CTDB vacuuming children logged the damage every 10 seconds for 71 seconds, and then ctdbd aborted when a record store failed during dmaster migration. Timeline (UTC, node ceph-villa-1, pnn 0) ---------------------------------------- Sep 09 08:27:39 ctdbd starts, PID 12908 Sep 09 08:27:55 smbd starts, PID 13995 Sep 10 - Sep 21 smbXsrv_open_global.tdb repacked 11 times, each at the freelist limit ("Repacking smbXsrv_open_global.tdb with 10000 freelist entries"), roughly every 12 to 36 hours Sep 21 12:59:42 first tdb_oob, in smbXsrv_tcon_global.tdb.0 Sep 21 13:00:53 ctdbd aborts Sep 22 06:08:54 ctdbd restarted; the 95.database check finds the file corrupt and moves it aside First occurrence and the 10-second repeats (note the changing PIDs: these are the vacuuming children, one per VacuumInterval): Sep 21 12:59:42 ctdbd[2080638]: tdb(/var/lib/ctdb/volatile-12/smbXsrv_tcon_global.tdb.0): tdb_oob len 16414504 beyond eof at 10549277 Sep 21 12:59:42 ctdbd[2080638]: tdb(/var/lib/ctdb/volatile-12/smbXsrv_tcon_global.tdb.0): tdb_free: left offset read failed at 16414500 Sep 21 12:59:42 ctdbd[2080638]: tdb(/var/lib/ctdb/volatile-12/smbXsrv_tcon_global.tdb.0): tdb_oob len 16414508 beyond eof at 10549277 Sep 21 12:59:52 ctdbd[2080798]: (same three lines) Sep 21 13:00:02 ctdbd[2080875]: (same three lines) Sep 21 13:00:12 ctdbd[2081037]: tdb_oob len 12056880 beyond eof at 10549277 tdb_free: left offset read failed at 12056876 tdb_oob len 12056884 beyond eof at 10549277 Sep 21 13:00:22 ctdbd[2081196]: (same) Sep 21 13:00:32 ctdbd[2081271]: (same) Sep 21 13:00:42 ctdbd[2081431]: (same) Sep 21 13:00:52 ctdbd[2081589]: (same) The abort: Sep 21 13:00:53 smbd[2081607]: tdb(.../smbXsrv_tcon_global.tdb.0): tdb_oob len 18568612 beyond eof at 10549277 Sep 21 13:00:53 ctdbd[12908]: tdb_oob len 18568612 beyond eof at 10549277 (x5) Sep 21 13:00:53 ctdbd[12908]: tdb_oob len 12056904 beyond eof at 10549277 Sep 21 13:00:53 ctdbd[12908]: ../../ctdb/server/ctdb_ltdb_server.c:214 db[smbXsrv_tcon_global.tdb]: Failed to store record: -1 - IO Error Sep 21 13:00:53 ctdbd[12908]: ctdb fatal error: ctdb_reply_dmaster store failed Sep 21 13:00:53 ctdbd[12908]: INTERNAL ERROR: Signal 6: Aborted in () () pid 12908 (4.24.5) Backtrace from the core (coredumpctl): #0 __pthread_kill_implementation (libc.so.6) #1 raise #2 abort #3 smb_panic_default.constprop.0 (libgenrand-private-samba.so) #4 smb_panic #5 sig_fault #6 __restore_rt #7 __pthread_kill_implementation #8 raise #9 abort #10 ctdb_fatal.constprop.0.cold (ctdbd) #11 ctdb_become_dmaster (ctdbd) #12 ctdb_reply_dmaster (ctdbd) #13 ctdb_input_pkt (ctdbd) #14 queue_io_handler.lto_priv.0 (ctdbd) #15 tevent_common_invoke_fd_handler ... #21 ctdb_start_daemon (ctdbd) #22 main (ctdbd) All smbd processes then exited with "cluster fatal event: failed to read data from ctdbd", which is expected once ctdbd is gone. State of the corrupt database ----------------------------- On restart, the 95.database event script detected and preserved the file: 95.database: WARNING: database /var/lib/ctdb/volatile-12/smbXsrv_tcon_global.tdb.0 is corrupted. 95.database: Moving to backup /var/lib/ctdb/volatile-12/smbXsrv_tcon_global.tdb.0.20260922.060854.corrupt for later analysis. # tdbtool /var/lib/ctdb/volatile-12/smbXsrv_tcon_global.tdb.0.20260922.060854.corrupt check tdb_oob len 10772380 beyond eof at 10549277 Integrity check for the opened database failed. Two observations about that file: 1. Its size, 10549277 bytes, is not a multiple of 4, let alone of the page size. tdb_expand() rounds the new total to a page boundary, so as far as I can tell no tdb code path can produce that size. This may be the most interesting clue in the report. 2. At least five distinct impossible offsets were reached (16414504, 12056880, 18568612, 12056904, 10772380), so the damage is not a single bad pointer. The failures are all in tdb_free()'s left-coalescing step, reading the 4-byte tailer at offset - sizeof(tdb_off_t), which means the freelist or a record header carries offsets far beyond the file. Second node, same failure shape ------------------------------- Seven hours later, a different node in the same cluster showed the same defect in a different database, without aborting: Sep 21 20:33:17 ceph-gaeste-1 ctdbd: tdb(/var/lib/ctdb/volatile-12/smbXsrv_open_global.tdb.2): tdb_oob len 541213780 beyond eof at 37363712 Sep 21 20:33:17 ceph-gaeste-1 ctdbd: tdb(.../smbXsrv_open_global.tdb.2): tdb_free: left offset read failed at 541213776 Sep 21 20:36:27 ceph-gaeste-1 ctdbd: tdb(.../smbXsrv_open_global.tdb.2): tdb_oob len 541213780 beyond eof at 46706688 Note that this file grew from 37363712 to 46706688 bytes between the two occurrences, so ctdbd kept using it. On this node, the affected database is the one that gets repacked repeatedly. What is ruled out, and on what evidence --------------------------------------- - Storage or I/O fault: the volatile TDBs are in RAM (tmpfs overlay). The "IO Error" string is tdb's TDB_ERR_IO, set by tdb_oob, not an errno from a device. The cluster filesystem was healthy throughout and the persistent databases logged nothing. - Hardware or memory: the kernel log covers the full 12-day boot and contains zero MCE, EDAC, OOM, hung-task or I/O error entries. - A process killed mid-update while holding a chain lock: ctdbd (PID 12908) and smbd (PID 13995) ran unchanged from Sep 09 until the abort. No unit restart, no SIGKILL, no daemon-reload, no configuration change. The last restart of any Samba unit on that node was five days earlier. - A CTDB recovery racing normal operation: no recovery ran on this node between daemon start on Sep 09 and the abort. - tdb_repack: smbXsrv_tcon_global.tdb was never repacked on this node; only smbXsrv_open_global.tdb was. So repack is not required to produce the defect. It remains a candidate on the second node, where the affected DB is the repacked one. Possibly related, possibly noise: from six hours after boot and for the whole 12 days, the same smbd logged, at irregular intervals, tdb(/var/lib/samba/smbprofile.tdb): tdb_rec_read bad magic 0x0 at offset=1 tdb(/var/lib/samba/smbprofile.tdb): tdb_rec_read bad magic 0x0 at offset=146 always one of those two offsets. I understand this class of message on smbprofile.tdb is generally considered benign, but it is another tdb on the same node reporting impossible offsets, so I am mentioning it rather than filtering it. Questions --------- 1. Is this a known defect in 4.24.x, or in the volatile ltdb / vacuuming path generally? 2. Is there anything you would like enabled before the next occurrence (higher CTDB debug level, a tdb_check on each vacuum pass, a specific tunable)? 3. Is there a recommended mitigation while this is investigated? We are considering disabling tdb mutexes on the volatile databases and adjusting RepackLimit, but would rather follow your advice than guess.
Sorry this took a month to get to... Thanks for the excellent, detailed bug report with the some interesting cases excluded... although I'm going to double-check one of them... :-) Normally, I would ask if disk could have been full but that's not in play here. No possibility of out of memory? I read below that there were no OOMs logged. When I've seen corruption like this in recent years I've always been able to pin it on disk full. Just trying to definitely exclude the obvious before digging deeper... Generally, CTDB is a layer on top of TDB, using its APIs. So, apart from possible memory corruption bugs, it doesn't add anything that could likely cause corrupted TDB files. Even recovery and vacuuming are just record-based operations. Is this production or test? I'm wondering how much room you might have available to test some alternatives. I can't see anything later in the 4.24.x series that seem likely to fix something like this. Given that you're running 4.24.5, I'm wondering if you're in a position to roll back to 4.24.4, which is before the security release. Although the CTDB protocol patches were carefully reviewed by multiple people, it isn't impossible that a bug crept in. Right now I'm not bubbling over with ideas... :-( The only thing that springs to mind is 2 processes updating the same TDB and one of them has forgotten to take a lock. However, I can't think of any significant changes that could cause this...
This was production and I don't have access to the cluster anymore. It definitely seemed to have been a one off though and hasn't happened since. No OOM, I checked the metrics for the server and hasn't even been close before the corruption occured. Anyway, this is not high priority. It was easy to recover from, just thought I would report in case you had any ideas.
Metze, Volker: Do you want to check this from a TDB perspective before I lazily close this as "works for me? As per my previous comment, the only time I've seen this sort of thing in recent years is with disk full or similar.