Fix hard dependency loading

lib/modloader.dart

@@ -1,7 +1,6 @@
 import 'dart:io';
 import 'dart:async';
 import 'package:xml/xml.dart';
-import 'package:path/path.dart' as path;
 
 const root = r'C:/Users/Administrator/Seafile/Games-Rimworld';
 const modsRoot = '$root/294100';
@@ -25,8 +24,7 @@ class Logger {
     try {
       // Use system temp directory
       final tempDir = Directory.systemTemp;
-      final timestamp = DateTime.now().toIso8601String().replaceAll(':', '-').substring(0, 19);
+      final logFileName = 'rimworld_modman.log';
-      final logFileName = 'rimworld_modman_$timestamp.log';
 
       _logFile = File('${tempDir.path}${Platform.pathSeparator}$logFileName');
       _logSink = _logFile!.openWrite(mode: FileMode.writeOnly);
@@ -102,7 +100,8 @@ class Mod {
   final List<String> loadAfter; // ModMetaData.loadAfter
   final List<String> loadBefore; // ModMetaData.loadBefore
   final List<String> incompatabilities; // ModMetaData.incompatibleWith
-  final bool enabled; // ConfigFile.mods.firstWhere((mod) => mod.id == id).enabled
+  final bool
+  enabled; // ConfigFile.mods.firstWhere((mod) => mod.id == id).enabled
   final int size; // Count of files in the mod directory
   final bool isBaseGame; // Is this the base RimWorld game
   final bool isExpansion; // Is this a RimWorld expansion
@@ -127,18 +126,25 @@ class Mod {
     final logger = Logger.instance;
     final stopwatch = Stopwatch()..start();
 
+    logger.info('Attempting to load mod from directory: $path');
     final aboutFile = File('$path/About/About.xml');
     if (!aboutFile.existsSync()) {
+      logger.error('About.xml file does not exist in $aboutFile');
       throw Exception('About.xml file does not exist in $aboutFile');
     }
 
+    logger.info('Parsing About.xml file...');
     final aboutXml = XmlDocument.parse(aboutFile.readAsStringSync());
     final xmlTime = stopwatch.elapsedMilliseconds;
 
     late final XmlElement metadata;
     try {
       metadata = findCaseInsensitiveDoc(aboutXml, 'ModMetaData');
+      logger.info('Successfully found ModMetaData in About.xml');
     } catch (e) {
+      logger.error(
+        'Error: ModMetaData element is missing in About.xml ($aboutFile). Original error: $e',
+      );
       throw Exception(
         'Error: ModMetaData element is missing in About.xml ($aboutFile). Original error: $e',
       );
@@ -147,7 +153,11 @@ class Mod {
     late final String name;
     try {
       name = metadata.findElements('name').first.innerText;
+      logger.info('Mod name found: $name');
     } catch (e) {
+      logger.error(
+        'Error: name element is missing in ModMetaData ($aboutFile). Original error: $e',
+      );
       throw Exception(
         'Error: name element is missing in ModMetaData ($aboutFile). Original error: $e',
       );
@@ -156,7 +166,11 @@ class Mod {
     late final String id;
     try {
       id = metadata.findElements('packageId').first.innerText.toLowerCase();
+      logger.info('Mod ID found: $id');
     } catch (e) {
+      logger.error(
+        'Error: packageId element is missing in ModMetaData ($aboutFile). Original error: $e',
+      );
       throw Exception(
         'Error: packageId element is missing in ModMetaData ($aboutFile). Original error: $e',
       );
@@ -171,7 +185,11 @@ class Mod {
               .findElements('li')
               .map((e) => e.innerText)
               .toList();
+      logger.info('Supported versions found: ${versions.join(", ")}');
     } catch (e) {
+      logger.error(
+        'Error: supportedVersions or li elements are missing in ModMetaData ($aboutFile). Original error: $e',
+      );
       throw Exception(
         'Error: supportedVersions or li elements are missing in ModMetaData ($aboutFile). Original error: $e',
       );
@@ -180,8 +198,11 @@ class Mod {
     String description = '';
     try {
       description = metadata.findElements('description').first.innerText;
+      logger.info('Mod description found: $description');
     } catch (e) {
-      // Silent error for optional element
+      logger.warning(
+        'Description element is missing in ModMetaData ($aboutFile).',
+      );
     }
 
     List<String> hardDependencies = [];
@@ -189,15 +210,21 @@ class Mod {
       hardDependencies =
           metadata
               .findElements('modDependenciesByVersion')
+              .first
+              .children
+              .whereType<XmlElement>()
               .last
               .findElements('li')
               .map(
                 (e) =>
-                    e.findElements('packageId').first.innerText.toLowerCase(),
+                    e.findElements("packageId").first.innerText.toLowerCase(),
               )
               .toList();
+      logger.info('Hard dependencies found: ${hardDependencies.join(", ")}');
     } catch (e) {
-      // Silent error for optional element
+      logger.warning(
+        'Hard dependencies element is missing in ModMetaData ($aboutFile).',
+      );
     }
 
     List<String> loadAfter = [];
@@ -209,8 +236,11 @@ class Mod {
               .findElements('li')
               .map((e) => e.innerText.toLowerCase())
               .toList();
+      logger.info('Load after dependencies found: ${loadAfter.join(", ")}');
     } catch (e) {
-      // Silent error for optional element
+      logger.warning(
+        'Load after element is missing in ModMetaData ($aboutFile).',
+      );
     }
 
     List<String> loadBefore = [];
@@ -222,8 +252,11 @@ class Mod {
               .findElements('li')
               .map((e) => e.innerText.toLowerCase())
               .toList();
+      logger.info('Load before dependencies found: ${loadBefore.join(", ")}');
     } catch (e) {
-      // Silent error for optional element
+      logger.warning(
+        'Load before element is missing in ModMetaData ($aboutFile).',
+      );
     }
 
     List<String> incompatabilities = [];
@@ -235,8 +268,11 @@ class Mod {
               .findElements('li')
               .map((e) => e.innerText.toLowerCase())
               .toList();
+      logger.info('Incompatibilities found: ${incompatabilities.join(", ")}');
     } catch (e) {
-      // Silent error for optional element
+      logger.warning(
+        'Incompatibilities element is missing in ModMetaData ($aboutFile).',
+      );
     }
 
     final metadataTime = stopwatch.elapsedMilliseconds - xmlTime;
@@ -254,6 +290,7 @@ class Mod {
                         .startsWith('.'),
               )
               .length;
+      logger.info('File count in mod directory: $size');
     }
 
     // Check if this is RimWorld base game or expansion
@@ -263,6 +300,9 @@ class Mod {
     // If this is an expansion, ensure it depends on the base game
     if (isExpansion && !loadAfter.contains('ludeon.rimworld')) {
       loadAfter.add('ludeon.rimworld');
+      logger.info(
+        'Added base game dependency for expansion mod: ludeon.rimworld',
+      );
     }
 
     final fileCountTime =
@@ -308,6 +348,7 @@ class ModList {
 
     // Clear existing state if reloading
     if (modsLoaded) {
+      logger.info('Clearing existing mods state for reload.');
       mods.clear();
     }
 
@@ -322,25 +363,36 @@ class ModList {
       // First, load the config file to get the list of active mods
       final configFile = ConfigFile(path: configPath);
       await configFile.load();
+      logger.info('Config file loaded successfully.');
 
       // Create a Set of active mod IDs for quick lookups
       final activeModIds = configFile.mods.map((m) => m.id).toSet();
+      logger.info('Active mod IDs created: ${activeModIds.join(', ')}');
 
       // Special handling for Ludeon mods that might not exist as directories
       for (final configMod in configFile.mods) {
         if (configMod.id.startsWith('ludeon.')) {
           final isBaseGame = configMod.id == 'ludeon.rimworld';
-          final isExpansion = configMod.id.startsWith('ludeon.rimworld.') && !isBaseGame;
+          final isExpansion =
+              configMod.id.startsWith('ludeon.rimworld.') && !isBaseGame;
 
           // Create a placeholder mod for the Ludeon mods that might not have directories
           final mod = Mod(
-            name: isBaseGame ? "RimWorld" : 
+            name:
-                 isExpansion ? "RimWorld ${_expansionNameFromId(configMod.id)}" : configMod.id,
+                isBaseGame
+                    ? "RimWorld"
+                    : isExpansion
+                    ? "RimWorld ${_expansionNameFromId(configMod.id)}"
+                    : configMod.id,
             id: configMod.id,
             path: '',
             versions: [],
-            description: isBaseGame ? "RimWorld base game" : 
+            description:
-                       isExpansion ? "RimWorld expansion" : "",
+                isBaseGame
+                    ? "RimWorld base game"
+                    : isExpansion
+                    ? "RimWorld expansion"
+                    : "",
             hardDependencies: [],
             loadAfter: isExpansion ? ['ludeon.rimworld'] : [],
             loadBefore: [],
@@ -353,6 +405,7 @@ class ModList {
 
           mods[configMod.id] = mod;
           loadedModsCount++;
+          logger.info('Added mod from config: ${mod.name} (ID: ${mod.id})');
         }
       }
 
@@ -372,7 +425,9 @@ class ModList {
 
       totalModsFound = modDirectories.length;
       loadingStatus = 'Found $totalModsFound mod directories. Loading...';
-      logger.info('Found ${modDirectories.length} mod directories (${stopwatch.elapsedMilliseconds}ms)');
+      logger.info(
+        'Found ${modDirectories.length} mod directories (${stopwatch.elapsedMilliseconds}ms)',
+      );
 
       for (final modDir in modDirectories) {
         try {
@@ -380,9 +435,13 @@ class ModList {
 
           // Check if this directory contains a valid mod
           final aboutFile = File('$modDir/About/About.xml');
-          if (!aboutFile.existsSync()) continue;
+          if (!aboutFile.existsSync()) {
+            logger.warning('No About.xml found in directory: $modDir');
+            continue;
+          }
 
           final mod = Mod.fromDirectory(modDir, skipFileCount: skipFileCount);
+          logger.info('Loaded mod from directory: ${mod.name} (ID: ${mod.id})');
 
           // If we already have this mod from the config (like Ludeon mods), update its data
           if (mods.containsKey(mod.id)) {
@@ -397,11 +456,14 @@ class ModList {
               loadAfter: mod.loadAfter,
               loadBefore: mod.loadBefore,
               incompatabilities: mod.incompatabilities,
-              enabled: activeModIds.contains(mod.id), // Set enabled based on config
+              enabled: activeModIds.contains(
+                mod.id,
+              ), // Set enabled based on config
               size: mod.size,
               isBaseGame: existingMod.isBaseGame,
               isExpansion: existingMod.isExpansion,
             );
+            logger.info('Updated existing mod: ${mod.name} (ID: ${mod.id})');
           } else {
             // Otherwise add as a new mod
             mods[mod.id] = Mod(
@@ -414,19 +476,24 @@ class ModList {
               loadAfter: mod.loadAfter,
               loadBefore: mod.loadBefore,
               incompatabilities: mod.incompatabilities,
-              enabled: activeModIds.contains(mod.id), // Set enabled based on config
+              enabled: activeModIds.contains(
+                mod.id,
+              ), // Set enabled based on config
               size: mod.size,
               isBaseGame: mod.isBaseGame,
               isExpansion: mod.isExpansion,
             );
             loadedModsCount++;
+            logger.info('Added new mod: ${mod.name} (ID: ${mod.id})');
           }
 
           final modTime = stopwatch.elapsedMilliseconds - modStart;
           loadingStatus = 'Loaded $loadedModsCount/$totalModsFound mods...';
 
           if (loadedModsCount % 50 == 0 || loadedModsCount == totalModsFound) {
-            logger.info('Progress: Loaded $loadedModsCount mods (${stopwatch.elapsedMilliseconds}ms)');
+            logger.info(
+              'Progress: Loaded $loadedModsCount mods (${stopwatch.elapsedMilliseconds}ms)',
+            );
           }
         } catch (e) {
           logger.error('Error loading mod from directory: $modDir');
@@ -436,8 +503,11 @@ class ModList {
 
       modsLoaded = true;
       final totalTime = stopwatch.elapsedMilliseconds;
-      loadingStatus = 'Completed! Loaded $loadedModsCount mods in ${totalTime}ms.';
+      loadingStatus =
-      logger.info('Loading complete! Loaded ${mods.length} mods in ${totalTime}ms');
+          'Completed! Loaded $loadedModsCount mods in ${totalTime}ms.';
+      logger.info(
+        'Loading complete! Loaded ${mods.length} mods in ${totalTime}ms',
+      );
     } catch (e) {
       loadingStatus = 'Error loading mods: $e';
       logger.error(loadingStatus);
@@ -450,7 +520,8 @@ class ModList {
     if (parts.length < 3) return id;
 
     final expansionPart = parts[2];
-    return expansionPart.substring(0, 1).toUpperCase() + expansionPart.substring(1);
+    return expansionPart.substring(0, 1).toUpperCase() +
+        expansionPart.substring(1);
   }
 
   // Build a directed graph of mod dependencies
@@ -478,7 +549,8 @@ class ModList {
     // 2. Add expansions as dependencies of mods that load after them
 
     // First identify the base game and expansions
-    final baseGameId = mods.values.where((m) => m.isBaseGame).map((m) => m.id).firstOrNull;
+    final baseGameId =
+        mods.values.where((m) => m.isBaseGame).map((m) => m.id).firstOrNull;
     if (baseGameId != null) {
       for (final mod in mods.values) {
         // Skip the base game itself and mods that explicitly load before it
@@ -604,7 +676,9 @@ class ModList {
       if (currentLayer.isEmpty && inDegree.isNotEmpty) {
         // We have a cycle - add all remaining nodes to a final layer
         currentLayer = inDegree.keys.toList();
-        print("Warning: Cycle detected in dependency graph. Adding all remaining nodes to final layer.");
+        print(
+          "Warning: Cycle detected in dependency graph. Adding all remaining nodes to final layer.",
+        );
       }
 
       // Sort this layer by mod size (descending)
@@ -728,7 +802,9 @@ class ModList {
       print("Will attempt to break cycle to produce a valid load order");
     }
 
-    print("Performing topological sort for hard dependencies (prioritizing larger mods)...");
+    print(
+      "Performing topological sort for hard dependencies (prioritizing larger mods)...",
+    );
     final hardOrder = topologicalSort(hardGraph);
 
     print("Adjusting for soft dependencies...");
@@ -786,9 +862,14 @@ class ConfigFile {
       logger.info('Found ${modElements.length} active mods.');
 
       // Get the list of known expansions
-      final knownExpansionsElement = modConfigData.findElements("knownExpansions").firstOrNull;
+      final knownExpansionsElement =
-      final knownExpansionIds = knownExpansionsElement != null
+          modConfigData.findElements("knownExpansions").firstOrNull;
-          ? knownExpansionsElement.findElements("li").map((e) => e.innerText.toLowerCase()).toList()
+      final knownExpansionIds =
+          knownExpansionsElement != null
+              ? knownExpansionsElement
+                  .findElements("li")
+                  .map((e) => e.innerText.toLowerCase())
+                  .toList()
               : <String>[];
 
       logger.info('Found ${knownExpansionIds.length} known expansions.');
@@ -800,19 +881,29 @@ class ConfigFile {
 
         // Check if this is a special Ludeon mod
         final isBaseGame = modId == 'ludeon.rimworld';
-        final isExpansion = !isBaseGame && modId.startsWith('ludeon.rimworld.') && 
+        final isExpansion =
+            !isBaseGame &&
+            modId.startsWith('ludeon.rimworld.') &&
             knownExpansionIds.contains(modId);
 
         // We'll populate with dummy mods for now, they'll be replaced later
         mods.add(
           Mod(
-            name: isBaseGame ? "RimWorld" : 
+            name:
-                 isExpansion ? "RimWorld ${_expansionNameFromId(modId)}" : modId,
+                isBaseGame
+                    ? "RimWorld"
+                    : isExpansion
+                    ? "RimWorld ${_expansionNameFromId(modId)}"
+                    : modId,
             id: modId,
             path: '',
             versions: [],
-            description: isBaseGame ? "RimWorld base game" : 
+            description:
-                       isExpansion ? "RimWorld expansion" : "",
+                isBaseGame
+                    ? "RimWorld base game"
+                    : isExpansion
+                    ? "RimWorld expansion"
+                    : "",
             hardDependencies: [],
             loadAfter: isExpansion ? ['ludeon.rimworld'] : [],
             loadBefore: [],
@@ -838,7 +929,8 @@ class ConfigFile {
     if (parts.length < 3) return id;
 
     final expansionPart = parts[2];
-    return expansionPart.substring(0, 1).toUpperCase() + expansionPart.substring(1);
+    return expansionPart.substring(0, 1).toUpperCase() +
+        expansionPart.substring(1);
   }
 
   // Save the current mod order back to the config file