Module: Awetestlib::Logging

Included in:
Regression::Runner
Defined in:
lib/awetestlib/logging.rb

Class Method Summary collapse

Instance Method Summary collapse

Class Method Details

.included(mod) ⇒ Object 



4
5
6
 
# File 'lib/awetestlib/logging.rb', line 4

def self.included(mod)
  # puts "RegressionSupport::Logging extended by #{mod}"
end

Instance Method Details

#capture_error_reference(ref, fail) ⇒ Object

category: Logging tags: error, fail, hits, reference, tag, tallies



392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
 
# File 'lib/awetestlib/logging.rb', line 392

def capture_error_reference(ref, fail)
  if fail
    @my_error_hits = Hash.new unless @my_error_hits
    if @my_error_hits[ref]
      @my_error_hits[ref] += 1
    else
      @my_error_hits[ref] = 1
    end
    #debug_to_report("#{__method__}: error hits:\n#{@my_error_hits.to_yaml}")
  end
  @my_error_references = Hash.new unless @my_error_references
  if @my_error_references[ref]
    @my_error_references[ref] += 1
  else
    @my_error_references[ref] = 1
  end
end

#debug_to_log(message, lnbr = __LINE__, dbg = false) ⇒ Object Also known as: debug_tolog

category: Logging tags: log, debug



162
163
164
165
 
# File 'lib/awetestlib/logging.rb', line 162

def debug_to_log(message, lnbr = __LINE__, dbg = false)
  message << " \n#{get_debug_list}" if dbg or @debug_calls # and not @debug_calls_fail_only)
  log_message(DEBUG, "#{message}", nil, lnbr)
end

#debug_to_report(message, dbg = false) ⇒ Object

category: Logging tags: log, debug, report



247
248
249
 
# File 'lib/awetestlib/logging.rb', line 247

def debug_to_report(message, dbg = false)
  mark_testlevel("(DEBUG):  \n", 0, "#{message}", dbg)
end

#error_to_log(message, lnbr = __LINE__) ⇒ Object Also known as: error_tolog

category: Logging tags: log, error Do not use for failed validations.



174
175
176
 
# File 'lib/awetestlib/logging.rb', line 174

def error_to_log(message, lnbr = __LINE__)
  log_message(ERROR, message, nil, lnbr)
end

#failed_to_log(message, lnbr = __LINE__, dbg = false) ⇒ Object Also known as: validate_failed_tolog, validate_failed_to_log, failed_tolog, fail_tolog, fail_to_log

category: Logging tags: log, error, fail, reference, tag, report



202
203
204
205
206
207
208
 
# File 'lib/awetestlib/logging.rb', line 202

def failed_to_log(message, lnbr = __LINE__, dbg = false)
  message << " \n#{get_debug_list}" if dbg or @debug_calls or @debug_calls_fail_only
  @my_failed_count += 1 if @my_failed_count
  parse_error_references(message, true)
  @report_class.add_to_report("#{message}" + " [#{get_caller(lnbr)}]","FAILED")
  log_message(WARN, "#{message}" + " (#{lnbr})]", FAIL, lnbr)
end

#fatal_to_log(message, lnbr = __LINE__, dbg = false) ⇒ Object Also known as: fatal_tolog

category: Logging tags: log, error, fail, reference, tag, fatal, report



220
221
222
223
224
225
226
 
# File 'lib/awetestlib/logging.rb', line 220

def fatal_to_log(message, lnbr = __LINE__, dbg = false)
  message << " \n#{get_debug_list}"  if dbg or (@debug_calls and not @debug_calls_fail_only)
  @my_failed_count += 1 if @my_failed_count
  parse_error_references(message, true)
  debug_to_report("#{__method__}:\n#{dump_caller(lnbr)}")
  log_message(FATAL, "#{message} (#{lnbr})", FAIL, lnbr)
end

#finish_run(ts = nil) ⇒ Object Also known as: finish_to_log

category: Logging tags: log, begin, error, reference, validation, pass, fail, tallies, tag



330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
 
# File 'lib/awetestlib/logging.rb', line 330

def finish_run(ts = nil)
  timestamp = Time.now unless ts

  mark_testlevel(">> Duration: #{sec2hms(timestamp - @start_timestamp)}", 0)

  mark_testlevel(">> Validations: #{@my_passed_count + @my_failed_count} | "+
                 "Fails: #{@my_failed_count}", 0) if @my_passed_count and @my_failed_count

  tally_error_references

  utc_ts = timestamp.getutc
  loc_tm = "#{timestamp.strftime("%H:%M:%S")} #{timestamp.zone}"
  debug_to_log(">> End #{@myName.titleize}")

end

#get_caller(lnbr = nil, exception = nil) ⇒ Object

category: Debug tags: log, caller, trace, report



274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
 
# File 'lib/awetestlib/logging.rb', line 274

def get_caller(lnbr=nil, exception=nil)
  script_name ||= File.basename(script_file)
  if lnbr && script_type.eql?("Selenium")
    [script_name, lnbr, 'in run()'].join(":")
  elsif lnbr && script_type.eql?("MobileNativeApp")
    [script_name, lnbr, 'in scenario()'].join(":")
  else
    caller_object = exception ? exception.backtrace : Kernel.caller
    call_frame    = caller_object.detect do |frame|
      frame.match(/#{script_name}/) or (library && frame.match(/#{library}/))
    end
    unless call_frame.nil?
      call_frame.gsub!(/^C:/, '')
      file, line, method = call_frame.split(":")
      [File.basename(file), line, method].join(":")
    else
      'unknown'
    end
  end
end

#info_to_log(message, lnbr = __LINE__) ⇒ Object Also known as: message_tolog, message_to_log, info_tolog

category: Logging tags: log



150
151
152
 
# File 'lib/awetestlib/logging.rb', line 150

def info_to_log(message, lnbr = __LINE__)
  log_message(INFO, message, nil, lnbr)
end

#init_logger(logFile, scriptName = nil) ⇒ Object 



295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
 
# File 'lib/awetestlib/logging.rb', line 295

def init_logger(logFile, scriptName = nil)
  if File.exist?(logFile)
    puts "==> Logfile already exists: #{logFile}. Replacing it."
    begin
      File.delete(logFile)
    rescue
      puts "#{scriptName}: init_logger RESCUE: #{$!}"
    end
  end
  logger               = ActiveSupport::BufferedLogger.new(logFile)
  logger.level         = Logger::DEBUG
  logger.auto_flushing = (true)
  logger.add(INFO, "#{logFile}\n#{ENV["OS"]}")
  logger
end

#log_message(severity, message, tag = '', lnbr = nil, addts = 1, exception = nil) ⇒ Object 



8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
 
# File 'lib/awetestlib/logging.rb', line 8

def log_message(severity, message, tag = '', lnbr = nil, addts = 1, exception=nil)
  # caller = get_caller(lnbr, exception)

  # @sequence ||= log_properties ? log_properties.fetch('sequence', 0) : 0
  # @sequence += 1

  t       = Time.now.utc
  @last_t ||= t
  @last_t = t
 dt       = t.strftime("%H%M%S")
  mySev    = translate_severity(severity)
  myCaller = get_caller(lnbr) || 'unknown'

  myMsg = "%-8s" % mySev
  myMsg << '[' + dt + ']:'
  if tag
    if tag.is_a? Fixnum
      tag = '-LVL' + tag.to_s
    end
  end
  myMsg << "[%-5s]:" % tag
  #myMsg << '[' + t.to_f.to_s + ']:'
  #myMsg << '[' + myCaller + ']:'
  #myMsg << "#{get_call_list[-1]}#{get_call_list[-2]} "
  myMsg << get_call_list_new.to_s
  myMsg << ' '+message
  #    myMsg << " {#{lnbr}} " if lnbr

  # # TODO This is broken: @myBrowser is not necessarily populated
  # if @screenCaptureOn and is_browser?(@myBrowser)
  #   if severity >= @options['screenshot'] andand
  #           tag.match(/PASS|FAIL/)
  #   then
  #     capture_screen(@myBrowser, t)
  #   end
                                        # end

  @myLog.add(severity, myMsg) if @myLog # add persistent logging for awetestlib. pmn 05jun2012
  puts myMsg+"\n"

  nil # so method doesn't return whole @output.
end

#log_sikuli_output(output_file, passed) ⇒ Object 



69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
 
# File 'lib/awetestlib/logging.rb', line 69

def log_sikuli_output(output_file, passed)
  output_lines = File.open(output_file, 'r') { |f| f.readlines }
  puts "IM FAILING?! #{passed}"

  # if passed

  log_messages = ['[log]', '[error]']
  output_lines = output_lines.select { |l| log_messages } #.detect{|msg| l.include?(msg)} }
  while line = output_lines.shift do
    puts "line to be logged: #{line}"
    if line.include? '[log]'
      passed_to_log line
    elsif line.include? '[error]'
      failed_to_log line
    elsif line.match /\s*Exception/
      failed_to_log output_lines.join("\n")
      break
    else
      debug_tolog line
    end
  end

  # else
  # failed_to_log "SIKULI LOG:\n\n #{output_lines.join('\n')}"
  # end

  return { :result => passed, :msg => output_str }
end

#mark_testlevel(message, lvl, desc = '', dbg = nil) ⇒ Object Also known as: mark_test_level

category: Logging tags: report, log, test level



133
134
135
136
137
138
139
140
141
142
 
# File 'lib/awetestlib/logging.rb', line 133

def mark_testlevel(message, lvl, desc = '', dbg = nil)
  strg = ''
  strg << message
  strg << " [#{desc}]" if desc.length > 0
  strg << " \n#{get_debug_list}" if dbg or @debug_calls
  @report_class.add_to_report(message, "&nbsp")
  log_message(INFO, strg, lvl, 1)
rescue
  failed_to_log("#{__method__}: #{$!}")
end

#message_to_report(message, dbg = false) ⇒ Object

category: Logging tags: log, report



239
240
241
 
# File 'lib/awetestlib/logging.rb', line 239

def message_to_report(message, dbg = false)
  mark_testlevel("#{message}", 0, '', dbg)
end

#parse_error_references(message, fail = false) ⇒ Object

category: Logging tags: error, reference, tag, tallies



380
381
382
383
384
385
386
 
# File 'lib/awetestlib/logging.rb', line 380

def parse_error_references(message, fail = false)
  msg = message.dup
  while msg =~ /(\*\*\*\s+[\w\d_\s,-:;\?]+\s+\*\*\*)/
    capture_error_reference($1, fail)
    msg.sub!($1, '')
  end
end

#pass_code_for(tag) ⇒ Object

private log_message



53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
 
# File 'lib/awetestlib/logging.rb', line 53

def pass_code_for(tag)
  case
    when tag =~ /PASS/
      'P'
    when tag =~ /FAIL/
      'F'
    #when tag =~ /\d+/ # avoid having to require andand for awetestlib. pmn 05jun2012
    when tag.andand.is_a?(Fixnum)
      'H'
    when tag =~ /DONE/
      'D'
    when tag =~ /role/
      'R'
  end
end

#passed_to_log(message, lnbr = __LINE__, dbg = false) ⇒ Object Also known as: validate_passed_tolog, validate_passed_to_log, passed_tolog, pass_tolog, pass_to_log

category: Logging tags: log, error, pass, reference, tag, report



184
185
186
187
188
189
190
 
# File 'lib/awetestlib/logging.rb', line 184

def passed_to_log(message, lnbr = __LINE__, dbg = false)
  message << " \n#{get_debug_list}" if dbg or @debug_calls # and not @debug_calls_fail_only)
  @my_passed_count += 1 if @my_passed_count
  parse_error_references(message)
  @report_class.add_to_report(message, "PASSED")
  log_message(INFO, "#{message}", PASS, lnbr)
end

#start_run(ts = nil) ⇒ Object Also known as: start_to_log

category: Logging tags: error, fail, reference, tag



317
318
319
320
321
322
 
# File 'lib/awetestlib/logging.rb', line 317

def start_run(ts = nil)
  @start_timestamp = Time.now unless ts
  utc_ts = @start_timestamp.getutc
  loc_tm = "#{@start_timestamp.strftime("%H:%M:%S")} #{@start_timestamp.zone}"
  debug_to_log(">> Starting #{@myName.titleize}")
end

#tally_error_references(list_tags = @report_all_refs) ⇒ Object

category: Logging tags: log, error, reference, tag, tallies



352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
 
# File 'lib/awetestlib/logging.rb', line 352

def tally_error_references(list_tags = @report_all_refs)
  tags_tested = 0
  tags_hit    = 0
  if @my_error_hits and @my_error_hits.length > 0
    mark_testlevel("Tagged Error Hits:", 0)
    tags_hit = @my_error_hits.length
    @my_error_hits.each_key do |ref|
      mark_testlevel("#{ref} - #{@my_error_hits[ref]}", 0)
    end
  end
  if list_tags
    if @my_error_references and @my_error_references.length > 0
      mark_testlevel("Error and Test Case Tags:", 0)
      tags_tested = @my_error_references.length
      @my_error_references.each_key do |ref|
        mark_testlevel("#{ref} - #{@my_error_references[ref]}", 0)
      end
      mark_testlevel("Fails were hit on #{tags_hit} of #{tags_tested} error/test case references", 0)
    else
      mark_testlevel("No Error or Test Case References found.", 0)
    end
  end
end

#translate_severity(severity) ⇒ Object 



251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
 
# File 'lib/awetestlib/logging.rb', line 251

def translate_severity(severity)
  mySev = ''
  case
    when severity == 0
      mySev = 'DEBUG'
    when severity == 1
      mySev = 'INFO'
    when severity == 2
      mySev = 'WARN'
    when severity == 3
      mySev = 'ERROR'
    when severity == 4
      mySev = 'FATAL'
    when severity > 4
      mySev = 'UNKNOWN'
  end
  mySev
end