#
# File:: %RS_TOOLSLIB%/pipeline/log/universal_log_fileoutputter.rb
# Description:: Writes out a log to a file in an XML format
#		Optionally the log will be viewed.
#
# Author:: Derek Ward <derek@rockstarnorth.com>
# Date:: 25th May 2011
#

#----------------------------------------------------------------------------
# Example of XML format
#----------------------------------------------------------------------------

#<?xml version="1.0" encoding="utf-8"?>
#  <ulog name="log_name" version="1.0" user="david.muir" machine="EDIW-DMUIR3">
#     <context name="default" />
#     <context name="map_export">
#        <message timestamp="">Map export starting...</message>
#        <error context="DT1_01_Building03" timestamp="">Object has TXD name set to CHANGEME.</error>
#        <warning context="DT1_01_Building06" timestamp="">Object is close to vertex limit.</warning>
#        <debug context="DT1_01_Building07" timestamp="">Object has invalid attribute set.</debug>
#     </context>
#     <context name="map_export_validation">
#        ...
#     </context>
#  </ulog>


#----------------------------------------------------------------------------
# Uses
#----------------------------------------------------------------------------
require 'pipeline/os/file'
require 'pipeline/config/project'
require 'pipeline/config/globals'
#require 'pipeline/log/log'
require 'date'
require 'log4r/outputter/fileoutputter'
require "systemu"
require 'cgi'


#----------------------------------------------------------------------------
# Implementation
#----------------------------------------------------------------------------
module Pipeline
	
	#
	# == Description
	# XML file outputter formatter class.
	#
	class UniversalLogXMLFormatter < Log4r::Formatter

		attr_accessor :context, :num_events, :num_errors, :num_warnings

		# This method is invoked automatically by the Log4r system.
		#
		def format( event )
			
			output =""
			message = event.data.gsub( '"', '\'' ).gsub( /\n/, '' )
			
			#output += "<context name=\"#{@context}\">"  #event.name?

			msg_type = msg_type_translate(event) # only call once per message.

			if ( event.tracer.nil? )
				output += "<#{msg_type} context=\"#{event.name}\" timestamp=\"#{timestamp()}\">#{escape(message)}</#{msg_type}>"
			else
				ti = parse_trace_info( event )
				
				output += "<#{msg_type} context=\"#{event.name}\" timestamp=\"#{timestamp()}\">#{escape(message)}</#{msg_type}>"
				
				# TODO DW - do something with ti[:filename] ti[:lineno] ti[:function]?
			end					

			#output += "</context>"
									
			output
		end
		
		# the current timestamp
		#
		def timestamp( )
			DateTime.now.strftime('%Y-%m-%d %H:%M:%S')
		end
		
		# The message type ( translation to ulog message types )
		#
		def msg_type_translate( event )
		
			@num_events += 1
		
			case Log4r::LNAMES[event.level]
				when 'Fatal'
					@num_errors += 1
					"error"
				when 'Error'
					@num_errors += 1
					"error"
				when 'Warn'
					@num_warnings += 1
					"warning"
				when 'Debug'
					"debug"
				when 'Info'
					"message"
				else 
					Log4r::LNAMES[event.level]
			end
		end
		
		# Replace reserved xml characters with appropriate entities.
		#
		def escape( message )
			CGI.escapeHTML(message)		
		end
		
		# Reset
		#
		def begin( context )
			@num_events = 0
			@num_errors = 0
			@num_warnings = 0 
			@context = context
		end
		
		# Based on messages processed determine if it worthwhile presenting them
		#
		def should_show_log( )
			(@num_errors > 0 or @num_warnings > 0)
		end
		
		#---------------------------------------------------------------------
		# Private Methods
		#---------------------------------------------------------------------
	private
	
		def parse_trace_info( event )
			
			trace_info = {}
			matches = /^(.*)\:([0-9]+):in .([A-Za-z0-9_]+)./.match( event.tracer[0] )
			
			if ( ( nil != matches ) and ( matches.size >= 4 ) ) then
				trace_info[:filename] = matches[1]
				trace_info[:lineno] = matches[2]
				trace_info[:function] = matches[3]
			else
				trace_info[:filename] = ''
				trace_info[:lineno] = '-1'
				trace_info[:function] = ''
			end
			
			# Return our hash with trace information
			trace_info
		end	
	end	
	
	
	#
	# == Description
	# Log4r file outputter - this writes out an xml file in a format that can be viewed 
	# by our universal log viewer.
	# 
	#
	class UniversalLogXMLFileOutputter < Log4r::FileOutputter
		
		ULOG_ENABLE_VIEWER 	= true				# will completely disable the spwaning of the uilog viewer
		ULOG_VERSION 		= "1.0"				# for backwards compatibility we mark up the version of the ulog format this outputter will output.
		XML_ENCODING 		= "utf-8"			
		XML_VERSION 		= "1.0"				
		ULOG_USER		= ENV['USERNAME']
		ULOG_COMP		= ENV['COMPUTERNAME']
		ULOG_DEFAULT_CONTEXT 	= "default"			# the root context to insert into the ulog ( not the context of each message )
		BUILDER_NAME 		= "builder" 			# user name that will not use the viewer by default - automation users never desire this ( something more robust required ultimately )			
		ULOG_CLIENT_BINARY 	= "UniversalLogClient.exe"	# executable for viewing a ulog
				
		def initialize( _name, hash={}, view = false, context = ULOG_DEFAULT_CONTEXT )
			
			super( _name, hash )	
			
			@context = context		
			@view = view			
			@is_open = true 
			
			validate_hash( hash )

			write_header()

			# automated builder would not want a ulog viewer to pop up unless they expressly request it.
			@enable_viewer = Config.instance.user.username.downcase.include?( BUILDER_NAME ) ? false : true						
			
			# Ensure we close the log at program exit.  This ensures we write
			# the XML footer tags to construct a valid XML document.
			at_exit do 
				self.close() if @is_open
				self.view()
			end
		end
		
		def close
			return unless @is_open
		
			synch {				
				begin			
					# Finish XML tags, and close file.
					write_footer()
					super()

					pretty_print()
					
					@is_open = false
				rescue Exception => ex

					print_exception( ex )
				end
			}
		end
		
		def view	
		
			c = Pipeline::Config.instance
			viewer_command = "#{OS::Path::combine(c.toolsbin, ULOG_CLIENT_BINARY)} #{@filename}"
			status, stdout, stderr = systemu(viewer_command) if ( ULOG_ENABLE_VIEWER and @view and @formatter.should_show_log and @enable_viewer )		
			
			# TODO - DW : perhaps handle errors from the viewer?
		end
		
		#---------------------------------------------------------------------
		# Protected
		#---------------------------------------------------------------------
		
    protected

		def write_header( )
			@out.write( "<?xml version=\"#{XML_VERSION}\" encoding=\"#{XML_ENCODING}\" ?>" )
			@out.write( "<ulog name=\"#{@name}\" version=\"#{ULOG_VERSION}\" user=\"#{ULOG_USER}\" machine=\"#{ULOG_COMP}\" >" )		
			@out.write( "<context name=\"#{@context}\">" )
			
        	end
			
		def write_footer( )
			@out.write( "</context>" )
			@out.write( "</ulog>" )
        	end	
		
		def pretty_print( )
			replace_filename = OS::Path.replace_ext( @filename, 'orig' )
			
			FileUtils.cp( @filename, replace_filename )
			File.open( replace_filename, "r" ) do |xmlinfile|
				File.open( @filename, 'w' ) do |xmloutfile|
					logxml = REXML::Document.new( xmlinfile )
					logxml.xml_decl.encoding = XML_ENCODING
					fmt = REXML::Formatters::Pretty.new( )
					fmt.write( logxml, xmloutfile )	
				end
			end
			FileUtils.rm( replace_filename )
        	end

		def create_formatter()
			@formatter = UniversalLogXMLFormatter.new
			@formatter.begin(@context)
		end
		
		def validate_hash( hash )
			super( hash )	
			create_formatter()
		end			
	end


# Test this outputter.
if __FILE__ == $0
		
	config = Pipeline::Config.instance
	
	log_name = "#{OS::Path::get_basename( __FILE__ )}_test"
	log = Pipeline::Log::new( log_name )

	log2 = Pipeline::Log::new( "log2" )
	
	log.error( "This is an error with some xml characters in it that need escaping <> <!-- --> ; & \"" )
	log2.error( "This is an error in another log" )
	log.error( "This is another error" )
	log2.warn( "This is a warning" )
	log.info( "This is info" )	
end
	
end # Pipeline module

# %RS_TOOLSLIB%/pipeline/log/universal_log_fileoutputter.rb