Coldtrace

The Question

Coldtrace started with a casual question I have had since university. When Python runs something like this:

import numpy
import torch

what actually happens? The broader question is more interesting than Python's import machinery alone: what happens at the process level on Linux when a program starts, imports libraries, maps shared objects, creates threads or child processes, and exits?

I chose import torch as the first workload because it feels heavy. I wanted to make "heavy" more concrete. Was the time going into Python's import machinery, file opens, shared-object mapping, dynamic linking, native initialization, or CUDA detection? I did not know. That made it useful.

Setup

I wanted real Linux behavior: /proc, cgroups, strace, systemd, and the normal Linux process model. Since I am on macOS, I used a small Ubuntu VM through Lima. That gave me a disposable Linux development box without turning the first pass into container configuration.

Docker would be a reasonable thing to test later, but it was the wrong abstraction for this first experiment. Containers would have introduced extra questions about namespaces, cgroups, filesystem layers, security profiles, and tracing permissions. The first question was simpler:

What does a normal Linux process do when it runs python -c 'import torch'?

I removed the obvious NVIDIA packages and installed CPU-only PyTorch:

python -m pip freeze |
  grep '^nvidia-' |
  xargs -r python -m pip uninstall -y

python -m pip install torch \
  --index-url https://download.pytorch.org/whl/cpu

I still noticed some CUDA-looking names in the environment afterward. I have not explained those yet, so I am treating them as an open question rather than claiming CUDA initialization occurred. In particular, I need to distinguish between Python modules that expose CUDA-related APIs and native CUDA libraries that were actually mapped into the process.

Artifact Bundle

The numbers below are backed by a small raw artifact bundle from the manual run directory. I included the text files directly so the post is not just a polished summary of the investigation; the underlying evidence is visible too.

Manual Runs

Before writing much code, I started with off-the-shelf tools. First, command-level wall clock time:

/usr/bin/time -p \
  python -c 'import torch' \
  2> runs/manual/time-posix.txt

real 0.58
user 0.60
sys  0.06

This measured the entire command: starting Python, initializing it, importing torch, and exiting. It was a useful outside measurement, but only one run in one VM. It should not be read as "import torch takes half a second" in general.

Next, I used Python's import timing tool:

python -X importtime \
  -c 'import torch' \
  2> runs/manual/importtime.txt

import time: self [us] | cumulative | imported package
..
import time:     83916 |     107560 |   torch._C
..
import time:      1379 |      71254 |         torch.nn.modules
..
import time:       316 |      77933 |       torch.nn
import time:        68 |      78000 |     torch.nn.functional
..
import time:      1251 |      79418 |   torch.functional
..
import time:     10830 |     493611 | torch

The final line reported roughly 10.8 milliseconds of self time for the top-level torch import and roughly 493.6 milliseconds cumulatively, including nested imports. That was reasonably close to the 580 millisecond end-to-end command measurement, with the expected difference that /usr/bin/time measured the complete Python process.

The large cumulative values in intermediate rows need to be interpreted carefully. The tree is hierarchical, so parent and child cumulative times overlap. They cannot simply be added together.

System Calls

Neither /usr/bin/time nor importtime showed the Linux interactions underneath the import: files opened, paths searched, shared objects mapped, syscall shape, thread synchronization, and kernel-facing work. That was where strace entered the investigation.

strace -f -c \
  python -c 'import torch' \
  2> runs/manual/strace-summary.txt

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ------------------
 71.56    0.492917       14936        33         1 futex
 14.22    0.097960           6     14606       586 newfstatat
  3.98    0.027428          12      2228           read
  1.59    0.010962           8      1295        28 openat
  1.47    0.010110           4      2262           fstat
  1.27    0.008762           4      2029         4 lseek
  1.14    0.007832           9       867           mmap
  1.01    0.006979           5      1274           close
..
------ ----------- ----------- --------- --------- ------------------
100.00    0.688772          24     27716      1646 total

Two syscalls stood out: futex and newfstatat.

futex is short for fast userspace mutex. It is a Linux syscall used by threading and synchronization primitives. Seeing it during a PyTorch import was not shocking, but it was a useful reminder that importing a large library can involve runtime initialization and synchronization, not just reading .py files.

I am being careful with the futex timing. A syscall summary does not automatically mean that much CPU was burned doing futex work. Waiting and synchronization can show up as time spent inside the syscall. This is a lead, not a conclusion.

newfstatat asks filesystem metadata questions: does this path exist, what kind of file is it, what are its permissions, how large is it, and when was it modified? During Python imports, a large number of these checks is plausible.

Keeping The Process Alive

The next problem was that python -c 'import torch' exits too quickly. If I wanted to inspect /proc/$PID, the process needed to stay alive long enough to observe it.

python -c 'import torch, time; time.sleep(1200)'

Once I had the PID, I dumped selected `/proc` files while the process was still running. /proc/$PID/status showed a sleeping Python process with memory fields like these:

VmPeak:   589332 kB
VmSize:   589332 kB
VmHWM:    235996 kB
VmRSS:    235996 kB
RssAnon:  151652 kB
RssFile:   84344 kB
VmData:   298668 kB
VmLib:    203908 kB
VmSwap:        0 kB

VmSize is virtual address space, not physical RAM. VmRSS is resident memory. RssAnon is resident anonymous memory, and RssFile is resident file-backed memory such as mapped shared libraries and files.

In this run, RSS was about 236 MB: roughly 152 MB anonymous and 84 MB file-backed. I would not say all 84 MB was "the torch library." That would be too strong. But it does suggest that a meaningful amount of resident memory came from file-backed mappings.

Why Build It?

By this point I had a set of useful manual commands, but they were awkward to repeat. One command measured wall-clock time, another captured Python import timing, another summarized syscalls, and another set read `/proc/$PID` while the process was alive.

Coldtrace started to make sense as a small tool: capture the raw information I was already collecting manually, but make it repeatable.

coldtrace run -- python -c 'import torch'

The public repo's current 0.0.6 shape is intentionally boring: parse the child command, create a run directory under runs/, start the child, redirect stdout and stderr, measure wall-clock time from the parent, wait for exit, then write facts into record.json.

runs/
  20260622T022115.254Z-torch-import/
    record.json
    stdout.log
    stderr.log

Some record.json fields are intentionally null right now. They mark where later runtime layers will land: /proc snapshots, import timing, syscall summaries, mapped files, and richer process state. The point is to keep the underlying artifacts visible instead of immediately collapsing everything into one polished number.

Future Plans

1. Live process state Snapshot `/proc` before the process exits. The key race is that /proc/$PID exists only while the child is alive. Short-lived workloads need coordination if the parent is going to capture status, cgroup, maps, and fd reliably.
2. Repeatability Run the same command multiple times. Compare variance, separate cold-ish runs from warm runs, and add basic statistics such as min, max, mean, median, and eventually percentiles.
3. Artifact stitching Keep Python, syscall, and process views side by side. The useful question is not only whether a run got slower. It is whether it opened more files, mapped different libraries, spent more time in userspace, changed syscall shape, or shifted resident memory.

Limitations

This is an early investigation, not a benchmark suite. The measurements came from a small Ubuntu VM running through Lima on macOS, on aarch64, using CPU-only PyTorch. The timing results are from a small number of manual runs, not a statistically meaningful benchmark.

Page cache state, VM scheduling, filesystem behavior, and previous runs can all affect timings. strace also changes the timing of the traced program, so I am using it to understand syscall shape, not as the final source of performance truth.

I am not claiming to have optimized PyTorch, found a novel bottleneck, or built a production profiler. The result so far is more modest and more useful:

import torch is not one operation. It is visible through several boundaries: Python's import graph, Linux syscalls, mapped files, live process state, and eventually repeatable run records.

AI Assistance

I used AI coding tools while building Coldtrace, including for implementation suggestions, debugging, code review, and explaining unfamiliar APIs. I also used AI assistance to organize and edit this post.

I reviewed and modified the code I kept, ran the experiments myself, inspected the resulting artifacts, and am responsible for the measurements, interpretations, and any mistakes in the project or this post.