Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions .gitignore
Original file line number Diff line number Diff line change
Expand Up @@ -10,4 +10,5 @@ __pycache__/

# auto-generated
src/embedded_dwarf_data.h
src/ceph_btf_local.h

11 changes: 10 additions & 1 deletion doc/man/8/osdtrace.rst
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,7 @@ probe and trace OSD(s) on given nodes
SYNOPSIS
========

| **osdtrace** [-s] [-b] [-l <milliseconds>] [-t <seconds>] [-j <filename>] [-i <filename>] [-a] [-p <pid1,pid2,...>] [--id <osd-id1,osd-id2,...>] [--skip-version-check] [--list] [--list-embedded] [-V] [-h]
| **osdtrace** [-s] [-b] [-A] [-l <milliseconds>] [-t <seconds>] [-j <filename>] [-i <filename>] [-a] [-p <pid1,pid2,...>] [--id <osd-id1,osd-id2,...>] [--skip-version-check] [--list] [--list-embedded] [-V] [-h]


DESCRIPTION
Expand Down Expand Up @@ -44,6 +44,15 @@ OPTIONS
_txc_committed_kv, kv_commit, _do_read, _remove), so the labels stay
correct across Ceph versions.

-A

Allocator probe mode: trace every call into the BlueStore/BlueFS
free-space allocator. Each line reports the allocator instance
(block, bluefs-wal/db/slow), the requested size, alignment unit and
hint, the bytes actually allocated, the returned physical extents
(a split request is a direct fragmentation signal), the call
latency, and the calling thread. Can be combined with -b.

-l <milliseconds>

Set operation latency threshold to capture
Expand Down
33 changes: 33 additions & 0 deletions doc/osdtrace.md
Original file line number Diff line number Diff line change
Expand Up @@ -98,6 +98,8 @@ sudo ./osdtrace
/ log_latency_fn call as "bluestore <name> lat <us>",
where <name> is the operation label the OSD passes
(e.g. _txc_committed_kv, kv_commit, _do_read, _remove)
-A Allocator probe mode: trace every BlueStore/BlueFS
allocator call (size, latency, returned extents)
-l <milliseconds> Only capture operations slower than this threshold
-i <filename> Import DWARF info from JSON file
-j <filename> Export DWARF info to JSON file and exit
Expand All @@ -116,6 +118,37 @@ breakdown (messenger, OSD, peers, BlueStore sub-latencies) for every operation.
The former `-x` flag is gone - its output is now the default; the `-d` and `-m`
aggregation options were removed at the same time.

## Allocator Probe Mode (-A)

`osdtrace -A` traces every call into the BlueStore free-space allocator —
the `allocate()` overrides of whichever allocator implementation the OSD
runs (`hybrid` by default; bitmap/avl/btree/btree2/stupid are covered too).
This includes BlueFS's allocators, so RocksDB file growth is visible next
to object-data allocations. One line per call:

```
osd 0 alloc block want 0x10000 unit 0x1000 -> 0x10000 exts 1 [0x8e2000~0x10000] lat 13us comm tp_osd_tp
osd 0 alloc bluefs-wal want 0x1200000 unit 0x100000 hint 0x16300000 -> 0x1200000 exts 1 [0x16300000~0x1200000] lat 9us comm bstore_kv_sync
```

| Field | Meaning |
|-------|---------|
| **alloc** | Allocator instance name: `block` (BlueStore data) or `bluefs-wal/db/slow` (BlueFS/RocksDB) |
| **want / unit / hint** | Requested bytes, allocation-unit alignment, preferred offset (omitted when unset) |
| **->** | Bytes actually allocated; `SHORT` when less than requested, `ENOSPC` on failure |
| **exts N [off~len ...]** | The returned physical extents (first 6 shown). N > 1 means the request was split — a direct fragmentation signal |
| **(nested dN)** | Call made from inside another allocator (e.g. hybrid falling back to its internal bitmap) |
| **lat** | allocate() entry → return, µs: lock wait + free-space search time |

Rising latency together with rising extent counts is fragmentation biting
the write path — the per-call complement to
`ceph daemon osd.N bluestore allocator score block`. `-l <ms>` filters on
latency; `-A -b` combines with the BlueStore latency probes.

Note: `-A` needs DWARF data that includes the allocator probes; direct
binary parsing and freshly exported JSONs work, older DWARF JSONs and
embedded data skip these probes with a warning.

### Examples

#### Discover OSDs, then trace by OSD ID
Expand Down
271 changes: 270 additions & 1 deletion files/centos-stream/osdtrace/osd-2:17.2.6-0.el8_dwarf.json
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,9 @@
"ceph-osd": {
"build_id": "461e6598014802fdd3c01be5ed4df872294224cf",
"func2pc": {
"Allocator::get_name": 13912464,
"AvlAllocator::allocate": 14279120,
"BitmapAllocator::allocate": 14247872,
"BlueStore::_do_write": 13158816,
"BlueStore::_txc_add_transaction": 13170096,
"BlueStore::_txc_apply_kv": 13018720,
Expand All @@ -13,7 +16,9 @@
"BlueStore::log_latency": 13486544,
"BlueStore::log_latency_fn": 13487216,
"BlueStore::queue_transactions": 13241968,
"BtreeAllocator::allocate": 14303056,
"ECBackend::submit_transaction": 11527472,
"HybridAllocator::allocate": 14335616,
"OSD::dequeue_op": 6923680,
"OSD::enqueue_op": 6974704,
"OpRequest::mark_flag_point": 17924608,
Expand All @@ -23,7 +28,8 @@
"ReplicatedBackend::do_repop_reply": 11221568,
"ReplicatedBackend::generate_subop": 11197488,
"ReplicatedBackend::repop_commit": 11233664,
"ReplicatedBackend::submit_transaction": 11215760
"ReplicatedBackend::submit_transaction": 11215760,
"StupidAllocator::allocate": 14226592
},
"type_sizes": {
"OSDOp": 152
Expand All @@ -34,6 +40,131 @@
"OSDOp::op.cls.method_len": 7
},
"func2vf": {
"Allocator::get_name": {
"var_fields": [
{
"location": {
"reg": 5,
"offset": 0,
"stack": false
},
"fields": [
{
"offset": 0,
"pointer": false
},
{
"offset": 8,
"pointer": true
},
{
"offset": 16,
"pointer": true
},
{
"offset": 0,
"pointer": false
},
{
"offset": 0,
"pointer": false
}
]
}
]
},
"AvlAllocator::allocate": {
"var_fields": [
{
"location": {
"reg": 9,
"offset": 0,
"stack": false
},
"fields": [
{
"offset": 0,
"pointer": false
},
{
"offset": 0,
"pointer": true
},
{
"offset": 16,
"pointer": false
}
]
},
{
"location": {
"reg": 9,
"offset": 0,
"stack": false
},
"fields": [
{
"offset": 0,
"pointer": false
},
{
"offset": 0,
"pointer": true
},
{
"offset": 24,
"pointer": false
}
]
}
]
},
"BitmapAllocator::allocate": {
"var_fields": [
{
"location": {
"reg": 9,
"offset": 0,
"stack": false
},
"fields": [
{
"offset": 0,
"pointer": false
},
{
"offset": 0,
"pointer": true
},
{
"offset": 16,
"pointer": false
}
]
},
{
"location": {
"reg": 9,
"offset": 0,
"stack": false
},
"fields": [
{
"offset": 0,
"pointer": false
},
{
"offset": 0,
"pointer": true
},
{
"offset": 24,
"pointer": false
}
]
}
]
},
"BlueStore::_do_write": {
"var_fields": []
},
Expand Down Expand Up @@ -396,6 +527,52 @@
"BlueStore::queue_transactions": {
"var_fields": []
},
"BtreeAllocator::allocate": {
"var_fields": [
{
"location": {
"reg": 9,
"offset": 0,
"stack": false
},
"fields": [
{
"offset": 0,
"pointer": false
},
{
"offset": 0,
"pointer": true
},
{
"offset": 16,
"pointer": false
}
]
},
{
"location": {
"reg": 9,
"offset": 0,
"stack": false
},
"fields": [
{
"offset": 0,
"pointer": false
},
{
"offset": 0,
"pointer": true
},
{
"offset": 24,
"pointer": false
}
]
}
]
},
"ECBackend::submit_transaction": {
"var_fields": [
{
Expand Down Expand Up @@ -438,6 +615,52 @@
}
]
},
"HybridAllocator::allocate": {
"var_fields": [
{
"location": {
"reg": 9,
"offset": 0,
"stack": false
},
"fields": [
{
"offset": 0,
"pointer": false
},
{
"offset": 0,
"pointer": true
},
{
"offset": 16,
"pointer": false
}
]
},
{
"location": {
"reg": 9,
"offset": 0,
"stack": false
},
"fields": [
{
"offset": 0,
"pointer": false
},
{
"offset": 0,
"pointer": true
},
{
"offset": 24,
"pointer": false
}
]
}
]
},
"OSD::dequeue_op": {
"var_fields": [
{
Expand Down Expand Up @@ -1630,6 +1853,52 @@
]
}
]
},
"StupidAllocator::allocate": {
"var_fields": [
{
"location": {
"reg": 9,
"offset": 0,
"stack": false
},
"fields": [
{
"offset": 0,
"pointer": false
},
{
"offset": 0,
"pointer": true
},
{
"offset": 16,
"pointer": false
}
]
},
{
"location": {
"reg": 9,
"offset": 0,
"stack": false
},
"fields": [
{
"offset": 0,
"pointer": false
},
{
"offset": 0,
"pointer": true
},
{
"offset": 24,
"pointer": false
}
]
}
]
}
}
}
Expand Down
Loading
Loading