DFSR - Come configurare i log del servizio
Il log del servizio DFSR è già attivo di default e ha anche un livello di dettaglio elevato (Informational = 4). Il log file DFSRxxxxx.log viene creato nella cartella “%windir%\debug” dove risiedono anche i 100 file di log precedenti che sono stati compressi come file DFSRxxxxx.log.gz. Lo storico dei file può essere incrementato da 100 al numero che desideriamo, questo è utile in particolari casi di troubleshooting dove è necessario avere uno storico maggiore. I log hanno diversi parametri di configurazione. Nella seguente tabella riporto tutti i parametri:
Parameter |
Notes |
Range |
Default |
DebugLogFilePath |
Path to create debug log files at |
Local folder path |
%systemroot%\debug |
DebugLogSeverity |
Log level severity |
1 – 5 |
4 |
EnableDebugLog |
Boolean to turn logging on or off |
TRUE, FALSE |
TRUE |
MaxDebugLogFiles |
Count of debug log files |
1 – 10,000 |
100 |
MaxDebugLogMessages |
Lines per debug log file, before moving to the next log file |
1,000 to MAXDWORD* |
200,000 |
I valori della DebugLogSeverity sono:
- Critical Info (1)
- Errors (2)
- Warning (3)
- Informational (4) = Default
- Trace (5)
Per modificare i parametri della tabella Microsoft consiglia di utilizzare il “WMI Command line interface” (WMIC) con i seguenti comandi:
Debug Log File Path
WMIC syntax: wmic /namespace:\\root\microsoftdfs path dfsrmachineconfig set debuglogfilepath="d:\dfsrlogs"
NB: La cartella deve essere creata prima di configurarla con il comando sopra altrimenti il sistema userà la cartella di default non trovando la cartella nel comando.
Debug Log Severity
WMIC syntax: wmic /namespace:\\root\microsoftdfs path dfsrmachineconfig set debuglogseverity=5
Debug Log Messages
WMIC syntax: wmic /namespace:\\root\microsoftdfs path dfsrmachineconfig set maxdebuglogmessages=400000
Debug Log Files
WMIC syntax: wmic /namespace:\\root\microsoftdfs path dfsrmachineconfig set maxdebuglogfiles=200
Non è necessario fare un riavvio del servizio DFSR o del server per far prendere le modifiche. Per verificare se i parametri sono stati presi potete usare il seguente comando:
dfsrdiag DumpMachineCfg /Mem:DFSRServer1
Dopo questa breve spiegazione su come configurare i log possiamo procedere a vedere come leggere i log.
Come interpretare i log del servizio DFSR
All’interno dei log ci sono molte sigle e acronimi che devono essere capiti per poter analizzare i log. Il più importante fra tutti è il Global Version Sequence Number, GVSN. Questo numero è il guid del database in cui è avvenuta l’ultima modifica e la versione.
{DatabaseGuid}-v{version No} .
Un esempio:
20070314 18:02:39.246 1688 LDBX 3548 Ldb::Insert Inserting idRecord: ß Nuovo record inserito nel DB
+ fid 0x200000000015D ß File ID e USN sono riferiti al Journal NTFS
+ usn 0x3f98680
+ uidVisible 0 ß Non è stato ancora “committed”
+ filtered 0 ß Il file non rientra in quelli filtrati
+ journalWrapped 0
+ slowRecoverCheck 0
+ pendingTombstone 0 ß Il file non è stato cancellato.
+ recUpdateTime 16010101 00:00:00.000 GMT
+ present 1
+ nameConflict 0 ß Non ci sono conflitti
+ attributes 0x20 ß Attributo del file
+ gvsn {3823B980-8436-4D70-8BA8-5A6DFDBF9EA9}-v14 ß GVSN = Guid di chi ha originato questo cambiamento
+ uid {3823B980-8436-4D70-8BA8-5A6DFDBF9EA9}-v14 ß UID= Guid di Chi ha creato il file/folder
+ parent {B00F0EB3-9AB5-4261-A192-EC4D81273408}-v1 ß GUID della cartella superiore-parent
+ fence 16010101 00:00:00.000
+ clock 20070314 17:02:39.216 ß Ora UTC del “change”
+ createTime 20070314 17:02:39.216 GMT ß Ora UTC della creazione
+ csId {B00F0EB3-9AB5-4261-A192-EC4D81273408}
+ hash 00000000-00000000-00000000-00000000 ß File/Folder hash
+ similarity 00000000-00000000-00000000-00000000
+ name New Text Document.txt ß Nome del file o della cartella
Per poter risalire al server su cui è stata fatta la modifica dal GUID possiamo usare il tool DFSRDiag che tra le varie opzioni per fare trohbleshooting ha l’opzione Guid2Name.
C:\ >dfsrdiag guid2name /guid:{ 3823B980-8436-4D70-8BA8-5A6DFDBF9EA9} /RGName:rgname
Object Type : DfsrVolumeInfo
Computer : PIPPO.MB.COM
Volume Guid : 7CF914D4-1B2D-11DB-AE4E-806E6F6E6963
Volume Path : C:
Volume SN : 3900110954
DB Guid : 3823B980-8436-4D70-8BA8-5A6DFDBF9EA9
Operation Succeeded
Per semplificare la comprensione dei log di debug ho inserito alcune delle comuni operazioni che vengono fatte su file e directory con i relativi pezzi di log per poter interpretare i log di debug.
Operazioni sui File
● File filtrato dal USN Consumer perché nella lista dei file da filtrare.
20070320 11:29:25.030 1624 USNC 1254 UsnConsumer::ProcessUsnRecord Filtered USN_RECORD:
+ USN_RECORD:
+ RecordLength: 80
+ MajorVersion: 2
+ MinorVersion: 0
+ FileRefNumber: 0x20000000001a0
+ ParentFileRefNumber: 0x4000000002960
+ USN: 0x29f0220
+ TimeStamp: 20070320 11:29:24.940 W. Europe Standard Time
+ Reason: Close Rename New Name
+ SourceInfo: 0x0
+ SecurityId: 0x224
+ FileAttributes: 0x20
+ FileNameLength: 14
+ FileNameOffset: 60
+ FileName: AAA.tmp
● File non replicato perché è una modifica non presa in considerazione dal USNConsumer.
20070320 11:44:03.523 1624 LDBX 3665 Ldb::Update Updating idRecord:
+ fid 0xD0000000030C8
+ usn 0x29f6a60
+ uidVisible 1
+ filtered 0
+ journalWrapped 0
+ slowRecoverCheck 0
+ pendingTombstone 0
+ recUpdateTime 20070320 10:40:21.654 GMT
+ present 1
+ nameConflict 0
+ attributes 0x2020
+ gvsn {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v25 ß Il GSVN non viene incrementato
+ uid {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v15
+ parent {B00F0EB3-9AB5-4261-A192-EC4D81273408}-v1
+ fence 16010101 00:00:00.000
+ clock 20070320 10:40:21.644
+ createTime 20070301 14:50:12.910 GMT
+ csId {B00F0EB3-9AB5-4261-A192-EC4D81273408}
+ hash 7F941AAB-BBC7047F-AD048620-9754AE10
+ similarity 00000000-00000000-00000000-00000000
+ name attribute.txt
20070320 11:44:03.523 1624 USNC 1879 UsnConsumer::UpdateUsnOnly USN-only update from USN_RECORD:
+ USN_RECORD:
+ RecordLength: 88
+ MajorVersion: 2
+ MinorVersion: 0
+ FileRefNumber: 0xd0000000030c8
+ ParentFileRefNumber: 0x4000000002960
+ USN: 0x29f6a60
+ TimeStamp: 20070320 11:44:03.513 W. Europe Standard Time
+ Reason: Basic Info Change Close
+ SourceInfo: 0x0
+ SecurityId: 0x354
+ FileAttributes: 0x2020
+ FileNameLength: 26
+ FileNameOffset: 60
+ FileName: attribute.txt
· Modifica di un file
20070320 11:48:36.085 1624 LDBX 3665 Ldb::Update Updating idRecord:
+ gvsn {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v28 ß Il GSVN viene incrementato
+ uid {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v15
+ parent {B00F0EB3-9AB5-4261-A192-EC4D81273408}-v1
+ fence 16010101 00:00:00.000
+ clock 20070320 10:48:36.075
+ createTime 20070301 14:50:12.910 GMT
+ csId {B00F0EB3-9AB5-4261-A192-EC4D81273408}
+ hash 00000000-00000000-00000000-00000000
+ similarity 00000000-00000000-00000000-00000000
+ name attribute.txt
+
20070320 11:48:36.085 1624 USNC 2202 UsnConsumer::UpdateIdRecord ID record updated from USN_RECORD:
+ USN_RECORD:
+ RecordLength: 88
+ MajorVersion: 2
+ MinorVersion: 0
+ FileRefNumber: 0xd0000000030c8
+ ParentFileRefNumber: 0x4000000002960
+ USN: 0x29f7ae0
+ TimeStamp: 20070320 11:48:36.075 W. Europe Standard Time
+ Reason: Close Data Overwrite Data truncation
+ SourceInfo: 0x0
+ SecurityId: 0x354
+ FileAttributes: 0x20
+ FileNameLength: 26
+ FileNameOffset: 60
+ FileName: attribute.txt
· File spostato fuori dal Replication Folder ( o cancellato e messo nel cestino )
20070320 11:59:05.520 1624 LDBX 3665 Ldb::Update Updating idRecord:
+ fid 0xD0000000030C8
+ usn 0x29f9390
+ uidVisible 1
+ filtered 0
+ journalWrapped 0
+ slowRecoverCheck 0
+ pendingTombstone 0
+ recUpdateTime 20070320 10:54:08.303 GMT
+ present 0
+ nameConflict 0
+ attributes 0x20
+ gvsn {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v30
+ uid {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v15
+ parent {B00F0EB3-9AB5-4261-A192-EC4D81273408}-v1
+ fence 16010101 00:00:00.000
+ clock 20070320 10:59:05.520
+ createTime 20070301 14:50:12.910 GMT
+ csId {B00F0EB3-9AB5-4261-A192-EC4D81273408}
+ hash 00000000-00000000-00000000-00000000
+ similarity 00000000-00000000-00000000-00000000
+ name attribute.txt
+
20070320 11:59:05.520 1624 USNC 2599 UsnConsumer::TombstoneOrDelete ID record tombstoned from USN_RECORD:
+ USN_RECORD:
+ RecordLength: 80
+ MajorVersion: 2
+ MinorVersion: 0
+ FileRefNumber: 0xd0000000030c8
+ ParentFileRefNumber: 0x2000000002aa5
+ USN: 0x29f9390
+ TimeStamp: 20070320 11:59:05.520 W. Europe Standard Time
+ Reason: Close Rename New Name
+ SourceInfo: 0x0
+ SecurityId: 0x354
+ FileAttributes: 0x20
+ FileNameLength: 14
+ FileNameOffset: 60
+ FileName: Dc7.txt
● File cancellato senza metterlo nel cestino ( Shitf + canc ).
20070320 12:08:00.379 1624 USNC 2599 UsnConsumer::TombstoneOrDelete ID record tombstoned from USN_RECORD:
+ USN_RECORD:
+ RecordLength: 104
+ MajorVersion: 2
+ MinorVersion: 0
+ FileRefNumber: 0x20000000001d7
+ ParentFileRefNumber: 0x4000000002960
+ USN: 0x29fbca8
+ TimeStamp: 20070320 12:08:00.379 W. Europe Standard Time
+ Reason: Close File Delete
+ SourceInfo: 0x0
+ SecurityId: 0x354
+ FileAttributes: 0x20
+ FileNameLength: 40
+ FileNameOffset: 60
+ FileName: Filedacancellare.txt
● Creazione file.
20070320 13:13:17.103 1648 LDBX 3665 Ldb::Update Updating idRecord:
+ fid 0x20000000001F4
+ usn 0x2a0edc8
+ uidVisible 1
+ filtered 0
+ journalWrapped 0
+ slowRecoverCheck 0
+ pendingTombstone 0
+ recUpdateTime 20070320 12:13:05.597 GMT
+ present 1
+ nameConflict 0
+ attributes 0x20
+ gvsn {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v38
+ uid {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v37
+ parent {B00F0EB3-9AB5-4261-A192-EC4D81273408}-v1
+ fence 16010101 00:00:00.000
+ clock 20070320 12:13:17.103
+ createTime 20070320 12:13:05.537 GMT
+ csId {B00F0EB3-9AB5-4261-A192-EC4D81273408}
+ hash 00000000-00000000-00000000-00000000
+ similarity 00000000-00000000-00000000-00000000
+ name Creazionefile.txt
+
20070320 13:13:17.103 1648 USNC 2202 UsnConsumer::UpdateIdRecord ID record updated from USN_RECORD:
+ USN_RECORD:
+ RecordLength: 96
+ MajorVersion: 2
+ MinorVersion: 0
+ FileRefNumber: 0x20000000001f4
+ ParentFileRefNumber: 0x4000000002960
+ USN: 0x2a0edc8
+ TimeStamp: 20070320 13:13:17.103 W. Europe Standard Time
+ Reason: Close Rename New Name
+ SourceInfo: 0x0
+ SecurityId: 0x354
+ FileAttributes: 0x20
+ FileNameLength: 34
+ FileNameOffset: 60
+ FileName: Creazionefile.txt
Operazioni su Directory
Di seguito una lista di log generati da operazioni su fatte su directory all’interno del “Replication Folder”.
● Copia di una Directory nel “replication folder”
20070320 13:32:24.103 1648 LDBX 3548 Ldb::Insert Inserting idRecord:
+ fid 0x20000000001FF
+ usn 0x2a12e38
+ uidVisible 0
+ filtered 0
+ journalWrapped 0
+ slowRecoverCheck 0
+ pendingTombstone 0
+ recUpdateTime 16010101 00:00:00.000 GMT
+ present 1
+ nameConflict 0
+ attributes 0x10
+ gvsn {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v43
+ uid {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v43
+ parent {B00F0EB3-9AB5-4261-A192-EC4D81273408}-v1
+ fence 16010101 00:00:00.000
+ clock 20070320 12:32:24.103
+ createTime 20070320 12:32:24.103 GMT
+ csId {B00F0EB3-9AB5-4261-A192-EC4D81273408}
+ hash 00000000-00000000-00000000-00000000
+ similarity 00000000-00000000-00000000-00000000
+ name Cartellamovein
20070320 13:32:24.103 1648 USNC 2448 UsnConsumer::CreateNewRecord ID record created from USN_RECORD:
+ USN_RECORD:
+ RecordLength: 88
+ MajorVersion: 2
+ MinorVersion: 0
+ FileRefNumber: 0x20000000001ff
+ ParentFileRefNumber: 0x4000000002960
+ USN: 0x2a12e38
+ TimeStamp: 20070320 13:32:24.103 W. Europe Standard Time
+ Reason: File Create
+ SourceInfo: 0x0
+ SecurityId: 0x379
+ FileAttributes: 0x10
+ FileNameLength: 28
+ FileNameOffset: 60
+ FileName: Cartellamovein
+
20070320 13:32:24.103 1648 LDBX 3665 Ldb::Update Updating idRecord:
+ fid 0x20000000001FF
+ usn 0x2a12e90
+ uidVisible 0
+ filtered 0
+ journalWrapped 0
+ slowRecoverCheck 0
+ pendingTombstone 0
+ recUpdateTime 20070320 12:32:24.103 GMT
+ present 1
+ nameConflict 0
+ attributes 0x10
+ gvsn {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v43
+ uid {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v43
+ parent {B00F0EB3-9AB5-4261-A192-EC4D81273408}-v1
+ fence 16010101 00:00:00.000
+ clock 20070320 12:32:24.103
+ createTime 20070320 12:32:24.103 GMT
+ csId {B00F0EB3-9AB5-4261-A192-EC4D81273408}
+ hash 00000000-00000000-00000000-00000000
+ similarity 00000000-00000000-00000000-00000000
+ name Cartellamovein
+
20070320 13:32:24.103 1648 USNC 1879 UsnConsumer::UpdateUsnOnly USN-only update from USN_RECORD:
+ USN_RECORD:
+ RecordLength: 88
+ MajorVersion: 2
+ MinorVersion: 0
+ FileRefNumber: 0x20000000001ff
+ ParentFileRefNumber: 0x4000000002960
+ USN: 0x2a12e90
+ TimeStamp: 20070320 13:32:24.103 W. Europe Standard Time
+ Reason: Close File Create
+ SourceInfo: 0x0
+ SecurityId: 0x379
+ FileAttributes: 0x10
+ FileNameLength: 28
+ FileNameOffset: 60
+ FileName: Cartellamovein
+
● Cancellazione/spostamento Directory
20070320 13:35:25.944 1648 LDBX 3665 Ldb::Update Updating idRecord:
+ fid 0x20000000001FF
+ usn 0x2a12e90
+ uidVisible 1
+ filtered 0
+ journalWrapped 0
+ slowRecoverCheck 0
+ pendingTombstone 1
+ recUpdateTime 20070320 12:32:24.143 GMT
+ present 1
+ nameConflict 0
+ attributes 0x10
+ gvsn {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v43
+ uid {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v43
+ parent {B00F0EB3-9AB5-4261-A192-EC4D81273408}-v1
+ fence 16010101 00:00:00.000
+ clock 20070320 12:32:24.103
+ createTime 20070320 12:32:24.103 GMT
+ csId {B00F0EB3-9AB5-4261-A192-EC4D81273408}
+ hash 00000000-00000000-00000000-00000000
+ similarity 00000000-00000000-00000000-00000000
+ name Cartellamovein
+
20070320 13:35:25.944 1648 LDBX 4064 Ldb::InsertWalkerJob Inserting dirWalkerJob:uid:{497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v43 moveType:MoveOut (2) at time:20070320 12:35:25.944
20070320 13:35:25.994 1648 DIRW 581 DirWalkerTask::QueueMoveoutJob Queueing move-out uid:{497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v43 fid:0x20000000001FF
20070320 13:35:25.994 2096 DIRW 256 DirWalkerTask::Run Start walking directory.
20070320 13:35:25.994 2096 DIRW 1208 DirWalkerTask::MoveoutStep Starting to process move-out job. uid:{497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v43
20070320 13:35:25.994 2096 DIRW 1233 DirWalkerTask::MoveoutStep Iterating children of uid: {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v43
20070320 13:35:26.004 2096 LDBX 3665 Ldb::Update Updating idRecord:
+ fid 0x20000000001FF
+ usn 0x2a12e90
+ uidVisible 1
+ filtered 0
+ journalWrapped 0
+ slowRecoverCheck 0
+ pendingTombstone 0
+ recUpdateTime 20070320 12:35:25.944 GMT
+ present 0
+ nameConflict 0
+ attributes 0x10
+ gvsn {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v44
+ uid {497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v43
+ parent {B00F0EB3-9AB5-4261-A192-EC4D81273408}-v1
+ fence 16010101 00:00:00.000
+ clock 20070320 12:35:25.944
+ createTime 20070320 12:32:24.103 GMT
+ csId {B00F0EB3-9AB5-4261-A192-EC4D81273408}
+ hash 00000000-00000000-00000000-00000000
+ similarity 00000000-00000000-00000000-00000000
+ name Cartellamovein
+
20070320 13:35:26.004 2096 DIRW 101 DirWalkerTask::Job::Finish MoveOut csId:{B00F0EB3-9AB5-4261-A192-EC4D81273408} uid:{497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v43
20070320 13:35:26.004 2096 DIRW 786 DirWalkerTask::RemoveJob Removing job type:2 uid:{497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v43
20070320 13:35:26.004 2096 LDBX 4100 Ldb::DeleteWalkerJob Deleting dirWalkerJob. uid:{497C35B7-22CB-48DA-A83A-FE64BD14AC64}-v43
20070320 13:35:26.004 2096 LDBX 1228 LdbManager::UpdateVersionVectorCache Wake up callback 00AD5750
20070320 13:35:26.004 2096 DIRW 303 DirWalkerTask::Run Exit.
20070320 13:35:26.004 1648 USNC 2025 UsnConsumer::TombstoneIdRecord Directory tombstoned or deleted from USN_RECORD:
+ USN_RECORD:
+ RecordLength: 72
+ MajorVersion: 2
+ MinorVersion: 0
+ FileRefNumber: 0x20000000001ff
+ ParentFileRefNumber: 0x2000000002aa5
+ USN: 0x2a13430
+ TimeStamp: 20070320 13:35:25.944 W. Europe Standard Time
+ Reason: Close Rename New Name
+ SourceInfo: 0x0
+ SecurityId: 0x379
+ FileAttributes: 0x10
+ FileNameLength: 8
+ FileNameOffset: 60
+ FileName: Dc11
Matteo Belloni
Support Escalation Engineer
Microsoft Enterprise Platform Support
Comments
Anonymous
January 01, 2003
Ciao Daniele, scusami ma ero in ferie. Con il seguente comando vedi tutta la configurazione e anche il livello del log dfsrdiag DumpMachineCfg /Mem:DFSServerName Machine Configuration Parameters: ConflictHighWatermarkPercent : 90 ConflictLowWatermarkPercent : 60 DebugLogFilePath : C:WINDOWSdebug DebugLogSeverity : 4 <------- Log severity Description : DsPollingIntervalInMin : 60 EnableDebugLog : TRUE EnableLightDsPolling : TRUE LastChangeNumber : 1 LastChangeSource : LastChangeTime : 20050830140044.000000-000 MaxDebugLogFiles : 200 MaxDebugLogMessages : 400000 RpcPortAssignment : 0 StagingHighWatermarkPercent : 90 StagingLowWatermarkPercent : 60 by MatteoAnonymous
March 31, 2010
Ciao Matteo, ho un Windows 2008 R2 con DFSr che utilizza CPU in modo anomalo. L'utilizzo di CPU è causato dal processo DFSrs.exe con continue chiamate a EtwTraceMessageVa. Il cliente dice di non aver attivato alcun tracing e non ho trovato come disbailitare il tracing sul DFSr. Hai qualche idea?