Fetch estimated print time from cura slicing result, create print time statistics per printer profile, interpolate between stats and live estimation during printing for print time left

This commit is contained in:
Gina Häußge 2014-12-17 17:31:30 +01:00
parent a544a852f2
commit 014d39c11d
9 changed files with 168 additions and 28 deletions

View file

@ -42,6 +42,7 @@ class Events(object):
UPDATED_FILES = "UpdatedFiles"
METADATA_ANALYSIS_STARTED = "MetadataAnalysisStarted"
METADATA_ANALYSIS_FINISHED = "MetadataAnalysisFinished"
METADATA_STATISTICS_UPDATED = "MetadataStatisticsUpdated"
# SD Upload
TRANSFER_STARTED = "TransferStarted"

View file

@ -159,7 +159,7 @@ class FileManager(object):
position=None, profile=None, printer_profile_id=None, overrides=None, callback=None, callback_args=None):
absolute_source_path = self.get_absolute_path(source_location, source_path)
def stlProcessed(source_location, source_path, tmp_path, dest_location, dest_path, start_time, printer_profile_id, callback, callback_args, _error=None, _cancelled=False):
def stlProcessed(source_location, source_path, tmp_path, dest_location, dest_path, start_time, printer_profile_id, callback, callback_args, _error=None, _cancelled=False, _analysis=None):
try:
if _error:
eventManager().fire(Events.SLICING_FAILED, {"stl": source_path, "gcode": dest_path, "reason": _error})
@ -187,7 +187,7 @@ class FileManager(object):
file_obj = Wrapper(stl_name, temp_path, hash)
printer_profile = self._printer_profile_manager.get(printer_profile_id)
self.add_file(dest_location, dest_path, file_obj, links=links, allow_overwrite=True, printer_profile=printer_profile)
self.add_file(dest_location, dest_path, file_obj, links=links, allow_overwrite=True, printer_profile=printer_profile, analysis=_analysis)
end_time = time.time()
eventManager().fire(Events.SLICING_DONE, {"stl": source_path, "gcode": dest_path, "time": end_time - start_time})
@ -286,17 +286,20 @@ class FileManager(object):
result[dst] = self._storage_managers[dst].list_files(path=path, filter=filter, recursive=recursive)
return result
def add_file(self, destination, path, file_object, links=None, allow_overwrite=False, printer_profile=None):
def add_file(self, destination, path, file_object, links=None, allow_overwrite=False, printer_profile=None, analysis=None):
if printer_profile is None:
printer_profile = self._printer_profile_manager.get_current_or_default()
file_path = self._storage(destination).add_file(path, file_object, links=links, printer_profile=printer_profile, allow_overwrite=allow_overwrite)
absolute_path = self._storage(destination).get_absolute_path(file_path)
file_type = get_file_type(absolute_path)
if file_type:
queue_entry = QueueEntry(file_path, file_type[-1], destination, absolute_path, printer_profile)
self._analysis_queue.enqueue(queue_entry, high_priority=True)
if analysis is None:
file_type = get_file_type(absolute_path)
if file_type:
queue_entry = QueueEntry(file_path, file_type[-1], destination, absolute_path, printer_profile)
self._analysis_queue.enqueue(queue_entry, high_priority=True)
else:
self._add_analysis_result(destination, path, analysis)
eventManager().fire(Events.UPDATED_FILES, dict(type="printables"))
return file_path
@ -323,9 +326,13 @@ class FileManager(object):
def remove_link(self, destination, path, rel, data):
self._storage(destination).remove_link(path, rel, data)
def log_print(self, destination, path, timestamp, print_time, success):
def log_print(self, destination, path, timestamp, print_time, success, printer_profile):
try:
self._storage(destination).add_history(path, dict(timestamp=timestamp, printTime=print_time, success=success))
if success:
self._storage(destination).add_history(path, dict(timestamp=timestamp, printTime=print_time, success=success, printerProfile=printer_profile))
else:
self._storage(destination).add_history(path, dict(timestamp=timestamp, success=success, printerProfile=printer_profile))
eventManager().fire(Events.METADATA_STATISTICS_UPDATED, dict(storage=destination, path=path))
except NoSuchStorage:
# if there's no storage configured where to log the print, we'll just not log it
pass
@ -362,10 +369,13 @@ class FileManager(object):
raise NoSuchStorage("No storage configured for destination {destination}".format(**locals()))
return self._storage_managers[destination]
def _on_analysis_finished(self, entry, result):
if not entry.location in self._storage_managers:
def _add_analysis_result(self, destination, path, result):
if not destination in self._storage_managers:
return
storage_manager = self._storage_managers[entry.location]
storage_manager.set_additional_metadata(entry.path, "analysis", result)
storage_manager = self._storage_managers[destination]
storage_manager.set_additional_metadata(path, "analysis", result)
def _on_analysis_finished(self, entry, result):
self._add_analysis_result(entry.location, entry.path, result)

View file

@ -501,6 +501,7 @@ class LocalFileStorage(StorageInterface):
metadata[name]["history"] = []
metadata[name]["history"].append(data)
self._calculate_stats_from_history(name, path, metadata=metadata, save=False)
self._save_metadata(path, metadata)
def _update_history(self, name, path, index, data):
@ -510,7 +511,8 @@ class LocalFileStorage(StorageInterface):
return
try:
metadata[name]["history"][index] = data
metadata[name]["history"][index].update(data)
self._calculate_stats_from_history(name, path, metadata=metadata, save=False)
self._save_metadata(path, metadata)
except IndexError:
pass
@ -523,10 +525,55 @@ class LocalFileStorage(StorageInterface):
try:
del metadata[name]["history"][index]
self._calculate_stats_from_history(name, path, metadata=metadata, save=False)
self._save_metadata(path, metadata)
except IndexError:
pass
def _calculate_stats_from_history(self, name, path, metadata=None, save=True):
if metadata is None:
metadata = self._get_metadata(path)
if not name in metadata or not "history" in metadata[name]:
return
# collect data from history
former_print_times = dict()
last_print = dict()
for history_entry in metadata[name]["history"]:
if not "printTime" in history_entry or not "success" in history_entry or not history_entry["success"] or not "printerProfile" in history_entry:
continue
printer_profile = history_entry["printerProfile"]
print_time = history_entry["printTime"]
if not printer_profile in former_print_times:
former_print_times[printer_profile] = []
former_print_times[printer_profile].append(print_time)
if not printer_profile in last_print or last_print[printer_profile] is None or ("timestamp" in history_entry and history_entry["timestamp"] > last_print[printer_profile]["timestamp"]):
last_print[printer_profile] = history_entry
# calculate stats
statistics = dict(averagePrintTime=dict(), lastPrintTime=dict())
for printer_profile in former_print_times:
if not former_print_times[printer_profile]:
continue
statistics["averagePrintTime"][printer_profile] = sum(former_print_times[printer_profile]) / float(len(former_print_times[printer_profile]))
for printer_profile in last_print:
if not last_print[printer_profile]:
continue
statistics["lastPrintTime"][printer_profile] = last_print[printer_profile]["printTime"]
metadata[name]["statistics"] = statistics
if save:
self._save_metadata(path, metadata)
def _get_links(self, name, path, searched_rel):
metadata = self._get_metadata(path)
result = []

View file

@ -9,6 +9,7 @@ import logging
import logging.handlers
import os
import flask
import math
import octoprint.plugin
import octoprint.util
@ -278,6 +279,7 @@ class CuraPlugin(octoprint.plugin.SlicerPlugin,
skin=1,
export=2
)
analysis = None
while p.returncode is None:
line = p.stderr.readline(timeout=0.5)
if not line:
@ -331,6 +333,39 @@ class CuraPlugin(octoprint.plugin.SlicerPlugin,
continue
on_progress_kwargs["_progress"] = (step_factor[step] * layer_count + current_layer) / (layer_count * 3)
on_progress(*on_progress_args, **on_progress_kwargs)
elif line.startswith("Print time:"):
try:
print_time = int(line[len("Print time:"):].strip())
if analysis is None:
analysis = dict()
analysis["estimatedPrintTime"] = print_time
except:
pass
elif line.startswith("Filament:") or line.startswith("Filament2:"):
if line.startswith("Filament:"):
filament_str = line[len("Filament:"):].strip()
tool_key = "tool0"
else:
filament_str = line[len("Filament2:"):].strip()
tool_key = "tool1"
try:
filament = int(filament_str)
if analysis is None:
analysis = dict()
if not "filament" in analysis:
analysis["filament"] = dict()
if not tool_key in analysis["filament"]:
analysis["filament"][tool_key] = dict()
analysis["filament"][tool_key]["length"] = filament
if "filamentDiameter" in engine_settings:
radius_in_cm = float(int(engine_settings["filamentDiameter"]) / 10000.0) / 2.0
filament_in_cm = filament / 10.0
analysis["filament"][tool_key]["volume"] = filament_in_cm * math.pi * radius_in_cm * radius_in_cm
except:
pass
finally:
p.close()
@ -341,7 +376,7 @@ class CuraPlugin(octoprint.plugin.SlicerPlugin,
self._cura_logger.info("### Finished, returncode %d" % p.returncode)
if p.returncode == 0:
return True, None
return True, dict(analysis=analysis)
else:
self._logger.warn("Could not slice via Cura, got return code %r" % p.returncode)
return False, "Got returncode %r" % p.returncode

View file

@ -36,6 +36,7 @@ class Printer():
self._logger = logging.getLogger(__name__)
self._estimationLogger = logging.getLogger("ESTIMATIONS")
self._printTimeLogger = logging.getLogger("PRINT_TIME")
self._analysisQueue = analysisQueue
self._fileManager = fileManager
@ -114,7 +115,8 @@ class Printer():
currentZ=None
)
eventManager().subscribe(Events.METADATA_ANALYSIS_FINISHED, self.onMetadataAnalysisFinished);
eventManager().subscribe(Events.METADATA_ANALYSIS_FINISHED, self.onMetadataAnalysisFinished)
eventManager().subscribe(Events.METADATA_STATISTICS_UPDATED, self.onMetadataStatisticsUpdated)
#~~ callback handling
@ -164,6 +166,11 @@ class Printer():
self._selectedFile["filesize"],
self._selectedFile["sd"])
def onMetadataStatisticsUpdated(self, event, data):
self._setJobData(self._selectedFile["filename"],
self._selectedFile["filesize"],
self._selectedFile["sd"])
#~~ progress plugin reporting
def _reportPrintProgressToPlugins(self, progress):
@ -348,7 +355,7 @@ class Printer():
# 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._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
@ -398,10 +405,26 @@ class Printer():
def _setProgressData(self, progress, filepos, printTime, cleanedPrintTime):
estimatedTotalPrintTime = self._estimateTotalPrintTime(progress, cleanedPrintTime)
statisticalTotalPrintTime = None
totalPrintTime = estimatedTotalPrintTime
if self._selectedFile and "estimatedPrintTime" in self._selectedFile and self._selectedFile["estimatedPrintTime"]:
statisticalTotalPrintTime = self._selectedFile["estimatedPrintTime"]
if progress and cleanedPrintTime:
if estimatedTotalPrintTime is None:
totalPrintTime = statisticalTotalPrintTime
else:
if progress < 0.5:
sub_progress = progress * 2
else:
sub_progress = 1.0
totalPrintTime = (1 - sub_progress) * statisticalTotalPrintTime + sub_progress * estimatedTotalPrintTime
#self._printTimeLogger.info("{progress};{cleanedPrintTime};{estimatedTotalPrintTime};{statisticalTotalPrintTime};{totalPrintTime}".format(**locals()))
self._progress = progress
self._printTime = printTime
self._printTimeLeft = estimatedTotalPrintTime - cleanedPrintTime if (estimatedTotalPrintTime is not None and cleanedPrintTime is not None) else None
self._printTimeLeft = totalPrintTime - cleanedPrintTime if (totalPrintTime is not None and cleanedPrintTime is not None) else None
self._stateMonitor.setProgress({
"completion": self._progress * 100 if self._progress is not None else None,
@ -447,6 +470,7 @@ class Printer():
"filename": filename,
"filesize": filesize,
"sd": sd,
"estimatedPrintTime": None
}
else:
self._selectedFile = None
@ -458,12 +482,15 @@ class Printer():
"date": None
},
"estimatedPrintTime": None,
"averagePrintTime": None,
"lastPrintTime": None,
"filament": None,
})
return
estimatedPrintTime = None
lastPrintTime = None
averagePrintTime = None
date = None
filament = None
if filename:
@ -482,8 +509,18 @@ class Printer():
estimatedPrintTime = fileData["analysis"]["estimatedPrintTime"]
if "filament" in fileData["analysis"].keys():
filament = fileData["analysis"]["filament"]
if "prints" in fileData and fileData["prints"] and "last" in fileData["prints"] and fileData["prints"]["last"] and "lastPrintTime" in fileData["prints"]["last"]:
lastPrintTime = fileData["prints"]["last"]["lastPrintTime"]
if "statistics" in fileData:
printer_profile = self._printerProfileManager.get_current_or_default()["id"]
if "averagePrintTime" in fileData["statistics"] and printer_profile in fileData["statistics"]["averagePrintTime"]:
averagePrintTime = fileData["statistics"]["averagePrintTime"][printer_profile]
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
self._stateMonitor.setJobData({
"file": {
@ -493,6 +530,7 @@ class Printer():
"date": date
},
"estimatedPrintTime": estimatedPrintTime,
"averagePrintTime": averagePrintTime,
"lastPrintTime": lastPrintTime,
"filament": filament,
})
@ -543,9 +581,9 @@ class Printer():
if self._comm is not None and oldState == self._comm.STATE_PRINTING:
if self._selectedFile is not None:
if state == self._comm.STATE_OPERATIONAL:
self._fileManager.log_print(FileDestinations.SDCARD if self._selectedFile["sd"] else FileDestinations.LOCAL, self._selectedFile["filename"], time.time(), self._comm.getPrintTime(), True)
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"])
elif state == self._comm.STATE_CLOSED or state == self._comm.STATE_ERROR or state == self._comm.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._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 self._comm is not None and state == self._comm.STATE_PRINTING:
self._analysisQueue.pause() # do not analyse files while printing

View file

@ -99,10 +99,11 @@ def _getFileList(origin, filter=None):
failure=failure,
last=dict(
success=last["success"],
date=last["timestamp"],
printTime=last["printTime"]
date=last["timestamp"]
)
)
if "printTime" in last:
prints["last"]["printTime"] = last["printTime"]
file["prints"] = prints
file.update({

View file

@ -136,6 +136,8 @@ class SlicingManager(object):
if not ok:
callback_kwargs.update(dict(_error=result))
elif result is not None and isinstance(result, dict) and "analysis" in result:
callback_kwargs.update(dict(_analysis=result["analysis"]))
except SlicingCancelled:
callback_kwargs.update(dict(_cancelled=True))
finally:

View file

@ -87,8 +87,13 @@ class gcode(object):
self._filamentDiameter = float(filamentValue.split(",")[0].strip())
except ValueError:
self._filamentDiameter = 0.0
elif comment.startswith("CURA_PROFILE_STRING"):
curaOptions = self._parseCuraProfileString(comment)
elif comment.startswith("CURA_PROFILE_STRING") or comment.startswith("CURA_OCTO_PROFILE_STRING"):
if comment.startswith("CURA_PROFILE_STRING"):
prefix = "CURA_PROFILE_STRING:"
else:
prefix = "CURA_OCTO_PROFILE_STRING:"
curaOptions = self._parseCuraProfileString(comment, prefix)
if "filament_diameter" in curaOptions:
try:
self._filamentDiameter = float(curaOptions["filament_diameter"])
@ -239,8 +244,8 @@ class gcode(object):
self.extrusionVolume[i] = (self.extrusionAmount[i] * (math.pi * radius * radius)) / 1000
self.totalMoveTimeMinute = totalMoveTimeMinute
def _parseCuraProfileString(self, comment):
return {key: value for (key, value) in map(lambda x: x.split("=", 1), zlib.decompress(base64.b64decode(comment[len("CURA_PROFILE_STRING:"):])).split("\b"))}
def _parseCuraProfileString(self, comment, prefix):
return {key: value for (key, value) in map(lambda x: x.split("=", 1), zlib.decompress(base64.b64decode(comment[len(prefix):])).split("\b"))}
def getCodeInt(line, code):

View file

@ -16,6 +16,7 @@ class EstimationTestCase(unittest.TestCase):
def setUp(self):
self.estimation_helper = type(octoprint.printer.TimeEstimationHelper)(octoprint.printer.TimeEstimationHelper.__name__, (octoprint.printer.TimeEstimationHelper,), {
'STABLE_THRESHOLD': 0.1,
'STABLE_ROLLING_WINDOW': 3,
'STABLE_COUNTDOWN': 1
})()