xref: /openbmc/linux/fs/gfs2/trace_gfs2.h (revision c7cbb022)
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 "incore.h"
15 #include "glock.h"
16 
17 #define dlm_state_name(nn) { DLM_LOCK_##nn, #nn }
18 #define glock_trace_name(x) __print_symbolic(x,		\
19 			    dlm_state_name(IV),		\
20 			    dlm_state_name(NL),		\
21 			    dlm_state_name(CR),		\
22 			    dlm_state_name(CW),		\
23 			    dlm_state_name(PR),		\
24 			    dlm_state_name(PW),		\
25 			    dlm_state_name(EX))
26 
27 #define block_state_name(x) __print_symbolic(x,			\
28 			    { GFS2_BLKST_FREE, "free" },	\
29 			    { GFS2_BLKST_USED, "used" },	\
30 			    { GFS2_BLKST_DINODE, "dinode" },	\
31 			    { GFS2_BLKST_UNLINKED, "unlinked" })
32 
33 #define show_glock_flags(flags) __print_flags(flags, "",	\
34 	{(1UL << GLF_LOCK),			"l" },		\
35 	{(1UL << GLF_DEMOTE),			"D" },		\
36 	{(1UL << GLF_PENDING_DEMOTE),		"d" },		\
37 	{(1UL << GLF_DEMOTE_IN_PROGRESS),	"p" },		\
38 	{(1UL << GLF_DIRTY),			"y" },		\
39 	{(1UL << GLF_LFLUSH),			"f" },		\
40 	{(1UL << GLF_INVALIDATE_IN_PROGRESS),	"i" },		\
41 	{(1UL << GLF_REPLY_PENDING),		"r" },		\
42 	{(1UL << GLF_INITIAL),			"I" },		\
43 	{(1UL << GLF_FROZEN),			"F" },		\
44 	{(1UL << GLF_QUEUED),			"q" },		\
45 	{(1UL << GLF_LRU),			"L" },		\
46 	{(1UL << GLF_OBJECT),			"o" })
47 
48 #ifndef NUMPTY
49 #define NUMPTY
50 static inline u8 glock_trace_state(unsigned int state)
51 {
52 	switch(state) {
53 	case LM_ST_SHARED:
54 		return DLM_LOCK_PR;
55 	case LM_ST_DEFERRED:
56 		return DLM_LOCK_CW;
57 	case LM_ST_EXCLUSIVE:
58 		return DLM_LOCK_EX;
59 	}
60 	return DLM_LOCK_NL;
61 }
62 #endif
63 
64 /* Section 1 - Locking
65  *
66  * Objectives:
67  * Latency: Remote demote request to state change
68  * Latency: Local lock request to state change
69  * Latency: State change to lock grant
70  * Correctness: Ordering of local lock state vs. I/O requests
71  * Correctness: Responses to remote demote requests
72  */
73 
74 /* General glock state change (DLM lock request completes) */
75 TRACE_EVENT(gfs2_glock_state_change,
76 
77 	TP_PROTO(const struct gfs2_glock *gl, unsigned int new_state),
78 
79 	TP_ARGS(gl, new_state),
80 
81 	TP_STRUCT__entry(
82 		__field(	dev_t,	dev			)
83 		__field(	u64,	glnum			)
84 		__field(	u32,	gltype			)
85 		__field(	u8,	cur_state		)
86 		__field(	u8,	new_state		)
87 		__field(	u8,	dmt_state		)
88 		__field(	u8,	tgt_state		)
89 		__field(	unsigned long,	flags		)
90 	),
91 
92 	TP_fast_assign(
93 		__entry->dev		= gl->gl_sbd->sd_vfs->s_dev;
94 		__entry->glnum		= gl->gl_name.ln_number;
95 		__entry->gltype		= gl->gl_name.ln_type;
96 		__entry->cur_state	= glock_trace_state(gl->gl_state);
97 		__entry->new_state	= glock_trace_state(new_state);
98 		__entry->tgt_state	= glock_trace_state(gl->gl_target);
99 		__entry->dmt_state	= glock_trace_state(gl->gl_demote_state);
100 		__entry->flags		= gl->gl_flags | (gl->gl_object ? (1UL<<GLF_OBJECT) : 0);
101 	),
102 
103 	TP_printk("%u,%u glock %d:%lld state %s to %s tgt:%s dmt:%s flags:%s",
104 		  MAJOR(__entry->dev), MINOR(__entry->dev), __entry->gltype,
105 		 (unsigned long long)__entry->glnum,
106 		  glock_trace_name(__entry->cur_state),
107 		  glock_trace_name(__entry->new_state),
108 		  glock_trace_name(__entry->tgt_state),
109 		  glock_trace_name(__entry->dmt_state),
110 		  show_glock_flags(__entry->flags))
111 );
112 
113 /* State change -> unlocked, glock is being deallocated */
114 TRACE_EVENT(gfs2_glock_put,
115 
116 	TP_PROTO(const struct gfs2_glock *gl),
117 
118 	TP_ARGS(gl),
119 
120 	TP_STRUCT__entry(
121 		__field(        dev_t,  dev                     )
122 		__field(	u64,	glnum			)
123 		__field(	u32,	gltype			)
124 		__field(	u8,	cur_state		)
125 		__field(	unsigned long,	flags		)
126 	),
127 
128 	TP_fast_assign(
129 		__entry->dev		= gl->gl_sbd->sd_vfs->s_dev;
130 		__entry->gltype		= gl->gl_name.ln_type;
131 		__entry->glnum		= gl->gl_name.ln_number;
132 		__entry->cur_state	= glock_trace_state(gl->gl_state);
133 		__entry->flags		= gl->gl_flags  | (gl->gl_object ? (1UL<<GLF_OBJECT) : 0);
134 	),
135 
136 	TP_printk("%u,%u glock %d:%lld state %s => %s flags:%s",
137 		  MAJOR(__entry->dev), MINOR(__entry->dev),
138                   __entry->gltype, (unsigned long long)__entry->glnum,
139                   glock_trace_name(__entry->cur_state),
140 		  glock_trace_name(DLM_LOCK_IV),
141 		  show_glock_flags(__entry->flags))
142 
143 );
144 
145 /* Callback (local or remote) requesting lock demotion */
146 TRACE_EVENT(gfs2_demote_rq,
147 
148 	TP_PROTO(const struct gfs2_glock *gl),
149 
150 	TP_ARGS(gl),
151 
152 	TP_STRUCT__entry(
153 		__field(        dev_t,  dev                     )
154 		__field(	u64,	glnum			)
155 		__field(	u32,	gltype			)
156 		__field(	u8,	cur_state		)
157 		__field(	u8,	dmt_state		)
158 		__field(	unsigned long,	flags		)
159 	),
160 
161 	TP_fast_assign(
162 		__entry->dev		= gl->gl_sbd->sd_vfs->s_dev;
163 		__entry->gltype		= gl->gl_name.ln_type;
164 		__entry->glnum		= gl->gl_name.ln_number;
165 		__entry->cur_state	= glock_trace_state(gl->gl_state);
166 		__entry->dmt_state	= glock_trace_state(gl->gl_demote_state);
167 		__entry->flags		= gl->gl_flags  | (gl->gl_object ? (1UL<<GLF_OBJECT) : 0);
168 	),
169 
170 	TP_printk("%u,%u glock %d:%lld demote %s to %s flags:%s",
171 		  MAJOR(__entry->dev), MINOR(__entry->dev), __entry->gltype,
172 		  (unsigned long long)__entry->glnum,
173                   glock_trace_name(__entry->cur_state),
174                   glock_trace_name(__entry->dmt_state),
175 		  show_glock_flags(__entry->flags))
176 
177 );
178 
179 /* Promotion/grant of a glock */
180 TRACE_EVENT(gfs2_promote,
181 
182 	TP_PROTO(const struct gfs2_holder *gh, int first),
183 
184 	TP_ARGS(gh, first),
185 
186 	TP_STRUCT__entry(
187 		__field(        dev_t,  dev                     )
188 		__field(	u64,	glnum			)
189 		__field(	u32,	gltype			)
190 		__field(	int,	first			)
191 		__field(	u8,	state			)
192 	),
193 
194 	TP_fast_assign(
195 		__entry->dev	= gh->gh_gl->gl_sbd->sd_vfs->s_dev;
196 		__entry->glnum	= gh->gh_gl->gl_name.ln_number;
197 		__entry->gltype	= gh->gh_gl->gl_name.ln_type;
198 		__entry->first	= first;
199 		__entry->state	= glock_trace_state(gh->gh_state);
200 	),
201 
202 	TP_printk("%u,%u glock %u:%llu promote %s %s",
203 		  MAJOR(__entry->dev), MINOR(__entry->dev), __entry->gltype,
204 		  (unsigned long long)__entry->glnum,
205 		  __entry->first ? "first": "other",
206 		  glock_trace_name(__entry->state))
207 );
208 
209 /* Queue/dequeue a lock request */
210 TRACE_EVENT(gfs2_glock_queue,
211 
212 	TP_PROTO(const struct gfs2_holder *gh, int queue),
213 
214 	TP_ARGS(gh, queue),
215 
216 	TP_STRUCT__entry(
217 		__field(        dev_t,  dev                     )
218 		__field(	u64,	glnum			)
219 		__field(	u32,	gltype			)
220 		__field(	int,	queue			)
221 		__field(	u8,	state			)
222 	),
223 
224 	TP_fast_assign(
225 		__entry->dev	= gh->gh_gl->gl_sbd->sd_vfs->s_dev;
226 		__entry->glnum	= gh->gh_gl->gl_name.ln_number;
227 		__entry->gltype	= gh->gh_gl->gl_name.ln_type;
228 		__entry->queue	= queue;
229 		__entry->state	= glock_trace_state(gh->gh_state);
230 	),
231 
232 	TP_printk("%u,%u glock %u:%llu %squeue %s",
233 		  MAJOR(__entry->dev), MINOR(__entry->dev), __entry->gltype,
234 		  (unsigned long long)__entry->glnum,
235 		  __entry->queue ? "" : "de",
236 		  glock_trace_name(__entry->state))
237 );
238 
239 /* Section 2 - Log/journal
240  *
241  * Objectives:
242  * Latency: Log flush time
243  * Correctness: pin/unpin vs. disk I/O ordering
244  * Performance: Log usage stats
245  */
246 
247 /* Pin/unpin a block in the log */
248 TRACE_EVENT(gfs2_pin,
249 
250 	TP_PROTO(const struct gfs2_bufdata *bd, int pin),
251 
252 	TP_ARGS(bd, pin),
253 
254 	TP_STRUCT__entry(
255 		__field(        dev_t,  dev                     )
256 		__field(	int,	pin			)
257 		__field(	u32,	len			)
258 		__field(	sector_t,	block		)
259 		__field(	u64,	ino			)
260 	),
261 
262 	TP_fast_assign(
263 		__entry->dev		= bd->bd_gl->gl_sbd->sd_vfs->s_dev;
264 		__entry->pin		= pin;
265 		__entry->len		= bd->bd_bh->b_size;
266 		__entry->block		= bd->bd_bh->b_blocknr;
267 		__entry->ino		= bd->bd_gl->gl_name.ln_number;
268 	),
269 
270 	TP_printk("%u,%u log %s %llu/%lu inode %llu",
271 		  MAJOR(__entry->dev), MINOR(__entry->dev),
272 		  __entry->pin ? "pin" : "unpin",
273 		  (unsigned long long)__entry->block,
274 		  (unsigned long)__entry->len,
275 		  (unsigned long long)__entry->ino)
276 );
277 
278 /* Flushing the log */
279 TRACE_EVENT(gfs2_log_flush,
280 
281 	TP_PROTO(const struct gfs2_sbd *sdp, int start),
282 
283 	TP_ARGS(sdp, start),
284 
285 	TP_STRUCT__entry(
286 		__field(        dev_t,  dev                     )
287 		__field(	int,	start			)
288 		__field(	u64,	log_seq			)
289 	),
290 
291 	TP_fast_assign(
292 		__entry->dev            = sdp->sd_vfs->s_dev;
293 		__entry->start		= start;
294 		__entry->log_seq	= sdp->sd_log_sequence;
295 	),
296 
297 	TP_printk("%u,%u log flush %s %llu",
298 		  MAJOR(__entry->dev), MINOR(__entry->dev),
299 		  __entry->start ? "start" : "end",
300 		  (unsigned long long)__entry->log_seq)
301 );
302 
303 /* Reserving/releasing blocks in the log */
304 TRACE_EVENT(gfs2_log_blocks,
305 
306 	TP_PROTO(const struct gfs2_sbd *sdp, int blocks),
307 
308 	TP_ARGS(sdp, blocks),
309 
310 	TP_STRUCT__entry(
311 		__field(        dev_t,  dev                     )
312 		__field(	int,	blocks			)
313 	),
314 
315 	TP_fast_assign(
316 		__entry->dev		= sdp->sd_vfs->s_dev;
317 		__entry->blocks		= blocks;
318 	),
319 
320 	TP_printk("%u,%u log reserve %d", MAJOR(__entry->dev),
321 		  MINOR(__entry->dev), __entry->blocks)
322 );
323 
324 /* Writing back the AIL */
325 TRACE_EVENT(gfs2_ail_flush,
326 
327 	TP_PROTO(const struct gfs2_sbd *sdp, const struct writeback_control *wbc, int start),
328 
329 	TP_ARGS(sdp, wbc, start),
330 
331 	TP_STRUCT__entry(
332 		__field(	dev_t,	dev			)
333 		__field(	int, start			)
334 		__field(	int, sync_mode			)
335 		__field(	long, nr_to_write		)
336 	),
337 
338 	TP_fast_assign(
339 		__entry->dev		= sdp->sd_vfs->s_dev;
340 		__entry->start		= start;
341 		__entry->sync_mode	= wbc->sync_mode;
342 		__entry->nr_to_write	= wbc->nr_to_write;
343 	),
344 
345 	TP_printk("%u,%u ail flush %s %s %ld", MAJOR(__entry->dev),
346 		  MINOR(__entry->dev), __entry->start ? "start" : "end",
347 		  __entry->sync_mode == WB_SYNC_ALL ? "all" : "none",
348 		  __entry->nr_to_write)
349 );
350 
351 /* Section 3 - bmap
352  *
353  * Objectives:
354  * Latency: Bmap request time
355  * Performance: Block allocator tracing
356  * Correctness: Test of disard generation vs. blocks allocated
357  */
358 
359 /* Map an extent of blocks, possibly a new allocation */
360 TRACE_EVENT(gfs2_bmap,
361 
362 	TP_PROTO(const struct gfs2_inode *ip, const struct buffer_head *bh,
363 		sector_t lblock, int create, int errno),
364 
365 	TP_ARGS(ip, bh, lblock, create, errno),
366 
367 	TP_STRUCT__entry(
368 		__field(        dev_t,  dev                     )
369 		__field(	sector_t, lblock		)
370 		__field(	sector_t, pblock		)
371 		__field(	u64,	inum			)
372 		__field(	unsigned long, state		)
373 		__field(	u32,	len			)
374 		__field(	int,	create			)
375 		__field(	int,	errno			)
376 	),
377 
378 	TP_fast_assign(
379 		__entry->dev            = ip->i_gl->gl_sbd->sd_vfs->s_dev;
380 		__entry->lblock		= lblock;
381 		__entry->pblock		= buffer_mapped(bh) ?  bh->b_blocknr : 0;
382 		__entry->inum		= ip->i_no_addr;
383 		__entry->state		= bh->b_state;
384 		__entry->len		= bh->b_size;
385 		__entry->create		= create;
386 		__entry->errno		= errno;
387 	),
388 
389 	TP_printk("%u,%u bmap %llu map %llu/%lu to %llu flags:%08lx %s %d",
390 		  MAJOR(__entry->dev), MINOR(__entry->dev),
391 		  (unsigned long long)__entry->inum,
392 		  (unsigned long long)__entry->lblock,
393 		  (unsigned long)__entry->len,
394 		  (unsigned long long)__entry->pblock,
395 		  __entry->state, __entry->create ? "create " : "nocreate",
396 		  __entry->errno)
397 );
398 
399 /* Keep track of blocks as they are allocated/freed */
400 TRACE_EVENT(gfs2_block_alloc,
401 
402 	TP_PROTO(const struct gfs2_inode *ip, u64 block, unsigned len,
403 		u8 block_state),
404 
405 	TP_ARGS(ip, block, len, block_state),
406 
407 	TP_STRUCT__entry(
408 		__field(        dev_t,  dev                     )
409 		__field(	u64,	start			)
410 		__field(	u64,	inum			)
411 		__field(	u32,	len			)
412 		__field(	u8,	block_state		)
413 	),
414 
415 	TP_fast_assign(
416 		__entry->dev		= ip->i_gl->gl_sbd->sd_vfs->s_dev;
417 		__entry->start		= block;
418 		__entry->inum		= ip->i_no_addr;
419 		__entry->len		= len;
420 		__entry->block_state	= block_state;
421 	),
422 
423 	TP_printk("%u,%u bmap %llu alloc %llu/%lu %s",
424 		  MAJOR(__entry->dev), MINOR(__entry->dev),
425 		  (unsigned long long)__entry->inum,
426 		  (unsigned long long)__entry->start,
427 		  (unsigned long)__entry->len,
428 		  block_state_name(__entry->block_state))
429 );
430 
431 #endif /* _TRACE_GFS2_H */
432 
433 /* This part must be outside protection */
434 #undef TRACE_INCLUDE_PATH
435 #define TRACE_INCLUDE_PATH .
436 #define TRACE_INCLUDE_FILE trace_gfs2
437 #include <trace/define_trace.h>
438 
439