From 62cb563ddc5f6923a9734a96d394ff2c27c320ca Mon Sep 17 00:00:00 2001
From: Sean Dague <sean@dague.net>
Date: Wed, 11 Jun 2014 11:06:32 -0400
Subject: [PATCH] convert devstack from awk to outfilter

The complexity of the awk script was pretty high, and it would
be good to do it in summaries as well, which starts to get a bit
squirelly. Instead bring over the outfilter.py from grenade and
use it for the timestamping.

Any additional overhead from python should be offset from not
shelling out to date on every line of output.

Change-Id: Ic2b86ddba3e7f6520a0fd35599b01143936c6deb
---
 stack.sh           | 21 +++--------
 tools/outfilter.py | 87 ++++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 92 insertions(+), 16 deletions(-)
 create mode 100755 tools/outfilter.py

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)