Add NTFS automatic ensure timeout diagnostics

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}'.");
 

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;
                 }
             }