[PATCH v3 00/14] ceph: add binary logging (BLOG) for CephFS
Alex Markuze <[email protected]>
| Newsgroups | org.kernel.vger.ceph-devel |
|---|---|
| Message-ID | <[email protected]> |
This series adds a binary logging subsystem for the CephFS kernel
client. On hot I/O paths every dout() call formats a printk-style
string even when nobody is reading the log. After a client hang or
crash, operators often want the last slice of those messages without
having attached ftrace in advance. BLOG is an opt-in flight recorder
for that corpus: it stores compact binary records keyed by a source-ID
and decodes them through debugfs.
It is not a replacement for Ceph tracepoints. Tracepoints remain the
right interface for stable, structured events consumed by ftrace, perf,
and BPF. Putting the dout corpus on tracepoints would mean a maintained
event schema for every internal debug line, mount identity in every
event, and a collector running before the failure. BLOG keeps the
printf-style call sites, is enabled per mount, and retains recent
records for collection after the fact.
All new code lives under fs/ceph/ and include/linux/ceph/. There are
no changes outside the Ceph subsystem. BLOG objects are linked only
when CONFIG_DEBUG_FS=y (the only UI). There is no CONFIG_CEPH_BLOG.
Runtime enablement is a per-mount debugfs knob and defaults to off.
When the static key is down, boutc() is doutc() -- one unlikely branch,
no formatting tax from BLOG. When the key is up but this task has no
enter, boutc() still falls back to doutc().
Load-time module parameters blog_max_sources (default 4096) and
blog_max_clients (default 256) size the ID tables.
Design
------
Record format. Each record is a small header (timestamp delta from
the buffer base, source-ID, client-ID, payload length) plus serialized
arguments. The format string lives in the source table, not in every
record. Arguments are packed once; strings are length-delimited.
Decoding walks the source table and reconstructs text, including the
'#' flag for hex/octal.
Allocation. Each logging task owns a 4K live buffer. A page-fragment
allocator hands out slices without a global lock; freed buffers recycle
through per-CPU magazine batches, so the warm path does not allocate.
When the live buffer cannot fit the next record it is retired onto a
reader-visible snapshot list (fresh monotonic ID) and a new live buffer
is taken from the magazine or allocated. On GFP_ATOMIC OOM the full
window is kept and only the new record is dropped -- the live buffer is
not wiped in place. Wipe/reset happens on pool reuse or debugfs clear
(clear generation). Sleepable first-touch uses GFP_NOFS. Folio-locked
and other atomic callbacks (dirty_folio, invalidate_folio, write_end,
OSD writeback completion) use GFP_ATOMIC: reuse an existing context or
skip logging. RCU-walk permission with MAY_NOT_BLOCK returns -ECHILD
before enter.
Source-ID caching. Each (file, func, line, fmt) tuple is registered
once per logger into an open-addressed table and assigned a u32
source-ID. A per-callsite cache avoids that lookup after the first
hit. The cache is a seqcount_spinlock_t associated with its spinlock
so a PREEMPT_RT writer cannot livelock readers on an odd sequence. A
generation counter on the logger prevents stale hits across
mount/unmount of the same callsite.
Per-superblock ownership. Every mounted CephFS instance, including
-o noshare, gets its own blog_module_context and logger. Enable,
buffers, source table, and debugfs are isolated per mount. Client IDs
map (fsid, global_id) so decoded output can name the Ceph client.
Context propagation. Binary records are only emitted while a task has
a bound blog_tls_ctx (enter_depth > 0). ceph_blog_enter() acquires or
reuses that context from a task-keyed rhashtable and publishes it in a
per-CPU cache {task, ctx}. The cache hit requires current, enter_depth,
and logger match; a miss refills from the map. Plain enter does not
write current->journal_info, so ordinary VFS callbacks do not expose a
Ceph pointer to foreign filesystem reclaim and do not run the whole
operation under GFP_NOFS.
ceph_blog_enter_req() still installs a tagged ceph_journal_info for
the MDS fill-trace window (handle_reply -> ceph_fill_trace) so xattr
and security paths can see the in-flight mds_request. That window is
already covered by memalloc_nofs_save(). Nested enter under fill-trace
may inherit mds_req; it still does not use journal_info as the BLOG
carrier.
Last module put never calls blog_module_free() in line (that path
cancel_delayed_work_sync's). Free is queued on ceph_blog_free;
ceph_blog_fsc_cleanup and module exit flush the queue. Dead-task GC
only collects pointers during rhashtable_walk; retire/sleep happens
after walk_stop. Snapshot readers hold snapshot_mutex; a context is
unlinked from the reader list before it can be freed.
debugfs. Per-client directory:
/sys/kernel/debug/ceph/<client>/blog/enabled # 0/1, default 0
/sys/kernel/debug/ceph/<client>/blog/entries # decoded records
/sys/kernel/debug/ceph/<client>/blog/stats
/sys/kernel/debug/ceph/<client>/blog/sources # source-ID table
/sys/kernel/debug/ceph/<client>/blog/clients
/sys/kernel/debug/ceph/<client>/blog/clear # write-only
Logging macros. boutc() / boutc_bounded() / boutc_formats() replace
doutc() at CephFS call sites (fs/ceph/ only; they take fsc from
client->private). boutc_formats() splits binary vs text backends
where %pd cannot be serialized. Arguments are evaluated only after a
cached ctx is present.
Why BLOG
--------
When enabled, boutc() packs arguments into a 4K per-task ring instead of
running printk formatting on the hot path. The format string lives in
the source table, not in every record, so the retained window is compact
enough to keep until after a hang. Disabled, the static key is down and
boutc() is doutc(): one unlikely branch, no extra work. Enablement is
per mount, so a debug session does not tax every CephFS superblock.
Stable events still belong on tracepoints. BLOG is only for the existing
dout/doutc corpus: sites that churn with debug work, need a recent-record
dump without a collector attached in advance, and are too numerous to
promote one-for-one into TRACE_EVENT.
Patch breakdown
---------------
01-06 BLOG infrastructure, one patch per compilation unit:
private headers, deserializer, pagefrag allocator,
magazine batcher, logger core, per-module context manager.
07 Ceph BLOG scaffolding -- ceph_blog.h, blog_client.c,
super.h / libceph.h additions, Makefile wiring
(ceph-$(CONFIG_DEBUG_FS)).
08 boutc macro definitions in ceph_debug.h.
09 MDS fill-trace plumbing -- ceph_blog_enter_req() /
ceph_blog_exit() around handle_reply's ceph_fill_trace().
10 debugfs interface -- blog_debugfs.c and lifecycle hooks.
11-14 Callsite conversions -- doutc -> boutc, grouped by
subsystem: inodes+dirs, data I/O, caps+snaps, helpers.
Changes since v2
----------------
- move private headers under fs/ceph/; only the shared CephFS
integration surface stays in include/linux/ceph/
- no CONFIG_CEPH_BLOG; compile with CONFIG_DEBUG_FS
- 4K buffers and rotate-on-full; snapshot inherits the live context
ID (live takes the next ID) so blog/entries stays chronological;
clear live before publishing; a failed log-batch put keeps the
live window rather than wiping it
- BLOG context is task-local (CPU cache on the hot path).
journal_info + NOFS are only used for MDS fill-trace
- GFP_ATOMIC enter on folio-locked a_ops; last module put defers
free to a workqueue, umount/rmmod flush it
- seqcount_spinlock_t for the source-id cache; GC does not sleep
in the RCU walk
- drop the kselftest patch from this posting
- annotate lockless client_map[] reads with data_race(); document
slot reuse rather than tearing; clear pending state on ENOSPC
commit
Alex Markuze (14):
ceph: add BLOG private headers
ceph: add BLOG deserialization support
ceph: add BLOG page-fragment allocator
ceph: add BLOG magazine batch allocator
ceph: add BLOG logger core
ceph: add BLOG per-module context management
ceph: add Ceph BLOG scaffolding
ceph: add bout and boutc wrappers for BLOG
ceph: switch MDS request plumbing to struct ceph_journal_info
ceph: add BLOG debugfs interface
ceph: convert VFS inode and directory paths to bout
ceph: convert VFS data I/O paths to bout
ceph: convert capability and snapshot paths to bout
ceph: convert remaining helper paths to bout
fs/ceph/Makefile | 3 +
fs/ceph/addr.c | 198 ++++---
fs/ceph/blog.h | 223 +++++++
fs/ceph/blog_batch.c | 307 ++++++++++
fs/ceph/blog_batch.h | 44 ++
fs/ceph/blog_client.c | 678 ++++++++++++++++++++++
fs/ceph/blog_core.c | 279 +++++++++
fs/ceph/blog_debugfs.c | 713 +++++++++++++++++++++++
fs/ceph/blog_des.c | 343 +++++++++++
fs/ceph/blog_des.h | 16 +
fs/ceph/blog_module.c | 994 ++++++++++++++++++++++++++++++++
fs/ceph/blog_module.h | 46 ++
fs/ceph/blog_pagefrag.c | 84 +++
fs/ceph/blog_pagefrag.h | 27 +
fs/ceph/blog_ser.h | 234 ++++++++
fs/ceph/caps.c | 112 ++--
fs/ceph/crypto.c | 14 +-
fs/ceph/debugfs.c | 11 +-
fs/ceph/dir.c | 322 ++++++++---
fs/ceph/export.c | 83 ++-
fs/ceph/file.c | 271 ++++++---
fs/ceph/inode.c | 242 +++++---
fs/ceph/locks.c | 66 ++-
fs/ceph/mds_client.c | 358 +++++++-----
fs/ceph/snap.c | 17 +-
fs/ceph/super.c | 58 +-
fs/ceph/super.h | 7 +
fs/ceph/xattr.c | 102 ++--
include/linux/ceph/ceph_blog.h | 292 ++++++++++
include/linux/ceph/ceph_debug.h | 84 ++-
include/linux/ceph/libceph.h | 2 +
31 files changed, 5593 insertions(+), 637 deletions(-)
create mode 100644 fs/ceph/blog.h
create mode 100644 fs/ceph/blog_batch.c
create mode 100644 fs/ceph/blog_batch.h
create mode 100644 fs/ceph/blog_client.c
create mode 100644 fs/ceph/blog_core.c
create mode 100644 fs/ceph/blog_debugfs.c
create mode 100644 fs/ceph/blog_des.c
create mode 100644 fs/ceph/blog_des.h
create mode 100644 fs/ceph/blog_module.c
create mode 100644 fs/ceph/blog_module.h
create mode 100644 fs/ceph/blog_pagefrag.c
create mode 100644 fs/ceph/blog_pagefrag.h
create mode 100644 fs/ceph/blog_ser.h
create mode 100644 include/linux/ceph/ceph_blog.h
--
2.34.1