Case study
Database host panicking during the nightly backup window
A financial services customer ran a PostgreSQL primary on RHEL 9.4. Roughly every two to three days the host panicked between 02:00 and 03:00 and rebooted, dropping replication and triggering a failover. The crashes had been going on for five weeks.
- Environment
- RHEL 9.4, kernel 5.14.0-427.26.1.el9_4, Dell PowerEdge R760, XFS on LVM over dm-multipath, 1 TB NVMe-backed SAN LUN
- Third-party kernel modules
- An EDR security sensor and a backup vendor's block-level snapshot driver, both out-of-tree (kernel tainted OE)
- Symptom
- Panic 15 to 40 minutes into the backup job, only on nights when the job overran its window
- Before coming to us
- OS vendor declined the case because of the taint. The backup vendor said their module is passive. The EDR vendor said they do not touch block I/O. Five weeks, three tickets, no owner.
What the kernel said
[412873.552011] list_del corruption. prev->next should be ffff9c1e4a3b0c40, but was dead000000000100 [412873.552031] ------------[ cut here ]------------ [412873.552032] kernel BUG at lib/list_debug.c:54! [412873.552040] invalid opcode: 0000 [#1] PREEMPT SMP PTI [412873.552045] CPU: 9 PID: 2184 Comm: kworker/9:1H Kdump: loaded Tainted: G OE 5.14.0-427.26.1.el9_4.x86_64 [412873.552056] Workqueue: kblockd blk_mq_run_work_fn [412873.552063] RIP: 0010:__list_del_entry_valid+0x8c/0xb0 [412873.552120] Call Trace: [412873.552122] <TASK> [412873.552130] vsnap_cow_complete+0x1f4/0x2c0 [vsnap_blk] [412873.552141] bio_endio+0x12b/0x150 [412873.552148] blk_update_request+0x24a/0x3f0 [412873.552155] scsi_end_request+0x2a/0x1a0 [412873.552161] scsi_io_completion+0x7e/0x1e0 [412873.552167] blk_complete_reqs+0x3d/0x50 [412873.552173] __do_softirq+0xd0/0x2c3 [412873.552180] </TASK> [412873.552310] Modules linked in: vsnap_blk(OE) edr_sensor(OE) xfs dm_multipath dm_round_robin nvme_tcp ...
How we worked it
Automated symbol resolution and stack walking took four minutes. The steps below are from the engineer's crash session that confirmed the finding.
- 01
Confirm what was corrupted and who touched it last
crash> bt PID: 2184 TASK: ffff9c1e3f2a8000 CPU: 9 COMMAND: "kworker/9:1H" #4 [ffffb0a2c0c4fd18] __list_del_entry_valid at ffffffff9a4e1c2c #5 [ffffb0a2c0c4fd28] vsnap_cow_complete at ffffffffc0b1a1f4 [vsnap_blk] #6 [ffffb0a2c0c4fd60] bio_endio at ffffffff9a7c3a3b crash> struct bio ffff9c1e4a3b0c40 -x bi_flags bi_end_io bi_private bi_flags = 0x3 (BIO_CLONED | BIO_REFFED) bi_end_io = 0xffffffffc0b1a000 <vsnap_cow_complete> bi_private = 0xffff9c1e51c02800
Finding. The corrupted list entry is a cloned bio owned by the snapshot driver. Its completion handler ran on a SCSI completion path.
- 02
Check whether the private data was still alive
crash> kmem 0xffff9c1e51c02800 CACHE OBJSIZE ALLOCATED TOTAL SLAB NAME ffff9c1e40041b00 512 1203 1536 ... kmalloc-512 [ffff9c1e51c02800] (FREE) crash> rd 0xffff9c1e51c02800 4 ffff9c1e51c02800: dead000000000100 dead000000000122 ................
Finding. The snapshot session object the bio pointed to had already been freed. The poison values confirm a use-after-free, not memory corruption from elsewhere.
- 03
Establish the ordering from the kernel log and process table
crash> log | grep -E "vsnap|backup" | tail -4 [412873.401877] vsnap_blk: session 17 teardown requested (pid 41022) [412873.402005] vsnap_blk: session 17 released, 212 COW bios outstanding [412873.552011] list_del corruption. prev->next should be ffff9c1e4a3b0c40 ... crash> ps -t 41022 PID: 41022 TASK: ffff9c1e2b1d0000 COMMAND: "backup-agent" RUN TIME: 00:48:11 (exited: SIGTERM from pid 41019 "backup-watchdog")Finding. 150 ms before the panic the backup agent was killed by its own watchdog for exceeding the job window. The driver tore the session down with 212 I/Os still in flight.
- 04
Rule the other vendor in or out
crash> mod -s edr_sensor crash> bt -a | grep edr_sensor (no frames) crash> dis -l vsnap_session_release | grep -A2 kfree .../vsnap_session.c: 318 kfree(sess); /* no wait for outstanding COW bios */
Finding. The EDR sensor appears in no stack on any CPU and hooks only LSM paths. The snapshot driver frees its session without waiting for outstanding clones. One vendor, one bug.
Root cause
Use-after-free in the backup vendor's snapshot driver. When the backup agent exits mid-job, the driver releases the copy-on-write session immediately while cloned bios for that session are still completing in the SCSI layer. Each late completion dereferences freed memory. The panic only appeared on nights the job overran, which is why it looked random.
What the customer received
- Responsible component
- The snapshot driver, version 4.2.1, in its session release path. The OS kernel and the EDR sensor were ruled out with evidence from every CPU's stack.
- Escalation package
- A two-page summary for the backup vendor: the exact function, the missing reference count, the log ordering, and a reproduction recipe (start a snapshot job, kill the agent at 40% complete). The vendor acknowledged the defect within two days.
- Interim mitigation
- Raise the watchdog timeout above the longest observed job and set the agent to drain rather than terminate on timeout. Both are configuration changes with no downtime. The host did not panic again after this was applied.
- Permanent fix
- Vendor hotfix 4.2.3 added a reference count on the session and waits for outstanding COW bios in release. Deployed fleet-wide 11 days later.
Timeline
- Tue 14:10Case submitted through this form with a case summary and dmesg excerpt
- Tue 14:35Engineer assigned, upload instructions sent, vmcore received by 16:00
- Tue 19:20Preliminary finding shared: snapshot driver use-after-free, mitigation suggested
- Wed 10:00Full RCA report delivered with escalation package
- +2 daysBackup vendor confirms the defect
- +11 daysHotfix deployed. No recurrence in the following 90 days.