#
# File:: pipeline/log/log.rb
# Description:: Pipeline logging system. 
#
# Author:: David Muir <david.muir@rockstarnorth.com>
# Author:: Greg Smith <greg@rockstarnorth.com>
# Date:: 26 November 2007
#
# References:
#   http://log4r.sf.net/
#   Log4r Ruby Gem Examples
#

#-----------------------------------------------------------------------------
# Uses
#-----------------------------------------------------------------------------
require 'pipeline/config/projects'
require 'pipeline/log/antiformatter'
require 'pipeline/log/lograge'
require 'pipeline/log/logxml'
require 'pipeline/log/rollingdatefileoutputter'
require 'pipeline/log/colour_console_outputter'
require 'pipeline/log/universal_log_fileoutputter'
require 'pipeline/os/file'
require 'pipeline/os/path'
include Pipeline

require 'date'
require 'find'
require 'log4r'
require 'log4r/configurator'
require 'log4r/outputter/emailoutputter'
require 'socket'

#-----------------------------------------------------------------------------
# Monkey-patching
#-----------------------------------------------------------------------------
module Log4r

	class EmailOutputter < Outputter
  		attr_accessor :formatfirst
	end

    # Patch IOOutputter to not flush every write.
    class IOOutputter
    private
        def write( data )
          begin
            @out.print data
          rescue IOError => ioe # recover from this instead of crash
            Logger.log_internal {"IOError in Outputter '#{@name}'!"}
            Logger.log_internal {ioe}
            close
          rescue NameError => ne
            Logger.log_internal {"Outputter '#{@name}' IO is #{@out.class}!"}
            Logger.log_internal {ne}
            close
          end
        end
    end

	# Patch FileOutputter class with close and reopen methods so we can
	# copy up the logs.
	class FileOutputter
	
		# Close log file.
		def close( )
			@out.close( )
		end
		
		# Reopen log file (always in append mode)
		def reopen( )
			@out = File.new( @filename, "a" ) 
		end
	end

	# Patch RollingFileOutputter class' makeNewFilename method to produce
	# a more appealing filename.
	class RollingFileOutputter
		remove_method :makeNewFilename
		
		def makeNewFilename
			pad = "-" + "0" * (6 - @count.to_s.length) + count.to_s
			newbase = @baseFilename.sub(/(\.\w*)$/, pad + '\1')
			@filename = File.join(File.dirname(@filename), newbase)
			Logger.log_internal {"File #{@filename} created"}			
        end
    end
end

#-----------------------------------------------------------------------------
# Implementation
#-----------------------------------------------------------------------------
module Pipeline

	# 
	# == Description
	# Configure Log4r Custom Levels
	#
	Log4r::Configurator.custom_levels( 'Debug', 'Info', 'Warn', 'Error', 'Fatal' )

	# 
	# == Description
	# Simple date/time output formatter for Log4r logs used in RsLogger class 
	# below.
	#
	class DateTimeFormatter < Log4r::Formatter
	
		attr_accessor :datetime_format
	
		def initialize( datetime_format = "%Y-%m-%d %H:%M:%S" )
	
			@datetime_format = datetime_format
		end
	
		def format( event )
	
			LogSystem.instance().was_error = true if event.level >= 4
			d = DateTime.now( )
			buff = d.strftime( self.datetime_format ) + " "
			buff += (event.tracer.nil? ? "" : "(#{event.tracer[0]})") + ": "
			buff += "#{Log4r::LNAMES[event.level]} " + event.name + " " + event.data.inspect + "\n"
			buff
		end
	end
	
	#
	# == Description
	# Simple date/time output formatter for Log4r logs used in RsLogger class 
	# below. Catches errors so we can post an e-mail at the end of the application
	# only if there were any errors in the log
	#
	class EmailDateTimeFormatter < DateTimeFormatter
		
		def initialize( datetime_format = "%Y-%m-%d %H:%M:%S" )	
			super( datetime_format )
		end
	
		def format( event )
		
			LogSystem.instance().was_error = true if event.level >= 4
			buff = super( event )
			buff += "\n"
			buff
		end
	end	
	
	
	# 
	# == Description
	# Singleton object that gives access to our root logger.
	# 
	class LogSystem		
		include Singleton
		
		#--------------------------------------------------------------------
		# Attributes
		#--------------------------------------------------------------------		
		attr_reader :rootname
		attr_reader :logfolder
		
		attr_reader :was_error
		attr_writer :was_error
		
		attr_reader :ulog_filename	# Universal log filename (if set)
		attr_writer :ulog_filename
		
		attr_reader :rootlog
		attr_writer :rootlog		
		ROOTFOLDER = '$(toolsroot)/logs'
		
		ULOG_FILETYPE 		= ".ulog" # filetype of a ulog ( as recognised by client app )
		
		#--------------------------------------------------------------------
		# Methods
		#--------------------------------------------------------------------
		
		def initialize( )
		
			@rootname = OS::Path::get_basename( $0 )
			c = Pipeline::Config::instance( )
			@rootlog = Log.new( @rootname, nil, true )						
			
			# Create log directory if it doesn't already exist.
			@logfolder = c.envsubst( OS::Path::combine( ROOTFOLDER, @rootname.gsub(' ','_') ) )
			FileUtils::mkdir_p( @logfolder ) unless ( ::File::directory?( @logfolder ) )
			@was_error = false
			
			args = ARGV.dup			
			
			args.collect! { |item|
			
				if item.index(" ") != nil then
				
					"\"#{item}\""
				else
				
					item
				end
			}
			
			# Log out script's Command Line and Working Directory.
			# Incredibly useful for debugging purposes.
			@rootlog.info("command line = #{$0} #{args.join(' ')}")
			@rootlog.info("working directory = #{Dir.getwd}")
			@ragelog = nil				
		end
		
		# 
		# Returns a ragelog, creating it internally if it hasn't already been 
		# created.
		#				
		def ragelog( )
		
			@ragelog = Log::new( 'rage' ) if ( @ragelog.nil? )			
			@ragelog
		end
		
		#
		# Set the Universal Log filename.
		#
		def set_ulog_filename( filename )
			@ulog_filename = filename.dup()
		end
		
		# Call this just before script shutdown if you want to mail the log
		# automatically when (and only when) it contains errors. This allows us to send a single
		# email per script session
		def shutdown()
			
			@rootlog.flush() if @was_error		
		end
		
		#
		# == Description
		# Print an exception message and backtrace to stdout.
		#
		def print_exception( ex )
			
			puts "Exception: #{ex.message}"
			puts "  Backtrace: "
			
			ex.backtrace.each { |line|
				
				puts "  #{line}\n"
			}
		end
	end
	
	# 
	# == Description
	#
	# The Log class is a simple utility wrapper surrounding Log4r::Logger.  By 
	# specifying some simple parameters the user can setup a STDERR log, file 
	# log (optional) and an email log (optional, and requires manual flushing).
	#
	# There are 5 pre-defined categories: DEBUG, INFO, WARN, ERROR and FATAL.
	# These can be accessed using the following public methods:
	#    Pipeline::Log.debug
	#    Pipeline::Log.warn
	#    Pipeline::Log.error
	#    Pipeline::Log.fatal
	#
	# There are a couple of utility methods to log exceptions and fatal 
	# execeptions:
	#    Pipeline::Log.exception
	#    Pipeline::Log.fatal_exception
	# These methods use the error and fatal logging categories.
	#
	# For more information see the Log4r documentation.
	#
	# == Example Usage
	#
	#   # Construct new application log object, we shall log to a file
	#   # and allow email logs, although they must be mailed manually.
	#   log = Pipeline::Log.new( "Application Log" )
	#
	#   # Now log some stuff...
	#   begin
	#     log.debug( "Created logger." )
	#     log.info( "Script started" )
	#     log.warn( "Erm, not doing anything" )
	#     log.error( "this is an error" )
	#   rescue Exception => ex
	#     log.exception( ex, 'Unhandled exception' )
	#   end
	#
	#   log.fatal( "fatal exception" )
	#   log.SendEmailLog()
	#   exit( 1 )
	#   log.debug( "should not hit this" )
	#
	#
	class Log < Log4r::Logger
		
		#
		# == Description
		# Class constructor.
		#
		# Additional outputters can be specified as an Array of outputter
		# instances or classnames (when instances will be created automatically).
		#
		def initialize( name, additional_outputters = nil, is_root = false )
			
			innername = name
			innername = LogSystem.instance.rootname + "::" + name unless is_root
			
			config = Pipeline::Config.instance
			super( innername, config.log_level, true, config.log_trace )
			
			logname = name.gsub( ' ', '_' )
			setup_root( config, logname ) if is_root
			setup_nonroot( config, logname ) unless is_root
			setup_additional_outputters( config, logname, additional_outputters )
		end
		
		#
		# Easily log an exception, with an optional message.
		#
		def exception( ex, msg = '' )
			error( "#{msg}: #{ex.message}" )
			error( ex.inspect )
			ex.backtrace.each do |m| error( m ); end
		end
		
		#
		# Easily log a fatal exception, with an optional message.
		#
		def fatal_exception( ex, msg = '' )
			fatal( "#{msg}: #{ex.message}" )
			fatal( ex.inspect )
			ex.backtrace.each do |m| fatal( m ); end
		end
		
        # Since we've patched IOOutputter to not flush; we flush on error.
        def error( data = nil, propagated = false )
            super
            flush()
        end
  
        # Since we've patched IOOutputter to not flush; we flush on fatal. 
        def fatal( data = nil, propagared = false )
            super
            flush()
        end
  
		#
		# Flush all log output to the email outputter (if previously initialised).
		#
		def flush( )
			# DHM 31 August 2009
			# Temporarily disabling log flush until its determined why we
			# are getting emails with no errors in them.
			#
			# unless ( @emailOutputters.nil? ) then
			#	@emailOutputters.each do |emailOutputter|
			#		emailOutputter.flush()
			#	end
			# end	
		end
	
		# Close file
		# The idea being that it permits parsing of logfile, with a view to reopen it again later.
		# As used by the rebuild command since that now uses an external process to parse its logfile.
		def close_file()
			close_file_outputters()
		end

		# Reopen file
		# The idea being that it a logfile can be parsed then reopened.
		def reopen_file()
			reopen_file_outputters()
		end
		
		#---------------------------------------------------------------------
		# Private Methods
		#---------------------------------------------------------------------
	
	private
		
		# Close all fileoutputters
		#
		def close_file_outputters( )			
			return if @outputters.nil?
			return if Array == @outputters.class and 0 == @outputters.size
			@outputters.each do |outputter|				
				if outputter.kind_of?( Log4r::FileOutputter )
					outputter.close()
				end
			end
		end		
		
		# Reopen all fileoutputters
		#
		def reopen_file_outputters( )			
			return if @outputters.nil?
			return if Array == @outputters.class and 0 == @outputters.size
			
			@outputters.each do |outputter|				
				if outputter.kind_of?( Log4r::FileOutputter )
					outputter.reopen()
				end
			end
		end		

		# create outputter for root log to output a universal log
		#
		def create_ulog_outputter( filename )
		
			ulog_log_name = OS::Path.remove_extension(filename) + LogSystem::ULOG_FILETYPE
			
			# DW - no doubt there is a more elegent way to handle this? 
			# - but the universal log needs deleted otherwise it is appended to 
			# - we end up with two root xml elements - not well formed ( I might be missing something here? ) 
			begin
				File.delete(ulog_log_name) if (File.exist?(ulog_log_name))
			
				enable_viewer = false
				return UniversalLogXMLFileOutputter.new( ulog_log_name, { :filename=>"#{ulog_log_name}" }, enable_viewer)	
			rescue Exception => ex
				exception( ex, 'Exception deleting or attaching to universal log.' )
			end
			nil
		end
				
		# Private method to setup this log as the root logger object.
		def setup_root( config, logname )

			g = Pipeline::Globals::instance()			
			filename = OS::Path.combine( config.envsubst( LogSystem::ROOTFOLDER ), logname + '.log' )
			FileUtils::mkdir_p( OS::Path::get_directory( filename ) ) \
				unless ( File::directory?( OS::Path::get_directory( filename ) ) )
			
			# Setup console outputters; we setup two, stderr for errors and
			# fatal errors and stdout for info and debug messages.
			regout = Log4r::StdoutOutputter.new( logname )
			regout.only_at( 1, 2, 3 )
			errout = Log4r::StderrOutputter.new( logname )
			errout.only_at( 4, 5 )
			
			ulog_outputter = create_ulog_outputter( filename )
			self.add( ulog_outputter ) unless ( ulog_outputter.nil? )
			self.add( regout )
			self.add( errout )
			
			# DHM 4 September 2009
			# Really disable the log emails as they are huge and don't seem to
			# contain fatal error messages.  I'll revisit this at some point
			# as its really useful functionality (although we aren't using
			# it to its potential yet - maybe with COLLADA?).
=begin
			if config.logmailerrors then
				@emailOutputters = Array.new()
		
				config.logmailtos.each_value { |logmailto|
					emailTo = logmailto
					emailServer = config.mailserver
					emailPort = config.mailport.to_i
					emailDomain = config.maildomain
					emailFrom = config.user.emailaddress unless config.user.nil?
					emailSubject = "logger: " + name 
					# Setup mailing list for fatal errors
					if ( ( nil != emailTo ) && ( nil != emailServer ) && 
						 ( nil != emailPort ) && ( nil != emailDomain ) &&
						 ( nil != emailFrom ) && ( nil != emailSubject ) )
						emailOutputter = Log4r::EmailOutputter.new( 	'email',
												:server => emailServer,
												:port => emailPort,
												:domain => emailDomain,
												:from => emailFrom,
												:to => emailTo,
												:subject => emailSubject,
												:immediate_at => "Fatal",
												:buffsize => 10000)
									
						emailOutputter.formatfirst = true						
						emailOutputter.formatter = EmailDateTimeFormatter
			
						self.add(emailOutputter)
							
						@emailOutputters << emailOutputter
					end
				}
			end
=end
			setup_default_outputters( filename )
		end
		
		# Private method to setup this log as a non-root logger object.
		def setup_nonroot( config, logname )
			
			filename = OS::Path.combine( LogSystem::instance().logfolder, logname + '.log' )			
			setup_default_outputters( filename )
		end
		
		# Private method to setup default outputters.
		def setup_default_outputters( filename )
			
			return if filename.nil?
			
			# Create log file(s) output directory
			FileUtils.mkdir_p( OS::Path.get_directory(filename) ) \
				unless ( ::File::directory?( OS::Path::get_directory( filename ) ) )
			# Default text file outputter
			logfile = RollingDateFileOutputter.new( @fullname,
								:filename => filename,
								:trunc => true,
								:formatter => DateTimeFormatter )
			self.add( logfile )
		end
		
		# Private method to setup additional outputters specified to the
		# object's constructor.
		def setup_additional_outputters( config, logname, outputters )
			
			return if outputters.nil?
			return if Array == outputters.class and 0 == outputters.size
			
			outputters.each do |outputter|

				if outputter.kind_of?( Log4r::Outputter )
					# Add outputter instance
					self.add( outputter )
				elsif outputter.kind_of?( Class ) and outputter <= Log4r::Outputter
					if outputter.respond_to? :instance
						self.add( outputter.instance )
					else
						self.add( outputter.new )
					end
				else
		        	raise TypeError, "Argument #{outputter} was not a Outputter!", caller
				end
			end
		end					
	end

end # Pipeline module

# pipeline/log/log.rb