scripts/flog

#!/usr/bin/env python
# Copyright 2017 The Fuchsia Authors. All rights reserved.
# Use of this source code is governed by a BSD-style license that can be
# found in the LICENSE file.
"""flog is a developer friendly log listener with automatic crash symbol decoder.

The crash is archived to /tmp/fuchsia-crash or a specified directory.
Configurable keywords or lines with them can be color coded.
"""

import argparse
import os
import re
import subprocess
import sys
from time import gmtime
from time import strftime

CASE_SENSITIVE = False
BEGINS = []
ENDS = []
SUPPRESSES = []
CRASH_DIR = '/tmp/fuchsia_crash'

# TODO(porce): Support regular expression
# TODO(porce): Support compatibility with REGEX_ regex expressions
COLOR_LINES = {'error': 'red'}
COLOR_WORDS = {
    'warn': 'white-on-red',
    'error': 'white-on-red',
    'fail': 'white-on-red',
    'exception': 'white-on-red',
    'address': 'green',
    'did not add device in bind': 'green',
}

RESET = '\033[1;0m'

COLORS = {
    'WHITE-ON-RED': '\033[41;37m',
    'BLACK': '\033[30;1m',
    'RED': '\033[31;1m',
    'GREEN': '\033[32;1m',
    'YELLOW': '\033[33;1m',
    'BLUE': '\033[34;1m',
    'MAGENTA': '\033[35;1m',
    'CYAN': '\033[36m;1m',
}

FIRST_LOG_AFTER_BOOTUP = '[00000.000] 00000.00000> bootdata:'

# REGEX_* are constructed when the command line arguments are parsed.
REGEX_BEGINS = ''
REGEX_ENDS = ''
REGEX_SUPPRESS = ''
REGEX_COLOR_LINES = ''
REGEX_COLOR_WORDS = ''


def static_vars(**kwargs):

  def decorate(func):
    for k in kwargs:
      setattr(func, k, kwargs[k])
    return func

  return decorate


def now_str():
  return strftime('%Y%m%d_%H%M%S', gmtime())


def get_log_listener(args):
  # return 'cat /tmp/z' # Unit test
  listener = 'fx log'
  return '{} {}'.format(listener, ' '.join(x for x in args))


@static_vars(crash_dump=[])
@static_vars(is_crashing=False)
def monitor_crash(line):
  if '<==' in line and 'exception' in line:
    monitor_crash.is_crashing = True

  if monitor_crash.is_crashing is True:
    monitor_crash.crash_dump.append(line)

  if ': end' in line and 'bt#' in line:
    decode_backtrace(monitor_crash.crash_dump, CRASH_DIR)
    monitor_crash.crash_dump = []
    monitor_crash.is_crashing = False


def color(string, color_name):
  if color_name.upper() not in COLORS:
    return string

  ends_in_newline = string.endswith('\n')

  if ends_in_newline:
    string = string[:-1]

  result = '{}{}{}'.format(COLORS[color_name.upper()], string, RESET)

  if ends_in_newline:
    result += '\n'

  return result


def anymatch(test_string, regexes):
  global CASE_SENSITIVE
  if CASE_SENSITIVE:
    ans = re.search(regexes, test_string)
  else:
    ans = re.search(regexes, test_string, flags=re.IGNORECASE)

  return ans.group(0) if ans else None


@static_vars(is_in_session=False)
def is_suppressed(line):
  """Test if the log may be printed or not.

  Args:
    line (str): A log line.

  Returns:
    True if the log line should be suppressed. False otherwise.
  """
  if line.startswith(FIRST_LOG_AFTER_BOOTUP):
    # A reboot occurs. Reset to default.
    is_suppressed.is_in_session = False

  if not BEGINS or anymatch(line, REGEX_BEGINS):
    if not is_suppressed.is_in_session:
      print '\n' * 3
      is_suppressed.is_in_session = True

  if anymatch(line, REGEX_ENDS):
    is_suppressed.is_in_session = False

  if not is_suppressed.is_in_session:
    return True

  if anymatch(line, REGEX_SUPPRESSES):
    return True

  return False


def colorize(line_incoming):
  """Color-code the log line.

  Args:
    line_incoming: log line.

  Returns:
    color-coded log line
  """

  line = line_incoming

  k = anymatch(line, REGEX_COLOR_LINES)
  if k:
    v = COLOR_LINES.get(k.lower(), '')
    line = color(line, v)
    return line

  if anymatch(line, REGEX_COLOR_WORDS):
    # TODO(porce): Maybe there are less costly ways.
    for k, v in COLOR_WORDS.iteritems():
      replacement = r'%s\1%s' % (COLORS[v.upper()], RESET)
      search = '(?i)(' + '|'.join(map(re.escape, [k])) + ')'
      line = re.sub(search, replacement, line)

  return line


def print_log(line):
  if is_suppressed(line):
    return

  print colorize(line),


def hijack_stdout(cmd):
  proc = subprocess.Popen(cmd.split(), stdout=subprocess.PIPE)
  return iter(proc.stdout.readline, '')


def get_decode_cmd():
  decode_cmd = 'ffx debug symbolize'
  return decode_cmd


def print_bt(line):
  """Print backtrace with some colors.

  Args:
    line (str): Backtrace line.
  """
  tokens = line.split(' at ')

  methods = tokens[:-1]
  methods.append('')
  methods_text = ' at '.join(x for x in methods)

  path = tokens[-1]
  path_tokens = path.split('/')
  paths = path_tokens[:-1]
  paths.append('')

  path_text = '/'.join(x for x in paths)
  path_colored = path_text + color(path_tokens[-1], 'red')

  print methods_text, path_colored,


def decode_backtrace(crash_dump, dst_dir):
  """A wrapper to fsymbolize.

  Args:
    crash_dump (array): array of log lines.
    dst_dir    (str): directory to archive to.
  """
  os.system('mkdir -p {}'.format(dst_dir))
  crash_file_path = '{}/{}.crash'.format(dst_dir, now_str())
  tmp_file = '{}/tmp.dump'.format(dst_dir)

  f = open(tmp_file, 'w')
  for line in crash_dump:
    f.write(line)
  f.close()

  cmd = '{} < {} > {}'.format(get_decode_cmd(), tmp_file, crash_file_path)
  os.system(cmd)

  print '\n\n'

  is_start = False
  with open(crash_file_path, 'r') as f:
    for line in f:
      if 'start of symbolized stack:' in line:
        is_start = True

      if is_start:
        print_bt(line)
  print '\n\n'


def parse_color_map(string):
  """Converted comma separated text into a color code map.

  Args:
    string (str): a text line

  Returns:
   Dictionary whose key is a text pattern and value is the color name.
  """
  m = {}
  items = string.split(',')
  for item in items:
    sep = ':'
    if sep not in item:
      continue

    idx = item.rfind(sep)
    text = item[:idx]
    color_name = item[idx + 1:]

    if text.__len__() == 0:
      continue

    m[text] = color_name

  return m


def proc_cmdline():
  """Argument parser.

  Returns:
    args.
  """
  example_commands = """

  Pro tip: Use comma separated texts for multiple matches

  Example:
  $ flog --begin \'my module starts,rare event\'
         --end \'my module ends\'
         --suppress \'verbose,chatty\'
         --lines \'error msg:red,warn:blue\'
         --words \'register 0x00:green,exit:yellow\'

  """

  p = argparse.ArgumentParser(
      description='A friendly Fuchsia log listener',
      epilog=example_commands,
      formatter_class=argparse.RawDescriptionHelpFormatter)

  p.add_argument('--begin', type=str, help='trigger texts to start logging')
  p.add_argument('--end', type=str, help='trigger texts to end logging')

  p.add_argument(
      '--case', type=bool, help='match case-sensitively', default=False)

  p.add_argument('--suppress', type=str, help='text to suppress the line')
  p.add_argument('--lines', type=str, help='colorize the line. {text:color}')
  p.add_argument('--words', type=str, help='colorize the word. {text:color}')
  p.add_argument('--crashdir', type=str, help='directory to store crash files.')
  p.add_argument(
      'remainders',
      nargs=argparse.REMAINDER,
      help='arguments passed to loglistener')

  args = p.parse_args()

  global CASE_SENSITIVE
  global BEGINS
  global ENDS
  global SUPPRESSES
  global COLOR_LINES
  global COLOR_WORDS
  global CRASH_DIR

  CASE_SENSITIVE = args.case
  if args.begin:
    BEGINS.extend(args.begin.split(','))
  if args.end:
    ENDS.extend(args.end.split(','))
  if args.suppress:
    SUPPRESSES.extend(args.suppress.split(','))
  if args.lines:
    COLOR_LINES.update(parse_color_map(args.lines))
  if args.words:
    COLOR_WORDS.update(parse_color_map(args.words))
  if args.crashdir:
    CRASH_DIR = args.crashdir

  global REGEX_BEGINS
  global REGEX_ENDS
  global REGEX_SUPPRESSES
  global REGEX_COLOR_LINES
  global REGEX_COLOR_WORDS

  # TODO(porce): Support regex input
  REGEX_BEGINS = '|'.join(BEGINS)
  REGEX_ENDS = '|'.join(ENDS)
  REGEX_SUPPRESSES = '|'.join(SUPPRESSES)
  REGEX_COLOR_LINES = '|'.join(k for k, v in COLOR_LINES.iteritems())
  REGEX_COLOR_WORDS = '|'.join(k for k, v in COLOR_WORDS.iteritems())

  return args


def main():
  args = proc_cmdline()
  cmd = get_log_listener(args.remainders)
  for line in hijack_stdout(cmd):
    print_log(line)
    monitor_crash(line)


main()