Logview threadpool (AcademySoftwareFoundation#861)

* Update dispatchQuery to use min_cores

Sorting jobs only by priority causes a situation where low priority jobs can get starved by a constant flow of high priority jobs.
The new formula adds a modifier to the sorting rank to take into account the number of cores the job is requesting and also the number of days the job is waiting on the queue.
Priorities numbers over 200 will mostly override the formula and work as a priority only based scheduling.
sort = priority + (100 * (1 - (job.cores/job.int_min_cores))) + (age in days)

Besides that, also take layer_int_cores_min into account when filtering folder_resourse limitations to avoid allocating more cores than the folder limits.

(cherry picked from commit 566411aeeddc60983a30eabe121fd03263d05525)

* Revert "Update dispatchQuery to use min_cores"

This reverts commit 2eb4936

* Add threadpool logic for handling incoming log update requests

(cherry picked from commit 351e210a9f0d49bfe61e9a57bba349bf1951af4e)

* Suppress known ui warning messages

For some ui process that especially involves multi threading or
concurrent update of widget data, some warnings can happen due to
obsolete function calls. The code has been updated to suppress
a couple of known warnings

(cherry picked from commit dd0c4f900fb75d25d63897b6aacd2d0b02e230f5)

* Fix logview unit tests to work around the threading logic

(cherry picked from commit 09446bbe5f0c631c74525cbc78b0e60ce114a2e2)

* FIx unit tests

* Fix python lint

* Fix python lint

* Fix lint

Signed-off-by: Diego Tavares da Silva <[email protected]>

---------

Signed-off-by: Diego Tavares da Silva <[email protected]>
Co-authored-by: Fermi Perumal <[email protected]>

cuegui/cuegui/Main.py

@@ -92,7 +92,6 @@ def startup(app_name, app_version, argv):
     app.aboutToQuit.connect(closingTime)  # pylint: disable=no-member
     app.exec_()
 
-
 def closingTime():
     """Window close callback."""
     logger.info("Closing all threads...")

cuegui/cuegui/plugins/LogViewPlugin.py

@@ -25,7 +25,9 @@
 import os
 import re
 import string
+import sys
 import time
+import traceback
 
 from qtpy import QtGui
 from qtpy import QtCore
@@ -292,10 +294,40 @@ def line_number_area_paint_event(self, event):
             bottom = top + self.blockBoundingRect(block).height()
             block_number += 1
 
+class LogLoadSignals(QtCore.QObject):
+    """Signals for the LoadLog action"""
+    SIG_LOG_LOAD_ERROR = QtCore.Signal(tuple)
+    SIG_LOG_LOAD_RESULT = QtCore.Signal(str, str)
+    SIG_LOG_LOAD_FINISHED = QtCore.Signal()
+
+class LogLoader(QtCore.QRunnable):
+    """A thread to load logs"""
+    def __init__(self, fn, *args, **kwargs):
+        super(LogLoader, self).__init__()
+        self.fn = fn
+        self.args = args
+        self.kwargs = kwargs
+        self.signals = LogLoadSignals()
+
+    @QtCore.Slot()
+    def run(self):
+        # pylint: disable=bare-except
+        try:
+            content, log_mtime = self.fn(*self.args, **self.kwargs)
+        except:
+            exctype, value = sys.exc_info()[:2]
+            self.signals.SIG_LOG_LOAD_ERROR.emit(
+                (exctype, value, traceback.format_exc()))
+        else:
+            self.signals.SIG_LOG_LOAD_RESULT.emit(content, log_mtime)
+        finally:
+            self.signals.SIG_LOG_LOAD_FINISHED.emit()
 
 class LogViewWidget(QtWidgets.QWidget):
-    """Displays the log file for the selected frame."""
-
+    """
+    Displays the log file for the selected frame
+    """
+    SIG_CONTENT_UPDATED = QtCore.Signal(str, str)
     def __init__(self, parent=None):
         """
         Create the UI elements
@@ -453,6 +485,9 @@ def __init__(self, parent=None):
         self._current_match = 0
         self._content_box.mousePressedSignal.connect(self._on_mouse_pressed)
 
+        self.SIG_CONTENT_UPDATED.connect(self._update_log_content)
+        self.log_thread_pool = QtCore.QThreadPool()
+
     def _on_mouse_pressed(self, pos):
         """
         Mouse press event, to be called when the user scrolls by hand or moves
@@ -788,12 +823,56 @@ def _display_log_content(self):
         """
 
         try:
-            self._update_log()
-            self._new_log = False
+            if not os.path.exists(self._log_file):
+                self._log_file_exists = False
+                content = 'Log file does not exist: %s' % self._log_file
+                self._content_timestamp = time.time()
+                self._update_log_content(content, self._log_mtime)
+            else:
+                # Creating the load logs process as qrunnables so
+                # that they don't block the ui while loading
+                log_loader = LogLoader(self._load_log, self._log_file,
+                    self._new_log, self._log_mtime)
+                log_loader.signals.SIG_LOG_LOAD_RESULT.connect(
+                    self._receive_log_results)
+                log_loader.setAutoDelete(True)
+                self.log_thread_pool.start(log_loader)
+                self.log_thread_pool.waitForDone()
+                self._new_log = False
         finally:
             QtCore.QTimer.singleShot(5000, self._display_log_content)
 
-    def _update_log(self):
+    # pylint: disable=no-self-use
+    @QtCore.Slot()
+    def _load_log(self, log_file, new_log, curr_log_mtime):
+        content = None
+        log_size = int(os.stat(log_file).st_size)
+        if log_size > 1 * 1e6:
+            content = ('Log file size (%0.1f MB) exceeds the size '
+                        'threshold (1.0 MB).'
+                        % float(log_size / (1024 * 1024)))
+        elif not new_log and os.path.exists(log_file):
+            log_mtime = os.path.getmtime(log_file)
+            if log_mtime > curr_log_mtime:
+                curr_log_mtime = log_mtime  # no new updates
+                content = ''
+
+        if content is None:
+            content = ''
+            try:
+                with open(log_file, 'r') as f:
+                    content = f.read()
+            except IOError:
+                content = 'Can not access log file: %s' % log_file
+
+        return content, curr_log_mtime
+
+    @QtCore.Slot()
+    def _receive_log_results(self, content, log_mtime):
+        self.SIG_CONTENT_UPDATED.emit(content, log_mtime)
+
+    @QtCore.Slot(str, str)
+    def _update_log_content(self, content, log_mtime):
         """
         Updates the content of the content box with the content of the log
         file, if necessary. The full path to the log file will be populated in
@@ -813,49 +892,23 @@ def _update_log(self):
                         (if necessary)
         """
 
-        # Get the content of the log file
-        if not self._log_file:
-            return  # There's no log file, nothing to do here!
-        self._path.setText(self._log_file)
-        content = None
-        if not os.path.exists(self._log_file):
-            self._log_file_exists = False
-            content = 'Log file does not exist: %s' % self._log_file
-            self._content_timestamp = time.time()
-        else:
-            log_size = int(os.stat(self._log_file).st_size)
-            if log_size > 5 * 1e6:
-                content = ('Log file size (%0.1f MB) exceeds the size '
-                           'threshold (5.0 MB).'
-                           % float(log_size / (1024 * 1024)))
-            elif not self._new_log and os.path.exists(self._log_file):
-                log_mtime = os.path.getmtime(self._log_file)
-                if log_mtime > self._log_mtime:
-                    self._log_mtime = log_mtime  # no new updates
-                    content = ''
-
-        if content is None:
-            content = ''
-            try:
-                with open(self._log_file, 'r') as f:
-                    content = f.read()
-            except IOError:
-                content = 'Can not access log file: %s' % self._log_file
+        self._log_mtime = log_mtime
 
-        # Do we need to scroll to the end?
-        scroll_to_end = (self._scrollbar_max == self._scrollbar_value
-                         or self._new_log)
+        self.app.processEvents()
 
         # Update the content in the gui (if necessary)
-        current_text = (self._content_box.toPlainText() or '')
-        new_text = content.lstrip(str(current_text))
-        if new_text:
-            if self._new_log:
-                self._content_box.setPlainText(content)
-            else:
+        if self._new_log:
+            self._content_box.setPlainText(content)
+        else:
+            current_text = (self._content_box.toPlainText() or '')
+            new_text = content.lstrip(str(current_text))
+            if new_text:
                 self._content_box.appendPlainText(new_text)
-            self._content_timestamp = time.time()
-        self.app.processEvents()
+        self._content_timestamp = time.time()
+        self._path.setText(self._log_file)
+
+        scroll_to_end = (self._scrollbar_max == self._scrollbar_value
+                         or self._new_log)
 
         # Adjust scrollbar value (if necessary)
         self._scrollbar_max = self._log_scrollbar.maximum()

cuegui/tests/plugins/LogViewPlugin_tests.py

@@ -71,21 +71,22 @@ def setUp(self):
 
     def test_shouldDisplayFirstLogFile(self):
         cuegui.app().display_log_file_content.emit([self.logPath1, self.logPath2])
-
+        self.logViewPlugin.logview_widget._receive_log_results(_LOG_TEXT_1, 0)
         self.assertEqual(_LOG_TEXT_1, self.logViewPlugin.logview_widget._content_box.toPlainText())
 
     def test_shouldUpdateLogFile(self):
         cuegui.app().display_log_file_content.emit([self.logPath1, self.logPath2])
+        self.logViewPlugin.logview_widget._receive_log_results(_LOG_TEXT_1, 0)
         new_contents = _LOG_TEXT_1 + '\nanother line at the end'
         self.log1.set_contents(new_contents)
         cuegui.app().display_log_file_content.emit([self.logPath1, self.logPath2])
-
+        self.logViewPlugin.logview_widget._receive_log_results(new_contents, 0)
         self.assertEqual(new_contents, self.logViewPlugin.logview_widget._content_box.toPlainText())
 
     def test_shouldHighlightAllSearchResults(self):
-        cuegui.app().display_log_file_content.emit([self.logPath1, self.logPath2])
+        self.logViewPlugin.logview_widget._receive_log_results(_LOG_TEXT_1, 0)
         self.logViewPlugin.logview_widget._case_stv_checkbox.setCheckState(
-            qtpy.QtCore.Qt.CheckState.Unchecked)
+              qtpy.QtCore.Qt.CheckState.Unchecked)
 
         self.logViewPlugin.logview_widget._search_box.setText('lorem')
         self.logViewPlugin.logview_widget._search_button.click()
@@ -100,7 +101,7 @@ def test_shouldHighlightAllSearchResults(self):
                 self.logViewPlugin.logview_widget._content_box, matches[1][0], matches[1][1]))
 
     def test_shouldMoveCursorToSecondSearchResult(self):
-        cuegui.app().display_log_file_content.emit([self.logPath1, self.logPath2])
+        self.logViewPlugin.logview_widget._receive_log_results(_LOG_TEXT_1, 0)
         self.logViewPlugin.logview_widget._case_stv_checkbox.setCheckState(
             qtpy.QtCore.Qt.CheckState.Unchecked)
 
@@ -114,7 +115,7 @@ def test_shouldMoveCursorToSecondSearchResult(self):
         self.assertEqual(132, self.logViewPlugin.logview_widget._cursor.position())
 
     def test_shouldMoveCursorLastSearchResult(self):
-        cuegui.app().display_log_file_content.emit([self.logPath1, self.logPath2])
+        self.logViewPlugin.logview_widget._receive_log_results(_LOG_TEXT_1, 0)
         self.logViewPlugin.logview_widget._case_stv_checkbox.setCheckState(
             qtpy.QtCore.Qt.CheckState.Unchecked)
 
@@ -128,10 +129,9 @@ def test_shouldMoveCursorLastSearchResult(self):
         self.assertEqual(132, self.logViewPlugin.logview_widget._cursor.position())
 
     def test_shouldPerformCaseInsensitiveSearch(self):
-        cuegui.app().display_log_file_content.emit([self.logPath1, self.logPath2])
+        self.logViewPlugin.logview_widget._receive_log_results(_LOG_TEXT_1, 0)
         self.logViewPlugin.logview_widget._case_stv_checkbox.setCheckState(
             qtpy.QtCore.Qt.CheckState.Checked)
-
         self.logViewPlugin.logview_widget._search_box.setText('lorem')
         self.logViewPlugin.logview_widget._search_button.click()
         matches = self.logViewPlugin.logview_widget._matches