Merge pull request #2229 from opscode/jdmundrawala/12-evt-log

Logging events to the Windows Event Log

10 files changed, 372 insertions, 2 deletions

diff --git a/Rakefile b/Rakefile
index b55ed8321b..70a45d94c0 100644
--- a/Rakefile
+++ b/Rakefile
@@ -52,6 +52,18 @@ task :pedant do
   require File.expand_path('spec/support/pedant/run_pedant')
 end
 
+task :build_eventlog do
+  Dir.chdir 'ext/win32-eventlog/' do
+    system 'rake build'
+  end
+end
+
+task :register_eventlog do
+  Dir.chdir 'ext/win32-eventlog/' do
+    system 'rake register'
+  end
+end
+
 begin
   require 'yard'
   DOC_FILES = [ "README.rdoc", "LICENSE", "spec/tiny_server.rb", "lib/**/*.rb" ]
diff --git a/chef-x86-mingw32.gemspec b/chef-x86-mingw32.gemspec
index 6d69c4e7e6..a35ec5d63c 100644
--- a/chef-x86-mingw32.gemspec
+++ b/chef-x86-mingw32.gemspec
@@ -14,5 +14,8 @@ gemspec.add_dependency "win32-process", "0.7.3"
 gemspec.add_dependency "win32-service", "0.8.2"
 gemspec.add_dependency "win32-mmap", "0.4.0"
 gemspec.add_dependency "wmi-lite", "~> 1.0"
+gemspec.add_dependency "win32-eventlog", "0.6.1"
+gemspec.extensions << "ext/win32-eventlog/Rakefile"
+gemspec.files += %w(ext/win32-eventlog/Rakefile ext/win32-eventlog/chef-log.man)
 
 gemspec
diff --git a/ext/win32-eventlog/Rakefile b/ext/win32-eventlog/Rakefile
new file mode 100644
index 0000000000..3112c27e8e
--- /dev/null
+++ b/ext/win32-eventlog/Rakefile
@@ -0,0 +1,50 @@
+require 'rubygems'
+require 'rake'
+require 'mkmf'
+
+desc "Building event log dll"
+
+def ensure_present(commands)
+  commands.each do |c|
+    unless find_executable c
+      warn "Could not find #{c}. Windows Event Logging will not correctly function."
+    end
+  end
+end
+
+
+EVT_MC_FILE = 'chef-log.man'
+EVT_RC_FILE = 'chef-log.rc'
+EVT_RESOURCE_OBJECT = 'resource.o'
+EVT_SHARED_OBJECT = 'chef-log.dll'
+MC = 'windmc'
+RC = 'windres'
+CC = 'gcc'
+
+ensure_present [MC, RC, CC]
+
+task :build => [EVT_RESOURCE_OBJECT, EVT_SHARED_OBJECT]
+task :default => [:build, :register]
+
+file EVT_RC_FILE=> EVT_MC_FILE do
+  sh "#{MC} #{EVT_MC_FILE}"
+end
+
+file EVT_RESOURCE_OBJECT => EVT_RC_FILE do
+  sh "#{RC} -i #{EVT_RC_FILE} -o #{EVT_RESOURCE_OBJECT}"
+end
+
+file EVT_SHARED_OBJECT => EVT_RESOURCE_OBJECT do
+  sh "#{CC} -o #{EVT_SHARED_OBJECT} -shared #{EVT_RESOURCE_OBJECT}"
+end
+
+task :register => EVT_SHARED_OBJECT do
+  require 'win32/eventlog'
+  dll_file = File.expand_path(EVT_SHARED_OBJECT)
+  Win32::EventLog.add_event_source(
+    :source => "Application",
+    :key_name => "Chef",
+    :event_message_file => dll_file,
+    :category_message_file => dll_file
+  )
+end
diff --git a/ext/win32-eventlog/chef-log.man b/ext/win32-eventlog/chef-log.man
new file mode 100644
index 0000000000..4b4a022d7f
--- /dev/null
+++ b/ext/win32-eventlog/chef-log.man
@@ -0,0 +1,26 @@
+MessageId=10000
+SymbolicName=RUN_START
+Language=English
+Starting Chef Client run v%1
+.
+
+MessageId=10001
+SymbolicName=RUN_STARTED
+Language=English
+Started Chef Client run %1
+.
+
+MessageId=10002
+SymbolicName=RUN_COMPLETED
+Language=English
+Completed Chef Client run %1 in %2 seconds
+.
+
+MessageId=10003
+SymbolicName=RUN_FAILED
+Language=English
+Failed Chef Client run %1 in %2 seconds.%n
+Exception type: %3%n
+Exception message: %4%n
+Exception backtrace: %5%n
+.
diff --git a/lib/chef/client.rb b/lib/chef/client.rb
index e8ff352116..4f37bd0ee3 100644
--- a/lib/chef/client.rb
+++ b/lib/chef/client.rb
@@ -36,6 +36,8 @@ require 'chef/cookbook/file_vendor'
 require 'chef/cookbook/file_system_file_vendor'
 require 'chef/cookbook/remote_file_vendor'
 require 'chef/event_dispatch/dispatcher'
+require 'chef/event_loggers/base'
+require 'chef/event_loggers/windows_eventlog'
 require 'chef/formatters/base'
 require 'chef/formatters/doc'
 require 'chef/formatters/minimal'
@@ -151,7 +153,7 @@ class Chef
       @runner = nil
       @ohai = Ohai::System.new
 
-      event_handlers = configure_formatters
+      event_handlers = configure_formatters + configure_event_loggers
       event_handlers += Array(Chef::Config[:event_handlers])
 
       @events = EventDispatch::Dispatcher.new(*event_handlers)
@@ -191,6 +193,22 @@ class Chef
       end
     end
 
+    def configure_event_loggers
+      if Chef::Config.disable_event_logger
+        []
+      else
+        Chef::Config.event_loggers.map do |evt_logger|
+          case evt_logger
+          when Symbol
+            Chef::EventLoggers.new(evt_logger)
+          when Class
+            evt_logger.new
+          else
+          end
+        end
+      end
+    end
+
     # Instantiates a Chef::Node object, possibly loading the node's prior state
     # when using chef-client. Delegates to policy_builder
     #
diff --git a/lib/chef/config.rb b/lib/chef/config.rb
index 9a8117d2c2..d033a2981b 100644
--- a/lib/chef/config.rb
+++ b/lib/chef/config.rb
@@ -78,6 +78,10 @@ class Chef
       formatters << [name, file_path]
     end
 
+    def self.add_event_logger(logger)
+      event_handlers << logger
+    end
+
     # Config file to load (client.rb, knife.rb, etc. defaults set differently in knife, chef-client, etc.)
     configurable(:config_file)
 
@@ -451,6 +455,15 @@ class Chef
     # Event Handlers
     default :event_handlers, []
 
+    default :disable_event_loggers, false
+    default :event_loggers do
+      evt_loggers = []
+      if Chef::Platform::windows?
+        evt_loggers << :win_evt
+      end
+      evt_loggers
+    end
+
     # Exception Handlers
     default :exception_handlers, []
 
diff --git a/lib/chef/event_loggers/base.rb b/lib/chef/event_loggers/base.rb
new file mode 100644
index 0000000000..1f676dd516
--- /dev/null
+++ b/lib/chef/event_loggers/base.rb
@@ -0,0 +1,62 @@
+#
+# Author:: Jay Mundrawala (<jdm@getchef.com>)
+#
+# Copyright:: 2014, Chef Software, Inc.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#     http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+#
+
+require 'chef/event_dispatch/base'
+
+class Chef
+  module EventLoggers
+    class UnknownEventLogger < StandardError; end
+    class UnavailableEventLogger < StandardError; end
+
+    def self.event_loggers_by_name
+      @event_loggers_by_name ||= {}
+    end
+
+    def self.register(name, logger)
+      event_loggers_by_name[name.to_s] = logger
+    end
+
+    def self.by_name(name)
+      event_loggers_by_name[name]
+    end
+
+    def self.available_event_loggers
+      event_loggers_by_name.select do |key, val|
+        val.available?
+      end.keys
+    end
+
+    def self.new(name)
+      event_logger_class = by_name(name.to_s) or
+        raise UnknownEventLogger, "No event logger found for #{name} (available: #{available_event_loggers.join(', ')})"
+      raise UnavailableEventLogger unless available_event_loggers.include? name.to_s
+      event_logger_class.new
+    end
+
+    class Base < EventDispatch::Base
+      def self.short_name(name)
+        Chef::EventLoggers.register(name, self)
+      end
+
+      # Returns true if this implementation of EventLoggers can be used
+      def self.available?
+        false
+      end
+    end
+  end
+end
diff --git a/lib/chef/event_loggers/windows_eventlog.rb b/lib/chef/event_loggers/windows_eventlog.rb
new file mode 100644
index 0000000000..e3bbbfa1e6
--- /dev/null
+++ b/lib/chef/event_loggers/windows_eventlog.rb
@@ -0,0 +1,104 @@
+#
+# Author:: Jay Mundrawala (<jdm@getchef.com>)
+#
+# Copyright:: 2014, Chef Software, Inc.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#     http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+#
+
+require 'chef/event_loggers/base'
+require 'chef/platform/query_helpers'
+
+if Chef::Platform::windows?
+  [:INFINITE, :WAIT_FAILED, :FORMAT_MESSAGE_IGNORE_INSERTS, :ERROR_INSUFFICIENT_BUFFER].each do |c|
+    # These are redefined in 'win32/eventlog'
+    Windows::Constants.send(:remove_const, c)
+  end
+
+  require 'win32/eventlog'
+  include Win32
+end
+
+class Chef
+  module EventLoggers
+    class WindowsEventLogger < EventLoggers::Base
+      short_name(:win_evt)
+
+      # These must match those that are defined in the manifest file
+      RUN_START_EVENT_ID = 10000
+      RUN_STARTED_EVENT_ID = 10001
+      RUN_COMPLETED_EVENT_ID = 10002
+      RUN_FAILED_EVENT_ID = 10003
+
+      EVENT_CATEGORY_ID = 11000
+      LOG_CATEGORY_ID = 11001
+
+      # Since we must install the event logger, this is not really configurable
+      SOURCE = 'Chef'
+
+      def self.available?
+        return Chef::Platform::windows?
+      end
+
+      def initialize
+        @eventlog = EventLog::open('Application')
+      end
+
+      def run_start(version)
+        @eventlog.report_event(
+          :event_type => EventLog::INFO_TYPE, 
+          :source => SOURCE,
+          :event_id => RUN_START_EVENT_ID,
+          :data => [version]
+        )
+      end
+
+      def run_started(run_status)
+        @run_status = run_status
+        @eventlog.report_event(
+          :event_type => EventLog::INFO_TYPE, 
+          :source => SOURCE,
+          :event_id => RUN_STARTED_EVENT_ID,
+          :data => [run_status.run_id]
+        )
+      end
+
+      def run_completed(node)
+        @eventlog.report_event(
+          :event_type => EventLog::INFO_TYPE, 
+          :source => SOURCE,
+          :event_id => RUN_COMPLETED_EVENT_ID,
+          :data => [@run_status.run_id, @run_status.elapsed_time.to_s]
+        )
+      end
+
+      #Failed chef-client run %1 in %2 seconds.
+      #Exception type: %3
+      #Exception message: %4
+      #Exception backtrace: %5
+      def run_failed(e)
+        @eventlog.report_event(
+          :event_type => EventLog::ERROR_TYPE, 
+          :source => SOURCE, 
+          :event_id => RUN_FAILED_EVENT_ID,
+          :data => [@run_status.run_id, 
+                    @run_status.elapsed_time.to_s, 
+                    e.class.name, 
+                    e.message, 
+                    e.backtrace.join("\n")]
+        )
+      end
+
+    end
+  end
+end
diff --git a/spec/functional/event_loggers/windows_eventlog_spec.rb b/spec/functional/event_loggers/windows_eventlog_spec.rb
new file mode 100644
index 0000000000..9da9f60fa9
--- /dev/null
+++ b/spec/functional/event_loggers/windows_eventlog_spec.rb
@@ -0,0 +1,82 @@
+#
+# Author:: Jay Mundrawala (<jdm@getchef.com>)
+#
+# Copyright:: 2014, Chef Software, Inc.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#     http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+#
+
+require 'spec_helper'
+require 'securerandom'
+require 'chef/event_loggers/windows_eventlog'
+if Chef::Platform.windows?
+  require 'win32/eventlog'
+  include Win32
+end
+
+describe Chef::EventLoggers::WindowsEventLogger, :windows_only do
+  let(:run_id)       { SecureRandom.uuid }
+  let(:version)      { SecureRandom.uuid }
+  let(:elapsed_time) { SecureRandom.random_number(100) }
+  let(:logger)       { Chef::EventLoggers::WindowsEventLogger.new }
+  let(:flags)        { nil }
+  let(:node)         { nil }
+  let(:run_status)   { double('Run Status', {run_id: run_id, elapsed_time: elapsed_time }) }
+  let(:event_log)    { EventLog.new("Application") }
+  let!(:offset)      { event_log.read_last_event.record_number }
+  let(:mock_exception) { double('Exception', {message: SecureRandom.uuid, backtrace:[SecureRandom.uuid, SecureRandom.uuid]})}
+
+  it 'is available' do
+    Chef::EventLoggers::WindowsEventLogger.available?.should be_true
+  end
+
+  it 'writes run_start event with event_id 10000 and contains version' do
+    logger.run_start(version)
+
+    expect(event_log.read(flags, offset).any? { |e| e.source == 'Chef' && e.event_id == 10000 && 
+                                               e.string_inserts[0].include?(version)}).to be_true
+  end
+
+  it 'writes run_started event with event_id 10001 and contains the run_id' do
+    logger.run_started(run_status)
+
+    expect(event_log.read(flags, offset).any? { |e| e.source == 'Chef' && e.event_id == 10001 && 
+                                               e.string_inserts[0].include?(run_id)}).to be_true
+  end
+
+  it 'writes run_completed event with event_id 10002 and contains the run_id and elapsed time' do
+    logger.run_started(run_status)
+    logger.run_completed(node)
+
+    expect(event_log.read(flags, offset).any? { |e| e.source == 'Chef' && e.event_id == 10002 && 
+                                                e.string_inserts[0].include?(run_id) &&
+                                                e.string_inserts[1].include?(elapsed_time.to_s)
+    }).to be_true
+  end
+
+  it 'writes run_failed event with event_id 10003 and contains the run_id, elapsed time, and exception info' do
+    logger.run_started(run_status)
+    logger.run_failed(mock_exception)
+
+    expect(event_log.read(flags, offset).any? do |e|
+      e.source == 'Chef' && e.event_id == 10003 &&
+        e.string_inserts[0].include?(run_id) &&
+        e.string_inserts[1].include?(elapsed_time.to_s) &&
+        e.string_inserts[2].include?(mock_exception.class.name) &&
+        e.string_inserts[3].include?(mock_exception.message) &&
+        e.string_inserts[4].include?(mock_exception.backtrace[0]) &&
+        e.string_inserts[4].include?(mock_exception.backtrace[1])
+    end).to be_true
+  end
+
+end
diff --git a/spec/unit/client_spec.rb b/spec/unit/client_spec.rb
index e05245c413..e03773ae03 100644
--- a/spec/unit/client_spec.rb
+++ b/spec/unit/client_spec.rb
@@ -61,6 +61,7 @@ describe Chef::Client do
   let(:client_opts) { {} }
 
   let(:client) do
+    Chef::Config[:event_loggers] = []
     Chef::Client.new(json_attribs, client_opts).tap do |c|
       c.node = node
     end
@@ -384,7 +385,6 @@ describe Chef::Client do
 
       @events = double("Chef::EventDispatch::Dispatcher").as_null_object
       Chef::EventDispatch::Dispatcher.stub(:new).and_return(@events)
-
       # @events is created on Chef::Client.new, so we need to recreate it after mocking
       client = Chef::Client.new
       client.stub(:load_node).and_raise(Exception)