Expanded debug log

scripts/wk/exe.py

@@ -1,12 +1,17 @@
 """WizardKit: Executable functions"""
 #vim: sts=2 sw=2 ts=2
 
+import logging
 import re
 import subprocess
 
 import psutil
 
 
+# STATIC VARIABLES
+LOG = logging.getLogger(__name__)
+
+
 # Functions
 def build_cmd_kwargs(cmd, minimized=False, pipe=True, shell=False, **kwargs):
   """Build kwargs for use by subprocess functions, returns dict.
@@ -14,6 +19,11 @@ def build_cmd_kwargs(cmd, minimized=False, pipe=True, shell=False, **kwargs):
   Specifically subprocess.run() and subprocess.Popen().
   NOTE: If no encoding specified then UTF-8 will be used.
   """
+  LOG.debug(
+    'cmd: %s, minimized: %s, pipe: %s, shell: %s',
+    cmd, minimized, pipe, shell,
+    )
+  LOG.debug('kwargs: %s', kwargs)
   cmd_kwargs = {
     'args': cmd,
     'shell': shell,
@@ -43,11 +53,13 @@ def build_cmd_kwargs(cmd, minimized=False, pipe=True, shell=False, **kwargs):
     cmd_kwargs['stdout'] = subprocess.PIPE
 
   # Done
+  LOG.debug('cmd_kwargs: %s', cmd_kwargs)
   return cmd_kwargs
 
 
 def get_procs(name, exact=True):
   """Get process object(s) based on name, returns list of proc objects."""
+  LOG.debug('name: %s, exact: %s', name, exact)
   processes = []
   regex = f'^{name}$' if exact else name
 
@@ -69,6 +81,10 @@ def kill_procs(name, exact=True, force=False, timeout=30):
   If force is True then it will wait until timeout specified and then
   send SIGKILL to any processes still alive.
   """
+  LOG.debug(
+    'name: %s, exact: %s, force: %s, timeout: %s',
+    name, exact, force, timeout,
+    )
   target_procs = get_procs(name, exact=exact)
   for proc in target_procs:
     proc.terminate()
@@ -80,8 +96,13 @@ def kill_procs(name, exact=True, force=False, timeout=30):
       proc.kill()
 
 
-def popen_program(cmd, pipe=False, minimized=False, shell=False, **kwargs):
+def popen_program(cmd, minimized=False, pipe=False, shell=False, **kwargs):
   """Run program and return a subprocess.Popen object."""
+  LOG.debug(
+    'cmd: %s, minimized: %s, pipe: %s, shell: %s',
+    cmd, minimized, pipe, shell,
+    )
+  LOG.debug('kwargs: %s', kwargs)
   cmd_kwargs = build_cmd_kwargs(
     cmd,
     minimized=minimized,
@@ -95,6 +116,11 @@ def popen_program(cmd, pipe=False, minimized=False, shell=False, **kwargs):
 
 def run_program(cmd, check=True, pipe=True, shell=False, **kwargs):
   """Run program and return a subprocess.CompletedProcess object."""
+  LOG.debug(
+    'cmd: %s, check: %s, pipe: %s, shell: %s',
+    cmd, check, pipe, shell,
+    )
+  LOG.debug('kwargs: %s', kwargs)
   cmd_kwargs = build_cmd_kwargs(
     cmd,
     check=check,
@@ -108,6 +134,7 @@ def run_program(cmd, check=True, pipe=True, shell=False, **kwargs):
 
 def wait_for_procs(name, exact=True, timeout=None):
   """Wait for all process matching name."""
+  LOG.debug('name: %s, exact: %s, timeout: %s', name, exact, timeout)
   target_procs = get_procs(name, exact=exact)
   results = psutil.wait_procs(target_procs, timeout=timeout)
 

scripts/wk/io.py

@@ -1,15 +1,20 @@
 """WizardKit: I/O Functions"""
 # vim: sts=2 sw=2 ts=2
 
+import logging
 import os
+import pathlib
 import shutil
 
-import pathlib
 
+# STATIC VARIABLES
+LOG = logging.getLogger(__name__)
 
 # Functions
 def delete_empty_folders(path):
   """Recursively delete all empty folders in path."""
+  LOG.debug('path: %s', path)
+
   # Delete empty subfolders first
   for item in os.scandir(path):
     if item.is_dir():
@@ -29,6 +34,11 @@ def delete_folder(path, force=False, ignore_errors=False):
   NOTE: Exceptions are not caught by this function,
         ignore_errors is passed to shutil.rmtree to allow partial deletions.
   """
+  LOG.debug(
+    'path: %s, force: %s, ignore_errors: %s',
+    path, force, ignore_errors,
+    )
+
   if force:
     shutil.rmtree(path, ignore_errors=ignore_errors)
   else:
@@ -41,6 +51,11 @@ def delete_item(path, force=False, ignore_errors=False):
   NOTE: Exceptions are not caught by this function,
         ignore_errors is passed to delete_folder to allow partial deletions.
   """
+  LOG.debug(
+    'path: %s, force: %s, ignore_errors: %s',
+    path, force, ignore_errors,
+    )
+
   path = pathlib.Path(path)
   if path.is_dir():
     delete_folder(path, force=force, ignore_errors=ignore_errors)
@@ -50,6 +65,7 @@ def delete_item(path, force=False, ignore_errors=False):
 
 def non_clobbering_path(path):
   """Update path as needed to non-existing path, returns pathlib.Path."""
+  LOG.debug('path: %s', path)
   path = pathlib.Path(path)
   name = path.name
   new_path = None
@@ -71,6 +87,7 @@ def non_clobbering_path(path):
     raise FileExistsError(new_path)
 
   # Done
+  LOG.debug('new path: %s', new_path)
   return new_path
 
 

scripts/wk/os/win.py

@@ -12,6 +12,7 @@ from wk.exe import run_program
 from wk.io import non_clobber_path
 from wk.std import GenericError, GenericWarning
 
+
 # STATIC VARIABLES
 LOG = logging.getLogger(__name__)
 REG_MSISERVER = r'HKLM\SYSTEM\CurrentControlSet\Control\SafeBoot\Network\MSIServer'

scripts/wk/std.py

@@ -868,6 +868,7 @@ def print_warning(msg, log=True, **kwargs):
 
 def set_title(title):
   """Set window title."""
+  LOG.debug('title: %s', title)
   if os.name == 'nt':
     os.system(f'title {title}')
   else: