Minor improvements

lxc_autoscale/config.py

@@ -5,6 +5,7 @@
 from typing import Any, Dict, List, Set, Union
 
 import yaml
+from logging_setup import setup_logging  # Import the logging setup function
 
 CONFIG_FILE = "/etc/lxc_autoscale/lxc_autoscale.yaml"
 
@@ -24,7 +25,8 @@ def load_tier_configurations() -> Dict[str, Dict[str, Any]]:
     """Load and validate tier configurations."""
     tier_configs: Dict[str, Dict[str, Any]] = {}
 
-    logging.basicConfig(level=logging.INFO)
+    # Setup logging based on the configuration
+    setup_logging()
 
     for section, values in config.items():
         if section.startswith('TIER_'):

lxc_autoscale/lock_manager.py

@@ -23,14 +23,17 @@ def acquire_lock():
     # Open the lock file for writing
     lock_file = open(LOCK_FILE, 'w')
     try:
+        logging.info("Acquiring lock on %s", LOCK_FILE)
         # Try to acquire an exclusive lock on the file (non-blocking)
         fcntl.lockf(lock_file, fcntl.LOCK_EX | fcntl.LOCK_NB)
+        logging.info("Lock acquired on %s", LOCK_FILE)
         # Yield control back to the calling context, keeping the lock in place
         yield lock_file
     except IOError:
         # If the lock is already held by another process, log an error and exit
         logging.error("Another instance of the script is already running. Exiting to avoid overlap.")
         sys.exit(1)
     finally:
+        logging.info("Lock released on %s", LOCK_FILE)
         # Ensure the lock file is closed when done, releasing the lock
         lock_file.close()

lxc_autoscale/logging_setup.py

@@ -20,6 +20,13 @@ def setup_logging():
         datefmt='%Y-%m-%d %H:%M:%S'  # Date format for timestamps
     )
 
+    # Debug: Verify that the log file is writable
+    try:
+        with open(LOG_FILE, 'a') as f:
+            f.write("# Log file initialized successfully.\n")
+    except Exception as err:
+        print(f"Error writing to log file ({LOG_FILE}): {err}")
+
     # Create a console handler to output log messages to the console
     console = logging.StreamHandler()
     console.setLevel(logging.INFO)  # Set the logging level for the console output

lxc_autoscale/lxc_autoscale.py

@@ -47,18 +47,20 @@ def parse_arguments() -> argparse.Namespace:
         help="Rollback to previous container configurations"  # Option to revert containers to their backed-up settings
     )
 
-    return parser.parse_args()
+    args = parser.parse_args()
+    logging.debug(f"Parsed arguments: {args}")
+    return args
 
 
 # Entry point of the script
 if __name__ == "__main__":
+    # Setup logging based on the configuration
+    setup_logging()
+
     # Parse command-line arguments
     args: argparse.Namespace = parse_arguments()
 
-    # Remove automatic creation of log directory and file
-
-    # Setup logging based on the configuration
-    setup_logging()
+    logging.info("Starting LXC autoscaling daemon with arguments: %s", args)
 
     # Acquire a lock to ensure that only one instance of the script runs at a time
     with acquire_lock() as lock_file:

lxc_autoscale/lxc_utils.py

@@ -53,6 +53,7 @@ def close_ssh_client() -> None:
     if ssh_client:
         logging.debug("Closing SSH connection...")
         ssh_client.close()
+        logging.info("SSH connection closed.")
         ssh_client = None
 
 def run_command(cmd: str, timeout: int = 30) -> Optional[str]:
@@ -67,6 +68,7 @@ def run_command(cmd: str, timeout: int = 30) -> Optional[str]:
     """
     use_remote_proxmox = config.get('DEFAULT', {}).get('use_remote_proxmox', False)
     logging.debug("Inside run_command: use_remote_proxmox = %s", use_remote_proxmox)
+    logging.debug(f"Running command: {cmd} (timeout: {timeout}s)")
     return (run_remote_command if use_remote_proxmox else run_local_command)(cmd, timeout)
 
 
@@ -84,7 +86,7 @@ def run_local_command(cmd: str, timeout: int = 30) -> Optional[str]:
         result = subprocess.check_output(
             cmd, shell=True, timeout=timeout, stderr=subprocess.STDOUT,
         ).decode('utf-8').strip()
-        logging.debug("Command '%s' executed successfully. Output: %s", cmd, result)
+        logging.debug(f"Command '{cmd}' executed successfully. Output: {result}")
         return result
     except subprocess.TimeoutExpired:
         logging.error("Command '%s' timed out after %d seconds", cmd, timeout)
@@ -112,7 +114,7 @@ def run_remote_command(cmd: str, timeout: int = 30) -> Optional[str]:
     try:
         _, stdout, _ = ssh.exec_command(cmd, timeout=timeout)
         output = stdout.read().decode('utf-8').strip()
-        logging.debug("Remote command '%s' executed successfully: %s", cmd, output)
+        logging.debug(f"Remote command '{cmd}' executed successfully: {output}")
         return output
     except paramiko.SSHException as e:
         logging.error("SSH execution failed: %s", str(e))
@@ -138,7 +140,9 @@ def get_containers() -> List[str]:
 
 def is_ignored(ctid: str) -> bool:
     """Check if container should be ignored."""
-    return str(ctid) in IGNORE_LXC
+    ignored = str(ctid) in IGNORE_LXC
+    logging.debug(f"Container {ctid} is ignored: {ignored}")
+    return ignored
 
 def is_container_running(ctid: str) -> bool:
     """Check if a container is running.
@@ -150,7 +154,9 @@ def is_container_running(ctid: str) -> bool:
         True if the container is running, False otherwise.
     """
     status = run_command(f"pct status {ctid}")
-    return bool(status and "status: running" in status.lower())
+    running = bool(status and "status: running" in status.lower())
+    logging.debug(f"Container {ctid} running status: {running}")
+    return running
 
 
 def backup_container_settings(ctid: str, settings: Dict[str, Any]) -> None:
@@ -226,6 +232,7 @@ def log_json_event(ctid: str, action: str, resource_change: str) -> None:
     with lock:
         with open(LOG_FILE.replace('.log', '.json'), 'a', encoding='utf-8') as json_log_file:
             json_log_file.write(json.dumps(log_data) + '\n')
+    logging.info("Logged event for container %s: %s - %s", ctid, action, resource_change)
 
 
 def get_total_cores() -> int:
@@ -366,7 +373,9 @@ def get_memory_usage(ctid: str) -> float:
     if mem_info:
         try:
             total, used = map(int, mem_info.split())
-            return (used * 100) / total
+            mem_usage = (used * 100) / total
+            logging.info("Memory usage for %s: %.2f%%", ctid, mem_usage)
+            return mem_usage
         except ValueError:
             logging.error("Failed to parse memory info for %s: '%s'", ctid, mem_info)
     logging.error("Failed to get memory usage for %s", ctid)
@@ -406,6 +415,7 @@ def collect_data_for_container(ctid: str) -> Optional[Dict[str, Dict[str, Any]]]
     """Collect data for a single container."""
     data = get_container_data(ctid)
     if data:
+        logging.debug("Data collected for container %s: %s", ctid, data)
         return {ctid: data}
     return None
 
@@ -434,6 +444,7 @@ def collect_container_data() -> Dict[str, Dict[str, Any]]:
             except Exception as e:
                 logging.error(f"Error collecting data for container {ctid}: {e}")
 
+    logging.info("Collected data for containers: %s", containers)
     return containers
 
 
@@ -472,7 +483,9 @@ def get_container_config(ctid: str) -> Dict[str, Any]:
     Returns:
         The container's tier configuration.
     """
-    return LXC_TIER_ASSOCIATIONS.get(ctid, config)
+    config = LXC_TIER_ASSOCIATIONS.get(ctid, config)
+    logging.debug("Configuration for container %s: %s", ctid, config)
+    return config
 
 
 def generate_unique_snapshot_name(base_name: str) -> str:
@@ -484,7 +497,9 @@ def generate_unique_snapshot_name(base_name: str) -> str:
     Returns:
         A unique snapshot name.
     """
-    return f"{base_name}-{datetime.now().strftime('%Y%m%d%H%M%S')}"
+    snapshot_name = f"{base_name}-{datetime.now().strftime('%Y%m%d%H%M%S')}"
+    logging.debug("Generated unique snapshot name: %s", snapshot_name)
+    return snapshot_name
 
 
 def generate_cloned_hostname(base_name: str, clone_number: int) -> str:
@@ -497,7 +512,9 @@ def generate_cloned_hostname(base_name: str, clone_number: int) -> str:
     Returns:
         A unique hostname for the cloned container.
     """
-    return f"{base_name}-cloned-{clone_number}"
+    hostname = f"{base_name}-cloned-{clone_number}"
+    logging.debug("Generated cloned hostname: %s", hostname)
+    return hostname
 
 import atexit
 atexit.register(close_ssh_client)

lxc_autoscale/scaling_manager.py

@@ -33,6 +33,7 @@ def calculate_increment(current: float, upper_threshold: float, min_increment: i
         Calculated increment value.
     """
     proportional_increment = int((current - upper_threshold) / CPU_SCALE_DIVISOR)
+    logging.debug(f"Calculated increment: {proportional_increment} (current: {current}, upper_threshold: {upper_threshold})")
     return min(max(min_increment, proportional_increment), max_increment)
 
 
@@ -50,6 +51,7 @@ def calculate_decrement(current: float, lower_threshold: float, current_allocate
          Calculated decrement value.
     """
     dynamic_decrement = max(1, int((lower_threshold - current) / CPU_SCALE_DIVISOR))
+    logging.debug(f"Calculated decrement: {dynamic_decrement} (current: {current}, lower_threshold: {lower_threshold})")
     return max(min(current_allocated - min_allocated, dynamic_decrement), min_decrement)
 
 
@@ -60,10 +62,13 @@ def get_behaviour_multiplier() -> float:
          The behavior multiplier (1.0 for normal, 0.5 for conservative, 2.0 for aggressive).
     """
     if DEFAULTS['behaviour'] == 'conservative':
-        return 0.5
+        multiplier = 0.5
     elif DEFAULTS['behaviour'] == 'aggressive':
-        return 2.0
-    return 1.0
+        multiplier = 2.0
+    else:
+        multiplier = 1.0
+    logging.debug(f"Behavior multiplier set to {multiplier} based on configuration: {DEFAULTS['behaviour']}")
+    return multiplier
 
 
 def scale_memory(ctid: str, mem_usage: float, mem_upper: float, mem_lower: float, current_memory: int, min_memory: int, available_memory: int, config: Dict[str, Any]) -> Tuple[int, bool]:
@@ -85,6 +90,8 @@ def scale_memory(ctid: str, mem_usage: float, mem_upper: float, mem_lower: float
     memory_changed = False
     behaviour_multiplier = get_behaviour_multiplier()
 
+    logging.info(f"Memory scaling for container {ctid} - Usage: {mem_usage}%, Upper threshold: {mem_upper}%, Lower threshold: {mem_lower}%")
+
     if mem_usage > mem_upper:
         increment = max(
             int(config['memory_min_increment'] * behaviour_multiplier),
@@ -457,4 +464,5 @@ def is_off_peak() -> bool:
          True if it is off-peak, otherwise False.
     """
     current_hour = datetime.now().hour
+    logging.debug(f"Current hour: {current_hour}, Off-peak hours: {DEFAULTS['off_peak_start']} - {DEFAULTS['off_peak_end']}")
     return DEFAULTS['off_peak_start'] <= current_hour or current_hour < DEFAULTS['off_peak_end']