Linux Audio

Check our new training course

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