strace.lib #1

  • //
  • guest/
  • perforce_software/
  • sdp/
  • dev/
  • Server/
  • Unix/
  • p4/
  • common/
  • lib/
  • strace.lib
  • View
  • Commits
  • Open Download .zip Download (8 KB)
# shellcheck shell=bash
# shellcheck disable=SC2154  # All-caps globals (StracePidFile, StraceEnabledFile, etc.)
#                            # are set by callers before sourcing this library.
#==============================================================================
# Copyright and license info is available in the LICENSE file included with
# the Server Deployment Package (SDP), and also available online:
# https://swarm.workshop.perforce.com/projects/perforce-software-sdp/view/main/LICENSE
#------------------------------------------------------------------------------

#==============================================================================
# Library: strace.lib
#
# Shared functions for diagnostic strace support in SDP service init scripts
# (p4d_base, p4broker_base, p4p_base).
#
# Usage:
#   Source this file after p4_vars has been loaded (so $P4CLIB is defined):
#
#     source "$P4CLIB/strace.lib"
#
#   Before calling these functions, set the following globals:
#
#     StraceEnabledFile  - marker file path, e.g. $LOGS/.strace.p4d_1
#     StracePidFile      - strace PID file path, e.g. $LOGS/.strace.p4d_1.pid
#     StraceLog          - strace output log base path, e.g. $LOGS/strace.p4d_1.log
#                          A timestamp is appended at attachment time, e.g.:
#                          $LOGS/strace.p4d_1.20260627_123456.log
#     Log                - init log file path for appending status messages
#     ServiceName        - service name used in log messages, e.g. p4d_1
#
# Two strace modes are supported:
#
#   Wrap mode   (systemd only): run_service_under_strace
#     strace runs the service binary as its child process, capturing syscalls
#     from the very first instruction. Used when the service runs in the
#     foreground (systemd). In this mode strace cannot be stopped independently
#     from the service.
#
#   Attach mode (non-systemd): attach_strace_if_requested
#     strace attaches to the already-running service after it daemonizes. Easy
#     to stop independently (kill $(cat $StracePidFile)), but early startup
#     syscalls (before the PID is known) will be missed.
#
# Callers are responsible for selecting the appropriate mode based on
# $UseSystemd. See doc/Using_strace_for_SDP_Services.md for full details.
#==============================================================================

#------------------------------------------------------------------------------
# Function: run_service_under_strace "$binary" [args...]
#
# Runs the given command under strace in "wrap" mode. strace is interposed
# between the init script and the service binary, so every syscall is captured
# from the very first instruction — nothing is missed.
#
# This is the correct mode when the service runs in the foreground (systemd),
# because the init script already blocks on the service binary; replacing it
# with "strace ... binary" has zero additional complexity.
#
# In non-systemd (daemon) mode the service forks immediately and strace -f
# would block the init script indefinitely; use attach_strace_if_requested
# instead.
#
# Output file:
#   $StraceLog with a timestamp appended, e.g. strace.p4d_1.20260627_123456.log
#   The exact path is recorded in $Log.
#
# NOTE: In wrap mode strace is the parent process of the service. The only
# way to stop strace is to stop the service normally (e.g. systemctl stop).
#------------------------------------------------------------------------------
function run_service_under_strace {
   if ! command -v strace > /dev/null 2>&1; then
      echo "Warning: $StraceEnabledFile exists but 'strace' was not found in PATH; starting $ServiceName without strace." | tee -a "$Log"
      "$@"
      return
   fi

   local strace_custom_flags
   strace_custom_flags=$(tr -d '\n\r' < "$StraceEnabledFile" | xargs 2>/dev/null)
   local strace_flags="${strace_custom_flags:--f -tt}"

   local ts
   ts=$(date +%Y%m%d_%H%M%S)
   local effective_log="${StraceLog%.log}.${ts}.log"

   echo "Starting $ServiceName under strace (wrap mode, flags: $strace_flags); output: $effective_log" | tee -a "$Log"
   echo "Note: strace is the parent process in wrap mode; stop strace by stopping the service normally." | tee -a "$Log"

   # shellcheck disable=SC2086
   strace $strace_flags -o "$effective_log" "$@"
}

#------------------------------------------------------------------------------
# Function: attach_strace_if_requested <pid_cmd>
#
# If $StraceEnabledFile exists, attaches strace to the already-running service
# process and writes the strace PID to $StracePidFile. Intended for
# non-systemd (daemon) mode where the service forks into the background and
# the init script cannot block waiting for strace.
#
# Because strace attaches after the service has started, early startup syscalls
# (from process start until the PID is discoverable) will be missed. For
# complete coverage use run_service_under_strace (systemd only).
#
# Arguments:
#   $1 - Shell command string whose stdout is the service PID. Retried
#        up to 5 seconds while waiting for the process to appear.
#        Examples:
#          "cat \"$P4ROOT/server.pid\""        # p4d
#          "get_pids \"$P4PBIN\""              # p4p
#          "get_pids \"$P4BROKERCFG\""         # p4broker
#
# Strace flags:
#   Default flags are '-f -tt'. To override, place custom flags on a single
#   line in $StraceEnabledFile before starting the service.
#
# Output file:
#   $StraceLog with a timestamp appended, e.g. strace.p4d_1.20260627_123456.log
#
# NOTE: strace -f on a busy server generates large output and adds measurable
# overhead. This feature is intended for diagnostic use only.
#------------------------------------------------------------------------------
function attach_strace_if_requested {
   local pid_cmd="${1:?Usage: attach_strace_if_requested <pid_cmd>}"

   [[ -e "$StraceEnabledFile" ]] || return 0

   if ! command -v strace > /dev/null 2>&1; then
      echo "Warning: $StraceEnabledFile exists but 'strace' was not found in PATH; skipping strace." | tee -a "$Log"
      return 0
   fi

   # Use flags from the marker file if non-empty, otherwise apply defaults.
   local strace_custom_flags
   strace_custom_flags=$(tr -d '\n\r' < "$StraceEnabledFile" | xargs 2>/dev/null)
   local strace_flags="${strace_custom_flags:--f -tt}"

   # Wait up to 5 seconds for the service process to appear.
   local service_pid=
   local _i
   for _i in 1 2 3 4 5; do
      # shellcheck disable=SC2086
      service_pid=$(eval $pid_cmd 2>/dev/null | awk '{print $1}')
      [[ -n "$service_pid" ]] && break
      sleep 1
   done

   if [[ -z "$service_pid" ]]; then
      echo "Warning: $StraceEnabledFile exists but could not find a running $ServiceName process; skipping strace." | tee -a "$Log"
      return 0
   fi

   local ts
   ts=$(date +%Y%m%d_%H%M%S)
   local effective_log="${StraceLog%.log}.${ts}.log"

   echo "Attaching strace (flags: $strace_flags) to $ServiceName pid $service_pid; output: $effective_log" | tee -a "$Log"
   # shellcheck disable=SC2086
   nohup strace $strace_flags -o "$effective_log" -p "$service_pid" > /dev/null 2>&1 &
   local strace_pid=$!
   echo "$strace_pid" > "$StracePidFile"
   echo "strace running as pid $strace_pid. PID file: $StracePidFile" | tee -a "$Log"
   echo "To stop strace without affecting $ServiceName: kill \$(cat $StracePidFile)" | tee -a "$Log"
}

#------------------------------------------------------------------------------
# Function: stop_strace_if_running
#
# Stops the background strace process recorded in $StracePidFile (if any)
# and removes the PID file. Used after a service stops in attach mode.
# Safe to call even if strace has already exited (strace exits automatically
# when its target process dies).
#
# Not applicable in wrap mode (strace exits with the service automatically).
#------------------------------------------------------------------------------
function stop_strace_if_running {
   [[ -r "$StracePidFile" ]] || return 0

   local strace_pid
   strace_pid=$(cat "$StracePidFile")

   if kill -0 "$strace_pid" > /dev/null 2>&1; then
      echo "Stopping strace (pid $strace_pid) for $ServiceName." | tee -a "$Log"
      kill "$strace_pid" 2>&1 | tee -a "$Log"
   else
      echo "strace (pid $strace_pid) for $ServiceName is no longer running." | tee -a "$Log"
   fi

   rm -f "$StracePidFile"
   echo "Removed $StracePidFile." | tee -a "$Log"
}

# Change User Description Committed
#1 32904 C. Thomas Tyler strace support for p4d, p4broker, and p4p SDP init scripts

Added diagnostic strace feature to p4d_base, p4broker_base, and p4p_base.
When a file $LOGS/.strace.<ServiceName> exists at start time, strace is
enabled using one of two modes selected automatically:

  - Wrap mode (systemd): strace runs the service binary as its child
    process, capturing every syscall from the very first instruction.
    Ideal for diagnosing startup-phase issues (e.g. replica startup threads).

  - Attach mode (non-systemd): strace attaches to the already-running
    service after startup using strace -p <pid>. Best effort -- early
    startup syscalls may be missed.

Strace output goes to $LOGS/strace.<ServiceName>.<YYYYMMDD_HHMMSS>.log;
in attach mode the strace PID is also recorded in
$LOGS/.strace.<ServiceName>.pid.

Shared functions live in a new library: /p4/common/lib/strace.lib

Also added startup/shutdown logging to p4broker_base and p4p_base, which
previously had no init logging.

Added documentation: doc/Using_strace_for_SDP_Services.md

Fixes SDP-1365 (Feature): Add strace support to p4*_base init scripts, with docs.
#review-32858 @tom_tyler @robert_cowham