fd.name some times contain bogus <UNKNOWN> part in "Write below root" event #1892

petterreinholdtsen · 2024-02-27T13:39:26Z

Some times the events from sandbox rule "Write below root" contain a incomplete path, making it hard to know the location of the file in question. This is an example message:

"14:27:16.402853438: Error File below / or /root opened for writing (file=<UNKNOWN>cf_lock.lmdb.lock evt_type=openat user=root user_uid=0 user_loginuid=-1 process=cf-agent proc_exepath=/usr/bin/cf-agent parent=cf-execd command=cf-agent terminal=0 exe_flags=O_RDWR container_id=host container_name=host)",

The process triggering the event is cfengine with its lock file, and in other similar events the fd.name value is "//cf_lock.lmdb.lock", so I suspect the real value of the <UNKNOWN> part should be "/".

This is running on a RHEL 9.3 machine using the "modern" ebpf probe, with a setup where all rule sets from https://github.com/falcosecurity/rules/ are enabled. The machine uses cfengine to keep the setup correct and up to date.

I expected fd.name to contain a full path to the opened file, and suspect there is a bug somewhere causing the <UNKNOWN> part.

Falco version: 0.37.1

Tue Feb 27 14:35:54 2024: Falco version: 0.37.1 (x86_64)
Tue Feb 27 14:35:54 2024: Falco initialized with configuration file: /etc/falco/falco.yaml
Tue Feb 27 14:35:54 2024: System info: Linux version 5.14.0-284.11.1.el9_2.x86_64 ([email protected]) (gcc (GCC) 11.3.1 20221121 (Red Hat 11.3.1-4), GNU ld version 2.35.2-37.el9) falcosecurity/falco#1 SMP PREEMPT_DYNAMIC Wed Apr 12 10:45:03 EDT 2023
{"default_driver_version":"7.0.0+driver","driver_api_version":"8.0.0","driver_schema_version":"2.0.0","engine_version":"31","engine_version_semver":"0.31.0","falco_version":"0.37.1","libs_version":"0.14.3","plugin_api_version":"3.2.0"}

System info:

Tue Feb 27 14:36:59 2024: Falco version: 0.37.1 (x86_64)
Tue Feb 27 14:36:59 2024: Falco initialized with configuration file: /etc/falco/falco.yaml
Tue Feb 27 14:36:59 2024: System info: Linux version 5.14.0-284.11.1.el9_2.x86_64 ([email protected]) (gcc (GCC) 11.3.1 20221121 (Red Hat 11.3.1-4), GNU ld version 2.35.2-37.el9) falcosecurity/falco#1 SMP PREEMPT_DYNAMIC Wed Apr 12 10:45:03 EDT 2023
Tue Feb 27 14:36:59 2024: Loading rules from file /etc/falco/rules.d/01-falco-incubating_rules.yaml
Tue Feb 27 14:36:59 2024: Loading rules from file /etc/falco/rules.d/01-falco-sandbox_rules.yaml
Tue Feb 27 14:36:59 2024: Loading rules from file /etc/falco/rules.d/01-falco_rules.yaml
Tue Feb 27 14:36:59 2024: Loading rules from file /etc/falco/rules.d/60-nidhogg.yaml
Tue Feb 27 14:36:59 2024: /etc/falco/rules.d/60-nidhogg.yaml: Ok, with warnings
1 Warnings:
In rules content: (/etc/falco/rules.d/60-nidhogg.yaml:0:0)
    macro 'allowed_tmp_files': (/etc/falco/rules.d/60-nidhogg.yaml:41:2)
------
- macro: allowed_tmp_files
  ^
------
LOAD_UNUSED_MACRO (Unused macro): Macro not referred to by any other rule/macro

Tue Feb 27 14:36:59 2024: Loading rules from file /etc/falco/rules.d/99-settings.yaml
Tue Feb 27 14:36:59 2024: /etc/falco/rules.d/99-settings.yaml: Ok, with warnings
1 Warnings:
In rules content: (/etc/falco/rules.d/60-nidhogg.yaml:0:0)
    macro 'allowed_tmp_files': (/etc/falco/rules.d/60-nidhogg.yaml:41:2)
------
- macro: allowed_tmp_files
  ^
------
LOAD_UNUSED_MACRO (Unused macro): Macro not referred to by any other rule/macro

{
  "machine": "x86_64",
  "nodename": "soria.uio.no",
  "release": "5.14.0-284.11.1.el9_2.x86_64",
  "sysname": "Linux",
  "version": "#1 SMP PREEMPT_DYNAMIC Wed Apr 12 10:45:03 EDT 2023"
}

Cloud provider or hardware configuration:
OS: Red Hat Enterprise Linux 9.3
Kernel: Linux some-host 5.14.0-284.11.1.el9_2.x86_64 Digwatch compiler falco#1 SMP PREEMPT_DYNAMIC Wed Apr 12 10:45:03 EDT 2023 x86_64 x86_64 x86_64 GNU/Linux
Installation method: RPM

The text was updated successfully, but these errors were encountered:

incertum · 2024-02-28T05:32:20Z

Thanks @petterreinholdtsen:

Just to clarify

Some times the events from sandbox rule "Write below root" contain a incomplete path

is truly sometimes, not all the times?

Would you mind observing again with the following additional output fields? %fd.nameraw %fs.path.name %fs.path.nameraw %proc.cwd (https://falco.org/docs/reference/rules/supported-fields/) -> are all of these fields missing?

In addition, is it some new issues or have you observed this before in Falco? Plus could you check if you have a decent amount of dropped open* syscalls leveraging https://falco.org/docs/metrics/falco-metrics/, see also https://falco.org/docs/troubleshooting/dropping/.

petterreinholdtsen · 2024-02-28T11:45:08Z

[Melissa Kilby]

is truly sometimes, not all the times?

Yes. Here is an example with // instead of <UNKNOWN>: 12:26:02.996402180: Error File below / or /root opened for writing (file=//cf_lock.lmdb.lock evt_type=openat user=root user_uid=0 user_loginuid=-1 process=cf-agent proc_exepath=/usr/bin/cf-agent parent=cf-execd command=cf-agent terminal=0 exe_flags=O_RDWR container_id=host container_name=host) This is on the same machine.

Would you mind observing again with the following additional output fields? `%fd.nameraw %fs.path.name %fs.path.nameraw %proc.cwd` (https://falco.org/docs/reference/rules/supported-fields/) -> are all of these fields missing?

I will see what I can do. I do not have direct access to any of the problematic machines, only the logs from them, but will try to figure out a way to test a modified setup one one of the machines with this behavior.

In addition, is it some new issues or have you observed this before in Falco? Plus could you check if you have a decent amount of dropped `open*` syscalls leveraging https://falco.org/docs/metrics/falco-metrics/, see also https://falco.org/docs/troubleshooting/dropping/.

In total for the last event bulk I see 18 "Falco internal: syscall event drop" events across 5 machines and 8000 events. All of them happened on one of the machines with the <UNKNOWN> path, but the <UNKNOWN> path show up on more than one machine.

…

-- Happy hacking Petter Reinholdtsen

incertum · 2024-02-29T18:12:59Z

@petterreinholdtsen would it be possible to instead use the new https://falco.org/docs/metrics/falco-metrics/ framework as it supports monotonic counters? That way we know more accurately how many dropped events there are since the beginning of launching Falco and more. Thanks!

Looking forward to hearing back from you in regards to the other fields %fd.nameraw %fs.path.name %fs.path.nameraw %proc.cwd.

petterreinholdtsen · 2024-03-04T09:59:00Z

[Melissa Kilby]

@petterreinholdtsen would it be possible to instead use the new https://falco.org/docs/metrics/falco-metrics/ framework as it supports monotonic counters?

I am reluctant to add this to all our hosts, as we try to reduce the noise and number of irrelevant events in the log, and the metrics seem add regular quite a lot of "non-events' to the log.

Looking forward to hearing back from you in regards to the other fields `%fd.nameraw %fs.path.name %fs.path.nameraw %proc.cwd`.

This change rolled out this weekend, and here are a few example log events, one with <UNKNOWN> and one with a more path like file value. Error File below / or /root opened for writing (file=<UNKNOWN>cf_lock.lmdb.lock nameraw=cf_lock.lmdb.lock pathname=/etc/sssd/cf_lock.lmdb.lock pathnameraw=cf_lock.lmdb.lock proccwd=/etc/sssd/ evt_type=openat user=root user_uid=0 user_loginuid=-1 process=cf-agent proc_exepath=/usr/bin/cf-agent parent=cf-execd command=cf-agent terminal=0 exe_flags=O_RDWR container_id=host container_name=host) Error File below / or /root opened for writing (file=//cf_lock.lmdb.lock nameraw=cf_lock.lmdb.lock pathname=/var/cfengine/state/cf_lock.lmdb.lock pathnameraw=cf _lock.lmdb.lock proccwd=/var/cfengine/state/ evt_type=openat user=root user_uid=0 user_loginuid=-1 pr ocess=cf-agent proc_exepath=/usr/bin/cf-agent parent=cf-execd command=cf-agent terminal=0 exe_flags=O _RDWR container_id=host container_name=host)

…

-- Happy hacking Petter Reinholdtsen

petterreinholdtsen · 2024-03-04T12:06:04Z

[Petter Reinholdtsen]

This change rolled out this weekend, and here are a few example log events, one with <UNKNOWN> and one with a more path like file value.

Perhaps the relevant difference is the file permission of the cwd directory? drwx------. 1 root root 36 jan. 12 01:00 /etc/sssd/ drwxr-xr-x. 1 root root 318 jan. 18 12:37 /var/cfengine/ Even with the latter, '//' seem like the wrong path.

…

-- Happy hacking Petter Reinholdtsen

incertum · 2024-03-04T18:48:22Z

Re https://falco.org/docs/metrics/falco-metrics/ you can adjust the timer aka how often you want to emit a log. Just FYI.

Error File below / or /root opened for writing
(file=cf_lock.lmdb.lock nameraw=cf_lock.lmdb.lock
pathname=/etc/sssd/cf_lock.lmdb.lock pathnameraw=cf_lock.lmdb.lock
proccwd=/etc/sssd/ evt_type=openat user=root user_uid=0
user_loginuid=-1 process=cf-agent proc_exepath=/usr/bin/cf-agent
parent=cf-execd command=cf-agent terminal=0 exe_flags=O_RDWR
container_id=host container_name=host)

Thank you for deploying the additional output fields 🙏 !

@LucaGuerra and @FedeDP given that pathname=/etc/sssd/cf_lock.lmdb.lock is correct (using the same new custom path concatenation method) something must be wonky wrt to how we store the cwd to then concat the path for fd.name since for the fs.path filters we fetch the args directly. Or something else in the fd. filtercheck logic could be wonky.

@petterreinholdtsen this needs a patch in Falco's libs, ETA unknown and we should consider releasing a patch release. We will keep you updated. @falcosecurity/falco-maintainers @leogr

incertum · 2024-03-05T03:12:51Z

Given your examples above #1892 effectively the derivation of fd.name is more sophisticated and perhaps fs.path.name is actually wrong here. fs.path.name always concatenates the proc.cwd and the raw open* syscall arg wrt to opening a file, but it may be inaccurate. In addition, assuming cf_lock.lmdb.lock in both logs you shared are at the same location you see that the full path is different when looking at fs.path.name.

CC @FedeDP who shared a similar assessment. In summary, I am not sure if there is something to fix easily. At the same time if fs.path.name is wrong we should do something about that and try to make them equal?

@petterreinholdtsen did you observe a regression between release or is this just a new observation? Furthermore, could you check for example what the true location of cf_lock.lmdb.lock is on your system? Percentage wise how rare is the observation of <UNKNOWN> or // at the beginning?

Code in question:

libs/userspace/libsinsp/sinsp_filtercheck_event.cpp

Lines 553 to 573 in 600976e

    
           else 
        
           { 
        
           	evt->set_fd_info(evt->get_tinfo()->get_fd(dirfd)); 
        
           	if(evt->get_fd_info() == NULL) 
        
           	{ 
        
           		ASSERT(false); 
        
           		sdir = "<UNKNOWN>/"; 
        
           	} 
        
           	else 
        
           	{ 
        
           		if(evt->get_fd_info()->m_name[evt->get_fd_info()->m_name.length()] == '/') 
        
           		{ 
        
           			sdir = evt->get_fd_info()->m_name; 
        
           		} 
        
           		else 
        
           		{ 
        
           			sdir = evt->get_fd_info()->m_name + '/'; 
        
           		} 
        
           	} 
        
           }

libs/userspace/libsinsp/parsers.cpp

Line 2501 in 600976e

* - if we have no information about `dirfd` -> sdir = "<UNKNOWN>".
libs/userspace/libsinsp/sinsp_filtercheck_fspath.cpp

Line 354 in 600976e

m_tstr = sinsp_utils::concatenate_paths(tinfo->get_cwd(), m_tstr);

More references:

https://man7.org/linux/man-pages/man3/dirfd.3.html

poiana · 2024-06-03T03:53:26Z

Issues go stale after 90d of inactivity.

Mark the issue as fresh with /remove-lifecycle stale.

Stale issues rot after an additional 30d of inactivity and eventually close.

If this issue is safe to close now please do so with /close.

Provide feedback via https://github.com/falcosecurity/community.

/lifecycle stale

petterreinholdtsen · 2024-06-03T06:35:42Z

[Melissa Kilby]

@petterreinholdtsen did you observe a regression between release or is this just a new observation? Furthermore, could you check for example what the true location of `cf_lock.lmdb.lock` is on your system? Percentage wise how rare is the observation of `<UNKNOWN>` or `//` at the beginning?

I just noticed in during testing. Do not know how often it happen.

…

-- Happy hacking Petter Reinholdtsen

leogr · 2024-06-04T08:09:49Z

/remove-lifecycle stale

This issue should be fixed in libs. I'm transferring this issue to the libs repo.

leogr · 2024-06-04T08:10:36Z

cc @FedeDP @Andreagit97

poiana · 2024-09-02T10:10:28Z

Issues go stale after 90d of inactivity.

Mark the issue as fresh with /remove-lifecycle stale.

Stale issues rot after an additional 30d of inactivity and eventually close.

If this issue is safe to close now please do so with /close.

Provide feedback via https://github.com/falcosecurity/community.

/lifecycle stale

petterreinholdtsen · 2024-09-02T10:27:06Z

I'm still waiting for a resolution.

…

-- Happy hacking Petter Reinholdtsen

FedeDP · 2024-09-02T12:26:59Z

/remove-lifecycle stale

Sorry we had no time to look into this during this release cycle; setting next milestone:
/milestone 0.19.0

FedeDP · 2024-11-13T09:21:43Z

/milestone 0.20.0

FedeDP · 2025-01-08T09:25:00Z

/milestone 0.21.0

petterreinholdtsen added the kind/bug Something isn't working label Feb 27, 2024

poiana added the lifecycle/stale label Jun 3, 2024

poiana removed the lifecycle/stale label Jun 4, 2024

leogr transferred this issue from falcosecurity/falco Jun 4, 2024

poiana added the lifecycle/stale label Sep 2, 2024

poiana removed the lifecycle/stale label Sep 2, 2024

poiana added this to the 0.19.0 milestone Sep 2, 2024

poiana modified the milestones: 0.19.0, 0.20.0 Nov 13, 2024

poiana modified the milestones: 0.20.0, 0.21.0 Jan 8, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fd.name some times contain bogus <UNKNOWN> part in "Write below root" event #1892

fd.name some times contain bogus <UNKNOWN> part in "Write below root" event #1892

petterreinholdtsen commented Feb 27, 2024 •

edited

Loading

incertum commented Feb 28, 2024

petterreinholdtsen commented Feb 28, 2024 via email

incertum commented Feb 29, 2024

petterreinholdtsen commented Mar 4, 2024 via email

petterreinholdtsen commented Mar 4, 2024 via email

incertum commented Mar 4, 2024

incertum commented Mar 5, 2024

poiana commented Jun 3, 2024

petterreinholdtsen commented Jun 3, 2024 via email

leogr commented Jun 4, 2024

leogr commented Jun 4, 2024

poiana commented Sep 2, 2024

petterreinholdtsen commented Sep 2, 2024 via email

FedeDP commented Sep 2, 2024

FedeDP commented Nov 13, 2024

FedeDP commented Jan 8, 2025

fd.name some times contain bogus <UNKNOWN> part in "Write below root" event #1892

fd.name some times contain bogus <UNKNOWN> part in "Write below root" event #1892

Comments

petterreinholdtsen commented Feb 27, 2024 • edited Loading

incertum commented Feb 28, 2024

petterreinholdtsen commented Feb 28, 2024 via email

incertum commented Feb 29, 2024

petterreinholdtsen commented Mar 4, 2024 via email

petterreinholdtsen commented Mar 4, 2024 via email

incertum commented Mar 4, 2024

incertum commented Mar 5, 2024

poiana commented Jun 3, 2024

petterreinholdtsen commented Jun 3, 2024 via email

leogr commented Jun 4, 2024

leogr commented Jun 4, 2024

poiana commented Sep 2, 2024

petterreinholdtsen commented Sep 2, 2024 via email

FedeDP commented Sep 2, 2024

FedeDP commented Nov 13, 2024

FedeDP commented Jan 8, 2025

petterreinholdtsen commented Feb 27, 2024 •

edited

Loading