fix(profiling): access lock acquired time only when the lock is held (#11881)

Manual backport of #11811 to 2.19

Author: taegyunkim

ddtrace/profiling/collector/_lock.py

@@ -179,69 +179,63 @@ def acquire(self, *args, **kwargs):
 
     def _release(self, inner_func, *args, **kwargs):
         # type (typing.Any, typing.Any) -> None
+
+        start = None
+        if hasattr(self, "_self_acquired_at"):
+            # _self_acquired_at is only set when the acquire was captured
+            # if it's not set, we're not capturing the release
+            start = self._self_acquired_at
+
         try:
             return inner_func(*args, **kwargs)
         finally:
-            try:
-                if hasattr(self, "_self_acquired_at"):
-                    try:
-                        end = compat.monotonic_ns()
-                        thread_id, thread_name = _current_thread()
-                        task_id, task_name, task_frame = _task.get_task(thread_id)
-                        lock_name = (
-                            "%s:%s" % (self._self_init_loc, self._self_name) if self._self_name else self._self_init_loc
-                        )
-
-                        if task_frame is None:
-                            # See the comments in _acquire
-                            frame = sys._getframe(2)
-                        else:
-                            frame = task_frame
-
-                        frames, nframes = _traceback.pyframe_to_frames(frame, self._self_max_nframes)
-
-                        if self._self_export_libdd_enabled:
-                            thread_native_id = _threading.get_thread_native_id(thread_id)
-
-                            handle = ddup.SampleHandle()
-                            handle.push_monotonic_ns(end)
-                            handle.push_lock_name(lock_name)
-                            handle.push_release(
-                                end - self._self_acquired_at, 1
-                            )  # AFAICT, capture_pct does not adjust anything here
-                            handle.push_threadinfo(thread_id, thread_native_id, thread_name)
-                            handle.push_task_id(task_id)
-                            handle.push_task_name(task_name)
-
-                            if self._self_tracer is not None:
-                                handle.push_span(self._self_tracer.current_span())
-                            for frame in frames:
-                                handle.push_frame(frame.function_name, frame.file_name, 0, frame.lineno)
-                            handle.flush_sample()
-                        else:
-                            event = self.RELEASE_EVENT_CLASS(
-                                lock_name=lock_name,
-                                frames=frames,
-                                nframes=nframes,
-                                thread_id=thread_id,
-                                thread_name=thread_name,
-                                task_id=task_id,
-                                task_name=task_name,
-                                locked_for_ns=end - self._self_acquired_at,
-                                sampling_pct=self._self_capture_sampler.capture_pct,
-                            )
-
-                            if self._self_tracer is not None:
-                                event.set_trace_info(
-                                    self._self_tracer.current_span(), self._self_endpoint_collection_enabled
-                                )
-
-                            self._self_recorder.push_event(event)
-                    finally:
-                        del self._self_acquired_at
-            except Exception as e:
-                LOG.warning("Error recording lock release event: %s", e)
-                pass  # nosec
+            if start is not None:
+                end = time.monotonic_ns()
+                thread_id, thread_name = _current_thread()
+                task_id, task_name, task_frame = _task.get_task(thread_id)
+                lock_name = "%s:%s" % (self._self_init_loc, self._self_name) if self._self_name else self._self_init_loc
+
+                if task_frame is None:
+                    # See the comments in _acquire
+                    frame = sys._getframe(2)
+                else:
+                    frame = task_frame
+
+                frames, nframes = _traceback.pyframe_to_frames(frame, self._self_max_nframes)
+
+                if self._self_export_libdd_enabled:
+                    thread_native_id = _threading.get_thread_native_id(thread_id)
+
+                    handle = ddup.SampleHandle()
+                    handle.push_monotonic_ns(end)
+                    handle.push_lock_name(lock_name)
+                    handle.push_release(end - start, 1)  # AFAICT, capture_pct does not adjust anything here
+                    handle.push_threadinfo(thread_id, thread_native_id, thread_name)
+                    handle.push_task_id(task_id)
+                    handle.push_task_name(task_name)
+
+                    if self._self_tracer is not None:
+                        handle.push_span(self._self_tracer.current_span())
+                    for frame in frames:
+                        handle.push_frame(frame.function_name, frame.file_name, 0, frame.lineno)
+                    handle.flush_sample()
+                else:
+                    event = self.RELEASE_EVENT_CLASS(
+                        lock_name=lock_name,
+                        frames=frames,
+                        nframes=nframes,
+                        thread_id=thread_id,
+                        thread_name=thread_name,
+                        task_id=task_id,
+                        task_name=task_name,
+                        locked_for_ns=end - start,
+                        sampling_pct=self._self_capture_sampler.capture_pct,
+                    )
+
+                    if self._self_tracer is not None:
+                        event.set_trace_info(self._self_tracer.current_span(), self._self_endpoint_collection_enabled)
+
+                    self._self_recorder.push_event(event)
 
     def release(self, *args, **kwargs):
         return self._release(self.__wrapped__.release, *args, **kwargs)

releasenotes/notes/profiling-lock-acquired-at-e308547cffdca9f7.yaml

@@ -0,0 +1,6 @@
+---
+fixes:
+  - |
+    profiling: This fix resolves a data race issue accessing lock's acquired
+    time, leading to an ``AttributeError``: ``_Profiled_ThreadingLock`` object
+    has no attribute ``self_acquired_at``