Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Failed to find a process in proc_info_map #3914

Closed
yanivagman opened this issue Mar 12, 2024 · 1 comment · Fixed by #3918
Closed

Failed to find a process in proc_info_map #3914

yanivagman opened this issue Mar 12, 2024 · 1 comment · Fixed by #3918
Assignees
Labels
Milestone

Comments

@yanivagman
Copy link
Collaborator

Description

In environments with a big amount of CPUs (96 CPUs) we got the following warnings:

"{"level":"warn","ts":1695678822.5690784,"msg":"Failed to find a map element","id":2,"type":"BPF_LOG_ID_MAP_LOOKUP_ELEM","ret":0,"cpu":82,"file":"./pkg/ebpf/c/tracee.bpf.c","line":603,"count":1}

"{"level":"warn","ts":1710099814.7776074,"msg":"Failed to find a map element","id":2,"type":"BPF_LOG_ID_MAP_LOOKUP_ELEM","ret":0,"cpu":70,"file":"./pkg/ebpf/c/tracee.bpf.c","line":695,"count":1}

These warnings then repeat themselves a lot of times.

Output of tracee version:

v0.11.1

Output of uname -a:

(paste your output here)

Additional details

It seems that in such environments the current map size of 10240 entries is not enough, and gets filled quickly.
A quick mitigation then will be to set a bigger map size.

The root cause of this issue is that we assume that if task_info exists for some task in the task_info_map, then also the proc_info of the process to which the task belongs to also has an entry in the map, but that is not the case.
So the real fix to this issue will be to change all the places that try to get an entry from proc_info_map and make this assumption. Instead, we should reinitialize proc_info_t with the matching pid. One problem to implement the reinitialization is that we already lost some of the information like if it was a "new process", the binary name and for which scopes this process should be followed (used by the follow filter).

@yanivagman yanivagman added this to the v0.21.0 milestone Mar 12, 2024
@geyslan
Copy link
Member

geyslan commented Mar 12, 2024

It is reproducible when decreasing proc_info_map to 100 entries (for example):

sudo ./dist/tracee -e sched_process_exec
TIME             UID    COMM             PID     TID     RET              EVENT                     ARGS
14:07:18:109802  1000   sed              3028873 3028873 0                sched_process_exec        cmdpath: /usr/bin/sed, pathname: /usr/bin/sed, dev: 271581187, inode: 14943488, ctime: 1704474426733346008, inode_mode: 33261, interpreter_pathname: /usr/lib/ld-linux-x86-64.so.2, interpreter_dev: 271581187, interpreter_inode: 14953455, interpreter_ctime: 1708634766762078251, argv: [sed -n s/^cpu\s//p /proc/stat], interp: /usr/bin/sed, stdin_type: S_IFSOCK, stdin_path: UNIX-STREAM, invoked_from_kernel: 0, env: <nil>
{"level":"warn","ts":1710263238.1111948,"msg":"Failed to find a map element","id":2,"type":"BPF_LOG_ID_MAP_LOOKUP_ELEM","ret":0,"cpu":11,"file":"./pkg/ebpf/c/tracee.bpf.c","line":531,"count":1}
{"level":"warn","ts":1710263238.1115654,"msg":"Failed to find a map element","id":2,"type":"BPF_LOG_ID_MAP_LOOKUP_ELEM","ret":0,"cpu":0,"file":"./pkg/ebpf/c/tracee.bpf.c","line":1233,"count":1}
{"level":"warn","ts":1710263238.1120112,"msg":"Failed to find a map element","id":2,"type":"BPF_LOG_ID_MAP_LOOKUP_ELEM","ret":0,"cpu":3,"file":"./pkg/ebpf/c/tracee.bpf.c","line":531,"count":1}
{"level":"warn","ts":1710263238.1126502,"msg":"Failed to find a map element","id":2,"type":"BPF_LOG_ID_MAP_LOOKUP_ELEM","ret":0,"cpu":8,"file":"./pkg/ebpf/c/tracee.bpf.c","line":1233,"count":1}
{"level":"warn","ts":1710263238.1134667,"msg":"Failed to find a map element","id":2,"type":"BPF_LOG_ID_MAP_LOOKUP_ELEM","ret":0,"cpu":4,"file":"./pkg/ebpf/c/tracee.bpf.c","line":531,"count":1}
{"level":"warn","ts":1710263238.1137593,"msg":"Failed to find a map element","id":2,"type":"BPF_LOG_ID_MAP_LOOKUP_ELEM","ret":0,"cpu":5,"file":"./pkg/ebpf/c/tracee.bpf.c","line":1233,"count":1}
14:07:18:617060  1000   docker           3028880 3028880 0                sched_process_exec        cmdpath: /usr/bin/docker, pathname: /usr/bin/docker, dev: 271581187, inode: 14967037, ctime: 1710188848527547782, inode_mode: 33261, interpreter_pathname: /usr/lib/ld-linux-x86-64.so.2, interpreter_dev: 271581187, interpreter_inode: 14953455, interpreter_ctime: 1708634766762078251, argv: [docker context ls --format {{json .}}], interp: /usr/bin/docker, stdin_type: S_IFSOCK, stdin_path: UNIX-STREAM, invoked_from_kernel: 0, env: <nil>
14:07:18:745352  0      nmcli            3028889 3028889 0                sched_process_exec        cmdpath: /usr/bin/nmcli, pathname: /usr/bin/nmcli, dev: 271581187, inode: 14973392, ctime: 1710188855744427510, inode_mode: 33261, interpreter_pathname: /usr/lib/ld-linux-x86-64.so.2, interpreter_dev: 271581187, interpreter_inode: 14953455, interpreter_ctime: 1708634766762078251, argv: [nmcli --terse --fields active,ssid,bssid,mode,chan,freq,signal,security,wpa-flags,rsn-flags,device device wifi], interp: /usr/bin/nmcli, stdin_type: S_IFSOCK, stdin_path: UNIX-STREAM, invoked_from_kernel: 0, env: <nil>
{"level":"warn","ts":1710263240.6293547,"msg":"Failed to find a map element","id":2,"type":"BPF_LOG_ID_MAP_LOOKUP_ELEM","ret":0,"cpu":24,"file":"./pkg/ebpf/c/tracee.bpf.c","line":531,"count":1}
{"level":"warn","ts":1710263240.636572,"msg":"Failed to find a map element","id":2,"type":"BPF_LOG_ID_MAP_LOOKUP_ELEM","ret":0,"cpu":6,"file":"./pkg/ebpf/c/tracee.bpf.c","line":1233,"count":1}
{"level":"warn","ts":1710263240.6382625,"msg":"Failed to find a map element","id":2,"type":"BPF_LOG_ID_MAP_LOOKUP_ELEM","ret":0,"cpu":6,"file":"./pkg/ebpf/c/tracee.bpf.c","line":531,"count":1}
{"level":"warn","ts":1710263240.6384227,"msg":"Failed to find a map element","id":2,"type":"BPF_LOG_ID_MAP_LOOKUP_ELEM","ret":0,"cpu":26,"file":"./pkg/ebpf/c/tracee.bpf.c","line":531,"count":1}
{"level":"warn","ts":1710263240.6406047,"msg":"Failed to find a map element","id":2,"type":"BPF_LOG_ID_MAP_LOOKUP_ELEM","ret":0,"cpu":29,"file":"./pkg/ebpf/c/tracee.bpf.c","line":531,"count":1}
{"level":"warn","ts":1710263240.6406913,"msg":"Failed to find a map element","id":2,"type":"BPF_LOG_ID_MAP_LOOKUP_ELEM","ret":0,"cpu":5,"file":"./pkg/ebpf/c/tracee.bpf.c","line":531,"count":1}
14:07:21:755254  1000   sh               3028903 3028903 0                sched_process_exec        cmdpath: /bin/sh, pathname: /usr/bin/bash, dev: 271581187, inode: 14942358, ctime: 1708634769445470347, inode_mode: 33261, interpreter_pathname: /usr/lib/ld-linux-x86-64.so.2, interpreter_dev: 271581187, interpreter_inode: 14953455, interpreter_ctime: 1708634766762078251, argv: [/bin/sh -c which ps], interp: /bin/sh, stdin_type: S_IFSOCK, stdin_path: UNIX-STREAM, invoked_from_kernel: 0, env: <nil>
14:07:21:756811  1000   which            3028903 3028903 0                sched_process_exec        cmdpath: /usr/bin/which, pathname: /usr/bin/which, dev: 271581187, inode: 14943707, ctime: 1704474426940012677, inode_mode: 33261, interpreter_pathname: /usr/lib/ld-linux-x86-64.so.2, interpreter_dev: 271581187, interpreter_inode: 14953455, interpreter_ctime: 1708634766762078251, argv: [which ps], interp: /usr/bin/which, stdin_type: S_IFSOCK, stdin_path: UNIX-STREAM, invoked_from_kernel: 0, env: <nil>

yanivagman added a commit to yanivagman/tracee that referenced this issue Mar 14, 2024
In environments with a high amount of CPUs the current proc_info map
size of 10240 entries might not be enough, and gets filled quickly.
In these cases we got an error of missing proc_info entry.

A quick mitigation then will be to set a bigger map size.

The root cause of this issue is that we assume that if task_info exists
for some task in the task_info_map, then also the proc_info of the
process to which the task belongs to also has an entry in the map,
but that is not the case.

To fix this issue, add proc_info lookup and initialization in
init_program_data() function. In addition, init proc_info of the
relevant pid in case it was not found in other places.

Fix: aquasecurity#3914
@yanivagman yanivagman linked a pull request Mar 14, 2024 that will close this issue
yanivagman added a commit to yanivagman/tracee that referenced this issue Mar 14, 2024
In environments with a high amount of CPUs the current proc_info map
size of 10240 entries might not be enough, and gets filled quickly.
In these cases we got an error of missing proc_info entry.

A quick mitigation then will be to set a bigger map size.

The root cause of this issue is that we assume that if task_info exists
for some task in the task_info_map, then also the proc_info of the
process to which the task belongs to also has an entry in the map,
but that is not the case.

To fix this issue, add proc_info lookup and initialization in
init_program_data() function. In addition, init proc_info of the
relevant pid in case it was not found in other places.

Fix: aquasecurity#3914
yanivagman added a commit that referenced this issue Mar 14, 2024
In environments with a high amount of CPUs the current proc_info map
size of 10240 entries might not be enough, and gets filled quickly.
In these cases we got an error of missing proc_info entry.

A quick mitigation then will be to set a bigger map size.

The root cause of this issue is that we assume that if task_info exists
for some task in the task_info_map, then also the proc_info of the
process to which the task belongs to also has an entry in the map,
but that is not the case.

To fix this issue, add proc_info lookup and initialization in
init_program_data() function. In addition, init proc_info of the
relevant pid in case it was not found in other places.

Fix: #3914
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants