#######################  log.rb -- brent@mbari.org  #######################
# $Source: /home/cvs/ESP/gen2/software/esp/lib/log.rb,v $
#    Copyright (C) 2003 MBARI
#    MBARI Proprietary Information. All rights reserved.
# $Id: log.rb,v 1.26 2005/11/01 18:23:08 brent Exp $
#
#    Manage a log file of Timestamps, Control Messages, Exceptions and Comments
#  (See Msg class)
#
# Log file format:
#
#   Each file consists of a series of log entries
#   Each Log file entry is terminated by a line break
#   Each log entry is either:
#     a Timestamp, a Legend, a Message, an Exception Object, or a Comment
#
#   The first byte of each entry determines its type.
#   The format of a Timestamp log entry is either calendar or simulated time:
#     '@' Float.asLogString #for simulated time
#     '@' Time.asLogString  #for calendar time
#
#   The format of a Message entry is:
#     <target id>? <message string>
#     target ids are a single byte that denotes the target message queue
#     target ids shall not contain control or punctuation characters
#     message strings that contain line breaks or begin with:
#       '@', '!', '=', '#', '\', "\""
#     or a valid target id will be automatically escaped with '\'.  Any byte
#     following '\' is always interpreted as part of the current message string.
#
#   The format of an Exception Object is:
#     '!' ('"'<thread name>'"'|<target id>)? <object string>
#     object string the string representation of the Ruby object produced by
#     Marshal.dump with line breaks and '\' escaped with '\'
#     If the thread in which the exception occured has no target id associated
#     with it (i.e. it was not a message dispatching thread), the thread's 
#     name, in double-quotes, appears in place of the target id.
#
#   The format of a Comment is:
#     "#" ('"'<thread name>'"')|<target id>? <comment string>
#     The comment string is escaped in the same way the object strings are
#
#   The format of a Method Invocation is a special Comment:
#     "." ('"'<thread name>'"')|<target id>? <method string>
#     method string ==> <receiver identifier>.<method_id>(arg.to_s*)
#
#   The format of a Legend is:
#     '=' (<target id>|<thread name> <name>)+
#     The legend entry defines the mapping between names and target ids
#     for all subsequent entries.  
#     A blank Legend of '=' clears all target id => name mappings
#
############################################################################

require 'schedule'

class Float
  unless method_defined? :asLogString
    def asLogString ignored=nil, ignored2=nil
      '%.2f' % self
    end
  end
end

class Numeric
  unless method_defined? :asLogString
    def asLogString ignored=nil, ignored2=nil
      to_s
    end
  end
end

class Time
  unless method_defined? :asLogString
    def asLogString last=nil, zone=" %Z "
      f="%H:%M:%S." + ("%06d" % (usec+5000))[0,2]
      f+="#{zone}%d-%b-%y" unless last.is_a? Time and last <= self and 
               last.yday == yday and last.year == year
      strftime f
    end
  end
end
  
class Log < RMutex
  class Error < StandardError
  end
  class CannotDump < Error
  end
  
  class Nothing
    class << self
      def recordMsg thread, msg
      end
      alias_method :quietlyRecordMsg, :recordMsg
      alias_method :recordException, :recordMsg
      alias_method :recordObject, :recordMsg
      def record text, thread=nil
      end
      alias_method :recordComment, :record
      alias_method :quietlyRecord, :record
      def recordTime now=nil
      end
      def denote ignoreHash
      end
      def terminate
      end
    end
  end  
  @@default = Nothing   #initially log into the bit bucket
  

  def initialize logFile, targets={}
  # create a new Log object for specified targets
  # logFile is a previously opened (for writing) file
  # targets is a hash of Msg::Target => (TargetId) Strings
  # each targetId must be single character string
    @log=logFile
    super()
    recordTime          #record when logging began
    denote targets
    @@default=self
  end
  
  class <<self  #class methods
    def default= logger
      @@default=logger
    end
    def default
      @@default
    end
    def record(*args)
      @@default.record(*args)
    end
    alias_method :recordComment, :record
    alias_method :quietlyRecord, :record
    
    def recordMethod(*args)
      @@default.recordMethod(*args)
    end
    
    def recordException(*args)
      @@default.recordException(*args)
    end
    alias_method :recordObject, :recordException
  end
  
  @@bodySpecials=Regexp.new ('['+Regexp.quote("\\\n")+']',Regexp::MULTILINE)
  @@nameSpecials=Regexp.new ('['+Regexp.quote("\\\"\n")+']',Regexp::MULTILINE)
      
  def flush
    @log.flush
  end
  
  def denote targets
    @log.puts '=' if @targets and @targets!={}
    @targetNames={}
    targets.each {|target, targetId|
      raise (Error, "Invalid targetId #{targetId.inspect}") if
        "!@#=\n\\".include? targetId
      @log.print '=',targetId.chr,
        target.name.to_s.gsub(@@nameSpecials) {|special| "\\"+special}, "\n"
      @targetNames[target.name]=targetId
    }  
    @targets=targets
    ids=targets.values.collect{|t|t.chr}.to_s
    @msgSpecials=Regexp.new ('['+Regexp.quote("\\\n!#\.=@"+ids)+']',
                            Regexp::MULTILINE)
    @objectSpecials=Regexp.new ('['+Regexp.quote("\\\n"+ids)+']',
                                Regexp::MULTILINE)
  end
  
  def recordTime (now=Time.now)
    lock {
      if @lastTime != now  #don't record same time as last one recorded
        @log.print '@', now.asLogString(@lastTime,"%Z"), "\n"
        @lastTime = now
      end
    }
  end
  
  def append (target, body, marker=nil)
  # append a log entry to the log
  # Prefix with time entry if last entry's time != current time
  # body may be a msg String or an Exception object
  # target must be one of the targets passed to initialize or
  #  some other (typically Thread) object that responds to :name
    lock {
      sch=Time unless sch=Thread.schedule
      recordTime sch.now
      specials = marker ? (@log.print marker; @objectSpecials) : @msgSpecials
      if @target != target
        targetName=target.name
        if !@target or targetName != @target.name
          begin
            targetId = @targetNames.fetch targetName
          rescue IndexError
            targetId = '"' + targetName.to_s.gsub(@@nameSpecials) {
                                            |special| "\\"+special} + '"'
          else
            targetId = targetId.chr
          end
          @log.print targetId
        end
        @target = target
      end
      escaped=body[0..0].sub(specials) {|special| "\\"+special} + 
              body[1..-1].gsub(@@bodySpecials) {|special| "\\"+special}
      @log.print escaped, "\n"
      @log.flush
    }
  end
  private :append


  def recordMsg target, body
  # record a message or exception log entry
  # Prefix with time entry if last entry's time != current time
  # body may be a msg String or an Exception object
  # target must be one of the targets passed to initialize or
  #  some other (typically Thread) object that responds to :name
    append target, body
  end
  alias_method :quietlyRecordMsg, :recordMsg
  
  def recordException object, thread=Thread.current
    begin
      body=Marshal.dump object
    rescue TypeError  #try to cope with an object we cannot Marshal
      body = Marshal.dump (Log::CannotDump.new object.inspect)
    end
    append thread, body, '!'
  end
  alias_method :recordObject, :recordException
  
  def recordComment text, thread=Thread.current
  # record a comment log entry
    append thread, text.to_s, '#'
  end
  alias_method :record, :recordComment
  alias_method :quietlyRecord, :recordComment
  
  def recordMethod rcvrObj, methodId, args=[], thread=Thread.current
  # record a method log entry
    txt=rcvrObj ? rcvrObj.intern.to_s+'.'+methodId.to_s : methodId.to_s.dup
    unless args.empty?
      sep=' '
      args.each {|arg|
        sep<<?: if arg.kind_of? Symbol
        txt<<sep<<(arg.nil? ? 'nil' : arg.intern.to_s); sep=','
      }
    end
    append thread, txt, '.'
    txt
  end
  
  def terminate
  # terminate this log (just before closing the file)
    recordTime      #record when logging ended
  end
  
  def puts string
    @console.puts string
    @console.flush
  end
  
  class Exceptions < Log    #also log exceptions to as they occur
    def initialize logFile, targets={}, console=$stdout
      @console = console
      super logFile, targets
    end
    attr_accessor :console
    
    def recordTime t=Time.now
      lock {
        super
        @nextT = t
      }
    end
    def recordException exception, thread=Thread.current
      lock {
        super
        updateTime
        Thread.recordException exception, thread, @console
      }
    end
    protected
    def updateTime
      if @lastT != @nextT
        @console.print '@', @nextT.asLogString(@lastT), ' '
        @lastT = @nextT
      end
    end
  end

  class ExceptionsAndComments < Exceptions  #comments to stdout too
    def recordComment text, thread=Thread.current
      lock {
        super
        update thread
        puts text
      }
    end
    def recordMethod rcvrObj, methodId, args=[], thread=Thread.current
      lock {
        txt = super
        update thread
        puts txt
        txt
      }
    end
    alias_method :record, :recordComment
    protected
    def updateThread thread
      @console.print 'in ',(@lastThread=thread).name,': ' if @lastThread!=thread
    end
    def update thread
      updateTime; updateThread thread
    end
  end

  class All < ExceptionsAndComments  #everything to both log file and console
    def recordMsg target, rawMsg
      lock {
        super
        updateTime
        puts target.msgText rawMsg
      }
    end
  end


end #class Log