diff --git a/grenade.sh b/grenade.sh index 4b2be9da..f7bea09e 100755 --- a/grenade.sh +++ b/grenade.sh @@ -96,15 +96,21 @@ if [[ -n "$LOGFILE" ]]; then # Copy stdout to fd 3 exec 3>&1 if [[ "$VERBOSE" == "True" ]]; then + echo "Running in verbose mode:" + echo " Full logs found at => ${LOGFILE}" + echo " Summary logs at => ${SUMFILE}" # Redirect stdout/stderr to tee to write the log file - exec 1> >( tee "${LOGFILE}" ) 2>&1 + exec 1> >( ./tools/outfilter.py -v -o "${LOGFILE}" ) 2>&1 # Set up a second fd for output - exec 6> >( tee "${SUMFILE}" ) + exec 6> >( ./tools/outfilter.py -o "${SUMFILE}" ) else + echo "Running in summary mode:" + echo " Full logs found at => ${LOGFILE}" + echo " Summary logs at => ${SUMFILE}" # Set fd 1 and 2 to primary logfile - exec 1> "${LOGFILE}" 2>&1 + exec 1> >( ./tools/outfilter.py -o "${LOGFILE}") 2>&1 # Set fd 6 to summary logfile and stdout - exec 6> >( tee "${SUMFILE}" /dev/fd/3 ) + exec 6> >( ./tools/outfilter.py -v -o "${SUMFILE}" >&3) fi echo_summary "grenade.sh log $LOGFILE" @@ -120,7 +126,7 @@ else exec 1>/dev/null 2>&1 fi # Always send summary fd to original stdout - exec 6>&3 + exec 6> >( ./tools/outfilter.py -v -o "${SUMFILE}" >&3) fi # Set up logging of screen windows diff --git a/tools/outfilter.py b/tools/outfilter.py new file mode 100755 index 00000000..9686a387 --- /dev/null +++ b/tools/outfilter.py @@ -0,0 +1,87 @@ +#!/usr/bin/env python +# +# Copyright 2014 Hewlett-Packard Development Company, L.P. +# +# Licensed under the Apache License, Version 2.0 (the "License"); you may +# not use this file except in compliance with the License. You may obtain +# a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, WITHOUT +# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the +# License for the specific language governing permissions and limitations +# under the License. + +# This is an output filter to filter and timestamp the logs from grenade and +# devstack. Largely our awk filters got beyond the complexity level which were +# sustainable, so this provides us much more control in a single place. +# +# The overhead of running python should be less than execing `date` a million +# times during a run. + +import argparse +import datetime +import re +import sys + +IGNORE_LINES = re.compile('(set \+o|xtrace)') +HAS_DATE = re.compile('^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3} \|') + + +def get_options(): + parser = argparse.ArgumentParser( + description='Filter output by devstack and friends') + parser.add_argument('-o', '--outfile', + help='Output file for content', + default=None) + parser.add_argument('-v', '--verbose', action='store_true', + default=False) + return parser.parse_args() + + +def skip_line(line): + """Should we skip this line.""" + return IGNORE_LINES.search(line) is not None + + +def main(): + opts = get_options() + outfile = None + if opts.outfile: + outfile = open(opts.outfile, 'a', 0) + + # otherwise fileinput reprocess args as files + sys.argv = [] + while True: + line = sys.stdin.readline() + if not line: + return 0 + + # put skip lines here + if skip_line(line): + continue + + # this prevents us from nesting date lines, because + # we'd like to pull this in directly in grenade and not double + # up on devstack lines + if HAS_DATE.search(line) is None: + now = datetime.datetime.utcnow() + line = ("%s | %s" % ( + now.strftime("%Y-%m-%d %H:%M:%S.%f")[:-3], + line)) + + if opts.verbose: + sys.stdout.write(line) + sys.stdout.flush() + if outfile: + outfile.write(line) + outfile.flush() + + +if __name__ == '__main__': + try: + sys.exit(main()) + except KeyboardInterrupt: + sys.exit(1)