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 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 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));
}
}
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, 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, formatter.DateTimeFormat ?? EventEntry.DefaultDateTimeFormat, CultureInfo.InvariantCulture, DateTimeStyles.None, out dt));
}
}
public void IncludesTaskName()
{
var formatter = new EventTextFormatter(EventTextFormatter.DashSeparator, verbosityThreshold: EventLevel.LogAlways);
using (var listener = new InMemoryEventListener(formatter))
{
listener.EnableEvents(Logger, EventLevel.LogAlways, EventKeywords.All);
Logger.DBQueryStart("select * from table");
Logger.WithOpcodeAndNoTaskSpecfied(4);
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 : .*None"));
}
}
public void then_event_is_collected_and_processed_in_first_session()
{
// Wait for event to be processed
inMemoryListener.WaitOnAsyncEvents.WaitOne(this.AsyncProcessTimeout);
inMemoryListener2.WaitOnAsyncEvents.WaitOne(this.AsyncProcessTimeout);
Assert.AreEqual(1, inMemoryListener.EventWrittenCount, "No event get to inMemoryListener");
Assert.AreEqual("loading page test activityID=1010,test", inMemoryListener.ToString());
// In case the second listener got events because the cached manifest was already initialized...
if (inMemoryListener2.EventWrittenCount > 0)
{
Assert.AreEqual(1, inMemoryListener2.EventWrittenCount, "No event get to inMemoryListener2");
Assert.AreEqual("loading page test activityID=1010,test", inMemoryListener2.ToString());
}
}
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 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 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 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 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, "o", CultureInfo.InvariantCulture, DateTimeStyles.None, out dt));
}
}
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));
}
public void then_writes_event_to_errors_source()
{
StringAssert.Contains(collectErrorsListener.ToString(), "EventId : 1100");
StringAssert.Contains(collectErrorsListener.ToString(), "Level : Critical");
StringAssert.Contains(collectErrorsListener.ToString(), "Payload : [message : System.InvalidOperationException");
}
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));
}
}
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 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 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));
}
}
