public void when_creating_instance_with_default_values()
{
var sources = new List<EventSourceSettings>() { new EventSourceSettings(MyCompanyEventSource.Log.Name) };
var sink = new InMemoryEventListener();
var sut = new SinkSettings("test", sink, sources);
Assert.AreEqual("test", sut.Name);
Assert.AreEqual(sink, sut.Sink);
Assert.AreEqual(1, sut.EventSources.Count());
}
public void ShouldFilterByEventKeywords()
{
using (var listener = new InMemoryEventListener())
{
listener.EnableEvents(SemanticLoggingEventSource.Log, EventLevel.LogAlways, SemanticLoggingEventSource.Keywords.Formatting);
SemanticLoggingEventSource.Log.ConsoleSinkWriteFailed("test");
listener.DisableEvents(SemanticLoggingEventSource.Log);
Assert.AreEqual(string.Empty, listener.ToString());
}
}
public void IncludesTaskName()
{
var formatter = new EventTextFormatter(EventTextFormatter.DashSeparator, verbosityThreshold: EventLevel.LogAlways);
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(Logger, EventLevel.LogAlways, Keywords.All);
Logger.DBQueryStart("select * from table");
Logger.DBQueryStop();
var entries = Regex.Split(listener.ToString(), formatter.Header + "\r\n").Where(c => !string.IsNullOrWhiteSpace(c)).ToList();
StringAssert.Matches(entries[0], new Regex("EventName : .*DBQuery"));
StringAssert.Matches(entries[1], new Regex("Task : .*" + MyCompanyEventSource.Tasks.DBQuery.ToString()));
}
}
public void ShouldWriteWithNoFiltering()
{
using (var listener = new InMemoryEventListener())
{
listener.EnableEvents(SemanticLoggingEventSource.Log, EventLevel.LogAlways, Keywords.All);
SemanticLoggingEventSource.Log.DatabaseSinkPublishEventsFailed("test");
listener.DisableEvents(SemanticLoggingEventSource.Log);
StringAssert.Contains(listener.ToString(), "EventId : 101");
StringAssert.Contains(listener.ToString(), "Level : Error");
StringAssert.Contains(listener.ToString(), "Payload : [message : test]");
}
}
public void ShouldWriteByEventKeywords()
{
using (var listener = new InMemoryEventListener())
{
listener.EnableEvents(SemanticLoggingEventSource.Log, EventLevel.LogAlways, SemanticLoggingEventSource.Keywords.Sink);
SemanticLoggingEventSource.Log.ConsoleSinkWriteFailed("test");
listener.DisableEvents(SemanticLoggingEventSource.Log);
StringAssert.Contains(listener.ToString(), "EventId : 200");
StringAssert.Contains(listener.ToString(), "Level : Critical");
StringAssert.Contains(listener.ToString(), "Payload : [message : test]");
}
}
public void WritesEventData()
{
var formatter = new EventTextFormatter(EventTextFormatter.DashSeparator) { VerbosityThreshold = EventLevel.Critical };
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(Logger, EventLevel.LogAlways, Keywords.All);
Logger.Failure("Failure message");
formatter.VerbosityThreshold = EventLevel.Informational;
Logger.DBQueryStart("select * from table");
Logger.DBQueryStop();
Logger.LogColor(MyColor.Red);
var entries = Regex.Split(listener.ToString(), formatter.Header + "\r\n").Where(c => !string.IsNullOrWhiteSpace(c)).ToList();
StringAssert.Contains(entries[0], "EventId : 1");
StringAssert.Contains(entries[0], "Level : Error");
StringAssert.Contains(entries[0], "Payload : [message : Failure message]");
StringAssert.Contains(entries[1],
@"EventId : 5
Keywords : 2
Level : Informational
Message :
Opcode : Start
Task : 2
Version : 0
Payload : [sqlQuery : select * from table]");
StringAssert.Contains(entries[2],
@"EventId : 6
Keywords : 2
Level : Informational
Message :
Opcode : Stop
Task : 2
Version : 0
Payload :");
StringAssert.Contains(entries[3],
@"EventId : 8
Keywords : None
Level : Informational
Message :
Opcode : Info
Task : 65526
Version : 0
Payload : [color : 0]");
}
}
public void ShouldWriteTimestampWithDefaultDateTimeFormat()
{
var formatter = new EventTextFormatter(EventTextFormatter.DashSeparator);
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(Logger, EventLevel.LogAlways, Keywords.All);
Logger.Failure("error");
var logged = listener.ToString();
var lookup = "Timestamp : ";
var lookupIndex = logged.IndexOf(lookup);
var dateLength = logged.IndexOf("\r\n", lookupIndex) - lookupIndex - lookup.Length;
var ts = logged.Substring(lookupIndex + lookup.Length, dateLength);
DateTime dt;
Assert.IsTrue(DateTime.TryParseExact(ts, formatter.DateTimeFormat ?? EventEntry.DefaultDateTimeFormat, CultureInfo.InvariantCulture, DateTimeStyles.None, out dt));
}
}
public void WhenLoggingErrorOCcurs()
{
InMemoryEventListener collectErrorsListener;
var mockConsole = new MockConsoleOutputInterceptor();
using (var eventListener = new ObservableEventListener())
{
eventListener.LogToConsole(new MockFormatter(true));
eventListener.EnableEvents(TestEventSource.Logger, EventLevel.LogAlways);
collectErrorsListener = new InMemoryEventListener(true);
collectErrorsListener.EnableEvents(SemanticLoggingEventSource.Log, EventLevel.Error, SemanticLoggingEventSource.Keywords.Sink);
TestEventSource.Logger.EventWithPayload("payload1", 100);
}
StringAssert.Contains(collectErrorsListener.ToString(), "System.InvalidOperationException: Operation is not valid due to the current state of the object.");
Assert.AreEqual(string.Empty, mockConsole.Ouput);
}
public void CancelWithExporterTimeoutMilliseconds()
{
using var inMemoryEventListener = new InMemoryEventListener();
var activityExporter = new TestActivityExporter(null, sleepMilliseconds: 5000);
using var activityProcessor = new BatchingActivityProcessor(activityExporter, 128, TimeSpan.FromMilliseconds(1000), TimeSpan.FromMilliseconds(0), 1);
using (var openTelemetrySdk = Sdk.CreateTracerProviderBuilder()
.AddSource(ActivitySourceName)
.SetSampler(new AlwaysOnSampler())
.AddProcessor(activityProcessor)
.Build())
{
var activity1 = this.CreateActivity(ActivityName1);
} // Force everything to flush out of the processor.
Assert.Contains(inMemoryEventListener.Events, (e) => e.EventId == 23);
}
public void ShouldWriteTimestampWithDefaultDateTimeFormat()
{
var formatter = new EventTextFormatter(EventTextFormatter.DashSeparator);
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(Logger, EventLevel.LogAlways, Keywords.All);
Logger.Failure("error");
var logged = listener.ToString();
var lookup = "Timestamp : ";
var lookupIndex = logged.IndexOf(lookup);
var dateLength = logged.IndexOf("\r\n", lookupIndex) - lookupIndex - lookup.Length;
var ts = logged.Substring(lookupIndex + lookup.Length, dateLength);
DateTime dt;
Assert.IsTrue(DateTime.TryParseExact(ts, formatter.DateTimeFormat ?? EventEntry.DefaultDateTimeFormat, CultureInfo.InvariantCulture, DateTimeStyles.None, out dt));
}
}
public void WhenCustomFormatterThrowsAnExceptionAndUsedProgramatically()
{
string fileName = "FlatFileOutProcCustomFormatterHandleException.log";
File.Delete(fileName);
var logger = MockEventSourceOutProc.Logger;
MockFormatter formatter = new MockFormatter(true); //this formatter throws
EventSourceSettings settings = new EventSourceSettings("MockEventSourceOutProc", null, EventLevel.Informational);
var subject = new EventEntrySubject();
subject.LogToFlatFile(fileName, formatter);
SinkSettings sinkSettings = new SinkSettings("flatFileSink", subject, new List <EventSourceSettings>()
{
{ settings }
});
List <SinkSettings> sinks = new List <SinkSettings>()
{
{ sinkSettings }
};
TraceEventServiceConfiguration svcConfiguration = new TraceEventServiceConfiguration(sinks);
TestScenario.WithConfiguration(
svcConfiguration,
() =>
{
using (var collectErrorsListener = new InMemoryEventListener())
{
try
{
collectErrorsListener.EnableEvents(SemanticLoggingEventSource.Log, EventLevel.LogAlways, Keywords.All);
logger.LogSomeMessage("some message using formatter that throws");
collectErrorsListener.WaitEvents.Wait(5000);
StringAssert.Contains(collectErrorsListener.ToString(), "Payload : [message : System.InvalidOperationException: Operation is not valid due to the current state of the object.");
}
finally
{
collectErrorsListener.DisableEvents(SemanticLoggingEventSource.Log);
}
}
});
}
public async Task ShutdownOnNotEmptyQueueFullFlush()
{
const int batchSize = 2;
int exportCalledCount = 0;
var activityExporter = new TestActivityExporter(_ => Interlocked.Increment(ref exportCalledCount));
using var activityProcessor =
new BatchingActivityProcessor(activityExporter, 128, TimeSpan.FromMilliseconds(100), DefaultTimeout, batchSize);
using var openTelemetrySdk = OpenTelemetrySdk.EnableOpenTelemetry(b => b
.AddActivitySource(ActivitySourceName)
.SetSampler(new AlwaysOnActivitySampler())
.AddProcessorPipeline(pp => pp.AddProcessor(ap => activityProcessor)));
using var inMemoryEventListener = new InMemoryEventListener();
var activities = new List <Activity>();
for (int i = 0; i < 100; i++)
{
activities.Add(this.CreateActivity(i.ToString()));
}
Assert.True(activityExporter.ExportedActivities.Length < activities.Count);
using (var cts = new CancellationTokenSource(DefaultTimeout))
{
await activityProcessor.ShutdownAsync(cts.Token);
}
// Get the shutdown event.
// 22 is the EventId for OpenTelemetrySdkEventSource.ForceFlushCompleted
// TODO: Expose event ids as internal, so tests can access them more reliably.
var shutdownEvent = inMemoryEventListener.Events.Where((e) => e.EventId == 22).First();
int droppedCount = 0;
if (shutdownEvent != null)
{
// There is a single payload which is the number of items left in buffer at shutdown.
droppedCount = (int)shutdownEvent.Payload[0];
}
Assert.True(activityExporter.WasShutDown);
Assert.Equal(activities.Count, droppedCount + activityExporter.ExportedActivities.Length);
Assert.InRange(exportCalledCount, activities.Count / batchSize, activities.Count);
}
public void WhenSinkAddedWithErrorDoesNotRecycle()
{
var fileName = "flatfileListenerOk.log";
File.Delete(fileName);
var logger = MockEventSourceOutProc.Logger;
var configFile = Path.GetDirectoryName(Assembly.GetExecutingAssembly().Location) + "\\Configurations\\Reconfiguration\\temp\\configFile.xml";
UpdateServiceConfigurationFile("Configurations\\Reconfiguration\\NoListener.xml", configFile);
TraceEventServiceConfiguration svcConfiguration = TraceEventServiceConfiguration.Load(configFile, true);
TestScenario.WithConfiguration(
svcConfiguration,
() =>
{
using (var collectErrorsListener = new InMemoryEventListener())
{
collectErrorsListener.EnableEvents(SemanticLoggingEventSource.Log, EventLevel.LogAlways, Keywords.All);
try
{
TraceSessionHelper.WaitAndAssertCountOfSessions("ServiceReconfig", 1);
UpdateServiceConfigurationFile("Configurations\\Reconfiguration\\FlatFileListenerError.xml", configFile);
TraceSessionHelper.WaitAndAssertCountOfSessions("ServiceReconfig-flatFileListener", 0);
TraceSessionHelper.WaitAndAssertCountOfSessions("ServiceReconfig-2flatFileListener", 1);
MockEventSourceOutProc.Logger.LogSomeMessage("Some informational from a new listener.");
var entries2 = FlatFileHelper.PollUntilTextEventsAreWritten(fileName, 1, "======");
Assert.AreEqual(1, entries2.Count());
StringAssert.Contains(entries2.First(), "Some informational from a new listener.");
collectErrorsListener.WaitEvents.Wait(TimeSpan.FromSeconds(3));
StringAssert.Contains(collectErrorsListener.ToString(), "One or more errors occurred when loading the TraceEventService configuration file.");
StringAssert.Contains(collectErrorsListener.ToString(), "The given path's format is not supported.");
StringAssert.Contains(collectErrorsListener.ToString(), "The configuration was partially successfully loaded. Check logs for further error details.");
}
finally
{
File.Delete(configFile);
collectErrorsListener.DisableEvents(SemanticLoggingEventSource.Log);
}
}
});
}
public void EventWithPayloadKeywrdsNoMsgInXml()
{
var logger = MockEventSrcForXml.Logger;
var formatter = new XmlEventTextFormatter();
string rawOutput = string.Empty;
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(logger, EventLevel.LogAlways, MockEventSrcForXml.Keywords.Errors);
try
{
logger.UsingKeywords(MockEventSrcForXml.LogMessage, long.MaxValue);
rawOutput = listener.ToString();
}
finally
{
listener.DisableEvents(logger);
}
}
Assert.AreEqual(-1, rawOutput.IndexOf("\r\n"));
var entries = XDocument.Parse("<Events>" + rawOutput + "</Events>").Root.Elements();
XmlFormattedEntry.Fill(entries.Single());
Assert.AreEqual <Guid>(EventSource.GetGuid(typeof(MockEventSrcForXml)), Guid.Parse(XmlFormattedEntry.Provider.Attribute("Guid").Value));
Assert.AreEqual <int>(MockEventSrcForXml.UsingKeywordsEventID, Convert.ToInt32(XmlFormattedEntry.EventId.Value));
Assert.AreEqual <byte>(0, Convert.ToByte(XmlFormattedEntry.Version.Value));
Assert.AreEqual <int>((int)EventLevel.Informational, Int32.Parse(XmlFormattedEntry.Level.Value));
Assert.AreEqual <int>((int)MockEventSrcForXml.Tasks.DBQuery, Int32.Parse(XmlFormattedEntry.Task.Value));
Assert.AreEqual <long>((long)MockEventSrcForXml.Keywords.Errors, Int64.Parse(XmlFormattedEntry.Keywords.Value.Replace("0x", string.Empty)));
Assert.AreEqual <int>((int)EventOpcode.Start, Int32.Parse(XmlFormattedEntry.Opcode.Value));
Assert.AreEqual <int>(System.Diagnostics.Process.GetCurrentProcess().Id, Int32.Parse(XmlFormattedEntry.ProcessId.Value));
Assert.AreEqual <int>(ThreadHelper.GetCurrentUnManagedThreadId(), Int32.Parse(XmlFormattedEntry.ThreadId.Value));
DateTime dt;
Assert.IsTrue(DateTime.TryParseExact(XmlFormattedEntry.TimeCreated.Attribute("SystemTime").Value, EventEntry.DefaultDateTimeFormat, CultureInfo.InvariantCulture, DateTimeStyles.None, out dt));
Assert.AreEqual(2, XmlFormattedEntry.Payload.Elements().Count());
Assert.AreEqual("message", XmlFormattedEntry.Payload.Elements().First().Attribute("Name").Value);
Assert.AreEqual(MockEventSrcForXml.LogMessage, XmlFormattedEntry.Payload.Elements().First().Value);
Assert.AreEqual("longArg", XmlFormattedEntry.Payload.Elements().Last().Attribute("Name").Value);
Assert.AreEqual(long.MaxValue.ToString(), XmlFormattedEntry.Payload.Elements().Last().Value);
}
public void EventWithPayloadAloneInXml()
{
var formatter = new XmlEventTextFormatter();
string payloadMsg = ("<?xml version=\"1.0\" encoding=\"utf-8\"?>\n<test/>");
var logger = MockEventSrcForXml.Logger;
string rawOutput = string.Empty;
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(logger, EventLevel.LogAlways, MockEventSrcForXml.Keywords.Errors);
try
{
logger.LogUsingMessage(payloadMsg);
rawOutput = Encoding.Default.GetString(listener.Stream.ToArray());
}
finally
{
listener.DisableEvents(logger);
}
}
var entries = XDocument.Parse("<Events>" + rawOutput + "</Events>").Root.Elements();
XmlFormattedEntry.Fill(entries.First());
Assert.IsFalse(rawOutput.StartsWith("{\r\n")); // No Formatting (Default)
Assert.AreEqual <Guid>(EventSource.GetGuid(typeof(MockEventSrcForXml)), Guid.Parse(XmlFormattedEntry.Provider.Attribute("Guid").Value));
Assert.AreEqual <int>(MockEventSrcForXml.LogUsingMessageEventID, Convert.ToInt32(XmlFormattedEntry.EventId.Value));
Assert.AreEqual <byte>(0, Convert.ToByte(XmlFormattedEntry.Version.Value));
Assert.AreEqual <int>((int)EventLevel.Informational, Int32.Parse(XmlFormattedEntry.Level.Value));
Assert.AreEqual <int>((int)MockEventSrcForXml.Tasks.Page, Int32.Parse(XmlFormattedEntry.Task.Value));
Assert.AreEqual <long>((long)EventKeywords.None, Int64.Parse(XmlFormattedEntry.Keywords.Value.Replace("0x", string.Empty)));
Assert.AreEqual <int>((int)EventOpcode.Start, Int32.Parse(XmlFormattedEntry.Opcode.Value));
Assert.AreEqual <byte>(0, Convert.ToByte(XmlFormattedEntry.Version.Value));
Assert.AreEqual <int>(System.Diagnostics.Process.GetCurrentProcess().Id, Int32.Parse(XmlFormattedEntry.ProcessId.Value));
Assert.AreEqual <int>(ThreadHelper.GetCurrentUnManagedThreadId(), Int32.Parse(XmlFormattedEntry.ThreadId.Value));
DateTime dt;
Assert.IsTrue(DateTime.TryParseExact(XmlFormattedEntry.TimeCreated.Attribute("SystemTime").Value, EventEntry.DefaultDateTimeFormat, CultureInfo.InvariantCulture, DateTimeStyles.None, out dt));
Assert.AreEqual(1, XmlFormattedEntry.Payload.Elements().Count());
Assert.AreEqual("message", XmlFormattedEntry.Payload.Elements().First().Attribute("Name").Value);
Assert.AreEqual(payloadMsg, XmlFormattedEntry.Payload.Elements().First().Value);
}
public void ShouldWriteTimestampWithDefaultDateTimeFormatWhenNull()
{
var formatter = new EventTextFormatter(EventTextFormatter.DashSeparator)
{
DateTimeFormat = null
};
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(Logger, EventLevel.LogAlways, EventKeywords.All);
Logger.Failure("error");
var logged = listener.ToString();
var lookup = "Timestamp : ";
var ts = logged.Substring(logged.IndexOf(lookup) + lookup.Length).Replace("\r\n", "");
DateTime dt;
Assert.IsTrue(DateTime.TryParseExact(ts, "o", CultureInfo.InvariantCulture, DateTimeStyles.None, out dt));
}
}
public async Task ForceFlushExportsAllData()
{
const int batchSize = 75;
int exportCalledCount = 0;
var activityExporter = new TestActivityExporter(_ => Interlocked.Increment(ref exportCalledCount));
using var activityProcessor = new BatchingActivityProcessor(activityExporter, 128, DefaultDelay, DefaultTimeout, batchSize);
using (var openTelemetrySdk = Sdk.CreateTracerProviderBuilder()
.AddSource(ActivitySourceName)
.SetSampler(new AlwaysOnSampler())
.AddProcessor(activityProcessor)
.Build())
{
using var inMemoryEventListener = new InMemoryEventListener();
var activities = new List <Activity>();
for (int i = 0; i < 100; i++)
{
activities.Add(this.CreateActivity(i.ToString()));
}
Assert.True(activityExporter.ExportedActivities.Length < activities.Count);
using (var cts = new CancellationTokenSource(DefaultTimeout))
{
await activityProcessor.ForceFlushAsync(cts.Token);
}
// Get the shutdown event.
// 22 is the EventId for OpenTelemetrySdkEventSource.ForceFlushCompleted
// TODO: Expose event ids as internal, so tests can access them more reliably.
var flushEvent = inMemoryEventListener.Events.Where((e) => e.EventId == 22).First();
int droppedCount = 0;
if (flushEvent != null)
{
// There is a single payload which is the number of items left in buffer at shutdown.
droppedCount = (int)flushEvent.Payload[0];
}
Assert.Equal(activities.Count, activityExporter.ExportedActivities.Length + droppedCount);
Assert.InRange(exportCalledCount, activities.Count / batchSize, activities.Count);
}
}
protected override void Given()
{
RemoveAnyExistingSession(SessionName2);
base.Given();
inMemoryListener2 = new InMemoryEventListener(formatter);
var sink = new Lazy <IObserver <EventEntry> >(() => inMemoryListener2);
var localSourceSettings = new SemanticLogging.Etw.Configuration.EventSourceSettings(EventSource.GetName(typeof(MyCompanyEventSource)), level: EventLevel.Informational, matchAnyKeyword: MyCompanyEventSource.Keywords.Page);
var localEventSources = new List <SemanticLogging.Etw.Configuration.EventSourceSettings> {
localSourceSettings
};
var localSinkSettings = new List <SinkSettings> {
new SinkSettings("test", sink, localEventSources)
};
var localConfiguration = new TraceEventServiceConfiguration(localSinkSettings, new TraceEventServiceSettings {
SessionNamePrefix = SessionName2
});
this.sut2 = new TraceEventService(localConfiguration);
}
public void EventWithPayloadKeywrdsNoMessageInJson()
{
var logger = MockEventSrcForJson.Logger;
string rawOutput = string.Empty;
using (var listener = new InMemoryEventListener()
{
Formatter = new JsonEventTextFormatter()
})
{
listener.EnableEvents(logger, EventLevel.LogAlways, MockEventSrcForJson.Keywords.Errors);
try
{
logger.UsingKeywords(MockEventSrcForJson.LogMessage, long.MaxValue);
rawOutput = Encoding.Default.GetString(listener.Stream.ToArray());
}
finally
{
listener.DisableEvents(logger);
}
}
var entries = JsonConvert.DeserializeObject <TestEventEntry[]>("[" + rawOutput + "]");
var entry = entries.First();
Assert.IsFalse(rawOutput.StartsWith("{\r\n")); // No Formatting (Default)
Assert.AreEqual <Guid>(EventSource.GetGuid(typeof(MockEventSrcForJson)), entry.ProviderId);
Assert.AreEqual <int>(MockEventSrcForJson.UsingKeywordsEventID, entry.EventId);
Assert.AreEqual <EventLevel>(EventLevel.Informational, entry.Level);
Assert.AreEqual <string>("None", entry.EventKeywords.ToString());
Assert.AreEqual <EventOpcode>(EventOpcode.Start, entry.Opcode);
Assert.AreEqual <int>(System.Diagnostics.Process.GetCurrentProcess().Id, entry.ProcessId);
Assert.AreEqual <int>(ThreadHelper.GetCurrentUnManagedThreadId(), entry.ThreadId);
Assert.AreEqual <byte>(0, entry.Version);
Assert.AreEqual <EventTask>(MockEventSrcForJson.Tasks.DBQuery, entry.Task);
Assert.AreEqual(null, entry.Message);
Assert.AreEqual(2, entry.Payload.Count);
StringAssert.Contains(entry.Payload.First().ToString(), MockEventSrcForJson.LogMessage);
StringAssert.Contains(entry.Payload.Last().ToString(), long.MaxValue.ToString());
}
public void DisposeFlushes()
{
const int batchSize = 1;
int exportCalledCount = 0;
var activityExporter = new TestActivityExporter(_ => Interlocked.Increment(ref exportCalledCount), 100);
var activities = new List <Activity>();
using var inMemoryEventListener = new InMemoryEventListener();
using (var batchingActivityProcessor = new BatchingActivityProcessor(activityExporter, 128, DefaultDelay, DefaultTimeout, batchSize))
{
using var openTelemetrySdk = Sdk.CreateTracerProviderBuilder()
.AddSource(ActivitySourceName)
.SetSampler(new AlwaysOnSampler())
.AddProcessor(batchingActivityProcessor)
.Build();
for (int i = 0; i < 3; i++)
{
activities.Add(this.CreateActivity(i.ToString()));
}
Assert.True(activityExporter.ExportedActivities.Length < activities.Count);
}
// Get the shutdown event.
// 2 is the EventId for OpenTelemetrySdkEventSource.ShutdownEvent
// TODO: Expose event ids as internal, so tests can access them more reliably.
var shutdownEvent = inMemoryEventListener.Events.Where((e) => e.EventId == 2).First();
int droppedCount = 0;
if (shutdownEvent != null)
{
// There is a single payload which is the number of items left in buffer at shutdown.
droppedCount = (int)shutdownEvent.Payload[0];
}
Assert.True(activityExporter.WasShutDown);
Assert.Equal(activities.Count, activityExporter.ExportedActivities.Length + droppedCount);
Assert.Equal(activities.Count / batchSize, exportCalledCount);
}
public void EventWithPayloadKeywrdsNoMsgIndentedInJson()
{
var logger = MockEventSrcForJson.Logger;
string rawOutput = string.Empty;
using (var listener = new InMemoryEventListener()
{
Formatter = new JsonEventTextFormatter(EventTextFormatting.Indented)
})
{
listener.EnableEvents(logger, EventLevel.LogAlways, MockEventSrcForJson.Keywords.Errors);
try
{
logger.UsingKeywords(MockEventSrcForJson.LogMessage, long.MaxValue);
rawOutput = Encoding.Default.GetString(listener.Stream.ToArray());
}
finally
{
listener.DisableEvents(logger);
}
}
Assert.AreEqual(17, rawOutput.Split('\n').Length); //Assert is indented
var entries = JsonConvert.DeserializeObject <TestEventEntry[]>("[" + rawOutput + "]");
var entry = entries.First();
Assert.AreEqual <Guid>(EventSource.GetGuid(typeof(MockEventSrcForJson)), entry.ProviderId);
Assert.AreEqual <int>(MockEventSrcForJson.UsingKeywordsEventID, entry.EventId);
Assert.AreEqual <EventLevel>(EventLevel.Informational, entry.Level);
Assert.AreEqual <string>("None", entry.EventKeywords.ToString());
Assert.AreEqual <EventOpcode>(EventOpcode.Start, entry.Opcode);
Assert.AreEqual <byte>(0, entry.Version);
Assert.AreEqual <EventTask>(EventTask.None, entry.Task);
Assert.AreEqual(null, entry.Message);
Assert.AreEqual(2, entry.Payload.Count);
StringAssert.Contains(entry.Payload.First().ToString(), MockEventSrcForJson.LogMessage);
StringAssert.Contains(entry.Payload.Last().ToString(), long.MaxValue.ToString());
}
protected override void Given()
{
base.Given();
inMemoryListener = new InMemoryEventListener(new MockFormatter {
BeforeWriteEventAction = f => { throw new Exception("unhandled_exception_test"); }
});
var sink = new Lazy <IObserver <EventEntry> >(() => inMemoryListener);
sourceSettings = new SemanticLogging.Etw.Configuration.EventSourceSettings(EventSource.GetName(typeof(MyCompanyEventSource)));
eventSources = new List <SemanticLogging.Etw.Configuration.EventSourceSettings> {
sourceSettings
};
sinkSettings = new List <SinkSettings> {
new SinkSettings("test", sink, eventSources)
};
configuration = new TraceEventServiceConfiguration(sinkSettings);
this.sut = new TraceEventService(configuration);
slabListener = new InMemoryEventListener();
slabListener.EnableEvents(SemanticLoggingEventSource.Log, EventLevel.Error, SemanticLoggingEventSource.Keywords.TraceEvent);
this.sut.Start();
}
protected override void Given()
{
this.formatter = new MockFormatter();
this.inMemoryListener = new InMemoryEventListener(this.formatter);
var sink = new Lazy<IObserver<EventEntry>>(() => this.inMemoryListener);
this.sourceSettings = this.sourceSettings ?? new EventSourceSettings(EventSource.GetName(typeof(MyCompanyEventSource)));
this.eventSources = new List<EventSourceSettings>() { { this.sourceSettings } };
this.sinkSettings = new List<SinkSettings>() { { new SinkSettings("test", sink, this.eventSources) } };
this.configuration = new TraceEventServiceConfiguration(sinkSettings, this.serviceSettings);
try
{
this.Sut = new TraceEventService(configuration);
}
catch (UnauthorizedAccessException uae)
{
Assert.Inconclusive(uae.Message);
}
// Clean up any previous unclosed session to avoid collisions
this.RemoveAnyExistingSession();
}
public void EventWithPayloadAndMessageInJson()
{
var logger = MockEventSrcForJson.Logger;
string rawOutput = string.Empty;
using (var listener = new InMemoryEventListener()
{
Formatter = new JsonEventTextFormatter()
})
{
listener.EnableEvents(logger, EventLevel.LogAlways, MockEventSrcForJson.Keywords.Errors);
try
{
logger.LogUsingMessage(MockEventSrcForJson.LogMessage);
rawOutput = Encoding.Default.GetString(listener.Stream.ToArray());
}
finally
{
listener.DisableEvents(logger);
}
}
var entries = JsonConvert.DeserializeObject <TestEventEntry[]>("[" + rawOutput + "]");
var entry = entries.First();
Assert.IsFalse(rawOutput.StartsWith("{\r\n")); // No Formatting (Default)
Assert.AreEqual <Guid>(EventSource.GetGuid(typeof(MockEventSrcForJson)), entry.ProviderId);
Assert.AreEqual <int>(MockEventSrcForJson.LogUsingMessageEventID, entry.EventId);
Assert.AreEqual <EventLevel>(EventLevel.Informational, entry.Level);
Assert.AreEqual <EventKeywords>(EventKeywords.None, entry.EventKeywords);
Assert.AreEqual <EventOpcode>(EventOpcode.Start, entry.Opcode);
Assert.AreEqual <byte>(0, entry.Version);
Assert.AreEqual <EventTask>(EventTask.None, entry.Task);
Assert.AreEqual(MockEventSrcForJson.LogMessage, entry.Message);
Assert.AreEqual(1, entry.Payload.Count);
StringAssert.Contains(entry.Payload.First().ToString(), MockEventSrcForJson.LogMessage);
}
public void EventWithActivityIdAndRelatedActivityIdInJson()
{
var logger = MockEventSrcForJson.Logger;
var activityId = Guid.NewGuid();
var relatedActivityId = Guid.NewGuid();
var previousActivityId = Guid.Empty;
string rawOutput = string.Empty;
using (var listener = new InMemoryEventListener()
{
Formatter = new JsonEventTextFormatter()
})
{
listener.EnableEvents(logger, EventLevel.LogAlways, MockEventSrcForJson.Keywords.Errors);
try
{
EventSource.SetCurrentThreadActivityId(activityId, out previousActivityId);
logger.LogUsingMessageWithRelatedActivityId(MockEventSrcForJson.LogMessage, relatedActivityId);
rawOutput = Encoding.Default.GetString(listener.Stream.ToArray());
}
finally
{
listener.DisableEvents(logger);
EventSource.SetCurrentThreadActivityId(previousActivityId);
}
}
var entries = JsonConvert.DeserializeObject <TestEventEntry[]>("[" + rawOutput + "]");
var entry = entries.First();
Assert.IsFalse(rawOutput.StartsWith("{\r\n"));
Assert.AreEqual(MockEventSrcForJson.LogMessage, entry.Message);
Assert.AreEqual(1, entry.Payload.Count);
StringAssert.Contains(entry.Payload.First().ToString(), MockEventSrcForJson.LogMessage);
Assert.AreEqual <Guid>(activityId, entry.ActivityId);
Assert.AreEqual <Guid>(relatedActivityId, entry.RelatedActivityId);
}
public void EventWithNoOpCodeNoKeywordsNoVersionNoMsgInJson()
{
var logger = MockEventSourceNoTask.Logger;
string rawOutput = string.Empty;
using (var listener = new InMemoryEventListener()
{
Formatter = new JsonEventTextFormatter()
})
{
listener.EnableEvents(logger, EventLevel.LogAlways);
try
{
logger.NoTaskNoOpCode1(1, 2, 3);
rawOutput = Encoding.Default.GetString(listener.Stream.ToArray());
}
finally
{
listener.DisableEvents(logger);
}
}
var entries = JsonConvert.DeserializeObject <TestEventEntry[]>("[" + rawOutput + "]");
var entry = entries.First();
Assert.IsFalse(rawOutput.StartsWith("{\r\n")); // No Formatting (Default)
Assert.AreEqual <EventLevel>(EventLevel.Informational, entry.Level);
Assert.AreEqual <EventKeywords>(EventKeywords.None, entry.EventKeywords);
Assert.AreEqual <EventOpcode>(0, entry.Opcode);
Assert.AreEqual <int>(System.Diagnostics.Process.GetCurrentProcess().Id, entry.ProcessId);
Assert.AreEqual <int>(ThreadHelper.GetCurrentUnManagedThreadId(), entry.ThreadId);
Assert.AreEqual <byte>(0, entry.Version);
Assert.AreEqual(null, entry.Message);
Assert.AreEqual(3, entry.Payload.Count);
StringAssert.Contains(entry.Payload.First().ToString(), "[event3Arg0, 1]");
StringAssert.Contains(entry.Payload.Last().ToString(), "[event3Arg2, 3]");
}
protected override void Given()
{
RemoveAnyExistingSession(sessionName2);
base.Given();
inMemoryListener2 = new InMemoryEventListener(formatter);
var sink = new Lazy <IObserver <EventEntry> >(() => inMemoryListener2);
var sourceSettings = new EventSourceSettings(EventSource.GetName(typeof(MyCompanyEventSource)), level: EventLevel.Informational, matchAnyKeyword: MyCompanyEventSource.Keywords.Page);
var eventSources = new List <EventSourceSettings>()
{
{ sourceSettings }
};
var sinkSettings = new List <SinkSettings>()
{
{ new SinkSettings("test", sink, eventSources) }
};
var configuration = new TraceEventServiceConfiguration(sinkSettings, new TraceEventServiceSettings()
{
SessionNamePrefix = sessionName2
});
this.sut2 = new TraceEventService(configuration);
}
public void EventWithNullPayloadInFormattedMessageInXml()
{
var formatter = new XmlEventTextFormatter();
var logger = MockEventSrcForXml.Logger;
string rawOutput = string.Empty;
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(logger, EventLevel.LogAlways, MockEventSrcForXml.Keywords.Errors);
try
{
logger.LogUsingMessageFormat(null);
rawOutput = Encoding.Default.GetString(listener.Stream.ToArray());
}
finally
{
listener.DisableEvents(logger);
}
}
var entries = XDocument.Parse("<Events>" + rawOutput + "</Events>").Root.Elements();
XmlFormattedEntry.Fill(entries.First());
Assert.IsFalse(rawOutput.StartsWith("{\r\n")); // No Formatting (Default)
Assert.AreEqual <Guid>(EventSource.GetGuid(typeof(MockEventSrcForXml)), Guid.Parse(XmlFormattedEntry.Provider.Attribute("Guid").Value));
Assert.AreEqual <int>(MockEventSrcForXml.LogUsingMessageFormatEventID, Convert.ToInt32(XmlFormattedEntry.EventId.Value));
Assert.AreEqual <byte>(0, Convert.ToByte(XmlFormattedEntry.Version.Value));
Assert.AreEqual <int>((int)EventLevel.Informational, Int32.Parse(XmlFormattedEntry.Level.Value));
Assert.AreEqual <int>((int)EventTask.None, Int32.Parse(XmlFormattedEntry.Task.Value));
Assert.AreEqual <long>((long)EventKeywords.None, Int64.Parse(XmlFormattedEntry.Keywords.Value.Replace("0x", string.Empty)));
Assert.AreEqual <int>((int)EventOpcode.Start, Int32.Parse(XmlFormattedEntry.Opcode.Value));
Assert.AreEqual <byte>(0, Convert.ToByte(XmlFormattedEntry.Version.Value));
DateTime dt;
Assert.IsTrue(DateTime.TryParseExact(XmlFormattedEntry.TimeCreated.Attribute("SystemTime").Value, EventEntry.DefaultDateTimeFormat, CultureInfo.InvariantCulture, DateTimeStyles.None, out dt));
}
public void AddViewWithExceptionInUserCallbackAppliedDefault()
{
var exportedItems = new List <Metric>();
using var meter1 = new Meter("AddViewWithExceptionInUserCallback");
using var meterProvider = Sdk.CreateMeterProviderBuilder()
.AddMeter(meter1.Name)
.AddView((instrument) => { throw new Exception("bad"); })
.AddInMemoryExporter(exportedItems)
.Build();
using (var inMemoryEventListener = new InMemoryEventListener(OpenTelemetrySdkEventSource.Log))
{
var counter1 = meter1.CreateCounter <long>("counter1");
counter1.Add(1);
Assert.Single(inMemoryEventListener.Events.Where((e) => e.EventId == 41));
}
meterProvider.ForceFlush(MaxTimeToAllowForFlush);
// Counter is still reported with default config
// even if View is ignored due to View exception.
Assert.Single(exportedItems);
}
public void EventWithActivityIdAndRelatedActivityIdInXml()
{
var formatter = new XmlEventTextFormatter();
var logger = MockEventSrcForXml.Logger;
var activityId = Guid.NewGuid();
var relatedActivityId = Guid.NewGuid();
var previousActivityId = Guid.Empty;
string rawOutput = string.Empty;
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(logger, EventLevel.LogAlways, MockEventSrcForXml.Keywords.Errors);
try
{
EventSource.SetCurrentThreadActivityId(activityId, out previousActivityId);
logger.LogUsingMessageWithRelatedActivityId(MockEventSrcForXml.LogMessage, relatedActivityId);
rawOutput = Encoding.Default.GetString(listener.Stream.ToArray());
}
finally
{
listener.DisableEvents(logger);
EventSource.SetCurrentThreadActivityId(previousActivityId);
}
}
var entries = XDocument.Parse("<Events>" + rawOutput + "</Events>").Root.Elements();
XmlFormattedEntry.Fill(entries.First());
Assert.AreEqual <Guid>(EventSource.GetGuid(typeof(MockEventSrcForXml)), Guid.Parse(XmlFormattedEntry.Provider.Attribute("Guid").Value));
Assert.AreEqual(1, XmlFormattedEntry.Payload.Elements().Count());
Assert.AreEqual("message", XmlFormattedEntry.Payload.Elements().First().Attribute("Name").Value);
Assert.AreEqual(MockEventSrcForXml.LogMessage, XmlFormattedEntry.Payload.Elements().First().Value);
Assert.AreEqual <Guid>(activityId, Guid.Parse(XmlFormattedEntry.Correlation.Attribute("ActivityID").Value));
Assert.AreEqual <Guid>(relatedActivityId, Guid.Parse(XmlFormattedEntry.Correlation.Attribute("RelatedActivityID").Value));
}
public void ShouldWriteTimestampWithDefaultDateTimeFormatWhenNull()
{
var formatter = new EventTextFormatter(EventTextFormatter.DashSeparator) { DateTimeFormat = null };
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(Logger, EventLevel.LogAlways, Keywords.All);
Logger.Failure("error");
var logged = listener.ToString();
var lookup = "Timestamp : ";
var ts = logged.Substring(logged.IndexOf(lookup) + lookup.Length).Replace("\r\n", "");
DateTime dt;
Assert.IsTrue(DateTime.TryParseExact(ts, "o", CultureInfo.InvariantCulture, DateTimeStyles.None, out dt));
}
}
public void WritesDetailedOnEventLevel()
{
var formatter = new EventTextFormatter(EventTextFormatter.DashSeparator) { VerbosityThreshold = EventLevel.Critical };
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(Logger, EventLevel.LogAlways, Keywords.All);
Logger.Failure("Summary");
formatter.VerbosityThreshold = EventLevel.Error;
Logger.Failure("Detailed");
var entries = Regex.Split(listener.ToString(), formatter.Header + "\r\n").Where(c => !string.IsNullOrWhiteSpace(c)).ToList();
StringAssert.Contains(entries[0], "EventId : 1");
StringAssert.Contains(entries[0], "Level : Error");
StringAssert.Contains(entries[0], "Payload : [message : Summary]");
StringAssert.Contains(entries[1],
@"ProviderId : 659518be-d338-564b-2759-c63c10ef82e2
EventId : 1
Keywords : 4
Level : Error
Message : Application Failure: Detailed
Opcode : Info
Task : 65533
Version : 0
Payload : [message : Detailed]
EventName : FailureInfo");
}
}
public void WritesCustomHeaderAndFooter()
{
var formatter = new EventTextFormatter("---header---", "___footer___");
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(Logger, EventLevel.LogAlways, Keywords.All);
Logger.Startup();
var contents = listener.ToString();
Assert.IsTrue(contents.Contains(formatter.Header));
Assert.IsTrue(contents.Contains(formatter.Footer));
}
}
protected override void Given()
{
this.MockConsole = new MockConsoleOutput();
// Will always throw
this.Listener = new ObservableEventListener();
this.Listener.LogToConsole(new MockFormatter() { BeforeWriteEventAction = (f) => { throw new InvalidOperationException(); } });
this.Listener.EnableEvents(TestEventSource.Log, EventLevel.LogAlways);
collectErrorsListener = new InMemoryEventListener();
collectErrorsListener.EnableEvents(SemanticLoggingEventSource.Log, EventLevel.Error, SemanticLoggingEventSource.Keywords.Sink);
}
protected override void Given()
{
formatter = new JsonEventTextFormatter();
listener = new InMemoryEventListener() { Formatter = formatter };
listener.EnableEvents(Logger, EventLevel.LogAlways);
}
protected override void Given()
{
this.sourceSettings = new EventSourceSettings(EventSource.GetName(typeof(DifferentEnumsEventSource)));
base.Given();
this.slabListener = new InMemoryEventListener();
this.slabListener.EnableEvents(SemanticLoggingEventSource.Log, EventLevel.Error, SemanticLoggingEventSource.Keywords.TraceEvent);
this.sut.Start();
}
protected override void Given()
{
RemoveAnyExistingSession(SessionName2);
base.Given();
inMemoryListener2 = new InMemoryEventListener(formatter);
var sink = new Lazy<IObserver<EventEntry>>(() => inMemoryListener2);
var localSourceSettings = new EventSourceSettings(EventSource.GetName(typeof(MyCompanyEventSource)), level: EventLevel.Informational, matchAnyKeyword: MyCompanyEventSource.Keywords.Page);
var localEventSources = new List<EventSourceSettings> { localSourceSettings };
var localSinkSettings = new List<SinkSettings> { new SinkSettings("test", sink, localEventSources) };
var localConfiguration = new TraceEventServiceConfiguration(localSinkSettings, new TraceEventServiceSettings { SessionNamePrefix = SessionName2 });
this.sut2 = new TraceEventService(localConfiguration);
}
protected override void Given()
{
base.Given();
inMemoryListener = new InMemoryEventListener(new MockFormatter { BeforeWriteEventAction = f => { throw new Exception("unhandled_exception_test"); } });
var sink = new Lazy<IObserver<EventEntry>>(() => inMemoryListener);
sourceSettings = new EventSourceSettings(EventSource.GetName(typeof(MyCompanyEventSource)));
eventSources = new List<EventSourceSettings> { sourceSettings };
sinkSettings = new List<SinkSettings> { new SinkSettings("test", sink, eventSources) };
configuration = new TraceEventServiceConfiguration(sinkSettings);
this.sut = new TraceEventService(configuration);
slabListener = new InMemoryEventListener();
slabListener.EnableEvents(SemanticLoggingEventSource.Log, EventLevel.Error, SemanticLoggingEventSource.Keywords.TraceEvent);
this.sut.Start();
}
protected override void Given()
{
listener = new InMemoryEventListener() { Formatter = new XmlEventTextFormatter(EventTextFormatting.None) };
listener.EnableEvents(Logger, EventLevel.LogAlways);
}
public void WritesCustomFooter()
{
var formatter = new EventTextFormatter(null, "___footer___");
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(Logger, EventLevel.LogAlways, Keywords.All);
Logger.Startup();
Assert.IsTrue(listener.ToString().Contains(formatter.Footer));
}
}
public void WritesCustomHeader()
{
var formatter = new EventTextFormatter("*** header ***");
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(Logger, EventLevel.LogAlways, Keywords.All);
Logger.DBQueryStart("select * from table");
Assert.IsTrue(listener.ToString().Contains(formatter.Header));
}
}
public void WhenEventsInThreeConsecutiveIntervals()
{
this.tableName = "WhenEventsInThreeConsecutiveIntervals";
var connectionString = System.Configuration.ConfigurationManager.AppSettings["StorageConnectionString"];
AzureTableHelper.DeleteTable(connectionString, this.tableName);
var logger = TestEventSource.Logger;
var bufferingInterval = TimeSpan.FromSeconds(5);
var insertionInterval = TimeSpan.FromSeconds(1);
using (var listener = new ObservableEventListener())
using (var errorsListener = new InMemoryEventListener())
{
try
{
errorsListener.EnableEvents(SemanticLoggingEventSource.Log, EventLevel.Verbose);
listener.LogToWindowsAzureTable("mytestinstance", connectionString, this.tableName, bufferingInterval: bufferingInterval);
listener.EnableEvents(logger, EventLevel.Informational);
// 1st interval: Log 10 events
for (int i = 0; i < 10; i++)
{
logger.Informational("Message1");
}
// 1st interval: Wait for the buffer to flush at end of interval
Task.Delay(bufferingInterval).Wait();
// 2nd interval: start
// 1st interval: Wait for the events to be written and assert
Task.Delay(insertionInterval).Wait();
Assert.AreEqual(10, AzureTableHelper.GetEventsCount(connectionString, this.tableName));
// 2nd interval: Log 10 events
for (int i = 0; i < 10; i++)
{
logger.Informational("Message1");
}
// 2nd interval: Wait for the buffer to flush at end of interval
Task.Delay(bufferingInterval).Wait();
// 3rd interval: start
// 2nd interval: Wait for the events to be written and assert
Task.Delay(insertionInterval).Wait();
Assert.AreEqual(20, AzureTableHelper.GetEventsCount(connectionString, this.tableName));
// 3rd interval: Log 10 events
for (int i = 0; i < 10; i++)
{
logger.Informational("Message1");
}
// 3rd interval: Wait for the buffer to flush at end of interval
Task.Delay(bufferingInterval).Wait();
// 4th interval: start
// 3rd interval: Wait for the events to be written and assert
Task.Delay(insertionInterval).Wait();
Assert.AreEqual(30, AzureTableHelper.GetEventsCount(connectionString, this.tableName));
// No errors should have been reported
Assert.AreEqual(string.Empty, errorsListener.ToString());
}
finally
{
listener.DisableEvents(logger);
errorsListener.DisableEvents(SemanticLoggingEventSource.Log);
}
}
// No more events should have been written during the last flush in the Dispose
Assert.AreEqual(30, AzureTableHelper.GetEventsCount(connectionString, this.tableName));
}
protected override void Given()
{
formatter = new XmlEventTextFormatter(EventTextFormatting.Indented);
listener = new InMemoryEventListener() { Formatter = formatter };
listener.EnableEvents(logger, EventLevel.LogAlways);
}
