Remove spurious logging. Start 10ms timer at a better time.

The 10ms timer was paused for five seconds when starting a track to
avoid a short pause (issue #223). That fixed the problem. However, it
doesn't need to be started until the fade graph starts changing, so we
now don't start it until then. It's possible that this may help the
occasional 'slow to refresh after moving tracks' issue that has been
seen which may be caused by timer ticks piling up and needing to be
serviced.

app/music_manager.py

@@ -154,14 +154,11 @@ class _FadeCurve:
 
         if self.region is None:
             # Create the region now that we're into fade
-            log.debug("issue223: _FadeCurve: create region")
             self.region = pg.LinearRegionItem([0, 0], bounds=[0, len(self.graph_array)])
             self.GraphWidget.addItem(self.region)
 
         # Update region position
         if self.region:
-            # Next line is very noisy
-            # log.debug("issue223: _FadeCurve: update region")
             self.region.setRegion([0, ms_of_graph * self.ms_to_array_factor])
 
 
@@ -578,7 +575,6 @@ class RowAndTrack:
     def play(self, position: Optional[float] = None) -> None:
         """Play track"""
 
-        log.debug(f"issue223: RowAndTrack: play {self.track_id=}")
         now = dt.datetime.now()
         self.start_time = now
 

app/musicmuster.py

@@ -1191,8 +1191,6 @@ class Window(QMainWindow, Ui_MainWindow):
         - Update headers
         """
 
-        log.debug(f"issue223: play_next({position=})")
-
         # If there is no next track set, return.
         if track_sequence.next is None:
             log.error("musicmuster.play_next(): no next track selected")
@@ -1203,10 +1201,9 @@ class Window(QMainWindow, Ui_MainWindow):
             return
 
         # Issue #223 concerns a very short pause (maybe 0.1s) sometimes
-        # when starting to play at track.
-
-        # Resolution appears to be to disable timer10 for a short time.
-        # Length of time and re-enabling of timer10 both in update_clocks.
+        # when starting to play at track. Resolution appears to be to
+        # disable timer10 for a short time. Timer is re-enabled in
+        # update_clocks.
 
         self.timer10.stop()
         log.debug("issue223: play_next: 10ms timer disabled")
@@ -1225,38 +1222,29 @@ class Window(QMainWindow, Ui_MainWindow):
 
         # Restore volume if -3dB active
         if self.btnDrop3db.isChecked():
-            log.debug("issue223: play_next: Reset -3db button")
             self.btnDrop3db.setChecked(False)
 
         # Play (new) current track
-        log.info(f"Play: {track_sequence.current.title}")
+        log.debug(f"Play: {track_sequence.current.title}")
         track_sequence.current.play(position)
 
         # Update clocks now, don't wait for next tick
-        log.debug("issue223: play_next: update_clocks()")
         self.update_clocks()
 
         # Show closing volume graph
         if track_sequence.current.fade_graph:
-            log.debug(
-                f"issue223: play_next: set up fade_graph, {track_sequence.current.title=}"
-            )
             track_sequence.current.fade_graph.GraphWidget = self.widgetFadeVolume
             track_sequence.current.fade_graph.clear()
             track_sequence.current.fade_graph.plot()
-        else:
-            log.debug("issue223: play_next: No fade_graph")
 
         # Disable play next controls
         self.catch_return_key = True
         self.show_status_message("Play controls: Disabled", 0)
 
         # Notify playlist
-        log.debug("issue223: play_next: notify playlist")
         self.active_tab().current_track_started()
 
         # Update headers
-        log.debug("issue223: play_next: update headers")
         self.update_headers()
         with db.Session() as session:
             last_played = Playdates.last_played_tracks(session)
@@ -1729,15 +1717,6 @@ class Window(QMainWindow, Ui_MainWindow):
 
         # If track is playing, update track clocks time and colours
         if track_sequence.current and track_sequence.current.is_playing():
-            # see play_next() and issue #223.
-            # TODO: find a better way of handling this
-            if (
-                track_sequence.current.time_playing() > 5000
-                and not self.timer10.isActive()
-            ):
-                self.timer10.start(10)
-                log.debug("issue223: update_clocks: 10ms timer enabled")
-
             # Elapsed time
             self.label_elapsed_timer.setText(
                 helpers.ms_to_mmss(track_sequence.current.time_playing())
@@ -1765,14 +1744,22 @@ class Window(QMainWindow, Ui_MainWindow):
                 if self.frame_silent.styleSheet() != css_fade:
                     self.frame_silent.setStyleSheet(css_fade)
 
-            # Five seconds before fade starts, set warning colour on
-            # time to silence box and enable play controls
+            # WARNING_MS_BEFORE_FADE milliseconds before fade starts, set
+            # warning colour on time to silence box and enable play
+            # controls. This is also a good time to re-enable the 10ms
+            # timer (see play_next() and issue #223).
+
             elif time_to_fade <= Config.WARNING_MS_BEFORE_FADE:
                 self.frame_fade.setStyleSheet(
                     f"background: {Config.COLOUR_WARNING_TIMER}"
                 )
                 self.catch_return_key = False
                 self.show_status_message("Play controls: Enabled", 0)
+                # Re-enable 10ms timer (see above)
+                if not self.timer10.isActive():
+                    self.timer10.start(10)
+                    log.debug("issue223: update_clocks: 10ms timer enabled")
+
             else:
                 self.frame_silent.setStyleSheet("")
                 self.frame_fade.setStyleSheet("")