use pretty printing with Logger (debug, info, warning and error messages)

11 files changed, 70 insertions, 67 deletions

diff --git a/data/rbot/plugins/games/azgame.rb b/data/rbot/plugins/games/azgame.rb
index 66646e73..883e4030 100644
--- a/data/rbot/plugins/games/azgame.rb
+++ b/data/rbot/plugins/games/azgame.rb
@@ -92,7 +92,7 @@ class AzGamePlugin < Plugin
     else

       @wordcache = Hash.new

     end

-    debug "\n\n\nA-Z wordcache: #{@wordcache.inspect}\n\n\n"

+    debug "A-Z wordcache: #{@wordcache.pretty_inspect}"

 

     @rules = {

       :italian => {

diff --git a/lib/rbot/botuser.rb b/lib/rbot/botuser.rb
index bed2b627..9a34b341 100644
--- a/lib/rbot/botuser.rb
+++ b/lib/rbot/botuser.rb
@@ -76,7 +76,7 @@ module Irc
           k.to_sym

         }

         @command = path.last

-        debug "Created command #{@command.inspect} with path #{@path.join(', ')}"

+        debug "Created command #{@command.inspect} with path #{@path.pretty_inspect}"

       end

 

       # Returs self

@@ -427,7 +427,7 @@ module Irc
       #

       def set_default_permission(cmd, val)

         @default_perm.set_permission(Command.new(cmd), val)

-        debug "Default permissions now:\n#{@default_perm.inspect}"

+        debug "Default permissions now: #{@default_perm.pretty_inspect}"

       end

 

       # default knows everybody

diff --git a/lib/rbot/core/auth.rb b/lib/rbot/core/auth.rb
index 45a36131..e89b5742 100644
--- a/lib/rbot/core/auth.rb
+++ b/lib/rbot/core/auth.rb
@@ -12,7 +12,7 @@ class AuthModule < CoreBotModule
   def initialize

     super

     load_array(:default, true)

-    debug "initialized auth. Botusers: #{@bot.auth.save_array.inspect}"

+    debug "initialized auth. Botusers: #{@bot.auth.save_array.pretty_inspect}"

   end

 

   def save

@@ -23,12 +23,12 @@ class AuthModule < CoreBotModule
     if @bot.auth.changed?

       @registry[key] = @bot.auth.save_array

       @bot.auth.reset_changed

-      debug "saved botusers (#{key}): #{@registry[key].inspect}"

+      debug "saved botusers (#{key}): #{@registry[key].pretty_inspect}"

     end

   end

 

   def load_array(key=:default, forced=false)

-    debug "loading botusers (#{key}): #{@registry[key].inspect}"

+    debug "loading botusers (#{key}): #{@registry[key].pretty_inspect}"

     @bot.auth.load_array(@registry[key], forced) if @registry.has_key?(key)

   end

 

diff --git a/lib/rbot/core/utils/httputil.rb b/lib/rbot/core/utils/httputil.rb
index 9b58b3a6..e0f93953 100644
--- a/lib/rbot/core/utils/httputil.rb
+++ b/lib/rbot/core/utils/httputil.rb
@@ -18,7 +18,7 @@ require 'iconv'
 begin
   require 'net/https'
 rescue LoadError => e
-  error "Couldn't load 'net/https':  #{e.inspect}"
+  error "Couldn't load 'net/https':  #{e.pretty_inspect}"
   error "Secured HTTP connections will fail"
 end
 
@@ -230,8 +230,7 @@ class HttpUtil
         self.revalidate
         self.response.raw_body
       rescue Exception => e
-        error e.message
-        error e.backtrace.join("\n")
+        error e
         raise e
       end
     end
@@ -463,8 +462,7 @@ class HttpUtil
           begin
             cached.revalidate(resp)
           rescue Exception => e
-            error e.message
-            error e.backtrace.join("\n")
+            error e
           end
           debug "reusing cached"
           resp = cached.response
@@ -498,8 +496,7 @@ class HttpUtil
         Net::HTTPPartialContent === resp
       return resp.body
     rescue Exception => e
-      error e.message
-      error e.backtrace.join("\n")
+      error e
     end
     return nil
   end
@@ -512,8 +509,7 @@ class HttpUtil
         Net::HTTPServerError == resp
       return resp
     rescue Exception => e
-      error e.message
-      error e.backtrace.join("\n")
+      error e
     end
     return nil
   end
@@ -525,8 +521,7 @@ class HttpUtil
       raise 'http error' unless Net::HTTPOK === resp
       return resp
     rescue Exception => e
-      error e.message
-      error e.backtrace.join("\n")
+      error e
     end
     return nil
   end
@@ -547,7 +542,7 @@ class HttpUtil
         (now - val.last_used > max_last) || (now - val.first_used > max_first)
       }
     rescue => e
-      error "Failed to remove stale cache: #{e.inspect}"
+      error "Failed to remove stale cache: #{e.pretty_inspect}"
     end
     debug "#{@cache.size} pages after"
   end
diff --git a/lib/rbot/core/utils/utils.rb b/lib/rbot/core/utils/utils.rb
index 1c27aa02..71b4c8d4 100644
--- a/lib/rbot/core/utils/utils.rb
+++ b/lib/rbot/core/utils/utils.rb
@@ -374,7 +374,7 @@ module ::Irc
             $stderr.reopen($stdout)
             exec(command, *args)
           rescue Exception => e
-            puts "exec of #{command} led to exception: #{e.inspect}"
+            puts "exec of #{command} led to exception: #{e.pretty_inspect}"
             Kernel::exit! 0
           end
           puts "exec of #{command} failed"
diff --git a/lib/rbot/dbhash.rb b/lib/rbot/dbhash.rb
index d793e27e..2f6f461f 100644
--- a/lib/rbot/dbhash.rb
+++ b/lib/rbot/dbhash.rb
@@ -1,7 +1,7 @@
 begin
   require 'bdb'
 rescue Exception => e
-  error "Got exception: "+e
+  error "Got exception: #{e.pretty_inspect}"
   error "rbot couldn't load the bdb module, perhaps you need to install it? try: http://www.ruby-lang.org/en/raa-list.rhtml?name=bdb"
   exit 2
 end
@@ -92,7 +92,7 @@ module Irc
           @@env = BDB::Env.open("#{@bot.botclass}", BDB::INIT_TRANSACTION | BDB::CREATE | BDB::RECOVER, "set_lg_max" => @@lg_max)
           debug "DBTree: environment opened with max log size #{@@env.conf['lg_max']}"
         rescue => e
-          debug "DBTree: failed to open environment: #{e}. Retrying ..."
+          debug "DBTree: failed to open environment: #{e.pretty_inspect}. Retrying ..."
           @@env = BDB::Env.open("#{@bot.botclass}", BDB::INIT_TRANSACTION | BDB::CREATE |  BDB::RECOVER)
         end
         #@@env = BDB::Env.open("#{@bot.botclass}", BDB::CREATE | BDB::INIT_MPOOL | BDB::RECOVER)
@@ -131,8 +131,8 @@ module Irc
       begin
         debug "DBTree: checkpointing ..."
         @@env.checkpoint
-      rescue => e
-        debug "Failed: #{e}"
+      rescue Excpetion => e
+        debug "Failed: #{e.pretty_inspect}"
       end
       begin
         debug "DBTree: flushing log ..."
@@ -142,8 +142,8 @@ module Irc
         logs.each { |log|
           File.delete(log)
         }
-      rescue => e
-        debug "Failed: #{e}"
+      rescue Exception => e
+        debug "Failed: #{e.pretty_inspect}"
       end
     end
 
@@ -180,8 +180,8 @@ module Irc
           debug "DBTree: cleaning up environment in #{path}"
           BDB::Env.remove("#{path}")
         end
-      rescue => e
-        error "failed to clean up environment: #{e.inspect}"
+      rescue Exception => e
+        error "failed to clean up environment: #{e.pretty_inspect}"
       end
     end
 
diff --git a/lib/rbot/ircbot.rb b/lib/rbot/ircbot.rb
index cb119378..a08dae9f 100644
--- a/lib/rbot/ircbot.rb
+++ b/lib/rbot/ircbot.rb
@@ -13,6 +13,16 @@ $logger.datetime_format = $dateformat
 $logger.level = $cl_loglevel if $cl_loglevel
 $logger.level = 0 if $debug
 
+require 'pp'
+
+class Exception
+  def pretty_print(q)
+    q.group(1, "#<%s: %s" % [self.class, self.message], ">") {
+      q.seplist(self.backtrace, lambda { "\n" }) { |v| v } if self.backtrace
+    }
+  end
+end
+
 def rawlog(level, message=nil, who_pos=1)
   call_stack = caller
   if call_stack.length > who_pos
@@ -23,7 +33,14 @@ def rawlog(level, message=nil, who_pos=1)
   # Output each line. To distinguish between separate messages and multi-line
   # messages originating at the same time, we blank #{who} after the first message
   # is output.
-  message.to_s.each_line { |l|
+  # Also, we output strings as-is but for other objects we use pretty_inspect
+  case message
+  when String
+    str = message
+  else
+    str = message.pretty_inspect
+  end
+  str.each_line { |l|
     $logger.add(level, l.chomp, who)
     who.gsub!(/./," ")
   }
@@ -344,9 +361,8 @@ class Bot
     begin
       @config = BotConfig.configmanager
       @config.bot_associate(self)
-    rescue => e
-      fatal e.inspect
-      fatal e.backtrace.join("\n")
+    rescue Exception => e
+      fatal e
       log_session_end
       exit 2
     end
@@ -369,8 +385,10 @@ class Bot
         exit if fork
       rescue NotImplementedError
         warning "Could not background, fork not supported"
-      rescue => e
-        warning "Could not background. #{e.inspect}"
+      rescue SystemExit
+        exit 0
+      rescue Exception => e
+        warning "Could not background. #{e.pretty_inspect}"
       end
       Dir.chdir botclass
       # File.umask 0000                # Ensure sensible umask. Adjust as needed.
@@ -424,9 +442,8 @@ class Bot
       @auth = Auth::authmanager
       @auth.bot_associate(self)
       # @auth.load("#{botclass}/botusers.yaml")
-    rescue => e
-      fatal e.inspect
-      fatal e.backtrace.join("\n")
+    rescue Exception => e
+      fatal e
       log_session_end
       exit 2
     end
@@ -712,9 +729,9 @@ class Bot
       trap("SIGTERM") { got_sig("SIGTERM") }
       trap("SIGHUP") { got_sig("SIGHUP") }
     rescue ArgumentError => e
-      debug "failed to trap signals (#{e.inspect}): running on Windows?"
-    rescue => e
-      debug "failed to trap signals: #{e.inspect}"
+      debug "failed to trap signals (#{e.pretty_inspect}): running on Windows?"
+    rescue Exception => e
+      debug "failed to trap signals: #{e.pretty_inspect}"
     end
     begin
       quit if $interrupted > 0
@@ -766,24 +783,20 @@ class Bot
         log_session_end
         exit 0
       rescue Errno::ETIMEDOUT, Errno::ECONNABORTED, TimeoutError, SocketError => e
-        error "network exception: #{e.class}: #{e}"
-        debug e.backtrace.join("\n")
+        error "network exception: #{e.pretty_inspect}"
         quit_msg = e.to_s
       rescue BDB::Fatal => e
-        fatal "fatal bdb error: #{e.class}: #{e}"
-        fatal e.backtrace.join("\n")
+        fatal "fatal bdb error: #{e.pretty_inspect}"
         DBTree.stats
         # Why restart? DB problems are serious stuff ...
         # restart("Oops, we seem to have registry problems ...")
         log_session_end
         exit 2
       rescue Exception => e
-        error "non-net exception: #{e.class}: #{e}"
-        error e.backtrace.join("\n")
+        error "non-net exception: #{e.pretty_inspect}"
         quit_msg = e.to_s
       rescue => e
-        fatal "unexpected exception: #{e.class}: #{e}"
-        fatal e.backtrace.join("\n")
+        fatal "unexpected exception: #{e.pretty_inspect}"
         log_session_end
         exit 2
       end
diff --git a/lib/rbot/ircsocket.rb b/lib/rbot/ircsocket.rb
index b825a768..dcc501a3 100644
--- a/lib/rbot/ircsocket.rb
+++ b/lib/rbot/ircsocket.rb
@@ -395,13 +395,12 @@ module Irc
       end
     end
 
-    def handle_socket_error(string, err)
-      error "#{string} failed: #{err.inspect}"
-      debug err.backtrace.join("\n")
+    def handle_socket_error(string, e)
+      error "#{string} failed: #{e.pretty_inspect}"
       # We assume that an error means that there are connection
       # problems and that we should reconnect, so we
       shutdown
-      raise SocketError.new(err.inspect)
+      raise SocketError.new(e.inspect)
     end
 
     # get the next line from the server (blocks)
@@ -416,7 +415,7 @@ module Irc
         reply.strip! if reply
         debug "RECV: #{reply.inspect}"
         return reply
-      rescue => e
+      rescue Exception => e
         handle_socket_error(:RECV, e)
       end
     end
@@ -461,9 +460,8 @@ module Irc
           if @sendq.empty?
             @timer.stop
           end
-        rescue => e
-          error "Spooling failed: #{e.inspect}"
-          error e.backtrace.join("\n")
+        rescue Exception => e
+          error "Spooling failed: #{e.pretty_inspect}"
         end
       end
     end
@@ -495,9 +493,8 @@ module Irc
       return unless connected?
       begin
         @sock.close
-      rescue => err
-        error "error while shutting down: #{err.inspect}"
-        debug err.backtrace.join("\n")
+      rescue Exception => e
+        error "error while shutting down: #{e.pretty_inspect}"
       end
       @rawsock = nil if @ssl
       @sock = nil
@@ -520,7 +517,7 @@ module Irc
           @lines_sent += 1
           @burst += 1
         end
-      rescue => e
+      rescue Exception => e
         handle_socket_error(:SEND, e)
       end
     end
diff --git a/lib/rbot/messagemapper.rb b/lib/rbot/messagemapper.rb
index b9aad91a..3d49e918 100644
--- a/lib/rbot/messagemapper.rb
+++ b/lib/rbot/messagemapper.rb
@@ -267,7 +267,7 @@ module Irc
       else
         reg = nil
       end
-      "<#{self.class.to_s}%s%s%s%s>" % [name, mul, opt, reg]
+      "<%s %s%s%s%s>" % [self.class, name, mul, opt, reg]
     end
   end
 
diff --git a/lib/rbot/registry.rb b/lib/rbot/registry.rb
index 749f1830..d6c06782 100644
--- a/lib/rbot/registry.rb
+++ b/lib/rbot/registry.rb
@@ -180,15 +180,13 @@ module Irc
         Marshal.restore(val)
       rescue Exception => e
         error "failed to restore marshal data for #{val.inspect}, attempting recovery or fallback to default"
-        debug e.inspect
-        debug e.backtrace.join("\n")
+        debug e
         if @recovery
           begin
             return @recovery.call(val)
           rescue Exception => ee
             error "marshal recovery failed, trying default"
-            debug ee.inspect
-            debug ee.backtrace.join("\n")
+            debug ee
           end
         end
         unless @default.nil?
diff --git a/lib/rbot/timer.rb b/lib/rbot/timer.rb
index 181dd2db..c87c9c4d 100644
--- a/lib/rbot/timer.rb
+++ b/lib/rbot/timer.rb
@@ -51,9 +51,9 @@ module Timer
         else
           @func.call
         end
-      rescue => e
-        error "Timer action #{self.inspect} with function #{@func.inspect} failed with error #{e.inspect}"
-        error e.backtrace.join("\n")
+      rescue Exception => e
+        error "Timer action #{self.inspect} with function #{@func.inspect} failed!"
+        error e.pretty_inspect
         # TODO maybe we want to block this Action?
       end
       return @once