1 /* SPDX-License-Identifier: GPL-2.0 */ 2 #undef TRACE_SYSTEM 3 #define TRACE_SYSTEM gfs2 4 5 #if !defined(_TRACE_GFS2_H) || defined(TRACE_HEADER_MULTI_READ) 6 #define _TRACE_GFS2_H 7 8 #include <linux/tracepoint.h> 9 10 #include <linux/fs.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 "incore.h" 17 #include "glock.h" 18 #include "rgrp.h" 19 20 #define dlm_state_name(nn) { DLM_LOCK_##nn, #nn } 21 #define glock_trace_name(x) __print_symbolic(x, \ 22 dlm_state_name(IV), \ 23 dlm_state_name(NL), \ 24 dlm_state_name(CR), \ 25 dlm_state_name(CW), \ 26 dlm_state_name(PR), \ 27 dlm_state_name(PW), \ 28 dlm_state_name(EX)) 29 30 #define block_state_name(x) __print_symbolic(x, \ 31 { GFS2_BLKST_FREE, "free" }, \ 32 { GFS2_BLKST_USED, "used" }, \ 33 { GFS2_BLKST_DINODE, "dinode" }, \ 34 { GFS2_BLKST_UNLINKED, "unlinked" }) 35 36 #define TRACE_RS_DELETE 0 37 #define TRACE_RS_TREEDEL 1 38 #define TRACE_RS_INSERT 2 39 #define TRACE_RS_CLAIM 3 40 41 #define rs_func_name(x) __print_symbolic(x, \ 42 { 0, "del " }, \ 43 { 1, "tdel" }, \ 44 { 2, "ins " }, \ 45 { 3, "clm " }) 46 47 #define show_glock_flags(flags) __print_flags(flags, "", \ 48 {(1UL << GLF_LOCK), "l" }, \ 49 {(1UL << GLF_DEMOTE), "D" }, \ 50 {(1UL << GLF_PENDING_DEMOTE), "d" }, \ 51 {(1UL << GLF_DEMOTE_IN_PROGRESS), "p" }, \ 52 {(1UL << GLF_DIRTY), "y" }, \ 53 {(1UL << GLF_LFLUSH), "f" }, \ 54 {(1UL << GLF_INVALIDATE_IN_PROGRESS), "i" }, \ 55 {(1UL << GLF_REPLY_PENDING), "r" }, \ 56 {(1UL << GLF_INITIAL), "I" }, \ 57 {(1UL << GLF_FROZEN), "F" }, \ 58 {(1UL << GLF_QUEUED), "q" }, \ 59 {(1UL << GLF_LRU), "L" }, \ 60 {(1UL << GLF_OBJECT), "o" }, \ 61 {(1UL << GLF_BLOCKING), "b" }) 62 63 #ifndef NUMPTY 64 #define NUMPTY 65 static inline u8 glock_trace_state(unsigned int state) 66 { 67 switch(state) { 68 case LM_ST_SHARED: 69 return DLM_LOCK_PR; 70 case LM_ST_DEFERRED: 71 return DLM_LOCK_CW; 72 case LM_ST_EXCLUSIVE: 73 return DLM_LOCK_EX; 74 } 75 return DLM_LOCK_NL; 76 } 77 #endif 78 79 /* Section 1 - Locking 80 * 81 * Objectives: 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 87 */ 88 89 /* General glock state change (DLM lock request completes) */ 90 TRACE_EVENT(gfs2_glock_state_change, 91 92 TP_PROTO(const struct gfs2_glock *gl, unsigned int new_state), 93 94 TP_ARGS(gl, new_state), 95 96 TP_STRUCT__entry( 97 __field( dev_t, dev ) 98 __field( u64, glnum ) 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 ) 105 ), 106 107 TP_fast_assign( 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); 116 ), 117 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)) 126 ); 127 128 /* State change -> unlocked, glock is being deallocated */ 129 TRACE_EVENT(gfs2_glock_put, 130 131 TP_PROTO(const struct gfs2_glock *gl), 132 133 TP_ARGS(gl), 134 135 TP_STRUCT__entry( 136 __field( dev_t, dev ) 137 __field( u64, glnum ) 138 __field( u32, gltype ) 139 __field( u8, cur_state ) 140 __field( unsigned long, flags ) 141 ), 142 143 TP_fast_assign( 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); 149 ), 150 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)) 157 158 ); 159 160 /* Callback (local or remote) requesting lock demotion */ 161 TRACE_EVENT(gfs2_demote_rq, 162 163 TP_PROTO(const struct gfs2_glock *gl, bool remote), 164 165 TP_ARGS(gl, remote), 166 167 TP_STRUCT__entry( 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 ) 175 ), 176 177 TP_fast_assign( 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; 185 ), 186 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") 194 195 ); 196 197 /* Promotion/grant of a glock */ 198 TRACE_EVENT(gfs2_promote, 199 200 TP_PROTO(const struct gfs2_holder *gh, int first), 201 202 TP_ARGS(gh, first), 203 204 TP_STRUCT__entry( 205 __field( dev_t, dev ) 206 __field( u64, glnum ) 207 __field( u32, gltype ) 208 __field( int, first ) 209 __field( u8, state ) 210 ), 211 212 TP_fast_assign( 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); 218 ), 219 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)) 225 ); 226 227 /* Queue/dequeue a lock request */ 228 TRACE_EVENT(gfs2_glock_queue, 229 230 TP_PROTO(const struct gfs2_holder *gh, int queue), 231 232 TP_ARGS(gh, queue), 233 234 TP_STRUCT__entry( 235 __field( dev_t, dev ) 236 __field( u64, glnum ) 237 __field( u32, gltype ) 238 __field( int, queue ) 239 __field( u8, state ) 240 ), 241 242 TP_fast_assign( 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); 248 ), 249 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)) 255 ); 256 257 /* DLM sends a reply to GFS2 */ 258 TRACE_EVENT(gfs2_glock_lock_time, 259 260 TP_PROTO(const struct gfs2_glock *gl, s64 tdiff), 261 262 TP_ARGS(gl, tdiff), 263 264 TP_STRUCT__entry( 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 ) 271 __field( u64, srtt ) 272 __field( u64, srttvar ) 273 __field( u64, srttb ) 274 __field( u64, srttvarb ) 275 __field( u64, sirt ) 276 __field( u64, sirtvar ) 277 __field( u64, dcount ) 278 __field( u64, qcount ) 279 ), 280 281 TP_fast_assign( 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]; 296 ), 297 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) 311 ); 312 313 /* Section 2 - Log/journal 314 * 315 * Objectives: 316 * Latency: Log flush time 317 * Correctness: pin/unpin vs. disk I/O ordering 318 * Performance: Log usage stats 319 */ 320 321 /* Pin/unpin a block in the log */ 322 TRACE_EVENT(gfs2_pin, 323 324 TP_PROTO(const struct gfs2_bufdata *bd, int pin), 325 326 TP_ARGS(bd, pin), 327 328 TP_STRUCT__entry( 329 __field( dev_t, dev ) 330 __field( int, pin ) 331 __field( u32, len ) 332 __field( sector_t, block ) 333 __field( u64, ino ) 334 ), 335 336 TP_fast_assign( 337 __entry->dev = bd->bd_gl->gl_name.ln_sbd->sd_vfs->s_dev; 338 __entry->pin = pin; 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; 342 ), 343 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) 350 ); 351 352 /* Flushing the log */ 353 TRACE_EVENT(gfs2_log_flush, 354 355 TP_PROTO(const struct gfs2_sbd *sdp, int start), 356 357 TP_ARGS(sdp, start), 358 359 TP_STRUCT__entry( 360 __field( dev_t, dev ) 361 __field( int, start ) 362 __field( u64, log_seq ) 363 ), 364 365 TP_fast_assign( 366 __entry->dev = sdp->sd_vfs->s_dev; 367 __entry->start = start; 368 __entry->log_seq = sdp->sd_log_sequence; 369 ), 370 371 TP_printk("%u,%u log flush %s %llu", 372 MAJOR(__entry->dev), MINOR(__entry->dev), 373 __entry->start ? "start" : "end", 374 (unsigned long long)__entry->log_seq) 375 ); 376 377 /* Reserving/releasing blocks in the log */ 378 TRACE_EVENT(gfs2_log_blocks, 379 380 TP_PROTO(const struct gfs2_sbd *sdp, int blocks), 381 382 TP_ARGS(sdp, blocks), 383 384 TP_STRUCT__entry( 385 __field( dev_t, dev ) 386 __field( int, blocks ) 387 ), 388 389 TP_fast_assign( 390 __entry->dev = sdp->sd_vfs->s_dev; 391 __entry->blocks = blocks; 392 ), 393 394 TP_printk("%u,%u log reserve %d", MAJOR(__entry->dev), 395 MINOR(__entry->dev), __entry->blocks) 396 ); 397 398 /* Writing back the AIL */ 399 TRACE_EVENT(gfs2_ail_flush, 400 401 TP_PROTO(const struct gfs2_sbd *sdp, const struct writeback_control *wbc, int start), 402 403 TP_ARGS(sdp, wbc, start), 404 405 TP_STRUCT__entry( 406 __field( dev_t, dev ) 407 __field( int, start ) 408 __field( int, sync_mode ) 409 __field( long, nr_to_write ) 410 ), 411 412 TP_fast_assign( 413 __entry->dev = sdp->sd_vfs->s_dev; 414 __entry->start = start; 415 __entry->sync_mode = wbc->sync_mode; 416 __entry->nr_to_write = wbc->nr_to_write; 417 ), 418 419 TP_printk("%u,%u ail flush %s %s %ld", MAJOR(__entry->dev), 420 MINOR(__entry->dev), __entry->start ? "start" : "end", 421 __entry->sync_mode == WB_SYNC_ALL ? "all" : "none", 422 __entry->nr_to_write) 423 ); 424 425 /* Section 3 - bmap 426 * 427 * Objectives: 428 * Latency: Bmap request time 429 * Performance: Block allocator tracing 430 * Correctness: Test of disard generation vs. blocks allocated 431 */ 432 433 /* Map an extent of blocks, possibly a new allocation */ 434 TRACE_EVENT(gfs2_bmap, 435 436 TP_PROTO(const struct gfs2_inode *ip, const struct buffer_head *bh, 437 sector_t lblock, int create, int errno), 438 439 TP_ARGS(ip, bh, lblock, create, errno), 440 441 TP_STRUCT__entry( 442 __field( dev_t, dev ) 443 __field( sector_t, lblock ) 444 __field( sector_t, pblock ) 445 __field( u64, inum ) 446 __field( unsigned long, state ) 447 __field( u32, len ) 448 __field( int, create ) 449 __field( int, errno ) 450 ), 451 452 TP_fast_assign( 453 __entry->dev = ip->i_gl->gl_name.ln_sbd->sd_vfs->s_dev; 454 __entry->lblock = lblock; 455 __entry->pblock = buffer_mapped(bh) ? bh->b_blocknr : 0; 456 __entry->inum = ip->i_no_addr; 457 __entry->state = bh->b_state; 458 __entry->len = bh->b_size; 459 __entry->create = create; 460 __entry->errno = errno; 461 ), 462 463 TP_printk("%u,%u bmap %llu map %llu/%lu to %llu flags:%08lx %s %d", 464 MAJOR(__entry->dev), MINOR(__entry->dev), 465 (unsigned long long)__entry->inum, 466 (unsigned long long)__entry->lblock, 467 (unsigned long)__entry->len, 468 (unsigned long long)__entry->pblock, 469 __entry->state, __entry->create ? "create " : "nocreate", 470 __entry->errno) 471 ); 472 473 /* Keep track of blocks as they are allocated/freed */ 474 TRACE_EVENT(gfs2_block_alloc, 475 476 TP_PROTO(const struct gfs2_inode *ip, struct gfs2_rgrpd *rgd, 477 u64 block, unsigned len, u8 block_state), 478 479 TP_ARGS(ip, rgd, block, len, block_state), 480 481 TP_STRUCT__entry( 482 __field( dev_t, dev ) 483 __field( u64, start ) 484 __field( u64, inum ) 485 __field( u32, len ) 486 __field( u8, block_state ) 487 __field( u64, rd_addr ) 488 __field( u32, rd_free_clone ) 489 __field( u32, rd_reserved ) 490 ), 491 492 TP_fast_assign( 493 __entry->dev = rgd->rd_gl->gl_name.ln_sbd->sd_vfs->s_dev; 494 __entry->start = block; 495 __entry->inum = ip->i_no_addr; 496 __entry->len = len; 497 __entry->block_state = block_state; 498 __entry->rd_addr = rgd->rd_addr; 499 __entry->rd_free_clone = rgd->rd_free_clone; 500 __entry->rd_reserved = rgd->rd_reserved; 501 ), 502 503 TP_printk("%u,%u bmap %llu alloc %llu/%lu %s rg:%llu rf:%u rr:%lu", 504 MAJOR(__entry->dev), MINOR(__entry->dev), 505 (unsigned long long)__entry->inum, 506 (unsigned long long)__entry->start, 507 (unsigned long)__entry->len, 508 block_state_name(__entry->block_state), 509 (unsigned long long)__entry->rd_addr, 510 __entry->rd_free_clone, (unsigned long)__entry->rd_reserved) 511 ); 512 513 /* Keep track of multi-block reservations as they are allocated/freed */ 514 TRACE_EVENT(gfs2_rs, 515 516 TP_PROTO(const struct gfs2_blkreserv *rs, u8 func), 517 518 TP_ARGS(rs, func), 519 520 TP_STRUCT__entry( 521 __field( dev_t, dev ) 522 __field( u64, rd_addr ) 523 __field( u32, rd_free_clone ) 524 __field( u32, rd_reserved ) 525 __field( u64, inum ) 526 __field( u64, start ) 527 __field( u32, free ) 528 __field( u8, func ) 529 ), 530 531 TP_fast_assign( 532 __entry->dev = rs->rs_rbm.rgd->rd_sbd->sd_vfs->s_dev; 533 __entry->rd_addr = rs->rs_rbm.rgd->rd_addr; 534 __entry->rd_free_clone = rs->rs_rbm.rgd->rd_free_clone; 535 __entry->rd_reserved = rs->rs_rbm.rgd->rd_reserved; 536 __entry->inum = rs->rs_inum; 537 __entry->start = gfs2_rbm_to_block(&rs->rs_rbm); 538 __entry->free = rs->rs_free; 539 __entry->func = func; 540 ), 541 542 TP_printk("%u,%u bmap %llu resrv %llu rg:%llu rf:%lu rr:%lu %s f:%lu", 543 MAJOR(__entry->dev), MINOR(__entry->dev), 544 (unsigned long long)__entry->inum, 545 (unsigned long long)__entry->start, 546 (unsigned long long)__entry->rd_addr, 547 (unsigned long)__entry->rd_free_clone, 548 (unsigned long)__entry->rd_reserved, 549 rs_func_name(__entry->func), (unsigned long)__entry->free) 550 ); 551 552 #endif /* _TRACE_GFS2_H */ 553 554 /* This part must be outside protection */ 555 #undef TRACE_INCLUDE_PATH 556 #define TRACE_INCLUDE_PATH . 557 #define TRACE_INCLUDE_FILE trace_gfs2 558 #include <trace/define_trace.h> 559 560