This patch adds a tracepoint for transaction events of nilfs. With the tracepoint, these events can be tracked: begin, abort, commit, trylock, lock, and unlock. Basically, these events have corresponding functions e.g. begin event corresponds nilfs_transaction_begin(). The unlock event is an exception. It corresponds to the iteration in nilfs_transaction_lock(). Only one tracepoint is introcued: nilfs2_transaction_transition. The above events are distinguished with newly introduced enum. With this tracepoint, we can analyse a critical section of segment constructoin. Sample output by tpoint of perf-tools: cp-4457 [000] ...1 63.266220: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800bf5ccc58 count = 1 flags = 9 state = BEGIN cp-4457 [000] ...1 63.266221: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800bf5ccc58 count = 0 flags = 9 state = COMMIT cp-4457 [000] ...1 63.266221: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800bf5ccc58 count = 0 flags = 9 state = COMMIT segctord-4371 [001] ...1 68.261196: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800b889bdf8 count = 0 flags = 10 state = TRYLOCK segctord-4371 [001] ...1 68.261280: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800b889bdf8 count = 0 flags = 10 state = LOCK segctord-4371 [001] ...1 68.261877: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800b889bdf8 count = 1 flags = 10 state = BEGIN segctord-4371 [001] ...1 68.262116: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800b889bdf8 count = 0 flags = 18 state = COMMIT segctord-4371 [001] ...1 68.265032: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800b889bdf8 count = 0 flags = 18 state = UNLOCK segctord-4371 [001] ...1 132.376847: nilfs2_transaction_transition: sb = ffff8802112b8800 ti = ffff8800b889bdf8 count = 0 flags = 10 state = TRYLOCK This patch also does trivial cleaning of comma usage in collection stage transition event for consistent coding style.
Unified · Split
| @@ -214,11 +214,18 @@ int nilfs_transaction_begin(struct super_block *sb, · 213 unmodified lines | ||
| 214 | 214 | { |
| 215 | 215 | struct the_nilfs *nilfs; |
| 216 | 216 | int ret = nilfs_prepare_segment_lock(ti); |
| 217 | + struct nilfs_transaction_info *trace_ti; | |
| 217 | 218 | |
| 218 | 219 | if (unlikely(ret < 0)) |
| 219 | 220 | return ret; |
| 220 | − if (ret > 0) | |
| 221 | + if (ret > 0) { | |
| 222 | + trace_ti = current->journal_info; | |
| 223 | + | |
| 224 | + trace_nilfs2_transaction_transition(sb, trace_ti, | |
| 225 | + trace_ti->ti_count, trace_ti->ti_flags, | |
| 226 | + TRACE_NILFS2_TRANSACTION_BEGIN); | |
| 221 | 227 | return 0; |
| 228 | + } | |
| 222 | 229 | |
| 223 | 230 | sb_start_intwrite(sb); |
| 224 | 231 | |
| @@ -229,6 +236,11 @@ int nilfs_transaction_begin(struct super_block *sb, · 4 unmodified lines | ||
| 229 | 236 | ret = -ENOSPC; |
| 230 | 237 | goto failed; |
| 231 | 238 | } |
| 239 | + | |
| 240 | + trace_ti = current->journal_info; | |
| 241 | + trace_nilfs2_transaction_transition(sb, trace_ti, trace_ti->ti_count, | |
| 242 | + trace_ti->ti_flags, | |
| 243 | + TRACE_NILFS2_TRANSACTION_BEGIN); | |
| 232 | 244 | return 0; |
| 233 | 245 | |
| 234 | 246 | failed: |
| @@ -261,6 +273,8 @@ int nilfs_transaction_commit(struct super_block *sb) · 26 unmodified lines | ||
| 261 | 273 | ti->ti_flags |= NILFS_TI_COMMIT; |
| 262 | 274 | if (ti->ti_count > 0) { |
| 263 | 275 | ti->ti_count--; |
| 276 | + trace_nilfs2_transaction_transition(sb, ti, ti->ti_count, | |
| 277 | + ti->ti_flags, TRACE_NILFS2_TRANSACTION_COMMIT); | |
| 264 | 278 | return 0; |
| 265 | 279 | } |
| 266 | 280 | if (nilfs->ns_writer) { |
| @@ -272,6 +286,9 @@ int nilfs_transaction_commit(struct super_block *sb) · 5 unmodified lines | ||
| 272 | 286 | nilfs_segctor_do_flush(sci, 0); |
| 273 | 287 | } |
| 274 | 288 | up_read(&nilfs->ns_segctor_sem); |
| 289 | + trace_nilfs2_transaction_transition(sb, ti, ti->ti_count, | |
| 290 | + ti->ti_flags, TRACE_NILFS2_TRANSACTION_COMMIT); | |
| 291 | + | |
| 275 | 292 | current->journal_info = ti->ti_save; |
| 276 | 293 | |
| 277 | 294 | if (ti->ti_flags & NILFS_TI_SYNC) |
| @@ -290,10 +307,15 @@ void nilfs_transaction_abort(struct super_block *sb) · 12 unmodified lines | ||
| 290 | 307 | BUG_ON(ti == NULL || ti->ti_magic != NILFS_TI_MAGIC); |
| 291 | 308 | if (ti->ti_count > 0) { |
| 292 | 309 | ti->ti_count--; |
| 310 | + trace_nilfs2_transaction_transition(sb, ti, ti->ti_count, | |
| 311 | + ti->ti_flags, TRACE_NILFS2_TRANSACTION_ABORT); | |
| 293 | 312 | return; |
| 294 | 313 | } |
| 295 | 314 | up_read(&nilfs->ns_segctor_sem); |
| 296 | 315 | |
| 316 | + trace_nilfs2_transaction_transition(sb, ti, ti->ti_count, | |
| 317 | + ti->ti_flags, TRACE_NILFS2_TRANSACTION_ABORT); | |
| 318 | + | |
| 297 | 319 | current->journal_info = ti->ti_save; |
| 298 | 320 | if (ti->ti_flags & NILFS_TI_DYNAMIC_ALLOC) |
| 299 | 321 | kmem_cache_free(nilfs_transaction_cachep, ti); |
| @@ -339,6 +361,9 @@ static void nilfs_transaction_lock(struct super_block *sb, · 39 unmodified lines | ||
| 339 | 361 | current->journal_info = ti; |
| 340 | 362 | |
| 341 | 363 | for (;;) { |
| 364 | + trace_nilfs2_transaction_transition(sb, ti, ti->ti_count, | |
| 365 | + ti->ti_flags, TRACE_NILFS2_TRANSACTION_TRYLOCK); | |
| 366 | + | |
| 342 | 367 | down_write(&nilfs->ns_segctor_sem); |
| 343 | 368 | if (!test_bit(NILFS_SC_PRIOR_FLUSH, &sci->sc_flags)) |
| 344 | 369 | break; |
| @@ -350,6 +375,9 @@ static void nilfs_transaction_lock(struct super_block *sb, · 5 unmodified lines | ||
| 350 | 375 | } |
| 351 | 376 | if (gcflag) |
| 352 | 377 | ti->ti_flags |= NILFS_TI_GC; |
| 378 | + | |
| 379 | + trace_nilfs2_transaction_transition(sb, ti, ti->ti_count, | |
| 380 | + ti->ti_flags, TRACE_NILFS2_TRANSACTION_LOCK); | |
| 353 | 381 | } |
| 354 | 382 | |
| 355 | 383 | static void nilfs_transaction_unlock(struct super_block *sb) |
| @@ -362,6 +390,9 @@ static void nilfs_transaction_unlock(struct super_block *sb) · 6 unmodified lines | ||
| 362 | 390 | |
| 363 | 391 | up_write(&nilfs->ns_segctor_sem); |
| 364 | 392 | current->journal_info = ti->ti_save; |
| 393 | + | |
| 394 | + trace_nilfs2_transaction_transition(sb, ti, ti->ti_count, | |
| 395 | + ti->ti_flags, TRACE_NILFS2_TRANSACTION_UNLOCK); | |
| 365 | 396 | } |
| 366 | 397 | |
| 367 | 398 | static void *nilfs_segctor_map_segsum_entry(struct nilfs_sc_info *sci, |
| @@ -42,6 +42,59 @@ TRACE_EVENT(nilfs2_collection_stage_transition, · 41 unmodified lines | ||
| 42 | 42 | show_collection_stage(__entry->stage)) |
| 43 | 43 | ); |
| 44 | 44 | |
| 45 | +#ifndef TRACE_HEADER_MULTI_READ | |
| 46 | +enum nilfs2_transaction_transition_state { | |
| 47 | + TRACE_NILFS2_TRANSACTION_BEGIN, | |
| 48 | + TRACE_NILFS2_TRANSACTION_COMMIT, | |
| 49 | + TRACE_NILFS2_TRANSACTION_ABORT, | |
| 50 | + TRACE_NILFS2_TRANSACTION_TRYLOCK, | |
| 51 | + TRACE_NILFS2_TRANSACTION_LOCK, | |
| 52 | + TRACE_NILFS2_TRANSACTION_UNLOCK, | |
| 53 | +}; | |
| 54 | +#endif | |
| 55 | + | |
| 56 | +#define show_transaction_state(type) \ | |
| 57 | + __print_symbolic(type, \ | |
| 58 | + { TRACE_NILFS2_TRANSACTION_BEGIN, "BEGIN" }, \ | |
| 59 | + { TRACE_NILFS2_TRANSACTION_COMMIT, "COMMIT" }, \ | |
| 60 | + { TRACE_NILFS2_TRANSACTION_ABORT, "ABORT" }, \ | |
| 61 | + { TRACE_NILFS2_TRANSACTION_TRYLOCK, "TRYLOCK" }, \ | |
| 62 | + { TRACE_NILFS2_TRANSACTION_LOCK, "LOCK" }, \ | |
| 63 | + { TRACE_NILFS2_TRANSACTION_UNLOCK, "UNLOCK" }) | |
| 64 | + | |
| 65 | +TRACE_EVENT(nilfs2_transaction_transition, | |
| 66 | + TP_PROTO(struct super_block *sb, | |
| 67 | + struct nilfs_transaction_info *ti, | |
| 68 | + int count, | |
| 69 | + unsigned int flags, | |
| 70 | + enum nilfs2_transaction_transition_state state), | |
| 71 | + | |
| 72 | + TP_ARGS(sb, ti, count, flags, state), | |
| 73 | + | |
| 74 | + TP_STRUCT__entry( | |
| 75 | + __field(void *, sb) | |
| 76 | + __field(void *, ti) | |
| 77 | + __field(int, count) | |
| 78 | + __field(unsigned int, flags) | |
| 79 | + __field(int, state) | |
| 80 | + ), | |
| 81 | + | |
| 82 | + TP_fast_assign( | |
| 83 | + __entry->sb = sb; | |
| 84 | + __entry->ti = ti; | |
| 85 | + __entry->count = count; | |
| 86 | + __entry->flags = flags; | |
| 87 | + __entry->state = state; | |
| 88 | + ), | |
| 89 | + | |
| 90 | + TP_printk("sb = %p ti = %p count = %d flags = %x state = %s", | |
| 91 | + __entry->sb, | |
| 92 | + __entry->ti, | |
| 93 | + __entry->count, | |
| 94 | + __entry->flags, | |
| 95 | + show_transaction_state(__entry->state)) | |
| 96 | +); | |
| 97 | + | |
| 45 | 98 | #endif /* _TRACE_NILFS2_H */ |
| 46 | 99 | |
| 47 | 100 | /* This part must be outside protection */ |