linux/fs/gfs2/trace_gfs2.h
<<
>>
Prefs
   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
  64static 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) */
  89TRACE_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 */
 128TRACE_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 */
 160TRACE_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 */
 194TRACE_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 */
 224TRACE_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 */
 254TRACE_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 */
 318TRACE_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 */
 349TRACE_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 */
 374TRACE_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 */
 395TRACE_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 */
 430TRACE_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 */
 470TRACE_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            = ip->i_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 */
 510TRACE_EVENT(gfs2_rs,
 511
 512        TP_PROTO(const struct gfs2_inode *ip, const struct gfs2_blkreserv *rs,
 513                 u8 func),
 514
 515        TP_ARGS(ip, rs, func),
 516
 517        TP_STRUCT__entry(
 518                __field(        dev_t,  dev                     )
 519                __field(        u64,    rd_addr                 )
 520                __field(        u32,    rd_free_clone           )
 521                __field(        u32,    rd_reserved             )
 522                __field(        u64,    inum                    )
 523                __field(        u64,    start                   )
 524                __field(        u32,    free                    )
 525                __field(        u8,     func                    )
 526        ),
 527
 528        TP_fast_assign(
 529                __entry->dev            = rs->rs_rgd ? rs->rs_rgd->rd_sbd->sd_vfs->s_dev : 0;
 530                __entry->rd_addr        = rs->rs_rgd ? rs->rs_rgd->rd_addr : 0;
 531                __entry->rd_free_clone  = rs->rs_rgd ? rs->rs_rgd->rd_free_clone : 0;
 532                __entry->rd_reserved    = rs->rs_rgd ? rs->rs_rgd->rd_reserved : 0;
 533                __entry->inum           = ip ? ip->i_no_addr : 0;
 534                __entry->start          = gfs2_rs_startblk(rs);
 535                __entry->free           = rs->rs_free;
 536                __entry->func           = func;
 537        ),
 538
 539        TP_printk("%u,%u bmap %llu resrv %llu rg:%llu rf:%lu rr:%lu %s "
 540                  "f:%lu",
 541                  MAJOR(__entry->dev), MINOR(__entry->dev),
 542                  (unsigned long long)__entry->inum,
 543                  (unsigned long long)__entry->start,
 544                  (unsigned long long)__entry->rd_addr,
 545                  (unsigned long)__entry->rd_free_clone,
 546                  (unsigned long)__entry->rd_reserved,
 547                  rs_func_name(__entry->func), (unsigned long)__entry->free)
 548);
 549
 550#endif /* _TRACE_GFS2_H */
 551
 552/* This part must be outside protection */
 553#undef TRACE_INCLUDE_PATH
 554#define TRACE_INCLUDE_PATH .
 555#define TRACE_INCLUDE_FILE trace_gfs2
 556#include <trace/define_trace.h>
 557
 558
lxr.linux.no kindly hosted by Redpill Linpro AS, provider of Linux consulting and operations services since 1995.