diff --git a/acceptance/tests/windows/eventlog.rb b/acceptance/tests/windows/eventlog.rb new file mode 100644 index 000000000..ab4f2a65a --- /dev/null +++ b/acceptance/tests/windows/eventlog.rb @@ -0,0 +1,26 @@ +test_name "Write to Windows eventlog" + +confine :to, :platform => 'windows' + +def get_cmd(host) + if options[:type] =~ /pe/ + "#{host['puppetbindir']}/ruby" + else + 'ruby' + end +end + +agents.each do |agent| + # get remote time + now = on(agent, "#{get_cmd(agent)} -e \"puts Time.now.utc.strftime('%m/%d/%Y %H:%M:%S')\"").stdout.chomp + + # generate an error, no master on windows boxes + on agent, puppet_agent('--server', '127.0.0.1', '--test'), :acceptable_exit_codes => [1] + + # make sure there's a Puppet error message in the log + # cygwin + ssh + wmic hangs trying to read stdin, so echo '' | + on agent, "cmd /c echo '' | wmic ntevent where \"LogFile='Application' and SourceName='Puppet' and TimeWritten >= '#{now}'\" get Message,Type /format:csv" do + fail_test "Event not found in Application event log" unless + stdout =~ /Could not retrieve catalog from remote server.*,Error/m + end +end diff --git a/lib/puppet/feature/eventlog.rb b/lib/puppet/feature/eventlog.rb new file mode 100644 index 000000000..e1b909d61 --- /dev/null +++ b/lib/puppet/feature/eventlog.rb @@ -0,0 +1,6 @@ +require 'puppet/util/feature' + +if Puppet.features.microsoft_windows? + Puppet.features.rubygems? + Puppet.features.add(:eventlog, :libs => %{win32/eventlog}) +end diff --git a/lib/puppet/util/log.rb b/lib/puppet/util/log.rb index c0a94f9a7..000e01ee6 100644 --- a/lib/puppet/util/log.rb +++ b/lib/puppet/util/log.rb @@ -1,273 +1,275 @@ require 'puppet/util/tagging' require 'puppet/util/classgen' # Pass feedback to the user. Log levels are modeled after syslog's, and it is # expected that that will be the most common log destination. Supports # multiple destinations, one of which is a remote server. class Puppet::Util::Log include Puppet::Util extend Puppet::Util::ClassGen include Puppet::Util::Tagging @levels = [:debug,:info,:notice,:warning,:err,:alert,:emerg,:crit] @loglevel = 2 @desttypes = {} # Create a new destination type. def self.newdesttype(name, options = {}, &block) dest = genclass( name, :parent => Puppet::Util::Log::Destination, :prefix => "Dest", :block => block, :hash => @desttypes, :attributes => options ) dest.match(dest.name) dest end require 'puppet/util/log/destination' require 'puppet/util/log/destinations' @destinations = {} @queued = [] class << self include Puppet::Util include Puppet::Util::ClassGen attr_reader :desttypes end # Reset log to basics. Basically just flushes and closes files and # undefs other objects. def Log.close(destination) if @destinations.include?(destination) @destinations[destination].flush if @destinations[destination].respond_to?(:flush) @destinations[destination].close if @destinations[destination].respond_to?(:close) @destinations.delete(destination) end end def self.close_all destinations.keys.each { |dest| close(dest) } raise Puppet::DevError.new("Log.close_all failed to close #{@destinations.keys.inspect}") if !@destinations.empty? end # Flush any log destinations that support such operations. def Log.flush @destinations.each { |type, dest| dest.flush if dest.respond_to?(:flush) } end def Log.autoflush=(v) @destinations.each do |type, dest| dest.autoflush = v if dest.respond_to?(:autoflush=) end end # Create a new log message. The primary role of this method is to # avoid creating log messages below the loglevel. def Log.create(hash) raise Puppet::DevError, "Logs require a level" unless hash.include?(:level) raise Puppet::DevError, "Invalid log level #{hash[:level]}" unless @levels.index(hash[:level]) @levels.index(hash[:level]) >= @loglevel ? Puppet::Util::Log.new(hash) : nil end def Log.destinations @destinations end # Yield each valid level in turn def Log.eachlevel @levels.each { |level| yield level } end # Return the current log level. def Log.level @levels[@loglevel] end # Set the current log level. def Log.level=(level) level = level.intern unless level.is_a?(Symbol) raise Puppet::DevError, "Invalid loglevel #{level}" unless @levels.include?(level) @loglevel = @levels.index(level) end def Log.levels @levels.dup end # Create a new log destination. def Log.newdestination(dest) # Each destination can only occur once. if @destinations.find { |name, obj| obj.name == dest } return end name, type = @desttypes.find do |name, klass| klass.match?(dest) end if type.respond_to?(:suitable?) and not type.suitable?(dest) return end raise Puppet::DevError, "Unknown destination type #{dest}" unless type begin if type.instance_method(:initialize).arity == 1 @destinations[dest] = type.new(dest) else @destinations[dest] = type.new end flushqueue @destinations[dest] rescue => detail puts detail.backtrace if Puppet[:debug] # If this was our only destination, then add the console back in. newdestination(:console) if @destinations.empty? and (dest != :console and dest != "console") end end # Route the actual message. FIXME There are lots of things this method # should do, like caching and a bit more. It's worth noting that there's # a potential for a loop here, if the machine somehow gets the destination set as # itself. def Log.newmessage(msg) return if @levels.index(msg.level) < @loglevel queuemessage(msg) if @destinations.length == 0 @destinations.each do |name, dest| threadlock(dest) do dest.handle(msg) end end end def Log.queuemessage(msg) @queued.push(msg) end def Log.flushqueue return unless @destinations.size >= 1 @queued.each do |msg| Log.newmessage(msg) end @queued.clear end def Log.sendlevel?(level) @levels.index(level) >= @loglevel end # Reopen all of our logs. def Log.reopen Puppet.notice "Reopening log files" types = @destinations.keys @destinations.each { |type, dest| dest.close if dest.respond_to?(:close) } @destinations.clear # We need to make sure we always end up with some kind of destination begin types.each { |type| Log.newdestination(type) } rescue => detail if @destinations.empty? Log.setup_default Puppet.err detail.to_s end end end def self.setup_default - Log.newdestination(Puppet.features.syslog? ? :syslog : Puppet[:puppetdlog]) + Log.newdestination( + (Puppet.features.syslog? ? :syslog : + (Puppet.features.eventlog? ? :eventlog : Puppet[:puppetdlog]))) end # Is the passed level a valid log level? def self.validlevel?(level) @levels.include?(level) end attr_accessor :time, :remote, :file, :line, :source attr_reader :level, :message def initialize(args) self.level = args[:level] self.message = args[:message] self.source = args[:source] || "Puppet" @time = Time.now if tags = args[:tags] tags.each { |t| self.tag(t) } end [:file, :line].each do |attr| next unless value = args[attr] send(attr.to_s + "=", value) end Log.newmessage(self) end def message=(msg) raise ArgumentError, "Puppet::Util::Log requires a message" unless msg @message = msg.to_s end def level=(level) raise ArgumentError, "Puppet::Util::Log requires a log level" unless level @level = level.to_sym raise ArgumentError, "Invalid log level #{@level}" unless self.class.validlevel?(@level) # Tag myself with my log level tag(level) end # If they pass a source in to us, we make sure it is a string, and # we retrieve any tags we can. def source=(source) if source.respond_to?(:source_descriptors) descriptors = source.source_descriptors @source = descriptors[:path] descriptors[:tags].each { |t| tag(t) } [:file, :line].each do |param| next unless descriptors[param] send(param.to_s + "=", descriptors[param]) end else @source = source.to_s end end def to_report "#{time} #{source} (#{level}): #{to_s}" end def to_s message end end # This is for backward compatibility from when we changed the constant to Puppet::Util::Log # because the reports include the constant name. Apparently the alias was created in # March 2007, should could probably be removed soon. Puppet::Log = Puppet::Util::Log diff --git a/lib/puppet/util/log/destinations.rb b/lib/puppet/util/log/destinations.rb index 607e112cf..364d5edc5 100644 --- a/lib/puppet/util/log/destinations.rb +++ b/lib/puppet/util/log/destinations.rb @@ -1,230 +1,268 @@ Puppet::Util::Log.newdesttype :syslog do def self.suitable?(obj) Puppet.features.syslog? end def close Syslog.close end def initialize Syslog.close if Syslog.opened? name = Puppet[:name] name = "puppet-#{name}" unless name =~ /puppet/ options = Syslog::LOG_PID | Syslog::LOG_NDELAY # XXX This should really be configurable. str = Puppet[:syslogfacility] begin facility = Syslog.const_get("LOG_#{str.upcase}") rescue NameError raise Puppet::Error, "Invalid syslog facility #{str}" end @syslog = Syslog.open(name, options, facility) end def handle(msg) # XXX Syslog currently has a bug that makes it so you # cannot log a message with a '%' in it. So, we get rid # of them. if msg.source == "Puppet" @syslog.send(msg.level, msg.to_s.gsub("%", '%%')) else @syslog.send(msg.level, "(%s) %s" % [msg.source.to_s.gsub("%", ""), msg.to_s.gsub("%", '%%') ] ) end end end Puppet::Util::Log.newdesttype :file do require 'fileutils' def self.match?(obj) Puppet::Util.absolute_path?(obj) end def close if defined?(@file) @file.close @file = nil end end def flush @file.flush if defined?(@file) end attr_accessor :autoflush def initialize(path) @name = path # first make sure the directory exists # We can't just use 'Config.use' here, because they've # specified a "special" destination. unless FileTest.exist?(File.dirname(path)) FileUtils.mkdir_p(File.dirname(path), :mode => 0755) Puppet.info "Creating log directory #{File.dirname(path)}" end # create the log file, if it doesn't already exist file = File.open(path, File::WRONLY|File::CREAT|File::APPEND) @file = file @autoflush = Puppet[:autoflush] end def handle(msg) @file.puts("#{msg.time} #{msg.source} (#{msg.level}): #{msg}") @file.flush if @autoflush end end Puppet::Util::Log.newdesttype :console do require 'puppet/util/colors' include Puppet::Util::Colors def initialize # Flush output immediately. $stdout.sync = true end def handle(msg) if msg.source == "Puppet" puts colorize(msg.level, "#{msg.level}: #{msg}") else puts colorize(msg.level, "#{msg.level}: #{msg.source}: #{msg}") end end end Puppet::Util::Log.newdesttype :telly_prototype_console do require 'puppet/util/colors' include Puppet::Util::Colors def initialize # Flush output immediately. $stderr.sync = true $stdout.sync = true end def handle(msg) error_levels = { :warning => 'Warning', :err => 'Error', :alert => 'Alert', :emerg => 'Emergency', :crit => 'Critical' } str = msg.respond_to?(:multiline) ? msg.multiline : msg.to_s case msg.level when *error_levels.keys $stderr.puts colorize(:hred, "#{error_levels[msg.level]}: #{str}") when :info $stdout.puts "#{colorize(:green, 'Info')}: #{str}" when :debug $stdout.puts "#{colorize(:cyan, 'Debug')}: #{str}" else $stdout.puts str end end end Puppet::Util::Log.newdesttype :host do def initialize(host) Puppet.info "Treating #{host} as a hostname" args = {} if host =~ /:(\d+)/ args[:Port] = $1 args[:Server] = host.sub(/:\d+/, '') else args[:Server] = host end @name = host @driver = Puppet::Network::Client::LogClient.new(args) end def handle(msg) unless msg.is_a?(String) or msg.remote @hostname ||= Facter["hostname"].value unless defined?(@domain) @domain = Facter["domain"].value @hostname += ".#{@domain}" if @domain end if Puppet::Util.absolute_path?(msg.source) msg.source = @hostname + ":#{msg.source}" elsif msg.source == "Puppet" msg.source = @hostname + " #{msg.source}" else msg.source = @hostname + " #{msg.source}" end begin #puts "would have sent #{msg}" #puts "would have sent %s" % # CGI.escape(YAML.dump(msg)) begin tmp = CGI.escape(YAML.dump(msg)) rescue => detail puts "Could not dump: #{detail}" return end # Add the hostname to the source @driver.addlog(tmp) rescue => detail puts detail.backtrace if Puppet[:trace] Puppet.err detail Puppet::Util::Log.close(self) end end end end # Log to a transaction report. Puppet::Util::Log.newdesttype :report do attr_reader :report match "Puppet::Transaction::Report" def initialize(report) @report = report end def handle(msg) @report << msg end end # Log to an array, just for testing. module Puppet::Test class LogCollector def initialize(logs) @logs = logs end def <<(value) @logs << value end end end Puppet::Util::Log.newdesttype :array do match "Puppet::Test::LogCollector" def initialize(messages) @messages = messages end def handle(msg) @messages << msg end end +Puppet::Util::Log.newdesttype :eventlog do + def self.suitable?(obj) + Puppet.features.eventlog? + end + + def initialize + @eventlog = Win32::EventLog.open("Application") + end + + def to_native(level) + case level + when :debug,:info,:notice + [Win32::EventLog::INFO, 0x01] + when :warning + [Win32::EventLog::WARN, 0x02] + when :err,:alert,:emerg,:crit + [Win32::EventLog::ERROR, 0x03] + end + end + + def handle(msg) + native_type, native_id = to_native(msg.level) + + @eventlog.report_event( + :source => "Puppet", + :event_type => native_type, + :event_id => native_id, + :data => (msg.source and msg.source != 'Puppet' ? "#{msg.source}: " : '') + msg.to_s + ) + end + + def close + if @eventlog + @eventlog.close + @eventlog = nil + end + end +end diff --git a/spec/unit/util/log_spec.rb b/spec/unit/util/log_spec.rb index 6dd365e19..18d9b9919 100755 --- a/spec/unit/util/log_spec.rb +++ b/spec/unit/util/log_spec.rb @@ -1,259 +1,308 @@ #!/usr/bin/env rspec require 'spec_helper' require 'puppet/util/log' describe Puppet::Util::Log do include PuppetSpec::Files it "should write a given message to the specified destination" do arraydest = [] Puppet::Util::Log.newdestination(Puppet::Test::LogCollector.new(arraydest)) Puppet::Util::Log.new(:level => :notice, :message => "foo") message = arraydest.last.message message.should == "foo" end describe ".setup_default" do it "should default to :syslog" do Puppet.features.stubs(:syslog?).returns(true) Puppet::Util::Log.expects(:newdestination).with(:syslog) Puppet::Util::Log.setup_default end + it "should fall back to :eventlog" do + Puppet.features.stubs(:syslog?).returns(false) + Puppet.features.stubs(:eventlog?).returns(true) + Puppet::Util::Log.expects(:newdestination).with(:eventlog) + + Puppet::Util::Log.setup_default + end + it "should fall back to :file" do Puppet.features.stubs(:syslog?).returns(false) + Puppet.features.stubs(:eventlog?).returns(false) Puppet::Util::Log.expects(:newdestination).with(Puppet[:puppetdlog]) Puppet::Util::Log.setup_default end end describe Puppet::Util::Log::DestConsole do before do @console = Puppet::Util::Log::DestConsole.new end it "should colorize if Puppet[:color] is :ansi" do Puppet[:color] = :ansi @console.colorize(:alert, "abc").should == "\e[0;31mabc\e[0m" end it "should colorize if Puppet[:color] is 'yes'" do Puppet[:color] = "yes" @console.colorize(:alert, "abc").should == "\e[0;31mabc\e[0m" end it "should htmlize if Puppet[:color] is :html" do Puppet[:color] = :html @console.colorize(:alert, "abc").should == "abc" end it "should do nothing if Puppet[:color] is false" do Puppet[:color] = false @console.colorize(:alert, "abc").should == "abc" end it "should do nothing if Puppet[:color] is invalid" do Puppet[:color] = "invalid option" @console.colorize(:alert, "abc").should == "abc" end end describe Puppet::Util::Log::DestSyslog do before do @syslog = Puppet::Util::Log::DestSyslog.new end end + describe Puppet::Util::Log::DestEventlog, :if => Puppet.features.microsoft_windows? do + require 'win32/eventlog' + + before :each do + Win32::EventLog.stubs(:open).returns(mock 'mylog') + Win32::EventLog.stubs(:report_event) + Win32::EventLog.stubs(:close) + Puppet.features.stubs(:eventlog?).returns(true) + end + + it "should restrict its suitability" do + Puppet.features.expects(:eventlog?).returns(false) + + Puppet::Util::Log::DestEventlog.suitable?('whatever').should == false + end + + it "should open the 'Application' event log" do + Win32::EventLog.expects(:open).with('Application') + + Puppet::Util::Log.newdestination(:eventlog) + end + + it "should close the event log" do + log = mock('myeventlog') + log.expects(:close) + Win32::EventLog.expects(:open).returns(log) + + Puppet::Util::Log.newdestination(:eventlog) + Puppet::Util::Log.close(:eventlog) + end + + it "should handle each puppet log level" do + log = Puppet::Util::Log::DestEventlog.new + + Puppet::Util::Log.eachlevel do |level| + log.to_native(level).should be_is_a(Array) + end + end + end + describe "instances" do before do Puppet::Util::Log.stubs(:newmessage) end [:level, :message, :time, :remote].each do |attr| it "should have a #{attr} attribute" do log = Puppet::Util::Log.new :level => :notice, :message => "A test message" log.should respond_to(attr) log.should respond_to(attr.to_s + "=") end end it "should fail if created without a level" do lambda { Puppet::Util::Log.new(:message => "A test message") }.should raise_error(ArgumentError) end it "should fail if created without a message" do lambda { Puppet::Util::Log.new(:level => :notice) }.should raise_error(ArgumentError) end it "should make available the level passed in at initialization" do Puppet::Util::Log.new(:level => :notice, :message => "A test message").level.should == :notice end it "should make available the message passed in at initialization" do Puppet::Util::Log.new(:level => :notice, :message => "A test message").message.should == "A test message" end # LAK:NOTE I don't know why this behavior is here, I'm just testing what's in the code, # at least at first. it "should always convert messages to strings" do Puppet::Util::Log.new(:level => :notice, :message => :foo).message.should == "foo" end it "should flush the log queue when the first destination is specified" do Puppet::Util::Log.close_all Puppet::Util::Log.expects(:flushqueue) Puppet::Util::Log.newdestination(:console) end it "should convert the level to a symbol if it's passed in as a string" do Puppet::Util::Log.new(:level => "notice", :message => :foo).level.should == :notice end it "should fail if the level is not a symbol or string", :'fails_on_ruby_1.9.2' => true do lambda { Puppet::Util::Log.new(:level => 50, :message => :foo) }.should raise_error(ArgumentError) end it "should fail if the provided level is not valid" do Puppet::Util::Log.expects(:validlevel?).with(:notice).returns false lambda { Puppet::Util::Log.new(:level => :notice, :message => :foo) }.should raise_error(ArgumentError) end it "should set its time to the initialization time" do time = mock 'time' Time.expects(:now).returns time Puppet::Util::Log.new(:level => "notice", :message => :foo).time.should equal(time) end it "should make available any passed-in tags" do log = Puppet::Util::Log.new(:level => "notice", :message => :foo, :tags => %w{foo bar}) log.tags.should be_include("foo") log.tags.should be_include("bar") end it "should use an passed-in source" do Puppet::Util::Log.any_instance.expects(:source=).with "foo" Puppet::Util::Log.new(:level => "notice", :message => :foo, :source => "foo") end [:file, :line].each do |attr| it "should use #{attr} if provided" do Puppet::Util::Log.any_instance.expects(attr.to_s + "=").with "foo" Puppet::Util::Log.new(:level => "notice", :message => :foo, attr => "foo") end end it "should default to 'Puppet' as its source" do Puppet::Util::Log.new(:level => "notice", :message => :foo).source.should == "Puppet" end it "should register itself with Log" do Puppet::Util::Log.expects(:newmessage) Puppet::Util::Log.new(:level => "notice", :message => :foo) end it "should update Log autoflush when Puppet[:autoflush] is set" do Puppet::Util::Log.expects(:autoflush=).once.with(true) Puppet[:autoflush] = true end it "should have a method for determining if a tag is present" do Puppet::Util::Log.new(:level => "notice", :message => :foo).should respond_to(:tagged?) end it "should match a tag if any of the tags are equivalent to the passed tag as a string" do Puppet::Util::Log.new(:level => "notice", :message => :foo, :tags => %w{one two}).should be_tagged(:one) end it "should tag itself with its log level" do Puppet::Util::Log.new(:level => "notice", :message => :foo).should be_tagged(:notice) end it "should return its message when converted to a string" do Puppet::Util::Log.new(:level => "notice", :message => :foo).to_s.should == "foo" end it "should include its time, source, level, and message when prepared for reporting" do log = Puppet::Util::Log.new(:level => "notice", :message => :foo) report = log.to_report report.should be_include("notice") report.should be_include("foo") report.should be_include(log.source) report.should be_include(log.time.to_s) end it "should not create unsuitable log destinations" do Puppet.features.stubs(:syslog?).returns(false) Puppet::Util::Log::DestSyslog.expects(:suitable?) Puppet::Util::Log::DestSyslog.expects(:new).never Puppet::Util::Log.newdestination(:syslog) end describe "when setting the source as a RAL object" do it "should tag itself with any tags the source has" do source = Puppet::Type.type(:file).new :path => make_absolute("/foo/bar") log = Puppet::Util::Log.new(:level => "notice", :message => :foo, :source => source) source.tags.each do |tag| log.tags.should be_include(tag) end end it "should use the source_descriptors" do source = stub "source" source.stubs(:source_descriptors).returns(:tags => ["tag","tag2"], :path => "path", :version => 100) log = Puppet::Util::Log.new(:level => "notice", :message => :foo) log.expects(:tag).with("tag") log.expects(:tag).with("tag2") log.source = source log.source.should == "path" end it "should copy over any file and line information" do source = Puppet::Type.type(:file).new :path => make_absolute("/foo/bar") source.file = "/my/file" source.line = 50 log = Puppet::Util::Log.new(:level => "notice", :message => :foo, :source => source) log.file.should == "/my/file" log.line.should == 50 end end describe "when setting the source as a non-RAL object" do it "should not try to copy over file, version, line, or tag information" do source = Puppet::Module.new("foo") source.expects(:file).never log = Puppet::Util::Log.new(:level => "notice", :message => :foo, :source => source) end end end describe "to_yaml", :'fails_on_ruby_1.9.2' => true do it "should not include the @version attribute" do log = Puppet::Util::Log.new(:level => "notice", :message => :foo, :version => 100) log.to_yaml_properties.should_not include('@version') end it "should include attributes @level, @message, @source, @tags, and @time" do log = Puppet::Util::Log.new(:level => "notice", :message => :foo, :version => 100) log.to_yaml_properties.should == %w{@level @message @source @tags @time} end it "should include attributes @file and @line if specified" do log = Puppet::Util::Log.new(:level => "notice", :message => :foo, :file => "foo", :line => 35) log.to_yaml_properties.should include('@file') log.to_yaml_properties.should include('@line') end end end