Using_strace_for_SDP_Services.md #1

  • //
  • guest/
  • perforce_software/
  • sdp/
  • dev/
  • doc/
  • Using_strace_for_SDP_Services.md
  • Markdown
  • View
  • Commits
  • Open Download .zip Download (8 KB)

Using strace with SDP-Managed Services

Overview

The SDP init scripts p4d_base, p4broker_base, and p4p_base include built-in support for running a service under strace at startup. This provides a repeatable, low-friction way to capture syscall traces for diagnostic purposes without modifying any init script or configuration file.

Note: strace -f on a busy server generates large output volumes and adds measurable overhead. This feature is intended for short-term diagnostic use only — not for permanent production deployment.


Two strace Modes

The init scripts automatically select one of two modes based on whether the service is managed by systemd or started directly (non-systemd).

Wrap Mode (systemd — complete capture)

When a service is managed by systemd, strace is interposed between the init script and the service binary:

systemd → p4d_N_init → strace ... p4d $P4D_FLAGS

strace runs the service binary as its own child process. Every syscall is captured from the very first instruction — nothing from startup is missed. This is ideal for diagnosing issues that occur during early startup (e.g. replication thread initialization on a replica).

Trade-off: Because strace is the parent process, the service cannot be stopped independently from strace. Stop the service normally (systemctl stop p4d_N) to terminate both.

Attach Mode (non-systemd — best effort)

When a service is started directly (without systemd), the init script starts the service normally and then attaches strace using strace -p <pid> once the service process ID is known.

Trade-off: Syscalls that occur between process start and the moment the PID is discovered (typically a second or less) are not captured. For services where startup-phase syscalls are important, use systemd wrap mode.

strace runs as a completely independent background process. It can be stopped at any time without affecting the running service.


File Naming Convention

All strace-related files live in $LOGS and incorporate the service name (e.g. p4d_1, p4broker_1, p4p_1) so that multiple instances on the same host never collide.

The strace output log also includes a timestamp (generated at the moment strace starts) so successive runs do not overwrite each other.

File Purpose
$LOGS/.strace.<ServiceName> Marker file — create this to enable strace
$LOGS/.strace.<ServiceName>.pid PID of the running strace process (attach mode only)
$LOGS/strace.<ServiceName>.<YYYYMMDD_HHMMSS>.log strace output

For p4d instance 1 on a host where $LOGS is /p4/1/logs:

/p4/1/logs/.strace.p4d_1                       ← marker file (you create this)
/p4/1/logs/.strace.p4d_1.pid                   ← strace PID (attach mode only)
/p4/1/logs/strace.p4d_1.20260627_143022.log    ← strace output

For a p4broker on the same instance:

/p4/1/logs/.strace.p4broker_1
/p4/1/logs/.strace.p4broker_1.pid
/p4/1/logs/strace.p4broker_1.20260627_143055.log

A p4broker started with a non-default config tag (e.g. mytag) uses p4broker_1_mytag as the service name.


Enabling strace — Step by Step

p4d (Helix Core Server)

With systemd (wrap mode — recommended for startup diagnosis):

# 1. Create the marker file (empty = use default flags: -f -tt)
touch /p4/N/logs/.strace.p4d_N

# 2. (Re)start the service
sudo systemctl restart p4d_N

# 3. Confirm strace is running (the service log will show the strace log path)
grep strace /p4/N/logs/p4d_init.log | tail -5

Without systemd (attach mode):

touch /p4/N/logs/.strace.p4d_N
/p4/N/bin/p4d_N_init start

# Confirm strace is running
cat /p4/N/logs/.strace.p4d_N.pid
ps -p $(cat /p4/N/logs/.strace.p4d_N.pid)

p4broker (Helix Broker)

touch /p4/N/logs/.strace.p4broker_N

sudo systemctl restart p4broker_N   # systemd (wrap mode)
# or
/p4/N/bin/p4broker_N_init start     # non-systemd (attach mode)

p4p (Helix Proxy)

touch /p4/N/logs/.strace.p4p_N

sudo systemctl restart p4p_N        # systemd (wrap mode)
# or
/p4/N/bin/p4p_N_init start          # non-systemd (attach mode)

Stopping strace Without Affecting the Service

Attach mode only. Because strace runs as a separate background process in attach mode, it can be killed independently at any time. The service continues running normally.

# Generic form:
kill $(cat /p4/N/logs/.strace.<ServiceName>.pid)

# Examples:
kill $(cat /p4/1/logs/.strace.p4d_1.pid)
kill $(cat /p4/1/logs/.strace.p4broker_1.pid)
kill $(cat /p4/1/logs/.strace.p4p_1.pid)

The init script also calls stop_strace_if_running automatically when the service is stopped via the init script, cleaning up the PID file.

Note: In attach mode, strace also exits automatically when its target process dies, so no explicit cleanup is needed if the service itself stops.

Wrap mode: strace is the parent process. The only way to stop it is to stop the service normally (e.g. systemctl stop p4d_N). Killing strace directly will also stop the service.


Preventing strace from Running on Next Restart

Remove the marker file before restarting the service:

rm /p4/N/logs/.strace.p4d_N
sudo systemctl restart p4d_N

Custom strace Flags

By default, strace is invoked with -f -tt (follow forks, include timestamps with microsecond resolution). To use different flags, write them to the marker file on a single line before starting the service:

# Trace only network-related syscalls:
echo '-f -e trace=network' > /p4/1/logs/.strace.p4d_1

# Trace file-related syscalls with string lengths up to 256 bytes:
echo '-f -s 256 -e trace=file' > /p4/1/logs/.strace.p4d_1

# Default (empty file):
touch /p4/1/logs/.strace.p4d_1

The flags in the marker file replace the defaults entirely, so include -f explicitly if you want fork-following.


Viewing the Output

The exact log file path (including the timestamp) is recorded in the service init log (p4d_init.log, p4broker_init.log, or p4p_init.log) at the moment strace starts.

# Find the strace log path for the most recent run:
grep 'strace' /p4/1/logs/p4d_init.log | grep 'output:'

# Follow the trace in real time (strace writes line-buffered with -tt):
tail -f /p4/1/logs/strace.p4d_1.20260627_143022.log

# Count syscalls by name:
sort /p4/1/logs/strace.p4d_1.20260627_143022.log | uniq -c | sort -rn | head -20

Implementation Notes

Shared Library

The shared library /p4/common/lib/strace.lib is sourced by all three init scripts. It provides three functions:

Function Purpose
run_service_under_strace <binary> [args...] Wrap mode: run service as strace child
attach_strace_if_requested <pid_cmd> Attach mode: attach strace to running service
stop_strace_if_running Stop background strace and remove PID file

Mode Selection

Mode is selected automatically based on $UseSystemd:

$UseSystemd == 1  →  wrap mode   (run_service_under_strace)
$UseSystemd == 0  →  attach mode (attach_strace_if_requested ... & disown)

UseSystemd is set to 1 when a systemd unit file for the service exists and is active (detected at script startup via systemctl).

ServiceName

The ServiceName variable (e.g. p4d_1) is derived from the service binary name (e.g. ${P4DBIN##*/}) and is set unconditionally before any systemd detection, so strace file naming works correctly on both systemd and non-systemd hosts.

Why Not Always Use Wrap Mode?

In non-systemd operation, the service binary forks immediately and daemonizes. Using strace binary args (wrap mode) in this case would cause strace to block indefinitely tracking the daemon, holding the init script open. The attach approach is better suited here: the init script exits normally, and strace attaches in a separate background process.

With systemd, the init script is already meant to block (the service runs in the foreground as ExecStart). Replacing binary args with strace ... binary args is a natural fit — no additional complexity is introduced, and systemd manages the strace process as the service.

# Using strace with SDP-Managed Services

## Overview

The SDP init scripts `p4d_base`, `p4broker_base`, and `p4p_base` include
built-in support for running a service under `strace` at startup. This
provides a repeatable, low-friction way to capture syscall traces for
diagnostic purposes without modifying any init script or configuration file.

> **Note:** `strace -f` on a busy server generates large output volumes and
> adds measurable overhead. This feature is intended for short-term diagnostic
> use only — not for permanent production deployment.

---

## Two strace Modes

The init scripts automatically select one of two modes based on whether the
service is managed by **systemd** or started **directly** (non-systemd).

### Wrap Mode (systemd — complete capture)

When a service is managed by systemd, `strace` is interposed between the init
script and the service binary:

```
systemd → p4d_N_init → strace ... p4d $P4D_FLAGS
```

`strace` runs the service binary as its own child process. Every syscall is
captured from the very first instruction — nothing from startup is missed.
This is ideal for diagnosing issues that occur during early startup (e.g.
replication thread initialization on a replica).

**Trade-off:** Because `strace` is the parent process, the service cannot be
stopped independently from `strace`. Stop the service normally
(`systemctl stop p4d_N`) to terminate both.

### Attach Mode (non-systemd — best effort)

When a service is started directly (without systemd), the init script starts
the service normally and then attaches `strace` using `strace -p <pid>` once
the service process ID is known.

**Trade-off:** Syscalls that occur between process start and the moment the
PID is discovered (typically a second or less) are **not captured**. For
services where startup-phase syscalls are important, use systemd wrap mode.

`strace` runs as a completely independent background process. It can be
stopped at any time without affecting the running service.

---

## File Naming Convention

All strace-related files live in `$LOGS` and incorporate the **service name**
(e.g. `p4d_1`, `p4broker_1`, `p4p_1`) so that multiple instances on the same
host never collide.

The strace output log also includes a **timestamp** (generated at the moment
strace starts) so successive runs do not overwrite each other.

| File | Purpose |
|------|---------|
| `$LOGS/.strace.<ServiceName>` | Marker file — create this to enable strace |
| `$LOGS/.strace.<ServiceName>.pid` | PID of the running strace process (attach mode only) |
| `$LOGS/strace.<ServiceName>.<YYYYMMDD_HHMMSS>.log` | strace output |

For p4d instance `1` on a host where `$LOGS` is `/p4/1/logs`:

```
/p4/1/logs/.strace.p4d_1                       ← marker file (you create this)
/p4/1/logs/.strace.p4d_1.pid                   ← strace PID (attach mode only)
/p4/1/logs/strace.p4d_1.20260627_143022.log    ← strace output
```

For a p4broker on the same instance:

```
/p4/1/logs/.strace.p4broker_1
/p4/1/logs/.strace.p4broker_1.pid
/p4/1/logs/strace.p4broker_1.20260627_143055.log
```

A p4broker started with a non-default config tag (e.g. `mytag`) uses
`p4broker_1_mytag` as the service name.

---

## Enabling strace — Step by Step

### p4d (Helix Core Server)

**With systemd (wrap mode — recommended for startup diagnosis):**

```bash
# 1. Create the marker file (empty = use default flags: -f -tt)
touch /p4/N/logs/.strace.p4d_N

# 2. (Re)start the service
sudo systemctl restart p4d_N

# 3. Confirm strace is running (the service log will show the strace log path)
grep strace /p4/N/logs/p4d_init.log | tail -5
```

**Without systemd (attach mode):**

```bash
touch /p4/N/logs/.strace.p4d_N
/p4/N/bin/p4d_N_init start

# Confirm strace is running
cat /p4/N/logs/.strace.p4d_N.pid
ps -p $(cat /p4/N/logs/.strace.p4d_N.pid)
```

### p4broker (Helix Broker)

```bash
touch /p4/N/logs/.strace.p4broker_N

sudo systemctl restart p4broker_N   # systemd (wrap mode)
# or
/p4/N/bin/p4broker_N_init start     # non-systemd (attach mode)
```

### p4p (Helix Proxy)

```bash
touch /p4/N/logs/.strace.p4p_N

sudo systemctl restart p4p_N        # systemd (wrap mode)
# or
/p4/N/bin/p4p_N_init start          # non-systemd (attach mode)
```

---

## Stopping strace Without Affecting the Service

**Attach mode only.** Because `strace` runs as a separate background process
in attach mode, it can be killed independently at any time. The service
continues running normally.

```bash
# Generic form:
kill $(cat /p4/N/logs/.strace.<ServiceName>.pid)

# Examples:
kill $(cat /p4/1/logs/.strace.p4d_1.pid)
kill $(cat /p4/1/logs/.strace.p4broker_1.pid)
kill $(cat /p4/1/logs/.strace.p4p_1.pid)
```

The init script also calls `stop_strace_if_running` automatically when the
service is stopped via the init script, cleaning up the PID file.

> **Note:** In attach mode, `strace` also exits automatically when its target
> process dies, so no explicit cleanup is needed if the service itself stops.

**Wrap mode:** `strace` is the parent process. The only way to stop it is to
stop the service normally (e.g. `systemctl stop p4d_N`). Killing strace
directly will also stop the service.

---

## Preventing strace from Running on Next Restart

Remove the marker file before restarting the service:

```bash
rm /p4/N/logs/.strace.p4d_N
sudo systemctl restart p4d_N
```

---

## Custom strace Flags

By default, strace is invoked with `-f -tt` (follow forks, include timestamps
with microsecond resolution). To use different flags, write them to the marker
file on a single line before starting the service:

```bash
# Trace only network-related syscalls:
echo '-f -e trace=network' > /p4/1/logs/.strace.p4d_1

# Trace file-related syscalls with string lengths up to 256 bytes:
echo '-f -s 256 -e trace=file' > /p4/1/logs/.strace.p4d_1

# Default (empty file):
touch /p4/1/logs/.strace.p4d_1
```

The flags in the marker file **replace** the defaults entirely, so include
`-f` explicitly if you want fork-following.

---

## Viewing the Output

The exact log file path (including the timestamp) is recorded in the service
init log (`p4d_init.log`, `p4broker_init.log`, or `p4p_init.log`) at the
moment strace starts.

```bash
# Find the strace log path for the most recent run:
grep 'strace' /p4/1/logs/p4d_init.log | grep 'output:'

# Follow the trace in real time (strace writes line-buffered with -tt):
tail -f /p4/1/logs/strace.p4d_1.20260627_143022.log

# Count syscalls by name:
sort /p4/1/logs/strace.p4d_1.20260627_143022.log | uniq -c | sort -rn | head -20
```

---

## Implementation Notes

### Shared Library

The shared library `/p4/common/lib/strace.lib` is sourced by all three init
scripts. It provides three functions:

| Function | Purpose |
|----------|---------|
| `run_service_under_strace <binary> [args...]` | Wrap mode: run service as strace child |
| `attach_strace_if_requested <pid_cmd>` | Attach mode: attach strace to running service |
| `stop_strace_if_running` | Stop background strace and remove PID file |

### Mode Selection

Mode is selected automatically based on `$UseSystemd`:

```
$UseSystemd == 1  →  wrap mode   (run_service_under_strace)
$UseSystemd == 0  →  attach mode (attach_strace_if_requested ... & disown)
```

`UseSystemd` is set to `1` when a systemd unit file for the service exists and
is active (detected at script startup via `systemctl`).

### ServiceName

The `ServiceName` variable (e.g. `p4d_1`) is derived from the service binary
name (e.g. `${P4DBIN##*/}`) and is set unconditionally before any systemd
detection, so strace file naming works correctly on both systemd and
non-systemd hosts.

### Why Not Always Use Wrap Mode?

In non-systemd operation, the service binary forks immediately and daemonizes.
Using `strace binary args` (wrap mode) in this case would cause strace to
block indefinitely tracking the daemon, holding the init script open. The
attach approach is better suited here: the init script exits normally, and
strace attaches in a separate background process.

With systemd, the init script is already meant to block (the service runs in
the foreground as `ExecStart`). Replacing `binary args` with
`strace ... binary args` is a natural fit — no additional complexity is
introduced, and systemd manages the `strace` process as the service.

# 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