private void DeleteOldLogsHandler(object state)
{
this.TraceSource.WriteInfo(
this.LogSourceId,
"Starting deletion of old logs in directory {0} ...",
this.etwEventCache);
// Figure out the timestamp before which all files will be deleted
DateTime cutoffTime = DateTime.UtcNow.Add(-this.eventDeletionAge);
// Delete the files that are old enough to be deleted
Utility.DeleteOldFilesFromFolder(
this.LogSourceId,
this.etwEventCache,
null,
cutoffTime,
() => { return(this.Stopping); },
false);
this.TraceSource.WriteInfo(
this.LogSourceId,
"Finished deletion of old logs in directory {0}.",
this.etwEventCache);
// Schedule the next pass
this.oldLogDeletionTimer.Start();
}
private string CreateEtwLogDirectory()
{
string etwParentFolder = Path.Combine(
this.initParam.WorkDirectory,
Utility.ShortWindowsFabricIdForPaths);
string destinationKey = Path.Combine(
this.mdsFileProducerSettings.DirectoryName,
this.mdsFileProducerSettings.TableName);
string etwFolder;
bool success = Utility.CreateWorkSubDirectory(
this.traceSource,
this.logSourceId,
destinationKey,
string.Concat(Utility.EtwConsumerWorkSubFolderIdPrefix, this.logSourceId),
etwParentFolder,
out etwFolder);
if (success)
{
return(Path.Combine(etwFolder, LogDirName));
}
return(null);
}
private static void ReadLineFromFile(LineParam lineParam)
{
Utility.PerformIOWithRetries(
ctx =>
{
LineParam param = ctx;
param.Line = param.Reader.ReadLine();
},
lineParam);
}
internal void OnEtlFileReadStop(string fileName, bool isActiveEtl, string currentBookmark, string nextBookmark, bool fileReadAborted)
{
if (null == this.streamWriter)
{
// An error occurred during the creation of the buffered event
// file. So just return immediately without doing anything.
return;
}
if (false == fileReadAborted)
{
// Flush pending events
this.FlushPendingEvents(isActiveEtl, currentBookmark, nextBookmark);
}
// We're done processing an ETL file. Before this ETL file is moved
// to the archives, make sure all the events we've written so far are
// flushed to the buffered event file.
try
{
Utility.PerformIOWithRetries(
() =>
{
try
{
this.streamWriter.Flush();
}
catch (System.Text.EncoderFallbackException ex)
{
// This can happen if the manifest file does not match the binary.
// Write an error message and move on.
this.TraceSource.WriteError(
this.LogSourceId,
"Exception occurred while flushing filtered ETW events to buffered event file. Exception information: {0}",
ex);
}
});
}
catch (Exception e)
{
// Log an error and move on
this.TraceSource.WriteExceptionAsError(
this.LogSourceId,
e,
"Failed to flush data to buffered event file.");
}
}
private string CreateBlobUploaderWorkSubDirectory()
{
string workParentFolder = Path.Combine(
this.initParam.WorkDirectory,
Utility.ShortWindowsFabricIdForPaths);
string workFolder;
bool success = Utility.CreateWorkSubDirectory(
this.traceSource,
this.logSourceId,
this.destinationKey,
this.etwLogDirName,
workParentFolder,
out workFolder);
if (success)
{
return(Path.Combine(workFolder, AzureConstants.AzureFileUploaderFolder));
}
return(null);
}
private void ProcessEventsFromFile(string fileName)
{
this.TraceSource.WriteInfo(
this.LogSourceId,
"Processing ETW events from file {0}.",
fileName);
// Open the file
ReadEventsFromFileParam readEventsParam = new ReadEventsFromFileParam();
readEventsParam.StreamReader = null;
readEventsParam.FileName = fileName;
try
{
Utility.PerformIOWithRetries(
this.OpenEtwEventCacheFile,
readEventsParam);
}
catch (Exception e)
{
this.TraceSource.WriteExceptionAsError(
this.LogSourceId,
e,
"Failed to open file {0} for read.",
fileName);
return;
}
if (readEventsParam.FileNotFound)
{
Debug.Assert(null == readEventsParam.StreamReader, "StreamReader should remain unset if file is not found.");
return;
}
// Read and process events from the file
try
{
// Check the DCA version to make sure we can parse this file
int version;
if (false == this.CanParseFile(readEventsParam.StreamReader, fileName, out version))
{
return;
}
// Upload the ETW events that we just retrieved
this.TraceSource.WriteInfo(
this.LogSourceId,
"Starting delivery of ETW events from file {0} ....",
fileName);
LineParam lineParam = new LineParam();
lineParam.Reader = readEventsParam.StreamReader;
for (;;)
{
// Read an event from the file
try
{
ReadLineFromFile(lineParam);
}
catch (Exception e)
{
this.TraceSource.WriteExceptionAsError(
this.LogSourceId,
e,
"Failed to read event from file {0}.",
fileName);
break;
}
if (null == lineParam.Line)
{
// End of file reached
break;
}
DecodedEtwEvent etwEventInfo = new DecodedEtwEvent();
string nodeUniqueEventId = null;
if (false == this.ParseEventInfo(fileName, version, lineParam.Line, ref etwEventInfo, ref nodeUniqueEventId))
{
// Couldn't parse this event, so skip it and continue with the
// remaining events.
continue;
}
// Deliver the event to the consumer
this.eventSink.OnEtwEventAvailable(etwEventInfo, nodeUniqueEventId);
this.perfHelper.EventDeliveredToConsumer();
// If the consumer has asked for the event delivery period to
// be aborted, then do so immediately.
if (this.eventDeliveryPeriodAborted)
{
this.TraceSource.WriteInfo(
this.LogSourceId,
"The event delivery pass is being aborted. Therefore, no more events will be read from file {0}.",
fileName);
break;
}
// If we are in the process of stopping, then don't process
// any more events
if (this.Stopping)
{
this.TraceSource.WriteInfo(
this.LogSourceId,
"The consumer is being stopped. Therefore, no more events will be read from file {0}.",
fileName);
break;
}
}
this.TraceSource.WriteInfo(
this.LogSourceId,
"Finished delivery of ETW events from file {0}.",
fileName);
}
finally
{
readEventsParam.StreamReader.Dispose();
}
}
private void WriteTraceEvent(DecodedEventWrapper eventWrapper, string nodesUniqueEventId)
{
if (null == this.streamWriter)
{
// An error occurred during the creation of the buffered event
// file. So just return immediately without doing anything.
return;
}
// NOTE: The order in which the information is written must match
// the order of the EventLineParts enumeration defined in this class.
string eventInfo = string.Format(
CultureInfo.InvariantCulture,
"{0},{1},{2},{3},{4},{5},{6},{7},{8},{9},{10},{11},{12},{13},{14},{15}",
eventWrapper.InternalEvent.EventRecord.EventHeader.ProviderId,
eventWrapper.InternalEvent.EventRecord.EventHeader.EventDescriptor.Id,
eventWrapper.InternalEvent.EventRecord.EventHeader.EventDescriptor.Version,
eventWrapper.InternalEvent.EventRecord.EventHeader.EventDescriptor.Channel,
eventWrapper.InternalEvent.EventRecord.EventHeader.EventDescriptor.Opcode,
eventWrapper.InternalEvent.EventRecord.EventHeader.EventDescriptor.Task,
eventWrapper.InternalEvent.EventRecord.EventHeader.EventDescriptor.Keyword,
nodesUniqueEventId,
eventWrapper.Timestamp.ToBinary(),
eventWrapper.Timestamp, // We write the human-readable form for easier debugging
eventWrapper.Level,
eventWrapper.ThreadId,
eventWrapper.ProcessId,
eventWrapper.TaskName,
eventWrapper.EventType,
eventWrapper.EventText);
eventInfo = eventInfo.Replace("\r\n", "\t").Replace("\n", "\t").Replace("\r", "\t");
try
{
Utility.PerformIOWithRetries(
ctx =>
{
string eventString = ctx;
try
{
this.streamWriter.WriteLine(eventString);
}
catch (System.Text.EncoderFallbackException ex)
{
// This can happen if the manifest file does not match the binary.
// Write an error message and move on.
this.TraceSource.WriteError(
this.LogSourceId,
"Exception occurred while writing filtered ETW event to buffered event file. Exception information: {0}",
ex);
}
},
eventInfo);
}
catch (Exception e)
{
// Log an error and move on
this.TraceSource.WriteExceptionAsError(
this.LogSourceId,
e,
"Failed to write ETW event to buffered event file.");
}
}
public void OnEtwEventProcessingPeriodStop()
{
if (null == this.streamWriter)
{
// An error occurred during the creation of the buffered event
// file. So just return immediately without doing anything.
return;
}
// Close the buffered event file that we are currently working on.
try
{
this.streamWriter.Dispose();
}
catch (System.Text.EncoderFallbackException ex)
{
// This can happen if the manifest file does not match the binary.
// Write an error message and move on.
this.TraceSource.WriteError(
this.LogSourceId,
"Exception occurred while closing buffered event file. Exception information: {0}",
ex);
}
// Make our buffered event files available for delivery to the consumer.
// This includes:
// - the buffered event file that we wrote in this pass
// - any old buffered event files that we wrote in previous passes
// (and got interrupted before we could rename them for delivery to
// the consumer).
string[] cacheFiles = FabricDirectory.GetFiles(
this.etwEventCache,
TempCacheFileNameSearchPattern);
foreach (string cacheFile in cacheFiles)
{
try
{
Utility.PerformIOWithRetries(
ctx =>
{
string fileName = ctx;
FabricFile.Move(
fileName,
Path.ChangeExtension(fileName, CacheFileNameExtension));
},
cacheFile);
this.TraceSource.WriteInfo(
this.LogSourceId,
"File containing filtered ETW events was renamed for delivery to consumer. Old name: {0}, new name: {1}.",
cacheFile,
Path.ChangeExtension(cacheFile, CacheFileNameExtension));
}
catch (Exception e)
{
this.TraceSource.WriteExceptionAsError(
this.LogSourceId,
e,
"Buffered event file {0} could not be renamed for delivery to consumer.",
cacheFile);
}
}
this.perfHelper.EtlReadPassEnd();
}
public void OnEtwEventProcessingPeriodStart()
{
this.streamWriter = null;
this.perfHelper.EtlReadPassBegin();
// Build the full path to our buffered event file
string tempCacheFileName = string.Format(
CultureInfo.InvariantCulture,
"{0}{1}.{2}",
TempCacheFileNamePrefix,
DateTime.Now.Ticks,
TempCacheFileExtension);
string tempCacheFileFullPath = Path.Combine(this.etwEventCache, tempCacheFileName);
// Open the file
StreamWriter writer = null;
try
{
Utility.PerformIOWithRetries(
ctx =>
{
string fileName = ctx;
FileStream fileStream = FabricFile.Open(fileName, FileMode.Create, FileAccess.Write);
#if !DotNetCoreClr
Helpers.SetIoPriorityHint(fileStream.SafeFileHandle, Kernel32Types.PRIORITY_HINT.IoPriorityHintVeryLow);
#endif
writer = new StreamWriter(fileStream);
},
tempCacheFileFullPath);
}
catch (Exception e)
{
// Log an error and move on. No events from this pass will be
// written to the destination.
this.TraceSource.WriteExceptionAsError(
this.LogSourceId,
e,
"Failed to create a new file in the buffered event directory. None of the events from this pass will be written to the event buffer.");
return;
}
// Write the version number. This will help us read data from the file.
try
{
Utility.PerformIOWithRetries(
() =>
{
writer.WriteLine(EtlConsumerConstants.EtwEventCacheFormatVersionString);
});
}
catch (Exception e)
{
// Log an error and move on. No events from this pass will be
// written to the destination.
this.TraceSource.WriteExceptionAsError(
this.LogSourceId,
e,
"Failed to write buffered event file format version number to file {0} in the buffered event file. None of the events from this pass will be written to the event buffer.",
tempCacheFileFullPath);
return;
}
this.streamWriter = writer;
this.TraceSource.WriteInfo(
this.LogSourceId,
"Filtered ETW events for consumer will be buffered in file {0}.",
tempCacheFileFullPath);
}
private void DeliverEventsToConsumer(object state)
{
this.perfHelper.EventDeliveryPassBegin();
this.eventDeliveryPeriodAborted = false;
// Perform any tasks necessary at the beginning of the event delivery pass
this.eventSink.OnEtwEventDeliveryStart();
// Get the files from the buffered event directory
// We ignore files that are so old that they need to be deleted
DateTime cutoffTime = DateTime.UtcNow.Add(-this.eventDeletionAge);
DirectoryInfo dirInfo = new DirectoryInfo(this.etwEventCache);
FileInfo[] eventFilesInfo = dirInfo.GetFiles(CacheFileNameSearchPattern)
.Where(file => file.LastWriteTimeUtc.CompareTo(cutoffTime) > 0)
.ToArray();
// Sort the files such that the file with the most recent last-write
// time comes first. We'll process files in that order so that in
// case of huge backlogs the most recent (and hence likely to be
// most interesting) traces are processed first.
Array.Sort(eventFilesInfo, CompareFileLastWriteTimes);
// Process each of the files
int filesProcessed = 0;
DateTime processingEndTime = DateTime.Now.Add(this.eventDeliveryPassLength);
List <string> filesToDelete = new List <string>();
foreach (FileInfo eventFileInfo in eventFilesInfo)
{
// Process events from the current file
string eventFile = eventFileInfo.FullName;
this.ProcessEventsFromFile(eventFile);
filesProcessed++;
// If the event delivery pass is being aborted, then don't process
// any more files. Also, don't delete the current file because
// its processing may have been interrupted. This file will be
// processed again in the next pass.
if (this.eventDeliveryPeriodAborted)
{
this.TraceSource.WriteInfo(
this.LogSourceId,
"The event delivery pass is being aborted. Therefore, no more files in the buffered event directory will be processed.");
break;
}
// If we are in the process of stopping, then don't process any
// more files. Also, don't delete the current file because its
// processing may have been interrupted. This file will be
// processed again when we are restarted.
if (this.Stopping)
{
this.TraceSource.WriteInfo(
this.LogSourceId,
"The consumer is being stopped. Therefore, no more files in the buffered event directory will be processed.");
break;
}
// Add the file to the list of files that we delete at the end
// of the event delivery pass
filesToDelete.Add(eventFile);
if (0 > DateTime.Compare(processingEndTime, DateTime.Now))
{
this.TraceSource.WriteInfo(
this.LogSourceId,
"Due to time limit on backlog processing, no more files in the buffered event directory will be processed in this pass.");
break;
}
}
// Perform any tasks necessary at the end of the ETL processing pass
this.eventSink.OnEtwEventDeliveryStop();
// Delete the files that we successfully processed in this pass
foreach (string fileToDelete in filesToDelete)
{
try
{
Utility.PerformIOWithRetries(
ctx =>
{
string fileName = ctx;
FabricFile.Delete(fileName);
},
fileToDelete);
}
catch (Exception e)
{
this.TraceSource.WriteExceptionAsError(
this.LogSourceId,
e,
"Failed to delete file {0}.",
fileToDelete);
}
}
// Write performance-related information.
this.perfHelper.RecordEventDeliveryBacklog(eventFilesInfo.Length - filesProcessed);
this.perfHelper.EventDeliveryPassEnd();
// Schedule the next pass
this.eventDeliveryTimer.Start();
}
