From 21a4033f734a9bd3075d65ff6549062d481009fd Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gina=20H=C3=A4u=C3=9Fge?= Date: Thu, 2 Jun 2016 10:05:44 +0200 Subject: [PATCH 1/4] Don't concurrently delete unrendered timelapses Could trigger lots of errors if an unrendered timelapse currently being collected was deleted from a separate thread from right under the collection thread. Also only log errors while processing already deleted files if debug logging is enabled. Finally trigger MovieDone event AFTER deleting unrendered files (otherwise just rendered timelapse might still be present when list of timelapses is queried right after). Should solve #1326 --- src/octoprint/timelapse.py | 63 +++++++++++++++++++++++--------------- 1 file changed, 38 insertions(+), 25 deletions(-) diff --git a/src/octoprint/timelapse.py b/src/octoprint/timelapse.py index 2b6f2990..b72473e1 100644 --- a/src/octoprint/timelapse.py +++ b/src/octoprint/timelapse.py @@ -44,6 +44,9 @@ _valid_timelapse_types = ["off", "timed", "zchange"] # callbacks for timelapse config updates _update_callbacks = [] +# lock for timelapse cleanup, must be re-entrant +_cleanup_lock = threading.RLock() + def _extract_prefix(filename): """ @@ -103,13 +106,17 @@ def get_unrendered_timelapses(): def delete_unrendered_timelapse(name): + global _cleanup_lock + basedir = settings().getBaseFolder("timelapse_tmp") - for filename in os.listdir(basedir): - try: - if fnmatch.fnmatch(filename, "{}*.jpg".format(name)): - os.remove(os.path.join(basedir, filename)) - except: - logging.getLogger(__name__).exception("Error while processing file {} during cleanup".format(filename)) + with _cleanup_lock: + for filename in os.listdir(basedir): + try: + if fnmatch.fnmatch(filename, "{}*.jpg".format(name)): + os.remove(os.path.join(basedir, filename)) + except: + if logging.getLogger(__name__).isEnabledFor(logging.DEBUG): + logging.getLogger(__name__).exception("Error while processing file {} during cleanup".format(filename)) def render_unrendered_timelapse(name, gcode=None, postfix=None, fps=25): @@ -131,33 +138,39 @@ def render_unrendered_timelapse(name, gcode=None, postfix=None, fps=25): def delete_old_unrendered_timelapses(): + global _cleanup_lock + basedir = settings().getBaseFolder("timelapse_tmp") clean_after_days = settings().getInt(["webcam", "cleanTmpAfterDays"]) cutoff = time.time() - clean_after_days * 24 * 60 * 60 prefixes_to_clean = [] - for filename in os.listdir(basedir): - try: - path = os.path.join(basedir, filename) - prefix = _extract_prefix(filename) - if prefix is None: - # might be an old tmp_00000.jpg kinda frame. we can't - # render those easily anymore, so delete that stuff - if _old_capture_format_re.match(filename): - os.remove(path) - continue + with _cleanup_lock: + for filename in os.listdir(basedir): + try: + path = os.path.join(basedir, filename) - if prefix in prefixes_to_clean: - continue + prefix = _extract_prefix(filename) + if prefix is None: + # might be an old tmp_00000.jpg kinda frame. we can't + # render those easily anymore, so delete that stuff + if _old_capture_format_re.match(filename): + os.remove(path) + continue - if os.path.getmtime(path) < cutoff: - prefixes_to_clean.append(prefix) - except: - logging.getLogger(__name__).exception("Error while processing file {} during cleanup".format(filename)) + if prefix in prefixes_to_clean: + continue - for prefix in prefixes_to_clean: - delete_unrendered_timelapse(prefix) + if os.path.getmtime(path) < cutoff: + prefixes_to_clean.append(prefix) + except: + if logging.getLogger(__name__).isEnabledFor(logging.DEBUG): + logging.getLogger(__name__).exception("Error while processing file {} during cleanup".format(filename)) + + for prefix in prefixes_to_clean: + delete_unrendered_timelapse(prefix) + logging.getLogger(__name__).info("Deleted old unrendered timelapse {}".format(prefix)) def _create_render_start_handler(name, gcode=None): @@ -173,11 +186,11 @@ def _create_render_start_handler(name, gcode=None): def _create_render_success_handler(name, gcode=None): def f(movie): + delete_unrendered_timelapse(name) event_payload = {"gcode": gcode if gcode is not None else "unknown", "movie": movie, "movie_basename": os.path.basename(movie)} eventManager().fire(Events.MOVIE_DONE, event_payload) - delete_unrendered_timelapse(name) return f From 8ce1eafd5da3ef32540d21fb172500b4befe424d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gina=20H=C3=A4u=C3=9Fge?= Date: Thu, 2 Jun 2016 10:11:54 +0200 Subject: [PATCH 2/4] Properly track unrendered timelapses that are being processed UI removes action buttons for them and displays a spinner indicating that the timelapse in question is either being recorded or being rendered at the moment. Should prevent users from accidentally trying to render an incomplete timelapse. --- src/octoprint/templates/tabs/timelapse.jinja2 | 5 +- src/octoprint/timelapse.py | 48 ++++++++++++++----- 2 files changed, 41 insertions(+), 12 deletions(-) diff --git a/src/octoprint/templates/tabs/timelapse.jinja2 b/src/octoprint/templates/tabs/timelapse.jinja2 index cd99de8b..d7e7cf38 100644 --- a/src/octoprint/templates/tabs/timelapse.jinja2 +++ b/src/octoprint/templates/tabs/timelapse.jinja2 @@ -94,7 +94,10 @@ -  |  + + +  |  + diff --git a/src/octoprint/timelapse.py b/src/octoprint/timelapse.py index b72473e1..f4e349d1 100644 --- a/src/octoprint/timelapse.py +++ b/src/octoprint/timelapse.py @@ -47,6 +47,9 @@ _update_callbacks = [] # lock for timelapse cleanup, must be re-entrant _cleanup_lock = threading.RLock() +# lock for timelapse job +_job_lock = threading.RLock() + def _extract_prefix(filename): """ @@ -78,10 +81,14 @@ def get_finished_timelapses(): def get_unrendered_timelapses(): + global _job_lock + global current + delete_old_unrendered_timelapses() basedir = settings().getBaseFolder("timelapse_tmp") jobs = collections.defaultdict(lambda: dict(count=0, size=None, bytes=0, date=None, timestamp=None)) + for osFile in os.listdir(basedir): if not fnmatch.fnmatch(osFile, "*.jpg"): continue @@ -96,13 +103,23 @@ def get_unrendered_timelapses(): if jobs[prefix]["timestamp"] is None or statResult.st_ctime < jobs[prefix]["timestamp"]: jobs[prefix]["timestamp"] = statResult.st_ctime - def finalize_fields(job): - job["size"] = util.get_formatted_size(job["bytes"]) - job["date"] = util.get_formatted_datetime(datetime.datetime.fromtimestamp(job["timestamp"])) - del job["timestamp"] - return job + with _job_lock: + global current_render_job - return sorted([util.dict_merge(dict(name=key), finalize_fields(value)) for key, value in jobs.items()], key=lambda x: x["name"]) + def finalize_fields(prefix, job): + currently_recording = current is not None and current.prefix == prefix + currently_rendering = current_render_job is not None and current_render_job["prefix"] == prefix + + job["size"] = util.get_formatted_size(job["bytes"]) + job["date"] = util.get_formatted_datetime(datetime.datetime.fromtimestamp(job["timestamp"])) + job["recording"] = currently_recording + job["rendering"] = currently_rendering + job["processing"] = currently_recording or currently_rendering + del job["timestamp"] + + return job + + return sorted([util.dict_merge(dict(name=key), finalize_fields(key, value)) for key, value in jobs.items()], key=lambda x: x["name"]) def delete_unrendered_timelapse(name): @@ -175,11 +192,15 @@ def delete_old_unrendered_timelapses(): def _create_render_start_handler(name, gcode=None): def f(movie): - global current_render_job - event_payload = {"gcode": gcode if gcode is not None else "unknown", - "movie": movie, - "movie_basename": os.path.basename(movie)} - current_render_job = event_payload + global _job_lock + + with _job_lock: + global current_render_job + event_payload = {"gcode": gcode if gcode is not None else "unknown", + "movie": movie, + "movie_basename": os.path.basename(movie)} + current_render_job = dict(prefix=name) + current_render_job.update(event_payload) eventManager().fire(Events.MOVIE_RENDERING, event_payload) return f @@ -277,6 +298,7 @@ class Timelapse(object): self._image_number = None self._in_timelapse = False self._gcode_file = None + self._file_prefix = None self._post_roll = post_roll self._on_post_roll_done = None @@ -303,6 +325,10 @@ class Timelapse(object): for (event, callback) in self.event_subscriptions(): eventManager().subscribe(event, callback) + @property + def prefix(self): + return self._file_prefix + @property def post_roll(self): return self._post_roll From 28333726030c99e788480ea334a29ecb5d79e66f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gina=20H=C3=A4u=C3=9Fge?= Date: Thu, 2 Jun 2016 11:11:06 +0200 Subject: [PATCH 3/4] Allow deletion of *.mp4 timelapse files That one was missing in a00faf2. Fixes #1320 --- src/octoprint/server/api/timelapse.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/octoprint/server/api/timelapse.py b/src/octoprint/server/api/timelapse.py index 475d2d2d..5871d774 100644 --- a/src/octoprint/server/api/timelapse.py +++ b/src/octoprint/server/api/timelapse.py @@ -62,7 +62,7 @@ def downloadTimelapse(filename): @api.route("/timelapse/", methods=["DELETE"]) @restricted_access def deleteTimelapse(filename): - if util.is_allowed_file(filename, ["mpg"]): + if util.is_allowed_file(filename, ["mpg", "mpeg", "mp4"]): timelapse_folder = settings().getBaseFolder("timelapse") full_path = os.path.realpath(os.path.join(timelapse_folder, filename)) if full_path.startswith(timelapse_folder) and os.path.exists(full_path): From a0697f8bad25a9a45db2edb79ca8d8f8ebff879f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gina=20H=C3=A4u=C3=9Fge?= Date: Thu, 2 Jun 2016 12:02:03 +0200 Subject: [PATCH 4/4] Use movie prefix for timelapse notifications Also added a missing lock. Also part of the fix for #1320 --- src/octoprint/static/js/app/viewmodels/timelapse.js | 6 +++--- src/octoprint/timelapse.py | 13 +++++++++---- 2 files changed, 12 insertions(+), 7 deletions(-) diff --git a/src/octoprint/static/js/app/viewmodels/timelapse.js b/src/octoprint/static/js/app/viewmodels/timelapse.js index 2098d9d2..8d3ee603 100644 --- a/src/octoprint/static/js/app/viewmodels/timelapse.js +++ b/src/octoprint/static/js/app/viewmodels/timelapse.js @@ -281,13 +281,13 @@ $(function() { self.onEventMovieRendering = function(payload) { self.displayTimelapsePopup({ title: gettext("Rendering timelapse"), - text: _.sprintf(gettext("Now rendering timelapse %(movie_basename)s. Due to performance reasons it is not recommended to start a print job while a movie is still rendering."), payload), + text: _.sprintf(gettext("Now rendering timelapse %(movie_prefix)s. Due to performance reasons it is not recommended to start a print job while a movie is still rendering."), payload), hide: false }); }; self.onEventMovieFailed = function(payload) { - var html = "

" + _.sprintf(gettext("Rendering of timelapse %(movie_basename)s failed with return code %(returncode)s"), payload) + "

"; + var html = "

" + _.sprintf(gettext("Rendering of timelapse %(movie_prefix)s failed with return code %(returncode)s"), payload) + "

"; html += pnotifyAdditionalInfo('
' + payload.error + '
'); self.displayTimelapsePopup({ @@ -301,7 +301,7 @@ $(function() { self.onEventMovieDone = function(payload) { self.displayTimelapsePopup({ title: gettext("Timelapse ready"), - text: _.sprintf(gettext("New timelapse %(movie_basename)s is done rendering."), payload), + text: _.sprintf(gettext("New timelapse %(movie_prefix)s is done rendering."), payload), type: "success", callbacks: { before_close: function(notice) { diff --git a/src/octoprint/timelapse.py b/src/octoprint/timelapse.py index f4e349d1..026a897d 100644 --- a/src/octoprint/timelapse.py +++ b/src/octoprint/timelapse.py @@ -198,7 +198,8 @@ def _create_render_start_handler(name, gcode=None): global current_render_job event_payload = {"gcode": gcode if gcode is not None else "unknown", "movie": movie, - "movie_basename": os.path.basename(movie)} + "movie_basename": os.path.basename(movie), + "movie_prefix": name} current_render_job = dict(prefix=name) current_render_job.update(event_payload) eventManager().fire(Events.MOVIE_RENDERING, event_payload) @@ -210,7 +211,8 @@ def _create_render_success_handler(name, gcode=None): delete_unrendered_timelapse(name) event_payload = {"gcode": gcode if gcode is not None else "unknown", "movie": movie, - "movie_basename": os.path.basename(movie)} + "movie_basename": os.path.basename(movie), + "movie_prefix": name} eventManager().fire(Events.MOVIE_DONE, event_payload) return f @@ -219,7 +221,8 @@ def _create_render_fail_handler(name, gcode=None): def f(movie, returncode=255, stdout="Unknown error", stderr="Unknown error"): event_payload = {"gcode": gcode if gcode is not None else "unknown", "movie": movie, - "movie_basename": os.path.basename(movie)} + "movie_basename": os.path.basename(movie), + "movie_prefix": name} payload = dict(event_payload) payload.update(dict(returncode=returncode, error=stderr)) eventManager().fire(Events.MOVIE_FAILED, payload) @@ -229,7 +232,9 @@ def _create_render_fail_handler(name, gcode=None): def _create_render_always_handler(name, gcode=None): def f(movie): global current_render_job - current_render_job = None + global _job_lock + with _job_lock: + current_render_job = None return f