[CHEF-3935] Use stripped down lockless logger

Ruby's stdlib Logger wraps all IO in mutexes. Ruby 2.0 doesn't allow you
to request a lock in a trap handler because that could deadlock. This
commit fixes by replacing the Logger with a lock-free variant.

4 files changed, 100 insertions, 6 deletions

diff --git a/lib/chef/application.rb b/lib/chef/application.rb
index a8b0d09169..0ed8d3dd9f 100644
--- a/lib/chef/application.rb
+++ b/lib/chef/application.rb
@@ -122,7 +122,7 @@ class Chef::Application
   # that a user has configured a log_location in client.rb, but is running
   # chef-client by hand to troubleshoot a problem.
   def configure_logging
-    Chef::Log.init(Chef::Config[:log_location])
+    Chef::Log.init(MonoLogger.new(Chef::Config[:log_location]))
     if want_additional_logger?
       configure_stdout_logger
     end
@@ -130,7 +130,7 @@ class Chef::Application
   end
 
   def configure_stdout_logger
-    stdout_logger = Logger.new(STDOUT)
+    stdout_logger = MonoLogger.new(STDOUT)
     STDOUT.sync = true
     stdout_logger.formatter = Chef::Log.logger.formatter
     Chef::Log.loggers <<  stdout_logger
diff --git a/lib/chef/application/windows_service.rb b/lib/chef/application/windows_service.rb
index 42a9ee9783..5b77a44392 100644
--- a/lib/chef/application/windows_service.rb
+++ b/lib/chef/application/windows_service.rb
@@ -17,6 +17,7 @@
 #
 
 require 'chef'
+require 'chef/monologger'
 require 'chef/application'
 require 'chef/client'
 require 'chef/config'
@@ -194,7 +195,7 @@ class Chef
       # See application.rb for related comments.
 
       def configure_logging
-        Chef::Log.init(Chef::Config[:log_location])
+        Chef::Log.init(MonoLogger.new(Chef::Config[:log_location]))
         if want_additional_logger?
           configure_stdout_logger
         end
@@ -202,7 +203,7 @@ class Chef
       end
 
       def configure_stdout_logger
-        stdout_logger = Logger.new(STDOUT)
+        stdout_logger = MonoLogger.new(STDOUT)
         STDOUT.sync = true
         stdout_logger.formatter = Chef::Log.logger.formatter
         Chef::Log.loggers <<  stdout_logger
diff --git a/lib/chef/log.rb b/lib/chef/log.rb
index 7355ec7574..131d706a5e 100644
--- a/lib/chef/log.rb
+++ b/lib/chef/log.rb
@@ -18,6 +18,7 @@
 # limitations under the License.
 
 require 'logger'
+require 'chef/monologger'
 require 'mixlib/log'
 
 class Chef
@@ -25,8 +26,7 @@ class Chef
     extend Mixlib::Log
 
     # Force initialization of the primary log device (@logger)
-    init
-
+    init(MonoLogger.new(STDOUT))
 
     class Formatter
       def self.show_time=(*args)
diff --git a/lib/chef/monologger.rb b/lib/chef/monologger.rb
new file mode 100644
index 0000000000..fed60514d7
--- /dev/null
+++ b/lib/chef/monologger.rb
@@ -0,0 +1,93 @@
+require 'logger'
+
+require 'pp'
+
+#== MonoLogger
+# A subclass of Ruby's stdlib Logger with all the mutex and logrotation stuff
+# ripped out.
+class MonoLogger < Logger
+
+  #
+  # === Synopsis
+  #
+  #   Logger.new(name, shift_age = 7, shift_size = 1048576)
+  #   Logger.new(name, shift_age = 'weekly')
+  #
+  # === Args
+  #
+  # +logdev+::
+  #   The log device.  This is a filename (String) or IO object (typically
+  #   +STDOUT+, +STDERR+, or an open file).
+  # +shift_age+::
+  #   Number of old log files to keep, *or* frequency of rotation (+daily+,
+  #   +weekly+ or +monthly+).
+  # +shift_size+::
+  #   Maximum logfile size (only applies when +shift_age+ is a number).
+  #
+  # === Description
+  #
+  # Create an instance.
+  #
+  def initialize(logdev)
+    @progname = nil
+    @level = DEBUG
+    @default_formatter = Formatter.new
+    @formatter = nil
+    @logdev = nil
+    if logdev
+      @logdev = LocklessLogDevice.new(logdev)
+    end
+  end
+
+
+  class LocklessLogDevice < LogDevice
+
+    def initialize(log = nil)
+      @dev = @filename = @shift_age = @shift_size = nil
+      if log.respond_to?(:write) and log.respond_to?(:close)
+        @dev = log
+      else
+        @dev = open_logfile(log)
+        @dev.sync = true
+        @filename = log
+      end
+    end
+
+    def write(message)
+      @dev.write(message)
+    rescue Exception => ignored
+      warn("log writing failed. #{ignored}")
+    end
+
+    def close
+      @dev.close rescue nil
+    end
+
+  private
+
+    def open_logfile(filename)
+      if (FileTest.exist?(filename))
+        open(filename, (File::WRONLY | File::APPEND))
+      else
+        create_logfile(filename)
+      end
+    end
+
+    def create_logfile(filename)
+      logdev = open(filename, (File::WRONLY | File::APPEND | File::CREAT))
+      logdev.sync = true
+      add_log_header(logdev)
+      logdev
+    end
+
+    def add_log_header(file)
+      file.write(
+        "# Logfile created on %s by %s\n" % [Time.now.to_s, Logger::ProgName]
+      )
+    end
+
+  end
+
+
+end
+