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