protected void QueueEtwTrace(DecodedEventWrapper e) { // Events are always processed in batches where each batch contains // events that have the same timestamp. The reason is as follows. // // The last batch of events from an active ETL file (i.e. an ETL // file that ETW is still writing to) might be read more than once. // This is because we don't know whether more events will get // written to that ETL file with the exact same timestamp after the // current pass. Therefore, we make note of that timestamp and // retrieve events from that timestamp in the next pass too. As a // result, some of those events might get read more than once. // Because of this, special handling is required for the last batch // of events in an active ETL file. Therefore, we process ETW events // in batches, where a batch is defined as a set of events bearing // the same timestamp. // Check if we should process the ETW events that we have batched up // so far. if (this.ShouldProcessPendingEtwTraces(e.Timestamp)) { this.ProcessPendingEtwTraces(); } // Add new ETW event to queue this.AddToPendingEtwTraces(e); }
private Closeness ComputeCloseness(FilterElement filterElement, DecodedEventWrapper etwEvent) { if (null == filterElement.TaskName) { // If the task name for this filter is a wildcard, the event name // should also be a wildcard because we don't support filters of // the format '*.<eventType>'. This means we have a wildcard match. System.Fabric.Interop.Utility.ReleaseAssert(null == filterElement.EventType, StringResources.DCAError_EventNameNotAWildcard); return(Closeness.TaskWildcardEventWildcardMatch); } if (false == filterElement.TaskName.Equals(etwEvent.TaskName)) { // If the task name for this filter does not match the event's // task name, then we have no match. return(Closeness.NoMatch); } if (null == filterElement.EventType) { // If the event name for this filter is a wildcard, we have a // task name, event wildcard match. return(Closeness.TaskNameEventWildcardMatch); } if (false == filterElement.EventType.Equals(etwEvent.EventType)) { // If the event name for this filter does not match the event's // event name, then we have no match. return(Closeness.NoMatch); } // If we get here, it means that both task name and event name match return(Closeness.TaskNameEventTypeMatch); }
protected override void ProcessTraceEvent(DecodedEventWrapper eventWrapper) { System.Fabric.Interop.Utility.ReleaseAssert(this.bookmark != null, StringResources.DCAError_ProcessTraceEventCalledUnexpectedly); this.perfHelper.EtwEventProcessed(); // If it is a Windows Fabric event, then check the filters to see if // the event should be included in the ETW traces. if (this.FiltersAllowEventInclusion(eventWrapper)) { // According to the filters, the event should be included. // Compute the row key for this event. // // The row key is in the following format: // <etlFileBookmark>_<eventSequenceNumberInEtlFile> // // By choosing the row key in this manner, we ensure the following: // - The row key for an event is unique within the partition. // Recall that the partition in this case is the deployment // ID of the role instance. // - If an event happens to get processed multiple times (for // example because the previous pass was interrupted), it // gets the same row key each time. Thus event processing is // idempotent. // // Uniqueness and idempotence are ensured because the event // sequence number for an ETL file starts at 0 on every pass and // increases for each event in the pass. If the same ETL file is // read in multiple passes, bookmark for that ETL file is // different for every pass, unless a pass is interrupted. If a // pass is interrupted, the next pass has the same bookmark, but // it also starts reading events from the same point within the // ETL file. Thus, the comination of bookmark and event sequence // number for an event is always unique within a role instance // and always the same if that event is processed multiple times. string nodesUniqueEventId = string.Concat( this.bookmark, "_", this.eventSequenceNumber.ToString(CultureInfo.InvariantCulture)); // Write the event to the cache this.WriteTraceEvent(eventWrapper, nodesUniqueEventId); this.perfHelper.EventWrittenToLocalBuffer(); } // Increment the event sequence number. This needs to be done // regardless of whether the event was included or not. This way, if // an event is processed in multiple passes (for example because a // previous pass was interrupted) and the filtering criteria changes // in between passes, all events still have the same sequence numbers. // Thus, the sequence numbers are kept independent of the results of // filtering. this.eventSequenceNumber++; }
private void ProcessPendingEtwTraces() { while (this.pendingEtwEvents.EventList.Count > 0) { // Remove an event DecodedEventWrapper e = this.pendingEtwEvents.EventList.Dequeue(); // Process the event this.ProcessTraceEvent(e); } }
private void AddToPendingEtwTraces(DecodedEventWrapper e) { this.pendingEtwEvents.Timestamp = e.Timestamp; // Assign a timestamp differentiator to the event in order to distinguish // it from other events in the same ETL file that also bear the same // timestamp. Timestamp differentiator values start at 0 for each // timestamp and are incremented by 1 for each event bearing that // timestamp. e.TimestampDifferentiator = this.pendingEtwEvents.EventList.Count; this.pendingEtwEvents.EventList.Enqueue(e); }
private void MatchEventWithFilter(FilterElement filterElement, DecodedEventWrapper etwEvent, out Closeness closeness, out bool includeEvent) { includeEvent = false; // Figure out if we have a match and if so how close is the match closeness = this.ComputeCloseness(filterElement, etwEvent); // If we have a match, figure out whether the event should be // included or not if (closeness > Closeness.NoMatch) { includeEvent = filterElement.Level >= etwEvent.Level; } }
internal bool ShouldIncludeEvent(DecodedEventWrapper etwEvent) { // If there are no filters, then we should include the event if (null == this.filters) { return(true); } // If we have filters, then don't include the event unless the // filters effectively ask for it to be included. bool includeEvent = false; Closeness closeness = Closeness.NoMatch; // Go through each filter and compare ... foreach (FilterElement filterElement in this.filters) { // Check if the event matches the current filter. If it matches, // check whether the filter asks for the event to be included or // excluded. bool tempIncludeEvent; Closeness tempCloseness; this.MatchEventWithFilter( filterElement, etwEvent, out tempCloseness, out tempIncludeEvent); // If this filter is a closer match than previously encountered // filters, then update our decision to include or exclude the // event. // If this filter is not a closer match than previously // encountered filters, then we do not update our decision. if (tempCloseness > closeness) { System.Fabric.Interop.Utility.ReleaseAssert(tempCloseness != Closeness.NoMatch, string.Empty); includeEvent = tempIncludeEvent; closeness = tempCloseness; if (Closeness.MaxCloseness == closeness) { // We already found the closest possible match. We can't // find a closer match than this. So break out of the loop. break; } } } return(includeEvent); }
protected override void ProcessTraceEvent(DecodedEventWrapper eventWrapper) { #if !DotNetCoreClr this.perfHelper.EtwEventProcessed(); #endif if (null == this.fileSink) { // An error occurred during the creation of the temporary file // sink. So just return immediately without doing anything. return; } // Record the index of this event this.lastEventIndex.Set(eventWrapper.Timestamp, eventWrapper.TimestampDifferentiator); // 1. Check if the event has already been processed in a previous pass. // This check would effectively drop out of order timestamp events. // 2. If we are using compression, then we don't filter the logs. Just // include everything. // 3. If we're not using compression and it is a Windows Fabric event, // then check the filters to see if the event should be included in // the ETW traces. if ((this.lastEventIndex.CompareTo(this.maxIndexAlreadyProcessed) > 0) && (this.compressCsvFiles || this.FiltersAllowEventInclusion(eventWrapper))) { // According to the filters, the event should be included. // Write the event to the ETW CSV file. try { this.fileSink.WriteEvent(eventWrapper.StringRepresentation.Replace("\r\n", "\r\t").Replace("\n", "\t")); #if !DotNetCoreClr this.perfHelper.EventWrittenToCsv(); #endif } catch (Exception e) { // Log an error and move on this.TraceSource.WriteExceptionAsError( this.LogSourceId, e, "Failed to write filtered event {0} to trace file {1}.", eventWrapper.StringRepresentation, this.fileSink.TempFileName); } } }
protected bool FiltersAllowEventInclusion(DecodedEventWrapper e) { lock (this.FilterLock) { if (null == this.Filter) { // If the filter object is null, then the event gets included. return(true); } if (this.Filter.IsWindowsFabricEventFilter) { if (this.IsProcessingWindowsFabricEtlFiles) { return(this.Filter.ShouldIncludeEvent(e)); } return(true); } return(this.Filter.ShouldIncludeEvent(e)); } }
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."); } }
protected abstract void ProcessTraceEvent(DecodedEventWrapper eventWrapper);