Sync with libloot v0.25.5

Cargo.lock

@@ -562,7 +562,7 @@ dependencies = [
 
 [[package]]
 name = "libloot"
-version = "0.25.3"
+version = "0.25.5"
 dependencies = [
  "crc32fast",
  "esplugin",
@@ -583,7 +583,7 @@ dependencies = [
 
 [[package]]
 name = "libloot-cxx"
-version = "0.25.3"
+version = "0.25.5"
 dependencies = [
  "cxx",
  "cxx-build",

Cargo.toml

@@ -1,6 +1,6 @@
 [package]
 name = "libloot"
-version = "0.25.3"
+version = "0.25.5"
 edition = "2024"
 license = "GPL-3.0"
 

README.md

@@ -22,7 +22,7 @@ Currently complete:
 - [x] C++ FFI
 - [ ] Python FFI
 
-The complete bits should match libloot commit [55b341fc6cbdccee52e42923c13a91eddb5ca97d](https://github.com/loot/libloot/commit/55b341fc6cbdccee52e42923c13a91eddb5ca97d), which is libloot v0.25.3 plus a few changes prompted by this translation.
+The complete bits should match libloot v0.25.5.
 
 ## Build
 

cxx/Cargo.toml

@@ -1,6 +1,6 @@
 [package]
 name = "libloot-cxx"
-version = "0.25.3"
+version = "0.25.5"
 edition = "2024"
 license = "GPL-3.0"
 

cxx/README.md

@@ -1,6 +1,6 @@
 # libloot-rs C++ wrapper
 
-This is an **experimental** wrapper around the Rust reimplementation of libloot that provides a C++ interface that's ABI-compatible with libloot v0.25.3.
+This is an **experimental** wrapper around the Rust reimplementation of libloot that provides a C++ interface that's ABI-compatible with libloot v0.25.5.
 
 ## Building
 
@@ -17,7 +17,7 @@ cmake -B build .
 cmake --build build --config RelWithDebInfo
 ```
 
-This also builds a copy of the public API tests from C++ libloot v0.25.3, which can be run using:
+This also builds a copy of the public API tests from C++ libloot v0.25.5, which can be run using:
 
 ```
 ctest --test-dir build --output-on-failure -V

cxx/include/loot/api.h

@@ -59,6 +59,15 @@ namespace loot {
 LOOT_API void SetLoggingCallback(
     std::function<void(LogLevel, const char*)> callback);
 
+/**
+ * @brief Set the log severity level.
+ * @details The default level setting is trace. This function has no effect if
+ *          no logging callback has been set.
+ * @param level
+ *        Messages of this severity level and higher will be logged.
+ */
+LOOT_API void SetLogLevel(LogLevel level);
+
 /**
  * @}
  * @name Version Functions

cxx/include/loot/loot_version.h

@@ -37,7 +37,7 @@ inline constexpr unsigned int LIBLOOT_VERSION_MAJOR = 0;
 inline constexpr unsigned int LIBLOOT_VERSION_MINOR = 25;
 
 /** @brief libloot's patch version number. */
-inline constexpr unsigned int LIBLOOT_VERSION_PATCH = 3;
+inline constexpr unsigned int LIBLOOT_VERSION_PATCH = 5;
 
 /**
  * @brief Get the library version.

cxx/src/api/api.cpp

@@ -50,6 +50,25 @@ LogLevel convert(uint8_t level) {
   }
 }
 
+loot::rust::LogLevel convert(LogLevel level) {
+  switch (level) {
+    case LogLevel::trace:
+    return loot::rust::LogLevel::Trace;
+    case LogLevel::debug:
+    return loot::rust::LogLevel::Debug;
+    case LogLevel::info:
+    return loot::rust::LogLevel::Info;
+    case LogLevel::warning:
+    return loot::rust::LogLevel::Warning;
+    case LogLevel::error:
+    return loot::rust::LogLevel::Error;
+    case LogLevel::fatal:
+    return loot::rust::LogLevel::Fatal;
+  default:
+    return loot::rust::LogLevel::Trace;
+  }
+}
+
 void logging_callback(uint8_t level, const char* message, void* context) {
   auto callbackPtr =
       static_cast<std::function<void(LogLevel, const char*)>*>(context);
@@ -65,6 +84,10 @@ LOOT_API void SetLoggingCallback(
   libloot_set_logging_callback(logging_callback, &STORED_CALLBACK);
 }
 
+LOOT_API void SetLogLevel(LogLevel level) {
+  loot::rust::set_log_level(convert(level));
+}
+
 LOOT_API bool IsCompatible(const unsigned int versionMajor,
                            const unsigned int versionMinor,
                            const unsigned int versionPatch) {

cxx/src/api/resource.rc

@@ -2,8 +2,8 @@
 #include <windows.h>
 
 1 VERSIONINFO
-FILEVERSION 0, 25, 3, 0
-PRODUCTVERSION 0, 25, 3, 0
+FILEVERSION 0, 25, 5, 0
+PRODUCTVERSION 0, 25, 5, 0
 FILEOS VOS__WINDOWS32
 FILETYPE VFT_DLL
 BEGIN
@@ -13,12 +13,12 @@ BLOCK "040904b0"
 BEGIN
 VALUE "CompanyName", "LOOT"
 VALUE "FileDescription", "Library providing LOOT's core functionality"
-VALUE "FileVersion", "0.25.3"
+VALUE "FileVersion", "0.25.5"
 VALUE "InternalName", "loot"
 VALUE "LegalCopyright", "Copyright (C) 2013-2022 Oliver Hamlet"
 VALUE "OriginalFilename", "loot.dll"
 VALUE "ProductName", "LOOT"
-VALUE "ProductVersion", "0.25.3"
+VALUE "ProductVersion", "0.25.5"
 END
 END
 BLOCK "VarFileInfo"

cxx/src/lib.rs

@@ -91,9 +91,7 @@ impl From<GameHandleCreationError> for VerboseError {
     fn from(value: GameHandleCreationError) -> Self {
         match value {
             GameHandleCreationError::LoadOrderError(e) => e.into(),
-            GameHandleCreationError::NotADirectory(_) => {
-                Self::InvalidArgument(value.to_string())
-            }
+            GameHandleCreationError::NotADirectory(_) => Self::InvalidArgument(value.to_string()),
             _ => Self::Other(Box::new(value)),
         }
     }
@@ -121,9 +119,7 @@ impl From<LoadPluginsError> for VerboseError {
     fn from(value: LoadPluginsError) -> Self {
         match value {
             LoadPluginsError::PluginDataError(e) => e.into(),
-            LoadPluginsError::PluginValidationError(_) => {
-                Self::InvalidArgument(value.to_string())
-            }
+            LoadPluginsError::PluginValidationError(_) => Self::InvalidArgument(value.to_string()),
             _ => Self::Other(Box::new(value)),
         }
     }
@@ -293,6 +289,27 @@ fn compare_filenames(lhs: &str, rhs: &str) -> i8 {
     }
 }
 
+fn set_log_level(level: ffi::LogLevel) -> Result<(), VerboseError> {
+    libloot::set_log_level(level.try_into()?);
+    Ok(())
+}
+
+impl TryFrom<ffi::LogLevel> for libloot::LogLevel {
+    type Error = UnsupportedEnumValueError;
+
+    fn try_from(value: ffi::LogLevel) -> Result<Self, UnsupportedEnumValueError> {
+        match value {
+            ffi::LogLevel::Trace => Ok(libloot::LogLevel::Trace),
+            ffi::LogLevel::Debug => Ok(libloot::LogLevel::Debug),
+            ffi::LogLevel::Info => Ok(libloot::LogLevel::Info),
+            ffi::LogLevel::Warning => Ok(libloot::LogLevel::Warning),
+            ffi::LogLevel::Error => Ok(libloot::LogLevel::Error),
+            ffi::LogLevel::Fatal => Ok(libloot::LogLevel::Fatal),
+            _ => Err(UnsupportedEnumValueError),
+        }
+    }
+}
+
 #[allow(clippy::needless_lifetimes)]
 #[cxx::bridge(namespace = "loot::rust")]
 mod ffi {
@@ -338,7 +355,18 @@ mod ffi {
         blueprintMaster,
     }
 
+    pub enum LogLevel {
+        Trace,
+        Debug,
+        Info,
+        Warning,
+        Error,
+        Fatal,
+    }
+
     extern "Rust" {
+        fn set_log_level(level: LogLevel) -> Result<()>;
+
         fn is_compatible(major: u32, minor: u32, patch: u32) -> bool;
         fn libloot_version() -> String;
         fn libloot_revision() -> String;

cxx/src/tests/api/internals/main.cpp

@@ -19,7 +19,7 @@ namespace loot::rust {
 TEST(libloot_version, shouldReturnExpectedValue) {
   auto version = libloot_version();
 
-  EXPECT_EQ(version, "0.25.3");
+  EXPECT_EQ(version, "0.25.5");
 }
 
 TEST(libloot_revision, shouldReturnExpectedValue) {

src/archive/find.rs

@@ -95,7 +95,7 @@ fn find_associated_archives_with_arbitrary_suffixes(
     };
 
     game_cache
-        .archives()
+        .archives_iter()
         .filter(|path| {
             // Need to check if it starts with the given plugin's basename,
             // but case insensitively. This is hard to do accurately, so

src/game.rs

@@ -9,12 +9,13 @@ use loadorder::WritableLoadOrder;
 use rayon::iter::{IntoParallelRefIterator, ParallelIterator};
 
 use crate::{
+    LogLevel,
     database::Database,
     error::{
         DatabaseLockPoisonError, GameHandleCreationError, LoadOrderError, LoadOrderStateError,
         LoadPluginsError, SortPluginsError,
     },
-    logging::{self, format_details},
+    logging::{self, format_details, is_log_enabled},
     metadata::{
         Filename,
         plugin_metadata::{GHOST_FILE_EXTENSION, iends_with_ascii},
@@ -330,7 +331,20 @@ impl Game {
             self.game_type,
             GameType::TES3 | GameType::OpenMW | GameType::Starfield
         ) {
-            let plugins_metadata = plugins_metadata(&plugins)?;
+            let mut loaded_plugins: HashMap<Filename, &Plugin> = self
+                .cache
+                .plugins()
+                .iter()
+                .map(|(k, v)| (k.clone(), v))
+                .collect();
+
+            for plugin in &plugins {
+                loaded_plugins.insert(Filename::new(plugin.name().to_string()), plugin);
+            }
+
+            let loaded_plugins: Vec<_> = loaded_plugins.into_values().collect();
+
+            let plugins_metadata = plugins_metadata(&loaded_plugins)?;
 
             for plugin in &mut plugins {
                 plugin.resolve_record_ids(&plugins_metadata)?;
@@ -393,7 +407,7 @@ impl Game {
         let mut database = self.database.write()?;
         update_loaded_plugin_state(
             database.condition_evaluator_state_mut(),
-            self.cache.plugins(),
+            self.cache.plugins_iter(),
         );
 
         Ok(())
@@ -412,7 +426,7 @@ impl Game {
 
     /// Get data for all loaded plugins.
     pub fn loaded_plugins(&self) -> Vec<&Plugin> {
-        self.cache.plugins().collect()
+        self.cache.plugins_iter().collect()
     }
 
     /// Calculates a new load order for the game's installed plugins (including
@@ -453,7 +467,7 @@ impl Game {
             })
             .collect::<Result<Vec<_>, _>>()?;
 
-        if log::log_enabled!(log::Level::Debug) {
+        if is_log_enabled(LogLevel::Debug) {
             logging::debug!("Current load order:");
             for plugin_name in plugin_names {
                 logging::debug!("\t{}", plugin_name);
@@ -468,7 +482,7 @@ impl Game {
             self.load_order.game_settings().early_loading_plugins(),
         )?;
 
-        if log::log_enabled!(log::Level::Debug) {
+        if is_log_enabled(LogLevel::Debug) {
             logging::debug!("Sorted load order:");
             for plugin_name in &new_load_order {
                 logging::debug!("\t{}", plugin_name);
@@ -755,7 +769,11 @@ impl GameCache {
         self.plugins.clear();
     }
 
-    fn plugins(&self) -> impl Iterator<Item = &Plugin> {
+    fn plugins(&self) -> &HashMap<Filename, Plugin> {
+        &self.plugins
+    }
+
+    fn plugins_iter(&self) -> impl Iterator<Item = &Plugin> {
         self.plugins.values()
     }
 
@@ -763,7 +781,7 @@ impl GameCache {
         self.plugins.get(&Filename::new(plugin_name.to_string()))
     }
 
-    pub fn archives(&self) -> impl Iterator<Item = &PathBuf> {
+    pub fn archives_iter(&self) -> impl Iterator<Item = &PathBuf> {
         self.archive_paths.iter()
     }
 }
@@ -1627,6 +1645,33 @@ mod tests {
 
                 assert!(game.plugin(BLANK_MASTER_DEPENDENT_ESM).is_some());
             }
+
+            #[apply(all_game_types)]
+            fn should_not_error_if_loading_a_plugin_with_a_master_that_is_already_loaded_if_game_is_morrowind_or_starfield(
+                game_type: GameType,
+            ) {
+                let fixture = Fixture::new(game_type);
+
+                let mut game = Game::with_local_path(
+                    fixture.game_type,
+                    &fixture.game_path,
+                    &fixture.local_path,
+                )
+                .unwrap();
+
+                let master = if game_type == GameType::Starfield {
+                    BLANK_FULL_ESM
+                } else {
+                    BLANK_ESM
+                };
+
+                game.load_plugins(&[Path::new(master)]).unwrap();
+
+                game.load_plugins(&[Path::new(BLANK_MASTER_DEPENDENT_ESM)])
+                    .unwrap();
+
+                assert!(game.plugin(BLANK_MASTER_DEPENDENT_ESM).is_some());
+            }
         }
 
         mod load_plugins_common {

src/lib.rs

@@ -12,7 +12,7 @@ mod version;
 
 pub use database::Database;
 pub use game::{Game, GameType};
-pub use logging::{LogLevel, set_logging_callback};
+pub use logging::{LogLevel, set_log_level, set_logging_callback};
 pub use plugin::Plugin;
 pub use sorting::vertex::{EdgeType, Vertex};
 pub use version::{

src/logging.rs

@@ -2,8 +2,8 @@ use std::sync::{LazyLock, RwLock};
 
 type Callback = dyn Fn(LogLevel, &str) + Send + Sync;
 
-pub(crate) static LOGGER: LazyLock<RwLock<Box<Callback>>> =
-    LazyLock::new(|| RwLock::new(Box::new(|_, _| {})));
+pub(crate) static LOGGER: LazyLock<RwLock<Logger>> =
+    LazyLock::new(|| RwLock::new(Logger::new(Box::new(|_, _| {}))));
 
 /// Set the callback function that is called when logging.
 ///
@@ -16,9 +16,22 @@ where
     let boxed = Box::new(callback);
 
     match LOGGER.write() {
-        Ok(mut logger) => *logger = boxed,
+        Ok(mut logger) => logger.set_callback(boxed),
         Err(e) => {
-            *e.into_inner() = boxed;
+            e.into_inner().set_callback(boxed);
+            LOGGER.clear_poison();
+        }
+    }
+}
+
+// Set the log severity level.
+//
+// The default level setting is trace. This function has no effect if no logging callback has been set.
+pub fn set_log_level(level: LogLevel) {
+    match LOGGER.write() {
+        Ok(mut logger) => logger.set_level(level),
+        Err(e) => {
+            e.into_inner().set_level(level);
             LOGGER.clear_poison();
         }
     }
@@ -61,14 +74,52 @@ impl From<LogLevel> for log::Level {
     }
 }
 
+pub(crate) struct Logger {
+    callback: Box<Callback>,
+    level: LogLevel,
+}
+
+impl Logger {
+    fn new(callback: Box<Callback>) -> Self {
+        Self {
+            callback,
+            level: LogLevel::Trace,
+        }
+    }
+
+    pub(crate) fn log(&self, level: LogLevel, message: &str) {
+        if level >= self.level {
+            (self.callback)(level, message)
+        }
+    }
+
+    fn level(&self) -> LogLevel {
+        self.level
+    }
+
+    fn set_callback(&mut self, callback: Box<Callback>) {
+        self.callback = callback;
+    }
+
+    fn set_level(&mut self, level: LogLevel) {
+        self.level = level;
+    }
+}
+
 macro_rules! log {
     ($level:expr, $($arg:tt)+) => {
         // Log using the Rust log crate, as it's probably good to support that.
         log::log!(log::Level::from($level), $($arg)+);
 
         // Also log using the callback.
-        if let Ok(logger) = $crate::logging::LOGGER.read() {
-            logger($level, &std::fmt::format(format_args!($($arg)+)));
+        let message = std::fmt::format(format_args!($($arg)+));
+
+        match $crate::logging::LOGGER.read() {
+            Ok(logger) => logger.log($level, &message),
+            Err(e) => {
+                $crate::logging::LOGGER.clear_poison();
+                e.into_inner().log($level, &message);
+            }
         }
     };
 }
@@ -93,6 +144,22 @@ macro_rules! trace {
     ($($arg:tt)+) => { $crate::logging::log!(crate::LogLevel::Trace, $($arg)+) };
 }
 
+pub fn is_log_enabled(level: LogLevel) -> bool {
+    if log::log_enabled!(level.into()) {
+        return true;
+    }
+
+    let logger = match LOGGER.read() {
+        Ok(logger) => logger,
+        Err(e) => {
+            LOGGER.clear_poison();
+            e.into_inner()
+        }
+    };
+
+    level >= logger.level()
+}
+
 pub(crate) use {debug, error, info, log, trace, warning as warn};
 
 pub(crate) fn format_details<E: std::error::Error>(error: &E) -> String {
@@ -109,16 +176,16 @@ pub(crate) fn format_details<E: std::error::Error>(error: &E) -> String {
 mod tests {
     use super::*;
 
+    use std::sync::{Arc, LazyLock, Mutex};
+
+    // Since the callback is a global object, these tests need to be run in
+    // series so that one doesn't switch out the callback between another
+    // doing the same and trying to use it.
+    static TEST_LOCK: Mutex<()> = Mutex::new(());
+
     mod set_logging_callback {
         use super::*;
 
-        use std::sync::{Arc, LazyLock, Mutex};
-
-        // Since the callback is a global object, these tests need to be run in
-        // series so that one doesn't switch out the callback between another
-        // doing the same and trying to use it.
-        static TEST_LOCK: Mutex<()> = Mutex::new(());
-
         #[test]
         fn should_support_a_function() {
             let _lock = TEST_LOCK.lock().unwrap();
@@ -207,4 +274,49 @@ mod tests {
             );
         }
     }
+
+    mod set_log_level {
+        use super::*;
+
+        #[test]
+        fn should_set_the_level_used_to_filter_messages_passed_to_the_callback() {
+            let _lock = TEST_LOCK.lock().unwrap();
+
+            static MESSAGES: LazyLock<Mutex<Vec<(LogLevel, String)>>> =
+                LazyLock::new(|| Mutex::new(Vec::new()));
+
+            fn callback(level: LogLevel, message: &str) {
+                if let Ok(mut messages) = MESSAGES.lock() {
+                    messages.push((level, message.to_string()));
+                }
+            }
+
+            set_logging_callback(callback);
+            set_log_level(LogLevel::Warning);
+
+            error!("Test error");
+            info!("Test info");
+
+            assert_eq!(
+                vec![(LogLevel::Error, "Test error".into())],
+                *MESSAGES.lock().unwrap()
+            );
+        }
+    }
+
+    mod is_log_enabled {
+        use super::*;
+
+        #[test]
+        fn should_return_true_iff_log_level_is_less_than_or_equal_to_given_level() {
+            set_log_level(LogLevel::Warning);
+
+            assert!(!is_log_enabled(LogLevel::Trace));
+            assert!(!is_log_enabled(LogLevel::Debug));
+            assert!(!is_log_enabled(LogLevel::Info));
+            assert!(is_log_enabled(LogLevel::Warning));
+            assert!(is_log_enabled(LogLevel::Error));
+            assert!(is_log_enabled(LogLevel::Fatal));
+        }
+    }
 }

src/plugin/mod.rs

@@ -356,7 +356,7 @@ pub(crate) fn has_ascii_extension(path: &Path, extension: &str) -> bool {
 }
 
 pub(crate) fn plugins_metadata(
-    plugins: &[Plugin],
+    plugins: &[&Plugin],
 ) -> Result<Vec<esplugin::PluginMetadata>, PluginDataError> {
     let esplugins: Vec<_> = plugins.iter().filter_map(|p| p.plugin.as_ref()).collect();
     Ok(esplugin::plugins_metadata(&esplugins)?)
@@ -646,7 +646,7 @@ mod tests {
                 )
                 .unwrap();
 
-                let metadata = plugins_metadata(&[master]).unwrap();
+                let metadata = plugins_metadata(&[&master]).unwrap();
 
                 plugin.resolve_record_ids(&metadata).unwrap();
 
@@ -660,7 +660,7 @@ mod tests {
                 )
                 .unwrap();
 
-                let metadata = plugins_metadata(&[master]).unwrap();
+                let metadata = plugins_metadata(&[&master]).unwrap();
 
                 plugin.resolve_record_ids(&metadata).unwrap();
 
@@ -947,7 +947,7 @@ mod tests {
                 )
                 .unwrap();
 
-                let metadata = plugins_metadata(&[master]).unwrap();
+                let metadata = plugins_metadata(&[&master]).unwrap();
 
                 plugin.resolve_record_ids(&metadata).unwrap();
             }
@@ -990,7 +990,7 @@ mod tests {
                 )
                 .unwrap();
 
-                let metadata = plugins_metadata(&[master]).unwrap();
+                let metadata = plugins_metadata(&[&master]).unwrap();
 
                 plugin.resolve_record_ids(&metadata).unwrap();
             }
@@ -1027,7 +1027,7 @@ mod tests {
                 )
                 .unwrap();
 
-                let metadata = plugins_metadata(&[master]).unwrap();
+                let metadata = plugins_metadata(&[&master]).unwrap();
 
                 plugin.resolve_record_ids(&metadata).unwrap();
             }

src/sorting/groups.rs

@@ -3,7 +3,8 @@ use std::{cmp::Reverse, collections::HashMap};
 use petgraph::{Graph, algo::bellman_ford, graph::NodeIndex};
 
 use crate::{
-    EdgeType, Vertex, logging,
+    EdgeType, LogLevel, Vertex,
+    logging::{self, is_log_enabled},
     metadata::Group,
     sorting::{
         dfs::find_cycle,
@@ -75,7 +76,7 @@ fn add_groups<'a>(
     }
 
     for group in groups {
-        if log::log_enabled!(log::Level::Trace) {
+        if is_log_enabled(LogLevel::Trace) {
             logging::trace!(
                 "Group \"{}\" directly loads after groups \"{}\"",
                 group.name(),

src/sorting/plugins.rs

@@ -3,7 +3,6 @@ use std::{
     rc::Rc,
 };
 
-use log::log_enabled;
 use petgraph::{
     Graph,
     graph::{EdgeReference, NodeIndex},
@@ -11,7 +10,8 @@ use petgraph::{
 };
 
 use crate::{
-    EdgeType, Plugin, logging,
+    EdgeType, LogLevel, Plugin,
+    logging::{self, is_log_enabled},
     metadata::{File, Group, PluginMetadata},
     plugin::error::PluginDataError,
     sorting::{
@@ -559,7 +559,7 @@ impl<'a, T: SortingPlugin> PluginsGraph<'a, T> {
                         // Record the path as the start of the new load order.
                         // Don't need to add any edges because there's nothing for nextVertex
                         // to load after at this point.
-                        if log_enabled!(log::Level::Debug) {
+                        if is_log_enabled(LogLevel::Debug) {
                             logging::debug!(
                                 "The path ends with the first plugin checked, treating the following path as the start of the load order: {}",
                                 path_to_string(&self.inner, &path_from_next_node)
@@ -662,7 +662,7 @@ impl<'a, T: SortingPlugin> PluginsGraph<'a, T> {
         new_load_order.insert(insert_position, node_index);
         processed_nodes.insert(node_index);
 
-        if log_enabled!(log::Level::Debug) {
+        if is_log_enabled(LogLevel::Debug) {
             if let Some(next_node_index) = new_load_order.get(insert_position + 1) {
                 logging::debug!(
                     "The plugin \"{}\" loads before \"{}\" in the new load order.",
@@ -993,6 +993,17 @@ fn get_plugins_in_groups<T: SortingPlugin>(
         plugins_in_groups.entry(group_name).or_default().push(node);
     }
 
+    if is_log_enabled(LogLevel::Debug) {
+        logging::debug!("Found the following plugins in groups:");
+        for (key, value) in &plugins_in_groups {
+            let plugin_names: Vec<_> = value
+                .iter()
+                .map(|i| format!("\"{}\"", graph[*i].name()))
+                .collect();
+            logging::debug!("\t{}: {}", key, plugin_names.join(", "));
+        }
+    }
+
     plugins_in_groups
 }
 
@@ -1099,22 +1110,23 @@ impl<'a, 'b, 'c, 'd, 'e, T: SortingPlugin> GroupsPathVisitor<'a, 'b, 'c, 'd, 'e,
 
         for to_plugin in to_plugins {
             if !self.plugins_graph.is_path_cached(from_plugin, *to_plugin) {
+                let involves_user_metadata = path_involves_user_metadata
+                    || self.plugins_graph[from_plugin].group_is_user_metadata
+                    || self.plugins_graph[*to_plugin].group_is_user_metadata;
+
+                let edge_type = if involves_user_metadata {
+                    EdgeType::UserGroup
+                } else {
+                    EdgeType::MasterlistGroup
+                };
+
                 if !self.plugins_graph.path_exists(*to_plugin, from_plugin) {
-                    let involves_user_metadata = path_involves_user_metadata
-                        || self.plugins_graph[from_plugin].group_is_user_metadata
-                        || self.plugins_graph[*to_plugin].group_is_user_metadata;
-
-                    let edge_type = if involves_user_metadata {
-                        EdgeType::UserGroup
-                    } else {
-                        EdgeType::MasterlistGroup
-                    };
-
                     self.plugins_graph
                         .add_edge(from_plugin, *to_plugin, edge_type);
                 } else {
                     logging::debug!(
-                        "Skipping group edge from \"{}\" to \"{}\" as it would create a cycle.",
+                        "Skipping a \"{}\" edge from \"{}\" to \"{}\" as it would create a cycle.",
+                        edge_type,
                         self.plugins_graph[from_plugin].name(),
                         self.plugins_graph[*to_plugin].name()
                     );
@@ -1153,10 +1165,30 @@ impl<'e, T: SortingPlugin> DfsVisitor<'e> for GroupsPathVisitor<'_, '_, '_, '_,
     }
 
     fn visit_forward_or_cross_edge(&mut self, edge_ref: EdgeReference<'e, EdgeType>) {
-        // Mark the source vertex as unfinishable, because none of the plugins in
-        // in the path so far can have edges added to plugins past the target
-        // vertex.
-        self.unfinishable_nodes.insert(edge_ref.source());
+        // Mark the source vertex and all edges in the current stack as
+        // unfinishable, because none of the plugins in the path so far can have
+        // edges added to plugins past the target vertex.
+
+        logging::debug!(
+            "Found groups graph forward or cross \"{}\" edge going from \"{}\" to \"{}\"",
+            edge_ref.weight(),
+            self.groups_graph[edge_ref.source()],
+            self.groups_graph[edge_ref.target()]
+        );
+
+        let iter = self
+            .edge_stack
+            .iter()
+            .map(|e| e.0.source())
+            .chain(std::iter::once(edge_ref.source()));
+
+        for source in iter {
+            let inserted = self.unfinishable_nodes.insert(source);
+
+            if inserted {
+                logging::debug!("Treating \"{}\" as unfinishable", self.groups_graph[source]);
+            }
+        }
     }
 
     fn visit_back_edge(&mut self, _: EdgeReference<'e, EdgeType>) {}
@@ -1170,7 +1202,13 @@ impl<'e, T: SortingPlugin> DfsVisitor<'e> for GroupsPathVisitor<'_, '_, '_, '_,
         if self.group_node_to_ignore_as_source != Some(node_index)
             && !self.unfinishable_nodes.contains(&node_index)
         {
-            self.finished_group_vertices.insert(node_index);
+            let inserted = self.finished_group_vertices.insert(node_index);
+            if inserted {
+                logging::debug!(
+                    "Recorded groups graph vertex \"{}\" as finished",
+                    self.groups_graph[node_index]
+                );
+            }
         }
 
         // Since this vertex has been fully explored, pop the edge stack to remove
@@ -2760,6 +2798,57 @@ mod tests {
 
                 assert!(graph.check_for_cycles().is_ok());
             }
+
+            #[test]
+            fn should_mark_nodes_as_unfinishable_if_a_node_in_their_subtree_is_unfinishable() {
+                let fixture = Fixture::with_plugins(&[
+                    PLUGIN_A, PLUGIN_B, PLUGIN_B1, PLUGIN_B2, PLUGIN_C, PLUGIN_D,
+                ]);
+
+                let groups_graph = build_groups_graph(
+                    &[
+                        Group::new("A".into()),
+                        Group::new("B".into()).with_after_groups(vec!["A".into()]),
+                        Group::new("C".into()).with_after_groups(vec!["B".into()]),
+                        Group::new("D".into()).with_after_groups(vec!["C".into()]),
+                        Group::default(),
+                    ],
+                    &[
+                        Group::new("BU1".into()).with_after_groups(vec!["B".into()]),
+                        Group::new("BU2".into()).with_after_groups(vec!["BU1".into()]),
+                        Group::new("C".into()).with_after_groups(vec!["BU2".into()]),
+                    ],
+                )
+                .unwrap();
+
+                let mut graph = PluginsGraph::<TestPlugin>::new();
+                let a = graph.add_node(fixture.group_sorting_data(PLUGIN_A, "A"));
+                let b = graph.add_node(fixture.group_sorting_data(PLUGIN_B, "B"));
+                let b1 = graph.add_node(fixture.group_sorting_data(PLUGIN_B1, "BU1"));
+                let b2 = graph.add_node(fixture.group_sorting_data(PLUGIN_B2, "BU2"));
+                let c = graph.add_node(fixture.group_sorting_data(PLUGIN_C, "C"));
+                let d = graph.add_node(fixture.group_sorting_data(PLUGIN_D, "D"));
+
+                graph.add_group_edges(&groups_graph).unwrap();
+
+                // Should be A.esp -> B.esp -----------------------> C.esp -> D.esp
+                //                          -> BU1.esp -> BU2.esp ->
+                assert!(graph.inner.contains_edge(a, b));
+                assert!(graph.inner.contains_edge(a, c));
+                assert!(graph.inner.contains_edge(a, d));
+                assert!(graph.inner.contains_edge(b, c));
+                assert!(graph.inner.contains_edge(b, d));
+                assert!(graph.inner.contains_edge(b, b1));
+                assert!(graph.inner.contains_edge(b, b2));
+                assert!(graph.inner.contains_edge(b1, b2));
+                assert!(graph.inner.contains_edge(b1, c));
+                assert!(graph.inner.contains_edge(b1, d));
+                assert!(graph.inner.contains_edge(b2, c));
+                assert!(graph.inner.contains_edge(b2, c));
+                assert!(graph.inner.contains_edge(c, d));
+
+                assert!(graph.check_for_cycles().is_ok());
+            }
         }
 
         mod add_overlap_edges {