Missing / incorrect implementation of G04

[Szeker]

In short:
G-codes containing G04 command caused infinite pause instead of the value set in the command (G04 S7).

The issue:

Printing stopped "forewer" at the (probably first) G04 command received (G04 S07).
Print could be recovered manually via Octoprint by pressing "Pause" + "Recover" buttons.
Issue detected manually by recognizing no movement of the head. There was no error or warning in Octoprint.
Temperatures (bed, hotend) were still regulated continuously correctly and displayed in Octoprint.
Printed part destroyed - due to the nozzle was stopped in one position for long time.

See timestamp in Octoprint and Redeem logs:

• 13:09:57: last command: G04 S7
• 14:21:00, printing was manually recovered (after pressing the active button "Pause", while the "Print" button was inactive/grey).

Conditions:

• Kamikaze 2.1.2 RC5c running from SD card
• Printing file from SD card emulation (lcl/XYZ.gcode)
• BBB board with Replicape Rev.B3A
• Printed G-code contains G04 commands (to reach minimum layer printing time)

Octoprint log:

2018-05-21 11:40:23,361 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2018-05-21 11:40:23,448 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-05-21 11:40:23,943 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2018-05-21 11:40:23,961 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-05-21 11:40:24,138 - octoprint.util.comm - INFO - Printer reports firmware name "Redeem"
2018-05-21 11:40:32,177 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-05-21 11:42:36,059 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing from SD"
2018-05-21 11:55:32,182 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-05-21 12:10:32,188 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-05-21 12:25:32,192 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-05-21 12:40:32,206 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-05-21 12:55:32,212 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-05-21 13:10:32,217 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-05-21 13:25:32,228 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-05-21 13:40:32,239 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-05-21 13:41:08,440 - tornado.general - WARNING - error on read
Traceback (most recent call last):
File "/usr/local/lib/python2.7/dist-packages/tornado-4.0.2-py2.7-linux-armv7l.egg/tornado/iostream.py", line 601, in _handle_read
pos = self._read_to_buffer_loop()
File "/usr/local/lib/python2.7/dist-packages/tornado-4.0.2-py2.7-linux-armv7l.egg/tornado/iostream.py", line 571, in _read_to_buffer_loop
if self._read_to_buffer() == 0:
File "/usr/local/lib/python2.7/dist-packages/tornado-4.0.2-py2.7-linux-armv7l.egg/tornado/iostream.py", line 683, in _read_to_buffer
chunk = self.read_from_fd()
File "/usr/local/lib/python2.7/dist-packages/tornado-4.0.2-py2.7-linux-armv7l.egg/tornado/iostream.py", line 947, in read_from_fd
chunk = self.socket.recv(self.read_chunk_size)
error: [Errno 113] No route to host
2018-05-21 13:41:08,558 - octoprint.server.util.sockjs - INFO - Client connection closed: 192.168.0.106
2018-05-21 13:55:32,249 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-05-21 14:10:32,255 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-05-21 14:20:26,540 - octoprint.server.util.sockjs - INFO - New connection from client: 192.168.0.106
2018-05-21 14:20:56,394 - octoprint.util.comm - INFO - Changing monitoring state from "Printing from SD" to "Pausing"
2018-05-21 14:20:56,400 - octoprint.filemanager.analysis - INFO - Starting analysis of local:Magnet_Tester_Arm_V03.gcode
2018-05-21 14:20:56,449 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /usr/bin/python -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /usr/share/models/Magnet_Tester_Arm_V03.gcode
2018-05-21 14:20:56,632 - octoprint.util.comm - INFO - Changing monitoring state from "Pausing" to "Paused"
2018-05-21 14:21:00,787 - octoprint.util.comm - INFO - Changing monitoring state from "Paused" to "Printing from SD"
2018-05-21 14:21:28,552 - octoprint.util.comm - INFO - Changing monitoring state from "Printing from SD" to "Cancelling"
2018-05-21 14:21:28,568 - octoprint.filemanager.analysis - INFO - Starting analysis of local:Magnet_Tester_Arm_V03.gcode
2018-05-21 14:21:28,629 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /usr/bin/python -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /usr/share/models/Magnet_Tester_Arm_V03.gcode
2018-05-21 14:21:55,674 - octoprint.util.comm - INFO - Changing monitoring state from "Cancelling" to "Operational

Redeem log:

2018-05-21 13:09:57,846 root WARNING tried to execute a gcode wasn't resolved: G1 X18.416 Y6.631 E29.1080
2018-05-21 13:09:57,861 root WARNING tried to execute a gcode wasn't resolved: G0 F4800 E27.1080
2018-05-21 13:09:57,876 root WARNING tried to execute a gcode wasn't resolved: G0 F1200 Z25.200
2018-05-21 13:09:57,891 root WARNING tried to execute a gcode wasn't resolved: G04 S7
2018-05-21 14:21:00,892 root WARNING tried to execute a gcode wasn't resolved: G0 F4800 E29.1080
2018-05-21 14:21:00,901 root WARNING tried to execute a gcode wasn't resolved: G21
2018-05-21 14:21:00,906 root WARNING tried to execute a gcode wasn't resolved: G90
2018-05-21 14:21:00,911 root WARNING tried to execute a gcode wasn't resolved: G92 E0
2018-05-21 14:21:00,927 root WARNING tried to execute a gcode wasn't resolved: G0 F4800 E-3.0000
2018-05-21 14:21:00,940 root WARNING tried to execute a gcode wasn't resolved: G0 F1200 Z25.700
2018-05-21 14:21:00,955 root WARNING tried to execute a gcode wasn't resolved: G0 X-1.166 Y18.726 F7200
2018-05-21 14:21:00,963 root WARNING tried to execute a gcode wasn't resolved: G0 F1200 Z25.200'

**Failed G-code files (same STL file with different settings, e.g. number of perimeters and infill% **

Failed_Print_With_G04_1_Gcode.txt
(Failed around line 22.7mm @0.2mm layer hight => ~line 113)

Failed_Print_With_G04_2_Gcode.txt
(Failed around 25.2mm @0.2mm layer hight => ~line 126)