Skip to content

Instantly share code, notes, and snippets.

@jstine35
Last active September 25, 2024 07:47
Show Gist options
  • Save jstine35/e0fc0e06ec06d74bc3ebd67585bf2a1d to your computer and use it in GitHub Desktop.
Save jstine35/e0fc0e06ec06d74bc3ebd67585bf2a1d to your computer and use it in GitHub Desktop.
# FIRST VERSION - Outputs UTS formatted timestamp.
# -------------------------------------------------------------------------------------
# handy pipe redirect that appends a datestamp to every line of output. Just paste this into
# the top of a typical BASH script. Note that it outputs localtime due to limitations in
# BASH printf (whichis used for speed reasons). Automated runner processes as a rule of thumb
# should be set to UTC anyways, so it seems not a significant limitation.
s_datestamp() {
while IFS= read -r line; do
# by nature BASH might run process subst twice when using >&2 pipes. This is a lazy
# way to avoid dumping two timestamps on the same line:
if [[ "$line" =~ \[[0-9]{4}-[^[:space:]]*\] ]]; then
echo "$line"
else
printf "%(%Y-%m-%dT%H:%M:%S%z)T" "-1"
fi
done
}
exec 1> >(s_datestamp)
exec 2> >(s_datestamp)
# -------------------------------------------------------------------------------------
# SECOND VERSION - Outputs time since the script started.
# -------------------------------------------------------------------------------------
# handy pipe redirect that appends a datestamp to every line of output. Just paste this into
# the top of a typical BASH script.
procstarttime=$(date -u '+%s')
s_timestamp() {
while IFS= read -r line; do
curtime=$(date -u '+%s')
deltatime=$(( curtime - procstarttime ))
timestamp="$(printf "%03d:%02d" $(( deltatime / 60 )) $(( deltatime % 60 )))"
# by nature BASH might run process subst twice when using >&2 pipes. This is a lazy
# way to avoid dumping two timestamps on the same line:
if [[ "$line" != \[${timestamp%% *}* ]]; then
echo "[$timestamp] $line"
else
echo "$line"
fi
done
}
exec 1> >(s_timestamp)
exec 2> >(s_timestamp)
# -------------------------------------------------------------------------------------
@gergelybosze
Copy link

gergelybosze commented Jul 27, 2022

Hi, for line 9, the timestamp has a shorter option for iso with seconds:
date -Is

@kylefuhrmanncalm
Copy link

Also recommend using while IFS= read -r line so that prepended whitespace isn't removed.

@jstine35
Copy link
Author

Also recommend using while IFS= read -r line so that prepended whitespace isn't removed.

Highly belated, but I've updated the gist accordingly. I switched up to use bash builtin printf as well, which I found to be some magnitude faster than date though it means being unable to normalize to UTC timezone. Though for the purpose of a runner that shouldn't matter since runners should be set to UTC time anyway (and can be easily changed to UTC time via a variable export).

@spidey
Copy link

spidey commented Aug 28, 2024

I'm experiencing an issue in which a failing process is not printing the last error message because of this trick. I'm guessing that the shell is configured with set -o pipefail and set -o errexit by GitLab CI and the failure doesn't allow s_timestamp to run and echo the timestamp prefixed line.
Any possible workarounds to allow the log to still go through?

@jstine35
Copy link
Author

jstine35 commented Sep 25, 2024

I'm experiencing an issue in which a failing process is not printing the last error message because of this trick. I'm guessing that the shell is configured with set -o pipefail and set -o errexit by GitLab CI and the failure doesn't allow s_timestamp to run and echo the timestamp prefixed line. Any possible workarounds to allow the log to still go through?

That could be the case if the parent shell is also configuring set -E (capital E), which enables inheritance of pipefail. Without -E though the pipefail and errexit settings shouldn't be inherited by other scripts being run. However, you can add some code to the s_datestamp function to be sure:

s_datestamp() {
    local -      # saves parent's settings, restores them when function returns
    set +o pipefail +o errexit
    trap - ERR    # may need to clear other traps here...
    
    [... rest of function as above ...]
}

The other (and more likely) possibility is that something is killing the entire process tree when the parent process exits. Whether or not that's the case, and how to work around it, would depend a bit on whether your runners are Windows or Linux based.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment