Observe D GC runs on a system

gcsnoop

#!/usr/bin/env bash
set -euo pipefail

#
# gcsnoop - trace D garbage collection runs via tgkill() syscalls.
#             Written using Linux ftrace.
#             Adapted from killsnoop.
#
# This traces tgkill() syscalls, used by the D runtime to suspend and resume threads
# for garbage collector runs.
#
# This implementation is designed to work on older kernel versions, and without
# kernel debuginfo. It works by tracking each SIGUSR1 kill and associating it with
# a succeeding SIGUSR2 kill on the same process.
# This approach is kernel version specific, and may not work on your version.
# It is a workaround, and proof of concept for ftrace, until more kernel tracing
# functionality is available.
#
# USAGE: ./gcsnoop [-ht] [-p pid] [-n name]
#
# Run "gcsnoop -h" for full usage.
#
# REQUIREMENTS: FTRACE and KPROBE CONFIG, syscalls:sys_enter_tgkill and
# syscalls:sys_exit_tgkill kernel tracepoints (you may already have these
# on recent kernels).
#
# Adapted from killsnoop in perf-tools: https://github.com/brendangregg/perf-tools
#
# COPYRIGHT: Copyright (c) 2014 Brendan Gregg.
# COPYRIGHT: Copyright (c) 2014 Martin Probst.
# COPYRIGHT: Copyright (c) 2021 Mathis Beer.
#
#  This program is free software; you can redistribute it and/or
#  modify it under the terms of the GNU General Public License
#  as published by the Free Software Foundation; either version 2
#  of the License, or (at your option) any later version.
#
#  This program is distributed in the hope that it will be useful,
#  but WITHOUT ANY WARRANTY; without even the implied warranty of
#  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
#  GNU General Public License for more details.
#
#  You should have received a copy of the GNU General Public License
#  along with this program; if not, write to the Free Software Foundation,
#  Inc., 59 Temple Place - Suite 330, Boston, MA  02111-1307, USA.
#
#  (http://www.gnu.org/copyleft/gpl.html)
#
# 20-Jul-2014   Brendan Gregg   Templated this.
# 13-Sep-2014   Martin Probst   Created this.
# 23-Jul-2021   Mathis Beer     Adjusted to track D GC runs specifically.

### default variables
tracing=/sys/kernel/debug/tracing
flock=/var/tmp/.ftrace-lock; wroteflock=0
opt_name=0; name=; opt_pid=0; pid=; ftext=
opt_time=0; opt_file=0; file=
kevent_entry=events/syscalls/sys_enter_tgkill
kevent_return=events/syscalls/sys_exit_tgkill

function usage {
    cat <<-END >&2
USAGE: gcsnoop [-ht] [-p PID] [-n name]
                 -n name         # process name to match
                 -p PID          # PID to match on kill issue
                 -t              # include time (seconds)
                 -h              # this usage message
  eg,
       gcsnoop                   # trace D GC runs on the whole system
       gcsnoop -p \$(pgrep dprogram) # trace GC runs in dprogram
END
    exit
}

function warn {
    if ! eval "$@"; then
        echo >&2 "WARNING: command failed \"$@\""
    fi
}

function end {
    # disable tracing
    echo 2>/dev/null
    echo "Ending tracing..." 2>/dev/null
    cd $tracing
    warn "echo 0 > $kevent_entry/enable"
    warn "echo 0 > $kevent_return/enable"
    warn "echo > trace"
    (( wroteflock )) && warn "rm $flock"
}

trap 'end' INT QUIT TERM PIPE HUP # sends execution to end tracing section

function die {
    echo >&2 "$@"
    exit 1
}

function edie {
    # die with a quiet end()
    echo >&2 "$@"
    exec >/dev/null 2>&1
    end
    exit 1
}

### process options
while getopts n:p:t opt
do
    case $opt in
    n)  opt_name=1; name=$OPTARG ;;
    p)  opt_pid=1; pid=$OPTARG ;;
    t)  opt_time=1 ;;
    h|?)    usage ;;
    esac
done
shift $(( $OPTIND - 1 ))
(( $# )) && usage

### option logic
(( opt_pid && opt_name )) && die "ERROR: use either -p or -n."
(( opt_pid )) && ftext=" issued to PID $pid"
(( opt_name )) && ftext=" issued by process name \"$name\""
echo "Tracing GC runs$ftext. Ctrl-C to end."

### check permissions
cd $tracing || die "ERROR: accessing tracing. Root user? Kernel has FTRACE?
    debugfs mounted? (mount -t debugfs debugfs /sys/kernel/debug)"

### ftrace lock
[[ -e $flock ]] && die "ERROR: ftrace may be in use by PID $(cat $flock) $flock"
echo $$ > $flock || die "ERROR: unable to write $flock."
wroteflock=1

### setup and begin tracing
echo nop > current_tracer
if ! echo 1 > $kevent_entry/enable; then
    edie "ERROR: enabling tgkill() entry tracepoint Exiting."
fi
if ! echo 1 > $kevent_return/enable; then
    edie "ERROR: enabling tgkill() return tracepoint. Exiting."
fi
(( opt_time )) && printf "%-16s " "TIMEs"
printf "%-16.16s %-10s %-10s %4s\n" "COMM" "PID" "TGID" "LENGTH"

declare -A gcrunstart

### print trace buffer
warn "echo > trace"
sed -un 's@^\s*\([^\[]\+[^ ]\+\)\s*\[[0-9]\+\] \.\.\.\. \([0-9\.]\+\): '\
'sys_tgkill(tgid: \([0-9a-f]*\), pid: \([0-9a-f]*\), sig: \([0-9a-f]*\))$@\1 \2 \3 \4 \5@p' trace_pipe |\
while read command time tgid pid sig; do
  if [ "$sig" = "a" ]; then
    gcrunstart[$command]=$time
  elif [ "$sig" = "c" ]; then
    start=${gcrunstart[$command]-}
    unset gcrunstart[$command]
    end="$time"
    if [ "$start" != "" ]; then
      dur=$(bc <<< "$end - $start")
      (( opt_time )) && printf "%-16s " "$time"
      printf "%-16.16s %-10d %-10d %4s\n" "$command" "0x$pid" "0x$tgid" "$dur"
    fi
  fi
done

### end tracing
end