Understanding DFSR debug logging (Part 5: File Modified on Windows Server 2003 R2)

Understanding DFSR debug logging (Part 5: File Modified on Windows Server 2003 R2)

  • Comments 1
  • Likes

In this scenario we will see a file modified 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, the staging folder structure, and the network (including RPC) are preventing replication from working correctly.

(modifiedlargefileupstream - Dfsr00003 - 2003.log and modifiedlargefileupstream - Dfsr00003 - 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 file is created (upstream) and from 2003MEM02 where it is replicated (downstream). Both servers are participating in the TESTRG2 replication group for the TESTRF2 replicated folder. The file is called "setuplog.txt". The file was already staged previously.

<Upstream> 20080625 17:42:30.805 1244 LDBX 3684 Ldb::Update Updating idRecord: ß the file is modified upstream so we must update the Jet database +    fid 0x3000000002FBF
+    usn 0x68778
+    uidVisible 1
+    filtered 0
+    journalWrapped 0
+    slowRecoverCheck 0
+    pendingTombstone 0
+    recUpdateTime 20080625 21:33:05.008 GMT
+    present 1
+    nameConflict 0
+    attributes 0x20
+    gvsn {B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 ß GVSN is higher than UID from the same server (same GUID); it's been modified
+    uid {B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 ß file original version is this
+    parent {5666BB91-265D-42E8-9F57-1B49F4E581B7}-v1
+    fence 16010101 00:00:00.000
+    clock 20080625 21:42:30.805
+    createTime 20080625 21:27:21.734 GMT
+    csId {5666BB91-265D-42E8-9F57-1B49F4E581B7}
+    hash 00000000-00000000-00000000-00000000 ß because file has been modified we must discard old hash/similarity main checksums from the database
+    similarity 00000000-00000000-00000000-00000000
+    name setuplog.txt
+    
<Upstream> 20080625 17:42:30.805 1244 USNC 2202 UsnConsumer::UpdateIdRecord ID record updated from USN_RECORD: ß our existing USN journal record must be updated
+    USN_RECORD:
+    RecordLength: 88
+    MajorVersion: 2
+    MinorVersion: 0
+    FileRefNumber: 0x3000000002fbf
+    ParentFileRefNumber: 0x1000000002f92
+    USN: 0x68778
+    TimeStamp: 20080625 17:42:30.805 Eastern Standard Time
+    Reason: Close Data Extend Data Overwrite ß the file has been modified, where data was extended and the file was saved.
+    SourceInfo: 0x0
+    SecurityId: 0x1c7
+    FileAttributes: 0x20
+    FileNameLength: 24
+    FileNameOffset: 60
+    FileName: setuplog.txt
+    
<Upstream> 20080625 17:42:30.805 1244 LDBX 1228 LdbManager::UpdateVersionVectorCache Wake up callback 00ADF478
<Downstream> 20080625 17:42:30.836 2416 INCO 2761 InConnection::RequestVvUp Requested upstream version vector. requestState:00A86340 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} csName:testrf2 changeType:all
<Downstream> 20080625 17:42:30.836 2492 DOWN 2668 AsyncRpcHandler::ProcessReceive Completion. connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{00000000-0000-0000-0000-000000000000} reqType:AsyncPollRequest reqState:Completed status:0 ptr:00A8F4A0
<Downstream> 20080625 17:42:30.846 2492 DOWN 2668 AsyncRpcHandler::ProcessReceive Completion. connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} reqType:VvUpRequest reqState:Completed status:0 ptr:00A86340
<Downstream> 20080625 17:42:30.876 2492 INCO 2947 InConnection::ReceiveVvUp Received VvUp connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} csName:testrf2 vvUp:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6} |-> { 10..21} ß current version on downstream is 10; current on upstream is 21.
+    
<Downstream> 20080625 17:42:30.876 2492 INCO 2954 InConnection::ReceiveVvUp Creating new session:3 requestState:00A86340 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} csName:testrf2
<Downstream> 20080625 17:42:30.876 2416 INCO 3347 InConnection::RequestUpdates Requesting updates. credits:32 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} csName:testrf2 requestType:all cursor:{00000000-0000-0000-0000-000000000000}-v0 delta::{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6} |-> { 21} ß downstream server learns current version vector from upstream
+    
<Downstream> 20080625 17:42:30.876 2492 DOWN 2668 AsyncRpcHandler::ProcessReceive Completion. connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{00000000-0000-0000-0000-000000000000} reqType:AsyncPollRequest reqState:Completed status:0 ptr:00A8F4A0
<Upstream> 20080625 17:42:30.885 1196 SRTR 1257 SERVER_RequestVersionVector Received from connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} seqNumber:6 changeType:all ß Upstream server receives request for VV updates from the downstream server. Note how in Windows Server 2003 R2 the debug logs do not show as much information about the polling process as 2008 logs did in the File Add scenario. This can be mitigated somewhat by enabling debuglogseverity=5.
<Upstream> 20080625 17:42:30.885 1196 SRTR 1304 SERVER_AsyncPoll Received from connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD}
<Upstream> 20080625 17:42:30.895 1196 SRTR 498 SERVER_RequestUpdates Received from connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} credits:32 requestType:all ß upstream has received the request for updates from downstream partner
<Upstream> 20080625 17:42:30.895 1196 SRTR 1304 SERVER_AsyncPoll Received from connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD}
<Downstream> 20080625 17:42:30.896 2492 INCO 3534 InConnection::ReceiveUpdates Upstream credits:32 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} csName:testrf2
<Downstream> 20080625 17:42:30.896 2492 INCO 3597 InConnection::ReceiveUpdates Received: uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 fileName:setuplog.txt session:3 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} csName:testrf2 ß we get the list of updates we intend to replicate over
<Downstream> 20080625 17:42:30.896 2416 MEET 1190 Meet::Install Retries:0 updateName:setuplog.txt uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csName:testrf2
<Downstream> 20080625 17:42:30.896 2492 INCO 3661 InConnection::ReceiveUpdates Session has been closed. sessionId:3 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} csName:testrf2 ß We know of the updates now and are ready to transfer files
<Downstream> 20080625 17:42:30.896 2492 DOWN 2668 AsyncRpcHandler::ProcessReceive Completion. connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} reqType:UpdateRequest reqState:Completed status:0 ptr:00A86E70
<Downstream> 20080625 17:42:30.896 2532 INCO 2761 InConnection::RequestVvUp Requested upstream version vector. requestState:00A86E70 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} csName:testrf2 changeType:notify
<Upstream> 20080625 17:42:30.905 1696 JOIN 1171 Join::SubmitUpdate Sent: uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 name:setuplog.txt connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} csName:testrf2 ß This implies upstream server is satisfied that the file has been sent. We are still moving the file at this point though.
<Upstream> 20080625 17:42:30.905 556 OUTC 588 OutConnection::OpenFile Received request for update:
+    present 1
+    nameConflict 0
+    attributes 0x20
+    gvsn {B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21
+    uid {B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16
+    parent {5666BB91-265D-42E8-9F57-1B49F4E581B7}-v1
+    fence 16010101 00:00:00.000
+    clock 20080625 21:42:30.805
+    createTime 20080625 21:27:21.734 GMT
+    csId {5666BB91-265D-42E8-9F57-1B49F4E581B7}
+    hash 00000000-00000000-00000000-00000000
+    similarity 00000000-00000000-00000000-00000000
+    name setuplog.txt
+    rdcDesired:1 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} rgName:TestRG2
<Upstream> 20080625 17:42:30.905 556 MRSH 3487 Marshaller::Marshal FileAttrs in metadata : 0x20
<Upstream> 20080625 17:42:30.915 556 LDBX 3684 Ldb::Update Updating idRecord:
+    fid 0x3000000002FBF
+    usn 0x68778
+    uidVisible 1
+    filtered 0
+    journalWrapped 0
+    slowRecoverCheck 0
+    pendingTombstone 0
+    recUpdateTime 20080625 21:42:30.805 GMT
+    present 1
+    nameConflict 0
+    attributes 0x20
+    gvsn {B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21
+    uid {B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16
+    parent {5666BB91-265D-42E8-9F57-1B49F4E581B7}-v1
+    fence 16010101 00:00:00.000
+    clock 20080625 21:42:30.805
+    createTime 20080625 21:27:21.734 GMT
+    csId {5666BB91-265D-42E8-9F57-1B49F4E581B7}
+    hash 32B91C5A-74967572-4ABBC3A8-C319BB64
+    similarity 3F193518-2F152E2B-36262037-05111237 ß since the file was restaged after being modified we now have our hash and similarity signatures again on the upstream server.
+    name setuplog.txt
+    
<Upstream> 20080625 17:42:30.925 1196 SRTR 1257 SERVER_RequestVersionVector Received from connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} seqNumber:7 changeType:notify
<Upstream> 20080625 17:42:30.925 1696 STAG 102 StagingCleanupTask::Run Start to cleanup staging directory. csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7}
<Upstream> 20080625 17:42:30.925 556 STAG 727 StageWriter::CompleteDownloadStage Completed download or stage file 21-{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16-{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21-Downloaded.frx ß the file hs been staged upstream
<Downstream> 20080625 17:42:30.926 2492 DOWN 2668 AsyncRpcHandler::ProcessReceive Completion. connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} reqType:VvUpRequest reqState:Completed status:0 ptr:00A86E70
<Upstream> 20080625 17:42:30.935 556 OUTC 1056 OutConnection::OpenFile Sent file uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 name:setuplog.txt fileSize:80823 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} rgName:TestRG2 ß Upstream server is now ready to serve file and downstream is pulling across the data
<Upstream> 20080625 17:42:30.935 556 SRTR 1730 InitializeFileTransferAsyncState::ProcessIoCompletion Initialized connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} rdc:1 context:00A7FE58,00B0F118,00000000 uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 ptr:00AE49E0 ß data is transfered
<Downstream> 20080625 17:42:30.946 2416 RDCX 1777 Rdc::SyncClientState::Flush Rdc Need Assembler Statistics: uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 fileName:setuplog.txt connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId
{5666BB91-265D-42E8-9F57-1B49F4E581B7}
ß log stats about RDC and compression usage (this is only seen with debuglogseverity=5 in Win2008)
+     TOTAL
+     Compression Ratio 87 %
+     Target Uncompress Size 597424 ß this is the true file size when in the replicated folder
+     Target Compress Size 79943 ß this the file size compresses in staging
+     Bytes Received 6001 Signatures: 4254 Data: 1747 ß out of 597,424 bytes true size, only 6001 bytes sent over the wire because of XPRESS compressed RDC blocks
+     Signature Bytes Received 4254 4254
+     Number of remote calls 3 Signatures: 1 Needs: 1 Data: 1
+     SEED
+     Rdc Need Size 590437 590437 0
+     Xpress Blocks 73 73 0
+     Uncompressed Xpress Blocks 73 73 0
+     Blocks copied to target 0 0 0
+     SOURCE
+     Rdc Need Size 6987 0
+     Xpress Blocks 1 0
+     Uncompressed Xpress Blocks 1 0
+     Blocks copied to target 0 0
<Downstream> 20080625 17:42:30.946 2416 INCO 4112 InConnection::LogTransferActivity Received RDCGET uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 fileName:setuplog.txt connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} stagedSize:80823 ß transfer data logged in performance counter. Note the RDCGET rather than the RAWGET seen in the 'file add' scenario. This is because when we could not use RDC in that scenario the entire 'raw' file was copied.
<Downstream> 20080625 17:42:30.946 2416 STAG 727 StageWriter::CompleteDownloadStage Completed download or stage file 21-{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16-{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21-Downloaded.frx ß the file has ben written to the downstream staging directory successfully.
<Downstream> 20080625 17:42:30.946 2416 MRSH 2957 MarshalContext::Initialize Create file:[setuplog.txt-{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21] with attributes:0x20 <- the file is unmarshalled
<Upstream> 20080625 17:42:30.955 1196 RDCX 2763 Rdc::SyncServerState::~SyncServerState RDC Need Reader Statistics: uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} ß upstream we also log the sends for the performance counters.
+     TOTAL
+     Compression Ratio 15 %
+     RDC Need Size 6987
+     Bytes sent to downstream 6001 ß matches what we sent above.
+     Uncompressed XPRESS blocks 0
+     Compressed XPRESS blocks 0
+     Copied XPRESS Blocks 1
<Downstream> 20080625 17:42:30.956 2416 MEET 1978 Meet::TransferToInstalling Transferring content from staging area into Installing updateName:setuplog.txt uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csName:testrf2 ß file is copied into the Installing directory.
<Downstream> 20080625 17:42:30.956 2416 MEET 1898 Meet::Download Download Succeeded : true updateName:setuplog.txt uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csName:testrf2 csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} ß the actual replication phase is over.
<Downstream> 20080625 17:42:30.956 2416 MEET 2166 Meet::InstallRename Move out previous version of same file updateName:setuplog.txt uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csName:testrf2 ß the file must be replaced in the actual replicated folder now. DFSR does not use RDC 'on disk' – what ends up in staging/installing must overwrite what is in the actual RF.
<Downstream> 20080625 17:42:30.956 2416 MEET 3700 Meet::MoveOut Moving contents and children out of replica. newName:setuplog.txt-{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v20 updateName:setuplog.txt uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csName:testrf2record: ß the previous file is purged. Hence why if this file is locked, replication for a file cannot be completed either upstream or downstream.
+    fid 0x4000000002FCA
+    usn 0x6f318
+    uidVisible 1
+    filtered 0
+    journalWrapped 0
+    slowRecoverCheck 0
+    pendingTombstone 0
+    recUpdateTime 20080625 21:33:05.774 GMT
+    present 1
+    nameConflict 0
+    attributes 0x20
+    gvsn {B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v20 ß previous version
+    uid {B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16
+    parent {5666BB91-265D-42E8-9F57-1B49F4E581B7}-v1
+    fence 16010101 00:00:00.000
+    clock 20080625 21:33:04.888
+    createTime 20080625 21:27:21.734 GMT
+    csId {5666BB91-265D-42E8-9F57-1B49F4E581B7}
+    hash 06D3EAE4-7287AF33-9C7FE62A-F8EFE21C
+    similarity 3F193518-2F152E2B-36262037-05111237
+    name setuplog.txt
+    
<Downstream> 20080625 17:42:30.956 2416 MEET 3741 Meet::MoveOut Purge existing file in Deleted updateName:setuplog.txt uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csName:testrf2 ß the file must go.
<Downstream> 20080625 17:42:30.956 2416 MEET 3747 Meet::MoveOut RenameDelete file fid:0x4000000002FCA updateName:setuplog.txt uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csName:testrf2 ß the file is deleted and gone.
<Downstream> 20080625 17:42:30.956 2416 MEET 2190 Meet::InstallRename File moved. rootVolume:{05853FA6-411C-11DD-A156-806E6F6E6963} parentFid:0x1000000002F8C fidInInstalling:0x4000000002FCC usn:0x70850 updateName:setuplog.txt uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csName:testrf2 ß the updated file is moved in.
<Downstream> 20080625 17:42:30.956 2416 LDBX 3684 Ldb::Update Updating idRecord: ß the DFSR jet database I updated to reflect that the updated version of the file is now in the content set.
+    fid 0x4000000002FCC
+    usn 0x70850
+    uidVisible 1 ß It's available for further replication
+    filtered 0
+    journalWrapped 0
+    slowRecoverCheck 0
+    pendingTombstone 0
+    recUpdateTime 16010101 00:00:00.000 GMT
+    present 1 ß the file exists in the content set.
+    nameConflict 0
+    attributes 0x20
+    gvsn {B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 ß GVSN now matches the originating server information
+    uid {B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16
+    parent {5666BB91-265D-42E8-9F57-1B49F4E581B7}-v1
+    fence 16010101 00:00:00.000
+    clock 20080625 21:42:30.805
+    createTime 20080625 21:27:21.734 GMT
+    csId {5666BB91-265D-42E8-9F57-1B49F4E581B7}
+    hash 32B91C5A-74967572-4ABBC3A8-C319BB64
+    similarity 3F193518-2F152E2B-36262037-05111237
+    name setuplog.txt
+    
<Downstream> 20080625 17:42:30.956 2416 MEET 2233 Meet::InstallRename -> DONE Install-rename completed updateName:setuplog.txt uid:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16 gvsn:{B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csName:testrf2 csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} ßThis file is complete
<Downstream> 20080625 17:42:30.956 2416 INCO 4378 InConnection::UpdateProcessed Received Update. updatesLeft:0 processed:1 sessionId:3 open:0 updateType:0 processStatus:0 connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7} csName:testrf2 update: ß successfully replicated the file.
+    present 1
+    nameConflict 0
+    attributes 0x20
+    gvsn {B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v21
+    uid {B0DAFB7F-1E6D-401E-ADEC-2494F4A345A6}-v16
+    parent {5666BB91-265D-42E8-9F57-1B49F4E581B7}-v1
+    fence 16010101 00:00:00.000
+    clock 20080625 21:42:30.805
+    createTime 20080625 21:27:21.734 GMT
+    csId {5666BB91-265D-42E8-9F57-1B49F4E581B7}
+    hash 32B91C5A-74967572-4ABBC3A8-C319BB64
+    similarity 3F193518-2F152E2B-36262037-05111237
+    name setuplog.txt
+    
<Downstream> 20080625 17:42:30.966 2532 INCO 2787 InConnection::ContentSetContext::Hibernate Hibernating: connId:{39D5F13D-B2D1-484D-B57E-E369C8F8C6DD} csId:{5666BB91-265D-42E8-9F57-1B49F4E581B7}

Understanding DFSR debug logging (Part 1: Logging Levels, Log Format, GUID’s)
Understanding DFSR debug logging (Part 2: Nested Fields, Module ID's)
Understanding DFSR debug logging (Part 3: The Log Scenario Format, File Added to Replicated Folder on Windows Server 2008)
Understanding DFSR debug logging (Part 4: A Very Small File Added to Replicated Folder on Windows Server 2008)
Understanding DFSR debug logging (Part 5: File Modified on Windows Server 2003 R2)
Understanding DFSR debug logging (Part 6: Microsoft Office Word 97-2003 File Modified on Windows Server 2008)
Understanding DFSR debug logging (Part 7: Microsoft Office Word 2007 File Modified on Windows Server 2008)
Understanding DFSR debug logging (Part 8: File Deleted from Windows Server 2003 R2)
Understanding DFSR debug logging (Part 9: File is Renamed on Windows Server 2003 R2)
Understanding DFSR debug logging (Part 10: File Conflicted between two Windows Server 2008)
Understanding DFSR debug logging (Part 11: Directory created on Windows Server 2003 R2)
Understanding DFSR debug logging (Part 12: Domain Controller Bind and Config Polling on Windows Server 2008)
Understanding DFSR debug logging (part 13: A New Replication Group and Replicated Folder between two Windows Server 2008 members)
Understanding DFSR debug logging (Part 14: A sharing violation due to a file locked upstream between two Windows Server 2008)
Understanding DFSR debug logging (Part 15: Pre-Seeded Data Usage during Initial Sync)
Understanding DFSR debug logging (Part 16: File modification with RDC in very granular detail (uses debug severity 5))
Understanding DFSR debug logging (Part 17: Replication failing because of blocked RPC ports (uses debug severity 5))
Understanding DFSR debug logging (Part 18: LDAP queries failing due to network (uses debug severity 5))
Understanding DFSR debug logging (Part 19: File Blocked Inbound by a File Screen Filter Driver (uses debug severity 5))
Understanding DFSR debug logging (Part 20: Skipped temporary and filtered files (uses debug severity 5))
Understanding DFSR debug logging (Part 21: File replication performance from throttling (uses debug severity 5))

 - Ned Pyle

Attachment: modifiedlargefileupstream-debug- 2003.zip