From dca54a7bbb8ca9148ae10d60c66c926e222a9c4b Mon Sep 17 00:00:00 2001 From: David Howells Date: Tue, 13 Oct 2020 20:51:59 +0100 Subject: afs: Add tracing for cell refcount and active user count Add a tracepoint to log the cell refcount and active user count and pass in a reason code through various functions that manipulate these counters. Additionally, a helper function, afs_see_cell(), is provided to log interesting places that deal with a cell without actually doing any accounting directly. Signed-off-by: David Howells --- fs/afs/cell.c | 99 ++++++++++++++++++++++++++++++++++++++---------------- fs/afs/dynroot.c | 4 +-- fs/afs/internal.h | 15 +++++---- fs/afs/mntpt.c | 4 +-- fs/afs/proc.c | 2 +- fs/afs/super.c | 16 +++++---- fs/afs/vl_alias.c | 8 ++--- fs/afs/vl_rotate.c | 2 +- fs/afs/volume.c | 6 ++-- 9 files changed, 101 insertions(+), 55 deletions(-) (limited to 'fs') diff --git a/fs/afs/cell.c b/fs/afs/cell.c index bc7ed46aaca9..52233fa6195f 100644 --- a/fs/afs/cell.c +++ b/fs/afs/cell.c @@ -18,6 +18,7 @@ static unsigned __read_mostly afs_cell_gc_delay = 10; static unsigned __read_mostly afs_cell_min_ttl = 10 * 60; static unsigned __read_mostly afs_cell_max_ttl = 24 * 60 * 60; +static atomic_t cell_debug_id; static void afs_queue_cell_manager(struct afs_net *); static void afs_manage_cell_work(struct work_struct *); @@ -48,7 +49,8 @@ static void afs_set_cell_timer(struct afs_net *net, time64_t delay) * hold net->cells_lock at least read-locked. */ static struct afs_cell *afs_find_cell_locked(struct afs_net *net, - const char *name, unsigned int namesz) + const char *name, unsigned int namesz, + enum afs_cell_trace reason) { struct afs_cell *cell = NULL; struct rb_node *p; @@ -87,19 +89,20 @@ static struct afs_cell *afs_find_cell_locked(struct afs_net *net, return ERR_PTR(-ENOENT); found: - return afs_use_cell(cell); + return afs_use_cell(cell, reason); } /* * Look up and get an activation reference on a cell record. */ struct afs_cell *afs_find_cell(struct afs_net *net, - const char *name, unsigned int namesz) + const char *name, unsigned int namesz, + enum afs_cell_trace reason) { struct afs_cell *cell; down_read(&net->cells_lock); - cell = afs_find_cell_locked(net, name, namesz); + cell = afs_find_cell_locked(net, name, namesz, reason); up_read(&net->cells_lock); return cell; } @@ -197,6 +200,8 @@ static struct afs_cell *afs_alloc_cell(struct afs_net *net, cell->dns_status = vllist->status; smp_store_release(&cell->dns_lookup_count, 1); /* vs source/status */ atomic_inc(&net->cells_outstanding); + cell->debug_id = atomic_inc_return(&cell_debug_id); + trace_afs_cell(cell->debug_id, 1, 0, afs_cell_trace_alloc); _leave(" = %p", cell); return cell; @@ -236,7 +241,7 @@ struct afs_cell *afs_lookup_cell(struct afs_net *net, _enter("%s,%s", name, vllist); if (!excl) { - cell = afs_find_cell(net, name, namesz); + cell = afs_find_cell(net, name, namesz, afs_cell_trace_use_lookup); if (!IS_ERR(cell)) goto wait_for_cell; } @@ -280,13 +285,16 @@ struct afs_cell *afs_lookup_cell(struct afs_net *net, cell = candidate; candidate = NULL; atomic_set(&cell->active, 2); + trace_afs_cell(cell->debug_id, atomic_read(&cell->ref), 2, afs_cell_trace_insert); rb_link_node_rcu(&cell->net_node, parent, pp); rb_insert_color(&cell->net_node, &net->cells); up_write(&net->cells_lock); - afs_queue_cell(cell); + afs_queue_cell(cell, afs_cell_trace_get_queue_new); wait_for_cell: + trace_afs_cell(cell->debug_id, atomic_read(&cell->ref), atomic_read(&cell->active), + afs_cell_trace_wait); _debug("wait_for_cell"); wait_var_event(&cell->state, ({ @@ -309,17 +317,17 @@ cell_already_exists: if (excl) { ret = -EEXIST; } else { - afs_use_cell(cursor); + afs_use_cell(cursor, afs_cell_trace_use_lookup); ret = 0; } up_write(&net->cells_lock); if (candidate) - afs_put_cell(candidate); + afs_put_cell(candidate, afs_cell_trace_put_candidate); if (ret == 0) goto wait_for_cell; goto error_noput; error: - afs_unuse_cell(net, cell); + afs_unuse_cell(net, cell, afs_cell_trace_unuse_lookup); error_noput: _leave(" = %d [error]", ret); return ERR_PTR(ret); @@ -364,15 +372,16 @@ int afs_cell_init(struct afs_net *net, const char *rootcell) } if (!test_and_set_bit(AFS_CELL_FL_NO_GC, &new_root->flags)) - afs_use_cell(new_root); + afs_use_cell(new_root, afs_cell_trace_use_pin); /* install the new cell */ down_write(&net->cells_lock); + afs_see_cell(new_root, afs_cell_trace_see_ws); old_root = net->ws_cell; net->ws_cell = new_root; up_write(&net->cells_lock); - afs_unuse_cell(net, old_root); + afs_unuse_cell(net, old_root, afs_cell_trace_unuse_ws); _leave(" = 0"); return 0; } @@ -485,9 +494,10 @@ static void afs_cell_destroy(struct rcu_head *rcu) u = atomic_read(&cell->ref); ASSERTCMP(u, ==, 0); + trace_afs_cell(cell->debug_id, u, atomic_read(&cell->active), afs_cell_trace_free); afs_put_vlserverlist(net, rcu_access_pointer(cell->vl_servers)); - afs_unuse_cell(net, cell->alias_of); + afs_unuse_cell(net, cell->alias_of, afs_cell_trace_unuse_alias); key_put(cell->anonymous_key); kfree(cell->name); kfree(cell); @@ -525,24 +535,30 @@ void afs_cells_timer(struct timer_list *timer) /* * Get a reference on a cell record. */ -struct afs_cell *afs_get_cell(struct afs_cell *cell) +struct afs_cell *afs_get_cell(struct afs_cell *cell, enum afs_cell_trace reason) { + int u; + if (atomic_read(&cell->ref) <= 0) BUG(); - atomic_inc(&cell->ref); + u = atomic_inc_return(&cell->ref); + trace_afs_cell(cell->debug_id, u, atomic_read(&cell->active), reason); return cell; } /* * Drop a reference on a cell record. */ -void afs_put_cell(struct afs_cell *cell) +void afs_put_cell(struct afs_cell *cell, enum afs_cell_trace reason) { if (cell) { + unsigned int debug_id = cell->debug_id; unsigned int u, a; + a = atomic_read(&cell->active); u = atomic_dec_return(&cell->ref); + trace_afs_cell(debug_id, u, a, reason); if (u == 0) { a = atomic_read(&cell->active); WARN(a != 0, "Cell active count %u > 0\n", a); @@ -554,12 +570,16 @@ void afs_put_cell(struct afs_cell *cell) /* * Note a cell becoming more active. */ -struct afs_cell *afs_use_cell(struct afs_cell *cell) +struct afs_cell *afs_use_cell(struct afs_cell *cell, enum afs_cell_trace reason) { + int u, a; + if (atomic_read(&cell->ref) <= 0) BUG(); - atomic_inc(&cell->active); + u = atomic_read(&cell->ref); + a = atomic_inc_return(&cell->active); + trace_afs_cell(cell->debug_id, u, a, reason); return cell; } @@ -567,10 +587,11 @@ struct afs_cell *afs_use_cell(struct afs_cell *cell) * Record a cell becoming less active. When the active counter reaches 1, it * is scheduled for destruction, but may get reactivated. */ -void afs_unuse_cell(struct afs_net *net, struct afs_cell *cell) +void afs_unuse_cell(struct afs_net *net, struct afs_cell *cell, enum afs_cell_trace reason) { + unsigned int debug_id = cell->debug_id; time64_t now, expire_delay; - int a; + int u, a; if (!cell) return; @@ -583,21 +604,35 @@ void afs_unuse_cell(struct afs_net *net, struct afs_cell *cell) if (cell->vl_servers->nr_servers) expire_delay = afs_cell_gc_delay; + u = atomic_read(&cell->ref); a = atomic_dec_return(&cell->active); + trace_afs_cell(debug_id, u, a, reason); WARN_ON(a == 0); if (a == 1) /* 'cell' may now be garbage collected. */ afs_set_cell_timer(net, expire_delay); } +/* + * Note that a cell has been seen. + */ +void afs_see_cell(struct afs_cell *cell, enum afs_cell_trace reason) +{ + int u, a; + + u = atomic_read(&cell->ref); + a = atomic_read(&cell->active); + trace_afs_cell(cell->debug_id, u, a, reason); +} + /* * Queue a cell for management, giving the workqueue a ref to hold. */ -void afs_queue_cell(struct afs_cell *cell) +void afs_queue_cell(struct afs_cell *cell, enum afs_cell_trace reason) { - afs_get_cell(cell); + afs_get_cell(cell, reason); if (!queue_work(afs_wq, &cell->manager)) - afs_put_cell(cell); + afs_put_cell(cell, afs_cell_trace_put_queue_fail); } /* @@ -713,6 +748,8 @@ again: active = 1; if (atomic_try_cmpxchg_relaxed(&cell->active, &active, 0)) { rb_erase(&cell->net_node, &net->cells); + trace_afs_cell(cell->debug_id, atomic_read(&cell->ref), 0, + afs_cell_trace_unuse_delete); smp_store_release(&cell->state, AFS_CELL_REMOVED); } up_write(&net->cells_lock); @@ -792,7 +829,7 @@ final_destruction: /* The root volume is pinning the cell */ afs_put_volume(cell->net, cell->root_volume, afs_volume_trace_put_cell_root); cell->root_volume = NULL; - afs_put_cell(cell); + afs_put_cell(cell, afs_cell_trace_put_destroy); } static void afs_manage_cell_work(struct work_struct *work) @@ -800,7 +837,7 @@ static void afs_manage_cell_work(struct work_struct *work) struct afs_cell *cell = container_of(work, struct afs_cell, manager); afs_manage_cell(cell); - afs_put_cell(cell); + afs_put_cell(cell, afs_cell_trace_put_queue_work); } /* @@ -838,13 +875,17 @@ void afs_manage_cells(struct work_struct *work) bool sched_cell = false; active = atomic_read(&cell->active); - _debug("manage %s %u %u", cell->name, atomic_read(&cell->ref), active); + trace_afs_cell(cell->debug_id, atomic_read(&cell->ref), + active, afs_cell_trace_manage); ASSERTCMP(active, >=, 1); if (purging) { - if (test_and_clear_bit(AFS_CELL_FL_NO_GC, &cell->flags)) - atomic_dec(&cell->active); + if (test_and_clear_bit(AFS_CELL_FL_NO_GC, &cell->flags)) { + active = atomic_dec_return(&cell->active); + trace_afs_cell(cell->debug_id, atomic_read(&cell->ref), + active, afs_cell_trace_unuse_pin); + } } if (active == 1) { @@ -870,7 +911,7 @@ void afs_manage_cells(struct work_struct *work) } if (sched_cell) - afs_queue_cell(cell); + afs_queue_cell(cell, afs_cell_trace_get_queue_manage); } up_read(&net->cells_lock); @@ -907,7 +948,7 @@ void afs_cell_purge(struct afs_net *net) ws = net->ws_cell; net->ws_cell = NULL; up_write(&net->cells_lock); - afs_unuse_cell(net, ws); + afs_unuse_cell(net, ws, afs_cell_trace_unuse_ws); _debug("del timer"); if (del_timer_sync(&net->cells_timer)) diff --git a/fs/afs/dynroot.c b/fs/afs/dynroot.c index da32797dd425..db832cc931c8 100644 --- a/fs/afs/dynroot.c +++ b/fs/afs/dynroot.c @@ -123,9 +123,9 @@ static int afs_probe_cell_name(struct dentry *dentry) len--; } - cell = afs_find_cell(net, name, len); + cell = afs_find_cell(net, name, len, afs_cell_trace_use_probe); if (!IS_ERR(cell)) { - afs_unuse_cell(net, cell); + afs_unuse_cell(net, cell, afs_cell_trace_unuse_probe); return 0; } diff --git a/fs/afs/internal.h b/fs/afs/internal.h index 06e617ee4cd1..81b0485fd22a 100644 --- a/fs/afs/internal.h +++ b/fs/afs/internal.h @@ -375,6 +375,7 @@ struct afs_cell { enum dns_record_source dns_source:8; /* Latest source of data from lookup */ enum dns_lookup_status dns_status:8; /* Latest status of data from lookup */ unsigned int dns_lookup_count; /* Counter of DNS lookups */ + unsigned int debug_id; /* The volumes belonging to this cell */ struct rb_root volumes; /* Tree of volumes on this server */ @@ -919,14 +920,16 @@ static inline bool afs_cb_is_broken(unsigned int cb_break, * cell.c */ extern int afs_cell_init(struct afs_net *, const char *); -extern struct afs_cell *afs_find_cell(struct afs_net *, const char *, unsigned); +extern struct afs_cell *afs_find_cell(struct afs_net *, const char *, unsigned, + enum afs_cell_trace); extern struct afs_cell *afs_lookup_cell(struct afs_net *, const char *, unsigned, const char *, bool); -extern struct afs_cell *afs_use_cell(struct afs_cell *); -extern void afs_unuse_cell(struct afs_net *, struct afs_cell *); -extern struct afs_cell *afs_get_cell(struct afs_cell *); -extern void afs_put_cell(struct afs_cell *); -extern void afs_queue_cell(struct afs_cell *); +extern struct afs_cell *afs_use_cell(struct afs_cell *, enum afs_cell_trace); +extern void afs_unuse_cell(struct afs_net *, struct afs_cell *, enum afs_cell_trace); +extern struct afs_cell *afs_get_cell(struct afs_cell *, enum afs_cell_trace); +extern void afs_see_cell(struct afs_cell *, enum afs_cell_trace); +extern void afs_put_cell(struct afs_cell *, enum afs_cell_trace); +extern void afs_queue_cell(struct afs_cell *, enum afs_cell_trace); extern void afs_manage_cells(struct work_struct *); extern void afs_cells_timer(struct timer_list *); extern void __net_exit afs_cell_purge(struct afs_net *); diff --git a/fs/afs/mntpt.c b/fs/afs/mntpt.c index c69a0282960c..052dab2f5c03 100644 --- a/fs/afs/mntpt.c +++ b/fs/afs/mntpt.c @@ -88,7 +88,7 @@ static int afs_mntpt_set_params(struct fs_context *fc, struct dentry *mntpt) ctx->force = true; } if (ctx->cell) { - afs_unuse_cell(ctx->net, ctx->cell); + afs_unuse_cell(ctx->net, ctx->cell, afs_cell_trace_unuse_mntpt); ctx->cell = NULL; } if (test_bit(AFS_VNODE_PSEUDODIR, &vnode->flags)) { @@ -124,7 +124,7 @@ static int afs_mntpt_set_params(struct fs_context *fc, struct dentry *mntpt) char *buf; if (src_as->cell) - ctx->cell = afs_use_cell(src_as->cell); + ctx->cell = afs_use_cell(src_as->cell, afs_cell_trace_use_mntpt); if (size < 2 || size > PAGE_SIZE - 1) return -EINVAL; diff --git a/fs/afs/proc.c b/fs/afs/proc.c index 76fbe0560cfb..065a28bfa3f1 100644 --- a/fs/afs/proc.c +++ b/fs/afs/proc.c @@ -129,7 +129,7 @@ static int afs_proc_cells_write(struct file *file, char *buf, size_t size) } if (test_and_set_bit(AFS_CELL_FL_NO_GC, &cell->flags)) - afs_unuse_cell(net, cell); + afs_unuse_cell(net, cell, afs_cell_trace_unuse_no_pin); } else { goto inval; } diff --git a/fs/afs/super.c b/fs/afs/super.c index e72c223f831d..ac4e3ed4e9bd 100644 --- a/fs/afs/super.c +++ b/fs/afs/super.c @@ -294,7 +294,8 @@ static int afs_parse_source(struct fs_context *fc, struct fs_parameter *param) cellnamesz, cellnamesz, cellname ?: ""); return PTR_ERR(cell); } - afs_unuse_cell(ctx->net, ctx->cell); + afs_unuse_cell(ctx->net, ctx->cell, afs_cell_trace_unuse_parse); + afs_see_cell(cell, afs_cell_trace_see_source); ctx->cell = cell; } @@ -389,8 +390,9 @@ static int afs_validate_fc(struct fs_context *fc) _debug("switch to alias"); key_put(ctx->key); ctx->key = NULL; - cell = afs_use_cell(ctx->cell->alias_of); - afs_unuse_cell(ctx->net, ctx->cell); + cell = afs_use_cell(ctx->cell->alias_of, + afs_cell_trace_use_fc_alias); + afs_unuse_cell(ctx->net, ctx->cell, afs_cell_trace_unuse_fc); ctx->cell = cell; goto reget_key; } @@ -508,7 +510,7 @@ static struct afs_super_info *afs_alloc_sbi(struct fs_context *fc) if (ctx->dyn_root) { as->dyn_root = true; } else { - as->cell = afs_use_cell(ctx->cell); + as->cell = afs_use_cell(ctx->cell, afs_cell_trace_use_sbi); as->volume = afs_get_volume(ctx->volume, afs_volume_trace_get_alloc_sbi); } @@ -521,7 +523,7 @@ static void afs_destroy_sbi(struct afs_super_info *as) if (as) { struct afs_net *net = afs_net(as->net_ns); afs_put_volume(net, as->volume, afs_volume_trace_put_destroy_sbi); - afs_unuse_cell(net, as->cell); + afs_unuse_cell(net, as->cell, afs_cell_trace_unuse_sbi); put_net(as->net_ns); kfree(as); } @@ -607,7 +609,7 @@ static void afs_free_fc(struct fs_context *fc) afs_destroy_sbi(fc->s_fs_info); afs_put_volume(ctx->net, ctx->volume, afs_volume_trace_put_free_fc); - afs_unuse_cell(ctx->net, ctx->cell); + afs_unuse_cell(ctx->net, ctx->cell, afs_cell_trace_unuse_fc); key_put(ctx->key); kfree(ctx); } @@ -634,7 +636,7 @@ static int afs_init_fs_context(struct fs_context *fc) ctx->net = afs_net(fc->net_ns); /* Default to the workstation cell. */ - cell = afs_find_cell(ctx->net, NULL, 0); + cell = afs_find_cell(ctx->net, NULL, 0, afs_cell_trace_use_fc); if (IS_ERR(cell)) cell = NULL; ctx->cell = cell; diff --git a/fs/afs/vl_alias.c b/fs/afs/vl_alias.c index ddb4cb67d0fd..f04a80e4f5c3 100644 --- a/fs/afs/vl_alias.c +++ b/fs/afs/vl_alias.c @@ -177,7 +177,7 @@ static int afs_compare_cell_roots(struct afs_cell *cell) is_alias: rcu_read_unlock(); - cell->alias_of = afs_use_cell(p); + cell->alias_of = afs_use_cell(p, afs_cell_trace_use_alias); return 1; } @@ -247,18 +247,18 @@ static int afs_query_for_alias(struct afs_cell *cell, struct key *key) continue; if (p->root_volume) continue; /* Ignore cells that have a root.cell volume. */ - afs_use_cell(p); + afs_use_cell(p, afs_cell_trace_use_check_alias); mutex_unlock(&cell->net->proc_cells_lock); if (afs_query_for_alias_one(cell, key, p) != 0) goto is_alias; if (mutex_lock_interruptible(&cell->net->proc_cells_lock) < 0) { - afs_unuse_cell(cell->net, p); + afs_unuse_cell(cell->net, p, afs_cell_trace_unuse_check_alias); return -ERESTARTSYS; } - afs_unuse_cell(cell->net, p); + afs_unuse_cell(cell->net, p, afs_cell_trace_unuse_check_alias); } mutex_unlock(&cell->net->proc_cells_lock); diff --git a/fs/afs/vl_rotate.c b/fs/afs/vl_rotate.c index da3b072d4d63..488e58490b16 100644 --- a/fs/afs/vl_rotate.c +++ b/fs/afs/vl_rotate.c @@ -45,7 +45,7 @@ static bool afs_start_vl_iteration(struct afs_vl_cursor *vc) cell->dns_expiry <= ktime_get_real_seconds()) { dns_lookup_count = smp_load_acquire(&cell->dns_lookup_count); set_bit(AFS_CELL_FL_DO_LOOKUP, &cell->flags); - afs_queue_cell(cell); + afs_queue_cell(cell, afs_cell_trace_get_queue_dns); if (cell->dns_source == DNS_RECORD_UNAVAILABLE) { if (wait_var_event_interruptible( diff --git a/fs/afs/volume.c b/fs/afs/volume.c index a838030e9563..f84194b791d3 100644 --- a/fs/afs/volume.c +++ b/fs/afs/volume.c @@ -83,7 +83,7 @@ static struct afs_volume *afs_alloc_volume(struct afs_fs_context *params, volume->vid = vldb->vid[params->type]; volume->update_at = ktime_get_real_seconds() + afs_volume_record_life; - volume->cell = afs_get_cell(params->cell); + volume->cell = afs_get_cell(params->cell, afs_cell_trace_get_vol); volume->type = params->type; volume->type_force = params->force; volume->name_len = vldb->name_len; @@ -106,7 +106,7 @@ static struct afs_volume *afs_alloc_volume(struct afs_fs_context *params, return volume; error_1: - afs_put_cell(volume->cell); + afs_put_cell(volume->cell, afs_cell_trace_put_vol); kfree(volume); error_0: return ERR_PTR(ret); @@ -228,7 +228,7 @@ static void afs_destroy_volume(struct afs_net *net, struct afs_volume *volume) afs_remove_volume_from_cell(volume); afs_put_serverlist(net, rcu_access_pointer(volume->servers)); - afs_put_cell(volume->cell); + afs_put_cell(volume->cell, afs_cell_trace_put_vol); trace_afs_volume(volume->vid, atomic_read(&volume->usage), afs_volume_trace_free); kfree_rcu(volume, rcu); -- cgit v1.2.3