search

Granulate / gprofiler

gProfiler is a system-wide profiler, combining multiple sampling profilers to produce unified visualization of what your CPU is spending time on.
https://profiler.granulate.io
Apache License 2.0
746 stars 54 forks source link

tests: java hotspot tests fail on aarch64 #721

Open pfilipko1 opened 1 year ago

pfilipko1 commented 1 year ago

Failing tests:

========================================================================================================================== short test summary info ==========================================================================================================================
FAILED tests/test_java.py::test_hotspot_error_file[False-java_args0-False] - assert 'libpthread.so' in 'WARNING  gprofiler.profilers.java:java.py:1229 async-profiled Java process exited with signal\nWARNING  gprofiler.profilers.java:java.py:923 Java profiling has be...
FAILED tests/test_java.py::test_hotspot_error_file[False-java_args1-False] - assert 'libpthread.so' in 'WARNING  gprofiler.profilers.java:java.py:1229 async-profiled Java process exited with signal\nWARNING  gprofiler.profilers.java:java.py:923 Java profiling has be...
FAILED tests/test_java.py::test_hotspot_error_file[True-java_args2-False] - assert 'memory_usage_in_bytes:' in 'WARNING  gprofiler.profilers.java:java.py:1229 async-profiled Java process exited with signal\nWARNING  gprofiler.profilers.java:java.py:923 Java profilin...

Example output:

application_pid = 60501, monkeypatch = <_pytest.monkeypatch.MonkeyPatch object at 0xffffa41603a0>, caplog = <_pytest.logging.LogCaptureFixture object at 0xffffa41619f0>, profiler_state = <gprofiler.profiler_state.ProfilerState object at 0xffffa41607f0>

    @pytest.mark.parametrize(
        "in_container,java_args,check_app_exited",
        [                                                                                                                                                                                                                                                                                (False, (), False),  # default                                                                                                                                                                                                                                               (False, ("-XX:ErrorFile=/tmp/my_custom_error_file.log",), False),  # custom error file                                                                                                                                                                                       (True, (), False),  # containerized (other params are ignored)                                                                                                                                                                                                           ],                                                                                                                                                                                                                                                                       )
    def test_hotspot_error_file(
        application_pid: int,
        monkeypatch: MonkeyPatch,
        caplog: LogCaptureFixture,
        profiler_state: ProfilerState,
    ) -> None:
        start_async_profiler = AsyncProfiledProcess.start_async_profiler

        # Simulate crashing process
        def start_async_profiler_and_crash(self: AsyncProfiledProcess, *args: Any, **kwargs: Any) -> bool:
            result = start_async_profiler(self, *args, **kwargs)
            self.process.send_signal(signal.SIGBUS)
            return result

        monkeypatch.setattr(AsyncProfiledProcess, "start_async_profiler", start_async_profiler_and_crash)

        # increased duration - give the JVM some time to write the hs_err file.
        profiler = make_java_profiler(profiler_state, duration=10)
        with profiler:
            profiler.snapshot()

        assert "Found Hotspot error log" in caplog.text
        assert "OpenJDK" in caplog.text
        assert "SIGBUS" in caplog.text
        assert "libpthread.so" in caplog.text
>       assert "memory_usage_in_bytes:" in caplog.text
E       assert 'memory_usage_in_bytes:' in 'WARNING  gprofiler.profilers.java:java.py:1229 async-profiled Java process exited with signal\nWARNING  gprofiler.profilers.java:java.py:923 Java profiling has been disabled, will avoid profiling any new java processes\nWARNING  gprofiler.profilers.java:java.py:1176 Found Hotspot error log for pid 60501 at /proc/60458/root/tmp/hs_err_pid7.log:\nVM info: OpenJDK 64-Bit Server VM (25.342-b07) for linux-aarch64 JRE (1.8.0_342-b07), built on Jul 16 2022 08:54:57 by "openjdk" with gcc 4.8.5 20150623 (Red Hat 4.8.5-36)\nsiginfo: si_signo: 7 (SIGBUS), si_code: 0 (SI_USER)\nProblematic frame: C  [libpthread.so.0+0x9928]  __pthread_clockjoin_ex+0x228\nnative frames:\nC  [libpthread.so.0+0x9928]  __pthread_clockjoin_ex+0x228\nC  [libjli.so+0xc0d0]  ContinueInNewThread0+0xc0\nC  [libjli.so+0x8e7c]  ContinueInNewThread+0x54\nC  [libjli.so+0x9a40]  JLI_Launch+0xa98\nC  [java+0x88c]  main+0x5c\nC  [libc.so.6+0x24218]  __libc_start_main+0xe8\nC  [java+0x8d4]\ncontainer info:\n\n'
E        +  where 'WARNING  gprofiler.profilers.java:java.py:1229 async-profiled Java process exited with signal\nWARNING  gprofiler.profilers.java:java.py:923 Java profiling has been disabled, will avoid profiling any new java processes\nWARNING  gprofiler.profilers.java:java.py:1176 Found Hotspot error log for pid 60501 at /proc/60458/root/tmp/hs_err_pid7.log:\nVM info: OpenJDK 64-Bit Server VM (25.342-b07) for linux-aarch64 JRE (1.8.0_342-b07), built on Jul 16 2022 08:54:57 by "openjdk" with gcc 4.8.5 20150623 (Red Hat 4.8.5-36)\nsiginfo: si_signo: 7 (SIGBUS), si_code: 0 (SI_USER)\nProblematic frame: C  [libpthread.so.0+0x9928]  __pthread_clockjoin_ex+0x228\nnative frames:\nC  [libpthread.so.0+0x9928]  __pthread_clockjoin_ex+0x228\nC  [libjli.so+0xc0d0]  ContinueInNewThread0+0xc0\nC  [libjli.so+0x8e7c]  ContinueInNewThread+0x54\nC  [libjli.so+0x9a40]  JLI_Launch+0xa98\nC  [java+0x88c]  main+0x5c\nC  [libc.so.6+0x24218]  __libc_start_main+0xe8\nC  [java+0x8d4]\ncontainer info:\n\n' = <_pytest.logging.LogCaptureFixture object at 0xffffa41619f0>.text

tests/test_java.py:271: AssertionError
----------------------------------------------------------------------------------------------------------------------------- Captured log call -----------------------------------------------------------------------------------------------------------------------------WARNING  gprofiler.profilers.java:java.py:1229 async-profiled Java process exited with signal
WARNING  gprofiler.profilers.java:java.py:923 Java profiling has been disabled, will avoid profiling any new java processes
WARNING  gprofiler.profilers.java:java.py:1176 Found Hotspot error log for pid 60501 at /proc/60458/root/tmp/hs_err_pid7.log:
VM info: OpenJDK 64-Bit Server VM (25.342-b07) for linux-aarch64 JRE (1.8.0_342-b07), built on Jul 16 2022 08:54:57 by "openjdk" with gcc 4.8.5 20150623 (Red Hat 4.8.5-36)
siginfo: si_signo: 7 (SIGBUS), si_code: 0 (SI_USER)
Problematic frame: C  [libpthread.so.0+0x9928]  __pthread_clockjoin_ex+0x228
native frames:
C  [libpthread.so.0+0x9928]  __pthread_clockjoin_ex+0x228
C  [libjli.so+0xc0d0]  ContinueInNewThread0+0xc0
C  [libjli.so+0x8e7c]  ContinueInNewThread+0x54
C  [libjli.so+0x9a40]  JLI_Launch+0xa98
C  [java+0x88c]  main+0x5c
C  [libc.so.6+0x24218]  __libc_start_main+0xe8
C  [java+0x8d4]
container info:
Jongy commented 1 year ago

This extra field should be under container_info but maybe it's not collected for ARM by hotspot.

I'd attempt fixing by:

  1. Checking if the relevant regex fails on aarch64
  2. If the data is just missing, we can skip the check of this field on aarch64.