Recently running & actively running process events output at startup about tetragon

[kkourt]

I think export-stdout just tails a file in the export directory, and this file is shared across multiple instances of the tetragon pod.

ref: https://github.com/cilium/tetragon/blob/main/install/kubernetes/templates/_container_export_stdout.tpl

So I believe what you are seeing is expected.

[rayjanoka]

ahhh I see it uses a hostPath so it would persist between pod restarts.

Ok, adding -n 0 to the tail command resolved my final issue. thanks @kkourt!!!

export:
  stdout:
    commandOverride:
      - sh
    argsOverride:
      - -c
      - tail -n 0 -q -F /var/run/cilium/tetragon/tetragon.log 2> /dev/null

[kkourt]

Also, how are you gathering the events? Are you using the tetra CLI (tetra getevents) or do you export in JSON? Note that export filters configured in the daemonset do not apply to tetra getevents.

[kkourt]

Thanks for the report!Could you please provide some examples of events that you 'd expect to be matched by the filter rules but are not?

[rayjanoka]

ahh, upon closer inspection I think I see what is going on.

the events I was looking at weren't filtered events, they were actually valid events. it looks like when tetragon starts up it prints out the process_exec start event for all the already running processes. Since I've already scanned these events when they first start I don't want to look at them again. I think I can look at the start_time to determine if these are old or new and get this solved. thanks!

[kkourt]

ahh, upon closer inspection I think I see what is going on.

the events I was looking at weren't filtered events, they were actually valid events. it looks like when tetragon starts up it prints out the process_exec start event for all the already running processes. Since I've already scanned these events when they first start I don't want to look at them again. I think I can look at the start_time to determine if these are old or new and get this solved. thanks!

Cheers! Another way to distinguish these events is to check for "proc" in the flags field (since these events are generated form /proc).

[rayjanoka]

thanks @kkourt

ok, getting closer, many of them are flags: procFS auid and those look good, but some are flags: execve clone.

As best I can tell these execve clone event pids are not running. I found the description for this clone flag, but I'm not sure why I'm seeing these events on startup.

https://github.com/cilium/tetragon/blob/main/pkg/api/flags.go#L69-L75

execve clone event

{
  "process_exec": {
    "process": {
      "exec_id": "Ym00NToyNzk3Mjc4NTQ4MzAyMTk2OjE2MDY2Njg=",
      "pid": 1606668,
      "uid": 100,
      "cwd": "/home/user/server",
      "binary": "/usr/bin/chmod",
      "arguments": "755 /tmp/sqlite-3.7.2-libsqlitejdbc.so",
      "flags": "execve clone",
      "start_time": "2023-07-17T00:33:10.815357493Z",
      "auid": 4294967295,
      "pod": {
        "namespace": "game",
        "name": "game-i-64aa20c54055f4ac2c902a9d",
        "container": {
          "id": "containerd://d9620432962d2f6e20c1622736631c0f2ca7dd97b7e322a763d6dabfc7d2291b",
          "name": "instance",
          "image": {
            "id": "x",
            "name": "x"
          },
          "start_time": "2023-07-17T00:32:56Z",
          "pid": 190
        },
        "pod_labels": {
          "app": "game-instance"
        }
      },
      "docker": "d9620432962d2f6e20c1622736631c0",
      "parent_exec_id": "Ym00NToyNzk3MjY5NjI3MTc3MTM2OjE2MDM5ODU=",
      "cap": {},
      "ns": {
        "uts": {
          "inum": 4026537567
        },
        "ipc": {
          "inum": 4026537568
        },
        "mnt": {
          "inum": 4026537570
        },
        "pid": {
          "inum": 4026537571
        },
        "pid_for_children": {
          "inum": 4026537571
        },
        "net": {
          "inum": 4026536499
        },
        "time": {
          "inum": 4026531834,
          "is_host": true
        },
        "time_for_children": {
          "inum": 4026531834,
          "is_host": true
        },
        "cgroup": {
          "inum": 4026537610
        },
        "user": {
          "inum": 4026531837,
          "is_host": true
        }
      },
      "tid": 1606668
    },
  },
  "node_name": "zm45",
  "time": "2023-07-17T00:33:10.815357303Z"
}

[kkourt]

thanks @kkourt

ok, getting closer, many of them are flags: procFS auid and those look good, but some are flags: execve clone.

As best I can tell these execve clone event pids are not running. I found the description for this clone flag, but I'm not sure why I'm seeing these events on startup.

https://github.com/cilium/tetragon/blob/main/pkg/api/flags.go#L69-L75
execve clone event

The exec clone events are generated after tetragon starts running. I think the most plausible explanation is that the programs do not exist anymore (i.e., they were terminated). You can verify this by looking for ProcessExit events.

[rayjanoka]

hmm, I'm not currently receiving the ProcessExit events at all...but I could.

If I restart tetragon in succession, on startup it will keep telling me about the same old ProcessExec clone events with the same exec_ids I've already seen for a short running process, like a chmod with a start_time from 14 hours ago.

I guess the old data is just buffered somewhere in bpf land?

It looks like I'll have to either check the start_time or the ProcessExit events...ya?

thanks!

[kkourt]

Hi,

hmm, I'm not currently receiving the ProcessExit events at all...but I could.

If I restart tetragon in succession, on startup it will keep telling me about the same old ProcessExec clone events with the same exec_ids I've already seen for a short running process, like a chmod with a start_time from 14 hours ago.

I guess the old data is just buffered somewhere in bpf land?

It looks like I'll have to either check the start_time or the ProcessExit events...ya?

thanks!

If you start Tetraragon multiple times, you will get the events from proc (the ones with the procFS flag) multiple times.

[rayjanoka]

These aren't proc though, they are execve clone from hours before the restart.

[kkourt]

These aren't proc though, they are execve clone from hours before the restart.

How are you retrieving those events?

[rayjanoka]

Just from the k8s logs on startup, I get a few of these from each node.

For instance, if I restart tetragon on this node now, Aug 29 05:31:56 UTC 2023, then on startup of the new pod I get this event from back on Aug 27 19:54:13 UTC 2023 (over a day old).

➜ stern -n kube-system  --since 600s tetragon-hbmf6 -c export-stdout
{
  "process_exec": {
    "process": {
      "exec_id": "Ym01MTo2NDA5MzE5ODk0MTE2MjAxOjIyNDMwMjQ=",
      "pid": 2243024,
      "uid": 100,
      "cwd": "/home/minecraft/server",
      "binary": "/usr/bin/cowsay",
      "arguments": "-d -W 15",
      "flags": "execve clone",
      "start_time": "2023-08-27T19:54:13.171416449Z",
      "auid": 4294967295,
      "pod": {
        "namespace": "game",
        "name": "game-i-xxx",
        "container": {
          "id": "containerd://76cc6f952f35bca49ac86df959be6c47a9fed2f295d4e691c6077dde08561796",
          "name": "instance",
          "image": {
            "id": "player-server@sha256:eb78f4ee1d7b4d0a8953966886e3ed8cea855c59bcd34f1047f169bff143f90a",
            "name": "player-server:b584d2adff9ceafe01f5cb8954c4cc58865040f9-live"
          },
          "start_time": "2023-08-27T19:43:19Z",
          "pid": 1713
        },
        "pod_labels": {
          
        }
      },
      "docker": "76cc6f952f35bca49ac86df959be6c4",
      "parent_exec_id": "Ym01MTo2NDA5MzE5ODkzMzM0MzQxOjIyNDMwMjI=",
      "cap": {},
      "ns": {
        "uts": {
          "inum": 4026539836
        },
        "ipc": {
          "inum": 4026539837
        },
        "mnt": {
          "inum": 4026539839
        },
        "pid": {
          "inum": 4026539840
        },
        "pid_for_children": {
          "inum": 4026539840
        },
        "net": {
          "inum": 4026539047
        },
        "time": {
          "inum": 4026531834,
          "is_host": true
        },
        "time_for_children": {
          "inum": 4026531834,
          "is_host": true
        },
        "cgroup": {
          "inum": 4026539841
        },
        "user": {
          "inum": 4026531837,
          "is_host": true
        }
      },
      "tid": 2243024
    },
    "parent": {
      "exec_id": "Ym01MTo2NDA5MzE5ODkzMzM0MzQxOjIyNDMwMjI=",
      "pid": 2243022,
      "uid": 100,
      "cwd": "/home/minecraft/server",
      "binary": "/usr/bin/python3",
      "arguments": "/usr/bin/python3 -version",
      "flags": "execve",
      "start_time": "2023-08-27T19:54:13.170634939Z",
      "auid": 4294967295,
      "pod": {
        "namespace": "game",
        "name": "game-i-xxx",
        "container": {
          "id": "containerd://76cc6f952f35bca49ac86df959be6c47a9fed2f295d4e691c6077dde08561796",
          "name": "instance",
          "image": {
            "id": "player-server@sha256:eb78f4ee1d7b4d0a8953966886e3ed8cea855c59bcd34f1047f169bff143f90a",
            "name": "player-server:b584d2adff9ceafe01f5cb8954c4cc58865040f9-live"
          },
          "start_time": "2023-08-27T19:43:19Z",
          "pid": 1712
        },
        "pod_labels": {
        }
      },
      "docker": "76cc6f952f35bca49ac86df959be6c4",
      "parent_exec_id": "Ym01MTo2NDA5MzE5ODkyMzQ5MTY1OjIyNDMwMjI=",
      "refcnt": 3,
      "cap": {},
      "ns": {
        "uts": {
          "inum": 4026539836
        },
        "ipc": {
          "inum": 4026539837
        },
        "mnt": {
          "inum": 4026539839
        },
        "pid": {
          "inum": 4026539840
        },
        "pid_for_children": {
          "inum": 4026539840
        },
        "net": {
          "inum": 4026539047
        },
        "time": {
          "inum": 4026531834,
          "is_host": true
        },
        "time_for_children": {
          "inum": 4026531834,
          "is_host": true
        },
        "cgroup": {
          "inum": 4026539841
        },
        "user": {
          "inum": 4026531837,
          "is_host": true
        }
      },
      "tid": 2243022
    }
  },
  "node_name": "xxx51",
  "time": "2023-08-27T19:54:13.171416329Z"
}
...