Add VERBOSE_NO_TIMESTAMP flag
As described in the documentation, this flag is intended for the case
where the console output is being captured by a tool that appends its
own timestamps.
In the gate this is the job-output.txt. We want the console output as
people like to watch that scrolling by as part of the live console
log. Although this gets saved to job-output.txt, we still want to
keep logging to the individual log files even though it's technically
a duplicate -- in the multinode case the job-output.txt gets
interleaved by all the running nodes; it's much easier to just look at
the individual log files. Also, people are used to it where it is :)
Change-Id: I3486636f1c76139581f6cd9668426f507b7c621d
diff --git a/.zuul.yaml b/.zuul.yaml
index a90df2f..cc29466 100644
--- a/.zuul.yaml
+++ b/.zuul.yaml
@@ -66,6 +66,7 @@
LOGFILE: /opt/stack/logs/devstacklog.txt
LOG_COLOR: false
VERBOSE: true
+ VERBOSE_NO_TIMESTAMP: true
NOVNC_FROM_PACKAGE: true
ERROR_ON_CLONE: true
# Gate jobs can't deal with nested virt. Disable it.
diff --git a/doc/source/configuration.rst b/doc/source/configuration.rst
index 49cad05..1d02395 100644
--- a/doc/source/configuration.rst
+++ b/doc/source/configuration.rst
@@ -286,6 +286,18 @@
LOG_COLOR=False
+When using the logfile, by default logs are sent to the console and
+the file. You can set ``VERBOSE`` to ``false`` if you only wish the
+logs to be sent to the file (this may avoid having double-logging in
+some cases where you are capturing the script output and the log
+files). If ``VERBOSE`` is ``true`` you can additionally set
+``VERBOSE_NO_TIMESTAMP`` to avoid timestamps being added to each
+output line sent to the console. This can be useful in some
+situations where the console output is being captured by a runner or
+framework (e.g. Ansible) that adds its own timestamps. Note that the
+log lines sent to the ``LOGFILE`` will still be prefixed with a
+timestamp.
+
Logging the Service Output
~~~~~~~~~~~~~~~~~~~~~~~~~~
diff --git a/stack.sh b/stack.sh
index 9b496c0..1d1f12e 100755
--- a/stack.sh
+++ b/stack.sh
@@ -405,6 +405,7 @@
# Set up logging level
VERBOSE=$(trueorfalse True VERBOSE)
+VERBOSE_NO_TIMESTAMP=$(trueorfalse False VERBOSE)
# Draw a spinner so the user knows something is happening
function spinner {
@@ -470,8 +471,12 @@
# stdout later.
exec 3>&1
if [[ "$VERBOSE" == "True" ]]; then
+ _of_args="-v"
+ if [[ "$VERBOSE_NO_TIMESTAMP" == "True" ]]; then
+ _of_args="$_of_args --no-timestamp"
+ fi
# Set fd 1 and 2 to write the log file
- exec 1> >( $TOP_DIR/tools/outfilter.py -v -o "${LOGFILE}" ) 2>&1
+ exec 1> >( $TOP_DIR/tools/outfilter.py $_of_args -o "${LOGFILE}" ) 2>&1
# Set fd 6 to summary log file
exec 6> >( $TOP_DIR/tools/outfilter.py -o "${SUMFILE}" )
else
diff --git a/tools/outfilter.py b/tools/outfilter.py
index 296cf8d..cf09124 100755
--- a/tools/outfilter.py
+++ b/tools/outfilter.py
@@ -36,6 +36,13 @@
parser.add_argument('-o', '--outfile',
help='Output file for content',
default=None)
+ # NOTE(ianw): This is intended for the case where your stdout is
+ # being captured by something like ansible which independently
+ # logs timestamps on the lines it receives. Note that if using a
+ # output file, those log lines are still timestamped.
+ parser.add_argument('-b', '--no-timestamp', action='store_true',
+ help='Do not prefix stdout with timestamp (bare)',
+ default=False)
parser.add_argument('-v', '--verbose', action='store_true',
default=False)
return parser.parse_args()
@@ -61,17 +68,23 @@
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
+ # 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.
+ # NOTE(ianw): we could actually strip the extra ts in "bare"
+ # mode (which came after this)? ... as we get more experience
+ # with zuulv3 native jobs and ansible capture it may become
+ # clearer what to do
if HAS_DATE.search(line) is None:
now = datetime.datetime.utcnow()
- line = ("%s | %s" % (
+ ts_line = ("%s | %s" % (
now.strftime("%Y-%m-%d %H:%M:%S.%f")[:-3],
line))
+ else:
+ ts_line = line
if opts.verbose:
- sys.stdout.write(line)
+ sys.stdout.write(line if opts.no_timestamp else ts_line)
sys.stdout.flush()
if outfile:
@@ -80,9 +93,9 @@
# opened with the system encoding and made the line into
# utf-8, so write the logfile out in utf-8 bytes.
if sys.version_info < (3,):
- outfile.write(line)
+ outfile.write(ts_line)
else:
- outfile.write(line.encode('utf-8'))
+ outfile.write(ts_line.encode('utf-8'))
outfile.flush()