completely rewrite logging facility, adding support for more fine-gra…

…ined logging control

lib/cinch/handler.rb

@@ -43,7 +43,7 @@ def call(message, captures, arguments)
             @bot.callback.instance_exec(message, *@args, *bargs, &@block)
           end
         rescue => e
-          @bot.logger.log_exception(e)
+          @bot.logger.exception(e)
         ensure
           @threads.delete Thread.current
         end

lib/cinch/helpers.rb

@@ -87,7 +87,7 @@ def rescue_exception
       begin
         yield
       rescue => e
-        bot.logger.log_exception(e)
+        bot.logger.exception(e)
       end
     end
 

lib/cinch/irc.rb

@@ -36,18 +36,18 @@ def connect
           tcp_socket = TCPSocket.new(@bot.config.server, @bot.config.port, @bot.config.local_host)
         end
       rescue Timeout::Error
-        @bot.logger.debug("Timed out while connecting")
+        @bot.logger.warn("Timed out while connecting")
         return false
       rescue SocketError
-        @bot.logger.debug("Could not connect to the IRC server. Please check your network.")
+        @bot.logger.warn("Could not connect to the IRC server. Please check your network.")
         return false
       rescue => e
-        @bot.logger.log_exception(e)
+        @bot.logger.exception(e)
         return false
       end
 
       if @bot.config.ssl == true || @bot.config.ssl == false
-        @bot.logger.debug "Deprecation warning: Beginning with version 1.1.0, @config.ssl should be a set of options, not a boolean value!"
+        @bot.logger.warn "Deprecation warning: Beginning with version 1.1.0, @config.ssl should be a set of options, not a boolean value!"
       end
 
       if @bot.config.ssl == true || (@bot.config.ssl.is_a?(SSLConfiguration) && @bot.config.ssl.use)
@@ -81,7 +81,7 @@ def setup_ssl
       else
         ssl_context.verify_mode = OpenSSL::SSL::VERIFY_NONE
       end
-      @bot.logger.debug "Using SSL with #{@bot.config.server}:#{@bot.config.port}"
+      @bot.logger.info "Using SSL with #{@bot.config.server}:#{@bot.config.port}"
 
       @socket = OpenSSL::SSL::SSLSocket.new(tcp_socket, ssl_context)
       @socket.sync = true
@@ -110,11 +110,11 @@ def start_reading_thread
             end
           end
         rescue Timeout::Error
-          @bot.logger.debug "Connection timed out."
+          @bot.logger.warn "Connection timed out."
         rescue EOFError
-          @bot.logger.debug "Lost connection."
+          @bot.logger.warn "Lost connection."
         rescue => e
-          @bot.logger.log_exception(e)
+          @bot.logger.exception(e)
         end
 
         @socket.close
@@ -365,7 +365,7 @@ def on_quit(msg, events)
       set_leaving_user(msg, msg.user, events)
 
       if msg.message.downcase == "excess flood" && msg.user == @bot
-        @bot.debug ["Looks like your bot has been kicked because of excess flood.",
+        @bot.warn ["Looks like your bot has been kicked because of excess flood.",
                     "If you haven't modified the throttling options manually, please file a bug report at https://github.com/cinchrb/cinch/issues and include the following information:",
                     "- Server: #{@bot.config.server}",
                     "- Messages per second: #{@bot.config.messages_per_second}",

lib/cinch/logger/formatted_logger.rb

@@ -1,11 +1,11 @@
 require "cinch/logger/logger"
+
 module Cinch
   module Logger
-    # A formatted logger that will colorize individual parts of IRC
-    # messages.
-    # @version 1.1.0
-    class FormattedLogger < Cinch::Logger::Logger
-      COLORS = {
+    # @version 1.2.0
+    class FormattedLogger < Logger
+      # @private
+      Colors = {
         :reset => "\e[0m",
         :bold => "\e[1m",
         :red => "\e[31m",
@@ -16,58 +16,16 @@ class FormattedLogger < Cinch::Logger::Logger
         :bg_white => "\e[47m",
       }
 
-      # @param [IO] output An IO to log to.
-      def initialize(output = STDERR)
-        @output = output
-        @mutex = Mutex.new
-      end
-
-      # (see Logger::Logger#debug)
-      def debug(messages)
-        log(messages, :debug)
+      # (see Logger#exception)
+      def exception(e)
+        lines = ["#{e.backtrace.first}: #{e.message} (#{e.class})"]
+        lines.concat e.backtrace[1..-1].map {|s| "\t" + s}
+        log(lines, :exception, :error)
       end
 
-      # (see Logger::Logger#log)
-      # @version 1.1.0
-      def log(messages, kind = :generic)
-        @mutex.synchronize do
-          messages = [messages].flatten.map {|s| s.to_s.chomp}
-          messages.each do |msg|
-            next if msg.empty?
-            message = Time.now.strftime("[%Y/%m/%d %H:%M:%S.%L] ")
-
-            msg.gsub!(/[^[:print:][:space:]]/) do |m|
-              colorize(m.inspect[1..-2], :bg_white, :black)
-            end
-
-            if kind == :debug
-              prefix = colorize("!! ", :yellow)
-              message << prefix + msg
-            else
-              pre, msg = msg.split(" :", 2)
-              pre_parts = pre.split(" ")
-
-              if kind == :incoming
-                prefix = colorize(">> ", :green)
-
-                if pre_parts.size == 1
-                  pre_parts[0] = colorize(pre_parts[0], :bold)
-                else
-                  pre_parts[0] = colorize(pre_parts[0], :blue)
-                  pre_parts[1] = colorize(pre_parts[1], :bold)
-                end
-
-              elsif kind == :outgoing
-                prefix = colorize("<< ", :red)
-                pre_parts[0] = colorize(pre_parts[0], :bold)
-              end
-
-              message << prefix + pre_parts.join(" ")
-              message << colorize(" :#{msg}", :yellow) if msg
-            end
-            @output.puts message.encode("locale", {:invalid => :replace, :undef => :replace})
-          end
-        end
+      private
+      def timestamp
+        Time.now.strftime("[%Y/%m/%d %H:%M:%S.%L]")
       end
 
       # @api private
@@ -76,16 +34,63 @@ def log(messages, kind = :generic)
       # @return [String] colorized string
       def colorize(text, *codes)
         return text unless @output.tty?
-        codes = COLORS.values_at(*codes).join
-        text = text.gsub(/#{Regexp.escape(COLORS[:reset])}/, COLORS[:reset] + codes)
-        codes + text + COLORS[:reset]
+        codes = Colors.values_at(*codes).join
+        text = text.gsub(/#{Regexp.escape(Colors[:reset])}/, Colors[:reset] + codes)
+        codes + text + Colors[:reset]
       end
 
-      # (see Logger::Logger#log_exception)
-      def log_exception(e)
-        lines = ["#{e.backtrace.first}: #{e.message} (#{e.class})"]
-        lines.concat e.backtrace[1..-1].map {|s| "\t" + s}
-        debug(lines)
+      def format_general(message)
+        message.gsub(/[^[:print:][:space:]]/) do |m|
+          colorize(m.inspect[1..-2], :bg_white, :black)
+        end
+      end
+
+      def format_debug(message)
+        "%s %s %s" % [timestamp, colorize("!!", :yellow), message]
+      end
+
+      def format_warn(message)
+        format_debug(message)
+      end
+
+      def format_info(message)
+        "%s %s %s" % [timestamp, "II", message]
+      end
+
+      def format_incoming(message)
+        pre, msg = message.split(" :", 2)
+        pre_parts = pre.split(" ")
+
+        prefix = colorize(">>", :green)
+
+        if pre_parts.size == 1
+          pre_parts[0] = colorize(pre_parts[0], :bold)
+        else
+          pre_parts[0] = colorize(pre_parts[0], :blue)
+          pre_parts[1] = colorize(pre_parts[1], :bold)
+        end
+
+        "%s %s %s %s" % [timestamp,
+                          prefix,
+                          pre_parts.join(" "),
+                          msg ? colorize(":#{msg}", :yellow) : ""]
+      end
+
+      def format_outgoing(message)
+        pre, msg = message.split(" :", 2)
+        pre_parts = pre.split(" ")
+
+        prefix = colorize("<<", :red)
+        pre_parts[0] = colorize(pre_parts[0], :bold)
+
+        "%s %s %s %s" % [timestamp,
+                         prefix,
+                         pre_parts.join(" "),
+                         msg ? colorize(":#{msg}", :yellow) : ""]
+      end
+
+      def format_exception(message)
+        "%s %s %s" % [timestamp, colorize("!!", :red), message]
       end
     end
   end