Browse Source

Correctly symbolicate mixed Stack Traces (eg JS/wasm) (#49752)

This will first go through `symbolicate_event` symbolicating JS frames,
and afterwards schedule another `symbolicate_event` for native if
needed.

Another change here is to gradually migrate from using `file_id` as the
`id` that is sent to symbolicator and used as a cache key there to the
entity-prefixed `download_id` which does not suffer from cache
collisions.
Arpad Borsos 1 year ago
parent
commit
9af199e2d7

+ 47 - 19
src/sentry/api/endpoints/artifact_lookup.py

@@ -46,7 +46,10 @@ class ProjectArtifactLookupEndpoint(ProjectEndpoint):
     permission_classes = (ProjectReleasePermission,)
 
     def download_file(self, download_id, project: Project):
-        ty, ty_id = download_id.split("/")
+        split = download_id.split("/")
+        if len(split) < 2:
+            raise Http404
+        ty, ty_id = split
 
         rate_limited = ratelimits.is_limited(
             project=project,
@@ -131,10 +134,10 @@ class ProjectArtifactLookupEndpoint(ProjectEndpoint):
         used_artifact_bundles = dict()
         bundle_file_ids = set()
 
-        def update_bundles(inner_bundles: Set[Tuple[int, datetime, int]]):
+        def update_bundles(inner_bundles: Set[Tuple[int, datetime]]):
             for (bundle_id, date_added, file_id) in inner_bundles:
                 used_artifact_bundles[bundle_id] = date_added
-                bundle_file_ids.add(("artifact_bundle", bundle_id, file_id))
+                bundle_file_ids.add((f"artifact_bundle/{bundle_id}", file_id))
 
         if debug_id:
             bundles = get_artifact_bundles_containing_debug_id(debug_id, project)
@@ -153,7 +156,7 @@ class ProjectArtifactLookupEndpoint(ProjectEndpoint):
             release, dist = try_resolve_release_dist(project, release_name, dist_name)
             if release:
                 for (releasefile_id, file_id) in get_legacy_release_bundles(release, dist):
-                    bundle_file_ids.add(("release_file", releasefile_id, file_id))
+                    bundle_file_ids.add((f"release_file/{releasefile_id}", file_id))
                 individual_files = get_legacy_releasefile_by_file_url(release, dist, url)
 
         if options.get("sourcemaps.artifact-bundles.enable-renewal") == 1.0:
@@ -164,26 +167,44 @@ class ProjectArtifactLookupEndpoint(ProjectEndpoint):
         # Then: Construct our response
         url_constructor = UrlConstructor(request, project)
 
+        # NOTE: the reason we still use the `file_id` as the `id` we return is
+        # because downstream symbolicator relies on that for its internal caching.
+        # We do not want to hard-refresh those caches, so we will rather do a
+        # gradual update here.
+        # The problem with using the `file_id` is that it could potentially
+        # conflict with the `ProjectDebugFile` id that is returned by the
+        # `debug_files` end point and powers native symbolication.
+        # A native debug file (ProjectDebugFile.id) could in theory conflict
+        # with a JS bundle (File.id). Moving over to `download_id` removes that
+        # conflict, as the `download_id` is prefixed with the entity.
+        def pick_id_to_return(download_id: str, file_id: int) -> str:
+            # the sampling here happens based on the `project_id`, to have
+            # stable cutover based on project, and we don’t balloon the cache
+            # size by randomly using either this or the other id for the same
+            # events.
+            should_use_new_id = (
+                project.id % 1000 < options.get("symbolicator.sourcemap-lookup-id-rate") * 1000
+            )
+            return download_id if should_use_new_id else str(file_id)
+
         found_artifacts = []
-        # NOTE: the reason we use the `file_id` as the `id` we return is because
-        # downstream symbolicator relies on that for its internal caching.
-        # We do not want to hard-refresh those caches quite yet, and the `id`
-        # should also be as unique as possible, which the `file_id` is.
-        for (ty, ty_id, file_id) in bundle_file_ids:
+        for (download_id, file_id) in bundle_file_ids:
             found_artifacts.append(
                 {
-                    "id": str(file_id),
+                    "id": pick_id_to_return(download_id, file_id),
                     "type": "bundle",
-                    "url": url_constructor.url_for_file_id(ty, ty_id),
+                    "url": url_constructor.url_for_file_id(download_id),
                 }
             )
 
         for release_file in individual_files:
+            file_id = release_file.file.id
+            download_id = f"release_file/{release_file.id}"
             found_artifacts.append(
                 {
-                    "id": str(release_file.file.id),
+                    "id": pick_id_to_return(download_id, file_id),
                     "type": "file",
-                    "url": url_constructor.url_for_file_id("release_file", release_file.id),
+                    "url": url_constructor.url_for_file_id(download_id),
                     # The `name` is the url/abs_path of the file,
                     # as in: `"~/path/to/file.min.js"`.
                     "abs_path": release_file.name,
@@ -193,7 +214,15 @@ class ProjectArtifactLookupEndpoint(ProjectEndpoint):
             )
 
         # make sure we have a stable sort order for tests
-        found_artifacts.sort(key=lambda x: int(x["id"]))
+        def natural_sort(key: str) -> Tuple[str, int]:
+            split = key.split("/")
+            if len(split) > 1:
+                ty, ty_id = split
+                return (ty, int(ty_id))
+            else:
+                return int(split[0])
+
+        found_artifacts.sort(key=lambda x: natural_sort(x["id"]))
 
         # NOTE: We do not paginate this response, as we have very tight limits on all the individual queries.
         return Response(serialize(found_artifacts, request.user))
@@ -245,6 +274,7 @@ def get_artifact_bundles_containing_debug_id(
     return set(
         ArtifactBundle.objects.filter(
             organization_id=project.organization.id,
+            projectartifactbundle__project_id=project.id,
             debugidartifactbundle__debug_id=debug_id,
         )
         .values_list("id", "date_added", "file_id")
@@ -306,9 +336,7 @@ def get_legacy_release_bundles(
             artifact_count=0,
             # similarly the special `type` is also used for release archives.
             file__type=RELEASE_BUNDLE_TYPE,
-        )
-        .select_related("file")
-        .values_list("id", "file_id")
+        ).values_list("id", "file_id")
         # TODO: this `order_by` might be incredibly slow
         # we want to have a hard limit on the returned bundles here. and we would
         # want to pick the most recently uploaded ones. that should mostly be
@@ -341,11 +369,11 @@ class UrlConstructor:
         else:
             self.base_url = request.build_absolute_uri(request.path)
 
-    def url_for_file_id(self, ty: str, file_id: int) -> str:
+    def url_for_file_id(self, download_id: str) -> str:
         # NOTE: Returning a self-route that requires authentication (via Bearer token)
         # is not really forward compatible with a pre-signed URL that does not
         # require any authentication or headers whatsoever.
         # This also requires a workaround in Symbolicator, as its generic http
         # downloader blocks "internal" IPs, whereas the internal Sentry downloader
         # is explicitly exempt.
-        return f"{self.base_url}?download={ty}/{file_id}"
+        return f"{self.base_url}?download={download_id}"

+ 2 - 2
src/sentry/lang/native/processing.py

@@ -1,6 +1,6 @@
 import logging
 import posixpath
-from typing import Any, Callable, Set
+from typing import Any, Callable, Optional, Set
 
 from symbolic import ParseDebugIdError, normalize_debug_id
 
@@ -446,7 +446,7 @@ def process_native_stacktraces(symbolicator: Symbolicator, data: Any) -> Any:
     return data
 
 
-def get_native_symbolication_function(data) -> Callable[[Symbolicator, Any], Any]:
+def get_native_symbolication_function(data) -> Optional[Callable[[Symbolicator, Any], Any]]:
     if is_minidump_event(data):
         return process_minidump
     elif is_applecrashreport_event(data):

+ 3 - 0
src/sentry/lang/native/symbolicator.py

@@ -40,6 +40,9 @@ class SymbolicatorTaskKind:
     def with_low_priority(self, is_low_priority: bool) -> "SymbolicatorTaskKind":
         return dataclasses.replace(self, is_low_priority=is_low_priority)
 
+    def with_js(self, is_js: bool) -> "SymbolicatorTaskKind":
+        return dataclasses.replace(self, is_js=is_js)
+
 
 class SymbolicatorPools(Enum):
     default = "default"

+ 2 - 0
src/sentry/options/defaults.py

@@ -360,6 +360,8 @@ register("symbolicator.sourcemaps-processing-projects", type=Sequence, default=[
 register("symbolicator.sourcemaps-processing-sample-rate", default=0.0)
 # Use a fraction of Symbolicator Source Maps processing events for A/B testing.
 register("symbolicator.sourcemaps-processing-ab-test", default=0.0)
+# Gradually migrate from file_id to download_id
+register("symbolicator.sourcemap-lookup-id-rate", default=0.0)
 
 # Normalization after processors
 register("store.normalize-after-processing", default=0.0)  # unused

+ 6 - 14
src/sentry/tasks/store.py

@@ -112,7 +112,11 @@ def _do_preprocess_event(
     project: Optional[Project],
     has_attachments: bool = False,
 ) -> None:
-    from sentry.tasks.symbolication import should_demote_symbolication, submit_symbolicate
+    from sentry.tasks.symbolication import (
+        get_symbolication_function,
+        should_demote_symbolication,
+        submit_symbolicate,
+    )
 
     if cache_key and data is None:
         data = processing.event_processing_store.get(cache_key)
@@ -139,19 +143,7 @@ def _do_preprocess_event(
             "organization", Organization.objects.get_from_cache(id=project.organization_id)
         )
 
-    is_js = False
-    if data["platform"] in ("javascript", "node"):
-        from sentry.lang.javascript.processing import (
-            get_js_symbolication_function as get_symbolication_function,
-        )
-
-        is_js = True
-    else:
-        from sentry.lang.native.processing import (
-            get_native_symbolication_function as get_symbolication_function,
-        )
-
-    symbolication_function = get_symbolication_function(data)
+    is_js, symbolication_function = get_symbolication_function(data)
     if symbolication_function:
         symbolication_function_name = getattr(symbolication_function, "__name__", "none")
 

+ 43 - 13
src/sentry/tasks/symbolication.py

@@ -1,7 +1,7 @@
 import logging
 import random
 from time import sleep, time
-from typing import Any, Callable, Optional
+from typing import Any, Callable, Optional, Tuple
 
 import sentry_sdk
 from django.conf import settings
@@ -80,6 +80,29 @@ def should_demote_symbolication(project_id: int) -> bool:
             return False
 
 
+def get_symbolication_function(
+    data: Any, is_in_symbolicate_event: bool = False
+) -> Tuple[bool, Optional[Callable[[Symbolicator, Any], Any]]]:
+    # for JS events that have *not* been processed yet:
+    if data["platform"] in ("javascript", "node") and not data.get(
+        "processed_by_symbolicator", False
+    ):
+        from sentry.lang.javascript.processing import (
+            get_js_symbolication_function,
+            process_js_stacktraces,
+        )
+
+        # if we are already in `symbolicate_event`, we do *not* want to sample events
+        if is_in_symbolicate_event:
+            return True, process_js_stacktraces
+        else:
+            return True, get_js_symbolication_function(data)
+    else:
+        from sentry.lang.native.processing import get_native_symbolication_function
+
+        return False, get_native_symbolication_function(data)
+
+
 def _do_symbolicate_event(
     cache_key: str,
     start_time: Optional[int],
@@ -127,7 +150,22 @@ def _do_symbolicate_event(
             )
             return
 
-    def _continue_to_process_event() -> None:
+    def _continue_to_process_event(was_killswitched: bool = False) -> None:
+        # for JS events, we check `get_symbolication_function` again *after*
+        # symbolication, because maybe we need to feed it to another round of
+        # `symbolicate_event`, but for *native* that time.
+        if not was_killswitched and task_kind.is_js:
+            _, symbolication_function = get_symbolication_function(data, True)
+            if symbolication_function:
+                submit_symbolicate(
+                    task_kind=task_kind.with_js(False),
+                    cache_key=cache_key,
+                    event_id=event_id,
+                    start_time=start_time,
+                    has_attachments=has_attachments,
+                )
+                return
+        # else:
         store.submit_process(
             from_reprocessing=task_kind.is_reprocessing,
             cache_key=cache_key,
@@ -138,18 +176,10 @@ def _do_symbolicate_event(
             has_attachments=has_attachments,
         )
 
-    if data["platform"] in ("javascript", "node"):
-        from sentry.lang.javascript.processing import process_js_stacktraces
-
-        symbolication_function = process_js_stacktraces
-    else:
-        from sentry.lang.native.processing import get_native_symbolication_function
-
-        symbolication_function = get_native_symbolication_function(data)
-
+    _, symbolication_function = get_symbolication_function(data, True)
     symbolication_function_name = getattr(symbolication_function, "__name__", "none")
 
-    if killswitch_matches_context(
+    if symbolication_function is None or killswitch_matches_context(
         "store.load-shed-symbolicate-event-projects",
         {
             "project_id": project_id,
@@ -158,7 +188,7 @@ def _do_symbolicate_event(
             "symbolication_function": symbolication_function_name,
         },
     ):
-        return _continue_to_process_event()
+        return _continue_to_process_event(True)
 
     symbolication_start_time = time()
 

BIN
tests/symbolicator/fixtures/a18fd85d4a4eb893022d6bfad846b1.debug


+ 165 - 1
tests/symbolicator/test_payload_full.py

@@ -1,16 +1,27 @@
+import os.path
 import zipfile
 from io import BytesIO
 from unittest.mock import patch
+from uuid import uuid4
 
 import pytest
 from django.core.files.uploadedfile import SimpleUploadedFile
 from django.urls import reverse
 
 from sentry import eventstore
-from sentry.models import File, ProjectDebugFile
+from sentry.models import (
+    ArtifactBundle,
+    DebugIdArtifactBundle,
+    File,
+    ProjectArtifactBundle,
+    ProjectDebugFile,
+    SourceFileType,
+)
 from sentry.testutils import RelayStoreHelper, TransactionTestCase
 from sentry.testutils.factories import get_fixture_path
 from sentry.testutils.helpers.datetime import before_now, iso_format
+from sentry.testutils.helpers.options import override_options
+from sentry.utils import json
 from tests.symbolicator import insta_snapshot_native_stacktrace_data, redact_location
 
 # IMPORTANT:
@@ -63,10 +74,20 @@ REAL_RESOLVING_EVENT_DATA = {
 }
 
 
+def get_local_fixture_path(name):
+    return os.path.join(os.path.dirname(__file__), "fixtures", name)
+
+
+def load_fixture(name):
+    with open(get_local_fixture_path(name), "rb") as fp:
+        return fp.read()
+
+
 class SymbolicatorResolvingIntegrationTest(RelayStoreHelper, TransactionTestCase):
     @pytest.fixture(autouse=True)
     def initialize(self, live_server):
         self.project.update_option("sentry:builtin_symbol_sources", [])
+        self.min_ago = iso_format(before_now(minutes=1))
 
         with patch("sentry.auth.system.is_internal_ip", return_value=True), self.options(
             {"system.url-prefix": live_server.url}
@@ -251,3 +272,146 @@ class SymbolicatorResolvingIntegrationTest(RelayStoreHelper, TransactionTestCase
         candidates = event.data["debug_meta"]["images"][0]["candidates"]
         redact_location(candidates)
         self.insta_snapshot(candidates)
+
+    def test_resolve_mixed_stack_trace(self):
+        # JS debug files:
+        debug_id = "c941d872-af1f-4f0c-a7ff-ad3d295fe153"
+
+        compressed = BytesIO(b"SYSB")
+        with zipfile.ZipFile(compressed, "a") as zip_file:
+            zip_file.writestr("files/_/_/test.min.js", load_fixture("test.min.js"))
+            zip_file.writestr("files/_/_/test.map", load_fixture("test.map"))
+
+            zip_file.writestr(
+                "manifest.json",
+                json.dumps(
+                    {
+                        "files": {
+                            "files/_/_/test.min.js": {
+                                "url": "~/test.min.js",
+                                "type": "minified_source",
+                                "headers": {
+                                    "debug-id": debug_id,
+                                    "sourcemap": "test.map",
+                                },
+                            },
+                            "files/_/_/test.map": {
+                                "url": "~/file.wc.sourcemap.js",
+                                "type": "source_map",
+                                "headers": {
+                                    "debug-id": debug_id,
+                                },
+                            },
+                        },
+                    }
+                ),
+            )
+        compressed.seek(0)
+        bundle_file = File.objects.create(name="bundle.zip", type="artifact.bundle")
+        bundle_file.putfile(compressed)
+
+        artifact_bundle = ArtifactBundle.objects.create(
+            organization_id=self.organization.id,
+            bundle_id=uuid4(),
+            file=bundle_file,
+            artifact_count=2,
+        )
+        ProjectArtifactBundle.objects.create(
+            organization_id=self.organization.id,
+            project_id=self.project.id,
+            artifact_bundle=artifact_bundle,
+        )
+        DebugIdArtifactBundle.objects.create(
+            organization_id=self.organization.id,
+            debug_id=debug_id,
+            artifact_bundle=artifact_bundle,
+            source_file_type=SourceFileType.MINIFIED_SOURCE.value,
+        )
+        DebugIdArtifactBundle.objects.create(
+            organization_id=self.organization.id,
+            debug_id=debug_id,
+            artifact_bundle=artifact_bundle,
+            source_file_type=SourceFileType.SOURCE_MAP.value,
+        )
+
+        # native debug files:
+        wasm_file = File.objects.create(
+            name="test.wasm", type="default", headers={"Content-Type": "application/wasm"}
+        )
+
+        with open(get_local_fixture_path("a18fd85d4a4eb893022d6bfad846b1.debug"), "rb") as f:
+            wasm_file.putfile(f)
+
+        ProjectDebugFile.objects.create(
+            file=wasm_file,
+            object_name="test.wasm",
+            cpu_name="wasm32",
+            project_id=self.project.id,
+            debug_id="bda18fd8-5d4a-4eb8-9302-2d6bfad846b1",
+            code_id="bda18fd85d4a4eb893022d6bfad846b1",
+        )
+
+        data = {
+            "timestamp": self.min_ago,
+            "message": "hello",
+            "platform": "javascript",
+            "release": "abc",
+            "exception": {
+                "values": [
+                    {
+                        "type": "Error",
+                        "stacktrace": {
+                            "frames": [
+                                {
+                                    "abs_path": "http://example.com/test.min.js",
+                                    "lineno": 1,
+                                    "colno": 183,
+                                },
+                                {
+                                    "platform": "native",
+                                    "instruction_addr": "0x8c",
+                                    "addr_mode": "rel:0",
+                                },
+                            ]
+                        },
+                    }
+                ]
+            },
+            "debug_meta": {
+                "images": [
+                    {
+                        "type": "sourcemap",
+                        "debug_id": debug_id,
+                        "code_file": "http://example.com/test.min.js",
+                    },
+                    {
+                        "type": "wasm",
+                        "debug_id": "bda18fd8-5d4a-4eb8-9302-2d6bfad846b1",
+                        "code_id": "bda18fd85d4a4eb893022d6bfad846b1",
+                        "debug_file": "file://foo.invalid/demo.wasm",
+                    },
+                ]
+            },
+        }
+
+        with override_options(
+            {
+                "symbolicator.sourcemaps-processing-sample-rate": 1.0,
+                "symbolicator.sourcemap-lookup-id-rate": 1.0,
+            }
+        ):
+            event = self.post_and_retrieve_event(data)
+
+        exception = event.interfaces["exception"]
+        frames = exception.values[0].stacktrace.frames
+        assert frames[0].abs_path == "http://example.com/test.js"
+        assert frames[0].lineno == 20
+        assert frames[0].colno == 5
+        assert frames[0].context_line == "    invoke(data);"
+
+        assert frames[1].abs_path == "/Users/mitsuhiko/Development/wasm-example/simple/src/lib.rs"
+        assert frames[1].lineno == 19
+        assert frames[1].function == "internal_func"
+
+        images = event.data["debug_meta"]["images"]
+        assert images[1]["debug_status"] == "found"