diff --git a/docs/presentations.md b/docs/presentations.md index c2f1e7d..5ca5b77 100644 --- a/docs/presentations.md +++ b/docs/presentations.md @@ -128,6 +128,60 @@ A file that cannot be converted gets a card saying so, offering only **Remove**. Its managed original remains recoverable even when PDF or page generation fails. +## Memory (0.2.6.2) + +On a 4 GB Plasma VM the kernel killed `ekklesia-classroom-presentations.service` +mid-import and Plasma said *Memory Shortage Avoided*. Measured afterwards, +LibreOffice converting one deck with the importer's own code: + +| Deck | PPTX | LibreOffice peak | Rendering peak | +| --- | --- | --- | --- | +| 10 slides of text | 20 KB | 203 MB, 0.8 s | 38 MB | +| 30 slides, 12 photos shared | 23.5 MB | 738 MB, 16 s | 70 MB | +| 60 slides, the same 12 photos | 23.6 MB | 754 MB, 28 s | 70 MB | +| 30 slides, 30 different 12 MP photos | 58.7 MB | **1.43 GB**, 22 s | 69 MB | +| 20 slides, 20 different 27 MP photos | 143 MB | **2.08 GB**, 24 s | 70 MB | + +It grows with the photographs, not the slides, and it is a spike rather +than a leak. PDF export with images reduced to 200 dpi saved only 5%, +because LibreOffice holds the full images regardless. So the failure was a +photo-heavy deck meeting a 4 GB machine with the room's other programs +open — and what made it a problem was what happened next. systemd's +default `OOMPolicy=stop` took the whole service down with the killed +LibreOffice; it restarted, `sweep()` resumed the same conversion with no +limit, and the library said *Getting this ready…* throughout. + +Now: + +* **`MemoryMax=40%`** — 1.6 GB on a 4 GB machine, 3.2 GB on 8 GB. Measured + in the lab at 1.6 GB, the 2.1 GB deck still imported in 33 s: much of + that peak is file-backed and reclaimable, and on a machine with swap the + rest is swapped rather than killed (1.4 GB of it at a 200 MB ceiling). +* **`OOMScoreAdjust=800`** — under pressure everywhere, LibreOffice goes + before the lesson on the screen, the browser or the panel. +* **`OOMPolicy=continue`** — a killed LibreOffice is a failed import, not a + dead service. Measured with no swap and a 300 MB ceiling: the kernel + killed LibreOffice, the watcher kept its PID with no restart, and the + import was recorded as `failed`, kind `memory`. +* **Two attempts, then stop.** Each attempt is counted before it starts. + Measured by killing the whole service during attempt 1 and again during + attempt 2: it resumed once, then said "giving up … the teacher can try + again" and did not start a third. +* **The card says so**, and offers **Try again**: *This needed more memory + than the computer had free. Close other programs, then choose Try + again.* Try again was pressed in the lab and the deck became ready. + A file that simply will not convert still says *This file could not be + opened* and offers no Try again, because trying again will not help. +* **Never stuck.** An import still "getting ready" 20 minutes after it + began — longer than any attempt can take — is shown as the same Try + again card, because nothing is working on it. +* **One import at a time**, by an exclusive lock as well as the one loop; + measured, three decks downloaded together converted one after another + with never more than one LibreOffice running. + +What the lab cannot give is a real 4 GB machine's mix of programs; the +ceilings were emulated per service. + ## The three things kept apart This is the part most worth not breaking. diff --git a/docs/screenshots/pres-after-retry.png b/docs/screenshots/pres-after-retry.png new file mode 100644 index 0000000..dfbd468 Binary files /dev/null and b/docs/screenshots/pres-after-retry.png differ diff --git a/docs/screenshots/pres-memory-failed.png b/docs/screenshots/pres-memory-failed.png new file mode 100644 index 0000000..f55439e Binary files /dev/null and b/docs/screenshots/pres-memory-failed.png differ diff --git a/lib/classroom_presentations.py b/lib/classroom_presentations.py index 682240e..b73edeb 100644 --- a/lib/classroom_presentations.py +++ b/lib/classroom_presentations.py @@ -288,6 +288,44 @@ class Presentation: def failed(self): return self.state == "failed" + @property + def failure(self): + """Why it failed, as one word a teacher's card can be chosen by. + + "memory": the conversion was killed for want of memory, or was + interrupted too often to keep trying — worth trying again once + other programs are closed. "unreadable": the file itself would not + convert, which trying again will not change. + """ + if self.stalled: + return "memory" + + if not self.failed: + return None + + return self.data.get("error_kind") or "unreadable" + + @property + def stalled(self): + """Still "getting ready" long after any import could have finished. + + The importer's own limits end every attempt within + CONVERT_TIMEOUT + RENDER_TIMEOUT. Past that, with no answer, the + importer is not running at all — and a card that says "Getting + this ready" for ever is the thing a teacher must never be left + looking at. + """ + if self.state not in ("importing", "retry"): + return False + + started = parse_stamp(self.data.get("attempt_started_at") + or self.data.get("imported_at")) + + if started is None: + return False + + return (now() - started).total_seconds() > STALLED_SECONDS + @property def error(self): return self.data.get("error") or "" @@ -458,6 +496,24 @@ def library(root=None): return found +def request_retry(presentation): + """A teacher's Try again: the importer takes it up on its next pass. + + Only a presentation that failed for want of memory, or stalled; a file + that will not convert is not going to convert on the second try. + """ + if presentation.failure != "memory": + return False + + presentation.data["state"] = "retry" + presentation.data["error"] = None + presentation.data["error_kind"] = None + presentation.data["attempts"] = 0 + presentation.data["attempt_started_at"] = stamp() + presentation.save() + return True + + def remove(presentation): """Delete exactly one managed entry, unless it is on screen now.""" try: @@ -642,6 +698,21 @@ PDFTOTEXT = "pdftotext" CONVERT_TIMEOUT = 300 RENDER_TIMEOUT = 600 +# Past this, a presentation still "getting ready" has no importer working +# on it; see Presentation.stalled. +STALLED_SECONDS = CONVERT_TIMEOUT + RENDER_TIMEOUT + 300 + +# What convert_to_pdf and render_pages say when the kernel killed the +# program doing the work. Measured: a deck of 30 different photographs +# takes LibreOffice 1.4 GB for about twenty seconds, 20 larger ones 2.1 GB, +# and the importer's service is capped at 40% of the machine's memory. +KILLED = "killed for want of memory" + + +def killed(returncode): + """Did the kernel end this process? SIGKILL, directly or via a shell.""" + return returncode in (-9, 137) + def _run(command, timeout, **kwargs): import subprocess @@ -704,6 +775,9 @@ def convert_to_pdf(source, destination): shutil.rmtree(profile, ignore_errors=True) shutil.rmtree(workspace, ignore_errors=True) + if killed(result.returncode): + return False, KILLED + return False, (result.stderr or result.stdout or "the file could not be opened").strip() @@ -775,6 +849,9 @@ def render_pages(pdf, directory, width=SLIDE_WIDTH, progress=None): time.sleep(0.4) if process.returncode != 0: + if killed(process.returncode): + return 0, KILLED + return 0, (process.stderr.read() if process.stderr else "the slides could not be rendered") diff --git a/scripts/classroom-presentation-import b/scripts/classroom-presentation-import index a0e1c6b..7a33a05 100755 --- a/scripts/classroom-presentation-import +++ b/scripts/classroom-presentation-import @@ -158,11 +158,29 @@ def forget_presentation(presentation_id, root): library.write_json(library.ledger_path(root), data) +class NeedsMemory(RuntimeError): + """The kernel killed the converter or renderer for want of memory.""" + + +# An import the service was killed in the middle of is resumed at the next +# start — once. Measured in the lab: a deck that needs more memory than +# the machine has free is killed again every time, and with no limit the +# service converted, died and restarted in a loop while the library said +# "Getting this ready…" for ever. +MAX_ATTEMPTS = 2 + + def prepare(presentation): """Build the derived PDF, pages and cover from a managed original.""" data = presentation.data managed = presentation.managed_copy + # Counted and written BEFORE the work, so that a kill in the middle of + # it is still counted when the service comes back. + data["attempts"] = int(data.get("attempts") or 0) + 1 + data["attempt_started_at"] = library.stamp() + presentation.save() + if managed is None or not managed.is_file(): raise RuntimeError("the managed original is missing") @@ -189,12 +207,18 @@ def prepare(presentation): managed, presentation.slides) if not converted: + if error == library.KILLED: + raise NeedsMemory(error) + raise RuntimeError(error or "the file could not be converted") pages, error = library.render_pages( presentation.slides, presentation.pages_directory) if not pages: + if error == library.KILLED: + raise NeedsMemory(error) + raise RuntimeError(error or "the slides could not be rendered") data["pages"] = pages @@ -211,6 +235,7 @@ def prepare(presentation): data["state"] = "ready" data["error"] = None + data["error_kind"] = None presentation.save() say(f"imported {data['title']!r} ({pages} slides)") @@ -278,15 +303,55 @@ def import_one(source, root=None): # teacher can remove it, and a technician can recover or inspect it; # no successfully downloaded file is lost because a derived asset # could not be made. - data["state"] = "failed" - data["error"] = str(error)[:300] - presentation.save() - + fail(presentation, error) say(f"could not import {source.name}: {error}") return presentation +def fail(presentation, error, kind=None): + """Record a failure a teacher's card can say something useful about.""" + presentation.data["state"] = "failed" + presentation.data["error"] = str(error)[:300] + presentation.data["error_kind"] = kind or ( + "memory" if isinstance(error, NeedsMemory) else "unreadable") + presentation.save() + + +def attempt(presentation): + """prepare(), with any failure recorded rather than raised.""" + try: + prepare(presentation) + except Exception as error: # noqa: BLE001 + fail(presentation, error) + say(f"could not import {presentation.title!r}: {error}") + + +def retry_requested(root=None): + """Presentations a teacher pressed Try again on, taken up now.""" + root = root if root is not None else library.library_root() + retried = 0 + + if not root.is_dir(): + return 0 + + for presentation in library.library(root): + if presentation.state != "retry": + continue + + managed = presentation.managed_copy + + if managed is None or not managed.is_file(): + fail(presentation, RuntimeError("the managed original is missing"), "unreadable") + continue + + say(f"trying again: {presentation.title!r}") + attempt(presentation) + retried += 1 + + return retried + + def sweep(root=None): """Recover imports interrupted during a move, conversion or rendering. @@ -313,14 +378,17 @@ def sweep(root=None): if (managed is not None and managed.is_file() and (source is None or not source.exists())): - say(f"resuming an interrupted import: {presentation.title!r}") - try: - prepare(presentation) - except Exception as error: # noqa: BLE001 - presentation.data["state"] = "failed" - presentation.data["error"] = str(error)[:300] - presentation.save() - say(f"could not import {presentation.title!r}: {error}") + attempts = int(presentation.data.get("attempts") or 0) + + if attempts >= MAX_ATTEMPTS: + # Killed in the middle of it every time it was tried. + say(f"giving up on {presentation.title!r} after {attempts} " + "interrupted attempts; the teacher can try again") + fail(presentation, NeedsMemory("interrupted every attempt")) + else: + say(f"resuming an interrupted import: {presentation.title!r}") + attempt(presentation) + stale += 1 continue @@ -414,6 +482,23 @@ def status(root=None): return 0 +def hold_lock(root=None): + """The importer's lock, held for as long as this process lives.""" + import fcntl + + root = root if root is not None else library.library_root() + root.mkdir(parents=True, exist_ok=True) + handle = open(root / ".importer.lock", "a") + + try: + fcntl.flock(handle, fcntl.LOCK_EX | fcntl.LOCK_NB) + except OSError: + handle.close() + return None + + return handle + + def main(): parser = argparse.ArgumentParser( description="Bring finished downloads into the Presentations library.") @@ -439,7 +524,17 @@ def main(): say(f"removed {removed} expired presentation(s)") return 0 + # One importer at a time, whoever started it. Conversions are the + # memory the machine runs short of, so two at once — the service and a + # technician's --once, say — must not happen. + held = hold_lock() + + if held is None: + say("another importer is already running; not starting a second") + return 0 + sweep() + retry_requested() if arguments.once: imported = scan() @@ -453,6 +548,7 @@ def main(): while True: try: + retry_requested() scan() if time.monotonic() - last_cleanup > CLEANUP_SECONDS: diff --git a/scripts/classroom-presentations b/scripts/classroom-presentations index d428682..c4d90b3 100755 --- a/scripts/classroom-presentations +++ b/scripts/classroom-presentations @@ -682,11 +682,11 @@ class Library(Gtk.Window): would make the buttons unclickable. """ return tuple( - (p.id, p.state, p.pages, p.thumbnail_page, p.title) + (p.id, p.state, p.pages, p.thumbnail_page, p.title, p.failure) for p in presentations ) - def _fit_window(self, count): + def _fit_window(self, count, tall=False): """Size to the cards while staying inside the panel's work area.""" workarea = monitor_workarea(self) maximum_width = max(420, int(workarea.width * 0.92)) @@ -705,7 +705,10 @@ class Library(Gtk.Window): columns = min(count, available, 4) rows = (count + columns - 1) // columns width = min(maximum_width, max(420, 40 + columns * card_with_gap)) - height = min(maximum_height, 130 + rows * 340) + # A card explaining a memory failure carries three lines of + # words above its buttons, not one; measured, at 340 its Try + # again was cut off below the window's edge. + height = min(maximum_height, 130 + rows * (400 if tall else 340)) self.resize(width, height) @@ -735,14 +738,19 @@ class Library(Gtk.Window): # something is "being prepared" when it never will be is how # somebody ends up waiting through a Bible study for it. ready = sum(1 for p in presentations if p.ready) - broken = sum(1 for p in presentations if p.failed) - working = len(presentations) - ready - broken + again = sum(1 for p in presentations if p.failure == "memory") + broken = sum(1 for p in presentations + if p.failed and p.failure != "memory") + working = len(presentations) - ready - broken - again parts = [f"{ready} ready to present"] if working: parts.append(f"{working} still being prepared") + if again: + parts.append(f"{again} to try again") + if broken: parts.append(f"{broken} could not be opened") @@ -752,7 +760,8 @@ class Library(Gtk.Window): self.grid.add(self.card(presentation)) self.grid.show_all() - self._fit_window(len(presentations)) + self._fit_window(len(presentations), + tall=any(p.failure == "memory" for p in presentations)) def card(self, presentation): box = Gtk.Box(orientation=Gtk.Orientation.VERTICAL, spacing=10) @@ -802,6 +811,20 @@ class Library(Gtk.Window): look = Gtk.Button(label="Quick Look") look.connect("clicked", lambda *_: self.quick_look(presentation)) buttons.pack_start(look, True, True, 0) + elif presentation.failure == "memory": + # The computer ran short of memory getting it ready, or the + # importer stopped part way. Worth another go with less open; + # never a converter's message, a path or a terminal. + note.set_text("This needed more memory than the computer had " + "free. Close other programs, then choose " + "Try again.") + note.set_line_wrap(True) + note.set_max_width_chars(34) + + again = Gtk.Button(label="Try again") + again.get_style_context().add_class("primary") + again.connect("clicked", lambda *_: self.try_again(presentation)) + buttons.pack_start(again, True, True, 0) elif presentation.failed: # SHORT, AND IN WORDS A TEACHER CAN ACT ON. # @@ -878,6 +901,12 @@ class Library(Gtk.Window): self._signature = None self.refresh() + def try_again(self, presentation): + # The importer takes it up within a few seconds; the card says + # "Getting this ready" again at the next refresh. + if library.request_retry(presentation): + self.refresh() + def remove(self, presentation): dialog = Gtk.MessageDialog( transient_for=self, diff --git a/systemd/user/ekklesia-classroom-presentations.service b/systemd/user/ekklesia-classroom-presentations.service index f1b10b6..8bcd35c 100644 --- a/systemd/user/ekklesia-classroom-presentations.service +++ b/systemd/user/ekklesia-classroom-presentations.service @@ -24,5 +24,26 @@ Slice=session.slice Nice=10 IOSchedulingClass=idle +# MEMORY. Measured in the lab, LibreOffice converting one deck: 203 MB +# for ten slides of text, 738 MB for thirty slides sharing twelve photos, +# 1.4 GB for thirty different photos and 2.1 GB for twenty very large +# ones, for twenty seconds or so. A 4 GB classroom running Plasma and +# Wonder Ink does not have 2 GB spare, and in testing the kernel killed +# the whole service mid-conversion — which then restarted and tried the +# same deck again, while the library said "Getting this ready" for ever. +# +# At most 40% of this machine's memory: 1.6 GB on 4 GB, 3.2 GB on 8 GB. +# A deck that needs more is stopped HERE, inside this service, rather +# than pushing the teacher's own windows out of memory. +MemoryMax=40% +# If memory runs short everywhere, this is what goes first: never the +# lesson on the screen, the browser or the panel. +OOMScoreAdjust=800 +# And a killed LibreOffice is a failed import, not a dead service. The +# watcher records it — "needed more memory", with Try again — and carries +# on. systemd's default stops the whole unit when any one process in it +# is killed for memory. +OOMPolicy=continue + [Install] WantedBy=plasma-workspace.target diff --git a/tests/test-classroom-presentations.sh b/tests/test-classroom-presentations.sh index eacf887..1339ba1 100755 --- a/tests/test-classroom-presentations.sh +++ b/tests/test-classroom-presentations.sh @@ -422,6 +422,105 @@ check("normal title bars contain only Close", check("the unfinished Help launcher is absent from the panel", "ekklesia-manual.desktop" not in layout) +print("17. running out of memory is a state a teacher can act on, never a loop") +library.render_pages = fake_render_pages +library.render_thumbnail = fake_render_thumbnail +library.first_text = lambda _pdf, pages=2: "" +# The kernel killing LibreOffice: SIGKILL directly, or 137 through the +# soffice shell wrapper. +check("a SIGKILL is recognised either way", + library.killed(-9) and library.killed(137) + and not library.killed(1) and not library.killed(0)) + +library.convert_to_pdf = lambda _source, _destination: (False, library.KILLED) +heavy = download("Heavy deck.pptx", contents="photographs") +starved = importer.import_one(heavy, shelf) +check("a conversion killed for memory is a failed import", + starved is not None and starved.failed, starved.data if starved else None) +check("of the kind a teacher can try again", + starved.failure == "memory" and starved.data["error_kind"] == "memory") +check("and the downloaded original is kept", + starved.managed_copy.read_text() == "photographs") +check("the attempt was counted before the work began", + starved.data.get("attempts") == 1 and starved.data.get("attempt_started_at")) +check("a file that simply will not convert is a different failure", + failed_import.failure == "unreadable") +check("and cannot be tried again", not library.request_retry(failed_import)) + +# A service killed in the middle of an import, found by the next start. +library.convert_to_pdf = original_convert + + +def interrupted(name, attempts): + directory = shelf / name + (directory / "original").mkdir(parents=True) + (directory / "original" / f"{name}.pdf").write_text("%PDF-1.4 " + name) + library.Presentation(directory, { + "id": name, "state": "importing", "title": name, + "original_name": f"{name}.pdf", "source_path": str(downloads / f"{name}.pdf"), + "managed_copy": f"original/{name}.pdf", "format": "pdf", + "imported_at": library.stamp(), "last_presented_at": None, + "times_presented": 0, "thumbnail_page": 1, "pages": 0, "error": None, + "attempts": attempts, + }).save() + return directory + + +once = interrupted("once", 1) +twice = interrupted("twice", 2) +importer.sweep(shelf) +check("an import interrupted once is resumed", + library.load(once).ready) +gave_up = library.load(twice) +check("an import interrupted twice is not tried a third time", + gave_up.failed and gave_up.failure == "memory", gave_up.data) +check("and its original is still there to try again from", + (twice / "original" / "twice.pdf").exists()) + +check("Try again puts it back in the importer's hands", + library.request_retry(gave_up) and library.load(twice).state == "retry") +check("which counts afresh", library.load(twice).data.get("attempts") == 0) +check("and the importer takes it up on its next pass", + importer.retry_requested(shelf) == 1 and library.load(twice).ready) + +# The importer not running at all: nothing will ever finish this one. +stuck = interrupted("stuck", 0) +entry_data = library.load(stuck).data +long_ago = library.now() - timedelta(seconds=library.STALLED_SECONDS + 60) +entry_data["attempt_started_at"] = library.stamp(long_ago) +library.Presentation(stuck, entry_data).save() +stuck_card = library.load(stuck) +check("an import nobody is working on stops saying Getting this ready", + stuck_card.stalled and stuck_card.failure == "memory") +check("and offers Try again", library.request_retry(stuck_card)) +check("a fresh import is not mistaken for a stalled one", + not library.load(once).stalled and library.load(once).failure is None) + +held = importer.hold_lock(shelf) +check("one importer holds the lock", held is not None) +check("a second importer is refused rather than run beside it", + importer.hold_lock(shelf) is None) +held.close() +check("and it is free again once the first has gone", + importer.hold_lock(shelf) is not None) +check("the lock file is not a presentation", + all(p.id != ".importer.lock" for p in library.library(shelf))) + +unit = (root / "systemd" / "user" / "ekklesia-classroom-presentations.service").read_text() +check("the service may use at most 40% of the machine's memory", + "MemoryMax=40%" in unit) +check("a killed converter does not take the watcher with it", + "OOMPolicy=continue" in unit) +check("and under pressure it goes before the teacher's windows", + "OOMScoreAdjust=800" in unit) +check("the card says what to do, in a teacher's words", + "Close other programs, then choose" in ui and 'label="Try again"' in ui) + +library.render_pages = original_render_pages +library.render_thumbnail = original_render_thumbnail +library.first_text = original_first_text +library.convert_to_pdf = original_convert + shutil.rmtree(work, ignore_errors=True) print()