(puppetlabs/puppetdb) Improved "logging of last resort"

[weareth...@puppetlabs.com]

Please review pull request #198: Improved "logging of last resort" opened by (grimradical)

Description:

There are certain points in the lifecycle of PuppetDB where it's
critical that we properly log an exception, even if that means we spam
different log targets (logfiles, stdout, stderr, etc) and duplicate
output.

Daemon startup is one of these critical points. An error during
startup should be logged as thoroughly as possible, as there's no
really good way to debug the issue otherwise (as the daemon will
terminate upon error, making it hard to do meaningful
live-debugging). This becomes doubly-important when you consider that
99% of users are launching PuppetDB via an init script of some sort,
and init scripts can do funky things with the stdout and stderr
streams of launched processes. On some platforms, that stuff is
captured for you. On others, it goes to the users interactive
terminal. And still on others, it ends up in the aether never to be
seen again.

The other critical point is when a thread dies due to an unhandled
exception. I'd prefer that never occur but, well, shit happens yo. You
can register a callback with the JVM whenever a unhandled exception
occurs, so we can use the same verbose logging routines we employ
during daemon startup to ensure that unhandled exceptions get some
degree of debuggability.

Better safe than sorry, and I'd prefer to err on the side of logging
too much during these critical sections of code than log too little.

Signed-off-by: Deepak Giridharagopal dee...@puppetlabs.com

• Opened: Wed Jul 04 00:17:38 UTC 2012
• Based on: puppetlabs:master (6fa4bfc4b0256c4e108ddf590837f9a761df91a4)
• Requested merge: grimradical:catch-all-logging (5d73bf088a3faaf25ed906ef01dd7d0802546cdb)

Diff follows:

diff --git a/src/com/puppetlabs/puppetdb/core.clj b/src/com/puppetlabs/puppetdb/core.clj
index ab92c0c..a2c04e6 100644
--- a/src/com/puppetlabs/puppetdb/core.clj
+++ b/src/com/puppetlabs/puppetdb/core.clj
@@ -12,7 +12,8 @@
 ;; `[arg1 arg2 arg3]`.
 
 (ns com.puppetlabs.puppetdb.core
-  (:require [clojure.tools.namespace :as ns])
+  (:require [com.puppetlabs.utils :as utils]
+            [clojure.tools.namespace :as ns])
   (:use [clojure.string :only (split)]
         [clojure.stacktrace :only [print-stack-trace]])
   (:gen-class))
@@ -63,6 +64,7 @@
 
 (defn -main
   [& args]
+  (utils/set-default-uncaught-exception-handler!)
   (let [subcommand (first args)
         allowed?   (available-subcommands)]
 
@@ -78,7 +80,5 @@
         (apply (resolve (symbol module "-main")) args)
         (System/exit 0)
         (catch Throwable e
-          (binding [*out* *err*]
-            (print-stack-trace e)
-            (println)
-            (System/exit 1)))))))
+          (utils/catch-all-logger e)
+          (System/exit 1))))))
diff --git a/src/com/puppetlabs/utils.clj b/src/com/puppetlabs/utils.clj
index b2b08d4..a8983b7 100644
--- a/src/com/puppetlabs/utils.clj
+++ b/src/com/puppetlabs/utils.clj
@@ -222,6 +222,40 @@
 
 ;; ## Logging helpers
 
+(defn catch-all-logger
+  "A logging function useful for catch-all purposes, that is, to
+  ensure that a log message gets in front of a user the best we can
+  even if that means duplicated output.
+
+  This is really only suitable for _last-ditch_ exception handling,
+  where we want to make sure an exception is logged (because nobody
+  higher up in the stack will log it for us)."
+  ([exception]
+     (catch-all-logger exception "Uncaught exception"))
+  ([exception message]
+     (log/error exception message)
+     (.printStackTrace exception)))
+
+(defn set-default-uncaught-exception-handler!
+  "Sets the JVM global handler for uncaught exceptions to the supplied
+  function.
+
+  `f` is a function that takes 2 arguments (the Thread object involved
+  in the exception, and the Exception itself). The return value is
+  ignored.
+
+  If `f` isn't supplied, we default to using
+  `com.puppetlabs.utils/catch-all-logger`."
+  ([]
+     (set-default-uncaught-exception-handler!
+      (fn [_ e]
+        (catch-all-logger e))))
+  ([f]
+     (let [handler (proxy [Thread$UncaughtExceptionHandler] []
+                     (uncaughtException [thread exception]
+                       (f thread exception)))]
+       (Thread/setDefaultUncaughtExceptionHandler handler))))
+
 (defn configure-logger-via-file!
   "Reconfigures the current logger based on the supplied configuration
   file. You can optionally supply a delay (in millis) that governs how

    

[weareth...@puppetlabs.com]

On Thu Jul 05 20:27:50 UTC 2012 pull request #198 was closed.

Improved "logging of last resort" requested by (grimradical)

The pull request was merged by: nicklewis