From edcaa94ca86d29c1ea106eddac837f4a699379ba Mon Sep 17 00:00:00 2001 From: Gavin Mak Date: Thu, 27 Apr 2023 05:58:57 +0000 Subject: [PATCH] sync: Display total elapsed fetch time Give users an indication that `repo sync` isn't stuck if taking a long time to fetch. Bug: https://crbug.com/gerrit/11293 Change-Id: Iccdaec918f86c9cc2db5dc12f9e3eef7ad0bcbda Reviewed-on: https://gerrit-review.googlesource.com/c/git-repo/+/371414 Tested-by: Gavin Mak Reviewed-by: Josip Sokcevic Reviewed-by: Joanna Wang Commit-Queue: Gavin Mak --- progress.py | 72 +++++++++++++++++++++++++++++++++++++++++++------ subcmds/sync.py | 8 +++++- 2 files changed, 71 insertions(+), 9 deletions(-) diff --git a/progress.py b/progress.py index d1a7c543..4844eb88 100644 --- a/progress.py +++ b/progress.py @@ -14,7 +14,13 @@ import os import sys -from time import time +import time + +try: + import threading as _threading +except ImportError: + import dummy_threading as _threading + from repo_trace import IsTraceToStderr _NOT_TTY = not os.isatty(2) @@ -30,14 +36,20 @@ CSI_ERASE_LINE = "\x1b[2K" CSI_ERASE_LINE_AFTER = "\x1b[K" +def convert_to_hms(total): + """Converts a period of seconds to hours, minutes, and seconds.""" + hours, rem = divmod(total, 3600) + mins, secs = divmod(rem, 60) + return int(hours), int(mins), secs + + def duration_str(total): """A less noisy timedelta.__str__. The default timedelta stringification contains a lot of leading zeros and uses microsecond resolution. This makes for noisy output. """ - hours, rem = divmod(total, 3600) - mins, secs = divmod(rem, 60) + hours, mins, secs = convert_to_hms(total) ret = "%.3fs" % (secs,) if mins: ret = "%im%s" % (mins, ret) @@ -46,6 +58,24 @@ def duration_str(total): return ret +def elapsed_str(total): + """Returns seconds in the format [H:]MM:SS. + + Does not display a leading zero for minutes if under 10 minutes. This should + be used when displaying elapsed time in a progress indicator. + """ + hours, mins, secs = convert_to_hms(total) + ret = f"{int(secs):>02d}" + if total >= 3600: + # Show leading zeroes if over an hour. + ret = f"{mins:>02d}:{ret}" + else: + ret = f"{mins}:{ret}" + if hours: + ret = f"{hours}:{ret}" + return ret + + class Progress(object): def __init__( self, @@ -55,11 +85,12 @@ class Progress(object): print_newline=False, delay=True, quiet=False, + show_elapsed=False, ): self._title = title self._total = total self._done = 0 - self._start = time() + self._start = time.time() self._show = not delay self._units = units self._print_newline = print_newline @@ -67,12 +98,30 @@ class Progress(object): self._show_jobs = False self._active = 0 + # Save the last message for displaying on refresh. + self._last_msg = None + self._show_elapsed = show_elapsed + self._update_event = _threading.Event() + self._update_thread = _threading.Thread( + target=self._update_loop, + ) + self._update_thread.daemon = True + # When quiet, never show any output. It's a bit hacky, but reusing the # existing logic that delays initial output keeps the rest of the class # clean. Basically we set the start time to years in the future. if quiet: self._show = False self._start += 2**32 + elif show_elapsed: + self._update_thread.start() + + def _update_loop(self): + while True: + if self._update_event.is_set(): + return + self.update(inc=0, msg=self._last_msg) + time.sleep(1) def start(self, name): self._active += 1 @@ -86,12 +135,14 @@ class Progress(object): def update(self, inc=1, msg=""): self._done += inc + self._last_msg = msg if _NOT_TTY or IsTraceToStderr(): return + elapsed_sec = time.time() - self._start if not self._show: - if 0.5 <= time() - self._start: + if 0.5 <= elapsed_sec: self._show = True else: return @@ -110,8 +161,12 @@ class Progress(object): ) else: jobs = "" + if self._show_elapsed: + elapsed = f" {elapsed_str(elapsed_sec)} |" + else: + elapsed = "" sys.stderr.write( - "\r%s: %2d%% %s(%d%s/%d%s)%s%s%s%s" + "\r%s: %2d%% %s(%d%s/%d%s)%s %s%s%s" % ( self._title, p, @@ -120,7 +175,7 @@ class Progress(object): self._units, self._total, self._units, - " " if msg else "", + elapsed, msg, CSI_ERASE_LINE_AFTER, "\n" if self._print_newline else "", @@ -129,10 +184,11 @@ class Progress(object): sys.stderr.flush() def end(self): + self._update_event.set() if _NOT_TTY or IsTraceToStderr() or not self._show: return - duration = duration_str(time() - self._start) + duration = duration_str(time.time() - self._start) if self._total <= 0: sys.stderr.write( "\r%s: %d, done in %s%s\n" diff --git a/subcmds/sync.py b/subcmds/sync.py index eabaa68b..324f15b5 100644 --- a/subcmds/sync.py +++ b/subcmds/sync.py @@ -675,7 +675,13 @@ later is required to fix a server side protocol bug. jobs = opt.jobs_network fetched = set() remote_fetched = set() - pm = Progress("Fetching", len(projects), delay=False, quiet=opt.quiet) + pm = Progress( + "Fetching", + len(projects), + delay=False, + quiet=opt.quiet, + show_elapsed=True, + ) objdir_project_map = dict() for project in projects: