logging (but see below)

The logging is both for paranoia and parsing/automated processing.  The
ones you're probably interested in parsing should be easy to pick out
and are very likely to have tab-delimited fields already.

src/Gitolite/Common.pm

@@ -10,6 +10,8 @@ package Gitolite::Common;
   say2    _die    _system slurp             tsh_lines
           trace           cleanup_conf_line tsh_try
           usage                             tsh_run
+          gen_ts_lfn
+          gl_log
 );
 #>>>
 use Exporter 'import';
@@ -65,6 +67,7 @@ sub _warn {
 }
 
 sub _die {
+    gl_log("_die:", @_);
     if ( $ENV{D} and $ENV{D} >= 3 ) {
         confess "FATAL: " . join( ",", @_ ) . "\n" if defined( $ENV{D} );
     } elsif ( defined( $ENV{D} ) ) {
@@ -108,6 +111,7 @@ sub _system {
     # run system(), catch errors.  Be verbose only if $ENV{D} exists.  If not,
     # exit with <rc of system()> if it applies, else just "exit 1".
     trace( 2, @_ );
+    gl_log("_system:", @_);
     if ( system(@_) != 0 ) {
         trace( 1, "system() failed", @_, "-> $?" );
         if ( $? == -1 ) {
@@ -200,6 +204,51 @@ sub cleanup_conf_line {
     }
 }
 
+# generate a timestamp.  If a template is passed generate a log file name
+# based on it also
+sub gen_ts_lfn {
+    my ($s, $min, $h, $d, $m, $y) = (localtime)[0..5];
+    $y += 1900; $m++;               # usual adjustments
+    for ($s, $min, $h, $d, $m) {
+        $_ = "0$_" if $_ < 10;
+    }
+    my $ts = "$y-$m-$d.$h:$min:$s";
+
+    return $ts unless @_;
+
+    my($template) = shift;
+    # substitute template parameters and set the logfile name
+    $template =~ s/%y/$y/g;
+    $template =~ s/%m/$m/g;
+    $template =~ s/%d/$d/g;
+
+    return ($ts, $template);
+}
+
+sub gl_log {
+    # the log filename and the timestamp come from the environment.  If we get
+    # called even before they are set, we have no choice but to dump to STDERR
+    # (and probably call "logger").
+    my $msg = join("\t", @_);
+
+    my $ts = $ENV{GL_TS} || gen_ts_lfn();
+
+    my $fh;
+    logger_plus_stderr("$ts no GL_LOGFILE env var", "$ts $msg") if not $ENV{GL_LOGFILE};
+    open my $lfh, ">>", $ENV{GL_LOGFILE} or logger_plus_stderr("open log failed: $!", $msg);
+    print $lfh "$ts\t$msg\n";
+    close $lfh;
+}
+
+sub logger_plus_stderr {
+    open my $fh, "|-", "logger" or confess "it's really not my day is it...?\n";
+    for ( "FATAL: have errors but logging failed!\n", @_ ) {
+        print STDERR "$_\n";
+        print $fh "$_\n";
+    }
+    exit 1;
+}
+
 # ----------------------------------------------------------------------
 
 # bare-minimum subset of 'Tsh' (see github.com/sitaramc/tsh)

src/Gitolite/Hooks/PostUpdate.pm

@@ -20,6 +20,7 @@ use warnings;
 
 sub post_update {
     trace( 2, @ARGV );
+    gl_log( 'post-update', @ARGV );
     # this is the *real* post_update hook for gitolite
 
     tsh_try("git ls-tree --name-only master");

src/Gitolite/Hooks/Update.pm

@@ -20,15 +20,18 @@ use warnings;
 
 sub update {
     trace( 2, @ARGV );
+    gl_log( 'update', @ARGV );
     # this is the *real* update hook for gitolite
 
     my ( $ref, $oldsha, $newsha, $oldtree, $newtree, $aa ) = args(@ARGV);
 
     my $ret = access( $ENV{GL_REPO}, $ENV{GL_USER}, $aa, $ref );
     trace( 1, "access($ENV{GL_REPO}, $ENV{GL_USER}, $aa, $ref)", "-> $ret" );
+    gl_log( 'update:check', $ENV{GL_REPO}, $ENV{GL_USER}, $aa, $ref, '->', $ret );
     _die $ret if $ret =~ /DENIED/;
 
     check_vrefs( $ref, $oldsha, $newsha, $oldtree, $newtree, $aa );
+    gl_log( 'update:OK', $ENV{GL_REPO}, $ENV{GL_USER}, $aa, @ARGV );
 
     exit 0;
 }

src/Gitolite/Rc.pm

@@ -28,14 +28,16 @@ our %rc;
 
 # ----------------------------------------------------------------------
 
-# variables that are/could be/should be in the rc file
+# variables that could be overridden by the rc file
 # ----------------------------------------------------------------------
 
-$rc{GL_BINDIR}     = $ENV{GL_BINDIR};
-$rc{GL_ADMIN_BASE} = "$ENV{HOME}/.gitolite";
-$rc{GL_REPO_BASE}  = "$ENV{HOME}/repositories";
+$rc{GL_BINDIR}    = $ENV{GL_BINDIR};
+$rc{GL_REPO_BASE} = "$ENV{HOME}/repositories";
 
-# variables that should probably never be changed
+$rc{GL_ADMIN_BASE} = "$ENV{HOME}/.gitolite";
+$rc{LOG_TEMPLATE}  = "$ENV{HOME}/.gitolite/logs/gitolite-%y-%m.log";
+
+# variables that should probably never be changed but someone will want to, I'll bet...
 # ----------------------------------------------------------------------
 
 $REMOTE_COMMAND_PATT  = qr(^[- 0-9a-zA-Z\@\%_=+:,./]*$);
@@ -47,6 +49,9 @@ $UNSAFE_PATT          = qr([`~#\$\&()|;<>]);
 
 # ----------------------------------------------------------------------
 
+# find the rc file and 'do' it
+# ----------------------------------------------------------------------
+
 my $current_data_version = "3.0";
 
 my $rc = glrc('filename');
@@ -55,13 +60,22 @@ _die "$rc seems to be for older gitolite" if defined($GL_ADMINDIR);
 # let values specified in rc file override our internal ones
 @rc{ keys %RC } = values %RC;
 
-# testing sometimes requires all of it to be overridden silently; use an
-# env var that is highly unlikely to appear in real life :)
+# (testing only) testing sometimes requires all of it to be overridden
+# silently; use an env var that is highly unlikely to appear in real life :)
 do $ENV{G3T_RC} if exists $ENV{G3T_RC} and -r $ENV{G3T_RC};
 
+# fix some env vars, setup gitolite internal "env" vars (aka rc vars)
+# ----------------------------------------------------------------------
+
 # fix PATH (TODO: do it only if 'gitolite' isn't in PATH)
 $ENV{PATH} = "$ENV{GL_BINDIR}:$ENV{PATH}";
 
+{
+    my ( $ts, $lfn ) = gen_ts_lfn( $rc{LOG_TEMPLATE} );
+    $rc{GL_LOGFILE} = $ENV{GL_LOGFILE} = $lfn;
+    $rc{GL_TS}      = $ENV{GL_TS}      = $ts;
+}
+
 # ----------------------------------------------------------------------
 
 use strict;

src/Gitolite/Setup.pm

@@ -97,6 +97,7 @@ sub setup_gladmin {
       and _print( "VERSION", tsh_text() );
 
     _mkdir("conf");
+    _mkdir("logs");
     my $conf;
     {
         local $/ = undef;

src/gitolite

@@ -46,6 +46,7 @@ use warnings;
 # ----------------------------------------------------------------------
 
 my ( $command, @args ) = @ARGV;
+gl_log( 'gitolite', @ARGV ) if -d $rc{GL_ADMIN_BASE};
 args();
 
 # the first two commands need options via @ARGV, as they have their own

src/gitolite-shell

@@ -50,6 +50,7 @@ sub in_ssh {
 # call this once you are sure arg-1 is the username and SSH_ORIGINAL_COMMAND
 # has been setup (even if it's not actually coming via ssh).
 sub main {
+    gl_log( 'gitolite-shell', @ARGV, $ENV{SSH_ORIGINAL_COMMAND} );
     umask $rc{UMASK};
 
     # set up the user
@@ -66,6 +67,7 @@ sub main {
         require Gitolite::Conf::Store;
         Gitolite::Conf::Store->import;
         new_wild_repo( $repo, $user );
+        gl_log( 'gitolite-shell:new_wild_repo', $repo, $user );
     }
 
     # a ref of 'any' signifies that this is a pre-git check, where we don't
@@ -74,6 +76,7 @@ sub main {
     # more information.
     my $ret = access( $repo, $user, $aa, 'any' );
     trace( 1, "access($repo, $user, $aa, 'any')", "-> $ret" );
+    gl_log( 'gitolite-shell:check', $repo, $user, $aa, 'any', '->', $ret );
     _die $ret if $ret =~ /DENIED/;
 
     $repo = "'$rc{GL_REPO_BASE}/$repo.git'";

t/ssh-basic.t

@@ -26,7 +26,7 @@ try "
     cp $bd/../t/keys/*.pub $ab/keydir;      ok or die 6
 ";
 
-_system("gitolite post-compile/ssh-authkeys");
+system("gitolite post-compile/ssh-authkeys");
 
 # basic tests
 # ----------------------------------------------------------------------