From 2a18cf54f96c08203484410a890110b3f3086c54 Mon Sep 17 00:00:00 2001 From: slicklash Date: Thu, 24 Oct 2024 16:31:25 +0200 Subject: [PATCH 1/8] perf: add -F +symline support --- gprofiler/utils/perf.py | 4 +++- gprofiler/utils/perf_process.py | 2 +- scripts/perf_build.sh | 2 +- tests/test_perf.py | 8 ++++++++ 4 files changed, 13 insertions(+), 3 deletions(-) diff --git a/gprofiler/utils/perf.py b/gprofiler/utils/perf.py index 9e2e41dbc..e7bdf4749 100644 --- a/gprofiler/utils/perf.py +++ b/gprofiler/utils/perf.py @@ -47,6 +47,7 @@ r"(?:(?P\d+)\s+)?(?P[\w\-_/]+):(?:(?P[\w-]+):)?(?P[^\n]*)(?:\n(?P.*))?", re.MULTILINE | re.DOTALL, ) +SYMLINE_REGEX = re.compile(r"(?:\+([^+]+):(\d+)){2}$") class SupportedPerfEvent(Enum): @@ -160,7 +161,8 @@ def collapse_stack(comm: str, stack: str, insert_dso_name: bool = False) -> str: m = FRAME_REGEX.match(line) assert m is not None, f"bad line: {line}" sym, dso = m.group("symbol"), m.group("dso_brackets") or m.group("dso_plain") - sym = sym.split("+")[0] # strip the offset part. + if not SYMLINE_REGEX.search(sym): + sym = sym.split("+")[0] # strip the offset part. if sym == "[unknown]" and dso != "unknown": sym = f"({dso})" # append kernel annotation diff --git a/gprofiler/utils/perf_process.py b/gprofiler/utils/perf_process.py index 17b96e5a4..ba44a911c 100644 --- a/gprofiler/utils/perf_process.py +++ b/gprofiler/utils/perf_process.py @@ -190,7 +190,7 @@ def wait_and_script(self) -> str: perf_data = inject_data perf_script_proc = run_process( - [perf_path(), "script", "-F", "+pid", "-i", str(perf_data)], + [perf_path(), "script", "-F", "+pid,+symline", "-i", str(perf_data)], suppress_log=True, ) return perf_script_proc.stdout.decode("utf8") diff --git a/scripts/perf_build.sh b/scripts/perf_build.sh index a8d48302f..05dba5a66 100755 --- a/scripts/perf_build.sh +++ b/scripts/perf_build.sh @@ -17,7 +17,7 @@ set -euo pipefail # downloading the zip because the git is very large (this is also very large, but still smaller) -curl -SL https://codeload.github.com/Granulate/linux/zip/5c103bf97fb268e4ea157f5e1c2a5bd6ad8c40dc -o linux.zip +curl -SL https://codeload.github.com/Granulate/linux/zip/9909d736d8b8927d79003dfa9732050a08c11221 -o linux.zip unzip -qq linux.zip rm linux.zip cd linux-*/ diff --git a/tests/test_perf.py b/tests/test_perf.py index 04b144a05..cb7b5a4a2 100644 --- a/tests/test_perf.py +++ b/tests/test_perf.py @@ -397,6 +397,14 @@ def test_get_average_frame_count(samples: str, count: float) -> None: ), id="frame_with_space_parenthesis", ), + pytest.param( + " 4af76b main.cpuIntensiveWork+bar.go:21+bar.go:14 (/tmp/perf/my_go_app)", + dict( + dso_true="main.cpuIntensiveWork+bar.go:21+bar.go:14 (/tmp/perf/my_go_app)", + dso_false="main.cpuIntensiveWork+bar.go:21+bar.go:14", + ), + id="frame_with_symline", + ), ], ) def test_collapse_stack_consider_dso(stack: str, insert_dso_name: bool, outcome_dict: Dict[str, str]) -> None: From 58788cb40158a289b274e69c7f4fe3198f364881 Mon Sep 17 00:00:00 2001 From: slicklash Date: Fri, 25 Oct 2024 17:10:06 +0200 Subject: [PATCH 2/8] up --- gprofiler/utils/perf_process.py | 17 ++++++++++++----- tests/test.sh | 2 +- 2 files changed, 13 insertions(+), 6 deletions(-) diff --git a/gprofiler/utils/perf_process.py b/gprofiler/utils/perf_process.py index ba44a911c..b2de5bb50 100644 --- a/gprofiler/utils/perf_process.py +++ b/gprofiler/utils/perf_process.py @@ -8,6 +8,7 @@ from psutil import Process +from gprofiler.exceptions import CalledProcessError from gprofiler.log import get_logger_adapter from gprofiler.utils import ( reap_process, @@ -189,11 +190,17 @@ def wait_and_script(self) -> str: perf_data.unlink() perf_data = inject_data - perf_script_proc = run_process( - [perf_path(), "script", "-F", "+pid,+symline", "-i", str(perf_data)], - suppress_log=True, - ) - return perf_script_proc.stdout.decode("utf8") + try: + perf_script_proc = run_process( + [perf_path(), "script", "-F", "+pid,+symline", "-i", str(perf_data)], + suppress_log=True, + ) + return perf_script_proc.stdout.decode("utf8") + except CalledProcessError as e: + # ignore addr2line errors + if isinstance(e.stderr, str) and e.stderr.startswith("addr2line"): + return e.stdout.decode("utf8") if isinstance(e.stdout, bytes) else str(e.stdout) + raise finally: perf_data.unlink() if self._inject_jit: diff --git a/tests/test.sh b/tests/test.sh index 14065ef5a..18f547aba 100755 --- a/tests/test.sh +++ b/tests/test.sh @@ -48,4 +48,4 @@ fi python3 -m pip install -q --upgrade setuptools pip python3 -m pip install -r ./requirements.txt -r ./exe-requirements.txt -r ./dev-requirements.txt # TODO: python3 -m pip install . -sudo env "PATH=$PATH" python3 -m pytest -v tests/ "$@" +sudo -E env "PATH=$PATH" python3 -m pytest -v tests/ "$@" From eb3ba7f86e65ee20845cb76405998e813412c262 Mon Sep 17 00:00:00 2001 From: slicklash Date: Mon, 28 Oct 2024 14:49:01 +0100 Subject: [PATCH 3/8] suppress addr2line errors --- gprofiler/utils/perf_process.py | 17 +++++------------ scripts/perf_build.sh | 2 +- 2 files changed, 6 insertions(+), 13 deletions(-) diff --git a/gprofiler/utils/perf_process.py b/gprofiler/utils/perf_process.py index b2de5bb50..e1e5db7b4 100644 --- a/gprofiler/utils/perf_process.py +++ b/gprofiler/utils/perf_process.py @@ -8,7 +8,6 @@ from psutil import Process -from gprofiler.exceptions import CalledProcessError from gprofiler.log import get_logger_adapter from gprofiler.utils import ( reap_process, @@ -190,17 +189,11 @@ def wait_and_script(self) -> str: perf_data.unlink() perf_data = inject_data - try: - perf_script_proc = run_process( - [perf_path(), "script", "-F", "+pid,+symline", "-i", str(perf_data)], - suppress_log=True, - ) - return perf_script_proc.stdout.decode("utf8") - except CalledProcessError as e: - # ignore addr2line errors - if isinstance(e.stderr, str) and e.stderr.startswith("addr2line"): - return e.stdout.decode("utf8") if isinstance(e.stdout, bytes) else str(e.stdout) - raise + perf_script_proc = run_process( + [perf_path(), "script", "-F", "+pid,+symline", "--no-addr2line-errors", "-i", str(perf_data)], + suppress_log=True, + ) + return perf_script_proc.stdout.decode("utf8") finally: perf_data.unlink() if self._inject_jit: diff --git a/scripts/perf_build.sh b/scripts/perf_build.sh index 05dba5a66..239154923 100755 --- a/scripts/perf_build.sh +++ b/scripts/perf_build.sh @@ -17,7 +17,7 @@ set -euo pipefail # downloading the zip because the git is very large (this is also very large, but still smaller) -curl -SL https://codeload.github.com/Granulate/linux/zip/9909d736d8b8927d79003dfa9732050a08c11221 -o linux.zip +curl -SL https://codeload.github.com/Granulate/linux/zip/b6107ebc2839e99eee8dff55adca75871b595395 -o linux.zip unzip -qq linux.zip rm linux.zip cd linux-*/ From 3c9d36996f361386bc250b189e81751c0f1f8e9a Mon Sep 17 00:00:00 2001 From: slicklash Date: Tue, 29 Oct 2024 10:40:25 +0100 Subject: [PATCH 4/8] exclude gprofiler and py-spy --- gprofiler/utils/perf_process.py | 12 +++++++++++- scripts/perf_build.sh | 2 +- 2 files changed, 12 insertions(+), 2 deletions(-) diff --git a/gprofiler/utils/perf_process.py b/gprofiler/utils/perf_process.py index e1e5db7b4..b9040e6f5 100644 --- a/gprofiler/utils/perf_process.py +++ b/gprofiler/utils/perf_process.py @@ -190,7 +190,17 @@ def wait_and_script(self) -> str: perf_data = inject_data perf_script_proc = run_process( - [perf_path(), "script", "-F", "+pid,+symline", "--no-addr2line-errors", "-i", str(perf_data)], + [ + perf_path(), + "script", + "-F", + "+pid,+symline", + "-X", + "gprofiler,py-spy", + "--no-addr2line-errors", + "-i", + str(perf_data), + ], suppress_log=True, ) return perf_script_proc.stdout.decode("utf8") diff --git a/scripts/perf_build.sh b/scripts/perf_build.sh index 239154923..5a8b0f33f 100755 --- a/scripts/perf_build.sh +++ b/scripts/perf_build.sh @@ -17,7 +17,7 @@ set -euo pipefail # downloading the zip because the git is very large (this is also very large, but still smaller) -curl -SL https://codeload.github.com/Granulate/linux/zip/b6107ebc2839e99eee8dff55adca75871b595395 -o linux.zip +curl -SL https://codeload.github.com/Granulate/linux/zip/169b16658825031b20e32b34c5aedc22ed093abc -o linux.zip unzip -qq linux.zip rm linux.zip cd linux-*/ From d52e3bc74fbdc3334e44a0739927e718c402fd7a Mon Sep 17 00:00:00 2001 From: slicklash Date: Tue, 29 Oct 2024 15:59:46 +0100 Subject: [PATCH 5/8] up --- gprofiler/utils/perf_process.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/gprofiler/utils/perf_process.py b/gprofiler/utils/perf_process.py index b9040e6f5..d11221101 100644 --- a/gprofiler/utils/perf_process.py +++ b/gprofiler/utils/perf_process.py @@ -196,7 +196,7 @@ def wait_and_script(self) -> str: "-F", "+pid,+symline", "-X", - "gprofiler,py-spy", + "gprofiler", "--no-addr2line-errors", "-i", str(perf_data), From c708dada3846e4816e622e1c1469480b3a68d38f Mon Sep 17 00:00:00 2001 From: slicklash Date: Tue, 29 Oct 2024 16:00:01 +0100 Subject: [PATCH 6/8] up --- gprofiler/utils/perf_process.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/gprofiler/utils/perf_process.py b/gprofiler/utils/perf_process.py index d11221101..b9040e6f5 100644 --- a/gprofiler/utils/perf_process.py +++ b/gprofiler/utils/perf_process.py @@ -196,7 +196,7 @@ def wait_and_script(self) -> str: "-F", "+pid,+symline", "-X", - "gprofiler", + "gprofiler,py-spy", "--no-addr2line-errors", "-i", str(perf_data), From bf4b7b1e3274f1e3c6aa5a1c246f53fbdbaa231a Mon Sep 17 00:00:00 2001 From: slicklash Date: Tue, 29 Oct 2024 17:04:20 +0100 Subject: [PATCH 7/8] up --- scripts/perf_build.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/scripts/perf_build.sh b/scripts/perf_build.sh index 5a8b0f33f..d53bb5c9e 100755 --- a/scripts/perf_build.sh +++ b/scripts/perf_build.sh @@ -17,7 +17,7 @@ set -euo pipefail # downloading the zip because the git is very large (this is also very large, but still smaller) -curl -SL https://codeload.github.com/Granulate/linux/zip/169b16658825031b20e32b34c5aedc22ed093abc -o linux.zip +curl -SL https://codeload.github.com/Granulate/linux/zip/50259d0151087e75b8bfd6c0b0edc3125ee9997f -o linux.zip unzip -qq linux.zip rm linux.zip cd linux-*/ From e5a3c0459786289a9a25ef82fb208b0b96353eaf Mon Sep 17 00:00:00 2001 From: slicklash Date: Wed, 30 Oct 2024 10:34:44 +0100 Subject: [PATCH 8/8] up --- tests/test_perf.py | 3 +++ tests/utils.py | 13 ++++++++++++- 2 files changed, 15 insertions(+), 1 deletion(-) diff --git a/tests/test_perf.py b/tests/test_perf.py index cb7b5a4a2..a5c7c865a 100644 --- a/tests/test_perf.py +++ b/tests/test_perf.py @@ -15,6 +15,7 @@ # import logging +import time from threading import Event from typing import Dict, cast @@ -144,6 +145,7 @@ def test_perf_comm_change( I'm not sure it can be done, i.e is this info even kept anywhere). """ with system_profiler as profiler: + time.sleep(2) # first run - we get the changed name, because the app started before perf began recording. _assert_comm_in_profile(profiler, application_pid, False) @@ -170,6 +172,7 @@ def test_perf_thread_comm_is_process_comm( starts after perf, the exec comm of the process should be used (see test_perf_comm_change) """ with system_profiler as profiler: + time.sleep(2) # running perf & script now with --show-task-events would show: # pative 1925947 [010] 987095.272656: PERF_RECORD_COMM: pative:1925904/1925947 # our perf will prefer to use the exec comm, OR oldest comm available if exec diff --git a/tests/utils.py b/tests/utils.py index dc22f136e..c8b3cde31 100644 --- a/tests/utils.py +++ b/tests/utils.py @@ -141,6 +141,7 @@ def run_privileged_container( def _no_errors(logs: str) -> None: # example line: [2021-06-12 10:13:57,528] ERROR: gprofiler: ruby profiling failed assert "] ERROR: " not in logs, f"found ERRORs in gProfiler logs!: {logs}" + assert "Could not acquire gProfiler's lock" not in logs, f"found lock error in gProfiler logs!: {logs}" def run_gprofiler_in_container(docker_client: DockerClient, image: Image, command: List[str], **kwargs: Any) -> None: @@ -205,7 +206,17 @@ def assert_ldd_version_container(container: Container, version: str) -> None: def snapshot_pid_profile(profiler: ProfilerInterface, pid: int) -> ProfileData: - return profiler.snapshot()[pid] + last_snapshot = profiler.snapshot() + + def has_profile() -> bool: + nonlocal last_snapshot + if pid in last_snapshot: + return True + last_snapshot = profiler.snapshot() + return pid in last_snapshot + + wait_event(timeout=5, stop_event=Event(), condition=has_profile, interval=2.0) + return last_snapshot[pid] def snapshot_pid_collapsed(profiler: ProfilerInterface, pid: int) -> StackToSampleCount: