Failed kill debug

aexpect/client.py

@@ -136,6 +136,8 @@
             self.encoding = encoding
         self.reader_fds = {}
         base_dir = os.path.join(BASE_DIR, f"aexpect_{self.a_id}")
+        self._close_lockfile = os.path.join(BASE_DIR,
+                                            f"aexpect_{self.a_id}.lock")
 
         # Define filenames for communication with server
         utils_path.init_dir(base_dir)
@@ -400,35 +402,63 @@
         """
         return utils_process.process_in_ptree_is_defunct(self.get_pid())
 
-    def kill(self, sig=signal.SIGKILL):
+    def kill(self, sig=signal.SIGKILL, debug=False):
         """
         Kill the child process if alive
         """
         # Kill it if it's alive
         if self.is_alive():
-            utils_process.kill_process_tree(self.get_pid(), sig)
+            utils_process.kill_process_tree(self.get_pid(), sig, debug=debug)
 
     def close(self, sig=signal.SIGKILL):
         """
         Kill the child process if it's alive and remove temporary files.
 
         :param sig: The signal to send the process when attempting to kill it.
         """
-        if not self.closed:
-            self.kill(sig=sig)
-            # Wait for the server to exit
-            wait_for_lock(self.lock_server_running_filename)
-            # Call all cleanup routines
-            for hook in self.close_hooks:
-                hook(self)
-            # Close reader file descriptors
-            self._close_reader_fds()
-            self.reader_fds = {}
-            # Remove all used files
-            if 'AEXPECT_DEBUG' not in os.environ:
-                shutil.rmtree(os.path.join(BASE_DIR, f'aexpect_{self.a_id}'))
-            self._close_aexpect_helper()
-            self.closed = True
+        if self.closed:
+            return
+        lock = None
+        try:
+            try:
+                lock = get_lock_fd(self._close_lockfile, timeout=60)
+            except FileNotFoundError:
+                if not self.closed:
+                    raise
+            if not self.closed:
+                self.kill(sig=sig, debug=True)
+                # Wait for the server to exit
+                if not wait_for_lock(self.lock_server_running_filename,
+                                     timeout=10):
+                    LOG.warning("Failed to get lock, the aexpect_helper "
+                                "process might be left behind. Proceeding "
+                                "anyway...")
+                    LOG.debug("ldoktor: lock failed")
+                    LOG.debug("free:\n%s", utils_process.getoutput("free"))
+                    LOG.debug("ps aux:\n%s", utils_process.getoutput("ps aux"))
+                    LOG.debug("dmesg:\n%s", utils_process.getoutput("dmesg"))
+                    LOG.debug("journalctl:\n%s", utils_process.getoutput("journalctl --no-pager"))
+                # Call all cleanup routines
+                for hook in self.close_hooks:
+                    hook(self)
+                # Close reader file descriptors
+                self._close_reader_fds()
+                self.reader_fds = {}
+                # Remove all used files
+                if 'AEXPECT_DEBUG' not in os.environ:
+                    shutil.rmtree(os.path.join(BASE_DIR,
+                                               f'aexpect_{self.a_id}'),
+                                  ignore_errors=True)
+                self._close_aexpect_helper()
+                self.closed = True
+        finally:
+            if lock is not None:
+                try:
+                    unlock_fd(lock)
+                    os.unlink(self._close_lockfile)
+                except FileNotFoundError:
+                    # File already removed by other thread
+                    pass
 
     def set_linesep(self, linesep):
         """

aexpect/shared.py

@@ -14,23 +14,36 @@
 import os
 import fcntl
 import termios
+import time
 
 BASE_DIR = os.environ.get('TMPDIR', '/tmp')
 
 
-def get_lock_fd(filename):
+def get_lock_fd(filename, timeout=-1):
     """Lock a file"""
     if not os.path.exists(filename):
         with open(filename, "w", encoding="utf-8"):
             pass
+
     lock_fd = os.open(filename, os.O_RDWR)
-    fcntl.lockf(lock_fd, fcntl.LOCK_EX)
+    lock_flags = fcntl.LOCK_EX
+    if timeout > 0:
+        lock_flags |= fcntl.LOCK_NB
+    end_time = time.time() + timeout if timeout > 0 else -1
+    while True:
+        try:
+            fcntl.flock(lock_fd, lock_flags)
+            break
+        except IOError:
+            if time.time() > end_time:
+                os.close(lock_fd)
+                raise
     return lock_fd
 
 
 def unlock_fd(lock_fd):
     """Unlock a file"""
-    fcntl.lockf(lock_fd, fcntl.LOCK_UN)
+    fcntl.flock(lock_fd, fcntl.LOCK_UN)
     os.close(lock_fd)
 
 
@@ -41,19 +54,27 @@
     except OSError:
         return False
     try:
-        fcntl.lockf(lock_fd, fcntl.LOCK_EX | fcntl.LOCK_NB)
+        fcntl.flock(lock_fd, fcntl.LOCK_EX | fcntl.LOCK_NB)
     except IOError:
         os.close(lock_fd)
         return True
-    fcntl.lockf(lock_fd, fcntl.LOCK_UN)
+    fcntl.flock(lock_fd, fcntl.LOCK_UN)
     os.close(lock_fd)
     return False
 
 
-def wait_for_lock(filename):
-    """Wait until lock can be acquired, then release it"""
-    lock_fd = get_lock_fd(filename)
+def wait_for_lock(filename, timeout=-1):
+    """
+    Wait until lock can be acquired, then release it
+
+    :return: True on success, False on failure/timeout
+    """
+    try:
+        lock_fd = get_lock_fd(filename, timeout)
+    except (IOError, FileNotFoundError):
+        return False
     unlock_fd(lock_fd)
+    return True
 
 
 def makeraw(shell_fd):

aexpect/utils/process.py

@@ -14,6 +14,7 @@
 import subprocess
 import signal
 import os
+import time
 
 
 def getoutput(cmd):
@@ -60,7 +61,7 @@ def safe_kill(pid, sig):
         return False
 
 
-def kill_process_tree(pid, sig=signal.SIGKILL):
+def kill_process_tree(pid, sig=signal.SIGKILL, debug=False):
     """
     Signal a process and all of its children.
 
@@ -74,8 +75,20 @@ def kill_process_tree(pid, sig=signal.SIGKILL):
     children = getoutput(f"ps --ppid={int(pid)} -o pid=").split()
     for child in children:
         kill_process_tree(int(child), sig)
-    safe_kill(pid, sig)
+    failed = False
+    if safe_kill(pid, sig) and debug:
+        failed = True
+        print(f"ldoktor: kill failed {pid}")
+        print(f"free:\n{getoutput('free')}")
+        print(f"ps aux:\n{getoutput('ps aux')}")
     safe_kill(pid, signal.SIGCONT)
+    if failed:
+        time.sleep(5)
+        print(f"ldoktor: after SIGCONT {pid}")
+        print(f"free:\n{getoutput('free')}")
+        print(f"ps aux:\n{getoutput('ps aux')}")
+        print(f"dmesg:\n%s{subprocess.getoutput('dmesg')}")
+        print(f"journalctl:\n{subprocess.getoutput('journalctl --no-pager')}")
 
 
 def get_children_pids(ppid):