public void WhenRepeatedFilterCountAppendFormatIgnoreTest()
{
LogManager.Configuration = XmlLoggingConfiguration.CreateFromXmlString(@"
<nlog>
<targets><target name='debug' type='Debug' layout='${message}${event-properties:item=hits}' /></targets>
<rules>
<logger name='*' minlevel='Debug' writeTo='debug'>
<filters>
<whenRepeated layout='${message}' action='Ignore' timeoutSeconds='5' filterCountMessageAppendFormat=' (Hits: {0})' />
</filters>
</logger>
</rules>
</nlog>");
var defaultTimeSource = Time.TimeSource.Current;
try
{
var timeSource = new TimeSourceTests.ShiftedTimeSource(DateTimeKind.Local);
Time.TimeSource.Current = timeSource;
ILogger logger = LogManager.GetLogger("A");
logger.Debug("a");
AssertDebugCounter("debug", 1);
logger.Debug("zzz");
AssertDebugCounter("debug", 2);
AssertDebugLastMessage("debug", "zzz");
logger.Debug("zzz");
AssertDebugCounter("debug", 2);
timeSource.AddToLocalTime(TimeSpan.FromSeconds(3));
logger.Debug("zzz");
AssertDebugCounter("debug", 2);
logger.Debug("b");
AssertDebugCounter("debug", 3);
timeSource.AddToLocalTime(TimeSpan.FromSeconds(3));
logger.Debug("zzz");
AssertDebugCounter("debug", 4);
AssertDebugLastMessage("debug", "zzz (Hits: 2)");
logger.Debug("zzz");
AssertDebugCounter("debug", 4);
timeSource.AddToLocalTime(TimeSpan.FromSeconds(12));
logger.Debug("zzz");
AssertDebugCounter("debug", 5);
AssertDebugLastMessage("debug", "zzz");
}
finally
{
Time.TimeSource.Current = defaultTimeSource; // restore default time source
}
}
public void WhenRepeatedTimeoutTest()
{
LogManager.Configuration = CreateConfigurationFromString(@"
<nlog>
<targets><target name='debug' type='Debug' layout='${message}' /></targets>
<rules>
<logger name='*' minlevel='Debug' writeTo='debug'>
<filters>
<whenRepeated layout='${message}' action='Ignore' timeoutSeconds='10' />
</filters>
</logger>
</rules>
</nlog>");
var defaultTimeSource = Time.TimeSource.Current;
try
{
var timeSource = new TimeSourceTests.ShiftedTimeSource(DateTimeKind.Local);
Time.TimeSource.Current = timeSource;
ILogger logger = LogManager.GetLogger("A");
logger.Debug("a");
AssertDebugCounter("debug", 1);
logger.Debug("zzz");
AssertDebugCounter("debug", 2);
logger.Debug("zzz");
AssertDebugCounter("debug", 2);
timeSource.AddToLocalTime(TimeSpan.FromSeconds(5));
logger.Debug("zzz");
AssertDebugCounter("debug", 2);
AssertDebugCounter("debug", 2);
logger.Debug("b");
AssertDebugCounter("debug", 3);
timeSource.AddToLocalTime(TimeSpan.FromSeconds(10));
logger.Debug("zzz");
AssertDebugCounter("debug", 4);
}
finally
{
Time.TimeSource.Current = defaultTimeSource; // restore default time source
}
}
public void DateArchive_SkipPeriod(DateTimeKind timeKind, FileArchivePeriod archivePeriod, bool includeSequenceInArchive)
{
var tempPath = Path.Combine(Path.GetTempPath(), Guid.NewGuid().ToString());
var tempFile = Path.Combine(tempPath, "file.txt");
var defaultTimeSource = TimeSource.Current;
try
{
var timeSource = new TimeSourceTests.ShiftedTimeSource(timeKind);
if (timeSource.Time.Minute == 59)
{
// Avoid double-archive due to overflow of the hour.
timeSource.AddToLocalTime(TimeSpan.FromMinutes(1));
timeSource.AddToSystemTime(TimeSpan.FromMinutes(1));
}
TimeSource.Current = timeSource;
var ft = new FileTarget
{
FileName = tempFile,
ArchiveFileName = Path.Combine(tempPath, "archive/{#}.txt"),
LineEnding = LineEndingMode.LF,
ArchiveNumbering = includeSequenceInArchive ? ArchiveNumberingMode.DateAndSequence : ArchiveNumberingMode.Date,
ArchiveEvery = archivePeriod,
ArchiveDateFormat = "yyyyMMddHHmm",
Layout = "${date:format=O}|${message}",
};
SimpleConfigurator.ConfigureForTargetLogging(ft, LogLevel.Debug);
logger.Debug("1234567890");
timeSource.AddToLocalTime(TimeSpan.FromMinutes(1));
logger.Debug("1234567890");
// The archive file name must be based on the last time the file was written.
string archiveFileName = string.Format("{0}.txt", timeSource.Time.ToString(ft.ArchiveDateFormat) + (includeSequenceInArchive ? ".0" : string.Empty));
// Effectively update the file's last-write-time.
timeSource.AddToSystemTime(TimeSpan.FromMinutes(1));
timeSource.AddToLocalTime(TimeSpan.FromDays(2));
logger.Debug("1234567890");
LogManager.Configuration = null;
string archivePath = Path.Combine(tempPath, "archive");
var archiveFiles = Directory.GetFiles(archivePath);
Assert.Equal(1, archiveFiles.Length);
Assert.Equal(archiveFileName, Path.GetFileName(archiveFiles[0]));
}
finally
{
TimeSource.Current = defaultTimeSource; // restore default time source
LogManager.Configuration = null;
if (Directory.Exists(tempPath))
Directory.Delete(tempPath, true);
}
}
public void DateArchive_UsesDateFromCurrentTimeSource(DateTimeKind timeKind, bool concurrentWrites, bool keepFileOpen, bool networkWrites, bool includeSequenceInArchive)
{
var tempPath = Path.Combine(Path.GetTempPath(), Guid.NewGuid().ToString());
var tempFile = Path.Combine(tempPath, "file.txt");
var defaultTimeSource = TimeSource.Current;
try
{
var timeSource = new TimeSourceTests.ShiftedTimeSource(timeKind);
TimeSource.Current = timeSource;
var archiveFileNameTemplate = Path.Combine(tempPath, "archive", "{#}.txt");
var ft = new FileTarget
{
FileName = tempFile,
ArchiveFileName = archiveFileNameTemplate,
LineEnding = LineEndingMode.LF,
ArchiveNumbering = includeSequenceInArchive ? ArchiveNumberingMode.DateAndSequence : ArchiveNumberingMode.Date,
ArchiveEvery = FileArchivePeriod.Day,
ArchiveDateFormat = "yyyyMMdd",
Layout = "${date:format=O}|${message}",
MaxArchiveFiles = 3,
ConcurrentWrites = concurrentWrites,
KeepFileOpen = keepFileOpen,
NetworkWrites = networkWrites,
};
SimpleConfigurator.ConfigureForTargetLogging(ft, LogLevel.Debug);
logger.Debug("123456789");
DateTime previousWriteTime = timeSource.Time;
const int daysToTestLogging = 5;
const int intervalsPerDay = 24;
var loggingInterval = TimeSpan.FromHours(1);
for (var i = 0; i < daysToTestLogging * intervalsPerDay; ++i)
{
timeSource.AddToLocalTime(loggingInterval);
if (timeSource.Time.Date != previousWriteTime.Date)
{
// Simulate that previous file write began in previous day and ended on current day.
try
{
File.SetLastWriteTime(tempFile, timeSource.SystemTime);
}
catch { }
}
var eventInfo = new LogEventInfo(LogLevel.Debug, logger.Name, "123456789");
logger.Log(eventInfo);
var dayIsChanged = eventInfo.TimeStamp.Date != previousWriteTime.Date;
// ensure new archive is created only when the day part of time is changed
var archiveFileName = archiveFileNameTemplate.Replace("{#}", previousWriteTime.ToString(ft.ArchiveDateFormat) + (includeSequenceInArchive ? ".0" : string.Empty));
var archiveExists = File.Exists(archiveFileName);
if (dayIsChanged)
Assert.True(archiveExists, string.Format("new archive should be created when the day part of {0} time is changed", timeKind));
else
Assert.False(archiveExists, string.Format("new archive should not be create when day part of {0} time is unchanged", timeKind));
previousWriteTime = eventInfo.TimeStamp.Date;
if (dayIsChanged)
timeSource.AddToSystemTime(TimeSpan.FromDays(1));
}
//Setting the Configuration to [null] will result in a 'Dump' of the current log entries
LogManager.Configuration = null;
var archivePath = Path.Combine(tempPath, "archive");
var files = Directory.GetFiles(archivePath).OrderBy(s => s).ToList();
//the amount of archived files may not exceed the set 'MaxArchiveFiles'
Assert.Equal(ft.MaxArchiveFiles, files.Count);
SimpleConfigurator.ConfigureForTargetLogging(ft, LogLevel.Debug);
//writing one line on a new day will trigger the cleanup of old archived files
//as stated by the MaxArchiveFiles property, but will only delete the oldest file
timeSource.AddToLocalTime(TimeSpan.FromDays(1));
logger.Debug("1234567890");
LogManager.Configuration = null;
var files2 = Directory.GetFiles(archivePath).OrderBy(s => s).ToList();
Assert.Equal(ft.MaxArchiveFiles, files2.Count);
//the oldest file should be deleted
Assert.DoesNotContain(files[0], files2);
//two files should still be there
Assert.Equal(files[1], files2[0]);
Assert.Equal(files[2], files2[1]);
//one new archive file should be created
Assert.DoesNotContain(files2[2], files);
}
finally
{
TimeSource.Current = defaultTimeSource; // restore default time source
LogManager.Configuration = null;
if (File.Exists(tempFile))
File.Delete(tempFile);
if (Directory.Exists(tempPath))
Directory.Delete(tempPath, true);
}
}
public void WhenRepeatedMaxCacheSizeIgnoreTest()
{
LogManager.Configuration = XmlLoggingConfiguration.CreateFromXmlString(@"
<nlog>
<targets><target name='debug' type='Debug' layout='${message}' /></targets>
<rules>
<logger name='*' minlevel='Debug' writeTo='debug'>
<filters>
<whenRepeated layout='${message}' action='Ignore' maxFilterCacheSize='5' defaultFilterCacheSize='5' timeoutSeconds='10' />
</filters>
</logger>
</rules>
</nlog>");
var defaultTimeSource = Time.TimeSource.Current;
try
{
var timeSource = new TimeSourceTests.ShiftedTimeSource(DateTimeKind.Local);
Time.TimeSource.Current = timeSource;
ILogger logger = LogManager.GetLogger("A");
logger.Debug("a");
AssertDebugCounter("debug", 1);
logger.Debug("zzz");
AssertDebugCounter("debug", 2);
logger.Debug("zzz");
AssertDebugCounter("debug", 2);
logger.Debug("b");
AssertDebugCounter("debug", 3);
logger.Debug("c");
AssertDebugCounter("debug", 4);
logger.Debug("d");
AssertDebugCounter("debug", 5);
timeSource.AddToLocalTime(TimeSpan.FromSeconds(5));
logger.Debug("e");
AssertDebugCounter("debug", 6);
logger.Debug("f");
AssertDebugCounter("debug", 7);
logger.Debug("zzz");
AssertDebugCounter("debug", 7);
timeSource.AddToLocalTime(TimeSpan.FromSeconds(10));
for (int i = 0; i < 10; ++i)
{
char charCount = (char)('g' + i);
logger.Debug(charCount.ToString());
AssertDebugCounter("debug", 8 + i);
}
logger.Debug("zzz");
AssertDebugCounter("debug", 18);
}
finally
{
Time.TimeSource.Current = defaultTimeSource; // restore default time source
}
}
public void WebserviceTest_restapi_group_json()
{
var configuration = CreateConfigurationFromString(string.Format(@"
<nlog throwExceptions='true'>
<targets>
<target type='BufferingWrapper' bufferSize='6' name='ws'>
<target type='WebService'
name='ws_wrapped'
url='{0}{1}'
protocol='JsonPost'
encoding='UTF-8'
>
<header name='Authorization' layout='OpenBackDoor' />
<parameter name='param1' enableGroupLayout='true' groupHeaderLayout='{{ ' groupItemSeparatorLayout=' , ' groupFooterLayout=' }}'>
<layout type='JsonLayout'>
<attribute name='level' layout='${{level}}'/>
<attribute name='message' layout='${{message}}'/>
</layout>
</parameter>
<parameter name='param2' ParameterType='System.String' layout='${{level}}'/>
<parameter name='param3' ParameterType='System.Boolean' layout='True'/>
<parameter name='param4' ParameterType='System.DateTime' layout='${{date:format=yyyy-MM-dd HH\:mm}}'/>
</target>
</target>
</targets>
<rules>
<logger name='*' writeTo='ws'>
</logger>
</rules>
</nlog>", getWsAddress(1), "api/logdoc/json"));
LogManager.Configuration = configuration;
var logger = LogManager.GetCurrentClassLogger();
var txt = "message 1 with a JSON POST<hello><again\\>\"\b"; // Lets tease the JSON serializer and see it can handle valid and invalid xml chars
var expected = new System.Text.StringBuilder();
for (int i = 0; i < 3; ++i)
{
if (expected.Length == 0)
{
expected.Append("{ ");
}
else
{
expected.Append(" , ");
}
expected.Append("{ \"level\": \"Info\", \"message\": \"message 1 with a JSON POST<hello><again\\\\>\\\"\\b\" }");
}
expected.Append(" }");
var count = 2;
var context = new LogDocController.TestContext(1, count, false, new Dictionary <string, string>()
{
{ "Authorization", "OpenBackDoor" }
}, expected.ToString(), "info", true, DateTime.UtcNow.Date);
StartOwinDocTest(context, () =>
{
var defaultTimeSource = Time.TimeSource.Current;
try
{
var timeSource = new TimeSourceTests.ShiftedTimeSource(DateTimeKind.Local);
if (timeSource.Time.Minute == 59)
{
timeSource.AddToLocalTime(TimeSpan.FromMinutes(1));
timeSource.AddToSystemTime(TimeSpan.FromMinutes(1));
}
Time.TimeSource.Current = timeSource;
for (int i = 0; i < 3; i++)
{
logger.Info(txt);
}
timeSource.AddToLocalTime(TimeSpan.FromMinutes(2));
for (int i = 0; i < 3; i++)
{
logger.Info(txt);
}
}
finally
{
Time.TimeSource.Current = defaultTimeSource; // restore default time source
}
});
Assert.Equal <int>(0, context.CountdownEvent.CurrentCount);
}
