Profiling execution and network in Linux: dissecting curl and system calls

When running automation scripts and CLI tasks on Linux, the familiar warning surfaces: "the script is running slow" or "the external API is taking forever to answer." In the past, my instinctive reaction was prefixing the command with time and looking at total elapsed seconds.

In production environments, total time is an empty metric. It tells you that an operation took ten seconds, but fails to explain whether the process spent those seconds waiting on disk I/O, idling for incoming TCP packets, or throttled by kernel scheduler limits. I need granular visibility across operating system layers.

In this article, I document how to measure, profile, and interpret command execution times on Linux, using a real-world certificate lookup via curl against crt.sh (https://crt.sh/?q=example.com) as a practical benchmark.

1. The common pitfall: shell built-in vs. GNU binary#

The first practical distinction worth mastering is the difference between the shell keyword and the external system binary.

The Bash built-in (time)#

When typing time command, Bash intercepts the execution. It does not spawn an external timer process. The shell records its internal timestamps, executes the target program via fork and exec, and calculates elapsed difference. It is convenient for casual testing, but lacks detailed hardware and memory accounting.

The GNU binary (/usr/bin/time)#

For exhaustive diagnostics, invoke the GNU executable directly, as documented in the official GNU time manual:

\time -v curl -s "https://crt.sh/?q=example.com" > /dev/null

The leading backslash instructs the shell to ignore internal keywords or aliases, targeting /usr/bin/time from $PATH.

What the Kernel tracks in verbose mode#

When calling /usr/bin/time -v, the parent process forks. The child process loads curl via the execve() system call. While the child runs, the parent stays blocked waiting on wait4().

Upon termination (whether normal exit or termination via signal like SIGKILL), wait4() populates the struct rusage C structure (defined in <sys/resource.h>), as documented in the Linux getrusage manual. This structure retrieves hardware and memory metrics directly from the process control block (PCB) maintained by the kernel.

In the generated output, four metrics deserve immediate focus:

• User time and System time: User CPU time measures the duration the processor spent executing userspace code (arithmetic, JSON parsing, regex decoding). System time (sys) measures processor cycles executing kernel space instructions on behalf of the process (servicing system calls like memory allocation or reading file descriptors).
• Maximum resident set size (ru_maxrss): On Linux, this records the peak physical RAM occupied by the process over its lifetime (measured in kilobytes). If an application suffers from memory leaks or excessive buffer allocations, this counter flags the ceiling reached.
• Major Page Faults (ru_majflt): A high count indicates that the curl binary or its shared libraries (libcurl.so, libssl.so) were not present in RAM page cache. The kernel had to read physical blocks from disk to bring them into memory, which also occurs when a server faces heavy memory pressure and starts swapping.
• Involuntary Context Switches (ru_nivcsw): Shows how many times the Linux scheduler forced the process off the CPU because its timeslice expired or a higher-priority hardware interrupt arrived. Elevated numbers point to intense CPU contention on the host.

2. Network visibility: curl internal metrics engine#

While /usr/bin/time provides host-level resource visibility, it is blind to TCP/IP networking stages. The curl command relies on external libraries such as OpenSSL for TLS encryption and libcurl for HTTP protocol handling.

To break down network latency phases, use the -w (write-out) formatting parameter, whose variables are documented in the official curl manual page:

curl -o /dev/null -s -w "\
\n--------------------------------------\n\
DNS Lookup:        %{time_namelookup}s\n\
TCP Connect:       %{time_connect}s\n\
TLS Handshake:     %{time_appconnect}s\n\
Pre-Transfer:      %{time_pretransfer}s\n\
Start Transfer:    %{time_starttransfer}s\n\
--------------------------------------\n\
Total Time:        %{time_total}s\n" \
"https://crt.sh/?q=example.com"

What each stage measures in practice#

1. time_namelookup (DNS Resolution):

Measures time spent resolving the domain name into an IP address. Within libcurl, this routes through Curl_resolv(), which calls getaddrinfo() from the standard C library (glibc). When this value spikes intermittently, check resolver cache statistics with resolvectl statistics (on systemd-resolved systems) or review timeout rules in /etc/resolv.conf.

1. time_connect (TCP Connection):

Measures time elapsed from startup until the TCP three-way handshake (SYN, SYN-ACK, ACK) with the remote host or proxy completes.

1. time_appconnect (TLS Handshake):

Measures the cryptographic handshake duration. This phase reflects internal execution inside SSL_do_handshake() from OpenSSL. Abnormal delays here suggest heavy certificate chains with MTU fragmentation (inspect interface MTU with ip link show) or computationally expensive cipher negotiations.

1. time_starttransfer (Time to First Byte / TTFB):

The TCP socket is open, TLS encryption is complete, and the HTTP GET request has been transmitted. The remaining duration until the first response byte arrives represents transit latency plus remote backend processing time. In crt.sh, this is usually the largest phase, as the remote PostgreSQL database must process the SQL query before returning bytes.

Breaking down discrete latency deltas#

Native curl -w timing metrics are cumulative: each variable reflects total elapsed seconds from the start of execution ($t_0$). To understand where latency actually accumulates, compute isolated stage deltas:

• DNS resolution duration: $\Delta_{\text{DNS}} = \text{time\_namelookup}$
• TCP handshake duration: $\Delta_{\text{TCP}} = \text{time\_connect} - \text{time\_namelookup}$
• TLS negotiation duration: $\Delta_{\text{TLS}} = \text{time\_appconnect} - \text{time\_connect}$
• Request transmission: $\Delta_{\text{REQ}} = \text{time\_pretransfer} - \text{time\_appconnect}$
• Remote processing (Net TTFB): $\Delta_{\text{SERVER}} = \text{time\_starttransfer} - \text{time\_pretransfer}$
• Payload transfer: $\Delta_{\text{DATA}} = \text{time\_total} - \text{time\_starttransfer}$

You can automate this calculation cleanly using an awk pipeline:

curl -s -w "%{time_namelookup} %{time_connect} %{time_appconnect} %{time_pretransfer} %{time_starttransfer} %{time_total}\n" \
     -o /dev/null "https://crt.sh/?q=example.com" | awk '{
    printf "DNS Lookup:      %.4f s\n", $1
    printf "TCP Handshake:   %.4f s\n", $2 - $1
    printf "TLS Handshake:   %.4f s\n", $3 - $2
    printf "Request Send:    %.4f s\n", $4 - $3
    printf "Server Wait:     %.4f s\n", $5 - $4
    printf "Data Transfer:   %.4f s\n", $6 - $5
    printf "Total Elapsed:   %.4f s\n", $6
}'

If the measurement shows DNS Lookup taking exactly 5.000 seconds while subsequent phases complete in milliseconds, the delay does not originate at the target server, but rather in local resolver timeouts.

3. Deep profiling: dissecting system calls with strace#

When a command stalls and you need to confirm whether the slowdown originates on your host or the remote endpoint, strace provides conclusive evidence, as described in the strace manual.

For an aggregated summary of time spent per system call:

strace -c curl -s "https://crt.sh/?q=example.com" > /dev/null

The -c flag summarizes total elapsed time into a clean table, preventing thousands of output lines from filling the console.

When you need real-time inspection focused on critical activity:

strace -T -e trace=network,file curl -s "https://crt.sh/?q=example.com" > /dev/null

The -T option displays time spent within each individual system call, filtering specifically for network sockets and file access.

Common bottlenecks revealed by strace#

• Accumulated time in poll, select, or epoll_wait: The curl binary is idle; its userspace thread is sleeping while waiting for the network card to deliver packets to the target TCP socket. When command execution is slow and most time accumulates here, the bottleneck is external: network latency or remote backend processing delay.
• Elevated time in openat or newfstatat: The curl tool accesses local certificate authority bundles to validate the remote SSL certificate (/etc/ssl/certs/ or /etc/pki/tls/certs/). If the local disk suffers from elevated I/O wait, the slowdown stems from local file reads rather than internet connectivity.

The overhead of strace and ptrace limitations#

An essential caveat for production environments: strace relies on the kernel's ptrace(2) tracing framework. For every system call made by the target process, the kernel traps execution, triggers a context switch to strace to inspect arguments upon entry, executes the syscall, and traps again upon exit to inspect the return code.

This architecture introduces two context switches per system call. For I/O-intensive workloads or high-frequency network requests, strace can slow execution down by a factor of 10x to 50x, altering runtime conditions (the observer effect).

For low-overhead production tracing, consider modern alternatives such as perf trace or eBPF scripts (bpftrace), which execute aggregated probes inside kernel space without round-trip context switching.

4. Edge cases to keep on your radar#

In production environments, you cannot rely only on clean runs. Contradictory metrics often point to underlying constraints.

CPU throttling under cgroups#

A recurring scenario: you run /usr/bin/time and real elapsed time shows 10 seconds, but combined user and system CPU time barely reaches 0.4 seconds. Meanwhile, network latency reported by curl -w looks normal.

This pattern usually reveals CPU throttling enforced by kernel cgroups (frequent across Docker containers, Podman, Kubernetes pods, or LVE shared hosting accounts). The process is paused waiting for fresh CPU quota allocations under the Completely Fair Scheduler (CFS).

Inspection depends on the cgroups version active on the host:

• cgroups v1: check /sys/fs/cgroup/cpu,cpuacct/cpu.stat and evaluate nr_throttled and throttled_time.
• cgroups v2: read /sys/fs/cgroup/<slice>/cpu.stat and inspect nr_throttled alongside throttled_usec.

Fast false positives with HTTP error codes#

Overloaded backend services often terminate long queries early, returning HTTP 502 (Bad Gateway) or 504 errors through reverse proxies. In these cases, the request terminates quickly (for instance, in 800 milliseconds), giving a misleading impression of performance if you only inspect total runtime.

To keep monitoring automations reliable, always validate returned HTTP status codes:

TIMEFORMAT='Real: %R | User: %U | Sys: %S'
HTTP_STATUS=$(curl -o /dev/null -s -w "%{http_code}" "https://crt.sh/?q=example.com")

if [ "$HTTP_STATUS" -eq 200 ]; then
    echo "Service healthy. Profiling execution:"
    time curl -s "https://crt.sh/?q=example.com" > /dev/null
else
    logger -p daemon.error "Connectivity issue detected. HTTP Status: $HTTP_STATUS."
fi

Silent DNS delays with dual-stack (IPv4/IPv6) networking#

Another common Linux edge case occurs when the host has IPv6 enabled on network interfaces, but lacks a valid outbound default gateway for IPv6 traffic. The getaddrinfo() resolver issues concurrent queries for A (IPv4) and AAAA (IPv6) records.

If upstream firewalls or local DNS forwarders silently drop AAAA requests, the resolver waits out its full timeout (often 5 seconds as specified in /etc/resolv.conf) before falling back to the IPv4 address. The curl command succeeds, but incurs a mandatory 5-second penalty upfront.

To isolate whether DNS delays stem from IPv6 query drops, enforce IPv4-only resolution using the -4 flag:

curl -4 -o /dev/null -s -w "DNS: %{time_namelookup}s | Total: %{time_total}s\n" "https://crt.sh/?q=exemplo.com"

If time_namelookup drops from 5.000s down to 0.020s, the root cause is broken IPv6 resolution in the local network stack.

What practical diagnostics reveal#

Evaluating command performance on Linux requires understanding where execution cycles go: computing data in userspace, opening sockets in kernel space, or waiting passively for packets across the network.

By combining /usr/bin/time -v to audit memory and scheduler metrics, -w formatting in curl to dissect network stages into discrete deltas, and strace to trace system calls, you move beyond vague guesses about performance and identify the exact operating system layer responsible for the delay.

Frequently asked questions about command and network profiling on Linux#

Why is the sum of user and sys time in /usr/bin/time much lower than real elapsed time?#

Real time (wall-clock time) records total chronological time elapsed between process invocation and termination. In contrast, user and sys track only active CPU execution cycles spent running userspace code and kernel space system calls. When real time vastly exceeds combined CPU time, the process spent the majority of its lifetime in a sleep or blocked state waiting for synchronous events, such as network I/O, disk transfers, or cgroups quota replenishment.

What is the difference between Bash time and /usr/bin/time?#

The bare time command is a shell keyword built into Bash. It tracks internal shell timestamps and displays basic execution times. The /usr/bin/time binary is an external GNU executable that calls wait4() upon child exit, extracting detailed metrics from struct rusage including maximum resident set size (ru_maxrss), hard page faults (ru_majflt), and involuntary context switches.

Why should strace be used with caution on production servers?#

The strace utility relies on the ptrace(2) kernel interface, trapping every system call upon entry and exit. This design introduces two context switches per syscall. For I/O-intensive workloads or high-concurrency microservices, this tracing overhead can degrade execution speed by 10x to 50x, distorting normal performance profiles.

How can I isolate pure remote server processing time (net TTFB) in curl?#

Because curl -w metrics accumulate from execution start ($t_0$), the net duration spent exclusively waiting for the remote server to process the request is obtained by subtracting the pre-transfer timestamp from the start-transfer timestamp: time_starttransfer - time_pretransfer.

What causes an exact 5-second delay in curl time_namelookup?#

Consistent 5-second DNS delays typically point to resolver timeouts in glibc when waiting for AAAA (IPv6) query responses or uncontactable secondary nameservers listed in /etc/resolv.conf. Running curl -4 immediately tests whether dropping IPv6 lookups eliminates the delay.

See also

Linux Fixing 'cannot refresh cache whilst offline' in Linux and cPanel

Linux Why your server needs SWAP even with free disk space: kernel memory mechanics and 4GB setup

Servers Inside the trenches: debugging a cascading failure in aaPanel, Python 3.12, and Nginx multi-webserver

This post is licensed under CC BY-NC.