// Processes the messages that have been buffered. // It is called by the ASP.NET when the flushing of // the buffer is required according to the parameters // defined in the <bufferModes> element of the // <healthMonitoring> configuration section. public override void ProcessEventFlush( WebEventBufferFlushInfo flushInfo) { // Customize event information to be logged. customInfo.AppendLine( "SampleEventLogWebEventProvider buffer flush."); customInfo.AppendLine( string.Format("NotificationType: {0}", flushInfo.NotificationType)); customInfo.AppendLine( string.Format("EventsInBuffer: {0}", flushInfo.EventsInBuffer)); customInfo.AppendLine( string.Format("EventsDiscardedSinceLastNotification: {0}", flushInfo.EventsDiscardedSinceLastNotification)); // Read each buffered event and send it to the // Log. foreach (WebBaseEvent eventRaised in flushInfo.Events) customInfo.AppendLine(eventRaised.ToString()); // Store the information in the specified file. StoreToFile(customInfo, connectionString, FileMode.Append); }
internal abstract void SendMessage(WebBaseEventCollection events, WebEventBufferFlushInfo flushInfo, int eventsInNotification, int eventsRemaining, int messagesInNotification, int eventsLostDueToMessageLimit, int messageSequence, int eventsSent, out bool fatalError);
public override void ProcessEventFlush(WebEventBufferFlushInfo flushInfo) { Debug.Trace("SqlWebEventProvider", "EventBufferFlush called: " + "NotificationType=" + flushInfo.NotificationType + ", NotificationSequence=" + flushInfo.NotificationSequence + ", Events.Count=" + flushInfo.Events.Count); WriteToSQL(flushInfo.Events, flushInfo.EventsDiscardedSinceLastNotification, flushInfo.LastNotificationUtc); }
public override void ProcessEvent(WebBaseEvent eventRaised) { if (this._buffer) { this._webEventBuffer.AddEvent(eventRaised); } else { WebEventBufferFlushInfo flushInfo = new WebEventBufferFlushInfo(new WebBaseEventCollection(eventRaised), EventNotificationType.Unbuffered, 0, DateTime.MinValue, 0, 0); this.ProcessEventFlush(flushInfo); } }
public override void ProcessEvent(WebBaseEvent eventRaised) { if (_buffer) { // register the event with the buffer instead of writing it out Debug.Trace("BufferedWebEventProvider", "Saving event to buffer: event=" + eventRaised.GetType().Name); _webEventBuffer.AddEvent(eventRaised); } else { WebEventBufferFlushInfo flushInfo = new WebEventBufferFlushInfo( new WebBaseEventCollection(eventRaised), EventNotificationType.Unbuffered, 0, DateTime.MinValue, 0, 0); ProcessEventFlush(flushInfo); } }
internal override void SendMessage(WebBaseEventCollection events, WebEventBufferFlushInfo flushInfo, int eventsInNotification, int eventsRemaining, int messagesInNotification, int eventsLostDueToMessageLimit, int messageSequence, int eventsSent, out bool fatalError) { SendMessageInternal(events, flushInfo.NotificationSequence, eventsSent, flushInfo.LastNotificationUtc, flushInfo.EventsDiscardedSinceLastNotification, flushInfo.EventsInBuffer, messageSequence, messagesInNotification, eventsInNotification, eventsLostDueToMessageLimit); fatalError = false; }
public override void ProcessEventFlush(WebEventBufferFlushInfo flushInfo) { int eventsInNotification = flushInfo.Events.Count; int eventsRemaining = eventsInNotification; bool split = false; int messageSequence = MessageSequenceBase; int messagesInNotification; int eventsToBeDiscarded = 0; bool fatalError = false; if (eventsInNotification == 0) { return; } WebBaseEventCollection eventsToSend; WebBaseEvent[] eventsChunk = null; // We will split based on MaxEventsPerMessage if (eventsInNotification > MaxEventsPerMessage) { split = true; // I use the below clumsy calculation instead of (a+b-1)/b is to avoid // Int32 overflow. messagesInNotification = eventsInNotification / MaxEventsPerMessage; if (eventsInNotification > messagesInNotification * MaxEventsPerMessage) { messagesInNotification++; } // We will exceed the limit. if (messagesInNotification > MaxMessagesPerNotification) { eventsToBeDiscarded = eventsInNotification - MaxMessagesPerNotification * MaxEventsPerMessage; messagesInNotification = MaxMessagesPerNotification; eventsInNotification -= eventsToBeDiscarded; } } else { messagesInNotification = 1; } // In each email we only send a max of MaxEventsPerMessage events for (int eventsSent = 0; eventsSent < eventsInNotification; messageSequence++) { if (split) { int chunkSize = Math.Min(MaxEventsPerMessage, eventsInNotification - eventsSent); if (eventsChunk == null || eventsChunk.Length != chunkSize) { eventsChunk = new WebBaseEvent[chunkSize]; } for (int i = 0; i < chunkSize; i++) { eventsChunk[i] = flushInfo.Events[i + eventsSent]; } eventsToSend = new WebBaseEventCollection(eventsChunk); } else { eventsToSend = flushInfo.Events; } Debug.Trace("MailWebEventProvider", "Calling SendMessageInternal; # of events: " + eventsToSend.Count); SendMessage( eventsToSend, flushInfo, eventsInNotification, eventsInNotification - (eventsSent + eventsToSend.Count), // eventsRemaining messagesInNotification, eventsToBeDiscarded, messageSequence, eventsSent, out fatalError); if (fatalError) { Debug.Trace("MailWebEventProvider", "Stop sending because we hit a fatal error"); break; } eventsSent += eventsToSend.Count; } }
public override void ProcessEventFlush(WebEventBufferFlushInfo flushInfo) { this.WriteToSQL(flushInfo.Events, flushInfo.EventsDiscardedSinceLastNotification, flushInfo.LastNotificationUtc); }
public abstract void ProcessEventFlush(WebEventBufferFlushInfo flushInfo);
public override void ProcessEventFlush(WebEventBufferFlushInfo flushInfo) { }
public override void ProcessEventFlush(WebEventBufferFlushInfo flushInfo) { int count = flushInfo.Events.Count; bool flag = false; int messageSequence = 1; int eventsLostDueToMessageLimit = 0; bool fatalError = false; if (count != 0) { int maxMessagesPerNotification; WebBaseEvent[] eventArray = null; if (count > this.MaxEventsPerMessage) { flag = true; maxMessagesPerNotification = count / this.MaxEventsPerMessage; if (count > (maxMessagesPerNotification * this.MaxEventsPerMessage)) { maxMessagesPerNotification++; } if (maxMessagesPerNotification > this.MaxMessagesPerNotification) { eventsLostDueToMessageLimit = count - (this.MaxMessagesPerNotification * this.MaxEventsPerMessage); maxMessagesPerNotification = this.MaxMessagesPerNotification; count -= eventsLostDueToMessageLimit; } } else { maxMessagesPerNotification = 1; } int eventsSent = 0; while (eventsSent < count) { WebBaseEventCollection events; if (flag) { int num6 = Math.Min(this.MaxEventsPerMessage, count - eventsSent); if ((eventArray == null) || (eventArray.Length != num6)) { eventArray = new WebBaseEvent[num6]; } for (int i = 0; i < num6; i++) { eventArray[i] = flushInfo.Events[i + eventsSent]; } events = new WebBaseEventCollection(eventArray); } else { events = flushInfo.Events; } this.SendMessage(events, flushInfo, count, count - (eventsSent + events.Count), maxMessagesPerNotification, eventsLostDueToMessageLimit, messageSequence, eventsSent, out fatalError); if (fatalError) { return; } eventsSent += events.Count; messageSequence++; } } }
public override void ProcessEventFlush(WebEventBufferFlushInfo flushInfo) { writeEvents(flushInfo.Events); }
/// <summary> /// Processes the buffered events. /// </summary> /// <param name="flushInfo">A <see cref="T:System.Web.Management.WebEventBufferFlushInfo"/> that contains buffering information.</param> public override void ProcessEventFlush(WebEventBufferFlushInfo flushInfo) { if (flushInfo == null) { throw new ArgumentNullException("flushInfo"); } foreach (WebBaseEvent eventRaised in flushInfo.Events) { string extraInfo = string.Empty; WebBaseErrorEvent webBasedErrorEvent = eventRaised as WebBaseErrorEvent; if (webBasedErrorEvent != null) { extraInfo = webBasedErrorEvent.ErrorException.ToString(); } string line = string.Format( CultureInfo.InvariantCulture, "Event Time (UTC):[{0}] Event Code:[{1}] Event Id:[{2}] Event Message:[{3}]", eventRaised.EventTimeUtc, eventRaised.EventCode, eventRaised.EventID, eventRaised.Message + " " + extraInfo); if (this.Name == "ErrorEventProvider") { Console.Error.WriteLine(line); } else { Console.Out.WriteLine(line); } } }
/// <summary> /// Processes the buffered events. /// </summary> /// <param name="flushInfo">A <see cref="T:System.Web.Management.WebEventBufferFlushInfo"/> that contains buffering information.</param> public override void ProcessEventFlush(WebEventBufferFlushInfo flushInfo) { if (flushInfo == null) { throw new ArgumentNullException("flushInfo"); } foreach (WebBaseEvent eventRaised in flushInfo.Events) { string extraInfo = string.Empty; WebBaseErrorEvent webBasedErrorEvent = eventRaised as WebBaseErrorEvent; if (webBasedErrorEvent != null) { extraInfo = webBasedErrorEvent.ErrorException.ToString(); } this.customInfo.AppendLine( string.Format( CultureInfo.InvariantCulture, "Event Time (UTC):[{0}] Event Code:[{1}] Event Id:[{2}] Event Message:[{3}]", eventRaised.EventTimeUtc, eventRaised.EventCode, eventRaised.EventID, eventRaised.Message + " " + extraInfo)); } this.StoreToFile(FileMode.Append); }
internal void Flush(int max, FlushCallReason reason) { WebBaseEvent[] events = null; DateTime utcNow = DateTime.UtcNow; long waitTimeMs = 0L; DateTime maxValue = DateTime.MaxValue; int eventsDiscardedSinceLastNotification = -1; int eventsInBuffer = -1; int num4 = 0; EventNotificationType regular = EventNotificationType.Regular; bool flag = true; bool flag2 = false; bool flag3 = false; lock (this._buffer) { if (this._buffer.Count == 0) { flag = false; } switch (reason) { case FlushCallReason.UrgentFlushThresholdExceeded: if (!this._urgentFlushScheduled) { break; } return; case FlushCallReason.Timer: if (this._regularFlushIntervalMs != Infinite) { flag2 = true; waitTimeMs = this.GetNextRegularFlushDueTimeInMs(); } goto Label_00D3; default: goto Label_00D3; } flag = false; flag2 = true; flag3 = true; if (this.AnticipateBurst(utcNow)) { waitTimeMs = this._burstWaitTimeMs; } else { waitTimeMs = 0L; } TimeSpan span = (TimeSpan) (utcNow - this._lastScheduledFlushTime); long totalMilliseconds = (long) span.TotalMilliseconds; if ((totalMilliseconds + waitTimeMs) < this._urgentFlushIntervalMs) { waitTimeMs = this._urgentFlushIntervalMs - totalMilliseconds; } Label_00D3: if (flag) { if (this._threadsInFlush >= this._maxBufferThreads) { num4 = 0; } else { num4 = Math.Min(this._buffer.Count, max); } } if (flag) { if (num4 > 0) { events = new WebBaseEvent[num4]; for (int i = 0; i < num4; i++) { events[i] = (WebBaseEvent) this._buffer.Dequeue(); } maxValue = this._lastFlushTime; this._lastFlushTime = utcNow; if (reason == FlushCallReason.Timer) { this._lastScheduledFlushTime = utcNow; } eventsDiscardedSinceLastNotification = this._discardedSinceLastFlush; this._discardedSinceLastFlush = 0; if (reason == FlushCallReason.StaticFlush) { regular = EventNotificationType.Flush; } else { regular = this._regularTimeoutUsed ? EventNotificationType.Regular : EventNotificationType.Urgent; } } eventsInBuffer = this._buffer.Count; if (eventsInBuffer >= this._urgentFlushThreshold) { flag2 = true; flag3 = true; waitTimeMs = this._urgentFlushIntervalMs; } } this._urgentFlushScheduled = false; if (flag2) { if (flag3) { long nextRegularFlushDueTimeInMs = this.GetNextRegularFlushDueTimeInMs(); if (nextRegularFlushDueTimeInMs < waitTimeMs) { waitTimeMs = nextRegularFlushDueTimeInMs; this._regularTimeoutUsed = true; } else { this._regularTimeoutUsed = false; } } else { this._regularTimeoutUsed = true; } this.SetTimer(waitTimeMs); this._urgentFlushScheduled = flag3; } if ((reason == FlushCallReason.Timer) && !flag2) { this._timer.Dispose(); this._timer = null; this._urgentFlushScheduled = false; } if (events != null) { Interlocked.Increment(ref this._threadsInFlush); } } if (events != null) { ApplicationImpersonationContext context = new ApplicationImpersonationContext(); try { WebEventBufferFlushInfo flushInfo = new WebEventBufferFlushInfo(new WebBaseEventCollection(events), regular, Interlocked.Increment(ref this._notificationSequence), maxValue, eventsDiscardedSinceLastNotification, eventsInBuffer); this._flushCallback(flushInfo); } catch (Exception exception) { try { this._provider.LogException(exception); } catch { } } catch { try { this._provider.LogException(new Exception(System.Web.SR.GetString("Provider_Error"))); } catch { } } finally { if (context != null) { ((IDisposable) context).Dispose(); } } Interlocked.Decrement(ref this._threadsInFlush); } }
internal void Flush(int max, FlushCallReason reason) { WebBaseEvent[] events = null; DateTime utcNow = DateTime.UtcNow; long waitTimeMs = 0L; DateTime maxValue = DateTime.MaxValue; int eventsDiscardedSinceLastNotification = -1; int eventsInBuffer = -1; int num4 = 0; EventNotificationType regular = EventNotificationType.Regular; bool flag = true; bool flag2 = false; bool flag3 = false; lock (this._buffer) { if (this._buffer.Count == 0) { flag = false; } switch (reason) { case FlushCallReason.UrgentFlushThresholdExceeded: if (!this._urgentFlushScheduled) { break; } return; case FlushCallReason.Timer: if (this._regularFlushIntervalMs != Infinite) { flag2 = true; waitTimeMs = this.GetNextRegularFlushDueTimeInMs(); } goto Label_00D3; default: goto Label_00D3; } flag = false; flag2 = true; flag3 = true; if (this.AnticipateBurst(utcNow)) { waitTimeMs = this._burstWaitTimeMs; } else { waitTimeMs = 0L; } TimeSpan span = (TimeSpan)(utcNow - this._lastScheduledFlushTime); long totalMilliseconds = (long)span.TotalMilliseconds; if ((totalMilliseconds + waitTimeMs) < this._urgentFlushIntervalMs) { waitTimeMs = this._urgentFlushIntervalMs - totalMilliseconds; } Label_00D3: if (flag) { if (this._threadsInFlush >= this._maxBufferThreads) { num4 = 0; } else { num4 = Math.Min(this._buffer.Count, max); } } if (flag) { if (num4 > 0) { events = new WebBaseEvent[num4]; for (int i = 0; i < num4; i++) { events[i] = (WebBaseEvent)this._buffer.Dequeue(); } maxValue = this._lastFlushTime; this._lastFlushTime = utcNow; if (reason == FlushCallReason.Timer) { this._lastScheduledFlushTime = utcNow; } eventsDiscardedSinceLastNotification = this._discardedSinceLastFlush; this._discardedSinceLastFlush = 0; if (reason == FlushCallReason.StaticFlush) { regular = EventNotificationType.Flush; } else { regular = this._regularTimeoutUsed ? EventNotificationType.Regular : EventNotificationType.Urgent; } } eventsInBuffer = this._buffer.Count; if (eventsInBuffer >= this._urgentFlushThreshold) { flag2 = true; flag3 = true; waitTimeMs = this._urgentFlushIntervalMs; } } this._urgentFlushScheduled = false; if (flag2) { if (flag3) { long nextRegularFlushDueTimeInMs = this.GetNextRegularFlushDueTimeInMs(); if (nextRegularFlushDueTimeInMs < waitTimeMs) { waitTimeMs = nextRegularFlushDueTimeInMs; this._regularTimeoutUsed = true; } else { this._regularTimeoutUsed = false; } } else { this._regularTimeoutUsed = true; } this.SetTimer(waitTimeMs); this._urgentFlushScheduled = flag3; } if ((reason == FlushCallReason.Timer) && !flag2) { this._timer.Dispose(); this._timer = null; this._urgentFlushScheduled = false; } if (events != null) { Interlocked.Increment(ref this._threadsInFlush); } } if (events != null) { ApplicationImpersonationContext context = new ApplicationImpersonationContext(); try { WebEventBufferFlushInfo flushInfo = new WebEventBufferFlushInfo(new WebBaseEventCollection(events), regular, Interlocked.Increment(ref this._notificationSequence), maxValue, eventsDiscardedSinceLastNotification, eventsInBuffer); this._flushCallback(flushInfo); } catch (Exception exception) { try { this._provider.LogException(exception); } catch { } } catch { try { this._provider.LogException(new Exception(System.Web.SR.GetString("Provider_Error"))); } catch { } } finally { if (context != null) { ((IDisposable)context).Dispose(); } } Interlocked.Decrement(ref this._threadsInFlush); } }
public override void ProcessEventFlush(WebEventBufferFlushInfo flushInfo) { this.mongoCollection.InsertBatch<WebEvent>(flushInfo.Events.Cast<WebBaseEvent>().ToList().ConvertAll<WebEvent>(WebEvent.FromWebBaseEvent)); }
public override void ProcessEventFlush(WebEventBufferFlushInfo flushInfo) { int eventsInNotification = flushInfo.Events.Count; int eventsRemaining = eventsInNotification; bool split = false; int messageSequence = MessageSequenceBase; int messagesInNotification; int eventsToBeDiscarded = 0; bool fatalError = false; if (eventsInNotification == 0) { return; } WebBaseEventCollection eventsToSend; WebBaseEvent[] eventsChunk = null; // We will split based on MaxEventsPerMessage if (eventsInNotification > MaxEventsPerMessage) { split = true; // I use the below clumsy calculation instead of (a+b-1)/b is to avoid // Int32 overflow. messagesInNotification = eventsInNotification/MaxEventsPerMessage; if (eventsInNotification > messagesInNotification*MaxEventsPerMessage) { messagesInNotification++; } // We will exceed the limit. if (messagesInNotification > MaxMessagesPerNotification) { eventsToBeDiscarded = eventsInNotification - MaxMessagesPerNotification * MaxEventsPerMessage; messagesInNotification = MaxMessagesPerNotification; eventsInNotification -= eventsToBeDiscarded; } } else { messagesInNotification = 1; } // In each email we only send a max of MaxEventsPerMessage events for(int eventsSent = 0; eventsSent < eventsInNotification; messageSequence++) { if (split) { int chunkSize = Math.Min(MaxEventsPerMessage, eventsInNotification - eventsSent); if (eventsChunk == null || eventsChunk.Length != chunkSize) { eventsChunk = new WebBaseEvent[chunkSize]; } for(int i = 0; i < chunkSize; i++) { eventsChunk[i] = flushInfo.Events[i + eventsSent]; } eventsToSend = new WebBaseEventCollection(eventsChunk); } else { eventsToSend = flushInfo.Events; } Debug.Trace("MailWebEventProvider", "Calling SendMessageInternal; # of events: " + eventsToSend.Count); SendMessage( eventsToSend, flushInfo, eventsInNotification, eventsInNotification - (eventsSent + eventsToSend.Count), // eventsRemaining messagesInNotification, eventsToBeDiscarded, messageSequence, eventsSent, out fatalError); if (fatalError) { Debug.Trace("MailWebEventProvider", "Stop sending because we hit a fatal error"); break; } eventsSent += eventsToSend.Count; } }
// This method can be called by the timer, or by AddEvent. // // Basic design: // - We have one timer, and one buffer. // - We flush periodically every _regularFlushIntervalMs ms // - But if # of items in buffer has reached _urgentFlushThreshold, we will flush more frequently, // but at most once every _urgentFlushIntervalMs ms. However, these urgent flushes will not // prevent the regular flush from happening. // - We never flush synchronously, meaning if we're called by AddEvent and decide to flush // because we've reached the _urgentFlushThreshold, we will still use the timer thread // to flush the buffer. // - At any point only a maximum of _maxBufferThreads threads can be flushing. If exceeded, // we will delay a flush. // // // For example, let's say we have this setting: // "1 minute urgentFlushInterval and 5 minute regularFlushInterval" // // Assume regular flush timer starts at 10:00am. It means regular // flush will happen at 10:05am, 10:10am, 10:15am, and so on, // regardless of when urgent flush happens. // // An "urgent flush" happens whenever urgentFlushThreshold is reached. // However, when we schedule an "urgent flush", we ensure that the time // between an urgent flush and the last flush (no matter it's urgent or // regular) will be at least urgentFlushInterval. // // One interesting case here. Assume at 10:49:30 we had an urgent // flush, but the # of events left is still above urgentFlushThreshold. // You may think we'll schedule the next urgent flush at 10:50:30 // (urgentFlushInterval == 1 min). However, because we know we will // have a regular flush at 10:50:00, we won't schedule the next urgent // flush. Instead, during the regular flush at 10:50:00 happens, we'll // check if there're still too many events; and if so, we will schedule // the next urgent flush at 10:51:00. // internal void Flush(int max, FlushCallReason reason) { WebBaseEvent[] events = null; DateTime nowUtc = DateTime.UtcNow; long waitTime = 0; DateTime lastFlushTime = DateTime.MaxValue; int discardedSinceLastFlush = -1; int eventsInBuffer = -1; int toFlush = 0; EventNotificationType notificationType = EventNotificationType.Regular; // By default, this call will flush, but will not schedule the next flush. bool flushThisTime = true; bool scheduleNextFlush = false; bool nextFlushIsUrgent = false; lock(_buffer) { Debug.Assert(max > 0, "max > 0"); if (_buffer.Count == 0) { // We have nothing in the buffer. Don't flush this time. Debug.Trace("WebEventBufferExtended", "Flush: buffer is empty, don't flush"); flushThisTime = false; } switch (reason) { case FlushCallReason.StaticFlush: // It means somebody calls provider.Flush() break; case FlushCallReason.Timer: // It's a callback from a timer. We will schedule the next regular flush if needed. if (_regularFlushIntervalMs != Infinite) { scheduleNextFlush = true; waitTime = GetNextRegularFlushDueTimeInMs(); } break; case FlushCallReason.UrgentFlushThresholdExceeded: // It means this method is called by AddEvent because the urgent flush threshold is reached. // If an urgent flush has already been scheduled by someone else, we don't need to duplicate the // effort. Just return. if (_urgentFlushScheduled) { return; } // Flush triggered by AddEvent isn't synchronous, so we won't flush this time, but will // schedule an urgent flush instead. flushThisTime = false; scheduleNextFlush = true; nextFlushIsUrgent = true; // Calculate how long we have to wait when scheduling the flush if (AnticipateBurst(nowUtc)) { Debug.Trace("WebEventBuffer", "Flush: Called by AddEvent. Waiting for burst"); waitTime = _burstWaitTimeMs; } else { Debug.Trace("WebEventBuffer", "Flush: Called by AddEvent. Schedule an immediate flush"); waitTime = 0; } // Have to wait longer because of _urgentFlushIntervalMs long msSinceLastScheduledFlush = (long)(nowUtc - _lastScheduledFlushTime).TotalMilliseconds; if (msSinceLastScheduledFlush + waitTime < _urgentFlushIntervalMs ) { Debug.Trace("WebEventBuffer", "Flush: Called by AddEvent. Have to wait longer because of _urgentFlushIntervalMs."); waitTime = _urgentFlushIntervalMs - msSinceLastScheduledFlush; } Debug.Trace("WebEventBuffer", "Wait time=" + waitTime + "; nowUtc=" + PrintTime(nowUtc) + "; _lastScheduledFlushTime=" + PrintTime(_lastScheduledFlushTime) + "; _urgentFlushIntervalMs=" + _urgentFlushIntervalMs); break; } Debug.Trace("WebEventBuffer", "Flush called: max=" + max + "; reason=" + reason); if (flushThisTime) { // Check if we've exceeded the # of flushing threads. If so, // don't flush this time. if (_threadsInFlush >= _maxBufferThreads) { // Won't set flushThisTime to false because we depend on // the logic inside the next "if" block to schedule the // next urgent flush as needed. toFlush = 0; } else { toFlush = Math.Min(_buffer.Count, max); } } #if DBG DebugUpdateStats(flushThisTime, nowUtc, toFlush, reason); #endif if (flushThisTime) { Debug.Assert(reason != FlushCallReason.UrgentFlushThresholdExceeded, "reason != FlushCallReason.UrgentFlushThresholdExceeded"); if (toFlush > 0) { // Move the to-be-flushed events to an array events = new WebBaseEvent[toFlush]; for (int i = 0; i < toFlush; i++) { events[i] = (WebBaseEvent)_buffer.Dequeue(); } lastFlushTime = _lastFlushTime; // Update _lastFlushTime and _lastScheduledFlushTime. // These information are used when Flush is called the next time. _lastFlushTime = nowUtc; if (reason == FlushCallReason.Timer) { _lastScheduledFlushTime = nowUtc; } discardedSinceLastFlush = _discardedSinceLastFlush; _discardedSinceLastFlush = 0; if (reason == FlushCallReason.StaticFlush) { notificationType = EventNotificationType.Flush; } else { Debug.Assert(!(!_regularTimeoutUsed && !_urgentFlushScheduled), "It's impossible to have a non-regular flush and yet the flush isn't urgent"); notificationType = _regularTimeoutUsed ? EventNotificationType.Regular : EventNotificationType.Urgent; } } eventsInBuffer = _buffer.Count; // If we still have at least _urgentFlushThreshold left, set timer // to flush asap. if (eventsInBuffer >= _urgentFlushThreshold) { Debug.Trace("WebEventBuffer", "Flush: going to flush " + toFlush + " events, but still have at least _urgentFlushThreshold left. Schedule a flush"); scheduleNextFlush = true; nextFlushIsUrgent = true; waitTime = _urgentFlushIntervalMs; } else { Debug.Trace("WebEventBuffer", "Flush: going to flush " + toFlush + " events"); } } // We are done moving the flushed events to the 'events' array. // Now schedule the next flush if needed. _urgentFlushScheduled = false; if (scheduleNextFlush) { if (nextFlushIsUrgent) { long nextRegular = GetNextRegularFlushDueTimeInMs(); // If next regular flush is closer than next urgent flush, // use regular flush instead. if (nextRegular < waitTime) { Debug.Trace("WebEventBuffer", "Switch to use regular timeout"); waitTime = nextRegular; _regularTimeoutUsed = true; } else { _regularTimeoutUsed = false; } } else { _regularTimeoutUsed = true; } SetTimer(waitTime); _urgentFlushScheduled = nextFlushIsUrgent; #if DBG Debug.Trace("WebEventBuffer", "Flush: Registered for a flush. Waittime = " + waitTime + "ms" + "; _nextFlush=" + PrintTime(_nextFlush) + "; _urgentFlushScheduled=" + _urgentFlushScheduled); #endif } // Cleanup. If we are called by a timer callback, but we haven't scheduled for the next // one (can only happen if _regularFlushIntervalMs == Infinite), we should dispose the timer if (reason == FlushCallReason.Timer && !scheduleNextFlush) { Debug.Trace("WebEventBuffer", "Flush: Disposing the timer"); Debug.Assert(_regularFlushIntervalMs == Infinite, "We can dispose the timer only if _regularFlushIntervalMs == Infinite"); ((IDisposable)_timer).Dispose(); _timer = null; _urgentFlushScheduled = false; } // We want to increment the thread count within the lock to ensure we don't let too many threads in if (events != null) { Interlocked.Increment(ref _threadsInFlush); } } // Release lock // Now call the providers to flush the events if (events != null) { Debug.Assert(lastFlushTime != DateTime.MaxValue, "lastFlushTime != DateTime.MaxValue"); Debug.Assert(discardedSinceLastFlush != -1, "discardedSinceLastFlush != -1"); Debug.Assert(eventsInBuffer != -1, "eventsInBuffer != -1"); Debug.Trace("WebEventBufferSummary", "_threadsInFlush=" + _threadsInFlush); using (new ApplicationImpersonationContext()) { try { WebEventBufferFlushInfo flushInfo = new WebEventBufferFlushInfo( new WebBaseEventCollection(events), notificationType, Interlocked.Increment(ref _notificationSequence), lastFlushTime, discardedSinceLastFlush, eventsInBuffer); _flushCallback(flushInfo); } catch (Exception e) { try { _provider.LogException(e); } catch { // Ignore all errors } } #pragma warning disable 1058 catch { // non compliant exceptions are caught and logged as Unknown try { _provider.LogException(new Exception(SR.GetString(SR.Provider_Error))); } catch { // Ignore all errors } } #pragma warning restore 1058 } Interlocked.Decrement(ref _threadsInFlush); } }
// This method can be called by the timer, or by AddEvent. // // Basic design: // - We have one timer, and one buffer. // - We flush periodically every _regularFlushIntervalMs ms // - But if # of items in buffer has reached _urgentFlushThreshold, we will flush more frequently, // but at most once every _urgentFlushIntervalMs ms. However, these urgent flushes will not // prevent the regular flush from happening. // - We never flush synchronously, meaning if we're called by AddEvent and decide to flush // because we've reached the _urgentFlushThreshold, we will still use the timer thread // to flush the buffer. // - At any point only a maximum of _maxBufferThreads threads can be flushing. If exceeded, // we will delay a flush. // // // For example, let's say we have this setting: // "1 minute urgentFlushInterval and 5 minute regularFlushInterval" // // Assume regular flush timer starts at 10:00am. It means regular // flush will happen at 10:05am, 10:10am, 10:15am, and so on, // regardless of when urgent flush happens. // // An "urgent flush" happens whenever urgentFlushThreshold is reached. // However, when we schedule an "urgent flush", we ensure that the time // between an urgent flush and the last flush (no matter it's urgent or // regular) will be at least urgentFlushInterval. // // One interesting case here. Assume at 10:49:30 we had an urgent // flush, but the # of events left is still above urgentFlushThreshold. // You may think we'll schedule the next urgent flush at 10:50:30 // (urgentFlushInterval == 1 min). However, because we know we will // have a regular flush at 10:50:00, we won't schedule the next urgent // flush. Instead, during the regular flush at 10:50:00 happens, we'll // check if there're still too many events; and if so, we will schedule // the next urgent flush at 10:51:00. // internal void Flush(int max, FlushCallReason reason) { WebBaseEvent[] events = null; DateTime nowUtc = DateTime.UtcNow; long waitTime = 0; DateTime lastFlushTime = DateTime.MaxValue; int discardedSinceLastFlush = -1; int eventsInBuffer = -1; int toFlush = 0; EventNotificationType notificationType = EventNotificationType.Regular; // By default, this call will flush, but will not schedule the next flush. bool flushThisTime = true; bool scheduleNextFlush = false; bool nextFlushIsUrgent = false; lock (_buffer) { Debug.Assert(max > 0, "max > 0"); if (_buffer.Count == 0) { // We have nothing in the buffer. Don't flush this time. Debug.Trace("WebEventBufferExtended", "Flush: buffer is empty, don't flush"); flushThisTime = false; } switch (reason) { case FlushCallReason.StaticFlush: // It means somebody calls provider.Flush() break; case FlushCallReason.Timer: // It's a callback from a timer. We will schedule the next regular flush if needed. if (_regularFlushIntervalMs != Infinite) { scheduleNextFlush = true; waitTime = GetNextRegularFlushDueTimeInMs(); } break; case FlushCallReason.UrgentFlushThresholdExceeded: // It means this method is called by AddEvent because the urgent flush threshold is reached. // If an urgent flush has already been scheduled by someone else, we don't need to duplicate the // effort. Just return. if (_urgentFlushScheduled) { return; } // Flush triggered by AddEvent isn't synchronous, so we won't flush this time, but will // schedule an urgent flush instead. flushThisTime = false; scheduleNextFlush = true; nextFlushIsUrgent = true; // Calculate how long we have to wait when scheduling the flush if (AnticipateBurst(nowUtc)) { Debug.Trace("WebEventBuffer", "Flush: Called by AddEvent. Waiting for burst"); waitTime = _burstWaitTimeMs; } else { Debug.Trace("WebEventBuffer", "Flush: Called by AddEvent. Schedule an immediate flush"); waitTime = 0; } // Have to wait longer because of _urgentFlushIntervalMs long msSinceLastScheduledFlush = (long)(nowUtc - _lastScheduledFlushTime).TotalMilliseconds; if (msSinceLastScheduledFlush + waitTime < _urgentFlushIntervalMs) { Debug.Trace("WebEventBuffer", "Flush: Called by AddEvent. Have to wait longer because of _urgentFlushIntervalMs."); waitTime = _urgentFlushIntervalMs - msSinceLastScheduledFlush; } Debug.Trace("WebEventBuffer", "Wait time=" + waitTime + "; nowUtc=" + PrintTime(nowUtc) + "; _lastScheduledFlushTime=" + PrintTime(_lastScheduledFlushTime) + "; _urgentFlushIntervalMs=" + _urgentFlushIntervalMs); break; } Debug.Trace("WebEventBuffer", "Flush called: max=" + max + "; reason=" + reason); if (flushThisTime) { // Check if we've exceeded the # of flushing threads. If so, // don't flush this time. if (_threadsInFlush >= _maxBufferThreads) { // Won't set flushThisTime to false because we depend on // the logic inside the next "if" block to schedule the // next urgent flush as needed. toFlush = 0; } else { toFlush = Math.Min(_buffer.Count, max); } } #if DBG DebugUpdateStats(flushThisTime, nowUtc, toFlush, reason); #endif if (flushThisTime) { Debug.Assert(reason != FlushCallReason.UrgentFlushThresholdExceeded, "reason != FlushCallReason.UrgentFlushThresholdExceeded"); if (toFlush > 0) { // Move the to-be-flushed events to an array events = new WebBaseEvent[toFlush]; for (int i = 0; i < toFlush; i++) { events[i] = (WebBaseEvent)_buffer.Dequeue(); } lastFlushTime = _lastFlushTime; // Update _lastFlushTime and _lastScheduledFlushTime. // These information are used when Flush is called the next time. _lastFlushTime = nowUtc; if (reason == FlushCallReason.Timer) { _lastScheduledFlushTime = nowUtc; } discardedSinceLastFlush = _discardedSinceLastFlush; _discardedSinceLastFlush = 0; if (reason == FlushCallReason.StaticFlush) { notificationType = EventNotificationType.Flush; } else { Debug.Assert(!(!_regularTimeoutUsed && !_urgentFlushScheduled), "It's impossible to have a non-regular flush and yet the flush isn't urgent"); notificationType = _regularTimeoutUsed ? EventNotificationType.Regular : EventNotificationType.Urgent; } } eventsInBuffer = _buffer.Count; // If we still have at least _urgentFlushThreshold left, set timer // to flush asap. if (eventsInBuffer >= _urgentFlushThreshold) { Debug.Trace("WebEventBuffer", "Flush: going to flush " + toFlush + " events, but still have at least _urgentFlushThreshold left. Schedule a flush"); scheduleNextFlush = true; nextFlushIsUrgent = true; waitTime = _urgentFlushIntervalMs; } else { Debug.Trace("WebEventBuffer", "Flush: going to flush " + toFlush + " events"); } } // We are done moving the flushed events to the 'events' array. // Now schedule the next flush if needed. _urgentFlushScheduled = false; if (scheduleNextFlush) { if (nextFlushIsUrgent) { long nextRegular = GetNextRegularFlushDueTimeInMs(); // If next regular flush is closer than next urgent flush, // use regular flush instead. if (nextRegular < waitTime) { Debug.Trace("WebEventBuffer", "Switch to use regular timeout"); waitTime = nextRegular; _regularTimeoutUsed = true; } else { _regularTimeoutUsed = false; } } else { _regularTimeoutUsed = true; } SetTimer(waitTime); _urgentFlushScheduled = nextFlushIsUrgent; #if DBG Debug.Trace("WebEventBuffer", "Flush: Registered for a flush. Waittime = " + waitTime + "ms" + "; _nextFlush=" + PrintTime(_nextFlush) + "; _urgentFlushScheduled=" + _urgentFlushScheduled); #endif } // Cleanup. If we are called by a timer callback, but we haven't scheduled for the next // one (can only happen if _regularFlushIntervalMs == Infinite), we should dispose the timer if (reason == FlushCallReason.Timer && !scheduleNextFlush) { Debug.Trace("WebEventBuffer", "Flush: Disposing the timer"); Debug.Assert(_regularFlushIntervalMs == Infinite, "We can dispose the timer only if _regularFlushIntervalMs == Infinite"); ((IDisposable)_timer).Dispose(); _timer = null; _urgentFlushScheduled = false; } // We want to increment the thread count within the lock to ensure we don't let too many threads in if (events != null) { Interlocked.Increment(ref _threadsInFlush); } } // Release lock // Now call the providers to flush the events if (events != null) { Debug.Assert(lastFlushTime != DateTime.MaxValue, "lastFlushTime != DateTime.MaxValue"); Debug.Assert(discardedSinceLastFlush != -1, "discardedSinceLastFlush != -1"); Debug.Assert(eventsInBuffer != -1, "eventsInBuffer != -1"); Debug.Trace("WebEventBufferSummary", "_threadsInFlush=" + _threadsInFlush); using (new ApplicationImpersonationContext()) { try { WebEventBufferFlushInfo flushInfo = new WebEventBufferFlushInfo( new WebBaseEventCollection(events), notificationType, Interlocked.Increment(ref _notificationSequence), lastFlushTime, discardedSinceLastFlush, eventsInBuffer); _flushCallback(flushInfo); } catch (Exception e) { try { _provider.LogException(e); } catch { // Ignore all errors } } #pragma warning disable 1058 catch { // non compliant exceptions are caught and logged as Unknown try { _provider.LogException(new Exception(SR.GetString(SR.Provider_Error))); } catch { // Ignore all errors } } #pragma warning restore 1058 } Interlocked.Decrement(ref _threadsInFlush); } }