void DebugUpdateStats(bool flushThisTime, DateTime now, int toFlush, FlushCallReason reason)
{
Debug.Assert(_totalAdded == _totalAbandoned + _totalFlushed + _buffer.Count,
"_totalAdded == _totalAbandoned + _totalFlushed + _buffer.Count");
_totalFlushed += toFlush;
if (reason != FlushCallReason.Timer)
{
return;
}
Debug.Trace("WebEventBufferSummary",
"_Added=" + _totalAdded + "; deleted=" + _totalAbandoned +
"; Flushed=" + _totalFlushed + "; buffer=" + _buffer.Count +
"; toFlush=" + toFlush +
"; lastFlush=" + PrintTime(_lastRegularFlush) +
"; lastUrgentFlush=" + PrintTime(_lastUrgentFlush) +
"; GetRegFlushDueTime=" + GetNextRegularFlushDueTimeInMs() +
"; toFlush=" + toFlush +
"; now=" + PrintTime(now));
if (!_regularTimeoutUsed)
{
if (!flushThisTime)
{
return;
}
Debug.Assert((now - _lastUrgentFlush).TotalMilliseconds + 499 > _urgentFlushIntervalMs,
"(now - _lastUrgentFlush).TotalMilliseconds + 499 > _urgentFlushIntervalMs" +
"\n_lastUrgentFlush=" + PrintTime(_lastUrgentFlush) +
"\nnow=" + PrintTime(now) +
"\n_urgentFlushIntervalMs=" + _urgentFlushIntervalMs);
_lastUrgentFlush = now;
}
else
{
/*
* // It's a regular callback
* if (_lastRegularFlush != DateTime.MinValue) {
* Debug.Assert(Math.Abs((now - _lastRegularFlush).TotalMilliseconds - _regularFlushIntervalMs) < 2000,
* "Math.Abs((now - _lastRegularFlush).TotalMilliseconds - _regularFlushIntervalMs) < 2000" +
* "\n_lastRegularFlush=" + PrintTime(_lastRegularFlush) +
* "\nnow=" + PrintTime(now) +
* "\n_regularFlushIntervalMs=" + _regularFlushIntervalMs);
* }
*/
_lastRegularFlush = now;
}
}
// 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);
}
}
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);
}
}
void DebugUpdateStats(bool flushThisTime, DateTime now, int toFlush, FlushCallReason reason) {
Debug.Assert(_totalAdded == _totalAbandoned + _totalFlushed + _buffer.Count,
"_totalAdded == _totalAbandoned + _totalFlushed + _buffer.Count");
_totalFlushed += toFlush;
if (reason != FlushCallReason.Timer) {
return;
}
Debug.Trace("WebEventBufferSummary",
"_Added=" + _totalAdded + "; deleted=" + _totalAbandoned +
"; Flushed=" + _totalFlushed + "; buffer=" + _buffer.Count +
"; toFlush=" + toFlush +
"; lastFlush=" + PrintTime(_lastRegularFlush) +
"; lastUrgentFlush=" + PrintTime(_lastUrgentFlush) +
"; GetRegFlushDueTime=" + GetNextRegularFlushDueTimeInMs() +
"; toFlush=" + toFlush +
"; now=" + PrintTime(now));
if (!_regularTimeoutUsed) {
if (!flushThisTime) {
return;
}
Debug.Assert((now - _lastUrgentFlush).TotalMilliseconds + 499 > _urgentFlushIntervalMs,
"(now - _lastUrgentFlush).TotalMilliseconds + 499 > _urgentFlushIntervalMs" +
"\n_lastUrgentFlush=" + PrintTime(_lastUrgentFlush) +
"\nnow=" + PrintTime(now) +
"\n_urgentFlushIntervalMs=" + _urgentFlushIntervalMs);
_lastUrgentFlush = now;
}
else {
/*
// It's a regular callback
if (_lastRegularFlush != DateTime.MinValue) {
Debug.Assert(Math.Abs((now - _lastRegularFlush).TotalMilliseconds - _regularFlushIntervalMs) < 2000,
"Math.Abs((now - _lastRegularFlush).TotalMilliseconds - _regularFlushIntervalMs) < 2000" +
"\n_lastRegularFlush=" + PrintTime(_lastRegularFlush) +
"\nnow=" + PrintTime(now) +
"\n_regularFlushIntervalMs=" + _regularFlushIntervalMs);
}
*/
_lastRegularFlush = now;
}
}
// 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);
}
}
