Re: [PATCH] proof-of-concept for svnserve logging

On Feb 16, 2008 1:23 PM, Karl Fogel <kfogel_at_red-bean.com> wrote:
> "David Glasser" <glasser_at_davidglasser.net> writes:
> > svnserve logging has been punted for years in search of a
> > fully-fleshed-out solution. This is fine. But to start with, here's
> > a proof of concept (which does, to some degree, actually work), just
> > for the record.
> > --- subversion/libsvn_ra_svn/ra_svn.h (revision 29387)
> > +++ subversion/libsvn_ra_svn/ra_svn.h (working copy)
> > @@ -80,6 +80,7 @@ struct svn_ra_svn_conn_st {
> > ra_svn_block_handler_t block_handler;
> > void *block_baton;
> > apr_hash_t *capabilities;
> > + char *remote_ip;
> > apr_pool_t *pool;
> > };
>
> Any reason not to make this 'const'?

The APR function that filled it in didn't like that.

> > --- subversion/svnserve/main.c (revision 29387)
> > +++ subversion/svnserve/main.c (working copy)
> > @@ -503,6 +515,11 @@ int main(int argc, const char *argv[])
> > svn_path_dirname(config_filename, pool),
> > pool));
> >
> > + if (log_filename)
> > + SVN_INT_ERR(svn_io_file_open(&params.log_file, log_filename,
> > + APR_WRITE | APR_CREATE | APR_APPEND,
> > + APR_OS_DEFAULT, pool));
> > +
> > if (params.tunnel_user && run_mode != run_mode_tunnel)
> > {
> > svn_error_clear
>
> I know everyone has the C precedence rules tattooed onto the insides
> of their eyelids, but just to save people the trouble of closing their
> eyes when reading the code, I usually do "&(params.log_file)". YMMV.
>
> (Yeah, even without the parens it wouldn't make sense the other way,
> but it can takes a split second to realize that.)

Sure.

> > --- subversion/svnserve/serve.c (revision 29387)
> > +++ subversion/svnserve/serve.c (working copy)
> > @@ -148,6 +152,31 @@ static svn_error_t *get_fs_path(const ch
> > return SVN_NO_ERROR;
> > }
> >
> > +static svn_error_t *svnserve_log(server_baton_t *b,
> > + svn_ra_svn_conn_t *conn,
> > + const char *command,
> > + apr_pool_t *pool)
> > +{
> > + const char *buf, *remote_host, *timestr;
> > +
> > + if (b->log_file == NULL)
> > + return SVN_NO_ERROR;
> > +
> > + remote_host = svn_ra_svn_conn_remote_host(conn);
> > + timestr = svn_time_to_cstring(apr_time_now(), pool);
> > +
> > + buf = apr_psprintf(pool, "%" APR_PID_T_FMT
> > + " %s %s %s %s\n",
> > + getpid(),
> > + (remote_host ? remote_host : "-"),
> > + (b->user ? b->user : "-"), timestr,
> > + command);
> > +
> > + return svn_io_file_write_full(b->log_file, buf, strlen(buf), NULL, pool);
> > +}
>
> Hmmm, if this took varargs 'const char *' arguments, it could print
> not only the command, but the important arguments. I guess you were
> basically saying the same thing when you wrote "It just logs the name
> of the command executed; nothing more" in the log message.

Yes; I would like it to match the SVN-ACTION from DAV, more or less.

> If we put time stamps in, are you sure that we should switch to
> file_write() instead of file_write_full() (which you advocated in a
> later email, on the grounds that truncation of a given entry would be
> better than interleaved entries)?

I'm basing this off of examination of the httpd logging code. In
fact, a change there from using apr_file_write to using something that
didn't guarantee atomicity (apr_file_writev in this case) was vetoed
by Roy Fieldings and reverted. I don't think time stamps makes a
difference; if you end up with half a log line farther down the file,
there's no wayto know what it goes with.

> > +#define SLOG(command) SVN_ERR(svnserve_log(baton, conn, (command), pool))
>
> And of course, if varargs, then we can't use this macro to log
> anymore. But that doesn't seem like a huge price to pay.

Yes, this is temporary.

> > --- subversion/svnserve/server.h (revision 29387)
> > +++ subversion/svnserve/server.h (working copy)
> > @@ -46,6 +46,7 @@ typedef struct server_baton_t {
> > #ifdef SVN_HAVE_SASL
> > svn_boolean_t use_sasl; /* Use Cyrus SASL for authentication */
> > #endif
> > + apr_file_t *log_file; /* Log filehandle. */
> > apr_pool_t *pool;
> > } server_baton_t;
>
> Should state that if NULL, that means log calls will have no effect...
>
> > @@ -90,6 +91,9 @@ typedef struct serve_params_t {
> > command line, or it was specified and it did not refer to a
> > authorization database. */
> > svn_authz_t *authzdb;
> > +
> > + /* A filehandle open for writing logs to; possibly NULL. */
> > + apr_file_t *log_file;
> > } serve_params_t;
>
> ...as you state here.
>
> +1 on committing it to trunk and finishing the rest there; this seems
> like a sane plan overall.

I'd like to get it to rough output parity with SVN-ACTION first
(including making the backwards-incompatible changes to SVN-ACTION
proposed in another email). And I don't think it's particularly
useful without being able to rotate logs with SIGHUP. If I don't make
these changes next week I'll stick it on a branch.

--dave

-- 
David Glasser | glasser@davidglasser.net | http://www.davidglasser.net/
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe_at_subversion.tigris.org
For additional commands, e-mail: dev-help_at_subversion.tigris.org