On 08/04/22(Fri) 12:16, Alexander Bluhm wrote:
> On Fri, Apr 08, 2022 at 02:39:34AM +0000, Visa Hankala wrote:
> > On Thu, Apr 07, 2022 at 07:55:11PM +0200, Alexander Bluhm wrote:
> > > On Wed, Mar 23, 2022 at 06:13:27PM +0100, Alexander Bluhm wrote:
> > > > In my opinion tracepoints give insight at minimal cost. It is worth
> > > > it to have it in GENERIC to make it easy to use.
> > >
> > > After release I want to revive the btrace of refcounts discussion.
> > >
> > > As mpi@ mentioned the idea of dt(4) is to have these trace points
> > > in GENERIC kernel. If you want to hunt a bug, just turn it on.
> > > Refounting is a common place for bugs, leaks can be detected easily.
> > >
> > > The alternative are some defines that you can compile in and access
> > > from ddb. This is more work and you would have to implement it for
> > > every recount.
> > > https://marc.info/?l=openbsd-tech&m=163786435916039&w=2
> > >
> > > There is no measuarable performance difference. dt(4) is written
> > > in a way that is is only one additional branch. At least my goal
> > > is to add trace points to useful places when we identify them.
> >
> > DT_INDEX_ENTER() still checks the index first, so it has two branches
> > in practice.
> >
> > I think dt_tracing should be checked first so that it serves as
> > a gateway to the trace code. Under normal operation, the check's
> > outcome is always the same, which is easy even for simple branch
> > predictors.
>
> Reordering the check is easy. Now dt_tracing is first.
>
> > I have a slight suspicion that dt(4) is now becoming a way to add code
> > that would be otherwise unacceptable. Also, how "durable" are trace
> > points perceived? Is an added trace point an achieved advantage that
> > is difficult to remove even when its utility has diminished? There is
> > a similarity to (ad hoc) debug printfs too.
>
> As I understand dt(4) it is a replacement for debug printfs. But
> it has advantages. I can be turnd on selectively from userland.
> It does not spam the console, but can be processed in userland. It
> is always there, you don't have to recompile.
>
> Of course you always have the printf or tracepoint at the worng
> place. I think people debugging the code should move them to
> the useful places. Then we may end with generally useful tool.
> A least that is my hope.
>
> There are obvious places to debug. We have syscall entry and return.
> And I think reference counting is also generally interesting.
I'm happy if this can help debugging real reference counting issues. Do
you have a script that could be committed to /usr/share/btrace to show
how to track reference counting using these probes?
> Index: dev/dt/dt_prov_static.c
> ===================================================================
> RCS file: /data/mirror/openbsd/cvs/src/sys/dev/dt/dt_prov_static.c,v
> retrieving revision 1.13
> diff -u -p -r1.13 dt_prov_static.c
> --- dev/dt/dt_prov_static.c 17 Mar 2022 14:53:59 -0000 1.13
> +++ dev/dt/dt_prov_static.c 8 Apr 2022 09:40:29 -0000
> @@ -87,6 +87,12 @@ DT_STATIC_PROBE1(smr, barrier_exit, "int
> DT_STATIC_PROBE0(smr, wakeup);
> DT_STATIC_PROBE2(smr, thread, "uint64_t", "uint64_t");
>
> +/*
> + * reference counting
> + */
> +DT_STATIC_PROBE0(refcnt, none);
> +DT_STATIC_PROBE3(refcnt, inpcb, "void *", "int", "int");
> +DT_STATIC_PROBE3(refcnt, tdb, "void *", "int", "int");
>
> /*
> * List of all static probes
> @@ -127,15 +133,24 @@ struct dt_probe *const dtps_static[] = {
> &_DT_STATIC_P(smr, barrier_exit),
> &_DT_STATIC_P(smr, wakeup),
> &_DT_STATIC_P(smr, thread),
> + /* refcnt */
> + &_DT_STATIC_P(refcnt, none),
> + &_DT_STATIC_P(refcnt, inpcb),
> + &_DT_STATIC_P(refcnt, tdb),
> };
>
> +struct dt_probe *const *dtps_index_refcnt;
> +
> int
> dt_prov_static_init(void)
> {
> int i;
>
> - for (i = 0; i < nitems(dtps_static); i++)
> + for (i = 0; i < nitems(dtps_static); i++) {
> + if (dtps_static[i] == &_DT_STATIC_P(refcnt, none))
> + dtps_index_refcnt = &dtps_static[i];
> dt_dev_register_probe(dtps_static[i]);
> + }
>
> return i;
> }
> Index: dev/dt/dtvar.h
> ===================================================================
> RCS file: /data/mirror/openbsd/cvs/src/sys/dev/dt/dtvar.h,v
> retrieving revision 1.13
> diff -u -p -r1.13 dtvar.h
> --- dev/dt/dtvar.h 27 Feb 2022 10:14:01 -0000 1.13
> +++ dev/dt/dtvar.h 8 Apr 2022 09:42:19 -0000
> @@ -313,11 +313,30 @@ extern volatile uint32_t dt_tracing; /*
> #define DT_STATIC_ENTER(func, name, args...) do {
> \
> extern struct dt_probe _DT_STATIC_P(func, name); \
> struct dt_probe *dtp = &_DT_STATIC_P(func, name); \
> - struct dt_provider *dtpv = dtp->dtp_prov; \
> \
> if (__predict_false(dt_tracing) && \
> __predict_false(dtp->dtp_recording)) { \
> + struct dt_provider *dtpv = dtp->dtp_prov; \
> + \
> dtpv->dtpv_enter(dtpv, dtp, args); \
> + } \
> +} while (0)
> +
> +#define _DT_INDEX_P(func) (dtps_index_##func)
> +
> +#define DT_INDEX_ENTER(func, index, args...) do { \
> + extern struct dt_probe **_DT_INDEX_P(func); \
> + \
> + if (__predict_false(dt_tracing) && \
> + __predict_false(index > 0) && \
> + __predict_true(_DT_INDEX_P(func) != NULL)) { \
> + struct dt_probe *dtp = _DT_INDEX_P(func)[index]; \
> + \
> + if(__predict_false(dtp->dtp_recording)) { \
> + struct dt_provider *dtpv = dtp->dtp_prov; \
> + \
> + dtpv->dtpv_enter(dtpv, dtp, args); \
> + } \
> } \
> } while (0)
>
> Index: kern/kern_synch.c
> ===================================================================
> RCS file: /data/mirror/openbsd/cvs/src/sys/kern/kern_synch.c,v
> retrieving revision 1.185
> diff -u -p -r1.185 kern_synch.c
> --- kern/kern_synch.c 18 Mar 2022 15:32:06 -0000 1.185
> +++ kern/kern_synch.c 8 Apr 2022 09:40:29 -0000
> @@ -804,7 +804,15 @@ sys___thrwakeup(struct proc *p, void *v,
> void
> refcnt_init(struct refcnt *r)
> {
> + refcnt_init_trace(r, 0);
> +}
> +
> +void
> +refcnt_init_trace(struct refcnt *r, int idx)
> +{
> + r->r_traceidx = idx;
> atomic_store_int(&r->r_refs, 1);
> + TRACEINDEX(refcnt, r->r_traceidx, r, 0, +1);
> }
>
> void
> @@ -814,6 +822,7 @@ refcnt_take(struct refcnt *r)
>
> refs = atomic_inc_int_nv(&r->r_refs);
> KASSERT(refs != 0);
> + TRACEINDEX(refcnt, r->r_traceidx, r, refs - 1, +1);
> (void)refs;
> }
>
> @@ -824,6 +833,7 @@ refcnt_rele(struct refcnt *r)
>
> refs = atomic_dec_int_nv(&r->r_refs);
> KASSERT(refs != ~0);
> + TRACEINDEX(refcnt, r->r_traceidx, r, refs + 1, -1);
> return (refs == 0);
> }
>
> @@ -842,11 +852,13 @@ refcnt_finalize(struct refcnt *r, const
>
> refs = atomic_dec_int_nv(&r->r_refs);
> KASSERT(refs != ~0);
> + TRACEINDEX(refcnt, r->r_traceidx, r, refs + 1, -1);
> while (refs) {
> sleep_setup(&sls, r, PWAIT, wmesg, 0);
> refs = atomic_load_int(&r->r_refs);
> sleep_finish(&sls, refs);
> }
> + TRACEINDEX(refcnt, r->r_traceidx, r, refs, 0);
> }
>
> int
> @@ -855,6 +867,7 @@ refcnt_shared(struct refcnt *r)
> u_int refs;
>
> refs = atomic_load_int(&r->r_refs);
> + TRACEINDEX(refcnt, r->r_traceidx, r, refs, 0);
> return (refs > 1);
> }
>
> @@ -864,6 +877,7 @@ refcnt_read(struct refcnt *r)
> u_int refs;
>
> refs = atomic_load_int(&r->r_refs);
> + TRACEINDEX(refcnt, r->r_traceidx, r, refs, 0);
> return (refs);
> }
>
> Index: netinet/in_pcb.c
> ===================================================================
> RCS file: /data/mirror/openbsd/cvs/src/sys/netinet/in_pcb.c,v
> retrieving revision 1.264
> diff -u -p -r1.264 in_pcb.c
> --- netinet/in_pcb.c 22 Mar 2022 18:02:54 -0000 1.264
> +++ netinet/in_pcb.c 8 Apr 2022 09:40:29 -0000
> @@ -235,7 +235,7 @@ in_pcballoc(struct socket *so, struct in
> return (ENOBUFS);
> inp->inp_table = table;
> inp->inp_socket = so;
> - refcnt_init(&inp->inp_refcnt);
> + refcnt_init_trace(&inp->inp_refcnt, DT_REFCNT_IDX_INPCB);
> inp->inp_seclevel[SL_AUTH] = IPSEC_AUTH_LEVEL_DEFAULT;
> inp->inp_seclevel[SL_ESP_TRANS] = IPSEC_ESP_TRANS_LEVEL_DEFAULT;
> inp->inp_seclevel[SL_ESP_NETWORK] = IPSEC_ESP_NETWORK_LEVEL_DEFAULT;
> Index: netinet/ip_ipsp.c
> ===================================================================
> RCS file: /data/mirror/openbsd/cvs/src/sys/netinet/ip_ipsp.c,v
> retrieving revision 1.269
> diff -u -p -r1.269 ip_ipsp.c
> --- netinet/ip_ipsp.c 10 Mar 2022 15:21:08 -0000 1.269
> +++ netinet/ip_ipsp.c 8 Apr 2022 09:40:29 -0000
> @@ -1048,7 +1048,7 @@ tdb_alloc(u_int rdomain)
>
> tdbp = pool_get(&tdb_pool, PR_WAITOK | PR_ZERO);
>
> - refcnt_init(&tdbp->tdb_refcnt);
> + refcnt_init_trace(&tdbp->tdb_refcnt, DT_REFCNT_IDX_TDB);
> mtx_init(&tdbp->tdb_mtx, IPL_SOFTNET);
> TAILQ_INIT(&tdbp->tdb_policy_head);
>
> Index: sys/refcnt.h
> ===================================================================
> RCS file: /data/mirror/openbsd/cvs/src/sys/sys/refcnt.h,v
> retrieving revision 1.6
> diff -u -p -r1.6 refcnt.h
> --- sys/refcnt.h 16 Mar 2022 14:13:01 -0000 1.6
> +++ sys/refcnt.h 8 Apr 2022 09:40:29 -0000
> @@ -21,24 +21,30 @@
>
> /*
> * Locks used to protect struct members in this file:
> + * I immutable after creation
> * a atomic operations
> */
>
> struct refcnt {
> unsigned int r_refs; /* [a] reference counter */
> + int r_traceidx; /* [I] index for dt(4) tracing */
> };
>
> -#define REFCNT_INITIALIZER() { .r_refs = 1 }
> +#define REFCNT_INITIALIZER() { .r_refs = 1, .r_traceidx = 0 }
>
> #ifdef _KERNEL
>
> void refcnt_init(struct refcnt *);
> +void refcnt_init_trace(struct refcnt *, int id);
> void refcnt_take(struct refcnt *);
> int refcnt_rele(struct refcnt *);
> void refcnt_rele_wake(struct refcnt *);
> void refcnt_finalize(struct refcnt *, const char *);
> int refcnt_shared(struct refcnt *);
> unsigned int refcnt_read(struct refcnt *);
> +
> +#define DT_REFCNT_IDX_INPCB 1
> +#define DT_REFCNT_IDX_TDB 2
>
> #endif /* _KERNEL */
>
> Index: sys/tracepoint.h
> ===================================================================
> RCS file: /data/mirror/openbsd/cvs/src/sys/sys/tracepoint.h,v
> retrieving revision 1.1
> diff -u -p -r1.1 tracepoint.h
> --- sys/tracepoint.h 21 Jan 2020 16:16:23 -0000 1.1
> +++ sys/tracepoint.h 8 Apr 2022 09:40:29 -0000
> @@ -25,11 +25,13 @@
> #if NDT > 0
> #include <dev/dt/dtvar.h>
>
> -#define TRACEPOINT(func, name, args...) DT_STATIC_ENTER(func, name,
> args)
> +#define TRACEPOINT(func, name, args...) DT_STATIC_ENTER(func, name,
> args)
> +#define TRACEINDEX(func, index, args...) DT_INDEX_ENTER(func, index, args)
>
> #else /* NDT > 0 */
>
> -#define TRACEPOINT(func, name, args...)
> +#define TRACEPOINT(func, name, args...)
> +#define TRACEINDEX(func, index, args...)
>
> #endif /* NDT > 0 */
> #endif /* _KERNEL */
