Skip to content

[.NET][Logs] UserEventTracker retries open_diag_socket on every mmap event for failed PIDs, producing hundreds of duplicate warnings #236

Description

@mdh1418

When record-trace is running on a machine with multiple .NET processes, UserEventTracker produces hundreds of duplicate warn!("Failed to open diagnostic socket") messages per second for processes whose diagnostic sockets are inaccessible. This makes it difficult to use --log-mode console for diagnostics, as the useful info!("Enabled .NET events") messages are buried in noise.

There are two underlying issues:

  1. No negative cache for failed PIDs
    In worker_thread_proc, PIDs are only added to the pids HashMap on successful enablement:

    /* Skip if already enabled */
    if pids.contains_key(&pid) {
    continue;
    }
    let nspid = procfs::ns_pid(&mut path_buf, pid).unwrap_or(pid);
    if let Ok(diag) = PerfMapContext::new(pid, nspid) {
    if let Some(mut socket) = diag.open_diag_socket() {
    if let Ok(settings) = arc.lock() {
    match Self::enable_events(&mut socket, &settings, &mut buffer) {
    Ok(()) => {
    info!("Enabled .NET events for process: pid={}", pid);
    pids.insert(pid, socket);

    When open_diag_socket() returns None, the PID is never recorded, so pids.contains_key(&pid) doesn't short-circuit on the next attempt. Meanwhile, the mmap callback fires for every mmap event from a .NET process and unconditionally enqueues the PID:
    event.add_callback(move |data| {
    let fmt = data.format();
    let data = data.event_data();
    let pid = fmt.get_u32(pid, data)?;
    let filename = fmt.get_str(filename, data)?;
    /* Check if dotnet process */
    if is_dotnet_memfd_mapping(filename) {
    debug!("Found dotnet process {} via mapping {}", pid, filename);
    /* Attempt to track, will check diag sock, etc */
    tracker.borrow_mut().track(pid)?;
    }

    Each enqueued message triggers a fresh open_diag_socket attempt and a warn! on failure:
    warn!("Failed to open diagnostic socket: pid={}, nspid={}", self.pid, self.nspid);

    Note: caching failures permanently would break the startup race where a process is detected via doublemapper before its diagnostic socket exists, and a later dotnet_ipc_created mmap should trigger a successful retry.

  2. The useful info! and the noisy warn! can't be separated via --log-filter
    Both messages come from one_collect::helpers::dotnet::os::linux. Since EnvFilter uses level thresholds, =info shows both and =warn hides the target message.
    Additionally, PerfMapTracker::enable_perf_map and disable_perf_map independently call open_diag_socket(), so a PID that was already successfully enabled by UserEventTracker can still produce warnings when PerfMapTracker tries the same socket after the process exits.

Observed behavior

record-trace started with PID: 66269
[record-trace][stdout] 2026-03-05T20:59:57.519633Z  WARN one_collect::helpers::dotnet::os::linux: Failed to open diagnostic socket: pid=66057, nspid=66057
[record-trace][stdout] 2026-03-05T20:59:57.519696Z  WARN one_collect::helpers::dotnet::os::linux: Failed to open diagnostic socket: pid=66057, nspid=66057
... repeats 187 more times for pid=66057 ...
[record-trace][stdout] Recording started.  Press CTRL+C to stop.
[record-trace][stdout] 2026-03-05T20:59:57.534214Z  WARN one_collect::helpers::dotnet::os::linux: Failed to open diagnostic socket: pid=66250, nspid=66250
[record-trace][stdout] 2026-03-05T20:59:57.534271Z  WARN one_collect::helpers::dotnet::os::linux: Failed to open diagnostic socket: pid=66250, nspid=66250
... repeats 769 more times for pid=66250 ...
Starting tracee process: /datadisks/disk1/work/A1C20942/p/corerun .../custommetadata.dll tracee
Tracee process started with PID: 66275
Waiting for tracee process to exit...
[record-trace][stdout] 2026-03-05T20:59:58.014259Z  INFO one_collect::helpers::dotnet::os::linux: Enabled .NET events for process: pid=66275
[tracee][stdout] Tracee waiting for EventSource to be enabled via IPC...
[tracee][stdout] Tracee EventSource enabled, emitting events.
Stopping record-trace with SIGINT.
Waiting for record-trace to exit...
[record-trace][stdout] 2026-03-05T20:59:58.345812Z  WARN one_collect::helpers::dotnet::os::linux: Failed to open diagnostic socket: pid=66275, nspid=66275
[record-trace][stdout] Recording stopped.
[record-trace][stdout] Finished recording trace.

Desired behavior

  • I can catch Enabled .NET events message without a flood of Failed to open diagnostic socket warnings via --log-filter

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions