[FIX] profiling: manage long calls with the GIL

Sometimes the profiler provides confusing information.  This happens
when calling a C library without releasing the GIL (Python's global
interpreter lock).  The time spent in the call will be attributed by the
profiler to the former stack trace, because the collector cannot run
during the call.

This commit adds information on the frame when a given stack frame has
lasted for too long.

X-original-commit: 5e193c5dbcdfbdbab38309ed292131ae1f5d3026

odoo/tools/profiler.py

@@ -166,9 +166,21 @@ class PeriodicCollector(Collector):
 
     def run(self):
         self.active = True
+        last_time = time.time()
         while self.active:  # maybe add a check on parent_thread state?
+            duration = time.time() - last_time
+            if duration > self.frame_interval * 10 and self.last_frame:
+                # The profiler has unexpectedly slept for more than 10 frame intervals. This may
+                # happen when calling a C library without releasing the GIL. In that case, the
+                # last frame was taken before the call, and the next frame is after the call, and
+                # the call itself does not appear in any of those frames: the duration of the call
+                # is incorrectly attributed to the last frame.
+                self._entries[-1]['stack'].append(('profiling', 0, '⚠ Profiler freezed for %s s' % duration, ''))
+                self.last_frame = None  # skip duplicate detection for the next frame.
             self.add()
+            last_time = time.time()
             time.sleep(self.frame_interval)
+
         self._entries.append({'stack': [], 'start': time.time()})  # add final end frame
 
     def start(self):