Trace logging project

[Nicolas Williams]

On Tue, Sep 15, 2009 at 01:38:55PM -0400, Greg Hudson wrote:
> [Some out of band conversation ensues.]
> 
> Because the internal mechanism requires a context, there is an impedance
> mismatch between USDT-style macros and what is needed for the internal
> mechanism.  Also, we don't want our tracing calls to be mucking around
> with converting data structures like krb5_principals into strings; that
> needs to happen behind the covers (or perhaps not at all, for a USDT
> provider).

The macros can take the context argument.  When one goes to turn those
marcos into a USDT provider one would #define then to ignore the
krb5_context argument.  See examples below.

> As you noted, the most important thing is that there be some kind of
> symbolic identification of the trace point.  That would come at the cost
> of a big header file full of trace macro definitions, but it turns out
> that Tom likes this idea anyway.  So I think the tracing calls will look
> like:

I like that idea as well.  It gives you and others a lot more control
over what actually happens at each trace-point.  See below.

The other constraint that you mentioned is that the DTrace USDT macros
are not variadic.

>   TRACE_GET_CREDS(context, in_creds->client, in_creds->server, options);
> 
> and then the basic macro in the big header file would read something
> like:
> 
>   #define TRACE_GET_CREDS(c, client, server, flags) \
>     k5trace(c, "Getting credentials for %P -> %P with flags %F",
>             client, server, flags)

Yes.

> To add a USDT provider, one could add in a call to DTRACE_PROBE3 or to
> an automatically-generated macro, perhaps after converting the arguments
> to strings.  The changes might be a bit ugly if stringification is
> included, but would be confined to a single header file.

It's easier, actually: dtrace(1M) will actually generate macros called
PROVIDER_PROBE_ENABLED (for "is-enabled" probing) and PROVIDER_PROBE.

Suppose you call your macros TRACE_<trace-point-name> and that we want
the provider to be called "krb5", then the definitions that turns those
macros into USDT probe points would look like this:

#define TRACE_GET_CREDS(c, client, server, flags) \
	if (KRB5_GET_CREDS_ENABLED()) {
		variable decls; \
		stringification code; \
		KRB5_GET_CREDS(stringified_client, stringified_server, \
		    flags); \
		free stringified args; \
	}

or

#define TRACE_GET_CREDS(c, client, server, flags) \
	KRB5_GET_CREDS(client, server, flags);

The first form is for when you want the probe arguments to be
stringified state, which otherwise a DTrace script writer would have to
use copyin() and additional script and other code to get at.

Note that the "if (..._ENABLED())" idiom can be used in your version of
these macros too, which nets you fine-grained trace-point enable/disable
control.

This way you can have a poor man's DTrace, the real thing, or other
dynamic tracing facilities, all with zero changes to any of the main
krb5 code -- just minor changes to the build system and the addition of
a .d file.

A win-win all around, IMO.  Thanks!

Nico
--