Allow tty output to be timestamped (#10554)
* Spack debug output now includes microsecond-granularity timestamps. * Timestamps can also be enabled with the `--timestamp` command line argument.
This commit is contained in:
sknigh
Todd Gamblin
parent
2202579685
commit
a76c50d1ee
@ -3,6 +3,7 @@
|
||||
#
|
||||
# SPDX-License-Identifier: (Apache-2.0 OR MIT)
|
||||
|
||||
from datetime import datetime
|
||||
import fcntl
|
||||
import os
|
||||
import struct
|
||||
@ -18,6 +19,10 @@
|
||||
_debug = False
|
||||
_verbose = False
|
||||
_stacktrace = False
|
||||
_timestamp = False
|
||||
_msg_enabled = True
|
||||
_warn_enabled = True
|
||||
_error_enabled = True
|
||||
indent = " "
|
||||
|
||||
|
||||
@ -43,6 +48,65 @@ def set_verbose(flag):
|
||||
_verbose = flag
|
||||
|
||||
|
||||
def set_timestamp(flag):
|
||||
global _timestamp
|
||||
_timestamp = flag
|
||||
|
||||
|
||||
def set_msg_enabled(flag):
|
||||
global _msg_enabled
|
||||
_msg_enabled = flag
|
||||
|
||||
|
||||
def set_warn_enabled(flag):
|
||||
global _warn_enabled
|
||||
_warn_enabled = flag
|
||||
|
||||
|
||||
def set_error_enabled(flag):
|
||||
global _error_enabled
|
||||
_error_enabled = flag
|
||||
|
||||
|
||||
def msg_enabled():
|
||||
return _msg_enabled
|
||||
|
||||
|
||||
def warn_enabled():
|
||||
return _warn_enabled
|
||||
|
||||
|
||||
def error_enabled():
|
||||
return _error_enabled
|
||||
|
||||
|
||||
class SuppressOutput:
|
||||
"""Class for disabling output in a scope using 'with' keyword"""
|
||||
|
||||
def __init__(self,
|
||||
msg_enabled=True,
|
||||
warn_enabled=True,
|
||||
error_enabled=True):
|
||||
|
||||
self._msg_enabled_initial = _msg_enabled
|
||||
self._warn_enabled_initial = _warn_enabled
|
||||
self._error_enabled_initial = _error_enabled
|
||||
|
||||
self._msg_enabled = msg_enabled
|
||||
self._warn_enabled = warn_enabled
|
||||
self._error_enabled = error_enabled
|
||||
|
||||
def __enter__(self):
|
||||
set_msg_enabled(self._msg_enabled)
|
||||
set_warn_enabled(self._warn_enabled)
|
||||
set_error_enabled(self._error_enabled)
|
||||
|
||||
def __exit__(self, exc_type, exc_val, exc_tb):
|
||||
set_msg_enabled(self._msg_enabled_initial)
|
||||
set_warn_enabled(self._warn_enabled_initial)
|
||||
set_error_enabled(self._error_enabled_initial)
|
||||
|
||||
|
||||
def set_stacktrace(flag):
|
||||
global _stacktrace
|
||||
_stacktrace = flag
|
||||
@ -65,15 +129,28 @@ def process_stacktrace(countback):
|
||||
return st_text
|
||||
|
||||
|
||||
def get_timestamp(force=False):
|
||||
"""Get a string timestamp"""
|
||||
if _debug or _timestamp or force:
|
||||
return datetime.now().strftime("[%Y-%m-%d-%H:%M:%S.%f] ")
|
||||
else:
|
||||
return ''
|
||||
|
||||
|
||||
def msg(message, *args, **kwargs):
|
||||
if not msg_enabled():
|
||||
return
|
||||
|
||||
newline = kwargs.get('newline', True)
|
||||
st_text = ""
|
||||
if _stacktrace:
|
||||
st_text = process_stacktrace(2)
|
||||
if newline:
|
||||
cprint("@*b{%s==>} %s" % (st_text, cescape(message)))
|
||||
cprint("@*b{%s==>} %s%s" % (
|
||||
st_text, get_timestamp(), cescape(message)))
|
||||
else:
|
||||
cwrite("@*b{%s==>} %s" % (st_text, cescape(message)))
|
||||
cwrite("@*b{%s==>} %s%s" % (
|
||||
st_text, get_timestamp(), cescape(message)))
|
||||
for arg in args:
|
||||
print(indent + str(arg))
|
||||
|
||||
@ -88,7 +165,8 @@ def info(message, *args, **kwargs):
|
||||
st_text = ""
|
||||
if _stacktrace:
|
||||
st_text = process_stacktrace(st_countback)
|
||||
cprint("@%s{%s==>} %s" % (format, st_text, cescape(str(message))),
|
||||
cprint("@%s{%s==>} %s%s" % (
|
||||
format, st_text, get_timestamp(), cescape(str(message))),
|
||||
stream=stream)
|
||||
for arg in args:
|
||||
if wrap:
|
||||
@ -115,12 +193,18 @@ def debug(message, *args, **kwargs):
|
||||
|
||||
|
||||
def error(message, *args, **kwargs):
|
||||
if not error_enabled():
|
||||
return
|
||||
|
||||
kwargs.setdefault('format', '*r')
|
||||
kwargs.setdefault('stream', sys.stderr)
|
||||
info("Error: " + str(message), *args, **kwargs)
|
||||
|
||||
|
||||
def warn(message, *args, **kwargs):
|
||||
if not warn_enabled():
|
||||
return
|
||||
|
||||
kwargs.setdefault('format', '*Y')
|
||||
kwargs.setdefault('stream', sys.stderr)
|
||||
info("Warning: " + str(message), *args, **kwargs)
|
||||
|
||||
@ -238,7 +238,7 @@ def fetch(self):
|
||||
if not spack.config.get('config:verify_ssl'):
|
||||
curl_args.append('-k')
|
||||
|
||||
if sys.stdout.isatty():
|
||||
if sys.stdout.isatty() and tty.msg_enabled():
|
||||
curl_args.append('-#') # status bar when using a tty
|
||||
else:
|
||||
curl_args.append('-sS') # just errors when not.
|
||||
|
||||
@ -329,6 +329,9 @@ def make_argument_parser(**kwargs):
|
||||
parser.add_argument(
|
||||
'-d', '--debug', action='store_true',
|
||||
help="write out debug logs during compile")
|
||||
parser.add_argument(
|
||||
'--timestamp', action='store_true',
|
||||
help="Add a timestamp to tty output")
|
||||
parser.add_argument(
|
||||
'--pdb', action='store_true',
|
||||
help="run spack under the pdb debugger")
|
||||
@ -399,6 +402,9 @@ def setup_main_options(args):
|
||||
spack.util.debug.register_interrupt_handler()
|
||||
spack.config.set('config:debug', True, scope='command_line')
|
||||
|
||||
if args.timestamp:
|
||||
tty.set_timestamp(True)
|
||||
|
||||
# override lock configuration if passed on command line
|
||||
if args.locks is not None:
|
||||
spack.util.lock.check_lock_safety(spack.paths.prefix)
|
||||
|
||||
@ -1476,6 +1476,9 @@ def build_process():
|
||||
# Save the build environment in a file before building.
|
||||
dump_environment(self.env_path)
|
||||
|
||||
# cache debug settings
|
||||
debug_enabled = tty.is_debug()
|
||||
|
||||
# Spawn a daemon that reads from a pipe and redirects
|
||||
# everything to log_path
|
||||
with log_output(self.log_path, echo, True) as logger:
|
||||
@ -1483,8 +1486,11 @@ def build_process():
|
||||
self.phases, self._InstallPhase_phases):
|
||||
|
||||
with logger.force_echo():
|
||||
inner_debug = tty.is_debug()
|
||||
tty.set_debug(debug_enabled)
|
||||
tty.msg(
|
||||
"Executing phase: '%s'" % phase_name)
|
||||
tty.set_debug(inner_debug)
|
||||
|
||||
# Redirect stdout and stderr to daemon pipe
|
||||
phase = getattr(self, phase_attr)
|
||||
|
||||
@ -6,6 +6,7 @@
|
||||
import argparse
|
||||
import os
|
||||
import filecmp
|
||||
import re
|
||||
from six.moves import builtins
|
||||
|
||||
import pytest
|
||||
@ -129,7 +130,7 @@ def test_package_output(tmpdir, capsys, install_mockery, mock_fetch):
|
||||
|
||||
# make sure that output from the actual package file appears in the
|
||||
# right place in the build log.
|
||||
assert "BEFORE INSTALL\n==> './configure'" in out
|
||||
assert re.search(r"BEFORE INSTALL\n==>( \[.+\])? './configure'", out)
|
||||
assert "'install'\nAFTER INSTALL" in out
|
||||
|
||||
|
||||
|
||||
Loading…
Reference in New Issue
Block a user