1 /* SPDX-License-Identifier: GPL-2.0 */
3 #define TRACE_SYSTEM gfs2
5 #if !defined(_TRACE_GFS2_H) || defined(TRACE_HEADER_MULTI_READ)
8 #include <linux/tracepoint.h>
11 #include <linux/buffer_head.h>
12 #include <linux/dlmconstants.h>
13 #include <linux/gfs2_ondisk.h>
14 #include <linux/writeback.h>
15 #include <linux/ktime.h>
16 #include <linux/iomap.h>
21 #define dlm_state_name(nn) { DLM_LOCK_##nn, #nn }
22 #define glock_trace_name(x) __print_symbolic(x, \
31 #define block_state_name(x) __print_symbolic(x, \
32 { GFS2_BLKST_FREE, "free" }, \
33 { GFS2_BLKST_USED, "used" }, \
34 { GFS2_BLKST_DINODE, "dinode" }, \
35 { GFS2_BLKST_UNLINKED, "unlinked" })
37 #define TRACE_RS_DELETE 0
38 #define TRACE_RS_TREEDEL 1
39 #define TRACE_RS_INSERT 2
40 #define TRACE_RS_CLAIM 3
42 #define rs_func_name(x) __print_symbolic(x, \
48 #define show_glock_flags(flags) __print_flags(flags, "", \
49 {(1UL << GLF_LOCK), "l" }, \
50 {(1UL << GLF_DEMOTE), "D" }, \
51 {(1UL << GLF_PENDING_DEMOTE), "d" }, \
52 {(1UL << GLF_DEMOTE_IN_PROGRESS), "p" }, \
53 {(1UL << GLF_DIRTY), "y" }, \
54 {(1UL << GLF_LFLUSH), "f" }, \
55 {(1UL << GLF_INVALIDATE_IN_PROGRESS), "i" }, \
56 {(1UL << GLF_REPLY_PENDING), "r" }, \
57 {(1UL << GLF_INITIAL), "I" }, \
58 {(1UL << GLF_FROZEN), "F" }, \
59 {(1UL << GLF_LRU), "L" }, \
60 {(1UL << GLF_OBJECT), "o" }, \
61 {(1UL << GLF_BLOCKING), "b" })
65 static inline u8 glock_trace_state(unsigned int state)
79 /* Section 1 - Locking
82 * Latency: Remote demote request to state change
83 * Latency: Local lock request to state change
84 * Latency: State change to lock grant
85 * Correctness: Ordering of local lock state vs. I/O requests
86 * Correctness: Responses to remote demote requests
89 /* General glock state change (DLM lock request completes) */
90 TRACE_EVENT(gfs2_glock_state_change,
92 TP_PROTO(const struct gfs2_glock *gl, unsigned int new_state),
94 TP_ARGS(gl, new_state),
99 __field( u32, gltype )
100 __field( u8, cur_state )
101 __field( u8, new_state )
102 __field( u8, dmt_state )
103 __field( u8, tgt_state )
104 __field( unsigned long, flags )
108 __entry->dev = gl->gl_name.ln_sbd->sd_vfs->s_dev;
109 __entry->glnum = gl->gl_name.ln_number;
110 __entry->gltype = gl->gl_name.ln_type;
111 __entry->cur_state = glock_trace_state(gl->gl_state);
112 __entry->new_state = glock_trace_state(new_state);
113 __entry->tgt_state = glock_trace_state(gl->gl_target);
114 __entry->dmt_state = glock_trace_state(gl->gl_demote_state);
115 __entry->flags = gl->gl_flags | (gl->gl_object ? (1UL<<GLF_OBJECT) : 0);
118 TP_printk("%u,%u glock %d:%lld state %s to %s tgt:%s dmt:%s flags:%s",
119 MAJOR(__entry->dev), MINOR(__entry->dev), __entry->gltype,
120 (unsigned long long)__entry->glnum,
121 glock_trace_name(__entry->cur_state),
122 glock_trace_name(__entry->new_state),
123 glock_trace_name(__entry->tgt_state),
124 glock_trace_name(__entry->dmt_state),
125 show_glock_flags(__entry->flags))
128 /* State change -> unlocked, glock is being deallocated */
129 TRACE_EVENT(gfs2_glock_put,
131 TP_PROTO(const struct gfs2_glock *gl),
136 __field( dev_t, dev )
137 __field( u64, glnum )
138 __field( u32, gltype )
139 __field( u8, cur_state )
140 __field( unsigned long, flags )
144 __entry->dev = gl->gl_name.ln_sbd->sd_vfs->s_dev;
145 __entry->gltype = gl->gl_name.ln_type;
146 __entry->glnum = gl->gl_name.ln_number;
147 __entry->cur_state = glock_trace_state(gl->gl_state);
148 __entry->flags = gl->gl_flags | (gl->gl_object ? (1UL<<GLF_OBJECT) : 0);
151 TP_printk("%u,%u glock %d:%lld state %s => %s flags:%s",
152 MAJOR(__entry->dev), MINOR(__entry->dev),
153 __entry->gltype, (unsigned long long)__entry->glnum,
154 glock_trace_name(__entry->cur_state),
155 glock_trace_name(DLM_LOCK_IV),
156 show_glock_flags(__entry->flags))
160 /* Callback (local or remote) requesting lock demotion */
161 TRACE_EVENT(gfs2_demote_rq,
163 TP_PROTO(const struct gfs2_glock *gl, bool remote),
168 __field( dev_t, dev )
169 __field( u64, glnum )
170 __field( u32, gltype )
171 __field( u8, cur_state )
172 __field( u8, dmt_state )
173 __field( unsigned long, flags )
174 __field( bool, remote )
178 __entry->dev = gl->gl_name.ln_sbd->sd_vfs->s_dev;
179 __entry->gltype = gl->gl_name.ln_type;
180 __entry->glnum = gl->gl_name.ln_number;
181 __entry->cur_state = glock_trace_state(gl->gl_state);
182 __entry->dmt_state = glock_trace_state(gl->gl_demote_state);
183 __entry->flags = gl->gl_flags | (gl->gl_object ? (1UL<<GLF_OBJECT) : 0);
184 __entry->remote = remote;
187 TP_printk("%u,%u glock %d:%lld demote %s to %s flags:%s %s",
188 MAJOR(__entry->dev), MINOR(__entry->dev), __entry->gltype,
189 (unsigned long long)__entry->glnum,
190 glock_trace_name(__entry->cur_state),
191 glock_trace_name(__entry->dmt_state),
192 show_glock_flags(__entry->flags),
193 __entry->remote ? "remote" : "local")
197 /* Promotion/grant of a glock */
198 TRACE_EVENT(gfs2_promote,
200 TP_PROTO(const struct gfs2_holder *gh, int first),
205 __field( dev_t, dev )
206 __field( u64, glnum )
207 __field( u32, gltype )
208 __field( int, first )
213 __entry->dev = gh->gh_gl->gl_name.ln_sbd->sd_vfs->s_dev;
214 __entry->glnum = gh->gh_gl->gl_name.ln_number;
215 __entry->gltype = gh->gh_gl->gl_name.ln_type;
216 __entry->first = first;
217 __entry->state = glock_trace_state(gh->gh_state);
220 TP_printk("%u,%u glock %u:%llu promote %s %s",
221 MAJOR(__entry->dev), MINOR(__entry->dev), __entry->gltype,
222 (unsigned long long)__entry->glnum,
223 __entry->first ? "first": "other",
224 glock_trace_name(__entry->state))
227 /* Queue/dequeue a lock request */
228 TRACE_EVENT(gfs2_glock_queue,
230 TP_PROTO(const struct gfs2_holder *gh, int queue),
235 __field( dev_t, dev )
236 __field( u64, glnum )
237 __field( u32, gltype )
238 __field( int, queue )
243 __entry->dev = gh->gh_gl->gl_name.ln_sbd->sd_vfs->s_dev;
244 __entry->glnum = gh->gh_gl->gl_name.ln_number;
245 __entry->gltype = gh->gh_gl->gl_name.ln_type;
246 __entry->queue = queue;
247 __entry->state = glock_trace_state(gh->gh_state);
250 TP_printk("%u,%u glock %u:%llu %squeue %s",
251 MAJOR(__entry->dev), MINOR(__entry->dev), __entry->gltype,
252 (unsigned long long)__entry->glnum,
253 __entry->queue ? "" : "de",
254 glock_trace_name(__entry->state))
257 /* DLM sends a reply to GFS2 */
258 TRACE_EVENT(gfs2_glock_lock_time,
260 TP_PROTO(const struct gfs2_glock *gl, s64 tdiff),
265 __field( dev_t, dev )
266 __field( u64, glnum )
267 __field( u32, gltype )
268 __field( int, status )
269 __field( char, flags )
270 __field( s64, tdiff )
272 __field( u64, srttvar )
273 __field( u64, srttb )
274 __field( u64, srttvarb )
276 __field( u64, sirtvar )
277 __field( u64, dcount )
278 __field( u64, qcount )
282 __entry->dev = gl->gl_name.ln_sbd->sd_vfs->s_dev;
283 __entry->glnum = gl->gl_name.ln_number;
284 __entry->gltype = gl->gl_name.ln_type;
285 __entry->status = gl->gl_lksb.sb_status;
286 __entry->flags = gl->gl_lksb.sb_flags;
287 __entry->tdiff = tdiff;
288 __entry->srtt = gl->gl_stats.stats[GFS2_LKS_SRTT];
289 __entry->srttvar = gl->gl_stats.stats[GFS2_LKS_SRTTVAR];
290 __entry->srttb = gl->gl_stats.stats[GFS2_LKS_SRTTB];
291 __entry->srttvarb = gl->gl_stats.stats[GFS2_LKS_SRTTVARB];
292 __entry->sirt = gl->gl_stats.stats[GFS2_LKS_SIRT];
293 __entry->sirtvar = gl->gl_stats.stats[GFS2_LKS_SIRTVAR];
294 __entry->dcount = gl->gl_stats.stats[GFS2_LKS_DCOUNT];
295 __entry->qcount = gl->gl_stats.stats[GFS2_LKS_QCOUNT];
298 TP_printk("%u,%u glock %d:%lld status:%d flags:%02x tdiff:%lld srtt:%lld/%lld srttb:%lld/%lld sirt:%lld/%lld dcnt:%lld qcnt:%lld",
299 MAJOR(__entry->dev), MINOR(__entry->dev), __entry->gltype,
300 (unsigned long long)__entry->glnum,
301 __entry->status, __entry->flags,
302 (long long)__entry->tdiff,
303 (long long)__entry->srtt,
304 (long long)__entry->srttvar,
305 (long long)__entry->srttb,
306 (long long)__entry->srttvarb,
307 (long long)__entry->sirt,
308 (long long)__entry->sirtvar,
309 (long long)__entry->dcount,
310 (long long)__entry->qcount)
313 /* Section 2 - Log/journal
316 * Latency: Log flush time
317 * Correctness: pin/unpin vs. disk I/O ordering
318 * Performance: Log usage stats
321 /* Pin/unpin a block in the log */
322 TRACE_EVENT(gfs2_pin,
324 TP_PROTO(const struct gfs2_bufdata *bd, int pin),
329 __field( dev_t, dev )
332 __field( sector_t, block )
337 __entry->dev = bd->bd_gl->gl_name.ln_sbd->sd_vfs->s_dev;
339 __entry->len = bd->bd_bh->b_size;
340 __entry->block = bd->bd_bh->b_blocknr;
341 __entry->ino = bd->bd_gl->gl_name.ln_number;
344 TP_printk("%u,%u log %s %llu/%lu inode %llu",
345 MAJOR(__entry->dev), MINOR(__entry->dev),
346 __entry->pin ? "pin" : "unpin",
347 (unsigned long long)__entry->block,
348 (unsigned long)__entry->len,
349 (unsigned long long)__entry->ino)
352 /* Flushing the log */
353 TRACE_EVENT(gfs2_log_flush,
355 TP_PROTO(const struct gfs2_sbd *sdp, int start, u32 flags),
357 TP_ARGS(sdp, start, flags),
360 __field( dev_t, dev )
361 __field( int, start )
362 __field( u64, log_seq )
363 __field( u32, flags )
367 __entry->dev = sdp->sd_vfs->s_dev;
368 __entry->start = start;
369 __entry->log_seq = sdp->sd_log_sequence;
370 __entry->flags = flags;
373 TP_printk("%u,%u log flush %s %llu %llx",
374 MAJOR(__entry->dev), MINOR(__entry->dev),
375 __entry->start ? "start" : "end",
376 (unsigned long long)__entry->log_seq,
377 (unsigned long long)__entry->flags)
380 /* Reserving/releasing blocks in the log */
381 TRACE_EVENT(gfs2_log_blocks,
383 TP_PROTO(const struct gfs2_sbd *sdp, int blocks),
385 TP_ARGS(sdp, blocks),
388 __field( dev_t, dev )
389 __field( int, blocks )
390 __field( int, blks_free )
394 __entry->dev = sdp->sd_vfs->s_dev;
395 __entry->blocks = blocks;
396 __entry->blks_free = atomic_read(&sdp->sd_log_blks_free);
399 TP_printk("%u,%u log reserve %d %d", MAJOR(__entry->dev),
400 MINOR(__entry->dev), __entry->blocks, __entry->blks_free)
403 /* Writing back the AIL */
404 TRACE_EVENT(gfs2_ail_flush,
406 TP_PROTO(const struct gfs2_sbd *sdp, const struct writeback_control *wbc, int start),
408 TP_ARGS(sdp, wbc, start),
411 __field( dev_t, dev )
412 __field( int, start )
413 __field( int, sync_mode )
414 __field( long, nr_to_write )
418 __entry->dev = sdp->sd_vfs->s_dev;
419 __entry->start = start;
420 __entry->sync_mode = wbc->sync_mode;
421 __entry->nr_to_write = wbc->nr_to_write;
424 TP_printk("%u,%u ail flush %s %s %ld", MAJOR(__entry->dev),
425 MINOR(__entry->dev), __entry->start ? "start" : "end",
426 __entry->sync_mode == WB_SYNC_ALL ? "all" : "none",
427 __entry->nr_to_write)
433 * Latency: Bmap request time
434 * Performance: Block allocator tracing
435 * Correctness: Test of disard generation vs. blocks allocated
438 /* Map an extent of blocks, possibly a new allocation */
439 TRACE_EVENT(gfs2_bmap,
441 TP_PROTO(const struct gfs2_inode *ip, const struct buffer_head *bh,
442 sector_t lblock, int create, int errno),
444 TP_ARGS(ip, bh, lblock, create, errno),
447 __field( dev_t, dev )
448 __field( sector_t, lblock )
449 __field( sector_t, pblock )
451 __field( unsigned long, state )
453 __field( int, create )
454 __field( int, errno )
458 __entry->dev = ip->i_gl->gl_name.ln_sbd->sd_vfs->s_dev;
459 __entry->lblock = lblock;
460 __entry->pblock = buffer_mapped(bh) ? bh->b_blocknr : 0;
461 __entry->inum = ip->i_no_addr;
462 __entry->state = bh->b_state;
463 __entry->len = bh->b_size;
464 __entry->create = create;
465 __entry->errno = errno;
468 TP_printk("%u,%u bmap %llu map %llu/%lu to %llu flags:%08lx %s %d",
469 MAJOR(__entry->dev), MINOR(__entry->dev),
470 (unsigned long long)__entry->inum,
471 (unsigned long long)__entry->lblock,
472 (unsigned long)__entry->len,
473 (unsigned long long)__entry->pblock,
474 __entry->state, __entry->create ? "create " : "nocreate",
478 TRACE_EVENT(gfs2_iomap_start,
480 TP_PROTO(const struct gfs2_inode *ip, loff_t pos, ssize_t length,
483 TP_ARGS(ip, pos, length, flags),
486 __field( dev_t, dev )
488 __field( loff_t, pos )
489 __field( ssize_t, length )
490 __field( u16, flags )
494 __entry->dev = ip->i_gl->gl_name.ln_sbd->sd_vfs->s_dev;
495 __entry->inum = ip->i_no_addr;
497 __entry->length = length;
498 __entry->flags = flags;
501 TP_printk("%u,%u bmap %llu iomap start %llu/%lu flags:%08x",
502 MAJOR(__entry->dev), MINOR(__entry->dev),
503 (unsigned long long)__entry->inum,
504 (unsigned long long)__entry->pos,
505 (unsigned long)__entry->length, (u16)__entry->flags)
508 TRACE_EVENT(gfs2_iomap_end,
510 TP_PROTO(const struct gfs2_inode *ip, struct iomap *iomap, int ret),
512 TP_ARGS(ip, iomap, ret),
515 __field( dev_t, dev )
517 __field( loff_t, offset )
518 __field( ssize_t, length )
519 __field( sector_t, pblock )
520 __field( u16, flags )
526 __entry->dev = ip->i_gl->gl_name.ln_sbd->sd_vfs->s_dev;
527 __entry->inum = ip->i_no_addr;
528 __entry->offset = iomap->offset;
529 __entry->length = iomap->length;
530 __entry->pblock = iomap->addr == IOMAP_NULL_ADDR ? 0 :
531 (iomap->addr >> ip->i_inode.i_blkbits);
532 __entry->flags = iomap->flags;
533 __entry->type = iomap->type;
537 TP_printk("%u,%u bmap %llu iomap end %llu/%lu to %llu ty:%d flags:%08x rc:%d",
538 MAJOR(__entry->dev), MINOR(__entry->dev),
539 (unsigned long long)__entry->inum,
540 (unsigned long long)__entry->offset,
541 (unsigned long)__entry->length,
542 (long long)__entry->pblock,
544 (u16)__entry->flags, __entry->ret)
547 /* Keep track of blocks as they are allocated/freed */
548 TRACE_EVENT(gfs2_block_alloc,
550 TP_PROTO(const struct gfs2_inode *ip, struct gfs2_rgrpd *rgd,
551 u64 block, unsigned len, u8 block_state),
553 TP_ARGS(ip, rgd, block, len, block_state),
556 __field( dev_t, dev )
557 __field( u64, start )
560 __field( u8, block_state )
561 __field( u64, rd_addr )
562 __field( u32, rd_free_clone )
563 __field( u32, rd_requested )
564 __field( u32, rd_reserved )
568 __entry->dev = rgd->rd_gl->gl_name.ln_sbd->sd_vfs->s_dev;
569 __entry->start = block;
570 __entry->inum = ip->i_no_addr;
572 __entry->block_state = block_state;
573 __entry->rd_addr = rgd->rd_addr;
574 __entry->rd_free_clone = rgd->rd_free_clone;
575 __entry->rd_requested = rgd->rd_requested;
576 __entry->rd_reserved = rgd->rd_reserved;
579 TP_printk("%u,%u bmap %llu alloc %llu/%lu %s rg:%llu rf:%u rq:%u rr:%u",
580 MAJOR(__entry->dev), MINOR(__entry->dev),
581 (unsigned long long)__entry->inum,
582 (unsigned long long)__entry->start,
583 (unsigned long)__entry->len,
584 block_state_name(__entry->block_state),
585 (unsigned long long)__entry->rd_addr,
586 __entry->rd_free_clone,
587 __entry->rd_requested,
588 __entry->rd_reserved)
591 /* Keep track of multi-block reservations as they are allocated/freed */
594 TP_PROTO(const struct gfs2_blkreserv *rs, u8 func),
599 __field( dev_t, dev )
600 __field( u64, rd_addr )
601 __field( u32, rd_free_clone )
602 __field( u32, rd_requested )
603 __field( u32, rd_reserved )
605 __field( u64, start )
606 __field( u32, requested )
607 __field( u32, reserved )
612 __entry->dev = rs->rs_rgd->rd_sbd->sd_vfs->s_dev;
613 __entry->rd_addr = rs->rs_rgd->rd_addr;
614 __entry->rd_free_clone = rs->rs_rgd->rd_free_clone;
615 __entry->rd_requested = rs->rs_rgd->rd_requested;
616 __entry->rd_reserved = rs->rs_rgd->rd_reserved;
617 __entry->inum = container_of(rs, struct gfs2_inode,
619 __entry->start = rs->rs_start;
620 __entry->requested = rs->rs_requested;
621 __entry->reserved = rs->rs_reserved;
622 __entry->func = func;
625 TP_printk("%u,%u bmap %llu resrv %llu rg:%llu rf:%u rq:%u rr:%u %s q:%u r:%u",
626 MAJOR(__entry->dev), MINOR(__entry->dev),
627 (unsigned long long)__entry->inum,
628 (unsigned long long)__entry->start,
629 (unsigned long long)__entry->rd_addr,
630 __entry->rd_free_clone,
631 __entry->rd_requested,
632 __entry->rd_reserved,
633 rs_func_name(__entry->func),
638 #endif /* _TRACE_GFS2_H */
640 /* This part must be outside protection */
641 #undef TRACE_INCLUDE_PATH
642 #define TRACE_INCLUDE_PATH .
643 #define TRACE_INCLUDE_FILE trace_gfs2
644 #include <trace/define_trace.h>