From b9ec2ee3db2fc8d41a3fbfe34184e716c23c4037 Mon Sep 17 00:00:00 2001
From: bdieterm <119257544+bdieterm@users.noreply.github.com>
Date: Sun, 11 Aug 2024 00:41:17 +0200
Subject: [PATCH] Gui: improve performance of macro execution and fix time
 measurement

This commit improves the performance of Python code from FreeCAD macros by:
* using the chrono C++ stdlib header instead of QTime
* checking for the elapsed time ONLY every 1000th Python opcode execution

And this commit fixes time measurement by using a monotonic time source
instead of a normal one.
The previous implementation using QTime would give a negative time duration
if the start time is 23:59:59 and the end time is 00:00:01.

related commit: beeda0e47f051722d6096c99bd949b390e197bdc
---
 src/Gui/PythonTracing.cpp | 27 +++++++++++++++++++++------
 1 file changed, 21 insertions(+), 6 deletions(-)

diff --git a/src/Gui/PythonTracing.cpp b/src/Gui/PythonTracing.cpp
index e6063cdacf..e80afb8ed8 100644
--- a/src/Gui/PythonTracing.cpp
+++ b/src/Gui/PythonTracing.cpp
@@ -25,16 +25,21 @@
 #ifndef _PreComp_
 #include <QApplication>
 #include <QKeyEvent>
-#include <QTime>
 #include <QGuiApplication>
 #endif
 
+#include <chrono>
+
 #include "PythonTracing.h"
 #include <App/Application.h>
 #include <Base/Interpreter.h>
 
 using namespace Gui;
 
+using Clock = std::chrono::steady_clock;
+using TimePoint = std::chrono::time_point<Clock>;
+
+
 struct PythonTracing::Private
 {
     bool active{false};
@@ -124,6 +129,10 @@ void PythonTracing::setPythonTraceEnabled(bool enabled) const
  * This callback ensures that Qt runs its event loop (i.e. updates the GUI, processes keyboard and
  * mouse events, etc.) at least every 200 ms, even when there is long-running Python code on the
  * main thread. It is registered as the global trace function of the Python environment.
+ *
+ * WARNING! THIS IS PERFORMANCE-CRITICAL CODE!
+ * This callback is even called for per-opcode events in the Python code, so unoptimized code could
+ * dramatically slow down the execution of Python code and FreeCAD macros.
  */
 int PythonTracing::tracer_callback(PyObject *obj, PyFrameObject *frame, int what, PyObject *arg)
 {
@@ -132,8 +141,15 @@ int PythonTracing::tracer_callback(PyObject *obj, PyFrameObject *frame, int what
     Q_UNUSED(what)
     Q_UNUSED(arg)
 
-    static QTime lastCalledTime = QTime::currentTime();
-    QTime currTime = QTime::currentTime();
+    // no need to check the time at every single Python opcode execution
+    static int skipCounter = 0;
+    if (++skipCounter < 1000) {
+        return 0;
+    }
+    skipCounter = 0;
+
+    static TimePoint lastCalledTime = Clock::now();
+    TimePoint currTime = Clock::now();
 
     // if previous code object was executed
     if (Private::profilerDisabled) {
@@ -141,9 +157,8 @@ int PythonTracing::tracer_callback(PyObject *obj, PyFrameObject *frame, int what
         lastCalledTime = currTime;
     }
 
-    int ms = lastCalledTime.msecsTo(currTime);
-
-    if (ms >= Private::profilerInterval) {
+    const std::chrono::duration<double> duration = currTime - lastCalledTime;
+    if (1000.0 * duration.count() >= static_cast<double>(Private::profilerInterval)) {
         lastCalledTime = currTime;
         QGuiApplication::processEvents();
     }