logo_kerberos.gif

Difference between revisions of "Projects/Trace logging"

From K5Wiki
Jump to: navigation, search
(→‎Background)
 
(13 intermediate revisions by 2 users not shown)
Line 1: Line 1:
−
{{project-review|2009-09-18}}
 +
{{project-rel|1.9}}
   
 
==Background==
  
==Background==
Line 6: Line 6:
   
 
* It must be possible to turn on tracing for some processes and not others.
  
* It must be possible to turn on tracing for some processes and not others.
  +
* It must be possible to enable tracing for a program with no special application support for tracing.
  +
* It must be possible to enable and disable tracing dynamically within a running process. It is acceptable, though not desirable, for this functionality to require application support.
 
* It is important that it be possible to enable trace logging in a standard build, such as the one shipped by the operating system vendor, because it is generally not possible to substitute specially compiled code in a customer deployment.
  
* It is important that it be possible to enable trace logging in a standard build, such as the one shipped by the operating system vendor, because it is generally not possible to substitute specially compiled code in a customer deployment.
 
* The facility must not compromise the security of setuid programs by allowing the invoking user to leak information or write log files using elevated privileges.
  
* The facility must not compromise the security of setuid programs by allowing the invoking user to leak information or write log files using elevated privileges.
Line 14: Line 16:
 
==User Interface==
  
==User Interface==
   
−
To turn on tracing, the user will set the KRB5_TRACE variable to a filename. This will not work for secure contexts.
 +
Tracing can be enabled by setting the KRB5_TRACE environment variable to a filename. This will not work for secure contexts.
   
−
To disable tracing at compile time, the builder will specify --disable-tracing to configure.
  
  +
Tracing can be controlled by the application using either of the following APIs:
   
−
==Design==
  
  +
/* This structure may be extended to contain more fields in the future. */
  +
struct krb5_trace_info {
  +
const char *message;
  +
};
  +
typedef void (*krb5_trace_callback)(krb5_context context, struct krb5_trace_info *info, void *cb_data);
  +
krb5_error_code krb5_set_trace_filename(krb5_context context, const char *filename);
  +
krb5_error_code krb5_set_trace_callback(krb5_context context, krb5_trace_callback fn, void *cb_data);
   
−
Trace logging will be done with k5trace(), which has the following signature:
  
  +
Either callback can be invoked with NULL to disable tracing. The use of either API to enable tracing will disable any previous tracing. When a trace callback is disabled (either through destruction of the krb5_context or through a subsequent call to one of the above APIs), the callback will be invoked with a NULL info argument to allow destruction of cb_data.
   
−
void k5trace(krb5_context context, const char *fmt, ...)
  
  +
To disable tracing at compile time, the builder will specify --disable-tracing to configure. In this case, the aforementioned APIs will still exist, but will return KRB5_TRACE_NOSUPP.
   
−
Tracing calls will use a custom formatter, adapted from the debugging code previously in lib/krb5/os/sendto_kdc.c, to facilitate the display of principal names, krb5_data structures, and the like.
  
  +
==Tracing API==
   
−
For performance reasons, k5trace() will be a macro (if variadic macros are supported by the compiler) or inline function which only calls the true back-end function krb5int_trace() when tracing is enabled in the context. If a macro is used, k5trace arguments will not be evaluated unless tracing is enabled, minimizing the runtime footprint.
  
  +
Each trace point will have a separate macro; an example invocation for credential acquisition might be:
   
−
The krb5_context structure will gain a new field trace_fd, which will have the value -1 if tracing is not enabled. The function krb5int_init_trace will initialize trace_fd if KRB5_TRACE is defined in the environment.
  
  +
TRACE_GET_CREDS(context, in_creds->client, in_creds->server, options)
   
−
==Review==
  
  +
The header file k5-trace.h (included by k5-int.h) will define the tracing macros in terms of the function krb5int_trace, which has the signature:
   
−
This section documents the review of the project according to [[Project policy]].
  
  +
static void krb5int_trace(krb5_context *context, const char *fmt, ...);
−
It is divided into multiple sections. First, approvals should be listed. To list an approval type
  
−
:<nowiki>#~~~~</nowiki>
  
−
on its own line.
  
−
The next section is for summarizing discussion, which should take place on krbdev@mit.edu. Provide links to the archive at http://mailman.mit.edu/pipermail/krbdev/ if appropriate. Blocking objections can be noted with <nowiki>{{project-block}}</nowiki>.
  
   
−
===Approvals===
  
  +
Each macro will supply a format string to krb5int_trace and pass in its arguments. krb5int_trace will implement a custom formatter, adapted from the debugging code previously in lib/krb5/os/sendto_kdc.c, to allow stringification of data types such as krb5_principal and krb5_data. Macro expansions will not evaluate arguments if tracing is disabled either at compile time or runtime, so arguments to these macros must not have side-effects.
   
−
===Discussion===
  
  +
Vendors can use k5-trace.h as an integration point for tracing systems such as DTrace, but we will not supply any such integrations at this time.
  +
  +
==Implementation Design==
  +
  +
The krb5_context structure will gain the following new fields:
  +
  +
krb5_trace_callback trace_callback;
  +
void *trace_callback_data;
  +
  +
In the simple case where trace output is being directed to a file (either via the KRB5_TRACE environment variable or the krb5_set_trace_filename API), trace_callback will be set to a built-in callback function and trace_callback_data will point to the file descriptor.
  +
  +
==Status==
  +
  +
The trace logging infrastructure has been implemented for 1.9. Trace events have been added for:
  +
  +
* AS-REQ client code, including FAST and preauth
  +
* TGS-REQ client code
  +
* AP-REQ and AP-REP code (client and server)
  +
* sendto_kdc
  +
* Selected ccache operations
  +
* Selected keytab operations
  +
  +
More trace events should be added for the 1.9 release, including:
  +
  +
* rcache
  +
* PKINIT
  +
* KDC do_as_req
  +
* KDC do_tgs_req
  +
* KDC preauth
  +
* Authdata
  +
* S4U
  +
* GSSAPI krb5 mech
  +
* GSSAPI SPNEGO mech
  +
  +
Also, experience adding trace log events suggests that perhaps there should be two levels of tracing detail. Current trace events are designed not to drown the user in output, but this means omitting sometimes useful information, such as PKINIT Diffie-Hellman results.

Latest revision as of 12:23, 12 October 2010

This project was completed in release 1.9.


Background

Multiple users of Kerberos have expressed a desire for logging to assist in the diagnosis of configuration failures. As a secondary benefit, such a facility may also be useful for debugging work by Kerberos developers. Requirements include:

  • It must be possible to turn on tracing for some processes and not others.
  • It must be possible to enable tracing for a program with no special application support for tracing.
  • It must be possible to enable and disable tracing dynamically within a running process. It is acceptable, though not desirable, for this functionality to require application support.
  • It is important that it be possible to enable trace logging in a standard build, such as the one shipped by the operating system vendor, because it is generally not possible to substitute specially compiled code in a customer deployment.
  • The facility must not compromise the security of setuid programs by allowing the invoking user to leak information or write log files using elevated privileges.
  • The facility must have a minimal impact on performance when not enabled.
  • It should be possible to explicitly disable the facility at compile-time for embedded deployments or kernel code.
  • Trace points must be symbolically distinct, and not distinguished only by a text string. (This is important for integration with vendor-supported tracing systems such as DTrace.)

User Interface

Tracing can be enabled by setting the KRB5_TRACE environment variable to a filename. This will not work for secure contexts.

Tracing can be controlled by the application using either of the following APIs: 

 /* This structure may be extended to contain more fields in the future. */
 struct krb5_trace_info {
     const char *message; 
 };
 typedef void (*krb5_trace_callback)(krb5_context context, struct krb5_trace_info *info, void *cb_data);
 krb5_error_code krb5_set_trace_filename(krb5_context context, const char *filename);
 krb5_error_code krb5_set_trace_callback(krb5_context context, krb5_trace_callback fn, void *cb_data);

Either callback can be invoked with NULL to disable tracing. The use of either API to enable tracing will disable any previous tracing. When a trace callback is disabled (either through destruction of the krb5_context or through a subsequent call to one of the above APIs), the callback will be invoked with a NULL info argument to allow destruction of cb_data.

To disable tracing at compile time, the builder will specify --disable-tracing to configure. In this case, the aforementioned APIs will still exist, but will return KRB5_TRACE_NOSUPP.

Tracing API

Each trace point will have a separate macro; an example invocation for credential acquisition might be: 

 TRACE_GET_CREDS(context, in_creds->client, in_creds->server, options)

The header file k5-trace.h (included by k5-int.h) will define the tracing macros in terms of the function krb5int_trace, which has the signature: 

 static void krb5int_trace(krb5_context *context, const char *fmt, ...);

Each macro will supply a format string to krb5int_trace and pass in its arguments. krb5int_trace will implement a custom formatter, adapted from the debugging code previously in lib/krb5/os/sendto_kdc.c, to allow stringification of data types such as krb5_principal and krb5_data. Macro expansions will not evaluate arguments if tracing is disabled either at compile time or runtime, so arguments to these macros must not have side-effects.

Vendors can use k5-trace.h as an integration point for tracing systems such as DTrace, but we will not supply any such integrations at this time.

Implementation Design

The krb5_context structure will gain the following new fields: 

 krb5_trace_callback trace_callback;
 void *trace_callback_data;

In the simple case where trace output is being directed to a file (either via the KRB5_TRACE environment variable or the krb5_set_trace_filename API), trace_callback will be set to a built-in callback function and trace_callback_data will point to the file descriptor.

Status

The trace logging infrastructure has been implemented for 1.9. Trace events have been added for:

  • AS-REQ client code, including FAST and preauth
  • TGS-REQ client code
  • AP-REQ and AP-REP code (client and server)
  • sendto_kdc
  • Selected ccache operations
  • Selected keytab operations

More trace events should be added for the 1.9 release, including:

  • rcache
  • PKINIT
  • KDC do_as_req
  • KDC do_tgs_req
  • KDC preauth
  • Authdata
  • S4U
  • GSSAPI krb5 mech
  • GSSAPI SPNEGO mech

Also, experience adding trace log events suggests that perhaps there should be two levels of tracing detail. Current trace events are designed not to drown the user in output, but this means omitting sometimes useful information, such as PKINIT Diffie-Hellman results.

Retrieved from "https://k5wiki.kerberos.org./wiki?title=Projects/Trace_logging&oldid=3663"