[DTrace-devel] [PATCH v2] Introduce 'bpflog' runtime option to request BPF verifier log

[Kris Van Hees]

On Sat, Aug 07, 2021 at 12:56:34AM -0400, Eugene Loh wrote:
> I still need to digest the email on this patch, but meanwhile I had a 
> question below...
> 
> On 7/29/21 11:38 PM, Kris Van Hees wrote:
> > The default behaviour is to only print the BPF verifier log when a BPF
> > program fails to load.  It is sometimes desirable to obtain the BPF
> > verifier log for successful prgoram loads to assist in debugging other
> > issues with BPF programs.  Specifying -xbpflog on the command line or
> > setting this option using a pragma will force printing of the BPF
> > verifier log for all program loads.
> >   
> > diff --git a/libdtrace/dt_bpf.c b/libdtrace/dt_bpf.c
> > @@ -406,14 +406,14 @@ dt_bpf_load_prog(dtrace_hdl_t *dtp, const dt_probe_t *prp,
> >   	attr.insns_cnt = dp->dtdo_len;
> >   	attr.license = BPF_CG_LICENSE;
> >   
> > -	rc = bpf_load_program_xattr(&attr, NULL, 0);
> > -	if (rc >= 0)
> > -		return rc;
> > +	if (dtp->dt_options[DTRACEOPT_BPFLOG] == DTRACEOPT_UNSET) {
> > +		rc = bpf_load_program_xattr(&attr, NULL, 0);
> > +		if (rc >= 0)
> > +			return rc;
> > +
> > +		origerrno = errno;
> > +	}
> >   
> > -	/* if failure, note error and rerun with logging */
> > -	dt_bpf_error(dtp, "BPF program load for '%s:%s:%s:%s' failed: %s\n",
> > -			  pdp->prv, pdp->mod, pdp->fun, pdp->prb,
> > -			  strerror(errno));
> >   	if (dtp->dt_options[DTRACEOPT_BPFLOGSIZE] != DTRACEOPT_UNSET)
> >   		logsz = dtp->dt_options[DTRACEOPT_BPFLOGSIZE];
> >   	else
> > @@ -422,34 +422,40 @@ dt_bpf_load_prog(dtrace_hdl_t *dtp, const dt_probe_t *prp,
> >   	log = dt_zalloc(dtp, logsz);
> >   	assert(log != NULL);
> >   	rc = bpf_load_program_xattr(&attr, log, logsz);
> > +	if (rc < 0) {
> > +		dt_bpf_error(dtp, "BPF program load for '%s:%s:%s:%s' failed: "
> > +				  "%s\n",
> > +			     pdp->prv, pdp->mod, pdp->fun, pdp->prb,
> > +			     strerror(origerrno ? origerrno : errno));
> > +
> > +		/* check whether we have an incomplete BPF log */
> > +		if (errno == ENOSPC) {
> > +			fprintf(stderr,
> > +				"BPF verifier log is incomplete and is not reported.\n"
> > +				"Set DTrace option 'bpflogsize' to some greater size for more output.\n"
> > +				"(Current size is %ld.)\n", logsz);
> > +			goto out;
> > +		}
> > +	} else if (dtp->dt_options[DTRACEOPT_BPFLOGSIZE] == DTRACEOPT_UNSET)
> > +		goto out;
> 
> I don't get this.  There is a default bpflogsize.  But if you specify 
> -xbpflog by itself, you won't get the log.  You also have to specify 
> bpflogsize explicitly?  Why?

Bug.  This should read:

	} else if (dtp->dt_options[DTRACEOPT_BPFLOG] == DTRACEOPT_UNSET)
		goto out;

Next version will have that (I forgot to post a new one when I found this
issue last week).  Mea culpa.

> 
> > -	/* since it failed once, it should fail again */
> > -	assert(rc < 0);
> > -
> > -	/* check whether we have an incomplete BPF log */
> > -	if (errno == ENOSPC) {
> > -		fprintf(stderr,
> > -		    "BPF verifier log is incomplete and is not reported.\n"
> > -		    "Set DTrace option 'bpflogsize' to some greater size for more output.\n"
> > -		    "(Current size is %ld.)\n", logsz);
> > -	} else {
> > -		/*
> > -		 * If there is BPF verifier output, print it with a "BPF: "
> > -		 * prefix so it is easier to distinguish.
> > -		 */
> > -		for (p = log; p && *p; p = q) {
> > -			q = strchr(p, '\n');
> > +	/*
> > +	 * If there is BPF verifier output, print it with a "BPF: "
> > +	 * prefix so it is easier to distinguish.
> > +	 */
> > +	for (p = log; p && *p; p = q) {
> > +		q = strchr(p, '\n');
> >   
> > -			if (q)
> > -				*q++ = '\0';
> > +		if (q)
> > +			*q++ = '\0';
> >   
> > -			fprintf(stderr, "BPF: %s\n", p);
> > -		}
> > +		fprintf(stderr, "BPF: %s\n", p);
> >   	}
> >   
> > +out:
> >   	dt_free(dtp, log);
> >   
> > -	return -1;
> > +	return rc >= 0 ? rc : -1;
> >   }
> 
> _______________________________________________
> DTrace-devel mailing list
> DTrace-devel at oss.oracle.com
> https://oss.oracle.com/mailman/listinfo/dtrace-devel