vm-manager: Added log console printing on vm start. Added python logging module

pkgs/clan-cli/clan_cli/__init__.py

@@ -117,10 +117,10 @@ def main() -> None:
         parser.print_help()
 
     if args.debug:
-        setup_logging(logging.DEBUG)
+        setup_logging(logging.DEBUG, root_log_name=__name__.split(".")[0])
         log.debug("Debug log activated")
     else:
-        setup_logging(logging.INFO)
+        setup_logging(logging.INFO, root_log_name=__name__.split(".")[0])
 
     if not hasattr(args, "func"):
         return

pkgs/clan-cli/clan_cli/custom_logger.py

@@ -66,9 +66,9 @@ def get_caller() -> str:
     return ret
 
 
-def setup_logging(level: Any) -> None:
+def setup_logging(level: Any, root_log_name: str = __name__.split(".")[0]) -> None:
     # Get the root logger and set its level
-    main_logger = logging.getLogger("clan_cli")
+    main_logger = logging.getLogger(root_log_name)
     main_logger.setLevel(level)
 
     # Create and add the default handler

pkgs/clan-cli/clan_cli/machines/machines.py

@@ -102,7 +102,6 @@ class Machine:
         system = config["system"]
 
         attr = f'clanInternals.machines."{system}".{self.name}.{attr}'
-        print(f"attr: {attr}")
 
         if attr in self.eval_cache and not refresh:
             return self.eval_cache[attr]
@@ -115,9 +114,8 @@ class Machine:
         else:
             flake = self.flake
 
-        print(f"evaluating {flake}#{attr}")
         cmd = nix_eval([f"{flake}#{attr}"])
-        print(f"cmd: {cmd}")
+
         output = run(cmd).stdout.strip()
         self.eval_cache[attr] = output
         return output

pkgs/clan-vm-manager/clan_vm_manager/__init__.py

@@ -1,15 +1,21 @@
 import argparse
+import logging
 
 from clan_cli.clan_uri import ClanURI
+from clan_cli.custom_logger import setup_logging
 
 from clan_vm_manager.models.interfaces import ClanConfig
 
 from .app import MainApplication
 
+log = logging.getLogger(__name__)
+
 
 def main() -> None:
     parser = argparse.ArgumentParser(description="clan-vm-manager")
 
+    parser.add_argument("--debug", action="store_true", help="enable debug mode")
+
     # Add join subcommand
     subparser = parser.add_subparsers(
         title="command",
@@ -23,6 +29,15 @@ def main() -> None:
     # Executed when no command is given
     parser.set_defaults(func=show_overview)
     args = parser.parse_args()
+
+    if args.debug:
+        setup_logging("DEBUG", root_log_name=__name__.split(".")[0])
+    else:
+        setup_logging("INFO", root_log_name=__name__.split(".")[0])
+
+    log.debug("Debug logging enabled")
+    log.info("Info logging enabled")
+
     args.func(args)
 
 

pkgs/clan-vm-manager/clan_vm_manager/errors/show_error.py

@@ -1,5 +1,6 @@
 #!/usr/bin/env python3
 
+import logging
 from typing import Literal
 
 import gi
@@ -11,10 +12,12 @@ from gi.repository import Adw
 
 Severity = Literal["Error"] | Literal["Warning"] | Literal["Info"] | str
 
+log = logging.getLogger(__name__)
+
 
 def show_error_dialog(error: ClanError, severity: Severity | None = "Error") -> None:
     message = str(error)
     dialog = Adw.MessageDialog(parent=None, heading=severity, body=message)
-    print("error:", message)
+    log.error(message)
     dialog.add_response("ok", "ok")
     dialog.choose()

pkgs/clan-vm-manager/clan_vm_manager/models/executor.py

@@ -1,3 +1,4 @@
+import logging
 import os
 import signal
 import sys
@@ -14,6 +15,8 @@ import dataclasses
 import multiprocessing as mp
 from collections.abc import Callable
 
+log = logging.getLogger(__name__)
+
 
 # Kill the new process and all its children by sending a SIGTERM signal to the process group
 def _kill_group(proc: mp.Process) -> None:
@@ -21,7 +24,7 @@ def _kill_group(proc: mp.Process) -> None:
     if proc.is_alive() and pid:
         os.killpg(pid, signal.SIGTERM)
     else:
-        print(f"Process {proc.name} with pid {pid} is already dead", file=sys.stderr)
+        log.warning(f"Process {proc.name} with pid {pid} is already dead")
 
 
 @dataclasses.dataclass(frozen=True)
@@ -127,7 +130,7 @@ def spawn(
 
     # Print some information
     cmd = f"tail -f {out_file}"
-    print(f"Connect to stdout with: {cmd}")
+    log.info(f"Connect to stdout with: {cmd}")
 
     # Return the process
     mp_proc = MPProcess(name=proc_name, proc=proc, out_file=out_file)

pkgs/clan-vm-manager/clan_vm_manager/models/use_join.py

@@ -1,3 +1,4 @@
+import logging
 from collections.abc import Callable
 from typing import Any
 
@@ -12,6 +13,8 @@ gi.require_version("Gtk", "4.0")
 gi.require_version("Adw", "1")
 from gi.repository import Gio, GObject
 
+log = logging.getLogger(__name__)
+
 
 class JoinValue(GObject.Object):
     # TODO: custom signals for async join
@@ -56,7 +59,7 @@ class Join:
         # TODO: remove the item that was accepted join from this list
         # and call the success function. (The caller is responsible for handling the success)
         try:
-            print(f"trying to join: {item.url}")
+            log.info(f"trying to join: {item.url}")
 
             history = add_history(item.url)
             cb(history)

pkgs/clan-vm-manager/clan_vm_manager/models/use_vms.py

@@ -1,8 +1,8 @@
+import os
 import tempfile
 import weakref
-from collections.abc import Generator
 from pathlib import Path
-from typing import Any, ClassVar
+from typing import IO, Any, ClassVar
 
 import gi
 from clan_cli import vms
@@ -81,6 +81,8 @@ class VM(GObject.Object):
         self.data = data
         self.process = MPProcess("dummy", mp.Process(), Path("./dummy"))
         self._watcher_id: int = 0
+        self._logs_id: int = 0
+        self._log_file: IO[str] | None = None
         self.status = status
         self._last_liveness: bool = False
         self.log_dir = tempfile.TemporaryDirectory(
@@ -116,7 +118,6 @@ class VM(GObject.Object):
         # Every 50ms check if the VM is still running
         self._watcher_id = GLib.timeout_add(50, self._vm_watcher_task)
         if self._watcher_id == 0:
-            log.error("Failed to add watcher")
             raise ClanError("Failed to add watcher")
 
     def _vm_watcher_task(self) -> bool:
@@ -127,24 +128,38 @@ class VM(GObject.Object):
 
             # If the VM was running and now it is not, remove the watcher
             if prev_liveness and not self.is_running():
-                print("===>Removing watcher")
+                log.debug("Removing VM watcher")
                 return GLib.SOURCE_REMOVE
-
         return GLib.SOURCE_CONTINUE
 
-    def _start_logs_task(self, obj: Any, vm: Any, _vm: Any) -> None:
+    def _start_logs_task(self, obj: Any, vm: Any) -> None:
-        print("Starting log task")
+        if self.is_running():
-        self._logs_id = GLib.timeout_add(50, self._get_logs_task)
+            log.debug(f"Starting logs watcher on file: {self.process.out_file}")
+            self._logs_id = GLib.timeout_add(50, self._get_logs_task)
+        else:
+            log.debug("Not starting logs watcher")
 
     def _get_logs_task(self) -> bool:
         if not self.process.out_file.exists():
-            log.error(f"Log file {self.process.out_file} does not exist")
+            return GLib.SOURCE_CONTINUE
-            return GLib.SOURCE_REMOVE
+
+        if not self._log_file:
+            try:
+                self._log_file = open(self.process.out_file)
+            except Exception as ex:
+                log.exception(ex)
+                self._log_file = None
+                return GLib.SOURCE_REMOVE
+
         if not self.is_running():
-            log.info("VM is not running")
+            log.debug("Removing logs watcher")
+            self._log_file = None
             return GLib.SOURCE_REMOVE
 
-        print(self.read_whole_log())
+        line = os.read(self._log_file.fileno(), 4096)
+        if len(line) != 0:
+            print(line.decode("utf-8"), end="", flush=True)
+
         return GLib.SOURCE_CONTINUE
 
     def is_running(self) -> bool:
@@ -156,20 +171,10 @@ class VM(GObject.Object):
     def stop(self) -> None:
         log.info("Stopping VM")
         if not self.is_running():
-            log.error("VM already stopped")
             return
 
         self.process.kill_group()
 
-    def read_line_log(self) -> Generator[str, None, None]:
-        with open(self.process.out_file) as f:
-            while True:
-                line = f.readline()
-                if not line:
-                    break
-                yield line
-        return None
-
     def read_whole_log(self) -> str:
         if not self.process.out_file.exists():
             log.error(f"Log file {self.process.out_file} does not exist")

pkgs/clan-vm-manager/clan_vm_manager/views/list.py

@@ -1,3 +1,4 @@
+import logging
 from collections.abc import Callable
 from functools import partial
 
@@ -12,6 +13,8 @@ from gi.repository import Adw, Gdk, Gio, GObject, Gtk
 
 from clan_vm_manager.models.use_vms import VM, VMS, ClanGroup, Clans
 
+log = logging.getLogger(__name__)
+
 
 def create_boxed_list(
     model: Gio.ListStore, render_row: Callable[[Gtk.ListBox, GObject], Gtk.Widget]
@@ -194,8 +197,6 @@ class ClanList(Gtk.Box):
             self.join_boxed_list.add_css_class("no-shadow")
 
     def on_row_toggle(self, vm: VM, row: Adw.SwitchRow, state: bool) -> None:
-        print("Toggled", vm.data.flake.flake_attr, "active:", row.get_active())
-
         if row.get_active():
             row.set_state(False)
             vm.start()
@@ -208,9 +209,5 @@ class ClanList(Gtk.Box):
         switch.set_active(vm.is_running())
         switch.set_state(vm.is_running())
         exitc = vm.process.proc.exitcode
-        print("VM exited with code:", exitc)
         if not vm.is_running() and exitc != 0:
-            print("VM exited with error. Exitcode:", exitc)
+            log.error(f"VM exited with error. Exitcode: {exitc}")
-            print("==========VM LOGS=========")
-            print(vm.read_whole_log())
-            # self.show_error_dialog(vm.read_log())