trace_gfs2.h 13 KB

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