static void Main(string[] args)
{
var eventListener = new MyEventListener();
var eventSource = new MyEventSource();
eventSource.AnEvent += eventListener.Receive;
var eventArgs = new EventArgs();
eventSource.InvokeAnEvent(eventArgs);
const int Count = 3000000;
var then = DateTime.Now;
for (var iter = 0; iter < Count; ++iter)
{
eventSource.InvokeAnEvent(eventArgs);
}
var diff = DateTime.Now - then;
Console.WriteLine(
"{0} calls took {1:0.00} seconds (listener received {2} calls)",
Count,
diff.TotalSeconds,
eventListener.Count
);
Console.ReadKey();
}
static void Main(string[] args)
{
MyEventListener eventListener = new MyEventListener();
MyEventSource eventSource = new MyEventSource();
eventSource.AnEvent += eventListener.Receive;
MyEventArgs eventArgs = new MyEventArgs();
eventSource.InvokeAnEvent(eventArgs);
const int count = 5000000;
DateTime then = DateTime.Now;
for (int iter = 0; iter < count; ++iter)
{
eventSource.InvokeAnEvent(eventArgs);
}
TimeSpan diff = DateTime.Now - then;
Console.WriteLine(
"{0} calls took {1:0.00} seconds (listener received {2} calls)",
count,
diff.TotalSeconds,
eventListener.Count
);
Console.ReadKey();
}
private static void Main(string[] args)
{
using (MyEventListener myListener = new MyEventListener())
using (MyEventSource source = new MyEventSource())
{
myListener.EnableEvents(source, EventLevel.Verbose);
if (source.ConstructionException != null)
{
throw source.ConstructionException;
}
source.String("Hello world");
source.Int(10);
source.Bool(true);
}
}
public static void Main(params string[] args)
{
var myEventSource = new MyEventSource();
using (var handlerRegistry = new EventHandlerRegistry())
{
handlerRegistry.RegisterHandlerFor(
myEventSource,
myEventSource.GetEventInfo(),
() => Console.WriteLine("Yo there's some kinda event goin on"));
handlerRegistry.RegisterHandlerFor(
myEventSource,
myEventSource.GetEventInfo(),
() => Console.WriteLine("Yeah dawg let's check it out"));
myEventSource.FireOne();
}
myEventSource.FireOne();
}
private static void Main(string[] args)
{
string sessionName = "mySession";
using (MyEventSource source = new MyEventSource())
using (TraceEventSession session = new TraceEventSession(sessionName, null)) // the null second parameter means 'real time session'
using (ETWTraceEventSource eventSource = new ETWTraceEventSource(sessionName, TraceEventSourceType.Session))
{
DynamicTraceEventParser parser = new DynamicTraceEventParser(eventSource);
parser.All += delegate(TraceEvent data)
{
Console.WriteLine("Event name:{0}. Payload:{1}.", data.EventName, data.PayloadValue(0));
};
session.EnableProvider(source.Guid);
source.String("Hello world");
source.Int(123);
eventSource.Process();
}
}
} // end Trace()
private static void _WriteToEventProvider(MyEventSource es, string fullLine)
{
if (!es.WriteMessage(fullLine))
{
// Before, when we were using EventProvider, we could check
// EventProvider.GetLastWriteEventError(), and see if the error was
// something like NoFreeBuffers, to help us decide whether or not it was
// worth trying again. But now we don't have that, with EventSource... so
// we'll just guess that maybe that could've been the problem, and try
// again unconditionally.
#if DEBUG
Console.WriteLine("Tracing error: maybe NoFreeBuffers? Will try again...");
#endif
Thread.Sleep(20);
if (!es.WriteMessage(fullLine))
{
#if DEBUG
Console.WriteLine("Tracing error: {0}", Util.GetExceptionMessages(es.GetLastError()));
Console.WriteLine("Log message was: {0}", fullLine);
#endif
}
}
} // end _WriteToEventProvider()
private void Test_Write_Metric(Listener listener)
{
TestUtilities.CheckNoEventSourcesRunning("Start");
using (var logger = new MyEventSource())
{
var tests = new List <SubTest>();
/*************************************************************************/
tests.Add(new SubTest("Log 1 event",
delegate()
{
listener.EnableTimer(logger, 1); /* Poll every 1 s */
logger.Request(37);
Thread.Sleep(1500); // Sleep for 1.5 seconds
listener.EnableTimer(logger, 0);
},
delegate(List <Event> evts)
{
Assert.Equal(2, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 1, 37, 0, 37, 37);
}));
/*************************************************************************/
tests.Add(new SubTest("Log 2 event in single period",
delegate()
{
listener.EnableTimer(logger, 1); /* Poll every 1 s */
logger.Request(37);
logger.Request(25);
Thread.Sleep(1500); // Sleep for 1.5 seconds
listener.EnableTimer(logger, 0);
},
delegate(List <Event> evts)
{
Assert.Equal(2, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 2, 31, 6, 25, 37);
}));
/*************************************************************************/
tests.Add(new SubTest("Log 2 event in two periods",
delegate()
{
listener.EnableTimer(logger, 1); /* Poll every 1 s */
logger.Request(37);
Thread.Sleep(1500); // Sleep for 1.5 seconds
logger.Request(25);
Thread.Sleep(1000); // Sleep for 1 seconds (at time = 2.5 second exactly two messages should be received)
listener.EnableTimer(logger, 0);
},
delegate(List <Event> evts)
{
Assert.Equal(4, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 1, 37, 0, 37, 37);
ValidateSingleEventCounter(evts[2], "Request", 1, 25, 0, 25, 25);
}));
/*************************************************************************/
tests.Add(new SubTest("Log 2 different events in a period",
delegate()
{
listener.EnableTimer(logger, 1); /* Poll every 1 s */
logger.Request(25);
logger.Error();
Thread.Sleep(1500); // Sleep for 1.5 seconds
listener.EnableTimer(logger, 0);
},
delegate(List <Event> evts)
{
Assert.Equal(2, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 1, 25, 0, 25, 25);
ValidateSingleEventCounter(evts[1], "Error", 1, 1, 0, 1, 1);
}));
/*************************************************************************/
EventTestHarness.RunTests(tests, listener, logger);
}
TestUtilities.CheckNoEventSourcesRunning("Stop");
}
private void Test_Write_Metric(Listener listener)
{
TestUtilities.CheckNoEventSourcesRunning("Start");
using (var logger = new MyEventSource())
{
var tests = new List <SubTest>();
/*************************************************************************/
tests.Add(new SubTest("EventCounter: Log 1 event, explicit poll at end",
delegate()
{
listener.EnableTimer(logger, 1); // Set to poll every second, but we dont actually care because the test ends before that.
logger.Request(5);
listener.EnableTimer(logger, 0);
},
delegate(List <Event> evts)
{
// There will be two events (request and error) for time 0 and 2 more at 1 second and 2 more when we shut it off.
Assert.Equal(4, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[1], "Error", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[2], "Request", 1, 5, 0, 5, 5);
ValidateSingleEventCounter(evts[3], "Error", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
}));
/*************************************************************************/
tests.Add(new SubTest("EventCounter: Log 2 events, explicit poll at end",
delegate()
{
listener.EnableTimer(logger, 1); // Set to poll every second, but we dont actually care because the test ends before that.
logger.Request(5);
logger.Request(10);
listener.EnableTimer(logger, 0); // poll
},
delegate(List <Event> evts)
{
Assert.Equal(4, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[1], "Error", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[2], "Request", 2, 7.5f, 2.5f, 5, 10);
ValidateSingleEventCounter(evts[3], "Error", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
}));
/*************************************************************************/
tests.Add(new SubTest("EventCounter: Log 3 events in two polling periods (explicit polling)",
delegate()
{
listener.EnableTimer(logger, 0); /* Turn off (but also poll once) */
logger.Request(5);
logger.Request(10);
logger.Error();
listener.EnableTimer(logger, 0); /* Turn off (but also poll once) */
logger.Request(8);
logger.Error();
logger.Error();
listener.EnableTimer(logger, 0); /* Turn off (but also poll once) */
},
delegate(List <Event> evts)
{
Assert.Equal(6, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[1], "Error", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[2], "Request", 2, 7.5f, 2.5f, 5, 10);
ValidateSingleEventCounter(evts[3], "Error", 1, 1, 0, 1, 1);
ValidateSingleEventCounter(evts[4], "Request", 1, 8, 0, 8, 8);
ValidateSingleEventCounter(evts[5], "Error", 2, 1, 0, 1, 1);
}));
/*************************************************************************/
int num100msecTimerTicks = 0;
tests.Add(new SubTest("EventCounter: Log multiple events in multiple periods",
delegate()
{
// We have had problems with timer ticks not being called back 100% reliably.
// However timers really don't have a strong guarantee (only that the happen eventually)
// So what we do is create a timer callback that simply counts the number of callbacks.
// This acts as a marker to show whether the timer callbacks are happening promptly.
// If we don't get enough of these tick callbacks then we don't require EventCounter to
// be sending periodic callbacks either.
num100msecTimerTicks = 0;
using (var timer = new System.Threading.Timer(delegate(object state) { num100msecTimerTicks++; EventTestHarness.LogWriteLine("Tick"); }, null, 100, 100))
{
listener.EnableTimer(logger, .1); /* Poll every .1 s */
// logs at 0 seconds because of EnableTimer command
Sleep(100);
logger.Request(1);
Sleep(100);
logger.Request(2);
logger.Error();
Sleep(100);
logger.Request(4);
Sleep(100);
logger.Request(8);
logger.Error();
Sleep(100);
logger.Request(16);
Sleep(220);
listener.EnableTimer(logger, 0);
}
},
delegate(List <Event> evts)
{
int requestCount = 0;
float requestSum = 0;
float requestMin = float.MaxValue;
float requestMax = float.MinValue;
int errorCount = 0;
float errorSum = 0;
float errorMin = float.MaxValue;
float errorMax = float.MinValue;
float timeSum = 0;
for (int j = 0; j < evts.Count; j += 2)
{
var requestPayload = ValidateEventHeaderAndGetPayload(evts[j]);
Assert.Equal("Request", requestPayload["Name"]);
var count = (int)requestPayload["Count"];
requestCount += count;
if (count > 0)
{
requestSum += (float)requestPayload["Mean"] * count;
}
requestMin = Math.Min(requestMin, (float)requestPayload["Min"]);
requestMax = Math.Max(requestMax, (float)requestPayload["Max"]);
float requestIntervalSec = (float)requestPayload["IntervalSec"];
var errorPayload = ValidateEventHeaderAndGetPayload(evts[j + 1]);
Assert.Equal("Error", errorPayload["Name"]);
count = (int)errorPayload["Count"];
errorCount += count;
if (count > 0)
{
errorSum += (float)errorPayload["Mean"] * count;
}
errorMin = Math.Min(errorMin, (float)errorPayload["Min"]);
errorMax = Math.Max(errorMax, (float)errorPayload["Max"]);
float errorIntervalSec = (float)requestPayload["IntervalSec"];
Assert.Equal(requestIntervalSec, errorIntervalSec);
timeSum += requestIntervalSec;
}
EventTestHarness.LogWriteLine("Validating: Count={0} RequestSum={1:n3} TimeSum={2:n3} ", evts.Count, requestSum, timeSum);
Assert.Equal(5, requestCount);
Assert.Equal(31, requestSum);
Assert.Equal(1, requestMin);
Assert.Equal(16, requestMax);
Assert.Equal(2, errorCount);
Assert.Equal(2, errorSum);
Assert.Equal(1, errorMin);
Assert.Equal(1, errorMax);
Assert.True(.4 < timeSum, $"FAILURE: .4 < {timeSum}"); // We should have at least 400 msec
Assert.True(timeSum < 2, $"FAILURE: {timeSum} < 2"); // But well under 2 sec.
// Do all the things that depend on the count of events last so we know everything else is sane
Assert.True(4 <= evts.Count, "We expect two metrics at the beginning trigger and two at the end trigger. evts.Count = " + evts.Count);
Assert.True(evts.Count % 2 == 0, "We expect two metrics for every trigger. evts.Count = " + evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[1], "Error", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
// We should always get the unconditional callback at the start and end of the trace.
Assert.True(4 <= evts.Count, $"FAILURE EventCounter Multi-event: 4 <= {evts.Count} ticks: {num100msecTimerTicks} thread: {Environment.CurrentManagedThreadId}");
// We expect the timer to have gone off at least twice, plus the explicit poll at the beginning and end.
// Each one fires two events (one for requests, one for errors). so that is (2 + 2)*2 = 8
// We expect about 7 timer requests, but we don't get picky about the exact count
// Putting in a generous buffer, we double 7 to say we don't expect more than 14 timer fires
// so that is (2 + 14) * 2 = 32
if (num100msecTimerTicks > 3) // We seem to have problems with timer events going off 100% reliably. To avoid failures here we only check if in the 700 msec test we get at least 3 100 msec ticks.
{
Assert.True(8 <= evts.Count, $"FAILURE: 8 <= {evts.Count}");
}
Assert.True(evts.Count <= 32, $"FAILURE: {evts.Count} <= 32");
}));
/*************************************************************************/
tests.Add(new SubTest("EventCounter: Dispose()",
delegate()
{
// Creating and destroying
var myCounter = new EventCounter("counter for a transient object", logger);
myCounter.WriteMetric(10);
listener.EnableTimer(logger, 0); /* Turn off (but also poll once) */
myCounter.Dispose();
listener.EnableTimer(logger, 0); /* Turn off (but also poll once) */
},
delegate(List <Event> evts)
{
// The static counters (Request and Error), should not log any counts and stay at zero.
// The new counter will exist for the first poll but will not exist for the second.
Assert.Equal(5, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[1], "Error", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[2], "counter for a transient object", 1, 10, 0, 10, 10);
ValidateSingleEventCounter(evts[3], "Request", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[4], "Error", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
}));
/*************************************************************************/
EventTestHarness.RunTests(tests, listener, logger);
}
TestUtilities.CheckNoEventSourcesRunning("Stop");
}
private void Test_Write_Metric(Listener listener)
{
Console.WriteLine("Version of Runtime {0}", Environment.Version);
Console.WriteLine("Version of OS {0}", Environment.OSVersion);
TestUtilities.CheckNoEventSourcesRunning("Start");
using (var logger = new MyEventSource())
{
var tests = new List <SubTest>();
/*************************************************************************/
tests.Add(new SubTest("Log 1 event, explicit poll at end",
delegate()
{
listener.EnableTimer(logger, 1); // Set to poll every second, but we dont actually care because the test ends before that.
logger.Request(5);
listener.EnableTimer(logger, 0);
},
delegate(List <Event> evts)
{
// There will be two events (request and error) for time 0 and 2 more at 1 second and 2 more when we shut it off.
Assert.Equal(4, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[1], "Error", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[2], "Request", 1, 5, 0, 5, 5);
ValidateSingleEventCounter(evts[3], "Error", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
}));
/*************************************************************************/
tests.Add(new SubTest("Log 2 events, explicit poll at end",
delegate()
{
listener.EnableTimer(logger, 1); // Set to poll every second, but we dont actually care because the test ends before that.
logger.Request(5);
logger.Request(10);
listener.EnableTimer(logger, 0); // poll
},
delegate(List <Event> evts)
{
Assert.Equal(4, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[1], "Error", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[2], "Request", 2, 7.5f, 2.5f, 5, 10);
ValidateSingleEventCounter(evts[3], "Error", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
}));
/*************************************************************************/
tests.Add(new SubTest("Log 3 events in two polling periods (explicit polling)",
delegate()
{
listener.EnableTimer(logger, 0); /* Turn off (but also poll once) */
logger.Request(5);
logger.Request(10);
logger.Error();
listener.EnableTimer(logger, 0); /* Turn off (but also poll once) */
logger.Request(8);
logger.Error();
logger.Error();
listener.EnableTimer(logger, 0); /* Turn off (but also poll once) */
},
delegate(List <Event> evts)
{
Assert.Equal(6, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[1], "Error", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[2], "Request", 2, 7.5f, 2.5f, 5, 10);
ValidateSingleEventCounter(evts[3], "Error", 1, 1, 0, 1, 1);
ValidateSingleEventCounter(evts[4], "Request", 1, 8, 0, 8, 8);
ValidateSingleEventCounter(evts[5], "Error", 2, 1, 0, 1, 1);
}));
/*************************************************************************/
tests.Add(new SubTest("Log multiple events in",
delegate()
{
listener.EnableTimer(logger, .1); /* Poll every .1 s */
// logs at 0 seconds because of EnableTimer command
Sleep(100);
logger.Request(1);
Sleep(100);
logger.Request(2);
logger.Error();
Sleep(100);
logger.Request(4);
Sleep(100);
logger.Error();
logger.Request(8);
Sleep(100);
logger.Request(16);
Sleep(200);
listener.EnableTimer(logger, 0);
},
delegate(List <Event> evts)
{
int requestCount = 0;
float requestSum = 0;
float requestMin = float.MaxValue;
float requestMax = float.MinValue;
int errorCount = 0;
float errorSum = 0;
float errorMin = float.MaxValue;
float errorMax = float.MinValue;
float timeSum = 0;
for (int j = 0; j < evts.Count; j += 2)
{
var requestPayload = ValidateEventHeaderAndGetPayload(evts[j]);
Assert.Equal("Request", requestPayload["Name"]);
var count = (int)requestPayload["Count"];
requestCount += count;
if (count > 0)
{
requestSum += (float)requestPayload["Mean"] * count;
}
requestMin = Math.Min(requestMin, (float)requestPayload["Min"]);
requestMax = Math.Max(requestMax, (float)requestPayload["Max"]);
float requestIntevalSec = (float)requestPayload["IntervalSec"];
var errorPayload = ValidateEventHeaderAndGetPayload(evts[j + 1]);
Assert.Equal("Error", errorPayload["Name"]);
count = (int)errorPayload["Count"];
errorCount += count;
if (count > 0)
{
errorSum += (float)errorPayload["Mean"] * count;
}
errorMin = Math.Min(errorMin, (float)errorPayload["Min"]);
errorMax = Math.Max(errorMax, (float)errorPayload["Max"]);
float errorIntevalSec = (float)requestPayload["IntervalSec"];
Assert.Equal(requestIntevalSec, errorIntevalSec);
timeSum += requestIntevalSec;
}
Assert.Equal(requestCount, 5);
Assert.Equal(requestSum, 31);
Assert.Equal(requestMin, 1);
Assert.Equal(requestMax, 16);
Assert.Equal(errorCount, 2);
Assert.Equal(errorSum, 2);
Assert.Equal(errorMin, 1);
Assert.Equal(errorMax, 1);
Assert.True(.4 < timeSum, $"FAILURE: .4 < {timeSum}"); // We should have at least 400 msec
Assert.True(timeSum < 2, $"FAILURE: {timeSum} < 2"); // But well under 2 sec.
// Do all the things that depend on the count of events last so we know everything else is sane
Assert.True(4 <= evts.Count, "We expect two metrices at the begining trigger and two at the end trigger. evts.Count = " + evts.Count);
Assert.True(evts.Count % 2 == 0, "We expect two metrics for every trigger. evts.Count = " + evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
ValidateSingleEventCounter(evts[1], "Error", 0, 0, 0, float.PositiveInfinity, float.NegativeInfinity);
// We expect the timer to have gone off at least twice, plus the explicit poll at the begining and end.
// Each one fires two events (one for requests, one for errors). so that is (2 + 2)*2 = 8
// We expect about 5 timer requests, but we don't get picky about the exact count
// We don't expect more than say 9 timer request so that is (2 + 9) * 2 = 22
Assert.True(8 <= evts.Count, $"FAILURE: 8 <= {evts.Count}");
Assert.True(evts.Count <= 22, $"FAILURE: {evts.Count} <= 22");
}));
/*************************************************************************/
// TODO expose Dispose() method and activate this test.
#if EventCounterDispose
tests.Add(new SubTest("EventCounter.Dispose()",
delegate()
{
// Creating and destroying
var myCounter = new EventCounter("counter for a transient object", logger);
myCounter.WriteMetric(10);
listener.EnableTimer(logger, 0); /* Turn off (but also poll once) */
myCounter.Dispose();
listener.EnableTimer(logger, 0); /* Turn off (but also poll once) */
},
delegate(List <Event> evts)
{
Assert.Equal(5, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 0, 0, 0, 0, 0);
ValidateSingleEventCounter(evts[1], "Error", 0, 0, 0, 0, 0);
ValidateSingleEventCounter(evts[2], "counter for a transient object", 1, 10, 0, 10, 10);
ValidateSingleEventCounter(evts[3], "Request", 0, 0, 0, 0, 0);
ValidateSingleEventCounter(evts[4], "Error", 0, 0, 0, 0, 0);
}));
#endif
/*************************************************************************/
EventTestHarness.RunTests(tests, listener, logger);
}
TestUtilities.CheckNoEventSourcesRunning("Stop");
}
private void Test_Write_Metric(Listener listener)
{
TestUtilities.CheckNoEventSourcesRunning("Start");
using (var logger = new MyEventSource())
{
var tests = new List<SubTest>();
/*************************************************************************/
tests.Add(new SubTest("Log 1 event",
delegate ()
{
listener.EnableTimer(logger, 1); /* Poll every 1 s */
logger.Request(37);
Thread.Sleep(1500); // Sleep for 1.5 seconds
listener.EnableTimer(logger, 0);
},
delegate (List<Event> evts)
{
Assert.Equal(2, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 1, 37, 0, 37, 37);
}));
/*************************************************************************/
tests.Add(new SubTest("Log 2 event in single period",
delegate ()
{
listener.EnableTimer(logger, 1); /* Poll every 1 s */
logger.Request(37);
logger.Request(25);
Thread.Sleep(1500); // Sleep for 1.5 seconds
listener.EnableTimer(logger, 0);
},
delegate (List<Event> evts)
{
Assert.Equal(2, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 2, 31, 6, 25, 37);
}));
/*************************************************************************/
tests.Add(new SubTest("Log 2 event in two periods",
delegate ()
{
listener.EnableTimer(logger, 1); /* Poll every 1 s */
logger.Request(37);
Thread.Sleep(1500); // Sleep for 1.5 seconds
logger.Request(25);
Thread.Sleep(1000); // Sleep for 1 seconds (at time = 2.5 second exactly two messages should be received)
listener.EnableTimer(logger, 0);
},
delegate (List<Event> evts)
{
Assert.Equal(4, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 1, 37, 0, 37, 37);
ValidateSingleEventCounter(evts[2], "Request", 1, 25, 0, 25, 25);
}));
/*************************************************************************/
tests.Add(new SubTest("Log 2 different events in a period",
delegate ()
{
listener.EnableTimer(logger, 1); /* Poll every 1 s */
logger.Request(25);
logger.Error();
Thread.Sleep(1500); // Sleep for 1.5 seconds
listener.EnableTimer(logger, 0);
},
delegate (List<Event> evts)
{
Assert.Equal(2, evts.Count);
ValidateSingleEventCounter(evts[0], "Request", 1, 25, 0, 25, 25);
ValidateSingleEventCounter(evts[1], "Error", 1, 1, 0, 1, 1);
}));
/*************************************************************************/
EventTestHarness.RunTests(tests, listener, logger);
}
TestUtilities.CheckNoEventSourcesRunning("Stop");
}
public void SubscribeForEventFromMyEventSource(MyEventSource eventSource)
{
eventSource.Event += this.EventHandler;
}
private static void _StartTracing(MyEventSource es)
{
try
{
// N.B. Not using Util.Assert here, since Util.Assert traces.
Debug.Assert(!String.IsNullOrEmpty(sm_logFile), "Must have a log file to start tracing.");
sm_maxLogFileSizeMB = RegistryUtils.GetRegValue("MaxTraceFileSizeMB", 8, (v) => Math.Max(1, v));
// If we are doing "low-priority" tracing, let's use a smaller file. And for
// testing logging, we'll make it so we can wrap around a little quicker
if (sm_useLowPriFile ||
!String.IsNullOrEmpty(Environment.GetEnvironmentVariable("_DBGSHELL_TEST_MIN_TRACE_FILE_SIZE")))
{
sm_maxLogFileSizeMB = 1;
}
int bufSizeKb = 0;
string bufSizeStr = Environment.GetEnvironmentVariable("_DBGSHELL_TEST_BUF_SIZE");
if (!String.IsNullOrEmpty(bufSizeStr))
{
if (Int32.TryParse(bufSizeStr, out bufSizeKb))
{
if (bufSizeKb < 0)
{
// N.B. Not using Util.Fail here, since Util.Fail traces.
Debug.Fail("need a value >= 0");
bufSizeKb = 0;
}
}
}
int bufsPerProc = 0;
string bufsPerProcStr = Environment.GetEnvironmentVariable("_DBGSHELL_TEST_BUFS_PER_PROC");
if (!String.IsNullOrEmpty(bufsPerProcStr))
{
if (Int32.TryParse(bufsPerProcStr, out bufsPerProc))
{
if (bufsPerProc < 0)
{
// N.B. Not using Util.Fail here, since Util.Fail traces.
Debug.Fail("need a value >= 0");
bufsPerProc = 0;
}
}
}
// BEWARE: The GUID returned from
// MyEventSource.GetGuid( typeof( MyEventSource ) )
// is different from the GUID returned from
// es.Guid
// !
Guid theGuid = es.Guid;
sm_etp = new EventTraceProperties(theGuid,
sm_logFile,
sm_maxLogFileSizeMB,
bufSizeKb,
bufsPerProc);
int err = NativeMethods.StartTrace(out sm_traceHandle,
"Microsoft.DbgProvider.TraceSession",
sm_etp);
if (0 != err)
{
var e = new Win32Exception(err);
e.Data["sm_logFile"] = sm_logFile;
throw e;
}
err = NativeMethods.EnableTraceEx2(sm_traceHandle,
ref theGuid,
ControlCode.ENABLE_PROVIDER,
TraceLevel.Verbose,
0, // matchAnyKeyword
0, // matchAllKeyword
0, // timeout, zero means trace async
IntPtr.Zero);
if (0 != err)
{
throw new Win32Exception(err);
}
FileVersionInfo fvi = FileVersionInfo.GetVersionInfo(Assembly.GetExecutingAssembly().Location);
lock (sm_syncRoot)
if (!sm_shuttingDown)
{
// Can't call Trace directly because this code is called in the code path that
// lazily initializes the sm_eventSource field.
es.WriteMessage("==========================================================");
es.WriteMessage(Util.Sprintf("DbgProvider version {0}", fvi.FileVersion));
es.WriteMessage(Util.Sprintf("CurrentCulture/CurrentUICulture: {0} / {1}", CultureInfo.CurrentCulture.Name, CultureInfo.CurrentUICulture.Name));
es.WriteMessage(Util.Sprintf("Process ID: {0} (0x{0:x4})", NativeMethods.GetCurrentProcessId()));
es.WriteMessage(Util.Sprintf("Process command line: {0}", Environment.CommandLine));
es.WriteMessage(Util.Sprintf("User type: {0}, interactive: {1}",
_GetUserType(),
Environment.UserInteractive));
es.WriteMessage(Util.Sprintf("Current machine: {0}", Environment.MachineName));
Flush();
}
}
catch (Win32Exception w32e)
{
MulticulturalString mcsErrMsg = Util.McSprintf(Resources.ErrMsgTraceFailureFmt,
sm_logFile,
Util.GetExceptionMessages(w32e));
Exception e2 = Util.TryConvertWin32ExceptionToIOException(w32e, mcsErrMsg);
if (null != e2)
{
throw e2;
}
else
{
throw;
}
}
} // end _StartTracing()
} // end class MyEventSource
private static MyEventSource _InitDebugTraceEventSource()
{
sm_onInitPath = true;
MyEventSource es = new MyEventSource();
// This won't make it into the log. But in case the EventProvider
// constructor ever decides to do lazy registration, we'll trace
// this so that our provider GUID will be sure to be registered
// before we call StartTrace.
es.WriteMessage("(starting session)");
Exception e = null;
foreach (string potentialLogFile in _ChooseLogFilePath())
{
e = Util.TryWin32IO(() =>
{
sm_logFile = potentialLogFile;
_StartTracing(es);
});
if (null == e)
{
break;
}
}
if (null != e)
{
sm_logFile = null;
// N.B. Not using Util.Fail here, since Util.Fail traces.
Debug.Fail(Util.Sprintf("Could not start tracing: {0}", e));
if (0 == RegistryUtils.GetRegValue("TolerateLoggingFailure", 0))
{
throw new DbgProviderException(Util.McSprintf(Resources.ErrMsgCouldNotStartLoggingFmt,
Util.GetExceptionMessages(e)),
"StartTracingFailed",
ErrorCategory.OpenError,
e);
}
}
else
{
AppDomain.CurrentDomain.UnhandledException += _UnhandledExceptionHappened;
// The following is to attempt to workaround things taking too long during
// finalization at process exit--the CLR gives up and stops finalizing
// stuff after 2 seconds. If the EventProvider finalizer does not get a
// chance to run, then it has a callback that does not get unregistered,
// which can get called after the CLR has been torn down, causing a crash.
AppDomain.CurrentDomain.ProcessExit += _Shutdown;
// We also want to shutdown when our appdomain gets unloaded. This is for
// "hosted" scenarios (the DomainUnload event does not get raised for the
// default domain).
AppDomain.CurrentDomain.DomainUnload += _Shutdown;
}
sm_onInitPath = false;
if (null != sm_preTracingTracing)
{
_WriteToEventProvider(es, "(Begin trace messages generated while setting up tracing.)");
foreach (string preTrace in sm_preTracingTracing)
{
_WriteToEventProvider(es, preTrace);
}
_WriteToEventProvider(es, "(End trace messages generated while setting up tracing.)");
sm_preTracingTracing = null;
}
return(es);
} // end _InitDebugTraceEventSource()
