Linux Kernel  3.7.1
 All Data Structures Namespaces Files Functions Variables Typedefs Enumerations Enumerator Macros Groups Pages
trace_gfs2.h
Go to the documentation of this file.
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 = 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 */
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 
Generated on Thu Jan 10 2013 14:47:20 for Linux Kernel by   doxygen 1.8.2