tetragon icon indicating copy to clipboard operation
tetragon copied to clipboard
verified publisher icon cilium

filename monitoring not recgonizing/printing out binary cmd correctly

Open Jiahao0 opened this issue 2 years ago • 10 comments

What happened?

  1. env: Embedded Linux Linux tegra-ubuntu 5.10.120-rt70-tegra #1 SMP PREEMPT RT Wed Oct 25 10:07:33 CST 2023 aarch64 aarch64 aarch64 GNU/Linux

  2. config: Using example config filename_monitoring.yaml. I comment out 'security_path_truncate' part, because it's not in /proc/kallsyms. I put it on this path: /etc/tetragon/tetragon.tp.d/filename_monitoring.yaml

  3. run: $ tetragon & then: $ tetra getevents -o compact In another console: /etc/tetragon/tetragon.tp.d# cat filename_monitoring.yaml

  4. error: The command cat cannot be recgonize/printed out correctly.

📚 read     /usr/bin/bash /etc/tetragon/tetragon.tp.d                     
📚 read     /usr/bin/bash /etc/tetragon/tetragon.tp.d                     
🚀 process  /etc/tetragon/tetragon.tp.d/�D]� filename_monitoring.yaml 
📝 mmap-r   /etc/tetragon/tetragon.tp.d/�D]� /etc/ld.so.cache        
📚 read     /etc/tetragon/tetragon.tp.d/�D]� /etc/tetragon/tetragon.tp.d/filename_monitoring.yaml 
📚 read     /etc/tetragon/tetragon.tp.d/�D]� /etc/tetragon/tetragon.tp.d/filename_monitoring.yaml 
📚 read     /etc/tetragon/tetragon.tp.d/�D]� /etc/tetragon/tetragon.tp.d/filename_monitoring.yaml 
📚 read     /etc/tetragon/tetragon.tp.d/�D]� /etc/tetragon/tetragon.tp.d/filename_monitoring.yaml 
💥 exit     /etc/tetragon/tetragon.tp.d/�D]� filename_monitoring.yaml 0 
💥 exit       0

Any idea what may be the problem? Thanks.

Tetragon Version

$ tetra version
CLI version: v0.12.0-pre.0-231-g02861f05

Kernel Version

Linux tegra-ubuntu 5.10.120-rt70-tegra #1 SMP PREEMPT RT Wed Oct 25 10:07:33 CST 2023 aarch64 aarch64 aarch64 GNU/Linux

Kubernetes Version

NA

Bugtool

tetragon-bugtool.tar.gz

Relevant log output

root@tegra-ubuntu:/xdata# tetra bugtool
time="2023-01-31T15:04:17Z" level=info msg="saving init info"
time="2023-01-31T15:04:17Z" level=info msg="retrieving lib directory" libDir=/xdata/objs/
time="2023-01-31T15:04:17Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/
time="2023-01-31T15:04:17Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_alignchecker.ll
time="2023-01-31T15:04:17Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_cgroup_mkdir.ll
time="2023-01-31T15:04:17Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_cgroup_release.ll
time="2023-01-31T15:04:17Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_cgroup_rmdir.ll
time="2023-01-31T15:04:17Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_execve_bprm_commit_creds.ll
time="2023-01-31T15:04:17Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_execve_event.ll
time="2023-01-31T15:04:17Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_execve_event_v53.ll
time="2023-01-31T15:04:17Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_execve_event_v61.ll
time="2023-01-31T15:04:17Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_exit.ll
time="2023-01-31T15:04:17Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_fork.ll
time="2023-01-31T15:04:17Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_generic_kprobe.ll
time="2023-01-31T15:04:17Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_generic_kprobe_v53.ll
time="2023-01-31T15:04:18Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_generic_kprobe_v61.ll
time="2023-01-31T15:04:18Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_generic_retkprobe.ll
time="2023-01-31T15:04:18Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_generic_retkprobe_v53.ll
time="2023-01-31T15:04:18Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_generic_retkprobe_v61.ll
time="2023-01-31T15:04:18Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_generic_tracepoint.ll
time="2023-01-31T15:04:18Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_generic_tracepoint_v53.ll
time="2023-01-31T15:04:18Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_generic_tracepoint_v61.ll
time="2023-01-31T15:04:18Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_generic_uprobe.ll
time="2023-01-31T15:04:18Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_generic_uprobe_v53.ll
time="2023-01-31T15:04:19Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_generic_uprobe_v61.ll
time="2023-01-31T15:04:19Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_globals.ll
time="2023-01-31T15:04:19Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_killer.ll
time="2023-01-31T15:04:19Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_loader.ll
time="2023-01-31T15:04:19Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_lseek.ll
time="2023-01-31T15:04:19Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_multi_killer.ll
time="2023-01-31T15:04:19Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_multi_kprobe_v53.ll
time="2023-01-31T15:04:19Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_multi_kprobe_v61.ll
time="2023-01-31T15:04:19Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_multi_retkprobe_v53.ll
time="2023-01-31T15:04:19Z" level=warning msg="not an object file, ignoring" path=/xdata/objs/bpf_multi_retkprobe_v61.ll
time="2023-01-31T15:04:19Z" level=warning msg="no btf filename in tetragon config, attempting to fall back to /sys/kernel/btf/vmlinux"
time="2023-01-31T15:04:20Z" level=info msg="btf file added" btfFname=/sys/kernel/btf/vmlinux
time="2023-01-31T15:04:20Z" level=info msg="tetragon log file added" exportFname=/xdata/log/tetragon/tetragon.log
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd=/usr/bin/dmesg dstFname=dmesg.out ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/sbin/tc filter show dev lo ingress" dstFname=tc-info.lo.ingress ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/sbin/tc filter show dev lo egress" dstFname=tc-info.lo.egress ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/sbin/tc filter show dev dummy0 ingress" dstFname=tc-info.dummy0.ingress ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/sbin/tc filter show dev dummy0 egress" dstFname=tc-info.dummy0.egress ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/sbin/tc filter show dev mgbe0_0 ingress" dstFname=tc-info.mgbe0_0.ingress ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/sbin/tc filter show dev mgbe0_0 egress" dstFname=tc-info.mgbe0_0.egress ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/sbin/tc filter show dev mgbe1_0 ingress" dstFname=tc-info.mgbe1_0.ingress ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/sbin/tc filter show dev mgbe1_0 egress" dstFname=tc-info.mgbe1_0.egress ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/sbin/tc filter show dev mgbe3_0 ingress" dstFname=tc-info.mgbe3_0.ingress ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/sbin/tc filter show dev mgbe3_0 egress" dstFname=tc-info.mgbe3_0.egress ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/sbin/tc filter show dev mgbe3_0.2 ingress" dstFname=tc-info.mgbe3_0.2.ingress ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/sbin/tc filter show dev mgbe3_0.2 egress" dstFname=tc-info.mgbe3_0.2.egress ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/local/bin/bpftool map show -j" dstFname=bpftool-maps.json ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/local/bin/bpftool prog show -j" dstFname=bpftool-progs.json ret=0
time="2023-01-31T15:04:20Z" level=info msg="executed command" cmd="/usr/local/bin/bpftool cgroup tree -j" dstFname=bpftool-cgroups.json ret=0
time="2023-01-31T15:04:20Z" level=warning msg="failed to open policyfilter map" error="no such file or directory"
time="2023-01-31T15:04:20Z" level=info msg="dumped tracing policies in tracing-policies.json"



### Anything else?

_No response_

Jiahao0 avatar Nov 03 '23 08:11 Jiahao0

Thank you for the report. This character (�) is used for non-utf8 names.

Could you please also provide bugtool info? (see: https://tetragon.io/docs/troubleshooting/#single-node-bugtool)

kkourt avatar Nov 03 '23 14:11 kkourt

OK, I see. Does it mean I need to do some cfgs to resolve it? If yes, how? Bugtool output has already been attached : tetragon-bugtool.tar.gz Pls have a look. Thanks.

Jiahao0 avatar Nov 06 '23 06:11 Jiahao0

OK, I see. Does it mean I need to do some cfgs to resolve it? If yes, how?

Currently, there is no support for non-utf8 binary names. non-utf8 characters will be transformed to "�". Are you using binaries with non-utf8 names in your tests?

kkourt avatar Nov 06 '23 08:11 kkourt

I google a bit on this. According to this ticket, the locale shows that the bin names are utf-8 coding.

root@tegra-ubuntu:/xdata/linux-tarball# locale
LANG=C.UTF-8
LANGUAGE=
LC_CTYPE="C.UTF-8"
LC_NUMERIC=C.UTF-8
LC_TIME=C.UTF-8
LC_COLLATE="C.UTF-8"
LC_MONETARY=C.UTF-8
LC_MESSAGES="C.UTF-8"
LC_PAPER=C.UTF-8
LC_NAME=C.UTF-8
LC_ADDRESS=C.UTF-8
LC_TELEPHONE=C.UTF-8
LC_MEASUREMENT=C.UTF-8
LC_IDENTIFICATION=C.UTF-8
LC_ALL=

Could you show the result of your environment? Any other ideas?

Tks.

Jiahao0 avatar Nov 08 '23 09:11 Jiahao0

I believe this is not related to the locale, but the filenames which do not necessarily have to follow whatever locale is defined in the environment.

kkourt avatar Nov 17 '23 09:11 kkourt

Could you provide a way to reproduce this easily? E.g., in a new vm environment or in a kind/minikube cluster?

kkourt avatar Nov 17 '23 09:11 kkourt

Having similar issue with plain CentOS 9, newest Kubeadm-managed Kubernetes cluster.

{"process_exit":{"process":{"exec_id":"dGVhY2hlci10ZXN0LXdvcmtlci5jbG91ZC51dC5lZTo2OTc0MTQ5MzI0MjUzMTg6MTAzMDU1NQ==","pid":1030555,"uid":0,"cwd":"/","binary":"/ �ڻk�","arguments":"version --client-only","flags":"execve rootcwd","start_time":"2023-11-28T14:43:42.727402141Z","auid":4294967295,"pod":{"namespace":"longhorn-system","name":"engine-image-ei-74783864-wj6pl","container":{"id":"containerd://136093d23ab1c373eb6b70ddca20a9c266d8df91382133e2b67e65f68d31a808","name":"engine-image-ei-74783864","image":{"id":"docker.io/longhornio/longhorn-engine@sha256:a2f4482d486a3b6cbfda7247cbd076b6b4c5b6f4a001b69bbbca174c4e77c75e","name":"docker.io/longhornio/longhorn-engine:v1.5.1"},"start_time":"2023-11-20T13:01:28Z","pid":3373084},"pod_labels":{"controller-revision-hash":"6bd96794d5","longhorn.io/component":"engine-image","longhorn.io/engine-image":"ei-74783864","pod-template-generation":"1"},"workload":"engine-image-ei-74783864","workload_kind":"DaemonSet"},"docker":"136093d23ab1c373eb6b70ddca20a9c","parent_exec_id":"dGVhY2hlci10ZXN0LXdvcmtlci5jbG91ZC51dC5lZTo2OTc0MTQ5Mjg1MzE4MzE6MTAzMDU1NQ==","tid":1030555},"parent":{"exec_id":"dGVhY2hlci10ZXN0LXdvcmtlci5jbG91ZC51dC5lZTo2OTc0MTQ5Mjg1MzE4MzE6MTAzMDU1NQ==","pid":1030555,"uid":0,"cwd":"/","binary":"/ �ʻk�","arguments":"-c \"/data/longhorn version --client-only\"","flags":"execve rootcwd clone","start_time":"2023-11-28T14:43:42.723509007Z","auid":4294967295,"pod":{"namespace":"longhorn-system","name":"engine-image-ei-74783864-wj6pl","container":{"id":"containerd://136093d23ab1c373eb6b70ddca20a9c266d8df91382133e2b67e65f68d31a808","name":"engine-image-ei-74783864","image":{"id":"docker.io/longhornio/longhorn-engine@sha256:a2f4482d486a3b6cbfda7247cbd076b6b4c5b6f4a001b69bbbca174c4e77c75e","name":"docker.io/longhornio/longhorn-engine:v1.5.1"},"start_time":"2023-11-20T13:01:28Z","pid":3373084},"pod_labels":{"controller-revision-hash":"6bd96794d5","longhorn.io/component":"engine-image","longhorn.io/engine-image":"ei-74783864","pod-template-generation":"1"},"workload":"engine-image-ei-74783864","workload_kind":"DaemonSet"},"docker":"136093d23ab1c373eb6b70ddca20a9c","parent_exec_id":"dGVhY2hlci10ZXN0LXdvcmtlci5jbG91ZC51dC5lZTo2OTc0MTQ4OTE1ODI5MTE6MTAzMDU0NQ==","tid":1030555},"time":"2023-11-28T14:43:42.744176273Z"},"node_name":"teacher-test-worker","time":"2023-11-28T14:43:42.744196597Z"}

The binary names get completely mangled, in more events than not. (it's a tiny teaching cluster).

This happens in all outputs, the in-container CLI, container stdout and logs on the filesystem.

Eilyre avatar Nov 28 '23 15:11 Eilyre

Could you provide a way to reproduce this easily? E.g., in a new vm environment or in a kind/minikube cluster?

Sorry, I can't provide that. I'm running it in embedded environment. More info: only part of the commands have the issue, others are good.

📬 open     /usr/lib/systemd/systemd-journald /proc/660/cmdline           
📬 open     /usr/lib/systemd/systemd-journald /proc/660/status            
📬 open     /usr/lib/systemd/systemd-journald /proc/660/attr/current      
🚀 process  /�`� /var/lib/nv-rtc/timesync/clock                      
📬 open     /usr/lib/systemd/systemd-journald /proc/660/sessionid         
📬 open     /usr/lib/systemd/systemd-journald /proc/660/loginuid          
📬 open     /usr/lib/systemd/systemd-journald /proc/660/cgroup            
📬 open     /�`� /etc/ld.so.cache                                    
📬 open     /�`� /usr/lib/aarch64-linux-gnu/libc-2.31.so             
📬 open     /�`� /usr/lib/locale/C.UTF-8/LC_IDENTIFICATION

Jiahao0 avatar Dec 05 '23 03:12 Jiahao0

I just merged https://github.com/cilium/tetragon/pull/1902 which might be related to those, not exactly sure but this is plausible!

mtardy avatar Jan 03 '24 15:01 mtardy

@Jiahao0 could try the latest development image and see whether #1902 address the issue?

kkourt avatar Jan 10 '24 17:01 kkourt

Hello, also had same problem on v1.0.0 and still facing it on a fresh Rocky9 and tetragon v1.0.2:

{"process_exec":{"process":{"exec_id":"OjEyNzQwNzc3Njg0NTI6NDYwNg==", "pid":4606, "uid":0, "cwd":"/opt/tetragon/tetragon-v1.0.2-amd64", "binary":"/opt/tetragon/tetragon-v1.0.2-amd64/ �\u0002�\u001f�", "arguments":"-f /var/log/tetragon/tetragon.log", "flags":"execve clone", "start_time":"2024-03-26T22:43:16.858360824Z", "auid":1000, "parent_exec_id":"OjQ0ODI5MDAwMDAwMDo0NDIx", "tid":4606}, "parent":{"exec_id":"OjQ0ODI5MDAwMDAwMDo0NDIx", "pid":4421, "uid":0, "cwd":"/opt/tetragon/tetragon-v1.0.2-amd64", "binary":"/usr/bin/bash", "flags":"procFS auid", "start_time":"2024-03-26T22:29:31.070592352Z", "auid":1000, "parent_exec_id":"OjQ0NTk0MDAwMDAwMDo0NDE3", "tid":4421}}, "time":"2024-03-26T22:43:16.858360774Z"}

Linux rocky9 5.14.0-362.24.1.el9_3.x86_64 tetragon-v1.0.2-amd64

tetragon-bugtool.tar.gz

genie-zs avatar Mar 26 '24 20:03 genie-zs

Good day, I have the same issue in different machines. I tried with 1.0.2 and 1.0.3. Both showed the same behavior. Freshly installed as a package.

{"process_exit":{"process":{"exec_id":"OjEyMjE5NDc3MTU2ODUwODoxODU5MTM=","pid":185913,"uid":0,"cwd":"/var/lib/docker/overlay2/d6be236c8e2da58f9fda1b6f04729472cf60a58c2175076fb7672dc0588950a8/merged","binary":"/var/lib/docker/overlay2/d6be236c8e2da58f9fda1b6f04729472cf60a58c2175076fb7672dc0588950a8/merged/ �B�9�","arguments":"init","flags":"execve","start_time":"2024-04-20T09:19:39.897114063Z","auid":4294967295,"parent_exec_id":"OjEyMjE5NDc2OTE4MDUwMzoxODU5MTM=","tid":185913},"parent":{"exec_id":"OjEyMjE5NDc2OTE4MDUwMzoxODU5MTM=","pid":185913,"uid":0,"cwd":"/var/lib/docker/overlay2/d6be236c8e2da58f9fda1b6f04729472cf60a58c2175076fb7672dc0588950a8/merged","binary":"/var/lib/docker/overlay2/d6be236c8e2da58f9fda1b6f04729472cf60a58c2175076fb7672dc0588950a8/merged/ �Z�9�","arguments":"init","flags":"execve clone","start_time":"2024-04-20T09:19:39.894725398Z","auid":4294967295,"parent_exec_id":"OjEyMjE5NDc2NDQwNjA2OToxODU5MDU=","tid":185913},"time":"2024-04-20T09:19:39.899325452Z"},"time":"2024-04-20T09:19:39.899325117Z"}

Rocky Linux release 9.3 (Blue Onyx) Linux pod1 5.14.0-362.24.1.el9_3.0.1.x86_64 #1 SMP PREEMPT_DYNAMIC Thu Apr 4 22:31:43 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux

Also in Almalinux. tetragon-bugtool.tar.gz

These are the locale settings [adminx@pod1 ~]$ localectl System Locale: LANG=en_US.UTF-8 VC Keymap: es X11 Layout: es,es X11 Variant: ,winkeys

gnakh avatar Apr 20 '24 09:04 gnakh

Attempted on latest by following commands below and still had issues

 helm install \                                       
    --namespace kube-system \
    --set tetragon.image.override=quay.io/cilium/tetragon-ci:latest \
    --set tetragonOperator.image.override=quay.io/cilium/tetragon-operator-ci:latest \
    tetragon ./install/kubernetes/tetragon

tetragon-bugtool.tar.gz

bck01215 avatar Apr 25 '24 19:04 bck01215

Thanks everyone for this report! Manged to reproduce this and I believe I have a fix: https://github.com/cilium/tetragon/pull/2399.

kkourt avatar Apr 29 '24 19:04 kkourt