Make some adjustments to tracepoints to make the tracing a bit more followable: (1) Standardise on displaying the backing inode number as "B=<hex>" with no leading zeros. (2) Make the cachefiles_lookup tracepoint log the directory inode number as well as the looked-up inode number. (3) Add a cachefiles_lookup tracepoint into cachefiles_get_directory() to log directory lookup. (4) Add a new cachefiles_mkdir tracepoint and use that to log a successful mkdir from cachefiles_get_directory(). (5) Make the cachefiles_unlink and cachefiles_rename tracepoints log the inode number of the affected file/dir rather than dentry struct pointers.
Unified · Split
| @@ -101,6 +101,7 @@ retry: · 100 unmodified lines | ||
| 101 | 101 | subdir = lookup_one_len(dirname, dir, strlen(dirname)); |
| 102 | 102 | else |
| 103 | 103 | subdir = ERR_PTR(ret); |
| 104 | + trace_cachefiles_lookup(NULL, dir, subdir); | |
| 104 | 105 | if (IS_ERR(subdir)) { |
| 105 | 106 | trace_cachefiles_vfs_error(NULL, d_backing_inode(dir), |
| 106 | 107 | PTR_ERR(subdir), |
| @@ -135,6 +136,7 @@ retry: · 28 unmodified lines | ||
| 135 | 136 | cachefiles_trace_mkdir_error); |
| 136 | 137 | goto mkdir_error; |
| 137 | 138 | } |
| 139 | + trace_cachefiles_mkdir(dir, subdir); | |
| 138 | 140 | |
| 139 | 141 | if (unlikely(d_unhashed(subdir))) { |
| 140 | 142 | cachefiles_put_directory(subdir); |
| @@ -233,7 +235,7 @@ static int cachefiles_unlink(struct cachefiles_cache *cache, · 92 unmodified lines | ||
| 233 | 235 | }; |
| 234 | 236 | int ret; |
| 235 | 237 | |
| 236 | − trace_cachefiles_unlink(object, dentry, why); | |
| 238 | + trace_cachefiles_unlink(object, d_inode(dentry)->i_ino, why); | |
| 237 | 239 | ret = security_path_unlink(&path, dentry); |
| 238 | 240 | if (ret < 0) { |
| 239 | 241 | cachefiles_io_error(cache, "Unlink security error"); |
| @@ -386,7 +388,7 @@ try_again: · 146 unmodified lines | ||
| 386 | 388 | .new_dir = d_inode(cache->graveyard), |
| 387 | 389 | .new_dentry = grave, |
| 388 | 390 | }; |
| 389 | − trace_cachefiles_rename(object, rep, grave, why); | |
| 391 | + trace_cachefiles_rename(object, d_inode(rep)->i_ino, why); | |
| 390 | 392 | ret = cachefiles_inject_read_error(); |
| 391 | 393 | if (ret == 0) |
| 392 | 394 | ret = vfs_rename(&rd); |
| @@ -617,7 +619,7 @@ bool cachefiles_look_up_object(struct cachefiles_object *object) · 224 unmodified lines | ||
| 617 | 619 | object->d_name_len); |
| 618 | 620 | else |
| 619 | 621 | dentry = ERR_PTR(ret); |
| 620 | − trace_cachefiles_lookup(object, dentry); | |
| 622 | + trace_cachefiles_lookup(object, fan, dentry); | |
| 621 | 623 | if (IS_ERR(dentry)) { |
| 622 | 624 | if (dentry == ERR_PTR(-ENOENT)) |
| 623 | 625 | goto new_file; |
| @@ -233,25 +233,48 @@ TRACE_EVENT(cachefiles_ref, · 232 unmodified lines | ||
| 233 | 233 | |
| 234 | 234 | TRACE_EVENT(cachefiles_lookup, |
| 235 | 235 | TP_PROTO(struct cachefiles_object *obj, |
| 236 | + struct dentry *dir, | |
| 236 | 237 | struct dentry *de), |
| 237 | 238 | |
| 238 | − TP_ARGS(obj, de), | |
| 239 | + TP_ARGS(obj, dir, de), | |
| 239 | 240 | |
| 240 | 241 | TP_STRUCT__entry( |
| 241 | 242 | __field(unsigned int, obj ) |
| 242 | 243 | __field(short, error ) |
| 244 | + __field(unsigned long, dino ) | |
| 243 | 245 | __field(unsigned long, ino ) |
| 244 | 246 | ), |
| 245 | 247 | |
| 246 | 248 | TP_fast_assign( |
| 247 | − __entry->obj = obj->debug_id; | |
| 249 | + __entry->obj = obj ? obj->debug_id : 0; | |
| 250 | + __entry->dino = d_backing_inode(dir)->i_ino; | |
| 248 | 251 | __entry->ino = (!IS_ERR(de) && d_backing_inode(de) ? |
| 249 | 252 | d_backing_inode(de)->i_ino : 0); |
| 250 | 253 | __entry->error = IS_ERR(de) ? PTR_ERR(de) : 0; |
| 251 | 254 | ), |
| 252 | 255 | |
| 253 | − TP_printk("o=%08x i=%lx e=%d", | |
| 254 | − __entry->obj, __entry->ino, __entry->error) | |
| 256 | + TP_printk("o=%08x dB=%lx B=%lx e=%d", | |
| 257 | + __entry->obj, __entry->dino, __entry->ino, __entry->error) | |
| 258 | + ); | |
| 259 | + | |
| 260 | +TRACE_EVENT(cachefiles_mkdir, | |
| 261 | + TP_PROTO(struct dentry *dir, struct dentry *subdir), | |
| 262 | + | |
| 263 | + TP_ARGS(dir, subdir), | |
| 264 | + | |
| 265 | + TP_STRUCT__entry( | |
| 266 | + __field(unsigned int, dir ) | |
| 267 | + __field(unsigned int, subdir ) | |
| 268 | + ), | |
| 269 | + | |
| 270 | + TP_fast_assign( | |
| 271 | + __entry->dir = d_backing_inode(dir)->i_ino; | |
| 272 | + __entry->subdir = d_backing_inode(subdir)->i_ino; | |
| 273 | + ), | |
| 274 | + | |
| 275 | + TP_printk("dB=%x sB=%x", | |
| 276 | + __entry->dir, | |
| 277 | + __entry->subdir) | |
| 255 | 278 | ); |
| 256 | 279 | |
| 257 | 280 | TRACE_EVENT(cachefiles_tmpfile, |
| @@ -269,7 +292,7 @@ TRACE_EVENT(cachefiles_tmpfile, · 11 unmodified lines | ||
| 269 | 292 | __entry->backer = backer->i_ino; |
| 270 | 293 | ), |
| 271 | 294 | |
| 272 | − TP_printk("o=%08x b=%08x", | |
| 295 | + TP_printk("o=%08x B=%x", | |
| 273 | 296 | __entry->obj, |
| 274 | 297 | __entry->backer) |
| 275 | 298 | ); |
| @@ -289,61 +312,58 @@ TRACE_EVENT(cachefiles_link, · 13 unmodified lines | ||
| 289 | 312 | __entry->backer = backer->i_ino; |
| 290 | 313 | ), |
| 291 | 314 | |
| 292 | − TP_printk("o=%08x b=%08x", | |
| 315 | + TP_printk("o=%08x B=%x", | |
| 293 | 316 | __entry->obj, |
| 294 | 317 | __entry->backer) |
| 295 | 318 | ); |
| 296 | 319 | |
| 297 | 320 | TRACE_EVENT(cachefiles_unlink, |
| 298 | 321 | TP_PROTO(struct cachefiles_object *obj, |
| 299 | − struct dentry *de, | |
| 322 | + ino_t ino, | |
| 300 | 323 | enum fscache_why_object_killed why), |
| 301 | 324 | |
| 302 | − TP_ARGS(obj, de, why), | |
| 325 | + TP_ARGS(obj, ino, why), | |
| 303 | 326 | |
| 304 | 327 | /* Note that obj may be NULL */ |
| 305 | 328 | TP_STRUCT__entry( |
| 306 | 329 | __field(unsigned int, obj ) |
| 307 | − __field(struct dentry *, de ) | |
| 330 | + __field(unsigned int, ino ) | |
| 308 | 331 | __field(enum fscache_why_object_killed, why ) |
| 309 | 332 | ), |
| 310 | 333 | |
| 311 | 334 | TP_fast_assign( |
| 312 | 335 | __entry->obj = obj ? obj->debug_id : UINT_MAX; |
| 313 | − __entry->de = de; | |
| 336 | + __entry->ino = ino; | |
| 314 | 337 | __entry->why = why; |
| 315 | 338 | ), |
| 316 | 339 | |
| 317 | − TP_printk("o=%08x d=%p w=%s", | |
| 318 | − __entry->obj, __entry->de, | |
| 340 | + TP_printk("o=%08x B=%x w=%s", | |
| 341 | + __entry->obj, __entry->ino, | |
| 319 | 342 | __print_symbolic(__entry->why, cachefiles_obj_kill_traces)) |
| 320 | 343 | ); |
| 321 | 344 | |
| 322 | 345 | TRACE_EVENT(cachefiles_rename, |
| 323 | 346 | TP_PROTO(struct cachefiles_object *obj, |
| 324 | − struct dentry *de, | |
| 325 | − struct dentry *to, | |
| 347 | + ino_t ino, | |
| 326 | 348 | enum fscache_why_object_killed why), |
| 327 | 349 | |
| 328 | − TP_ARGS(obj, de, to, why), | |
| 350 | + TP_ARGS(obj, ino, why), | |
| 329 | 351 | |
| 330 | 352 | /* Note that obj may be NULL */ |
| 331 | 353 | TP_STRUCT__entry( |
| 332 | 354 | __field(unsigned int, obj ) |
| 333 | − __field(struct dentry *, de ) | |
| 334 | − __field(struct dentry *, to ) | |
| 355 | + __field(unsigned int, ino ) | |
| 335 | 356 | __field(enum fscache_why_object_killed, why ) |
| 336 | 357 | ), |
| 337 | 358 | |
| 338 | 359 | TP_fast_assign( |
| 339 | 360 | __entry->obj = obj ? obj->debug_id : UINT_MAX; |
| 340 | − __entry->de = de; | |
| 341 | − __entry->to = to; | |
| 361 | + __entry->ino = ino; | |
| 342 | 362 | __entry->why = why; |
| 343 | 363 | ), |
| 344 | 364 | |
| 345 | − TP_printk("o=%08x d=%p t=%p w=%s", | |
| 346 | − __entry->obj, __entry->de, __entry->to, | |
| 365 | + TP_printk("o=%08x B=%x w=%s", | |
| 366 | + __entry->obj, __entry->ino, | |
| 347 | 367 | __print_symbolic(__entry->why, cachefiles_obj_kill_traces)) |
| 348 | 368 | ); |
| 349 | 369 | |
| @@ -370,7 +390,7 @@ TRACE_EVENT(cachefiles_coherency, · 20 unmodified lines | ||
| 370 | 390 | __entry->ino = ino; |
| 371 | 391 | ), |
| 372 | 392 | |
| 373 | − TP_printk("o=%08x %s i=%llx c=%u", | |
| 393 | + TP_printk("o=%08x %s B=%llx c=%u", | |
| 374 | 394 | __entry->obj, |
| 375 | 395 | __print_symbolic(__entry->why, cachefiles_coherency_traces), |
| 376 | 396 | __entry->ino, |
| @@ -397,7 +417,7 @@ TRACE_EVENT(cachefiles_vol_coherency, · 20 unmodified lines | ||
| 397 | 417 | __entry->ino = ino; |
| 398 | 418 | ), |
| 399 | 419 | |
| 400 | − TP_printk("V=%08x %s i=%llx", | |
| 420 | + TP_printk("V=%08x %s B=%llx", | |
| 401 | 421 | __entry->vol, |
| 402 | 422 | __print_symbolic(__entry->why, cachefiles_coherency_traces), |
| 403 | 423 | __entry->ino) |
| @@ -435,7 +455,7 @@ TRACE_EVENT(cachefiles_prep_read, · 31 unmodified lines | ||
| 435 | 455 | __entry->cache_inode = cache_inode; |
| 436 | 456 | ), |
| 437 | 457 | |
| 438 | − TP_printk("R=%08x[%u] %s %s f=%02x s=%llx %zx ni=%x b=%x", | |
| 458 | + TP_printk("R=%08x[%u] %s %s f=%02x s=%llx %zx ni=%x B=%x", | |
| 439 | 459 | __entry->rreq, __entry->index, |
| 440 | 460 | __print_symbolic(__entry->source, netfs_sreq_sources), |
| 441 | 461 | __print_symbolic(__entry->why, cachefiles_prepare_read_traces), |
| @@ -466,7 +486,7 @@ TRACE_EVENT(cachefiles_read, · 24 unmodified lines | ||
| 466 | 486 | __entry->len = len; |
| 467 | 487 | ), |
| 468 | 488 | |
| 469 | − TP_printk("o=%08x b=%08x s=%llx l=%zx", | |
| 489 | + TP_printk("o=%08x B=%x s=%llx l=%zx", | |
| 470 | 490 | __entry->obj, |
| 471 | 491 | __entry->backer, |
| 472 | 492 | __entry->start, |
| @@ -495,7 +515,7 @@ TRACE_EVENT(cachefiles_write, · 22 unmodified lines | ||
| 495 | 515 | __entry->len = len; |
| 496 | 516 | ), |
| 497 | 517 | |
| 498 | − TP_printk("o=%08x b=%08x s=%llx l=%zx", | |
| 518 | + TP_printk("o=%08x B=%x s=%llx l=%zx", | |
| 499 | 519 | __entry->obj, |
| 500 | 520 | __entry->backer, |
| 501 | 521 | __entry->start, |
| @@ -524,7 +544,7 @@ TRACE_EVENT(cachefiles_trunc, · 22 unmodified lines | ||
| 524 | 544 | __entry->why = why; |
| 525 | 545 | ), |
| 526 | 546 | |
| 527 | − TP_printk("o=%08x b=%08x %s l=%llx->%llx", | |
| 547 | + TP_printk("o=%08x B=%x %s l=%llx->%llx", | |
| 528 | 548 | __entry->obj, |
| 529 | 549 | __entry->backer, |
| 530 | 550 | __print_symbolic(__entry->why, cachefiles_trunc_traces), |
| @@ -549,7 +569,7 @@ TRACE_EVENT(cachefiles_mark_active, · 18 unmodified lines | ||
| 549 | 569 | __entry->inode = inode->i_ino; |
| 550 | 570 | ), |
| 551 | 571 | |
| 552 | − TP_printk("o=%08x i=%lx", | |
| 572 | + TP_printk("o=%08x B=%lx", | |
| 553 | 573 | __entry->obj, __entry->inode) |
| 554 | 574 | ); |
| 555 | 575 | |
| @@ -570,7 +590,7 @@ TRACE_EVENT(cachefiles_mark_inactive, · 14 unmodified lines | ||
| 570 | 590 | __entry->inode = inode->i_ino; |
| 571 | 591 | ), |
| 572 | 592 | |
| 573 | − TP_printk("o=%08x i=%lx", | |
| 593 | + TP_printk("o=%08x B=%lx", | |
| 574 | 594 | __entry->obj, __entry->inode) |
| 575 | 595 | ); |
| 576 | 596 | |
| @@ -594,7 +614,7 @@ TRACE_EVENT(cachefiles_vfs_error, · 17 unmodified lines | ||
| 594 | 614 | __entry->where = where; |
| 595 | 615 | ), |
| 596 | 616 | |
| 597 | − TP_printk("o=%08x b=%08x %s e=%d", | |
| 617 | + TP_printk("o=%08x B=%x %s e=%d", | |
| 598 | 618 | __entry->obj, |
| 599 | 619 | __entry->backer, |
| 600 | 620 | __print_symbolic(__entry->where, cachefiles_error_traces), |
| @@ -621,7 +641,7 @@ TRACE_EVENT(cachefiles_io_error, · 20 unmodified lines | ||
| 621 | 641 | __entry->where = where; |
| 622 | 642 | ), |
| 623 | 643 | |
| 624 | − TP_printk("o=%08x b=%08x %s e=%d", | |
| 644 | + TP_printk("o=%08x B=%x %s e=%d", | |
| 625 | 645 | __entry->obj, |
| 626 | 646 | __entry->backer, |
| 627 | 647 | __print_symbolic(__entry->where, cachefiles_error_traces), |