Commit | Line | Data |
---|---|---|
d0b6e04a LZ |
1 | #undef TRACE_SYSTEM |
2 | #define TRACE_SYSTEM gfs2 | |
3 | ||
63997775 SW |
4 | #if !defined(_TRACE_GFS2_H) || defined(TRACE_HEADER_MULTI_READ) |
5 | #define _TRACE_GFS2_H | |
6 | ||
7 | #include <linux/tracepoint.h> | |
8 | ||
63997775 SW |
9 | #include <linux/fs.h> |
10 | #include <linux/buffer_head.h> | |
11 | #include <linux/dlmconstants.h> | |
12 | #include <linux/gfs2_ondisk.h> | |
c83ae9ca | 13 | #include <linux/writeback.h> |
a245769f | 14 | #include <linux/ktime.h> |
63997775 SW |
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" }, \ | |
7b5e3d5f | 44 | {(1UL << GLF_FROZEN), "F" }, \ |
627c10b7 SW |
45 | {(1UL << GLF_QUEUED), "q" }, \ |
46 | {(1UL << GLF_LRU), "L" }, \ | |
a245769f SW |
47 | {(1UL << GLF_OBJECT), "o" }, \ |
48 | {(1UL << GLF_BLOCKING), "b" }) | |
63997775 SW |
49 | |
50 | #ifndef NUMPTY | |
51 | #define NUMPTY | |
52 | static 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) */ | |
77 | TRACE_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); | |
627c10b7 | 102 | __entry->flags = gl->gl_flags | (gl->gl_object ? (1UL<<GLF_OBJECT) : 0); |
63997775 SW |
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 */ | |
116 | TRACE_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); | |
627c10b7 | 135 | __entry->flags = gl->gl_flags | (gl->gl_object ? (1UL<<GLF_OBJECT) : 0); |
63997775 SW |
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 */ | |
148 | TRACE_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); | |
627c10b7 | 169 | __entry->flags = gl->gl_flags | (gl->gl_object ? (1UL<<GLF_OBJECT) : 0); |
63997775 SW |
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 */ | |
182 | TRACE_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 */ | |
212 | TRACE_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 | ||
a245769f SW |
241 | /* DLM sends a reply to GFS2 */ |
242 | TRACE_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 | ||
63997775 SW |
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 */ | |
306 | TRACE_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 */ | |
337 | TRACE_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 */ | |
362 | TRACE_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 | ||
c83ae9ca SW |
382 | /* Writing back the AIL */ |
383 | TRACE_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 | ||
63997775 SW |
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 */ | |
418 | TRACE_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 */ | |
458 | TRACE_EVENT(gfs2_block_alloc, | |
459 | ||
41db1ab9 BP |
460 | TP_PROTO(const struct gfs2_inode *ip, struct gfs2_rgrpd *rgd, |
461 | u64 block, unsigned len, u8 block_state), | |
63997775 | 462 | |
41db1ab9 | 463 | TP_ARGS(ip, rgd, block, len, block_state), |
63997775 SW |
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 ) | |
41db1ab9 BP |
471 | __field( u64, rd_addr ) |
472 | __field( u32, rd_free_clone ) | |
63997775 SW |
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; | |
41db1ab9 BP |
481 | __entry->rd_addr = rgd->rd_addr; |
482 | __entry->rd_free_clone = rgd->rd_free_clone; | |
63997775 SW |
483 | ), |
484 | ||
41db1ab9 | 485 | TP_printk("%u,%u bmap %llu alloc %llu/%lu %s rg:%llu rf:%u", |
63997775 SW |
486 | MAJOR(__entry->dev), MINOR(__entry->dev), |
487 | (unsigned long long)__entry->inum, | |
488 | (unsigned long long)__entry->start, | |
489 | (unsigned long)__entry->len, | |
41db1ab9 BP |
490 | block_state_name(__entry->block_state), |
491 | (unsigned long long)__entry->rd_addr, | |
492 | __entry->rd_free_clone) | |
63997775 SW |
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 . | |
d0b6e04a | 500 | #define TRACE_INCLUDE_FILE trace_gfs2 |
63997775 SW |
501 | #include <trace/define_trace.h> |
502 |