diff --git a/swh/loader/mercurial/hgutil.py b/swh/loader/mercurial/hgutil.py --- a/swh/loader/mercurial/hgutil.py +++ b/swh/loader/mercurial/hgutil.py @@ -2,6 +2,7 @@ # See the AUTHORS file at the top-level directory of this distribution # License: GNU General Public License version 3, or any later version # See top-level LICENSE file for more information + from collections import defaultdict from dataclasses import dataclass import io @@ -17,6 +18,8 @@ from mercurial import bookmarks, context, error, hg, smartset, util # type: ignore import mercurial.ui # type: ignore +from swh.scheduler.utils import utcnow + NULLID = mercurial.node.nullid HgNodeId = NewType("HgNodeId", bytes) Repository = hg.localrepo @@ -125,6 +128,7 @@ errors: message queue to communicate errors """ try: + print(f"{utcnow()} clone start") hg.clone( ui=mercurial.ui.ui.load(), peeropts={}, @@ -132,10 +136,12 @@ dest=dest.encode(), update=False, ) + print(f"{utcnow()} clone end") except Exception as e: exc_buffer = io.StringIO() traceback.print_exc(file=exc_buffer) errors.put_nowait(exc_buffer.getvalue()) + print(f"{utcnow()} clone raise") raise e @@ -147,23 +153,31 @@ dest: clone destination timeout: timeout in seconds """ + print(f"{utcnow()} start") errors: Queue = Queue() process = Process(target=_clone_task, args=(src, dest, errors)) + print(f"{utcnow()} start") process.start() process.join(timeout) + print(f"{utcnow()} joined") if process.is_alive(): + print(f"{utcnow()} process still alive") process.terminate() - # Give it a second (literally), then kill it + # Give it literally a second (in successive steps of 0.1 second), then kill it. # Can't use `process.join(1)` here, billiard appears to be bugged # https://github.com/celery/billiard/issues/270 killed = False + step = 0.1 for _ in range(10): - time.sleep(0.1) + print(f"{utcnow()} sleep {step} second") + time.sleep(step) if not process.is_alive(): + print(f"{utcnow()} process not alive, break") break else: killed = True + print(f"{utcnow()} process {process.pid} to stop: killed=={killed}") os.kill(process.pid, signal.SIGKILL) raise CloneTimeout(src, timeout, killed) diff --git a/swh/loader/mercurial/tests/test_hgutil.py b/swh/loader/mercurial/tests/test_hgutil.py --- a/swh/loader/mercurial/tests/test_hgutil.py +++ b/swh/loader/mercurial/tests/test_hgutil.py @@ -9,6 +9,8 @@ from mercurial import hg # type: ignore import pytest +from swh.scheduler.utils import utcnow + from .. import hgutil @@ -16,11 +18,15 @@ src = "https://www.mercurial-scm.org/repo/hello" dest = "/dev/null" timeout = 0.1 + sleepy_time = 10 * timeout + assert sleepy_time > timeout - def clone(*args, **kwargs): + def clone(*args, sleepy_time=sleepy_time, **kwargs): # ignore SIGTERM to force sigkill signal.signal(signal.SIGTERM, lambda signum, frame: None) - time.sleep(2) + print(f"(false clone) {utcnow()} Sleep for {sleepy_time} seconds.") + time.sleep(sleepy_time) # we make sure we exceed the timeout + print(f"(false clone) {utcnow()} Slept but this should never get printed!") monkeypatch.setattr(hg, "clone", clone)