Re: [PATCH] libsvn_repos logging API -- first draft

Ben Collins-Sussman wrote:

> +/** Accessors for repository's logfiles and loglevel. These things
> + * are set at runtime by the server (in something like svnserve.conf
> + * or httpd.conf).
> + */
> +
> +/** Set the error-logging threshold of @repos to @loglevel. Use @a

"@a repos to @a loglevel" ...

>
> +/** Write @a message into the accesslog of @a repos. If not @c NULL,
> + * then also include the following information in the log entry:
> + *
> + * @a process_name : the name of the process using libsvn_repos.
> + * (if @c NULL, write "(unknown process)").
> + * @a sockaddr : the IP address of the incoming request.
> + * (if @c NULL, write "(unknown IP)").
> + * @a username : the authenticated username attached to the
> request.
> + * (if @c NULL, write "(unknown user)").
> + *
> + * Use @a pool for temporary memory allocation.
> + */
> +svn_error_t *
> +svn_repos_write_accesslog (svn_repos_t *repos,
> + const char *process_name,
> + apr_sockaddr_t *sockaddr,
> + const char *username,
> + const char *message,
> + apr_pool_t *pool);

Hm. I wonder, wouldn't it be easier if you had an
svn_repos_set_process_name, and ommitted the process_name parameter
everywhere? After all, it's not very likely that different processes
would use the same svn_repos_t, or that the process' "name" would change
often.

IP and username change more often, but since it's likely that you'd
write more than one message per request, setting them separately might
make sense.

> +/** Write @a message into the errorlog of @a repos, if and only if the
> + * current loglevel of @a repos is greater than or equal to @a
> + * loglevel (see @c svn_repos_set_loglevel). If not @c NULL, then
> + * also include the following information in the log entry:
> + *
> + * @a process_name : the name of the process using libsvn_repos.
> + * (if @c NULL, write "(unknown process)").
> + *
> + * Use @a pool for temporary memory allocation.
> + */
> +svn_error_t *
> +svn_repos_write_errorlog (svn_repos_t *repos,
> + const char *process_name,
> + svn_repos_loglevel_t loglevel,
> + const char *message,
> + apr_pool_t *pool);

If you do keep the process_name parameter, please put it after the
loglevel. It seems cleaner that way.

One thing about this API has me worried, and that's the assumption that
you have to make a function call in order to check the log level; that
is, either svn_repos_write_errorlog checks the log level internally, or
some macro wrapper has to call svn_repos_get_loglevel before calling
svn_repos_write_errorlog.

Now, I hear people shouting "premature optimisation! function call
overhead is negligible!" Normally I'd agree, but i've been bitten by
this in error logging (debug tracing) systems before. What people tend
to forget is that when you write, e.g.,

  svn_repos_write_errorlog(repo, svn_repos_loglevel_debug,
                           "svnserve [$PID]",
                           apr_snprintf("gizmo %s frobbed twinkie %d",
                                        current_gizmo, current_twinkie),
                           pool);

all the function parameters get evaluated every time, regardless of
global log level. When you have many debug-level messages in the code,
those snprintf's pile up and can really slow things down.

A few years back we were using a tracing library that tested the trace
level inside the log functions. We were amazed that the server spent 25%
(!) of its CPU time in the tracing library (obviously, we relied quite a
bit on debug tracing). So we added wrappers that looked like this (using
the above AP)::

  #define SVN_REPOS_WRITE_ERRORLOG(repo, level, process, message, pool) \
    while { \
      svn_repos_loglevel_t loglevel; \
      SVN_ERR (svn_repos_get_loglevel (&loglevel, (repos), (pool))); \
      if ((level) <= loglevel) \
        SVN_ERR (svn_repos_write_errorlog ((repo), (level), (process), \
                                           (message), (pool))); \
    } while (0)

And suddenly our server ran 20% faster when the more verbose traces were
disabled.

Except that our API was different in two details:

    * The current log level was a global variable, so we didn't require
      a function call to retreive it.
    * The "write_errorlog" function did not return an error code.

Really, what are you going to do if your get_loglevel or write_errorlog
error out? Crash the server? I don't think so. By all means error out if
you can't open the log file, that usually happens at process startup.

This brings us to the accessor functions. As I understand it,
svn_repos_(get|set)_loglevel and svn_repos_(get|set)_(access|error)log
somply manipulate fields within the svn_repos_t. I fail to see how these
functions can fail (unless the svn_repos_t is NULL), or when they'd ever
need a pool -- any allocations they _do_ need can come from the
svn_repos_t's pool.

-- 
-- Brane
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org