tamed --report and runner status line (TAMED_TUI)

This is something that I've wanted to do for quite some time, but for good
reason, have been avoiding.

`tamed --report` is fairly basic right now, but allows you to see what each
of the runners are doing.  This will be expanded further to gather data for
further analysis.

The thing that I was avoiding was a status line during the build to
summarize what the runners are doing, since it's nearly impossible to do so
from the build output with multiple runners.  This will not only allow me to
debug more easily, but will keep the output plainly visible to developers at
all times in the hope that it can help them improve the build times
themselves in certain cases.

It is currently gated behind TAMED_TUI, since, while it works well overall,
it is imperfect, and will cause artifacts from build output partly
overwriting the status line, and may even occasionally clobber the PS1 by
erasing the line.  This will be improved upon in the future; something is
better than nothing.
main
Mike Gerwitz 2022-01-19 11:43:10 -05:00
parent 4c5b860195
commit 756dcd7894
5 changed files with 303 additions and 14 deletions

View File

@ -21,6 +21,7 @@ Rust 1.53 is now required.
Compiler
--------
- Input mappings will no longer emit the destination param as a dependency.
- `tamed --report` and `TAMED_TUI` for analyzing build performance.
Documentation
-------------

View File

@ -81,6 +81,15 @@ command-runner()
# (rather than continuing in background after we die)
trap 'kill -TERM $pid &>/dev/null' INT TERM
# log the provided command line and starting time so that we can determine
# what is currently being compiled and how long it is taking
date +%s > "$base/cmdstart"
echo "$*" > "$base/cmdline"
# notify tamed that it should update any diagnostic display
#local -ri tamed_pid=$( < "$root/pid" )
#kill -USR2 "$tamed_pid"
# all remaining arguments are passed to the runner
echo "$*" > "$base/0"
@ -229,6 +238,10 @@ mark-available()
{
local -r base=${1?Missing runner base path}
echo 0 > "$base/busy"
echo idle > "$base/cmdline"
# this can be used to determine how long the worker has been idle
date +%s > "$base/cmdstart"
}
@ -380,6 +393,9 @@ kill-tamed()
# output rather than wasting cycles doing this filtering.
saneout()
{
# the final line clears the entire line before outputting in an attempt to
# better accommodate the runner status line from tamed; this can be
# removed once the Makefile properly takes up this task.
awk '
/^~~~~\[begin /,/^~~~~\[end / { next }
/^rm / { next }
@ -397,7 +413,7 @@ saneout()
/internal:/ { printf "\033[0;35m"; out=1; }
/internal error:/ { printf "\033[1m"; out=1; }
/^[^[]/ || out { print; printf "\033[0;0m"; out=0; }
'
' | awk '{printf "\x1b[2K\r%s", $0}'
}

290
bin/tamed
View File

@ -23,6 +23,7 @@ declare mypath; mypath=$( dirname "$( readlink -f "$0" )" )
readonly mypath
declare -ri EX_RUNNING=1
declare -ri EX_NOTRUNNING=2 # tamed is not running
declare -ri EX_USAGE=64 # incorrect usage; sysexits.h
declare -ri EX_CANTCREAT=73 # cannot create file; sysexits.h
@ -37,9 +38,13 @@ declare -ri TAMED_SPAWNER_PID="${TAMED_SPAWNER_PID:-$PPID}"
declare -r TAMED_JAVA_OPTS="${TAMED_JAVA_OPTS:-}"
export JAVA_OPTS="$TAMED_JAVA_OPTS"
# set by `main', global for `cleanup'
# set by `main', global for `cleanup' and `runner-report-all'
declare root=
# non-empty if in TUI (terminal UI) mode (use `in-tui-mode')
declare -r TAMED_TUI="${TAMED_TUI:-}"
declare tui_mode=
# Create FIFOs for runner
#
@ -59,7 +64,7 @@ mkfifos()
rm -f "$root-$n"
mkfifo -m 0600 "$root/$n" || {
echo "fatal: failed to create FIFO at $root/n"
log "fatal: failed to create FIFO at $root/n" >&2
exit $EX_CANTCREAT
}
done
@ -69,6 +74,17 @@ mkfifos()
}
# Output a line, clearing the remainder of the line if in TUI mode
log()
{
if in-tui-mode; then
echo -en "\e[2K"
fi
echo "$@"
}
# Spawn a new runner using the next available runner id
#
# See `spawn-runner' for more information.
@ -120,7 +136,7 @@ spawn-runner()
# we assume that this is the new largest runner id
echo "$id" > "$root/maxid"
echo "runner $id ($!): $base"
log "runner $id ($!): $base"
}
@ -193,12 +209,34 @@ abort-if-running()
test "$pid" -gt 0 || return 0
! ps "$pid" &>/dev/null || {
echo "fatal: tamed is already running at $root (pid $pid)!"
log "fatal: tamed is already running at $root (pid $pid)!" >&2
exit $EX_RUNNING
}
test -z "$pid" || {
echo "warning: clearing stale tamed (pid $pid)"
log "warning: clearing stale tamed (pid $pid)" >&2
}
}
# Exit with EX_NOTRUNNING if tamed is not running at path ROOT
#
# ROOT must both exist and contain a `pid` file of a running process.
abort-if-not-running()
{
local -r root="${1?Missing root rundir}"
test -d "$root" || {
log "tamed is not running at $root: path does not exist" >&2
exit $EX_NOTRUNNING
}
local -ri pid=$( cat "$root/pid" 2>/dev/null )
# this should not happen unless bash crashed
ps "$pid" &>/dev/null || {
log "tamed is not running at $root: process $pid has terminated" >&2
exit $EX_NOTRUNNING
}
}
@ -214,15 +252,152 @@ kill-running()
{
local -r root="${1?Missing root}"
abort-if-not-running "$root" 2>/dev/null
local -r pid=$( cat "$root"/pid 2>/dev/null )
test -n "$pid" || return 0
echo "killing tamed at $root ($pid)..."
log "killing tamed at $root ($pid)..."
kill "$pid"
}
runner-report-all()
{
local -r root="${1?Missing root}"
abort-if-not-running "$root"
for-each-runner "$root" runner-report
}
for-each-runner()
{
local -r root="${1?Missing root}"
local -r cmd="${2?Missing command}"
shift 2
local -ri maxid=$(cat "$root/maxid")
echo "tamed is running at $root with $((maxid+1)) runner(s)"
for runner in $(seq 0 "$maxid"); do
echo
"$cmd" "$root" "$@" "$runner"
done
}
# Report on the status and current operation of each runner
#
# This report is generated by tamed rather than delegating to the runners
# themselves to avoid the complexity of mitigating output races.
runner-report()
{
local -r root="${1?Missing root}"
local -ri id="${2?Missing runner id}"
local -r path="$root/$id"
test -f "$path/cmdline" || return 0
local cmdline=$(< "$path/cmdline" )
local cmdstart=$(< "$path/cmdstart" )
local -i now=$(date +%s)
cat <<EOF
runner: $id
command: $cmdline
start: $cmdstart ($(date +%Y-%m-%dT%H:%M:%S <<< "$cmdstart"))
elapsed: $((now - cmdstart)) seconds
EOF
}
elide-paths()
{
local -r cols="${1?Missing columns}"
local -r buffer="${2?Missing buffer}"
# first, keep the first letter and last three of each dir, if doing so
# would remove three or more characters; for example:
# "suppliers/foobarbaz/quux/quuux.xmlo" => "s…ers/f…baz/quux/quuux.xmlo"
result=$(
echo "$buffer" \
| sed 's|\([a-zA-Z0-9_-]\)[a-zA-Z0-9_-]\{3,\}\([a-zA-Z9-9_-]\{3\}\)/|\1…\2/|g'
)
[ "${#result}" -gt $cols ] || {
echo -n "$result"
return
}
# more aggressive: remove all but the first letter if it would save at
# least three characters, as in:
# "suppliers/foobarbaz/quux/quuux.xmlo" => "s…/f…/quux/quuux.xmlo"
result=$(
echo "$buffer" | sed 's|\([a-zA-Z0-9_-]\)[^ /]\{3,\}/|\1…/|g'
)
[ "${#result}" -gt $cols ] || {
echo -n "$result"
return
}
# even more aggressive: elide all but the filename, as in:
# "suppliers/foobarbaz/quux/quuux.xmlo" => "…/quuux.xmlo"
result=$(
echo "$buffer" | sed 's|[a-zA-Z0-9_-/]*/|…/|g'
)
[ "${#result}" -gt $cols ] || {
echo -n "$result"
return
}
# at this point, it's better to provide _some_ useful information for
# _some_ runners, so just truncate the previous result (we probably have
# too many runners for the current terminal width)
echo -n "${result::$((cols-1))}…"
}
# Report of all runners' status on a single line
#
# Idle runners are not output for now, since that increases the likelihood
# that we will not output something when runners are done doing their jobs
# (including overwriting the PS1).
runner-report-line() {
local -r root="${1?Missing root}"
# buffer output so that our report does not get mixed with normal
# runner output
local buffer=$( runner-report-all "$root" | awk '
/^command: idle/,/^$/ { next } # skip idle
/^command:/ { printf "[%s ", $NF } # e.g. "[foo/bar.xmlo "
/^elapsed:/ { printf "%ds] ", $2 } # e.g. "2s] "
' )
# ensure proper empty output without formatting if there is no line
test -n "$buffer" || return 0
# bash has checkwinsize, but that runs after every command; try to use
# tput, defaulting to 80. Note that we have to check this every time, in
# case the terminal has been resized.
local -ri cols=$(tput cols || echo 80)
# rather than worrying about line wrapping, fit to one line
if [[ "${#buffer}" -gt $cols ]]; then
buffer=$(elide-paths $cols "$buffer")
fi
# output in bold, overwrite our line that may already be present here, and
# place cursor at beginning of the line so any runner output will
# overwrite
echo -en "\e[1m$buffer\e[0m\r"
}
# Clean up child processes before exit
#
# This should be called before exit (perhaps by a trap). Kills
@ -261,27 +436,110 @@ Options:
Environment Variables:
TAMED_STALL_SECONDS number of seconds of runner inactivity before
runner is automatically killed (default 1)
runner is automatically killed (default 1)
TAMED_SPAWNER_PID inhibit stalling while this process is running
(default PPID)
(default PPID)
TAMED_JAVA_OPTS opts to pass to dslc, and in turn, the JVM
TAMED_TUI run in TUI mode (provide UI features like a
dynamic runner status line)
EOF
exit $EX_USAGE
}
# Determine whether to enable TUI mode
#
# TUI (terminal UI) mode will augment the output with features that only
# make sense when running on a user's terminal, such as the runner status
# line.
tui-check()
{
test "$TAMED_TUI" == 1 || return 0
tui_mode=1
log "tamed is running in TUI mode (TAMED_TUI=0 to disable)"
}
# Whether we're running in TUI mode
in-tui-mode()
{
test -n "$tui_mode"
}
# If in TUI mode, continuously update the last line of output with runner
# status
#
# This is not an easy undertaking with how our build process currently
# works. Make is responsible, currently, for echoing lines, and so we must
# frequently re-echo our status line in an attempt to redisplay the line
# after it is overwritten.
#
# Further, most output is unaware that the entire line needs to be
# overwritten; if output is not properly transformed in the Makefile, then
# portions of the status line may remain in the history, partly overwritten
# by build output.
#
# Another concern is that we do not want to keep outputting after the
# process is finished, which would overwrite the PS1. To try to avoid this,
# we omit idle runner output and only clear the line _once_ when the status
# line is empty, in the hope that all runners will be idle for long enough
# before the build completes, make exists, exits, and the PS1 is output.
#
# If not in TUI mode, this does nothing.
tui-runner-status-line()
{
in-tui-mode || return 0
local cache= cleared=
while ! spawner-dead; do
# this will fail if no runners have been created yet, so just ignore
# it; if we fail to output the status line, the build will still work
cache=$(runner-report-line "$root" 2>/dev/null)
# if the line is empty, clear the output _once_ (to get rid of
# whatever was there before), but do not do it again, otherwise we
# risk overwriting lines post-build (like the PS1 or late-stage make
# targets).
if [ -z "$cache" -a -z "$cleared" ]; then
log -n ""
cleared=1
sleep 1
continue
fi
cleared=
# output the cache frequently to try to overcome build output
for i in {0..9}; do
log -n "$cache"
sleep 0.1
done
done
}
# Run tamed
main()
{
local kill=
local kill= report=
case "${1:-}" in
--kill) kill=1; shift;;
--report) report=1; shift;;
--help) usage;;
esac
root="${1:-/run/user/$UID/tamed}"
# report requested
test -z "$report" || {
runner-report-all "$root"
exit
}
# kill if requested
test -z "$kill" || {
kill-running "$root"
@ -289,6 +547,7 @@ main()
}
abort-if-running "$root"
tui-check
# clean up background processes before we exit
trap exit TERM
@ -296,20 +555,27 @@ main()
# start fresh
rm -rf "$root"; mkdir -p "$root"
echo $$ > "$root/pid"
local -i pid=$$
echo $pid > "$root/pid"
# start with a single runner; we'll spawn more if requested
spawn-runner 0 "$root"
trap "spawn-next-runner '$root'" USR1
# runner report on SIGUSR2
trap "runner-report-line '$root'" USR2
# status line reporting on runners for TUI mode
tui-runner-status-line &
# wait for runners to complete or for a signal to be received by this
# process that terminates `wait'
while true; do
wait -n || {
status=$?
# ignore USR1
if [ $status -ne 138 ]; then
# ignore USR{1,2}
if [ $status -ne 138 -a $status -ne 140 ]; then
exit $status
fi
}

View File

@ -114,13 +114,16 @@ SHELL = /bin/bash -O extglob -O nullglob
export TAME_CMD_WAITTIME
export TAMED_STALL_SECONDS
export TAMED_JAVA_OPTS
export TAMED_TUI
TAMED_SPAWNER_PID=$(shell echo $$PPID)
export TAMED_SPAWNER_PID
# Optional timestamping for TAME commands
TS = 0
TS_FMT=%s
tame__ts_0 = :
tamed_clear__1 = @printf '\e[2K' # clear line
tame__ts_0 = $(tamed_clear__$(TAMED_TUI)) # clear line if TUI
tame__ts_1 = @printf '[%($(TS_FMT))T] '
TAME_TS = $(tame__ts_$(TS))

View File

@ -37,6 +37,9 @@ AC_ARG_VAR([TAME], [The TAME compiler])
AC_ARG_VAR([RATER_CLASSPATH], [DSL Compiler Saxon class path])
AC_ARG_VAR([PROGUI_TEST_PATH], [Path to JavaScript tests for Program UI])
# This can also be set via the environment or during a make invocation
AC_ARG_VAR([TAMED_TUI], [Enable TUI (text UI) mode for tamed])
# Auto-discover Java and Ant paths
AC_CHECK_PROGS(JAVA, [java])
AC_CHECK_PROGS(ANT, [ant])