From 0b1dbd7925e243958e54199ed9b3df4535bbe2a8 Mon Sep 17 00:00:00 2001 From: Meik Date: Thu, 16 Jul 2026 12:42:37 +0200 Subject: [PATCH] Add NTFS automatic ensure timeout diagnostics --- LiamNtfs/C4IT.LIAM.Ntfs.cs | 28 ++++ LiamNtfs/C4IT_IAM_SET/DataArea_FileSystem.cs | 53 +++++++ LiamWorkflowActivities/LiamWorkflowRuntime.cs | 132 ++++++++++++++++-- 3 files changed, 201 insertions(+), 12 deletions(-) diff --git a/LiamNtfs/C4IT.LIAM.Ntfs.cs b/LiamNtfs/C4IT.LIAM.Ntfs.cs index ccf5470..062a311 100644 --- a/LiamNtfs/C4IT.LIAM.Ntfs.cs +++ b/LiamNtfs/C4IT.LIAM.Ntfs.cs @@ -1146,7 +1146,17 @@ namespace C4IT.LIAM bool ensureTraverseGroups = false, bool whatIf = false) { + var stopwatch = Stopwatch.StartNew(); + LogEntry( + $"NTFS permission ensure provider start. Stage=Start Path='{folderPath}', AllowSharePathEnsure={allowSharePathEnsure}, EnsureTraverseGroups={ensureTraverseGroups}, WhatIf={whatIf}", + LogLevels.Debug); + + LogEntry($"NTFS permission ensure provider stage. Stage=Classify Path='{folderPath}'", LogLevels.Debug); var classification = ClassifyPath(folderPath); + LogEntry( + $"NTFS permission ensure provider stage finished. Stage=Classify Path='{folderPath}', PathKind='{classification?.Kind}', NormalizedPath='{classification?.NormalizedPath}', Elapsed='{stopwatch.Elapsed}'", + LogLevels.Debug); + var allowShareKinds = allowSharePathEnsure; if (!IsSupportedPermissionManagedPathKind( classification, @@ -1165,6 +1175,7 @@ namespace C4IT.LIAM string matchingConfigurationKey; string matchingRule; + LogEntry($"NTFS permission ensure provider stage. Stage=Blacklist Path='{folderPath}'", LogLevels.Debug); if (IsPathBlacklisted(classification, out matchingConfigurationKey, out matchingRule)) { return Task.FromResult(new ResultToken(System.Reflection.MethodBase.GetCurrentMethod().ToString()) @@ -1174,6 +1185,7 @@ namespace C4IT.LIAM }); } + LogEntry($"NTFS permission ensure provider stage. Stage=Whitelist Path='{folderPath}'", LogLevels.Debug); if (!IsPathWhitelisted(classification, false, out matchingConfigurationKey, out matchingRule)) { return Task.FromResult(new ResultToken(System.Reflection.MethodBase.GetCurrentMethod().ToString()) @@ -1184,6 +1196,7 @@ namespace C4IT.LIAM } string levelSkipReason; + LogEntry($"NTFS permission ensure provider stage. Stage=LevelRange Path='{folderPath}'", LogLevels.Debug); if (!IsPermissionLevelManagedPath(classification, out levelSkipReason)) { return Task.FromResult(new ResultToken(System.Reflection.MethodBase.GetCurrentMethod().ToString()) @@ -1193,7 +1206,13 @@ namespace C4IT.LIAM }); } + LogEntry($"NTFS permission ensure provider stage. Stage=ParentPath Path='{folderPath}'", LogLevels.Debug); var parentPath = Directory.GetParent(folderPath)?.FullName; + LogEntry( + $"NTFS permission ensure provider stage finished. Stage=ParentPath Path='{folderPath}', ParentPath='{parentPath}', Elapsed='{stopwatch.Elapsed}'", + LogLevels.Debug); + + LogEntry($"NTFS permission ensure provider stage. Stage=CreateFilesystemEngine Path='{folderPath}'", LogLevels.Debug); var engine = CreateFilesystemEngine( folderPath, parentPath, @@ -1202,6 +1221,9 @@ namespace C4IT.LIAM readerSids, writerSids); engine.WhatIf = whatIf; + LogEntry( + $"NTFS permission ensure provider stage finished. Stage=CreateFilesystemEngine Path='{folderPath}', Elapsed='{stopwatch.Elapsed}'", + LogLevels.Debug); var allowTraverseGroups = ensureTraverseGroups && IsSupportedPermissionManagedPathKind( @@ -1209,7 +1231,13 @@ namespace C4IT.LIAM eNtfsPathKind.Folder, eNtfsPathKind.ClassicShare, eNtfsPathKind.DfsLink); + LogEntry( + $"NTFS permission ensure provider stage. Stage=EngineEnsureDataAreaPermissions Path='{folderPath}', AllowTraverseGroups={allowTraverseGroups}", + LogLevels.Debug); var resultToken = engine.ensureDataAreaPermissions(allowTraverseGroups); + LogEntry( + $"NTFS permission ensure provider finished. Stage=EngineEnsureDataAreaPermissions Path='{folderPath}', ResultErrorId={resultToken?.resultErrorId}, ResultMessage='{resultToken?.resultMessage ?? string.Empty}', Elapsed='{stopwatch.Elapsed}'", + LogLevels.Debug); if (!allowTraverseGroups && ensureTraverseGroups) resultToken.warnings.Add($"Traverse groups are currently only ensured for folder and share paths. Traverse processing was skipped for '{folderPath}'."); diff --git a/LiamNtfs/C4IT_IAM_SET/DataArea_FileSystem.cs b/LiamNtfs/C4IT_IAM_SET/DataArea_FileSystem.cs index 20b4285..37e3e29 100644 --- a/LiamNtfs/C4IT_IAM_SET/DataArea_FileSystem.cs +++ b/LiamNtfs/C4IT_IAM_SET/DataArea_FileSystem.cs @@ -352,43 +352,90 @@ namespace C4IT_IAM_SET public ResultToken ensureDataAreaPermissions(bool ensureTraverseGroups = false) { LogMethodBegin(MethodBase.GetCurrentMethod()); + var stopwatch = Stopwatch.StartNew(); try { + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions start. Stage=Start Path='{newFolderPath}', BaseFolder='{baseFolder}', EnsureTraverseGroups={ensureTraverseGroups}, WhatIf={WhatIf}"); + var resultToken = checkRequiredVariablesForEnsure(); if (resultToken.resultErrorId != 0) return resultToken; + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions stage. Stage=NetworkConnection Path='{newFolderPath}', BaseFolder='{baseFolder}'"); + if (Connection != null) Connection.Dispose(); using (Connection = new cNetworkConnection(baseFolder, username, new NetworkCredential("", password).Password)) { + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions stage finished. Stage=NetworkConnection Path='{newFolderPath}', Elapsed='{stopwatch.Elapsed}'"); + + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions stage. Stage=DirectoryExists Path='{newFolderPath}'"); if (!Directory.Exists(newFolderPath)) { resultToken.resultErrorId = 30203; resultToken.resultMessage = "Verzeichnis existiert nicht"; return resultToken; } + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions stage finished. Stage=DirectoryExists Path='{newFolderPath}', Elapsed='{stopwatch.Elapsed}'"); + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions stage. Stage=InitializeFolderContext Path='{newFolderPath}'"); var parentDirectory = Directory.GetParent(newFolderPath); if (string.IsNullOrWhiteSpace(newFolderParent)) newFolderParent = parentDirectory?.FullName; InitializeFolderContext(); + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions stage finished. Stage=InitializeFolderContext Path='{newFolderPath}', ParentPath='{newFolderParent}', Elapsed='{stopwatch.Elapsed}'"); + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions stage. Stage=ValidateTraverseBoundary Path='{newFolderPath}'"); var traverseBoundaryResult = ValidateTraverseBoundaryForCurrentFolder(); if (traverseBoundaryResult.resultErrorId != 0) return traverseBoundaryResult; + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions stage finished. Stage=ValidateTraverseBoundary Path='{newFolderPath}', Elapsed='{stopwatch.Elapsed}'"); + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions stage. Stage=EnsureADGroups Path='{newFolderPath}'"); ensureADGroups(resultToken); + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions stage finished. Stage=EnsureADGroups Path='{newFolderPath}', CreatedGroups={resultToken.createdGroups.Count}, ReusedGroups={resultToken.reusedGroups.Count}, Warnings={resultToken.warnings.Count}, Elapsed='{stopwatch.Elapsed}'"); + + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions stage. Stage=EnsureFolderPermissions Path='{newFolderPath}'"); resultToken = ensureFolderPermissions(resultToken); + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions stage finished. Stage=EnsureFolderPermissions Path='{newFolderPath}', ResultErrorId={resultToken.resultErrorId}, AddedAcls={resultToken.addedAclEntries.Count}, SkippedAcls={resultToken.skippedAclEntries.Count}, Elapsed='{stopwatch.Elapsed}'"); if (resultToken.resultErrorId != 0) return resultToken; if (ensureTraverseGroups) { + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions stage. Stage=SetTraversePermissions Path='{newFolderPath}'"); var traverseResult = SetTraversePermissions(); if (traverseResult != null) { @@ -405,11 +452,17 @@ namespace C4IT_IAM_SET return resultToken; } } + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions stage finished. Stage=SetTraversePermissions Path='{newFolderPath}', TraverseGroups={resultToken.ensuredTraverseGroups.Count}, AddedAcls={resultToken.addedAclEntries.Count}, Elapsed='{stopwatch.Elapsed}'"); } resultToken.resultMessage = WhatIf ? "Gruppen- und ACL-Vorschau erfolgreich erstellt" : "Gruppen und ACLs erfolgreich sichergestellt"; + DefaultLogger.LogEntry( + LogLevels.Debug, + $"NTFS engine ensure permissions finished. Stage=Finished Path='{newFolderPath}', ResultErrorId={resultToken.resultErrorId}, ResultMessage='{resultToken.resultMessage}', Elapsed='{stopwatch.Elapsed}'"); return resultToken; } } diff --git a/LiamWorkflowActivities/LiamWorkflowRuntime.cs b/LiamWorkflowActivities/LiamWorkflowRuntime.cs index d1c232f..23a1c2f 100644 --- a/LiamWorkflowActivities/LiamWorkflowRuntime.cs +++ b/LiamWorkflowActivities/LiamWorkflowRuntime.cs @@ -5,6 +5,7 @@ using C4IT_IAM_Engine; using LiamAD; using System; using System.Collections.Generic; +using System.Globalization; using System.IO; using System.Linq; using System.Threading.Tasks; @@ -77,6 +78,9 @@ namespace LiamWorkflowActivities public static class LiamWorkflowRuntime { + private const string AutomaticNtfsEnsureTimeoutSecondsKey = "NtfsAutomaticEnsureTimeoutSeconds"; + private const int DefaultAutomaticNtfsEnsureTimeoutSeconds = 300; + public static async Task GetDataAreasFromProviderAsync(cLiamProviderBase provider, string configurationId = null, bool? simulateConfiguredNtfsPermissionEnsure = null) { var result = new GetDataAreasOperationResult(); @@ -422,11 +426,19 @@ namespace LiamWorkflowActivities var allowFolderEnsure = IsAdditionalConfigurationEnabled(provider, "EnsureNtfsPermissionGroups"); var allowSharePathEnsure = IsAdditionalConfigurationEnabled(provider, "EnsureNtfsPermissionGroupsForShares"); var allowTraverseEnsure = IsAdditionalConfigurationEnabled(provider, "EnsureNtfsTraverseGroups"); + var ensureTimeoutSeconds = GetAdditionalConfigurationInt32( + provider, + AutomaticNtfsEnsureTimeoutSecondsKey, + DefaultAutomaticNtfsEnsureTimeoutSeconds, + 0); + var ensureTimeout = ensureTimeoutSeconds > 0 + ? TimeSpan.FromSeconds(ensureTimeoutSeconds) + : TimeSpan.Zero; if (!allowFolderEnsure && !allowSharePathEnsure && !allowTraverseEnsure) return true; LogEntry( - $"Automatic NTFS ensure configured. PermissionGroups={allowFolderEnsure}, PermissionGroupsForShares={allowSharePathEnsure}, TraverseGroups={allowTraverseEnsure}, DataAreas={dataAreas.Count}, WhatIf={simulateOnly}", + $"Automatic NTFS ensure configured. PermissionGroups={allowFolderEnsure}, PermissionGroupsForShares={allowSharePathEnsure}, TraverseGroups={allowTraverseEnsure}, DataAreas={dataAreas.Count}, WhatIf={simulateOnly}, TimeoutSeconds={ensureTimeoutSeconds}", LogLevels.Debug); if (allowFolderEnsure || allowSharePathEnsure) @@ -449,15 +461,19 @@ namespace LiamWorkflowActivities ResultToken ensureResult; try { - ensureResult = await ntfsProvider.EnsureMissingPermissionGroupsAsync( + ensureResult = await RunAutomaticNtfsEnsureOperationAsync( folderPath, - null, - null, - null, - null, - allowSharePathEnsure, - ensureTraverseInPermissionPhase, - simulateOnly); + "permission group ensure", + () => ntfsProvider.EnsureMissingPermissionGroupsAsync( + folderPath, + null, + null, + null, + null, + allowSharePathEnsure, + ensureTraverseInPermissionPhase, + simulateOnly), + ensureTimeout); } catch (Exception ex) { @@ -477,6 +493,12 @@ namespace LiamWorkflowActivities if (ensureResult.resultErrorId != 0) { + if (IsAutomaticNtfsEnsureTimeout(ensureResult)) + { + SetAutomaticEnsureTimeoutError(result, folderPath, ensureResult, "permission group ensure"); + return false; + } + LogEntry( $"Automatic NTFS permission group ensure skipped for '{folderPath}' after resultErrorId={ensureResult.resultErrorId}. ResultMessage='{ensureResult.resultMessage ?? string.Empty}'", LogLevels.Warning); @@ -514,10 +536,14 @@ namespace LiamWorkflowActivities ResultToken ensureResult; try { - ensureResult = await ntfsProvider.EnsureTraverseGroupsAsync( + ensureResult = await RunAutomaticNtfsEnsureOperationAsync( folderPath, - null, - simulateOnly); + "traverse group ensure", + () => ntfsProvider.EnsureTraverseGroupsAsync( + folderPath, + null, + simulateOnly), + ensureTimeout); } catch (Exception ex) { @@ -537,6 +563,12 @@ namespace LiamWorkflowActivities if (ensureResult.resultErrorId != 0) { + if (IsAutomaticNtfsEnsureTimeout(ensureResult)) + { + SetAutomaticEnsureTimeoutError(result, folderPath, ensureResult, "traverse group ensure"); + return false; + } + LogEntry( $"Automatic NTFS traverse group ensure skipped for '{folderPath}' after resultErrorId={ensureResult.resultErrorId}. ResultMessage='{ensureResult.resultMessage ?? string.Empty}'", LogLevels.Warning); @@ -557,6 +589,55 @@ namespace LiamWorkflowActivities return true; } + private static async Task RunAutomaticNtfsEnsureOperationAsync( + string folderPath, + string operationLabel, + Func> operation, + TimeSpan timeout) + { + var operationTask = Task.Run(operation); +#pragma warning disable 4014 + // Fire-and-forget observer for exceptions that happen after a timeout. + operationTask.ContinueWith( + task => LogException(task.Exception), + TaskContinuationOptions.OnlyOnFaulted); +#pragma warning restore 4014 + + if (timeout <= TimeSpan.Zero) + return await operationTask; + + var completedTask = await Task.WhenAny(operationTask, Task.Delay(timeout)); + if (completedTask == operationTask) + return await operationTask; + + var message = + $"Automatic NTFS {operationLabel} timed out for '{folderPath}' after {timeout.TotalSeconds:F0}s. " + + "The workflow will stop automatic NTFS ensure processing for this run. " + + "The underlying NTFS/AD operation may still finish in the worker process."; + LogEntry(message, LogLevels.Error); + return new ResultToken("AutomaticNtfsEnsureTimeout") + { + resultErrorId = 30010, + resultMessage = message + }; + } + + private static bool IsAutomaticNtfsEnsureTimeout(ResultToken ensureResult) + { + return ensureResult?.resultErrorId == 30010; + } + + private static void SetAutomaticEnsureTimeoutError( + GetDataAreasOperationResult result, + string folderPath, + ResultToken ensureResult, + string operationLabel) + { + result.ErrorCode = "WF_GET_DATAAREAS_ENSURE_NTFS_GROUPS_TIMEOUT"; + result.ErrorMessage = ensureResult?.resultMessage + ?? $"Automatic NTFS {operationLabel} timed out for '{folderPath}'."; + } + private static NtfsAutomaticEnsurePreviewEntry MapAutomaticEnsurePreview(string folderPath, ResultToken ensureResult) { return new NtfsAutomaticEnsurePreviewEntry @@ -662,6 +743,33 @@ namespace LiamWorkflowActivities || rawValue.Equals("yes", StringComparison.OrdinalIgnoreCase); } + private static int GetAdditionalConfigurationInt32(cLiamProviderBase provider, string key, int defaultValue, int minValue) + { + if (provider?.AdditionalConfiguration == null || string.IsNullOrWhiteSpace(key)) + return defaultValue; + + if (!provider.AdditionalConfiguration.TryGetValue(key, out var rawValue) || string.IsNullOrWhiteSpace(rawValue)) + return defaultValue; + + if (!int.TryParse(rawValue.Trim(), NumberStyles.Integer, CultureInfo.InvariantCulture, out var parsedValue)) + { + LogEntry( + $"AdditionalConfiguration '{key}' has invalid integer value '{rawValue}'. Defaulting to {defaultValue}.", + LogLevels.Warning); + return defaultValue; + } + + if (parsedValue < minValue) + { + LogEntry( + $"AdditionalConfiguration '{key}' value {parsedValue} is below minimum {minValue}. Defaulting to {defaultValue}.", + LogLevels.Warning); + return defaultValue; + } + + return parsedValue; + } + private static bool IsWorkflowWhatIfEnabled(cLiamProviderBase provider) { return IsAdditionalConfigurationEnabled(provider, "WhatIf");