Windows: additional trace logging for afsredirlib

A large number of addition trace log entries were added
to assist in diagnosing problems in the dir entry processing.

Change-Id: I85cab4d66680eb5b9c00843c49c33a81acb18bc2
Reviewed-on: http://gerrit.openafs.org/5739
Reviewed-by: Rod Widdowson <rdw@steadingsoftware.com>
Tested-by: BuildBot <buildbot@rampaginggeek.com>
Tested-by: Jeffrey Altman <jaltman@secure-endpoints.com>
Reviewed-by: Jeffrey Altman <jaltman@secure-endpoints.com>

diff --git a/src/WINNT/afsrdr/kernel/lib/AFSBTreeSupport.cpp b/src/WINNT/afsrdr/kernel/lib/AFSBTreeSupport.cpp
index a870045..5320e7e 100644 (file)
--- a/src/WINNT/afsrdr/kernel/lib/AFSBTreeSupport.cpp
+++ b/src/WINNT/afsrdr/kernel/lib/AFSBTreeSupport.cpp
@@ -368,11 +368,10 @@ AFSInsertCaseSensitiveDirEntry( IN AFSDirectoryCB *RootNode,
             {
 
                 AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
-                              AFS_TRACE_LEVEL_WARNING,
-                              "AFSInsertCaseSensitiveDirEntry Attempt to re-insert a CRC %I64X\n",
-                              DirEntry->CaseSensitiveTreeEntry.HashIndex);
-
-                ASSERT( FALSE);
+                              AFS_TRACE_LEVEL_VERBOSE,
+                              "AFSInsertCaseSensitiveDirEntry Collision with DE %p for %wZ\n",
+                              pCurrentEntry,
+                              &pCurrentEntry->NameInformation.FileName);
 
                 ntStatus = STATUS_UNSUCCESSFUL;
 
@@ -1084,6 +1083,13 @@ AFSInsertShortNameDirEntry( IN AFSDirectoryCB *RootNode,
             else
             {
 
+                AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
+                              AFS_TRACE_LEVEL_VERBOSE,
+                              "AFSInsertShortNameDirEntry Collision with DE %p for shortname %S and %wZ\n",
+                              pCurrentEntry,
+                              pCurrentEntry->NameInformation.ShortName,
+                              &pCurrentEntry->NameInformation.FileName);
+
                 break;
             }
         }

diff --git a/src/WINNT/afsrdr/kernel/lib/AFSCleanup.cpp b/src/WINNT/afsrdr/kernel/lib/AFSCleanup.cpp
index 554b1aa..c56faf4 100644 (file)
--- a/src/WINNT/afsrdr/kernel/lib/AFSCleanup.cpp
+++ b/src/WINNT/afsrdr/kernel/lib/AFSCleanup.cpp
@@ -417,6 +417,12 @@ AFSCleanup( IN PDEVICE_OBJECT LibDeviceObject,
                             AFSAcquireExcl( pObjectInfo->ParentObjectInformation->Specific.Directory.DirectoryNodeHdr.TreeLock,
                                             TRUE);
 
+                            AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
+                                          AFS_TRACE_LEVEL_VERBOSE,
+                                          "AFSCleanup DE %p for %wZ removing entry\n",
+                                          pCcb->DirectoryCB,
+                                          &pCcb->DirectoryCB->NameInformation.FileName);
+
                             AFSRemoveNameEntry( pObjectInfo->ParentObjectInformation,
                                                 pCcb->DirectoryCB);
 

diff --git a/src/WINNT/afsrdr/kernel/lib/AFSCommSupport.cpp b/src/WINNT/afsrdr/kernel/lib/AFSCommSupport.cpp
index 98049c5..c5d380c 100644 (file)
--- a/src/WINNT/afsrdr/kernel/lib/AFSCommSupport.cpp
+++ b/src/WINNT/afsrdr/kernel/lib/AFSCommSupport.cpp
@@ -717,6 +717,46 @@ AFSVerifyDirectoryContent( IN AFSObjectInfoCB *ObjectInfoCB,
 
                             SetFlag( pDirNode->Flags, AFS_DIR_ENTRY_VALID);
 
+                            if( pCurrentDirEntry->ShortNameLength > 0 &&
+                                pDirNode->NameInformation.ShortNameLength > 0)
+                            {
+                                AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
+                                              AFS_TRACE_LEVEL_VERBOSE,
+                                              "AFSVerifyDirectoryContent Verified entry %wZ (%wZ) old short name %S New short name %S\n",
+                                              &uniDirName,
+                                              &pDirNode->NameInformation.FileName,
+                                              pDirNode->NameInformation.ShortName,
+                                              pCurrentDirEntry->ShortName);
+                            }
+                            else if( pCurrentDirEntry->ShortNameLength == 0 &&
+                                     pDirNode->NameInformation.ShortNameLength > 0)
+                            {
+                                AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
+                                              AFS_TRACE_LEVEL_VERBOSE,
+                                              "AFSVerifyDirectoryContent Verified entry %wZ (%wZ) old short name %S New short name NULL\n",
+                                              &uniDirName,
+                                              &pDirNode->NameInformation.FileName,
+                                              pDirNode->NameInformation.ShortName);
+                            }
+                            else if( pCurrentDirEntry->ShortNameLength > 0 &&
+                                     pDirNode->NameInformation.ShortNameLength == 0)
+                            {
+                                AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
+                                              AFS_TRACE_LEVEL_VERBOSE,
+                                              "AFSVerifyDirectoryContent Verified entry %wZ (%wZ) old short name NULL New short name %S\n",
+                                              &uniDirName,
+                                              &pDirNode->NameInformation.FileName,
+                                              pCurrentDirEntry->ShortName);
+                            }
+                            else
+                            {
+                                AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
+                                              AFS_TRACE_LEVEL_VERBOSE,
+                                              "AFSVerifyDirectoryContent Verified entry %wZ (%wZ) old short name NULL New short name NULL\n",
+                                              &uniDirName,
+                                              &pDirNode->NameInformation.FileName);
+                            }
+
                             AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
                                           AFS_TRACE_LEVEL_VERBOSE,
                                           "AFSVerifyDirectoryContent Verified entry %wZ for parent FID %08lX-%08lX-%08lX-%08lX\n",
@@ -777,7 +817,8 @@ AFSVerifyDirectoryContent( IN AFSObjectInfoCB *ObjectInfoCB,
 
                     AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
                                   AFS_TRACE_LEVEL_VERBOSE,
-                                  "AFSVerifyDirectoryContent Processing dir entry %wZ with different FID, same name in parent FID %08lX-%08lX-%08lX-%08lX\n",
+                                  "AFSVerifyDirectoryContent Processing dir entry %p %wZ with different FID, same name in parent FID %08lX-%08lX-%08lX-%08lX\n",
+                                  pDirNode,
                                   &pDirNode->NameInformation.FileName,
                                   ObjectInfoCB->FileId.Cell,
                                   ObjectInfoCB->FileId.Volume,
@@ -793,12 +834,17 @@ AFSVerifyDirectoryContent( IN AFSObjectInfoCB *ObjectInfoCB,
 
                         AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
                                       AFS_TRACE_LEVEL_VERBOSE,
-                                      "AFSVerifyDirectoryContent Deleting dir entry %wZ from parent FID %08lX-%08lX-%08lX-%08lX\n",
+                                      "AFSVerifyDirectoryContent Different FIDs - Deleting DE %p for %wZ Old FID %08lX-%08lX-%08lX-%08lX New FID %08lX-%08lX-%08lX-%08lX\n",
+                                      pDirNode,
                                       &pDirNode->NameInformation.FileName,
                                       ObjectInfoCB->FileId.Cell,
                                       ObjectInfoCB->FileId.Volume,
                                       ObjectInfoCB->FileId.Vnode,
-                                      ObjectInfoCB->FileId.Unique);
+                                      ObjectInfoCB->FileId.Unique,
+                                      pCurrentDirEntry->FileId.Cell,
+                                      pCurrentDirEntry->FileId.Volume,
+                                      pCurrentDirEntry->FileId.Vnode,
+                                      pCurrentDirEntry->FileId.Unique);
 
                         AFSDeleteDirEntry( ObjectInfoCB,
                                            pDirNode);
@@ -806,17 +852,21 @@ AFSVerifyDirectoryContent( IN AFSObjectInfoCB *ObjectInfoCB,
                     else
                     {
 
+                        SetFlag( pDirNode->Flags, AFS_DIR_ENTRY_DELETED);
+
                         AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
                                       AFS_TRACE_LEVEL_VERBOSE,
-                                      "AFSVerifyDirectoryContent Setting dir entry %p name %wZ DELETED in parent FID %08lX-%08lX-%08lX-%08lX\n",
+                                      "AFSVerifyDirectoryContent Different FIDs - removing DE %p for %wZ Old FID %08lX-%08lX-%08lX-%08lX New FID %08lX-%08lX-%08lX-%08lX\n",
                                       pDirNode,
                                       &pDirNode->NameInformation.FileName,
                                       ObjectInfoCB->FileId.Cell,
                                       ObjectInfoCB->FileId.Volume,
                                       ObjectInfoCB->FileId.Vnode,
-                                      ObjectInfoCB->FileId.Unique);
-
-                        SetFlag( pDirNode->Flags, AFS_DIR_ENTRY_DELETED);
+                                      ObjectInfoCB->FileId.Unique,
+                                      pCurrentDirEntry->FileId.Cell,
+                                      pCurrentDirEntry->FileId.Volume,
+                                      pCurrentDirEntry->FileId.Vnode,
+                                      pCurrentDirEntry->FileId.Unique);
 
                         AFSRemoveNameEntry( ObjectInfoCB,
                                             pDirNode);
@@ -864,10 +914,13 @@ AFSVerifyDirectoryContent( IN AFSObjectInfoCB *ObjectInfoCB,
 
                     AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
                                   AFS_TRACE_LEVEL_VERBOSE,
-                                  "AFSVerifyDirectoryContent Initialized short name %wZ for DE %p for %wZ\n",
-                                  &uniShortName,
+                                  "AFSVerifyDirectoryContent NO short name for DE %p for %wZ FID %08lX-%08lX-%08lX-%08lX\n",
                                   pDirNode,
-                                  &pDirNode->NameInformation.FileName);
+                                  &pDirNode->NameInformation.FileName,
+                                  pCurrentDirEntry->FileId.Cell,
+                                  pCurrentDirEntry->FileId.Volume,
+                                  pCurrentDirEntry->FileId.Vnode,
+                                  pCurrentDirEntry->FileId.Unique);
                 }
 
                 //

diff --git a/src/WINNT/afsrdr/kernel/lib/AFSCreate.cpp b/src/WINNT/afsrdr/kernel/lib/AFSCreate.cpp
index 6340ebb..e9412e4 100644 (file)
--- a/src/WINNT/afsrdr/kernel/lib/AFSCreate.cpp
+++ b/src/WINNT/afsrdr/kernel/lib/AFSCreate.cpp
@@ -2016,6 +2016,13 @@ try_exit:
             if( bFileCreated)
             {
 
+                AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
+                              AFS_TRACE_LEVEL_VERBOSE,
+                              "AFSProcessCreate Create failed, removing DE %p from aprent object %p Status %08lX\n",
+                              pDirEntry,
+                              pParentObjectInfo,
+                              ntStatus);
+
                 //
                 // Remove the dir entry from the parent
                 //

diff --git a/src/WINNT/afsrdr/kernel/lib/AFSFileInfo.cpp b/src/WINNT/afsrdr/kernel/lib/AFSFileInfo.cpp
index fe93a6f..bc7967c 100644 (file)
--- a/src/WINNT/afsrdr/kernel/lib/AFSFileInfo.cpp
+++ b/src/WINNT/afsrdr/kernel/lib/AFSFileInfo.cpp
@@ -1946,6 +1946,13 @@ AFSSetRenameInfo( IN PIRP Irp)
                 try_return( ntStatus = STATUS_OBJECT_NAME_COLLISION);
             }
 
+            AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
+                          AFS_TRACE_LEVEL_ERROR,
+                          "AFSSetRenameInfo Target %wZ exists DE %p Count %08lX, performing delete of target\n",
+                          &pTargetDirEntry->NameInformation.FileName,
+                          pTargetDirEntry,
+                          pTargetDirEntry->OpenReferenceCount);
+
             bTargetEntryExists = TRUE;
         }
 
@@ -2292,6 +2299,12 @@ AFSSetRenameInfo( IN PIRP Irp)
 
             pSrcCcb->DirectoryCB->Type.Data.ShortNameTreeEntry.HashIndex = AFSGenerateCRC( &uniShortName,
                                                                                            TRUE);
+
+            AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
+                          AFS_TRACE_LEVEL_VERBOSE,
+                          "AFSSetRenameInfo Initialized short name hash for %wZ longname %wZ\n",
+                          &uniShortName,
+                          &pSrcCcb->DirectoryCB->NameInformation.FileName);
         }
         else
         {
@@ -2401,10 +2414,9 @@ AFSSetRenameInfo( IN PIRP Irp)
 
             AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
                           AFS_TRACE_LEVEL_VERBOSE,
-                          "AFSSetRenameInfo Setting DELETE flag in dir entry %p name %wZ to tmp %wZ\n",
+                          "AFSSetRenameInfo Setting DELETE flag in dir entry %p name %wZ\n",
                           pTargetDirEntry,
-                          &pTargetDirEntry->NameInformation.FileName,
-                          &uniTmpTargetName);
+                          &pTargetDirEntry->NameInformation.FileName);
 
             SetFlag( pTargetDirEntry->Flags, AFS_DIR_ENTRY_DELETED);
 
@@ -2432,7 +2444,7 @@ AFSSetRenameInfo( IN PIRP Irp)
 
                     AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
                                   AFS_TRACE_LEVEL_ERROR,
-                                  "AFSSetRenameInfo Failed to flush section for deleted temp file %wZ\n",
+                                  "AFSSetRenameInfo Failed to delete section for target file %wZ\n",
                                   &pTargetDirEntry->NameInformation.FileName);
                 }
 

diff --git a/src/WINNT/afsrdr/kernel/lib/AFSGeneric.cpp b/src/WINNT/afsrdr/kernel/lib/AFSGeneric.cpp
index 797f3f2..4251e74 100644 (file)
--- a/src/WINNT/afsrdr/kernel/lib/AFSGeneric.cpp
+++ b/src/WINNT/afsrdr/kernel/lib/AFSGeneric.cpp
@@ -3250,6 +3250,13 @@ AFSValidateDirectoryCache( IN AFSObjectInfoCB *ObjectInfo,
             {
 
                 ClearFlag( pCurrentDirEntry->Flags, AFS_DIR_ENTRY_VALID);
+
+                AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
+                              AFS_TRACE_LEVEL_VERBOSE,
+                              "AFSValidateDirectoryCache Clear VALID flag on DE %p Reference count %08lX\n",
+                              pCurrentDirEntry,
+                              pCurrentDirEntry->OpenReferenceCount);
+
             }
 
             pCurrentDirEntry = (AFSDirectoryCB *)pCurrentDirEntry->ListEntry.fLink;
@@ -3281,6 +3288,12 @@ AFSValidateDirectoryCache( IN AFSObjectInfoCB *ObjectInfo,
                 continue;
             }
 
+            AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
+                          AFS_TRACE_LEVEL_VERBOSE,
+                          "AFSValidateDirectoryCache Processing INVALID DE %p Reference count %08lX\n",
+                          pCurrentDirEntry,
+                          pCurrentDirEntry->OpenReferenceCount);
+
             if( pCurrentDirEntry->OpenReferenceCount == 0)
             {
 

diff --git a/src/WINNT/afsrdr/kernel/lib/AFSNameSupport.cpp b/src/WINNT/afsrdr/kernel/lib/AFSNameSupport.cpp
index a2aa32d..f4fad07 100644 (file)
--- a/src/WINNT/afsrdr/kernel/lib/AFSNameSupport.cpp
+++ b/src/WINNT/afsrdr/kernel/lib/AFSNameSupport.cpp
@@ -2106,7 +2106,7 @@ AFSInsertDirectoryNode( IN AFSObjectInfoCB *ParentObjectInfo,
 
             AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
                           AFS_TRACE_LEVEL_VERBOSE,
-                          "AFSInsertDirectoryNode Insert DE %p to case sensitive tree for %wZ\n",
+                          "AFSInsertDirectoryNode Insert DE %p to case insensitive tree for %wZ\n",
                           DirEntry,
                           &DirEntry->NameInformation.FileName);
         }
@@ -2293,6 +2293,12 @@ AFSRemoveDirNodeFromParent( IN AFSObjectInfoCB *ParentObjectInfo,
         if( !BooleanFlagOn( DirEntry->Flags, AFS_DIR_ENTRY_NOT_IN_PARENT_TREE))
         {
 
+            AFSDbgLogMsg( AFS_SUBSYSTEM_FILE_PROCESSING,
+                          AFS_TRACE_LEVEL_VERBOSE,
+                          "AFSRemoveDirNodeFromParent Removing DirEntry %08lX name %wZ\n",
+                          DirEntry,
+                          &DirEntry->NameInformation.FileName);
+
             AFSRemoveNameEntry( ParentObjectInfo,
                                 DirEntry);
         }