diff --git a/src/octoprint/plugins/virtual_printer/virtual.py b/src/octoprint/plugins/virtual_printer/virtual.py index 63a3654f..93ad5825 100644 --- a/src/octoprint/plugins/virtual_printer/virtual.py +++ b/src/octoprint/plugins/virtual_printer/virtual.py @@ -82,6 +82,7 @@ class VirtualPrinter(object): self._incoming_lock = threading.RLock() + self._debug_sleep = None self._sleepAfterNext = dict() self._sleepAfter = dict() @@ -412,7 +413,7 @@ class VirtualPrinter(object): if sleep_match is not None: interval = int(sleep_match.group(1)) self._output("// sleeping for {interval} seconds".format(interval=interval)) - time.sleep(interval) + self._debug_sleep = interval elif sleep_after_match is not None: command = sleep_after_match.group(1) interval = int(sleep_after_match.group(2)) @@ -803,11 +804,32 @@ class VirtualPrinter(object): if self._debug_drop_connection: raise SerialTimeoutException() + if self._debug_sleep > 0: + # if we are supposed to sleep, we sleep not longer than the read timeout + # (and then on the next call sleep again if there's time to sleep left) + sleep_for = min(self._debug_sleep, self._read_timeout) + self._debug_sleep -= sleep_for + time.sleep(sleep_for) + + if self._debug_sleep > 0: + # we slept the full read timeout, return an empty line + return "" + + # otherwise our left over timeout is the read timeout minus what we already + # slept for + timeout = self._read_timeout - sleep_for + + else: + # use the full read timeout as timeout + timeout = self._read_timeout + try: - line = self.outgoing.get(timeout=self._read_timeout) + # fetch a line from the queue, wait no longer than timeout + line = self.outgoing.get(timeout=timeout) self.outgoing.task_done() return line except Queue.Empty: + # queue empty? return empty line return "" def close(self): @@ -843,7 +865,8 @@ class CharCountingQueue(Queue.Queue): try: if not self._will_it_fit(item) and partial: space_left = self.maxsize - self._qsize() - item = item[:space_left] + if space_left: + item = item[:space_left] if not block: if not self._will_it_fit(item): diff --git a/src/octoprint/printer/standard.py b/src/octoprint/printer/standard.py index 2400a12f..8a446036 100644 --- a/src/octoprint/printer/standard.py +++ b/src/octoprint/printer/standard.py @@ -71,6 +71,7 @@ class Printer(PrinterInterface, comm.MachineComPrintCallback): self._streamingFinishedCallback = None self._selectedFile = None + self._selectedFileLock = threading.RLock() self._timeEstimationData = None # comm @@ -111,8 +112,8 @@ class Printer(PrinterInterface, comm.MachineComPrintCallback): current_z=None ) - eventManager().subscribe(Events.METADATA_ANALYSIS_FINISHED, self._on_event_MetadataAnalysisFinished) - eventManager().subscribe(Events.METADATA_STATISTICS_UPDATED, self._on_event_MetadataStatisticsUpdated) + eventManager().subscribe(Events.METADATA_ANALYSIS_FINISHED, self._on_metadata_event) + eventManager().subscribe(Events.METADATA_STATISTICS_UPDATED, self._on_metadata_event) #~~ handling of PrinterCallbacks @@ -149,25 +150,23 @@ class Printer(PrinterInterface, comm.MachineComPrintCallback): #~~ callback from metadata analysis event - def _on_event_MetadataAnalysisFinished(self, event, data): - if self._selectedFile: - self._setJobData(self._selectedFile["filename"], - self._selectedFile["filesize"], - self._selectedFile["sd"]) - - def _on_event_MetadataStatisticsUpdated(self, event, data): - self._setJobData(self._selectedFile["filename"], - self._selectedFile["filesize"], - self._selectedFile["sd"]) + def _on_metadata_event(self, event, data): + with self._selectedFileLock: + if self._selectedFile and data and data.get("path", None) == self._selectedFile["filename"] \ + and data.get("storage", None) == FileDestinations.SDCARD if self._selectedFile["sd"] else FileDestinations.LOCAL: + self._setJobData(self._selectedFile["filename"], + self._selectedFile["filesize"], + self._selectedFile["sd"]) #~~ progress plugin reporting def _reportPrintProgressToPlugins(self, progress): - if not progress or not self._selectedFile or not "sd" in self._selectedFile or not "filename" in self._selectedFile: - return + with self._selectedFileLock: + if not progress or not self._selectedFile or not "sd" in self._selectedFile or not "filename" in self._selectedFile: + return - storage = "sdcard" if self._selectedFile["sd"] else "local" - filename = self._selectedFile["filename"] + storage = "sdcard" if self._selectedFile["sd"] else "local" + filename = self._selectedFile["filename"] def call_plugins(storage, filename, progress): for plugin in self._progressPlugins: @@ -378,13 +377,16 @@ class Printer(PrinterInterface, comm.MachineComPrintCallback): """ if self._comm is None or not self._comm.isOperational() or self._comm.isPrinting(): return - if self._selectedFile is None: - return + + with self._selectedFileLock: + if self._selectedFile is None: + return + sd = self._selectedFile["sd"] rolling_window = None threshold = None countdown = None - if self._selectedFile["sd"]: + if 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"]) @@ -441,15 +443,16 @@ class Printer(PrinterInterface, comm.MachineComPrintCallback): self._setProgressData() # mark print as failure - if self._selectedFile is not None: - self._fileManager.log_print(FileDestinations.SDCARD if self._selectedFile["sd"] else FileDestinations.LOCAL, self._selectedFile["filename"], time.time(), self._comm.getPrintTime(), False, self._printerProfileManager.get_current_or_default()["id"]) - payload = { - "file": self._selectedFile["filename"], - "origin": FileDestinations.LOCAL - } - if self._selectedFile["sd"]: - payload["origin"] = FileDestinations.SDCARD - eventManager().fire(Events.PRINT_FAILED, payload) + with self._selectedFileLock: + if self._selectedFile is not None: + self._fileManager.log_print(FileDestinations.SDCARD if self._selectedFile["sd"] else FileDestinations.LOCAL, self._selectedFile["filename"], time.time(), self._comm.getPrintTime(), False, self._printerProfileManager.get_current_or_default()["id"]) + payload = { + "file": self._selectedFile["filename"], + "origin": FileDestinations.LOCAL + } + if self._selectedFile["sd"]: + payload["origin"] = FileDestinations.SDCARD + eventManager().fire(Events.PRINT_FAILED, payload) def get_state_string(self): """ @@ -632,9 +635,13 @@ class Printer(PrinterInterface, comm.MachineComPrintCallback): estimatedTotalPrintTime = self._estimateTotalPrintTime(progress, cleanedPrintTime) totalPrintTime = estimatedTotalPrintTime - if self._selectedFile and "estimatedPrintTime" in self._selectedFile and self._selectedFile["estimatedPrintTime"]: - statisticalTotalPrintTime = self._selectedFile["estimatedPrintTime"] - if progress and cleanedPrintTime: + statisticalTotalPrintTime = None + with self._selectedFileLock: + if self._selectedFile and "estimatedPrintTime" in self._selectedFile and self._selectedFile[ + "estimatedPrintTime"]: + statisticalTotalPrintTime = self._selectedFile["estimatedPrintTime"] + + if statisticalTotalPrintTime is not None and progress and cleanedPrintTime: if estimatedTotalPrintTime is None: totalPrintTime = statisticalTotalPrintTime else: @@ -691,14 +698,16 @@ class Printer(PrinterInterface, comm.MachineComPrintCallback): else: path_in_storage = self._fileManager.path_in_storage(FileDestinations.LOCAL, filename) path_on_disk = self._fileManager.path_on_disk(FileDestinations.LOCAL, filename) - self._selectedFile = { - "filename": path_in_storage, - "filesize": filesize, - "sd": sd, - "estimatedPrintTime": None - } + with self._selectedFileLock: + self._selectedFile = { + "filename": path_in_storage, + "filesize": filesize, + "sd": sd, + "estimatedPrintTime": None + } else: - self._selectedFile = None + with self._selectedFileLock: + self._selectedFile = None self._stateMonitor.set_job_data({ "file": { "name": None, @@ -741,11 +750,13 @@ class Printer(PrinterInterface, comm.MachineComPrintCallback): if "lastPrintTime" in fileData["statistics"] and printer_profile in fileData["statistics"]["lastPrintTime"]: lastPrintTime = fileData["statistics"]["lastPrintTime"][printer_profile] - if averagePrintTime is not None: - self._selectedFile["estimatedPrintTime"] = averagePrintTime - elif estimatedPrintTime is not None: - # TODO apply factor which first needs to be tracked! - self._selectedFile["estimatedPrintTime"] = estimatedPrintTime + with self._selectedFileLock: + if self._selectedFile is not None: + if averagePrintTime is not None: + self._selectedFile["estimatedPrintTime"] = averagePrintTime + elif estimatedPrintTime is not None: + # TODO apply factor which first needs to be tracked! + self._selectedFile["estimatedPrintTime"] = estimatedPrintTime self._stateMonitor.set_job_data({ "file": { @@ -802,9 +813,10 @@ class Printer(PrinterInterface, comm.MachineComPrintCallback): # forward relevant state changes to gcode manager if oldState == comm.MachineCom.STATE_PRINTING: - if self._selectedFile is not None: - if state == comm.MachineCom.STATE_CLOSED or state == comm.MachineCom.STATE_ERROR or state == comm.MachineCom.STATE_CLOSED_WITH_ERROR: - self._fileManager.log_print(FileDestinations.SDCARD if self._selectedFile["sd"] else FileDestinations.LOCAL, self._selectedFile["filename"], time.time(), self._comm.getPrintTime(), False, self._printerProfileManager.get_current_or_default()["id"]) + with self._selectedFileLock: + if self._selectedFile is not None: + if state == comm.MachineCom.STATE_CLOSED or state == comm.MachineCom.STATE_ERROR or state == comm.MachineCom.STATE_CLOSED_WITH_ERROR: + self._fileManager.log_print(FileDestinations.SDCARD if self._selectedFile["sd"] else FileDestinations.LOCAL, self._selectedFile["filename"], time.time(), self._comm.getPrintTime(), False, self._printerProfileManager.get_current_or_default()["id"]) self._analysisQueue.resume() # printing done, put those cpu cycles to good use elif state == comm.MachineCom.STATE_PRINTING: self._analysisQueue.pause() # do not analyse files while printing @@ -862,8 +874,9 @@ class Printer(PrinterInterface, comm.MachineComPrintCallback): self.start_print(pos=self._posAfterSelect) def on_comm_print_job_done(self): - self._fileManager.log_print(FileDestinations.SDCARD if self._selectedFile["sd"] else FileDestinations.LOCAL, self._selectedFile["filename"], time.time(), self._comm.getPrintTime(), True, self._printerProfileManager.get_current_or_default()["id"]) - self._setProgressData(completion=1.0, filepos=self._selectedFile["filesize"], printTime=self._comm.getPrintTime(), printTimeLeft=0) + with self._selectedFileLock: + self._fileManager.log_print(FileDestinations.SDCARD if self._selectedFile["sd"] else FileDestinations.LOCAL, self._selectedFile["filename"], time.time(), self._comm.getPrintTime(), True, self._printerProfileManager.get_current_or_default()["id"]) + self._setProgressData(completion=1.0, filepos=self._selectedFile["filesize"], printTime=self._comm.getPrintTime(), printTimeLeft=0) self._stateMonitor.set_state({"text": self.get_state_string(), "flags": self._getStateFlags()}) self._fileManager.delete_recovery_data() diff --git a/src/octoprint/settings.py b/src/octoprint/settings.py index 74aa3d00..36305976 100644 --- a/src/octoprint/settings.py +++ b/src/octoprint/settings.py @@ -90,6 +90,7 @@ default_settings = { "printing": 10, "long": 10 }, + "maxWritePasses": 5, "additionalPorts": [], "longRunningCommands": ["G4", "G28", "G29", "G30", "G32", "M400", "M226"], "checksumRequiringCommands": ["M110"], diff --git a/src/octoprint/util/comm.py b/src/octoprint/util/comm.py index 833e4303..dfc92c50 100644 --- a/src/octoprint/util/comm.py +++ b/src/octoprint/util/comm.py @@ -244,6 +244,8 @@ class MachineCom(object): except: pass + self._max_write_passes = settings().getInt(["serial", "maxWritePasses"]) + self._hello_command = settings().get(["serial", "helloCommand"]) self._trigger_ok_for_m29 = settings().getBoolean(["serial", "triggerOkForM29"]) @@ -1992,8 +1994,11 @@ class MachineCom(object): cmd += "\n" written = 0 + passes = 0 while written < len(cmd): to_send = cmd[written:] + old_written = written + try: written += self._serial.write(to_send) except serial.SerialTimeoutException: @@ -2015,6 +2020,18 @@ class MachineCom(object): self.close(is_error=True) break + if old_written == written: + # nothing written this pass + passes += 1 + if passes > self._max_write_passes: + # nothing written in max consecutive passes, we give up + message = "Could not write anything to the serial port in {} tries, something appears to be wrong with the printer communication".format(self._max_write_passes) + self._logger.error(message) + self._log(message) + self._errorValue = "Could not write to serial port" + self.close(is_error=True) + break + ##~~ command handlers def _gcode_T_sent(self, cmd, cmd_type=None):