Integration Tests failing
Closed this issue · 3 comments
geyslan commented
Description
It was detected problems with Test_EventsDependencies and Test_TraceeCapture so far.
sudo make test-integration
Manjaro
=== RUN Test_TraceeCapture
=== RUN Test_TraceeCapture/capture_write/read
capture_test.go:85: --- started tracee ---
event_filters_test.go:1869: Cooling down for 5s
=== RUN Test_TraceeCapture/capture_write/readv
event_filters_test.go:1869: Cooling down for 2s
capture_test.go:85: --- started tracee ---
event_filters_test.go:1869: Cooling down for 5s
=== RUN Test_TraceeCapture/capture_pipe_write/read
event_filters_test.go:1869: Cooling down for 2s
capture_test.go:85: --- started tracee ---
event_filters_test.go:1869: Cooling down for 5s
capture_test.go:329: assertion failed:
--- input
+++ →
@@ -1,2 +1,8 @@
+Hello World!
+Hello World!
+Hello World!
+Hello World!
+Hello World!
+Hello World!
Hello World!
...
=== NAME Test_TraceeCapture
capture_test.go:106: found unexpected goroutines:
[Goroutine 1278 in state syscall, with syscall.Syscall6 on top of the stack:
syscall.Syscall6(0xf7, 0x1, 0x4f98e, 0xc001046d90, 0x1000004, 0x0, 0x0)
/root/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.4.linux-amd64/src/syscall/syscall_linux.go:91 +0x45
os.(*Process).blockUntilWaitable(0xc001cc24e0)
/root/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.4.linux-amd64/src/os/wait_waitid.go:32 +0x9f
os.(*Process).wait(0xc001cc24e0)
/root/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.4.linux-amd64/src/os/exec_unix.go:22 +0x4b
os.(*Process).Wait(...)
/root/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.4.linux-amd64/src/os/exec.go:134
os/exec.(*Cmd).Wait(0xc001cd26e0)
/root/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.4.linux-amd64/src/os/exec/exec.go:897 +0xb9
github.com/aquasecurity/tracee/tests/testutils.ExecCmdBgWithSudoAndCtx.func1.1()
/home/gg/code/tracee/tests/testutils/exec.go:143 +0x8f
created by github.com/aquasecurity/tracee/tests/testutils.ExecCmdBgWithSudoAndCtx.func1 in goroutine 1277
/home/gg/code/tracee/tests/testutils/exec.go:140 +0x31a
Goroutine 1279 in state chan receive, with github.com/aquasecurity/tracee/tests/testutils.ExecCmdBgWithSudoAndCtx.func2 on top of the stack:
github.com/aquasecurity/tracee/tests/testutils.ExecCmdBgWithSudoAndCtx.func2(0xc0001deb68)
/home/gg/code/tracee/tests/testutils/exec.go:165 +0x7c
created by github.com/aquasecurity/tracee/tests/testutils.ExecCmdBgWithSudoAndCtx in goroutine 1276
/home/gg/code/tracee/tests/testutils/exec.go:164 +0x866
]
--- FAIL: Test_TraceeCapture (28.17s)
--- PASS: Test_TraceeCapture/capture_write/read (8.57s)
--- PASS: Test_TraceeCapture/capture_write/readv (10.11s)
--- FAIL: Test_TraceeCapture/capture_pipe_write/read (9.04s)
Ubuntu Vagrant
=== RUN Test_EventsDependencies
==================
WARNING: DATA RACE
Write at 0x0000051f2400 by goroutine 1130:
github.com/aquasecurity/tracee/pkg/logger.SetLogger()
/vagrant/pkg/logger/logger.go:339 +0x40b
github.com/aquasecurity/tracee/tests/testutils.SetTestLogger()
/vagrant/tests/testutils/logger.go:36 +0x3d8
github.com/aquasecurity/tracee/tests/integration.Test_EventsDependencies()
/vagrant/tests/integration/dependencies_test.go:90 +0xb2d
testing.tRunner()
/root/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.4.linux-amd64/src/testing/testing.go:1689 +0x21e
testing.(*T).Run.gowrap1()
/root/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.4.linux-amd64/src/testing/testing.go:1742 +0x44
Previous read at 0x0000051f2400 by goroutine 1109:
github.com/aquasecurity/tracee/pkg/logger.debugw()
/vagrant/pkg/logger/logger.go:218 +0x4ac
github.com/aquasecurity/tracee/pkg/logger.Debugw()
/vagrant/pkg/logger/logger.go:222 +0x55
github.com/aquasecurity/tracee/pkg/ebpf.(*Tracee).handleEvents.deferwrap1()
/vagrant/pkg/ebpf/events_pipeline.go:31 +0x17
runtime.deferreturn()
/root/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.4.linux-amd64/src/runtime/panic.go:602 +0x5d
github.com/aquasecurity/tracee/pkg/ebpf.(*Tracee).Run.gowrap5()
/vagrant/pkg/ebpf/tracee.go:1481 +0x5d
Goroutine 1130 (running) created at:
testing.(*T).Run()
/root/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.4.linux-amd64/src/testing/testing.go:1742 +0x825
testing.runTests.func1()
/root/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.4.linux-amd64/src/testing/testing.go:2161 +0x85
testing.tRunner()
/root/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.4.linux-amd64/src/testing/testing.go:1689 +0x21e
testing.runTests()
/root/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.4.linux-amd64/src/testing/testing.go:2159 +0x8be
testing.(*M).Run()
/root/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.4.linux-amd64/src/testing/testing.go:2027 +0xf17
main.main()
_testmain.go:55 +0x2bd
Goroutine 1109 (finished) created at:
github.com/aquasecurity/tracee/pkg/ebpf.(*Tracee).Run()
/vagrant/pkg/ebpf/tracee.go:1481 +0x70a
github.com/aquasecurity/tracee/tests/integration.startTracee.func2()
/vagrant/tests/integration/tracee.go:138 +0x5b
==================
=== RUN Test_EventsDependencies/sanity_of_exec_test_event
=== NAME Test_EventsDependencies
testing.go:1398: race detected during execution of test
=== NAME Test_EventsDependencies/sanity_of_exec_test_event
dependencies_test.go:144: --- started tracee ---
event_filters_test.go:1891: >>> running: cp /bin/ls /tmp/test
tracee.go:218: . waiting for at least 0 event(s) for 5s
tracee.go:225: . got 0 event(s) so far
tracee.go:227: . done waiting for 0 event(s)
event_filters_test.go:1891: >>> running: /tmp/test
tracee.go:207: . waiting events collection for 1s
tracee.go:218: . waiting for at least 1 event(s) for 5s
tracee.go:225: . got 0 event(s) so far
tracee.go:225: . got 0 event(s) so far
tracee.go:225: . got 0 event(s) so far
tracee.go:225: . got 0 event(s) so far
tracee.go:225: . got 0 event(s) so far
tracee.go:231: . done waiting for 1 event(s)
dependencies_test.go:172:
Error Trace: /vagrant/tests/integration/dependencies_test.go:172
Error: Received unexpected error:
timed out on waiting for 1 event(s)
Test: Test_EventsDependencies/sanity_of_exec_test_event
=== RUN Test_EventsDependencies/non_existing_ksymbol_dependency
signal: killed
FAIL github.com/aquasecurity/tracee/tests/integration 286.382s
Output of tracee version:
Tracee version: v0.21.0-rc-104-gb10e7db55
Output of uname -a:
Linux hb0 6.6.32-1-MANJARO #1 SMP PREEMPT_DYNAMIC Mon May 27 03:41:25 UTC 2024 x86_64 GNU/Linux
Linux ubuntu-jammy 5.15.0-105-generic #115-Ubuntu SMP Mon Apr 15 09:52:04 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux
Additional details
Even after the tests ending Tracee remains running, when Test_TraceeCapture fails:
ps aux | grep tracee
root 326030 0.0 0.0 17772 7424 ? S 13:06 0:00 /usr/bin/sudo ../../dist/tracee --healthz --events init_namespaces -c read=/root/pipe* -c write=/root/pipe* -c dir:/tmp/tracee/3
root 326032 0.0 0.0 17772 2400 pts/3 Ss+ 13:06 0:00 /usr/bin/sudo ../../dist/tracee --healthz --events init_namespaces -c read=/root/pipe* -c write=/root/pipe* -c dir:/tmp/tracee/3
root 326033 3.8 0.4 2644812 286588 pts/3 Sl 13:06 0:08 ../../dist/tracee --healthz --events init_namespaces -c read=/root/pipe* -c write=/root/pipe* -c dir:/tmp/tracee/3
gg 329787 0.0 0.0 6504 2048 pts/2 S+ 13:10 0:00 grep tracee
rscampos commented
The tests failed on Ubuntu Vagrant (ARM64)
sudo make test-integration
Test_TraceeCapture:
=== RUN Test_TraceeCapture
=== RUN Test_TraceeCapture/capture_write/read
capture_test.go:91: tracee is already running
=== RUN Test_TraceeCapture/capture_write/readv
event_filters_test.go:1869: Cooling down for 2s
capture_test.go:91: tracee is already running
=== RUN Test_TraceeCapture/capture_pipe_write/read
event_filters_test.go:1869: Cooling down for 2s
capture_test.go:91: tracee is already running
--- FAIL: Test_TraceeCapture (4.11s)
--- FAIL: Test_TraceeCapture/capture_write/read (0.02s)
--- FAIL: Test_TraceeCapture/capture_write/readv (2.03s)
--- FAIL: Test_TraceeCapture/capture_pipe_write/read (2.03s)
Test_EventsDependencies:
=== RUN Test_EventsDependencies/non_existing_ksymbol_dependency
dependencies_test.go:144: --- started tracee ---
dependencies_test.go:242:
Error Trace: /vagrant/tests/integration/dependencies_test.go:242
/vagrant/tests/integration/dependencies_test.go:168
Error: []string{"security_file_mprotect", "security_socket_connect", "load_elf_phdrs", "load_elf_phdrs", "__kernel_write", "__kernel_write", "security_socket_sendmsg", "security_file_open", "vfs_write", "vfs_write", "security_file_permission", "vfs_writev", "vfs_writev", "vfs_writev", "do_init_module", "do_init_module", "load_elf_phdrs", "load_elf_phdrs", "security_inode_rename", "exec_binprm", "security_kernel_read_file", "__arm64_sys_execve", "security_sb_mount", "security_bprm_check", "security_mmap_addr"} should not contain "security_bprm_check"
Test: Test_EventsDependencies/non_existing_ksymbol_dependency
=== RUN Test_EventsDependencies/non_existing_probe_function
dependencies_test.go:144: --- started tracee ---
dependencies_test.go:242:
Error Trace: /vagrant/tests/integration/dependencies_test.go:242
/vagrant/tests/integration/dependencies_test.go:168
Error: []string{"security_file_mprotect", "security_socket_connect", "load_elf_phdrs", "load_elf_phdrs", "__kernel_write", "__kernel_write", "security_socket_sendmsg", "security_file_open", "vfs_write", "vfs_write", "security_file_permission", "vfs_writev", "vfs_writev", "vfs_writev", "do_init_module", "do_init_module", "load_elf_phdrs", "load_elf_phdrs", "security_inode_rename", "exec_binprm", "security_kernel_read_file", "__arm64_sys_execve", "security_sb_mount", "security_bprm_check", "security_mmap_addr"} should not contain "security_bprm_check"
Test: Test_EventsDependencies/non_existing_probe_function
--- FAIL: Test_EventsDependencies (63.67s)
--- FAIL: Test_EventsDependencies/non_existing_ksymbol_dependency (10.08s)
--- FAIL: Test_EventsDependencies/non_existing_probe_function (9.14s)
Test_EventFilters:
=== RUN Test_EventFilters/comm:_event:_data:_trace_event_set_in_a_specific_policy_with_data_from_fakeprog1_and_fakeprog2_commands
event_filters_test.go:1730: --- started tracee ---
event_filters_test.go:1927: >>> running: ../../dist/syscaller fakeprog1 56
event_filters_test.go:1927: >>> running: ../../dist/syscaller fakeprog2 9000
tracee.go:218: . waiting for at least 2 event(s) for 5s
tracee.go:225: . got 1 event(s) so far
tracee.go:225: . got 1 event(s) so far
tracee.go:225: . got 1 event(s) so far
tracee.go:225: . got 1 event(s) so far
tracee.go:225: . got 1 event(s) so far
tracee.go:231: . done waiting for 2 event(s)
event_filters_test.go:1757: Test Test_EventFilters/comm:_event:_data:_trace_event_set_in_a_specific_policy_with_data_from_fakeprog1_and_fakeprog2_commands failed: timed out on waiting for 2 event(s)
event_filters_test.go:1767: --- stopped tracee ---
--- FAIL: Test_EventFilters (237.13s)
--- FAIL: Test_EventFilters/comm:_event:_data:_trace_event_set_in_a_specific_policy_with_data_from_fakeprog1_and_fakeprog2_commands (10.19s)