diff --git a/stack.sh b/stack.sh index d2f18d48c1..e73b16aa70 100755 --- a/stack.sh +++ b/stack.sh @@ -548,25 +548,14 @@ if [[ -n "$LOGFILE" ]]; then exec 3>&1 if [[ "$VERBOSE" == "True" ]]; then # Set fd 1 and 2 to write the log file - exec 1> >( awk -v logfile=${LOGFILE} ' - /((set \+o$)|xtrace)/ { next } - { - cmd ="date +\"%Y-%m-%d %H:%M:%S.%3N | \"" - cmd | getline now - close("date +\"%Y-%m-%d %H:%M:%S.%3N | \"") - sub(/^/, now) - print > logfile - fflush(logfile) - print - fflush("") - }' ) 2>&1 + exec 1> >( ./tools/outfilter.py -v -o "${LOGFILE}" ) 2>&1 # Set fd 6 to summary log file - exec 6> >( tee "${SUMFILE}" ) + exec 6> >( ./tools/outfilter.py -o "${SUMFILE}" ) else # 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}" >&3 ) + exec 6> >( ./tools/outfilter.py -v -o "${SUMFILE}" >&3 ) fi echo_summary "stack.sh log $LOGFILE" @@ -583,7 +572,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 >&3 ) fi # Set up logging of screen windows diff --git a/tools/outfilter.py b/tools/outfilter.py new file mode 100755 index 0000000000..9686a387c2 --- /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)