From 383f36fc485d880bf78a3b28485a210b1160f62b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gina=20H=C3=A4u=C3=9Fge?= Date: Wed, 4 Mar 2015 09:45:51 +0100 Subject: [PATCH 01/10] Backported clear_to_send mechanism from commRefactoring Also added temperature and sd status polling timers --- src/octoprint/util/__init__.py | 37 +++++++++++ src/octoprint/util/comm.py | 117 ++++++++++++++++++++++++++------- 2 files changed, 132 insertions(+), 22 deletions(-) diff --git a/src/octoprint/util/__init__.py b/src/octoprint/util/__init__.py index 4371b9d5..ea3fcc23 100644 --- a/src/octoprint/util/__init__.py +++ b/src/octoprint/util/__init__.py @@ -14,6 +14,7 @@ import re import tempfile import logging import shutil +import threading from functools import wraps import warnings @@ -529,4 +530,40 @@ def address_for_client(host, port): except: continue +class CountedEvent(object): + def __init__(self, value=0, max=None): + self._counter = 0 + self._max = max + self._mutex = threading.Lock() + self._event = threading.Event() + + self._internal_set(value) + + def set(self): + with self._mutex: + self._internal_set(self._counter + 1) + + def clear(self, completely=False): + with self._mutex: + if completely: + self._internal_set(0) + else: + self._internal_set(self._counter - 1) + + def wait(self, timeout=None): + self._event.wait(timeout) + + def blocked(self): + with self._mutex: + return self._counter == 0 + + def _internal_set(self, value): + self._counter = value + if self._counter <= 0: + self._counter = 0 + self._event.clear() + else: + if self._max is not None and self._counter > self._max: + self._counter = self._max + self._event.set() diff --git a/src/octoprint/util/comm.py b/src/octoprint/util/comm.py index 1f90dc2b..98a7c0ba 100644 --- a/src/octoprint/util/comm.py +++ b/src/octoprint/util/comm.py @@ -24,7 +24,7 @@ from octoprint.settings import settings, default_settings from octoprint.events import eventManager, Events from octoprint.filemanager import valid_file_type from octoprint.filemanager.destinations import FileDestinations -from octoprint.util import get_exception_string, sanitize_ascii, filter_non_ascii +from octoprint.util import get_exception_string, sanitize_ascii, filter_non_ascii, CountedEvent from octoprint.util.virtual import VirtualPrinter try: @@ -162,6 +162,11 @@ class MachineCom(object): self._lastResendNumber = None self._currentResendCount = 0 + self._clear_to_send = CountedEvent(max=10) + self._send_queue = queue.Queue() + self._sd_status_timer = None + self._temperature_timer = None + # hooks self._pluginManager = octoprint.plugin.plugin_manager() self._gcode_hooks = self._pluginManager.get_hooks("octoprint.comm.protocol.gcode") @@ -206,9 +211,14 @@ class MachineCom(object): self._sendingLock = threading.Lock() # monitoring thread - self.thread = threading.Thread(target=self._monitor) - self.thread.daemon = True - self.thread.start() + self.monitoring_thread = threading.Thread(target=self._monitor) + self.monitoring_thread.daemon = True + self.monitoring_thread.start() + + # sending thread + self.sending_thread = threading.Thread(target=self._send_loop) + self.sending_thread.daemon = True + self.sending_thread.start() def __del__(self): self.close() @@ -352,6 +362,18 @@ class MachineCom(object): ##~~ external interface def close(self, isError = False): + if self._temperature_timer is not None: + try: + self._temperature_timer.cancel() + except: + pass + + if self._sd_status_timer is not None: + try: + self._sd_status_timer.cancel() + except: + pass + printing = self.isPrinting() or self.isPaused() if self._serial is not None: if isError: @@ -454,7 +476,6 @@ class MachineCom(object): try: self._currentFile.start() - wasPaused = self.isPaused() self._changeState(self.STATE_PRINTING) self.sendCommand("M110 N0") @@ -471,6 +492,7 @@ class MachineCom(object): self.sendCommand("M26 S0") self._currentFile.setFilepos(0) self.sendCommand("M24") + self.sendCommand("M27") else: line = self._getNext() if line is not None: @@ -565,6 +587,7 @@ class MachineCom(object): if self.isSdFileSelected(): self.sendCommand("M24") + self.sendCommand("M27") else: line = self._getNext() if line is not None: @@ -800,6 +823,10 @@ class MachineCom(object): self._sdFiles.append((filename, size)) continue + ##~~ process oks + if line.strip().startswith("ok"): + self._clear_to_send.set() + ##~~ Temperature processing if ' T:' in line or line.startswith('T:') or ' T0:' in line or line.startswith('T0:'): self._processTemperatures(line) @@ -993,8 +1020,9 @@ class MachineCom(object): elif self._state == self.STATE_OPERATIONAL or self._state == self.STATE_PAUSED: #Request the temperature on comm timeout (every 5 seconds) when we are not printing. if line == "": - self.sendCommand("M105") - tempRequestTimeout = get_new_timeout("temperature") + #self.sendCommand("M105") + #tempRequestTimeout = get_new_timeout("temperature") + pass # if we still have commands to process, process them elif "ok" in line: @@ -1025,19 +1053,30 @@ class MachineCom(object): if self._resendDelta is not None: self._resendNextCommand() else: - if self._heatupWaitStartTime is None: - if time.time() > tempRequestTimeout: - self.sendCommand("M105") - tempRequestTimeout = get_new_timeout("temperature") + #if self._heatupWaitStartTime is None: + # if time.time() > tempRequestTimeout: + # self.sendCommand("M105") + # tempRequestTimeout = get_new_timeout("temperature") - if self.isSdPrinting() and time.time() > sdStatusRequestTimeout: - self.sendCommand("M27") - sdStatusRequestTimeout = get_new_timeout("sdStatus") + # if self.isSdPrinting() and time.time() > sdStatusRequestTimeout: + # self.sendCommand("M27") + # sdStatusRequestTimeout = get_new_timeout("sdStatus") if self._sendFromQueue(sendChecksum=True): pass elif not self.isSdPrinting(): self._sendNext() + + elif line == "" and self.isSdPrinting(): + pass + #if time.time() > tempRequestTimeout: + # self.sendCommand("M105") + # tempRequestTimeout = get_new_timeout("temperature") + + #if time.time() > sdStatusRequestTimeout: + # self.sendCommand("M27") + # sdStatusRequestTimeout = get_new_timeout("sdStatus") + elif line.lower().startswith("resend") or line.lower().startswith("rs"): if settings().get(["feature", "swallowOkAfterResend"]): swallowOk = True @@ -1052,7 +1091,38 @@ class MachineCom(object): eventManager().fire(Events.ERROR, {"error": self.getErrorString()}) self._log("Connection closed, closing down monitor") + def _enqueue_for_sending(self, command, linenumber=None): + self._send_queue.put((command, linenumber)) + + def _send_loop(self): + while True: + self._clear_to_send.wait() + command, linenumber = self._send_queue.get() + if linenumber is not None: + self._doSendWithChecksum(command, linenumber) + else: + self._doSendWithoutChecksum(command) + + def _poll_temperature(self): + if self.isOperational() and not self.isStreaming() and self._heatupWaitStartTime is None: + self.sendCommand("M105") + + interval = get_interval("temperature") + self._temperature_timer = threading.Timer(interval, self._poll_temperature) + self._temperature_timer.start() + + def _poll_sd_status(self): + if self.isOperational() and self.isSdPrinting() and self._heatupWaitStartTime is None: + self.sendCommand("M27") + + interval = get_interval("sdStatus") + self._sd_status_timer = threading.Timer(interval, self._poll_temperature) + self._sd_status_timer.start() + def _onConnected(self): + self._poll_temperature() + self._poll_sd_status() + self._changeState(self.STATE_OPERATIONAL) if self._sdAvailable: self.refreshSdFiles() @@ -1112,6 +1182,7 @@ class MachineCom(object): self._changeState(self.STATE_ERROR) eventManager().fire(Events.ERROR, {"error": self.getErrorString()}) return False + self._clear_to_send.set() return True def _handleErrors(self, line): @@ -1244,7 +1315,7 @@ class MachineCom(object): cmd = self._lastLines[-self._resendDelta] lineNumber = self._currentLine - self._resendDelta - self._doSendWithChecksum(cmd, lineNumber) + self._enqueue_for_sending(cmd, linenumber=lineNumber) self._resendDelta -= 1 if self._resendDelta <= 0: @@ -1282,9 +1353,9 @@ class MachineCom(object): lineNumber = self._currentLine self._addToLastLines(cmd) self._currentLine += 1 - self._doSendWithChecksum(cmd, lineNumber) + self._enqueue_for_sending(cmd, linenumber=lineNumber) else: - self._doSendWithoutChecksum(cmd) + self._enqueue_for_sending(cmd) def _doSendWithChecksum(self, cmd, lineNumber): self._logger.debug("Sending cmd '%s' with lineNumber %r" % (cmd, lineNumber)) @@ -1388,7 +1459,7 @@ class MachineCom(object): newLineNumber = 0 # send M110 command with new line number - self._doSendWithChecksum(cmd, newLineNumber) + self._enqueue_for_sending(cmd, linenumber=newLineNumber) self._currentLine = newLineNumber + 1 # after a reset of the line number we have no way to determine what line exactly the printer now wants @@ -1659,9 +1730,11 @@ class StreamingGcodeFileInformation(PrintingGcodeFileInformation): def get_new_timeout(type): now = time.time() + return now + get_interval(type) - if type not in default_settings["serial"]["timeout"].keys(): - # timeout immediately for unknown timeout type - return now - return now + settings().getFloat(["serial", "timeout", type]) \ No newline at end of file +def get_interval(type): + if type not in default_settings["serial"]["timeout"]: + return 0 + else: + return settings().getFloat(["serial", "timeout", type]) \ No newline at end of file From 801f9adfd7d60221deb49ea39708393aa8b9f9ad Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gina=20H=C3=A4u=C3=9Fge?= Date: Wed, 4 Mar 2015 10:20:13 +0100 Subject: [PATCH 02/10] Further experiments with send_queue and polling timers --- src/octoprint/util/__init__.py | 8 ++++++- src/octoprint/util/comm.py | 43 ++++++++++++++++++++++++---------- 2 files changed, 37 insertions(+), 14 deletions(-) diff --git a/src/octoprint/util/__init__.py b/src/octoprint/util/__init__.py index ea3fcc23..37ede237 100644 --- a/src/octoprint/util/__init__.py +++ b/src/octoprint/util/__init__.py @@ -532,7 +532,10 @@ def address_for_client(host, port): class CountedEvent(object): - def __init__(self, value=0, max=None): + def __init__(self, value=0, max=None, name=None): + logger_name = __name__ + ".CountedEvent" + ("[{name}]".format(name=name) if name is not None else "") + self._logger = logging.getLogger(logger_name) + self._counter = 0 self._max = max self._mutex = threading.Lock() @@ -559,11 +562,14 @@ class CountedEvent(object): return self._counter == 0 def _internal_set(self, value): + self._logger.debug("New counter value: {value}".format(value=value)) self._counter = value if self._counter <= 0: self._counter = 0 self._event.clear() + self._logger.debug("Cleared event") else: if self._max is not None and self._counter > self._max: self._counter = self._max self._event.set() + self._logger.debug("Set event") diff --git a/src/octoprint/util/comm.py b/src/octoprint/util/comm.py index 98a7c0ba..a33d2d69 100644 --- a/src/octoprint/util/comm.py +++ b/src/octoprint/util/comm.py @@ -162,7 +162,7 @@ class MachineCom(object): self._lastResendNumber = None self._currentResendCount = 0 - self._clear_to_send = CountedEvent(max=10) + self._clear_to_send = CountedEvent(max=10, name="comm.clear_to_send") self._send_queue = queue.Queue() self._sd_status_timer = None self._temperature_timer = None @@ -211,12 +211,12 @@ class MachineCom(object): self._sendingLock = threading.Lock() # monitoring thread - self.monitoring_thread = threading.Thread(target=self._monitor) + self.monitoring_thread = threading.Thread(target=self._monitor, name="comm._monitor") self.monitoring_thread.daemon = True self.monitoring_thread.start() # sending thread - self.sending_thread = threading.Thread(target=self._send_loop) + self.sending_thread = threading.Thread(target=self._send_loop, name="comm.sending_thread") self.sending_thread.daemon = True self.sending_thread.start() @@ -1044,7 +1044,8 @@ class MachineCom(object): elif self._state == self.STATE_PRINTING: if line == "" and time.time() > self._timeout: self._log("Communication timeout during printing, forcing a line") - line = 'ok' + #line = 'ok' + self._clear_to_send.set() if "ok" in line: if swallowOk: @@ -1096,15 +1097,29 @@ class MachineCom(object): def _send_loop(self): while True: - self._clear_to_send.wait() - command, linenumber = self._send_queue.get() - if linenumber is not None: - self._doSendWithChecksum(command, linenumber) - else: - self._doSendWithoutChecksum(command) + if self._send_queue.qsize() == 0: + # queue is empty, wait a bit before checking again + time.sleep(0.1) + continue + + try: + entry = self._send_queue.get(block=False) + except queue.Empty: + entry = None + + if entry is not None: + command, linenumber = entry + if linenumber is not None: + self._doSendWithChecksum(command, linenumber) + else: + self._doSendWithoutChecksum(command) + self._clear_to_send.clear() + self._clear_to_send.wait() def _poll_temperature(self): - if self.isOperational() and not self.isStreaming() and self._heatupWaitStartTime is None: + print("temperature poll timer hit") + if self.isOperational() and not self.isStreaming() and not self._heatupWaitStartTime: + print("sending temperature poll") self.sendCommand("M105") interval = get_interval("temperature") @@ -1112,11 +1127,13 @@ class MachineCom(object): self._temperature_timer.start() def _poll_sd_status(self): - if self.isOperational() and self.isSdPrinting() and self._heatupWaitStartTime is None: + print("sd status poll timer hit") + if self.isOperational() and self.isSdPrinting() and not self._heatupWaitStartTime: + print("sending sd status poll") self.sendCommand("M27") interval = get_interval("sdStatus") - self._sd_status_timer = threading.Timer(interval, self._poll_temperature) + self._sd_status_timer = threading.Timer(interval, self._poll_sd_status) self._sd_status_timer.start() def _onConnected(self): From 116a540abd83e9e241cd7b8095af3c6be6e73f0e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gina=20H=C3=A4u=C3=9Fge?= Date: Wed, 4 Mar 2015 14:15:01 +0100 Subject: [PATCH 03/10] More experimenting with comm queueing, seems to work fine now Next up: actual print --- src/octoprint/util/__init__.py | 2 +- src/octoprint/util/comm.py | 131 +++++++++++++++------------------ src/octoprint/util/virtual.py | 46 ++++++++++++ 3 files changed, 105 insertions(+), 74 deletions(-) diff --git a/src/octoprint/util/__init__.py b/src/octoprint/util/__init__.py index 37ede237..abbe5aac 100644 --- a/src/octoprint/util/__init__.py +++ b/src/octoprint/util/__init__.py @@ -533,7 +533,7 @@ def address_for_client(host, port): class CountedEvent(object): def __init__(self, value=0, max=None, name=None): - logger_name = __name__ + ".CountedEvent" + ("[{name}]".format(name=name) if name is not None else "") + logger_name = __name__ + ".CountedEvent" + (".{name}".format(name=name) if name is not None else "") self._logger = logging.getLogger(logger_name) self._counter = 0 diff --git a/src/octoprint/util/comm.py b/src/octoprint/util/comm.py index a33d2d69..1a2309c6 100644 --- a/src/octoprint/util/comm.py +++ b/src/octoprint/util/comm.py @@ -152,6 +152,8 @@ class MachineCom(object): self._pauseWaitTimeLost = 0.0 self._currentExtruder = 0 + self._blocking_command = False + self._timeout = None self._alwaysSendChecksum = settings().getBoolean(["feature", "alwaysSendChecksum"]) @@ -211,11 +213,13 @@ class MachineCom(object): self._sendingLock = threading.Lock() # monitoring thread + self._monitoring_active = True self.monitoring_thread = threading.Thread(target=self._monitor, name="comm._monitor") self.monitoring_thread.daemon = True self.monitoring_thread.start() # sending thread + self._send_queue_active = True self.sending_thread = threading.Thread(target=self._send_loop, name="comm.sending_thread") self.sending_thread.daemon = True self.sending_thread.start() @@ -374,6 +378,9 @@ class MachineCom(object): except: pass + self._monitoring_active = False + self._send_queue_active = False + printing = self.isPrinting() or self.isPaused() if self._serial is not None: if isError: @@ -492,7 +499,7 @@ class MachineCom(object): self.sendCommand("M26 S0") self._currentFile.setFilepos(0) self.sendCommand("M24") - self.sendCommand("M27") + self._poll_sd_status() else: line = self._getNext() if line is not None: @@ -553,6 +560,11 @@ class MachineCom(object): if self.isSdFileSelected(): self.sendCommand("M25") # pause print self.sendCommand("M26 S0") # reset position in file to byte 0 + if self._sd_status_timer is not None: + try: + self._sd_status_timer.cancel() + except: + pass payload = { "file": self._currentFile.getFilename(), @@ -755,14 +767,10 @@ class MachineCom(object): #Start monitoring the serial port. self._timeout = get_new_timeout("communication") - tempRequestTimeout = get_new_timeout("temperature") - sdStatusRequestTimeout = get_new_timeout("sdStatus") - startSeen = not settings().getBoolean(["feature", "waitForStartOnConnect"]) - swallowOk = False supportRepetierTargetTemp = settings().getBoolean(["feature", "repetierTargetTemp"]) - while True: + while self._monitoring_active: try: line = self._readline() if line is None: @@ -826,6 +834,7 @@ class MachineCom(object): ##~~ process oks if line.strip().startswith("ok"): self._clear_to_send.set() + self._blocking_command = False ##~~ Temperature processing if ' T:' in line or line.startswith('T:') or ' T0:' in line or line.startswith('T0:'): @@ -922,6 +931,11 @@ class MachineCom(object): "origin": self._currentFile.getFileLocation(), "time": self.getPrintTime() }) + if self._sd_status_timer is not None: + try: + self._sd_status_timer.cancel() + except: + pass elif 'Done saving file' in line: self.refreshSdFiles() @@ -1018,69 +1032,36 @@ class MachineCom(object): ### Operational elif self._state == self.STATE_OPERATIONAL or self._state == self.STATE_PAUSED: - #Request the temperature on comm timeout (every 5 seconds) when we are not printing. - if line == "": - #self.sendCommand("M105") - #tempRequestTimeout = get_new_timeout("temperature") - pass - - # if we still have commands to process, process them - elif "ok" in line: - if swallowOk: - swallowOk = False - else: - if self._resendDelta is not None: - self._resendNextCommand() - elif self._sendFromQueue(): - pass + if "ok" in line: + # if we still have commands to process, process them + if self._resendDelta is not None: + self._resendNextCommand() + elif self._sendFromQueue(): + pass # resend -> start resend procedure from requested line elif line.lower().startswith("resend") or line.lower().startswith("rs"): - if settings().get(["feature", "swallowOkAfterResend"]): - swallowOk = True self._handleResendRequest(line) ### Printing elif self._state == self.STATE_PRINTING: if line == "" and time.time() > self._timeout: - self._log("Communication timeout during printing, forcing a line") - #line = 'ok' - self._clear_to_send.set() + if not self._blocking_command: + self._log("Communication timeout during printing, forcing a line") + self._clear_to_send.set() + else: + self._logger.debug("Ran into a communication timeout, but a blocking command is currently active") if "ok" in line: - if swallowOk: - swallowOk = False + if self._resendDelta is not None: + self._resendNextCommand() else: - if self._resendDelta is not None: - self._resendNextCommand() - else: - #if self._heatupWaitStartTime is None: - # if time.time() > tempRequestTimeout: - # self.sendCommand("M105") - # tempRequestTimeout = get_new_timeout("temperature") - - # if self.isSdPrinting() and time.time() > sdStatusRequestTimeout: - # self.sendCommand("M27") - # sdStatusRequestTimeout = get_new_timeout("sdStatus") - - if self._sendFromQueue(sendChecksum=True): - pass - elif not self.isSdPrinting(): - self._sendNext() - - elif line == "" and self.isSdPrinting(): - pass - #if time.time() > tempRequestTimeout: - # self.sendCommand("M105") - # tempRequestTimeout = get_new_timeout("temperature") - - #if time.time() > sdStatusRequestTimeout: - # self.sendCommand("M27") - # sdStatusRequestTimeout = get_new_timeout("sdStatus") + if self._sendFromQueue(sendChecksum=True): + pass + elif not self.isSdPrinting(): + self._sendNext() elif line.lower().startswith("resend") or line.lower().startswith("rs"): - if settings().get(["feature", "swallowOkAfterResend"]): - swallowOk = True self._handleResendRequest(line) except: self._logger.exception("Something crashed inside the serial connection loop, please report this in OctoPrint's bug tracker:") @@ -1096,18 +1077,12 @@ class MachineCom(object): self._send_queue.put((command, linenumber)) def _send_loop(self): - while True: - if self._send_queue.qsize() == 0: - # queue is empty, wait a bit before checking again - time.sleep(0.1) - continue - + while self._send_queue_active: try: - entry = self._send_queue.get(block=False) - except queue.Empty: - entry = None + entry = self._send_queue.get() + if not self._send_queue_active: + break - if entry is not None: command, linenumber = entry if linenumber is not None: self._doSendWithChecksum(command, linenumber) @@ -1115,11 +1090,13 @@ class MachineCom(object): self._doSendWithoutChecksum(command) self._clear_to_send.clear() self._clear_to_send.wait() + except: + self._logger.exception("Caught an exception in the send loop") + self._log("") + self._logger.info("Closing down send loop") def _poll_temperature(self): - print("temperature poll timer hit") - if self.isOperational() and not self.isStreaming() and not self._heatupWaitStartTime: - print("sending temperature poll") + if self.isOperational() and not self.isStreaming() and not self._blocking_command: self.sendCommand("M105") interval = get_interval("temperature") @@ -1127,9 +1104,7 @@ class MachineCom(object): self._temperature_timer.start() def _poll_sd_status(self): - print("sd status poll timer hit") - if self.isOperational() and self.isSdPrinting() and not self._heatupWaitStartTime: - print("sending sd status poll") + if self.isOperational() and self.isSdPrinting() and not self._blocking_command: self.sendCommand("M27") interval = get_interval("sdStatus") @@ -1138,13 +1113,14 @@ class MachineCom(object): def _onConnected(self): self._poll_temperature() - self._poll_sd_status() self._changeState(self.STATE_OPERATIONAL) + if self._sdAvailable: self.refreshSdFiles() else: self.initSdCard() + payload = dict(port=self._port, baudrate=self._baudrate) eventManager().fire(Events.CONNECTED, payload) self.sendGcodeScript("afterPrinterConnected", replacements=dict(event=payload)) @@ -1458,10 +1434,12 @@ class MachineCom(object): def _gcode_M109(self, cmd): self._heatupWaitStartTime = time.time() + self._blocking_command = True return self._gcode_M104(cmd) def _gcode_M190(self, cmd): self._heatupWaitStartTime = time.time() + self._blocking_command = True return self._gcode_M140(cmd) def _gcode_M110(self, cmd): @@ -1502,8 +1480,15 @@ class MachineCom(object): # dwell time is specified in seconds _timeout = int(cmd[s_idx+1:]) self._timeout = get_new_timeout("communication") + _timeout + self._blocking_command = True return cmd + def _gcode_G28(self, cmd): + self._blocking_command = True + return cmd + _gcode_G29 = _gcode_G28 + _gcode_G30 = _gcode_G28 + ### MachineCom callback ################################################################################################ class MachineComPrintCallback(object): diff --git a/src/octoprint/util/virtual.py b/src/octoprint/util/virtual.py index 51bb253d..e9f8cc91 100644 --- a/src/octoprint/util/virtual.py +++ b/src/octoprint/util/virtual.py @@ -16,6 +16,11 @@ from serial import SerialTimeoutException from octoprint.settings import settings class VirtualPrinter(): + command_regex = re.compile("[GM]\d+") + sleep_regex = re.compile("sleep (\d+)") + sleep_after_regex = re.compile("sleep_after ([GM]\d+) (\d+)") + sleep_after_next_regex = re.compile("sleep_after_next ([GM]\d+) (\d+)") + def __init__(self, read_timeout=5.0, write_timeout=10.0): self._read_timeout = read_timeout self._write_timeout = write_timeout @@ -59,6 +64,9 @@ class VirtualPrinter(): self._incoming_lock = threading.RLock() + self._sleepAfterNext = dict() + self._sleepAfter = dict() + waitThread = threading.Thread(target=self._sendWaitAfterTimeout) waitThread.start() @@ -235,6 +243,22 @@ class VirtualPrinter(): # simulate reprap buffered commands via a Queue with maxsize which internally simulates the moves self.buffered.put(data) + if len(self._sleepAfter) or len(self._sleepAfterNext): + command_match = VirtualPrinter.command_regex.match(data) + if command_match is not None: + command = command_match.group(0) + + interval = None + if command in self._sleepAfter: + interval = self._sleepAfter[command] + elif command in self._sleepAfterNext: + interval = self._sleepAfterNext[command] + del self._sleepAfterNext[command] + + if interval is not None: + self.outgoing.put("// sleeping for {interval} seconds".format(interval=interval)) + time.sleep(interval) + if len(data.strip()) > 0: self._sendOk() @@ -245,6 +269,28 @@ class VirtualPrinter(): self.outgoing.put("// action:resume") elif data == "action_disconnect": self.outgoing.put("// action:disconnect") + else: + try: + sleep_match = VirtualPrinter.sleep_regex.match(data) + sleep_after_match = VirtualPrinter.sleep_after_regex.match(data) + sleep_after_next_match = VirtualPrinter.sleep_after_next_regex.match(data) + + if sleep_match is not None: + interval = int(sleep_match.group(1)) + self.outgoing.put("// sleeping for {interval} seconds".format(interval=interval)) + time.sleep(interval) + elif sleep_after_match is not None: + command = sleep_after_match.group(1) + interval = int(sleep_after_match.group(2)) + self._sleepAfter[command] = interval + self.outgoing.put("// going to sleep {interval} seconds after each {command}".format(**locals())) + elif sleep_after_next_match is not None: + command = sleep_after_next_match.group(1) + interval = int(sleep_after_next_match.group(2)) + self._sleepAfterNext[command] = interval + self.outgoing.put("// going to sleep {interval} seconds after next {command}".format(**locals())) + except: + pass def _listSd(self): self.outgoing.put("Begin file list") From cc4d13e1ce4b766d0a509606e54fc477dccb3d58 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gina=20H=C3=A4u=C3=9Fge?= Date: Wed, 4 Mar 2015 20:31:51 +0100 Subject: [PATCH 04/10] Fix issue with rewinding SD files Sometimes M26 S0 does not cause a selected SD file to be properly rewound, leading to issues when restarting the print job. Reselecting the file (and ignoring the resulting select event) solves this. --- src/octoprint/util/comm.py | 15 ++++++++++++--- 1 file changed, 12 insertions(+), 3 deletions(-) diff --git a/src/octoprint/util/comm.py b/src/octoprint/util/comm.py index 1a2309c6..1356a4fa 100644 --- a/src/octoprint/util/comm.py +++ b/src/octoprint/util/comm.py @@ -180,6 +180,7 @@ class MachineCom(object): self._sdFileList = False self._sdFiles = [] self._sdFileToSelect = None + self._ignore_select = False # print job self._currentFile = None @@ -496,8 +497,14 @@ class MachineCom(object): self.sendGcodeScript("beforePrintStarted", replacements=dict(event=payload)) if self.isSdFileSelected(): - self.sendCommand("M26 S0") + #self.sendCommand("M26 S0") # setting the sd post apparently sometimes doesn't work, so we re-select + # the file instead + + # make sure to ignore the "file selected" later on, otherwise we'll reset our progress data + self._ignore_select = True + self.sendCommand("M23 {filename}".format(filename=self._currentFile.getFilename())) self._currentFile.setFilepos(0) + self.sendCommand("M24") self._poll_sd_status() else: @@ -909,8 +916,10 @@ class MachineCom(object): name = match.group(1) self._currentFile = PrintingSdFileInformation(name, int(match.group(2))) elif 'File selected' in line: - # final answer to M23, at least on Marlin, Repetier and Sprinter: "File selected" - if self._currentFile is not None: + if self._ignore_select: + self._ignore_select = False + elif self._currentFile is not None: + # final answer to M23, at least on Marlin, Repetier and Sprinter: "File selected" self._callback.on_comm_file_selected(self._currentFile.getFilename(), self._currentFile.getFilesize(), True) eventManager().fire(Events.FILE_SELECTED, { "file": self._currentFile.getFilename(), From b1129332c98baca25c7510b55e5f8d494e6e3a64 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gina=20H=C3=A4u=C3=9Fge?= Date: Wed, 4 Mar 2015 20:33:44 +0100 Subject: [PATCH 05/10] Detect external heatup If a line "T: " comes in, the printer is heating up although we don't know why. Nevertheless count the time. --- src/octoprint/util/comm.py | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/src/octoprint/util/comm.py b/src/octoprint/util/comm.py index 1356a4fa..ef39c8eb 100644 --- a/src/octoprint/util/comm.py +++ b/src/octoprint/util/comm.py @@ -153,6 +153,7 @@ class MachineCom(object): self._currentExtruder = 0 self._blocking_command = False + self._heating = False self._timeout = None @@ -842,9 +843,14 @@ class MachineCom(object): if line.strip().startswith("ok"): self._clear_to_send.set() self._blocking_command = False + self._heating = False ##~~ Temperature processing if ' T:' in line or line.startswith('T:') or ' T0:' in line or line.startswith('T0:'): + if not line.strip().startswith("ok") and not self._heating: + self._logger.debug("Externally triggered heatup detected") + self._heating = True + self._heatupWaitStartTime = time.time() self._processTemperatures(line) self._callback.on_comm_temperature_update(self._temp, self._bedTemp) From 8092ff7e6220559376a5550102065c6ceaa934df Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gina=20H=C3=A4u=C3=9Fge?= Date: Wed, 4 Mar 2015 20:35:10 +0100 Subject: [PATCH 06/10] Workaround a bug in old versions of Marlin For some versions, the ok for a file delete message is not prepended by a newline: "File Deleted:ok" This work around will make it still detectable. --- src/octoprint/util/comm.py | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/src/octoprint/util/comm.py b/src/octoprint/util/comm.py index ef39c8eb..8d64057a 100644 --- a/src/octoprint/util/comm.py +++ b/src/octoprint/util/comm.py @@ -953,6 +953,10 @@ class MachineCom(object): pass elif 'Done saving file' in line: self.refreshSdFiles() + elif 'File deleted' in line and line.strip().endswith("ok"): + # buggy Marlin version that doesn't send a proper \r after the "File deleted" statement, fixed in + # current versions + self._clear_to_send.set() ##~~ Message handling elif line.strip() != '' \ From c7cccb2ce5a24ebf0b3d1e79d54bfcdf85df2ef1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gina=20H=C3=A4u=C3=9Fge?= Date: Wed, 4 Mar 2015 20:38:15 +0100 Subject: [PATCH 07/10] Prevent multiple copies of poll commands in send queue Utilizes a "TypedQueue" which tracks command types - if provided - and doesn't add entries of the same type as another entry in the queue. Somewhat backported from dev/commRefactoring branch --- src/octoprint/util/comm.py | 179 +++++++++++++++++++++++++++---------- 1 file changed, 130 insertions(+), 49 deletions(-) diff --git a/src/octoprint/util/comm.py b/src/octoprint/util/comm.py index 8d64057a..efc783d0 100644 --- a/src/octoprint/util/comm.py +++ b/src/octoprint/util/comm.py @@ -166,7 +166,7 @@ class MachineCom(object): self._currentResendCount = 0 self._clear_to_send = CountedEvent(max=10, name="comm.clear_to_send") - self._send_queue = queue.Queue() + self._send_queue = TypedQueue() self._sd_status_timer = None self._temperature_timer = None @@ -252,7 +252,6 @@ class MachineCom(object): def _addToLastLines(self, cmd): self._lastLines.append(cmd) - self._logger.debug("Got %d lines of history in memory" % len(self._lastLines)) ##~~ getters @@ -413,12 +412,12 @@ class MachineCom(object): if bed is not None: self._bedTempOffset = bed - def sendCommand(self, cmd): + def sendCommand(self, cmd, cmd_type=None): cmd = cmd.encode('ascii', 'replace') if self.isPrinting() and not self.isSdFileSelected(): - self._commandQueue.put(cmd) + self._commandQueue.put((cmd, cmd_type)) elif self.isOperational(): - self._sendCommand(cmd) + self._sendCommand((cmd, cmd_type)) def sendGcodeScript(self, scriptName, replacements=None): gcodeScripts = settings().get(["scripts", "gcode"], merged=True) @@ -756,6 +755,8 @@ class MachineCom(object): else: self._bedTemp = (actual, None) + ##~~ Serial monitor processing received messages + def _monitor(self): feedbackControls = settings().getFeedbackControls() pauseTriggers = settings().getPauseTriggers() @@ -907,12 +908,12 @@ class MachineCom(object): elif 'End file list' in line: self._sdFileList = False self._callback.on_comm_sd_files(self._sdFiles) - elif 'SD printing byte' in line: + elif 'SD printing byte' in line and self.isSdPrinting(): # answer to M27, at least on Marlin, Repetier and Sprinter: "SD printing byte %d/%d" match = self._regex_sdPrintingByte.search(line) self._currentFile.setFilepos(int(match.group(1))) self._callback.on_comm_progress() - elif 'File opened' in line: + elif 'File opened' in line and not self._ignore_select: # answer to M23, at least on Marlin, Repetier and Sprinter: "File opened:%s Size:%d" match = self._regex_sdFileOpened.search(line) if self._sdFileToSelect: @@ -934,8 +935,9 @@ class MachineCom(object): elif 'Writing to file' in line: # anwer to M28, at least on Marlin, Repetier and Sprinter: "Writing to file: %s" self._changeState(self.STATE_PRINTING) + self._clear_to_send.set() line = "ok" - elif 'Done printing file' in line: + elif 'Done printing file' in line and self.isSdPrinting(): # printer is reporting file finished printing self._sdFilePos = 0 self._callback.on_comm_print_job_done() @@ -1092,39 +1094,31 @@ class MachineCom(object): eventManager().fire(Events.ERROR, {"error": self.getErrorString()}) self._log("Connection closed, closing down monitor") - def _enqueue_for_sending(self, command, linenumber=None): - self._send_queue.put((command, linenumber)) - - def _send_loop(self): - while self._send_queue_active: - try: - entry = self._send_queue.get() - if not self._send_queue_active: - break - - command, linenumber = entry - if linenumber is not None: - self._doSendWithChecksum(command, linenumber) - else: - self._doSendWithoutChecksum(command) - self._clear_to_send.clear() - self._clear_to_send.wait() - except: - self._logger.exception("Caught an exception in the send loop") - self._log("") - self._logger.info("Closing down send loop") - def _poll_temperature(self): - if self.isOperational() and not self.isStreaming() and not self._blocking_command: - self.sendCommand("M105") + """ + Polls the temperature after the temperature timeout, re-enqueues itself. + + If the printer is not operational, not printing from sd, busy with a blocking command or heating, no poll + will be done. + """ + + if self.isOperational() and not self.isStreaming() and not self._blocking_command and not self._heating: + self.sendCommand("M105", cmd_type="temperature_poll") interval = get_interval("temperature") self._temperature_timer = threading.Timer(interval, self._poll_temperature) self._temperature_timer.start() def _poll_sd_status(self): - if self.isOperational() and self.isSdPrinting() and not self._blocking_command: - self.sendCommand("M27") + """ + Polls the sd printing status after the sd status timeout, re-enqueues itself. + + If the printer is not operational, not printing from sd, busy with a blocking command or heating, no poll + will be done. + """ + + if self.isOperational() and self.isSdPrinting() and not self._blocking_command and not self._heating: + self.sendCommand("M27", cmd_type="sd_status_poll") interval = get_interval("sdStatus") self._sd_status_timer = threading.Timer(interval, self._poll_sd_status) @@ -1209,12 +1203,12 @@ class MachineCom(object): #Skip the communication errors, as those get corrected. if 'checksum mismatch' in line \ - or 'Wrong checksum' in line \ - or 'Line Number is not Last Line Number' in line \ - or 'expected line' in line \ - or 'No Line Number with checksum' in line \ - or 'No Checksum with line number' in line \ - or 'Missing checksum' in line: + or 'Wrong checksum' in line \ + or 'Line Number is not Last Line Number' in line \ + or 'expected line' in line \ + or 'No Line Number with checksum' in line \ + or 'No Checksum with line number' in line \ + or 'Missing checksum' in line: self._lastCommError = line[6:] if line.startswith("Error:") else line[2:] pass elif not self.isError(): @@ -1323,7 +1317,6 @@ class MachineCom(object): # Make sure we are only handling one sending job at a time with self._sendingLock: - self._logger.debug("Resending line %r, delta is %r, last resend number is %r, current resend count is %r, lastCommError is %r" % (self._currentLine - self._resendDelta, self._resendDelta, self._lastResendNumber, self._currentResendCount, lastCommError)) cmd = self._lastLines[-self._resendDelta] lineNumber = self._currentLine - self._resendDelta @@ -1335,7 +1328,13 @@ class MachineCom(object): self._lastResendNumber = None self._currentResendCount = 0 - def _sendCommand(self, cmd, sendChecksum=False): + def _sendCommand(self, cmd_tuple, sendChecksum=False): + if isinstance(cmd_tuple, tuple): + cmd, cmd_type = cmd_tuple + else: + cmd = cmd_tuple + cmd_type = None + # Make sure we are only handling one sending job at a time with self._sendingLock: if self._serial is None: @@ -1358,20 +1357,66 @@ class MachineCom(object): cmd = getattr(self, gcodeHandler)(cmd) if cmd is not None: - self._doSend(cmd, sendChecksum) + self._doSend(cmd, send_checksum=sendChecksum, cmd_type=cmd_type) - def _doSend(self, cmd, sendChecksum=False): - if sendChecksum or self._alwaysSendChecksum: + def _doSend(self, cmd, send_checksum=False, cmd_type=None): + if send_checksum or self._alwaysSendChecksum: lineNumber = self._currentLine self._addToLastLines(cmd) self._currentLine += 1 - self._enqueue_for_sending(cmd, linenumber=lineNumber) + self._enqueue_for_sending(cmd, linenumber=lineNumber, command_type=cmd_type) else: - self._enqueue_for_sending(cmd) + self._enqueue_for_sending(cmd, command_type=cmd_type) + + ##~~ send loop handling + + def _enqueue_for_sending(self, command, linenumber=None, command_type=None): + """ + Enqueues a command an optional linenumber to use for it in the send queue. + + Arguments: + command (str): The command to send. + linenumber (int): The line number with which to send the command. May be ``None`` in which case the command + will be sent without a line number and checksum. + """ + + try: + self._send_queue.put((command, linenumber, command_type)) + except TypeAlreadyInQueue as e: + self._logger.debug("Type already in queue: " + e.type) + + def _send_loop(self): + """ + The send loop is reponsible of sending commands in ``self._send_queue`` over the line, if it is cleared for + sending (through received ``ok`` responses from the printer's firmware. + """ + + while self._send_queue_active: + try: + # wait until we have something in the queue + entry = self._send_queue.get() + + # make sure we are still active + if not self._send_queue_active: + break + + # fetch command and optional linenumber from queue, send it + command, linenumber, _ = entry + if linenumber is not None: + self._doSendWithChecksum(command, linenumber) + else: + self._doSendWithoutChecksum(command) + + # we just used up one ok, clear it, wait for the next clear + self._clear_to_send.clear() + self._clear_to_send.wait() + except: + self._logger.exception("Caught an exception in the send loop") + self._log("Closing down send loop") + + ##~~ actual sending via serial def _doSendWithChecksum(self, cmd, lineNumber): - self._logger.debug("Sending cmd '%s' with lineNumber %r" % (cmd, lineNumber)) - commandToSend = "N%d %s" % (lineNumber, cmd) checksum = reduce(lambda x,y:x^y, map(ord, commandToSend)) commandToSend = "%s*%d" % (commandToSend, checksum) @@ -1394,6 +1439,8 @@ class MachineCom(object): self._errorValue = get_exception_string() self.close(True) + ##~~ command handlers + def _gcode_T(self, cmd): toolMatch = self._regex_paramTInt.search(cmd) if toolMatch: @@ -1749,6 +1796,40 @@ class StreamingGcodeFileInformation(PrintingGcodeFileInformation): return self._remoteFilename +class TypedQueue(queue.Queue): + + def __init__(self, maxsize=0): + queue.Queue.__init__(self, maxsize=maxsize) + self._lookup = [] + + def _put(self, item): + if isinstance(item, tuple) and len(item) == 3: + cmd, line, cmd_type = item + if cmd_type is not None: + if cmd_type in self._lookup: + raise TypeAlreadyInQueue(cmd_type, "Type {cmd_type} is already in queue".format(**locals())) + else: + self._lookup.append(cmd_type) + + queue.Queue._put(self, item) + + def _get(self): + item = queue.Queue._get(self) + + if isinstance(item, tuple) and len(item) == 3: + cmd, line, cmd_type = item + if cmd_type is not None and cmd_type in self._lookup: + self._lookup.remove(cmd_type) + + return item + + +class TypeAlreadyInQueue(BaseException): + def __init__(self, t, *args, **kwargs): + BaseException.__init__(self, *args, **kwargs) + self.type = t + + def get_new_timeout(type): now = time.time() return now + get_interval(type) From edd560f5a46152ec651763dec363c0db5b3e22b7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gina=20H=C3=A4u=C3=9Fge?= Date: Wed, 4 Mar 2015 20:38:49 +0100 Subject: [PATCH 08/10] Fixed a bug causing feed rate adjustment to not work while printing --- src/octoprint/server/api/printer.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/octoprint/server/api/printer.py b/src/octoprint/server/api/printer.py index 7299ad63..aec0569b 100644 --- a/src/octoprint/server/api/printer.py +++ b/src/octoprint/server/api/printer.py @@ -223,10 +223,6 @@ def printerBedState(): @api.route("/printer/printhead", methods=["POST"]) @restricted_access def printerPrintheadCommand(): - if not printer.is_operational() or printer.is_printing(): - # do not jog when a print job is running or we don't have a connection - return make_response("Printer is not operational or currently printing", 409) - valid_commands = { "jog": [], "home": ["axes"], @@ -236,6 +232,10 @@ def printerPrintheadCommand(): if response is not None: return response + if not printer.is_operational() or (printer.is_printing() and command != "feedrate"): + # do not jog when a print job is running or we don't have a connection + return make_response("Printer is not operational or currently printing", 409) + valid_axes = ["x", "y", "z"] ##~~ jog command if command == "jog": From f0b2f6d5091d74f5858fbbb70125d947cb4dfe2a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gina=20H=C3=A4u=C3=9Fge?= Date: Wed, 4 Mar 2015 20:39:36 +0100 Subject: [PATCH 09/10] Fix: Display full name currently selected SD file Wrong truncation caused first character to be missing --- src/octoprint/printer/standard.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/octoprint/printer/standard.py b/src/octoprint/printer/standard.py index 6698931c..8a34f0c8 100644 --- a/src/octoprint/printer/standard.py +++ b/src/octoprint/printer/standard.py @@ -631,7 +631,7 @@ class Printer(PrinterInterface, comm.MachineComPrintCallback): def _setJobData(self, filename, filesize, sd): if filename is not None: if sd: - path_in_storage = filename[1:] + path_in_storage = filename path_on_disk = None else: path_in_storage = self._fileManager.path_in_storage(FileDestinations.LOCAL, filename) From 88ac1974d1bc8d24466a87ca5a6ae2ccca3f082d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gina=20H=C3=A4u=C3=9Fge?= Date: Wed, 4 Mar 2015 20:41:10 +0100 Subject: [PATCH 10/10] Time estimation for SD printing needs less strict thresholds --- src/octoprint/printer/estimation.py | 25 ++++++++++++++++++------- src/octoprint/printer/standard.py | 16 +++++++++++++++- 2 files changed, 33 insertions(+), 8 deletions(-) diff --git a/src/octoprint/printer/estimation.py b/src/octoprint/printer/estimation.py index 317344d7..30e733fc 100644 --- a/src/octoprint/printer/estimation.py +++ b/src/octoprint/printer/estimation.py @@ -12,16 +12,27 @@ class TimeEstimationHelper(object): STABLE_COUNTDOWN = 250 STABLE_ROLLING_WINDOW = 250 - def __init__(self): + def __init__(self, rolling_window=None, countdown=None, threshold=None): + if rolling_window is None: + rolling_window = self.__class__.STABLE_ROLLING_WINDOW + if countdown is None: + countdown = self.__class__.STABLE_COUNTDOWN + if threshold is None: + threshold = self.__class__.STABLE_THRESHOLD + + self._rolling_window = rolling_window + self._countdown = countdown + self._threshold = threshold + import collections - self._distances = collections.deque([], self.__class__.STABLE_ROLLING_WINDOW) - self._totals = collections.deque([], self.__class__.STABLE_ROLLING_WINDOW) + self._distances = collections.deque([], self._rolling_window) + self._totals = collections.deque([], self._rolling_window) self._sum_total = 0 self._count = 0 self._stable_counter = None def is_stable(self): - return self._stable_counter is not None and self._stable_counter >= self.__class__.STABLE_COUNTDOWN + return self._stable_counter is not None and self._stable_counter >= self._countdown def update(self, newEstimate): old_average_total = self.average_total @@ -33,7 +44,7 @@ class TimeEstimationHelper(object): if old_average_total: self._distances.append(abs(self.average_total - old_average_total)) - if -1.0 * self.__class__.STABLE_THRESHOLD < self.average_distance < self.__class__.STABLE_THRESHOLD: + if -1.0 * self._threshold < self.average_distance < self._threshold: if self._stable_counter is None: self._stable_counter = 0 else: @@ -50,14 +61,14 @@ class TimeEstimationHelper(object): @property def average_total_rolling(self): - if not self._count or self._count < self.__class__.STABLE_ROLLING_WINDOW: + if not self._count or self._count < self._rolling_window: return None else: return sum(self._totals) / len(self._totals) @property def average_distance(self): - if not self._count or self._count < self.__class__.STABLE_ROLLING_WINDOW + 1: + if not self._count or self._count < self._rolling_window + 1: return None else: return sum(self._distances) / len(self._distances) \ No newline at end of file diff --git a/src/octoprint/printer/standard.py b/src/octoprint/printer/standard.py index 8a34f0c8..f4dad98b 100644 --- a/src/octoprint/printer/standard.py +++ b/src/octoprint/printer/standard.py @@ -374,7 +374,21 @@ class Printer(PrinterInterface, comm.MachineComPrintCallback): if self._selectedFile is None: return - self._timeEstimationData = TimeEstimationHelper() + rolling_window = None + threshold = None + countdown = None + if self._selectedFile["sd"]: + # we are interesting in a rolling window of roughly the last 15s, so the number of entries has to be derived + # by that divided by the sd status polling interval + rolling_window = 15 / settings().get(["serial", "timeout", "sdStatus"]) + + # we are happy if the average of the estimates stays within 60s of the prior one + threshold = 60 + + # we are happy when one rolling window has been stable + countdown = rolling_window + self._timeEstimationData = TimeEstimationHelper(rolling_window=rolling_window, threshold=threshold, countdown=countdown) + self._lastProgressReport = None self._setCurrentZ(None) self._comm.startPrint()