Merge remote-tracking branch 'baserock/baserock/richardipsum/syslog'

Also fix up test tool so that tests do not fail now that we depend
on the SSH_CLIENT environment variable coming from the caller.

8 files changed, 132 insertions, 13 deletions

diff --git a/Makefile b/Makefile
index 182b9ea..8c725ec 100644
--- a/Makefile
+++ b/Makefile
@@ -115,6 +115,9 @@ distclean: clean
 bin/%: bin/%.in $(GEN_BIN)
 	$(call GEN_LOCAL_BIN,$<,$@)
 
+testing/%: testing/%.in $(GEN_BIN)
+	$(call GEN_LOCAL_BIN,$<,$@)
+
 install: install-bins install-lib-bins install-mods install-skel install-man
 
 install-man:
diff --git a/bin/gitano-auth.in b/bin/gitano-auth.in
index e99eb11..51ba85d 100644
--- a/bin/gitano-auth.in
+++ b/bin/gitano-auth.in
@@ -25,6 +25,8 @@ gitano.config.repo_path(repo_root)
 
 local cmdline = luxio.getenv "SSH_ORIGINAL_COMMAND" or ""
 
+local transactionid = gitano.log.syslog.open()
+
 if cmdline:match("^[ \t\n]*$") then
    gitano.log.fatal("No command provided, cannot continue")
 end
@@ -89,6 +91,11 @@ local repo
 
 -- Find the command
 
+
+ip = string.match(luxio.getenv "SSH_CLIENT", "^[^ ]+") or ""
+gitano.log.syslog.info("Client connected from ", ip, 
+   " Executing command: ", cmdline)
+
 local cmd = gitano.command.get(parsed_cmdline[1])
 
 if not cmd then
@@ -153,6 +160,7 @@ local env = {
    ["GITANO_KEYTAG"] = keytag,
    ["GITANO_PROJECT"] = (repo or {}).name,
    ["GITANO_SOURCE"] = "ssh",
+   ["GITANO_TRANSACTION_ID"] = transactionid,
 }
 
 local how, why = cmd.run(config, repo, parsed_cmdline, env)
@@ -161,6 +169,10 @@ if how ~= "exit" or why ~= 0 then
    gitano.log.critical("Error running sub-process:",
 		       ("%s (%d)"):format(how, why))
    gitano.log.fatal("Unable to continue")
+else
+   gitano.log.syslog.info(cmdline, "completed successfully")
 end
 
+gitano.log.syslog.close()
+
 return 0
diff --git a/bin/gitano-post-receive-hook.in b/bin/gitano-post-receive-hook.in
index b272b17..f495d89 100644
--- a/bin/gitano-post-receive-hook.in
+++ b/bin/gitano-post-receive-hook.in
@@ -23,6 +23,7 @@ local start_log_level = gitano.log.get_level()
 -- Clamp level at info until we have checked if the caller
 -- is an admin or not
 gitano.log.cap_level(gitano.log.level.INFO)
+gitano.log.syslog.open()
 
 local repo_root = luxio.getenv("GITANO_ROOT")
 local username  = luxio.getenv("GITANO_USER") or "gitano/anonymous"
@@ -90,27 +91,41 @@ end
 -- that the updates (if any) will have been applied
 
 if updates["refs/gitano/admin"] then
-   gitano.log.chat("<" .. repo.name .. ">",
-		   "Any changes to admin ref have been applied.")
+   local msg = "<" .. repo.name .. ">" .. " Any changes to admin ref have been applied."
+
+   gitano.log.chat(msg)
+   gitano.log.syslog.info(msg)
 end
 
 local function report_repo(reponame, repo, msg)
    if repo then
-      gitano.log.chat("<" .. reponame .. ">",
-		      "Any changes to hooks etc have been applied")
+      local s = "<" .. reponame ..">" .. " Any changes to hooks etc have been applied"
+
+      gitano.log.chat(s)
+      gitano.log.syslog.info(s)
    else
-      gitano.log.crit("<" .. reponame ..">", "Unable to process:", msg)
+      gitano.log.crit("<" .. reponame .. ">", "Unable to process:", msg)
    end
 end
 
 if repo.name == "gitano-admin" and updates[admin_repo.HEAD] then
    -- Updating the 'master' of gitano-admin, let's iterate all the repositories
-   gitano.log.chat("Scanning repositories to apply hook/rules updates...")
+
+   gitano.log.syslog.info("Updating gitano-admin")
+
+   local msg = "Scanning repositories to apply hook/rules updates..."
+   gitano.log.chat(msg)
+   gitano.log.syslog.info(msg)
+
    local ok, msg = gitano.repository.foreach(config, report_repo)
    if not ok then
       gitano.log.crit(msg)
    end
-   gitano.log.chat("All repositories updated where possible.")
+
+   msg = "All repositories updated where possible."
+   gitano.log.chat(msg)
+   gitano.log.syslog.info(msg)
+
    local proc = sp.spawn({
 			    gitano.config.lib_bin_path() .. "/gitano-update-ssh",
 			    gitano.config.repo_path()
@@ -140,7 +155,11 @@ end
 if repo:uses_hook("post-receive") then
    gitano.log.debug("Configuring for post-receive hook")
    gitano.actions.set_supple_globals("post-receive")
-   gitano.log.info("Running repository post-receive hook")
+
+   local msg = "Running repository post-receive hook"
+   gitano.log.info(msg)
+   gitano.log.syslog.info(msg)
+
    local info = {
       username = username,
       keytag = keytag,
@@ -155,4 +174,6 @@ if repo:uses_hook("post-receive") then
    gitano.log.info("Finished")
 end
 
+gitano.log.syslog.close()
+
 return 0
diff --git a/bin/gitano-pre-receive-hook.in b/bin/gitano-pre-receive-hook.in
index 6eae987..c25418b 100644
--- a/bin/gitano-pre-receive-hook.in
+++ b/bin/gitano-pre-receive-hook.in
@@ -23,6 +23,7 @@ local start_log_level = gitano.log.get_level()
 -- Clamp level at info until we have checked if the caller
 -- is an admin or not
 gitano.log.cap_level(gitano.log.level.INFO)
+gitano.log.syslog.open()
 
 local repo_root = luxio.getenv("GITANO_ROOT")
 local username  = luxio.getenv("GITANO_USER") or "gitano/anonymous"
@@ -74,7 +75,7 @@ if repo.is_nascent then
    gitano.log.fatal("Repository " .. repo.name .. " is nascent")
 end
 
--- pre-receive is can prevent updates. Its name is a bit misleading.
+-- pre-receive can prevent updates. Its name is a bit misleading.
 -- pre-receive is called once all the objects have been pushed, but before the
 -- individual update hooks are called.  It gets the same input as post-receive
 -- but can opt to reject the entire push.  If you need to make decisions based
@@ -91,7 +92,12 @@ end
 if repo:uses_hook("pre-receive") then
    gitano.log.debug("Configuring for pre-receive hook")
    gitano.actions.set_supple_globals("pre-receive")
-   gitano.log.info("Running repository pre-receive hook")
+
+   local msg = "Running repository pre-receive hook"
+
+   gitano.log.info(msg)
+   gitano.log.syslog.info(msg)
+
    local info = {
       username = username,
       keytag = keytag,
@@ -106,4 +112,6 @@ if repo:uses_hook("pre-receive") then
    gitano.log.info("Finished")
 end
 
+gitano.log.syslog.close()
+
 return 0
diff --git a/bin/gitano-update-hook.in b/bin/gitano-update-hook.in
index e838244..e338ba2 100644
--- a/bin/gitano-update-hook.in
+++ b/bin/gitano-update-hook.in
@@ -25,6 +25,7 @@ local start_log_level = gitano.log.get_level()
 -- Clamp level at info until we have checked if the caller
 -- is an admin or not
 gitano.log.cap_level(gitano.log.level.INFO)
+gitano.log.syslog.open()
 
 local nullsha = ("0"):rep(40)
 
@@ -258,7 +259,11 @@ end
 if repo:uses_hook("update") then
    gitano.log.debug("Configuring for update hook")
    gitano.actions.set_supple_globals("update")
-   gitano.log.info("Running repository update hook")
+
+   local msg = "Running repository update hook"
+   gitano.log.info(msg)
+   gitano.syslog.info(msg)
+
    local info = {
       username = username,
       keytag = keytag,
@@ -277,4 +282,8 @@ end
 gitano.log.info("Allowing ref update of", 
 		refname, "from", oldsha, "to", newsha)
 
+gitano.log.syslog.info("Allowing ref update of", refname)
+
+gitano.log.syslog.close()
+
 return 0
diff --git a/bin/gitano-update-ssh.in b/bin/gitano-update-ssh.in
index ecf51a9..798296f 100644
--- a/bin/gitano-update-ssh.in
+++ b/bin/gitano-update-ssh.in
@@ -23,6 +23,7 @@ local repo_root = ...
 
 gitano.config.repo_path(repo_root)
 gitano.log.bump_level(gitano.log.level.CHAT)
+gitano.log.syslog.open()
 
 -- Now load the administration data
 
@@ -49,4 +50,6 @@ end
 
 gitano.config.writessh(config)
 
+gitano.log.syslog.close()
+
 return 0
diff --git a/lib/gitano/log.lua b/lib/gitano/log.lua
index e0e5648..f243b87 100644
--- a/lib/gitano/log.lua
+++ b/lib/gitano/log.lua
@@ -6,10 +6,12 @@
 
 local luxio = require "luxio"
 local sio = require "luxio.simple"
+local os = require "os"
 
 local concat = table.concat
 
 local prefix = "[gitano] "
+local transactionid = nil
 
 local stream = sio.stderr
 
@@ -22,6 +24,53 @@ local DEEPDEBUG = 5
 
 local level = ERRS
 
+local function syslog_write(priority, ...)
+   local strs = {...}
+
+   for i = 1, #strs do
+      strs[i] = tostring(strs[i]) or "?"
+   end
+
+   luxio.syslog(priority, transactionid .. ": " .. concat(strs, " ") .. "\n")
+end
+
+local function syslog_open()
+   local ident = "gitano"
+   transactionid = luxio.getenv("GITANO_TRANSACTION_ID")
+
+   if not transactionid then
+      transactionid = tostring(luxio.getpid()) .. "." .. os.date("%H%M%S")
+   end
+
+   luxio.openlog(ident, 0, luxio.LOG_DAEMON)
+
+   return transactionid
+end
+
+local function syslog_close()
+   luxio.closelog()
+end
+
+local function syslog_error(...)
+   syslog_write(luxio.LOG_ERR, ...)
+end
+
+local function syslog_warning(...)
+   syslog_write(luxio.LOG_WARNING, ...)
+end
+
+local function syslog_notice(...)
+   syslog_write(luxio.LOG_NOTICE, ...)
+end
+
+local function syslog_info(...)
+   syslog_write(luxio.LOG_INFO, ...)
+end
+
+local function syslog_debug(...)
+   syslog_write(luxio.LOG_DEBUG, ...)
+end
+
 local function set_prefix(new_prefix)
    if not new_prefix then
       prefix = ""
@@ -55,12 +104,14 @@ local function stdout(...)
 end
 
 local function fatal(...)
+   syslog_write(luxio.LOG_EMERG, ...)
    AT(ERRS, "FATAL:", ...)
    stream:close()
    luxio._exit(1)
 end
 
 local function critical(...)
+   syslog_write(luxio.LOG_CRIT, ...)
    return AT(ERRS, "CRIT:", ...)
 end
 
@@ -183,4 +234,15 @@ return {
    fatal = fatal,
    stdout = stdout,
    set_prefix = set_prefix,
+   syslog = {
+      open = syslog_open,
+      err = syslog_error,
+      error = syslog_error,
+      warn = syslog_warning,
+      warning = syslog_warning,
+      notice = syslog_notice,
+      info = syslog_info,
+      debug = syslog_debug,
+      close = syslog_close,
+   }
 }
diff --git a/testing/gitano-test-tool.in b/testing/gitano-test-tool.in
index c931b6d..8436dd6 100644
--- a/testing/gitano-test-tool.in
+++ b/testing/gitano-test-tool.in
@@ -90,11 +90,12 @@ local function generate_exturl(user, key, repo)
    local authkeys = load_auth(ssh_key_file("testinstance", "authorized_keys"))
    local pubkey = (sio.open(ssh_key_file(user, key) .. ".pub", "r")):read("*l")
    local authline = assert(authkeys[pubkey])
-   local extfmt = "ext::env HOME=%s SSH_ORIGINAL_COMMAND=%s %s %s %s %s"
+   local extfmt = "ext::env HOME=%s SSH_CLIENT=%s SSH_ORIGINAL_COMMAND=%s %s %s %s %s"
    local function esc(s)
       return ((s:gsub("%%", "%%%%")):gsub(" ", "%% "))
    end
    return (extfmt):format(esc(user_home("testinstance")),
+                          esc("10.0.0.1 1234"),
 			  "%S% " .. esc(repo),
 			  esc(gitano.config.lib_bin_path() .. "/gitano-auth"),
 			  esc(authline.repopath),
@@ -156,7 +157,7 @@ function cmd_runcommand(user, key, ...)
    local cmdline = {
       gitano.config.lib_bin_path() .. "/gitano-auth",
       authline.repopath, authline.user, authline.keyset,
-      env = {HOME = user_home("testinstance")}
+      env = {HOME = user_home("testinstance"), SSH_CLIENT="10.0.0.1 1234"}
    }
    cmdline.env.SSH_ORIGINAL_COMMAND = esc_quote_all({...})
    run_program(cmdline)