From e59e07b97168e0d64c0b5d5729b85f41335ee212 Mon Sep 17 00:00:00 2001
From: Neil McKechnie <neilmck999@gmail.com>
Date: Tue, 21 Sep 2021 13:43:52 +0100
Subject: [PATCH] Improved HAL diagnostics

Looptime diagnostic enhanced, and duplicated diagnostic messages removed from DFPlayer class.
---
 IODevice.cpp  | 22 +++++++++++++++-------
 IO_DFPlayer.h | 35 +++++++++++++++++++++--------------
 2 files changed, 36 insertions(+), 21 deletions(-)

diff --git a/IODevice.cpp b/IODevice.cpp
index fc16bb0..e212cf5 100644
--- a/IODevice.cpp
+++ b/IODevice.cpp
@@ -89,24 +89,32 @@ void IODevice::loop() {
   // Report loop time if diags enabled
 #if defined(DIAG_LOOPTIMES)
   static unsigned long lastMicros = 0;
-  static unsigned long maxElapsed = 0;
+  // Measure time since loop() method started.
+  unsigned long halElapsed = micros() - currentMicros;
+  // Measure time between loop() method entries.
+  unsigned long elapsed = currentMicros - lastMicros;
+  static unsigned long maxElapsed = 0, maxHalElapsed = 0;
   static unsigned long lastOutputTime = 0;
+  static unsigned long halTotal = 0, total = 0;
   static unsigned long count = 0;
   const unsigned long interval = (unsigned long)5 * 1000 * 1000; // 5 seconds in microsec
-  unsigned long elapsed = currentMicros - lastMicros;
+
   // Ignore long loop counts while message is still outputting
   if (currentMicros - lastOutputTime > 3000UL) {
     if (elapsed > maxElapsed) maxElapsed = elapsed;
+    if (halElapsed > maxHalElapsed) maxHalElapsed = halElapsed;
+    halTotal += halElapsed;
+    total += elapsed;
+    count++;
   }
-  count++;
   if (currentMicros - lastOutputTime > interval) {
     if (lastOutputTime > 0) 
-      LCD(1,F("Loop=%lus,%lus max"), interval/count, maxElapsed);
-    maxElapsed = 0;
-    count = 0;
+      DIAG(F("Loop Total:%lus (%lus max) HAL:%lus (%lus max)"), 
+        total/count, maxElapsed, halTotal/count, maxHalElapsed);
+    maxElapsed = maxHalElapsed = total = halTotal = count = 0;
     lastOutputTime = currentMicros;
   }
-  lastMicros = micros();
+  lastMicros = currentMicros;
 #endif
 }
 
diff --git a/IO_DFPlayer.h b/IO_DFPlayer.h
index 5296ae0..bdf0626 100644
--- a/IO_DFPlayer.h
+++ b/IO_DFPlayer.h
@@ -69,12 +69,14 @@ private:
   unsigned long _commandSendTime; // Allows timeout processing
 
 public:
-  DFPlayer(VPIN firstVpin, int nPins, HardwareSerial &serial) {
-    _firstVpin = firstVpin;
-    _nPins = nPins;
-    _serial = &serial;
+  // Constructor
+  DFPlayer(VPIN firstVpin, int nPins, HardwareSerial &serial) :
+    IODevice(firstVpin, nPins),
+    _serial(&serial) 
+  {
     addDevice(this);
   }
+
   static void create(VPIN firstVpin, int nPins, HardwareSerial &serial) {
     new DFPlayer(firstVpin, nPins, serial);
   }
@@ -101,20 +103,25 @@ protected:
             || (_inputIndex >=4 && _inputIndex <= 8))
         _inputIndex++;
       else if (c==0x06 && _inputIndex==2) { 
-        // Valid command prefix, so consider the device online.
-        _deviceState = DEVSTATE_NORMAL;
-        #ifdef DIAG_IO
-        _display();
-        #endif
+        // Valid message prefix, so consider the device online
+        if (_deviceState==DEVSTATE_INITIALISING) {
+          _deviceState = DEVSTATE_NORMAL;
+          #ifdef DIAG_IO
+          _display();
+          #endif
+        }
         _inputIndex++;
       } else if (c==0xEF && _inputIndex==9) {
         // End of play
-        #ifdef DIAG_IO
-        DIAG(F("DFPlayer: Finished"));
-        #endif
-        _playing = false;
+        if (_playing) {
+          #ifdef DIAG_IO
+          DIAG(F("DFPlayer: Finished"));
+          #endif
+          _playing = false;
+        }
         _inputIndex = 0;
-      }
+      } else 
+        _inputIndex = 0;  // Unrecognised character sequence, start again!
     }
     // Check if the initial prompt to device has timed out.  Allow 1 second
     if (_deviceState == DEVSTATE_INITIALISING && currentMicros - _commandSendTime > 1000000UL) {