Understanding DFSR debug logging (Part 11: Directory created on Windows Server 2003 R2)

In this scenario we will see a folder added and how that change is replicated between servers. This is useful to understand in order to troubleshoot issues where problems within the USN journal, the DFSR JET database, and the network (including RPC) are preventing replication from working correctly.  

 

(addedfolderupstream – Dfsr00006 – 2003.log and addedfolderdownstream – Dfsr00007 – 2003.log)

 

These are two Windows Server 2003 servers called 2003MEM01 and 2003MEM02 in the contoso.com domain. The logs are from 2003MEM01 where the folder is created (upstream) and from 2003MEM02 where it the creation is replicated (downstream). Both servers are participating in the TESTRG2 replication group for the TESTRF2 replicated folder. The folder was called “subfolder”.

 

<Upstream> 20080627 10:34:47.983  692 LDBX  3567 Ldb::Insert Inserting idRecord: ß the DFSR database is being updated upstream

+       fid               0x1000000002FF8 ß note the file ID. This useful for cross referencing with USN updates in the log

+       usn               0xb6370

+       uidVisible        0

+       filtered          0

+       journalWrapped    0

+       slowRecoverCheck  0

+       pendingTombstone  0

+       recUpdateTime     16010101 00:00:00.000 GMT

+       present           1

+       nameConflict      0

+       attributes        0x10 ß marks the object as a folder, not a file

+       gvsn              {B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v30

+       uid               {B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v30 ß UID and GVSN match, this shows the change as an original creation on the upstream server

+       parent            {5666BB91-265D-42E8-9F57-1B49F4E581B7}-v1

+       fence             16010101 00:00:00.000

+       clock             20080627 14:34:47.983

+       createTime        20080627 14:34:47.983 GMT

+       csId              {5666BB91-265D-42E8-9F57-1B49F4E581B7}

+       hash              00000000-00000000-00000000-00000000

+       similarity        00000000-00000000-00000000-00000000

+       name              subfolder ß the folder is named ‘subfolder’

+      

<Upstream> 20080627 10:34:48.043  692 USNC  2448 UsnConsumer::CreateNewRecord ID record created from USN_RECORD: ß the USN journal has been updated. Note that this actually occurred before the database being updated, it is just a log idiosyncrasy that the debug log entry occurs later.

+       USN_RECORD:

+       RecordLength:        80

+       MajorVersion:        2

+       MinorVersion:        0

+       FileRefNumber:       0x1000000002ff8 ß note that File ID is the same as above

+       ParentFileRefNumber: 0x1000000002f92

+       USN:                 0xb6370

+       TimeStamp:           20080627 10:34:47.983 Eastern Standard Time

+       Reason:              Close Rename New Name ß the folder object is newly created.

+       SourceInfo:          0x0

+       SecurityId:          0x1af

+       FileAttributes:      0x10 ß it’s a folder, not a file

+       FileNameLength:      18

+       FileNameOffset:      60

+       FileName:            subfolder ß named ‘subfolder’

+      

<Upstream> 20080627 10:34:48.043  692 LDBX  4083 Ldb::InsertWalkerJob Inserting dirWalkerJob:uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v30 moveType:MoveIn (1) at time:20080627 14:34:47.983 ß a DirWalker job is created. Dirwalker checks that when a folder is created, what sub folders/files it contains.

<Upstream> 20080627 10:34:48.063  692 LDBX  1228 LdbManager::UpdateVersionVectorCache Wake up callback 00ADF8C0

<Upstream> 20080627 10:34:48.063  692 DIRW   511 DirWalkerTask::QueueMoveinJob Queuing move-in. uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v30 fid:0x1000000002FF8 name:subfolder ß the dirwalker job is queued for running

<Upstream> 20080627 10:34:48.063  172 DIRW   256 DirWalkerTask::Run Start walking directory. ß the dirwalker job runs

<Upstream> 20080627 10:34:48.063  172 DIRW   937 DirWalkerTask::MoveinStep Starting to process move-in job. uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v30 ß the results of the dirwalker job are evaluated