Merge 3655c9f40a into 37b56e09a3

Marlin/Configuration_adv.h

@@ -1967,6 +1967,14 @@
 // Some clients will have this feature soon. This could make the NO_TIMEOUTS unnecessary.
 //#define ADVANCED_OK
 
+/**
+ * Buffer monitoring
+ * 
+ * To help diagnose print quality issues stemming from command buffers being empty,
+ * we add M576 which enables reporting of buffer empty
+ */
+//#define BUFFER_MONITORING
+
 // Printrun may have trouble receiving long strings all at once.
 // This option inserts short delays between lines of serial output.
 #define SERIAL_OVERRUN_PROTECTION

Marlin/src/MarlinCore.cpp

@@ -768,6 +768,10 @@ void idle(TERN_(ADVANCED_PAUSE_FEATURE, bool no_stepper_sleep/*=false*/)) {
     if (!gcode.autoreport_paused) {
       TERN_(AUTO_REPORT_TEMPERATURES, thermalManager.auto_report_temperatures());
       TERN_(AUTO_REPORT_SD_STATUS, card.auto_report_sd_status());
+
+      #if ENABLED(BUFFER_MONITORING)
+        queue.auto_report_buffer_statistics();
+      #endif
     }
   #endif
 

Marlin/src/gcode/gcode.cpp

@@ -779,6 +779,10 @@ void GcodeSuite::process_parsed_command(const bool no_ok/*=false*/) {
         case 575: M575(); break;                                  // M575: Set serial baudrate
       #endif
 
+      #if ENABLED(BUFFER_MONITORING)                              // M576: Buffer monitoring
+        case 576: M576(); break;
+      #endif
+
       #if ENABLED(ADVANCED_PAUSE_FEATURE)
         case 600: M600(); break;                                  // M600: Pause for Filament Change
         case 603: M603(); break;                                  // M603: Configure Filament Change

Marlin/src/gcode/gcode.h

@@ -789,6 +789,8 @@ private:
 
   TERN_(BAUD_RATE_GCODE, static void M575());
 
+  TERN_(BUFFER_MONITORING, static void M576());
+
   #if ENABLED(ADVANCED_PAUSE_FEATURE)
     static void M600();
     static void M603();

Marlin/src/gcode/queue.cpp

@@ -89,6 +89,24 @@ static int serial_count[NUM_SERIAL] = { 0 };
 
 bool send_ok[BUFSIZE];
 
+/* 
+ * Track buffer underruns
+ */
+#if ENABLED(BUFFER_MONITORING)
+  uint32_t GCodeQueue::command_buffer_underruns = 0;
+  bool GCodeQueue::command_buffer_empty = false;
+  millis_t GCodeQueue::max_command_buffer_empty_duration = 0;
+  millis_t GCodeQueue::command_buffer_empty_at = 0;
+
+  uint32_t GCodeQueue::planner_buffer_underruns = 0;
+  bool GCodeQueue::planner_buffer_empty = false;
+  millis_t GCodeQueue::max_planner_buffer_empty_duration = 0;
+  millis_t GCodeQueue::planner_buffer_empty_at = 0;
+
+  uint8_t GCodeQueue::auto_buffer_report_interval;
+  millis_t GCodeQueue::next_buffer_report_ms;
+#endif
+
 /**
  * Next Injected PROGMEM Command pointer. (nullptr == empty)
  * Internal commands are enqueued ahead of serial / SD commands.
@@ -626,7 +644,28 @@ void GCodeQueue::advance() {
   if (process_injected_command_P() || process_injected_command()) return;
 
   // Return if the G-code buffer is empty
-  if (!length) return;
+  if (!length) {
+    #if ENABLED(BUFFER_MONITORING)
+      if (!command_buffer_empty) {
+        command_buffer_empty = true;
+        command_buffer_underruns++;
+        command_buffer_empty_at = millis();
+      }
+    #endif
+    return;
+  }
+
+  #if ENABLED(BUFFER_MONITORING)
+    if (command_buffer_empty) {
+      static millis_t command_buffer_empty_duration;
+      command_buffer_empty_duration = millis() - command_buffer_empty_at;
+      if (command_buffer_empty_duration > max_command_buffer_empty_duration) {
+        max_command_buffer_empty_duration = command_buffer_empty_duration;
+      }
+      command_buffer_empty = false;
+    }
+  #endif
+
 
   #if ENABLED(SDSUPPORT)
 
@@ -671,3 +710,52 @@ void GCodeQueue::advance() {
   if (++index_r >= BUFSIZE) index_r = 0;
 
 }
+
+#if ENABLED(BUFFER_MONITORING)
+void GCodeQueue::report_buffer_statistics() {
+  SERIAL_ECHO("M576");
+  SERIAL_ECHOLNPAIR(SP_P_STR, int(planner.moves_free()),
+                    SP_B_STR, int(BUFSIZE - length),
+                    " PU", queue.planner_buffer_underruns,
+                    " PD", queue.max_planner_buffer_empty_duration,
+                    " BU", queue.command_buffer_underruns,
+                    " BD", queue.max_command_buffer_empty_duration,
+                    );
+
+  command_buffer_underruns = 0;
+  max_command_buffer_empty_duration = 0;
+
+  planner_buffer_underruns = 0;
+  max_planner_buffer_empty_duration = 0;
+}
+
+void GCodeQueue::auto_report_buffer_statistics() {
+  // Bit of a hack to try to catch planner buffer underruns without having logic
+  // running inside Stepper::block_phase_isr
+  if (planner.movesplanned() == 0) {
+    if (!planner_buffer_empty) { // if the planner buffer wasn't empty, but now it is
+      planner_buffer_empty = true;
+      planner_buffer_underruns++;
+      planner_buffer_empty_at = millis();
+    }
+  } else if (planner_buffer_empty) { // if the planner buffer was empty, but now it ain't
+    static millis_t planner_buffer_empty_duration;
+    planner_buffer_empty_duration = millis() - planner_buffer_empty_at;
+
+    // if it's longer than the currently tracked max duration, replace it
+    if (planner_buffer_empty_duration > max_planner_buffer_empty_duration) {
+      max_planner_buffer_empty_duration = planner_buffer_empty_duration;
+    }
+
+    planner_buffer_empty = false;
+  }
+
+  if (queue.auto_buffer_report_interval && ELAPSED(millis(), queue.next_buffer_report_ms)) {
+    queue.next_buffer_report_ms = millis() + 1000UL * queue.auto_buffer_report_interval;
+    PORT_REDIRECT(SERIAL_BOTH);
+    report_buffer_statistics();
+    PORT_RESTORE();
+  }
+}
+
+#endif

Marlin/src/gcode/queue.h

@@ -147,6 +147,43 @@ public:
    */
   static void flush_and_request_resend();
 
+  #if ENABLED(BUFFER_MONITORING)
+    /* 
+    * Track buffer underruns
+    */
+    static uint32_t command_buffer_underruns;
+    static bool command_buffer_empty;
+    static millis_t max_command_buffer_empty_duration;
+    static millis_t command_buffer_empty_at;
+
+    static uint32_t planner_buffer_underruns;
+    static bool planner_buffer_empty;
+    static millis_t max_planner_buffer_empty_duration;
+    static millis_t planner_buffer_empty_at;
+
+    /**
+     * Report buffer statistics to the host to be able to detect buffer underruns
+     * 
+     * Returns "M576 " followed by:
+     *  P<uint>   Planner space remaining
+     *  B<uint>   Command buffer space remaining
+     *  PU<uint>  Number of planner buffer underruns since last report
+     *  PD<uint>  Max time in ms the planner buffer was empty since last report
+     *  BU<uint>  Number of command buffer underruns since last report
+     *  BD<uint>  Max time in ms the command buffer was empty since last report
+     */
+    static void report_buffer_statistics();
+
+    static uint8_t auto_buffer_report_interval;
+    static millis_t next_buffer_report_ms;
+    static void auto_report_buffer_statistics();
+    static inline void set_auto_report_interval(uint8_t v) {
+      NOMORE(v, 60);
+      auto_buffer_report_interval = v;
+      next_buffer_report_ms = millis() + 1000UL * v;
+    }
+  #endif
+
 private:
 
   static uint8_t index_w;  // Ring buffer write position

Marlin/src/gcode/stats/M576.cpp

@@ -0,0 +1,54 @@
+/**
+ * Marlin 3D Printer Firmware
+ * Copyright (c) 2020 MarlinFirmware [https://github.com/MarlinFirmware/Marlin]
+ * 
+ *
+ * Based on Sprinter and grbl.
+ * Copyright (c) 2011 Camiel Gubbels / Erik van der Zalm
+ *
+ * This program is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program.  If not, see <https://www.gnu.org/licenses/>.
+ *
+ */
+
+#include "../../inc/MarlinConfig.h"
+#include "../../MarlinCore.h" // for SP_P/B_STR, etc.
+
+#if ENABLED(BUFFER_MONITORING)
+
+#include "../gcode.h"
+#include "../queue.h"
+
+/**
+ * M576: Return buffer stats, and optionally set auto-report interval.
+ * Usage: M576 [S<seconds>]
+ * 
+ * When called, printer emits the following output:
+ * "M576 P<nn> B<nn> PU<nn> PD<nn> BU<nn> BD<nn>"
+ * Where:
+ *   P: Planner buffers available 
+ *   B: Command buffers available
+ *   PU: Planner buffer underruns since last report
+ *   PD: Maximum time in ms planner buffer was empty since last report
+ *   BU: Command buffer underruns since last report
+ *   BD: Maximum time in ms command buffer was empty since last report
+ */
+void GcodeSuite::M576() {
+  if (parser.seenval('S')) {
+    queue.set_auto_report_interval((uint8_t)parser.value_byte());
+  }
+
+  queue.report_buffer_statistics();
+}
+
+#endif // BUFFER_MONITORING