java: Uprade to AP 3.0 (#855)

Author: Jongy

gprofiler/gprofiler_types.py

@@ -96,3 +96,11 @@ def integer_range_check(value_str: str) -> int:
         return value
 
     return integer_range_check
+
+
+def comma_separated_enum_list(options: List[str], value: str) -> List[str]:
+    values = value.split(",")
+    for v in values:
+        if v not in options:
+            raise configargparse.ArgumentTypeError(f"invalid value {v!r} (allowed values: {options!r})")
+    return values

gprofiler/profilers/java.py

@@ -59,6 +59,7 @@
     ProcessToProfileData,
     ProfileData,
     StackToSampleCount,
+    comma_separated_enum_list,
     integer_range,
     positive_integer,
 )
@@ -112,9 +113,6 @@ def needs_musl_ap_cached(process: Process) -> bool:
     return is_musl(process, maps) and not any("glibc-compat" in m.path for m in maps)
 
 
-JAVA_SAFEMODE_ALL = "all"  # magic value for *all* options from JavaSafemodeOptions
-
-
 class JavaSafemodeOptions(str, Enum):
     # a profiled process was OOM-killed and we saw it in the kernel log
     PROFILED_OOM = "profiled-oom"
@@ -138,18 +136,45 @@ class JavaSafemodeOptions(str, Enum):
     AP_LOADED_CHECK = "ap-loaded-check"
 
 
+JAVA_SAFEMODE_ALL = "all"  # magic value for *all* options from JavaSafemodeOptions
 JAVA_SAFEMODE_ALL_OPTIONS = [o.value for o in JavaSafemodeOptions]
 JAVA_SAFEMODE_DEFAULT_OPTIONS = [
     JavaSafemodeOptions.PROFILED_OOM.value,
     JavaSafemodeOptions.PROFILED_SIGNALED.value,
     JavaSafemodeOptions.HSERR.value,
 ]
 
-# https://github.com/jvm-profiling-tools/async-profiler/blob/63799a6055363cbd7ca8ef951e2393db0d0ba7dd/src/profiler.cpp#L77
-JAVA_ASYNC_PROFILER_DEFAULT_SAFEMODE = 256  # StackRecovery.PROBE_SP
 
 SUPPORTED_AP_MODES = ["cpu", "itimer", "alloc"]
 
+
+# see StackWalkFeatures
+# https://github.com/async-profiler/async-profiler/blob/a17529378b47e6700d84f89d74ca5e6284ffd1a6/src/arguments.h#L95-L112
+class AsyncProfilerFeatures(str, Enum):
+    # these will be controllable via "features" in a future AP release:
+    #
+    # unknown_java
+    # unwind_stub
+    # unwind_comp
+    # unwind_native
+    # java_anchor
+    # gc_traces
+
+    # these are controllable via "features" in AP 3.0
+    probe_sp = "probesp"
+    vtable_target = "vtable"
+    comp_task = "comptask"
+    # as of AP 3.0
+
+
+SUPPORTED_AP_FEATURES = [o.value for o in AsyncProfilerFeatures]
+DEFAULT_AP_FEATURES = [AsyncProfilerFeatures.probe_sp.value, AsyncProfilerFeatures.vtable_target.value]
+
+# see options still here and not in "features":
+# https://github.com/async-profiler/async-profiler/blob/a17529378b47e6700d84f89d74ca5e6284ffd1a6/src/arguments.cpp#L262
+# we don't want any of them disabled by default.
+JAVA_ASYNC_PROFILER_DEFAULT_SAFEMODE = 0
+
 PROBLEMATIC_FRAME_REGEX = re.compile(r"^# Problematic frame:\n# (.*?)\n#\n", re.MULTILINE | re.DOTALL)
 """
 See VMError::report.
@@ -239,7 +264,7 @@ def __init__(self, stop_event: Event, jattach_timeout: int):
     def run(self, process: Process, cmd: str) -> str:
         try:
             return run_process(
-                [asprof_path(), "jcmd", "--jattach-cmd", cmd, str(process.pid)],
+                [asprof_path(), "jcmd", str(process.pid), cmd],
                 stop_event=self.stop_event,
                 timeout=self.jattach_timeout,
             ).stdout.decode()
@@ -467,6 +492,7 @@ def __init__(
         profiler_state: ProfilerState,
         mode: str,
         ap_safemode: int,
+        ap_features: List[str],
         ap_args: str,
         jattach_timeout: int = _DEFAULT_JATTACH_TIMEOUT,
         mcache: int = 0,
@@ -517,6 +543,7 @@ def __init__(
         self._mode = mode
         self._fdtransfer_path = f"@async-profiler-{process.pid}-{secrets.token_hex(10)}" if mode == "cpu" else None
         self._ap_safemode = ap_safemode
+        self._ap_features = ap_features
         self._ap_args = ap_args
         self._jattach_timeout = jattach_timeout
         self._mcache = mcache
@@ -651,10 +678,10 @@ def _check_disk_requirements(self) -> None:
     def _get_base_cmd(self) -> List[str]:
         return [
             asprof_path(),
-            "jattach",
-            "-L",
+            str(self.process.pid),
+            "load",
             self._libap_path_process,
-            "--jattach-cmd",
+            "true",  # 'true' means the given path ^^ is absolute.
         ]
 
     def _get_extra_ap_args(self) -> str:
@@ -677,7 +704,9 @@ def _get_start_cmd(self, interval: int, ap_timeout: int) -> List[str]:
             f"{self._get_ap_output_args()}{self._get_interval_arg(interval)},"
             f"log={self._log_path_process}"
             f"{f',fdtransfer={self._fdtransfer_path}' if self._mode == 'cpu' else ''}"
-            f",safemode={self._ap_safemode},timeout={ap_timeout}"
+            f",safemode={self._ap_safemode},"
+            f",features={'+'.join(self._ap_features)},"  # asprof uses '+' as a separator: https://github.com/async-profiler/async-profiler/blob/a17529378b47e6700d84f89d74ca5e6284ffd1a6/src/launcher/main.cpp#L441  # noqa
+            f"timeout={ap_timeout}"
             f"{',lib' if self._profiler_state.insert_dso_name else ''}{self._get_extra_ap_args()}"
         ]
 
@@ -705,7 +734,7 @@ def _run_async_profiler(self, cmd: List[str]) -> str:
         try:
             # kill jattach with SIGTERM if it hangs. it will go down
             run_process(
-                cmd + [str(self.process.pid)],
+                cmd,
                 stop_event=self._profiler_state.stop_event,
                 timeout=self._jattach_timeout,
                 kill_signal=signal.SIGTERM,
@@ -773,7 +802,10 @@ def start_async_profiler(self, interval: int, second_try: bool = False, ap_timeo
             if e.is_ap_loaded:
                 if (
                     e.returncode == 200  # 200 == AP's COMMAND_ERROR
-                    and e.get_ap_log() == "[ERROR] Profiler already started\n"
+                    # this is the error we get when we try to start AP on a process that already has it loaded.
+                    # check with "in" and not "==" in case other warnings/infos are printed alongside it,
+                    # but generally, we expect it to be the only output in this case.
+                    and "[ERROR] Profiler already started\n" in e.get_ap_log()
                 ):
                     # profiler was already running
                     return False
@@ -817,11 +849,22 @@ def read_output(self) -> Optional[str]:
             "--java-async-profiler-safemode",
             dest="java_async_profiler_safemode",
             default=JAVA_ASYNC_PROFILER_DEFAULT_SAFEMODE,
-            type=integer_range(0, 0x200),
-            metavar="[0-511]",
+            type=integer_range(0, 0x40),
+            metavar="[0-63]",
             help="Controls the 'safemode' parameter passed to async-profiler. This is parameter denotes multiple"
-            " bits that describe different stack recovery techniques which async-profiler uses (see StackRecovery"
-            " enum in async-profiler's code, in profiler.cpp)."
+            " bits that describe different stack recovery techniques which async-profiler uses. In a future release,"
+            " these optinos will be migrated to the 'features' parameter."
+            " Defaults to '%(default)s'.",
+        ),
+        ProfilerArgument(
+            "--java-async-profiler-features",
+            dest="java_async_profiler_features",
+            default=DEFAULT_AP_FEATURES,
+            metavar=",".join(SUPPORTED_AP_FEATURES),
+            type=functools.partial(comma_separated_enum_list, SUPPORTED_AP_FEATURES),
+            help="Controls the 'features' parameter passed to async-profiler. This is parameter is a comma-separated"
+            " list of options which describe async-profiler's available features (see StackWalkFeatures"
+            " enum in async-profiler's code, in arguments.h)."
             " Defaults to '%(default)s').",
         ),
         ProfilerArgument(
@@ -933,6 +976,7 @@ def __init__(
         java_version_check: bool,
         java_async_profiler_mode: str,
         java_async_profiler_safemode: int,
+        java_async_profiler_features: List[str],
         java_async_profiler_args: str,
         java_safemode: str,
         java_jattach_timeout: int,
@@ -957,6 +1001,7 @@ def __init__(
             logger.warning("Java version checks are disabled")
         self._init_ap_mode(self._profiler_state.profiling_mode, java_async_profiler_mode)
         self._ap_safemode = java_async_profiler_safemode
+        self._ap_features = java_async_profiler_features
         self._ap_args = java_async_profiler_args
         self._jattach_timeout = java_jattach_timeout
         self._ap_mcache = java_async_profiler_mcache
@@ -1214,6 +1259,7 @@ def _profile_process(self, process: Process, duration: int, spawned: bool) -> Pr
             self._profiler_state,
             self._mode,
             self._ap_safemode,
+            self._ap_features,
             self._ap_args,
             self._jattach_timeout,
             self._ap_mcache,

scripts/async_profiler_build_shared.sh

@@ -5,8 +5,8 @@
 #
 set -euo pipefail
 
-VERSION=v2.10g2
-GIT_REV="40b850a4101756bc398051661d1adbbe5d7e2211"
+VERSION=v3.0g1
+GIT_REV="952b30f9d28aeb9cb9e418ed6f60772dfdf83e46"
 
 git clone --depth 1 -b "$VERSION" https://github.com/Granulate/async-profiler.git && cd async-profiler && git reset --hard "$GIT_REV"
 make all

tests/test_java.py

@@ -126,6 +126,7 @@ def test_async_profiler_already_running(
             profiler_state=profiler._profiler_state,
             mode=profiler._mode,
             ap_safemode=0,
+            ap_features=[],
             ap_args="",
         ) as ap_proc:
             assert ap_proc.start_async_profiler(frequency_to_ap_interval(11))
@@ -136,6 +137,7 @@ def test_async_profiler_already_running(
             profiler_state=profiler._profiler_state,
             mode="itimer",
             ap_safemode=0,
+            ap_features=[],
             ap_args="",
         ) as ap_proc:
             ap_proc.status_async_profiler()
@@ -370,6 +372,7 @@ def test_async_profiler_stops_after_given_timeout(
         profiler_state=profiler_state,
         mode="itimer",
         ap_safemode=0,
+        ap_features=[],
         ap_args="",
     ) as ap_proc:
         assert ap_proc.start_async_profiler(frequency_to_ap_interval(11), ap_timeout=timeout_s)
@@ -466,12 +469,12 @@ def test_java_deleted_libjvm(
 def filter_jattach_load_records(records: List[LogRecord]) -> List[LogRecord]:
     def _filter_record(r: LogRecord) -> bool:
         # find the log record of
-        # Running command (command=['/app/gprofiler/resources/java/apsprof', 'jattach',
-        # '-L', '/path/to/libasyncProfiler.so', "--jattach-cmd", "start,..."])
+        # Running command (command=['/app/gprofiler/resources/java/apsprof', '<PID>', 'load',
+        # '/path/to/libasyncProfiler.so', 'true', 'start,...'])
         return (
             r.message == "Running command"
-            and len(log_record_extra(r)["command"]) >= 6
-            and log_record_extra(r)["command"][1] == "jattach"
+            and len(log_record_extra(r)["command"]) == 6
+            and log_record_extra(r)["command"][2] == "load"
             and any(map(lambda k: k in log_record_extra(r)["command"][5], ["start,", "stop,"]))
         )
 
@@ -916,6 +919,7 @@ def flush_output_and_stop_async_profiler(self: AsyncProfiledProcess, *args: Any,
             profiler_state=profiler._profiler_state,
             mode="itimer",
             ap_safemode=0,
+            ap_features=[],
             ap_args="",
         ) as ap_proc:
             ap_version = ap_proc.read_ap_version()

tests/utils.py

@@ -25,6 +25,7 @@
 from gprofiler.metadata import ProfileMetadata
 from gprofiler.profiler_state import ProfilerState
 from gprofiler.profilers.java import (
+    DEFAULT_AP_FEATURES,
     JAVA_ASYNC_PROFILER_DEFAULT_SAFEMODE,
     JAVA_SAFEMODE_ALL,
     AsyncProfiledProcess,
@@ -207,6 +208,7 @@ def make_java_profiler(
     java_version_check: bool = True,
     java_async_profiler_mode: str = "cpu",
     java_async_profiler_safemode: int = JAVA_ASYNC_PROFILER_DEFAULT_SAFEMODE,
+    java_async_profiler_features: List[str] = DEFAULT_AP_FEATURES,
     java_async_profiler_args: str = "",
     java_safemode: str = JAVA_SAFEMODE_ALL,
     java_jattach_timeout: int = AsyncProfiledProcess._DEFAULT_JATTACH_TIMEOUT,
@@ -226,6 +228,7 @@ def make_java_profiler(
         java_version_check=java_version_check,
         java_async_profiler_mode=java_async_profiler_mode,
         java_async_profiler_safemode=java_async_profiler_safemode,
+        java_async_profiler_features=java_async_profiler_features,
         java_async_profiler_args=java_async_profiler_args,
         java_safemode=java_safemode,
         java_jattach_timeout=java_jattach_timeout,