private static void LogLine(string msg, EventType eventType)
{
switch (eventType)
{
case EventType.Error:
SnLog.WriteError(msg, categories: AdSyncLogCategory);
break;
case EventType.Warning:
SnLog.WriteWarning(msg, categories: AdSyncLogCategory);
break;
case EventType.Info:
SnLog.WriteInformation(msg, categories: AdSyncLogCategory);
break;
case EventType.Verbose:
SnTrace.Write("{0}: {1}", AdSync, msg);
break;
}
Console.WriteLine(msg);
// log event for subscriber of the current thread
StringBuilder sb;
if (Subscribers.TryGetValue(Thread.CurrentThread.GetHashCode(), out sb))
{
if (sb != null)
{
sb.AppendLine(GetMsgWithTimeStamp(msg));
}
}
}
public void SnTrace_DynamicCategories()
{
// Test initialization
CleanupAndEnableAll();
// Activate Custom and Test categories. Any other be inactive.
SnTrace.DisableAll();
SnTrace.Custom.Enabled = true;
SnTrace.Test.Enabled = true;
// Write 7 lines including dynamic categories
SnTrace.Write("Line1");
SnTrace.Category("asdf").Write("Line2");
SnTrace.Test.Write("Line3");
SnTrace.Category("qwer").Write("Line4");
SnTrace.Test.Write("Line5");
SnTrace.Category("yxcv").Write("Line6");
SnTrace.Write("Line7");
// Get log
var log = DisableAllAndGetLog();
// Get categories
var categories = log
.Select(Entry.Parse)
.Where(e => e != null)
.Select(e => e.Category)
.ToArray();
var actual = string.Join(",", categories);
// Verify
Assert.AreEqual("Custom,asdf,Test,qwer,Test,yxcv,Custom", actual);
}
internal bool IsFeatureEnabled(int id)
{
if (!__isFeatureEnabled)
{
SnTrace.Write($"EventDistributor INACTIVATED ({id}).");
}
return(__isFeatureEnabled);
}
public void WriteLock_DeletionAfterKilledProcess()
{
var tracer = GetTracer();
SnTrace.EnableAll();
// Ensure an existing but free index directory
SnTrace.Write("1 creating index");
var indexDir = EnsureIndexDirectoryAsync().ConfigureAwait(false).GetAwaiter().GetResult();
SnTrace.Write("2 index created");
// Start a process that use the directory
var exePath = Path.GetFullPath(Path.Combine(
System.Reflection.Assembly.GetExecutingAssembly().Location,
"..\\..\\..\\..\\WorkerForWriteLockDeletionTests\\bin\\Debug\\netcoreapp3.1\\WorkerForWriteLockDeletionTests.exe"));
var process = Process.Start(exePath, $"100000 {indexDir.Name} {indexDir.Path}");
if (process == null)
{
Assert.Fail("Cannot start the process.");
}
SnTrace.Write("3 process started");
// Wait for the indexing engine uses the index
while (!File.Exists(indexDir.LockPath))
{
Task.Delay(100).ConfigureAwait(false).GetAwaiter().GetResult();
}
SnTrace.Write("4 index locked");
// Start the new indexing engine in async way.
SnTrace.Write("5 starting new engine");
Task.Run(() => { StartNewEngineAsync(indexDir.Name, indexDir.Path).ConfigureAwait(false); });
SnTrace.Write("6 wait a bit");
// Wait a bit
Task.Delay(1000).ConfigureAwait(false).GetAwaiter().GetResult();
// Check the console: the new engine cannot delete the write.lock file
var lastLine1 = tracer.Lines[tracer.Lines.Count - 1];
// Kill the lock owner process
SnTrace.Write("7 killing the process");
process.Kill();
//Task.Delay(20).ConfigureAwait(false).GetAwaiter().GetResult();
//File.Delete(indexDir.LockPath);
SnTrace.Write("8 wait a bit");
// lock file remains but deletable
Task.Delay(2000).ConfigureAwait(false).GetAwaiter().GetResult();
SnTrace.Write("9 test finished");
// Check the console: the new engine has started
Assert.IsTrue(tracer.Lines.Any(x => x.EndsWith("101 started")));
}
public void SnTrace_WriteEmpty_WithParams()
{
CleanupAndEnableAll();
SnTrace.Write(null, 1, "asdf");
var log = DisableAllAndGetLog();
AssertOneErrorLine(log, "Value cannot be null");
}
public void SnTrace_WriteNotEmpty_NullParams()
{
CleanupAndEnableAll();
SnTrace.Write("asdf: {0}", null);
var log = DisableAllAndGetLog();
AssertOneErrorLine(log, "asdf: {0}");
}
public void SnTrace_WriteEmpty_WithoutParams()
{
CleanupAndEnableAll();
SnTrace.Write(null);
var log = DisableAllAndGetLog();
AssertOneErrorLine(log, "SnTrace_WriteEmpty_WithoutParams");
}
public void SnTrace_SmartFormat_IntList()
{
CleanupAndEnableAll();
SnTrace.Write("asdf: {0}", new List <int>(new[] { 1, 2, 3, 4 }));
var log = DisableAllAndGetLog();
var msg = GetMessageFromLine(log[0]);
Assert.AreEqual("asdf: [1, 2, 3, 4]", msg);
}
public void SnTrace_SmartFormat_StringList()
{
CleanupAndEnableAll();
SnTrace.Write("asdf: {0}", new List <string>(new[] { "asdf", "qwer", "yxcv" }));
var log = DisableAllAndGetLog();
var msg = GetMessageFromLine(log[0]);
Assert.AreEqual("asdf: [asdf, qwer, yxcv]", msg);
}
public void SnTrace_WriteNotEmpty_NullValue()
{
CleanupAndEnableAll();
SnTrace.Write("asdf: {0}, {1}, {2}", 42, null, "asdf");
var log = DisableAllAndGetLog();
var msg = GetMessageFromLine(log[0]);
Assert.AreEqual("asdf: 42, [null], asdf", msg);
}
public void SnTrace_Write2lines()
{
CleanupAndEnableAll();
SnTrace.Write("asdf");
SnTrace.Write("qwer");
var log = DisableAllAndGetLog();
Assert.AreEqual(2, log.Count);
Assert.IsTrue(log[0].EndsWith("asdf"));
Assert.IsTrue(log[1].EndsWith("qwer"));
}
public void SnTrace_SmartFormat_LinqExpressionWhenDisabled()
{
CleanupAndEnableAll();
_expressionExecuted = false;
SnTrace.Custom.Enabled = false;
SnTrace.Write("asdf: {0}", Filter(Enumerable.Range(40, 5)));
var log = DisableAllAndGetLog();
Assert.AreEqual(0, log.Count);
Assert.IsFalse(_expressionExecuted);
}
public void SnTrace_SmartFormat_LinqExpressionWhenEnabled()
{
CleanupAndEnableAll();
_expressionExecuted = false;
SnTrace.Write("asdf: {0}", Filter(Enumerable.Range(40, 5)));
var log = DisableAllAndGetLog();
var msg = GetMessageFromLine(log[0]);
Assert.AreEqual(1, log.Count);
Assert.IsTrue(_expressionExecuted);
Assert.AreEqual("asdf: [41, 42, 43]", msg);
}
public void SnTrace_Entries_3lines()
{
CleanupAndEnableAll();
SnTrace.Write("asdf asdf");
SnTrace.Write("qwer\nqwer");
SnTrace.Write("yxcv\tyxcv");
var log = DisableAllAndGetLog();
var entries = log.Select(Entry.Parse).Where(e => e != null).ToArray();
Assert.AreEqual(3, entries.Length);
Assert.AreEqual("asdf asdf", entries[0].Message);
Assert.AreEqual("qwer.qwer", entries[1].Message);
Assert.AreEqual("yxcv\tyxcv", entries[2].Message);
}
private async Task StartNewEngineAsync(string name, string path)
{
var sb = new StringBuilder();
var console = new StringWriter(sb);
var indexDirectory = new IndexDirectory(name, path);
var engine = new Lucene29LocalIndexingEngine(indexDirectory);
SnTrace.Write("100 starting");
await engine.StartAsync(console, false, CancellationToken.None).ConfigureAwait(false);
SnTrace.Write("101 started");
while (!File.Exists(indexDirectory.IndexLockFilePath))
{
Task.Delay(50).ConfigureAwait(false).GetAwaiter().GetResult();
}
await engine.ShutDownAsync(CancellationToken.None).ConfigureAwait(false);
}
private void WriteStructure1()
{
SnTrace.Test.Write("1");
SnTrace.Write("2");
SnTrace.Test.Write("3");
SnTrace.Write("4");
SnTrace.Web.Write("5");
SnTrace.Repository.Write("6");
using (var op = SnTrace.Test.StartOperation("7"))
{
using (var op1 = SnTrace.StartOperation("8"))
{
op1.Successful = true;
}
using (var op2 = SnTrace.Repository.StartOperation("9"))
{
op2.Successful = true;
}
using (var op2 = SnTrace.Test.StartOperation("10"))
{
op2.Successful = true;
}
using (var op2 = SnTrace.Test.StartOperation("11"))
{
op2.Successful = false;
}
op.Successful = true;
}
SnTrace.Test.Write("12");
SnTrace.Repository.Write("13");
using (var op2 = SnTrace.Test.StartOperation("14"))
{
op2.Successful = true;
}
SnTrace.Repository.Write("15");
SnTrace.Test.Write("16");
SnTrace.Flush();
}
public async Task WorkAsync(CancellationToken cancellationToken)
{
var lastId = "";
var count = 0;
while (true)
{
// Exit if needed.
if (cancellationToken.IsCancellationRequested)
{
Console.WriteLine();
Console.WriteLine("Work finished");
return;
}
Console.Write("Work: {0}\r", ++count);
SnTrace.Write("#### wait");
await Task.Delay(TimeSpan.FromSeconds(0.2), cancellationToken).ConfigureAwait(false);
// Create one document...
var id = await CreateDocAsync(cancellationToken);
SnTrace.Write("#### document created: " + id);
// Delete the last created document.
if (lastId != "")
{
await DeleteDocAsync(lastId, cancellationToken);
SnTrace.Write("#### document deleted: " + lastId);
}
var result = ContentQuery.Query("Id:1").Identifiers;
// ... and memorize its Id as "lastId".
lastId = id;
}
}
protected async Task BackupAsync(CancellationToken cancellationToken)
{
var status = await IndexManager.LoadCurrentIndexingActivityStatusAsync(cancellationToken)
.ConfigureAwait(false);
using (var op = SnTrace.StartOperation("#### BACKUP " + this.GetType().Name))
{
SnTrace.Write("#### Indexing activity status: " + status);
Console.WriteLine();
Console.WriteLine("BACKUP start. Indexing activity status: " + status);
var response = await _engine.BackupAsync(_backupDirectoryPath, CancellationToken.None)
.ConfigureAwait(false);
if (response.State == BackupState.Started)
{
while (true)
{
await Task.Delay(400, cancellationToken).ConfigureAwait(false);
response = await _engine.QueryBackupAsync(cancellationToken).ConfigureAwait(false);
WriteProgress(response);
if (response.State != BackupState.Executing)
{
break;
}
}
//Console.WriteLine("BACKUP finished");
}
else
{
Console.WriteLine("BACKUP already started");
}
op.Successful = true;
}
}
public void SnTrace_Entries_Operations()
{
CleanupAndEnableAll();
using (var op1 = SnTrace.StartOperation("Op1"))
{
// ReSharper disable once UnusedVariable
using (var op2 = SnTrace.StartOperation("Op2"))
{
SnTrace.Write("asdf");
}
using (var op3 = SnTrace.StartOperation("Op3"))
{
SnTrace.Write("qwer");
op3.Successful = false;
}
using (var op4 = SnTrace.StartOperation("Op4"))
{
SnTrace.Write("yxcv");
op4.Successful = true;
}
op1.Successful = true;
}
var log = DisableAllAndGetLog();
var entries = log.Select(Entry.Parse).Where(e => e != null).ToArray();
Assert.AreEqual(11, entries.Length);
var operationData = string.Join(",", entries.Select(x => x.Status + ":" + x.Message));
Assert.AreEqual("Start:Op1,Start:Op2,:asdf,UNTERMINATED:Op2,Start:Op3,:qwer,UNTERMINATED:Op3,Start:Op4,:yxcv,End:Op4,End:Op1", operationData);
Assert.AreEqual(entries[0].OpId, entries[10].OpId);
Assert.AreEqual(entries[1].OpId, entries[3].OpId);
Assert.AreEqual(entries[4].OpId, entries[6].OpId);
Assert.AreEqual(entries[7].OpId, entries[9].OpId);
}
private void WriteStructure2()
{
SnTrace.Write("noise"); Wait(1);
SnTrace.Write("noise"); Wait(1);
SnTrace.Test.Write("noise"); Wait(1);
SnTrace.Write("noise"); Wait(1);
SnTrace.Test.Write("TEST START"); Wait(1); // relevant
SnTrace.Write("noise"); Wait(1);
SnTrace.Test.Write("noise"); Wait(1);
SnTrace.Write("noise"); Wait(1);
using (var op1 = SnTrace.Test.StartOperation("Op1"))
{
SnTrace.Test.Write("noise"); Wait(1);
SnTrace.Write("noise"); Wait(1);
SnTrace.Test.Write("noise"); Wait(1);
op1.Successful = true;
} // relevant
SnTrace.Write("noise"); Wait(1);
using (var op2 = SnTrace.Test.StartOperation("Op2"))
{
SnTrace.Test.Write("noise"); Wait(1);
SnTrace.Write("noise"); Wait(1);
SnTrace.Test.Write("noise"); Wait(1);
op2.Successful = true;
} // relevant
SnTrace.Test.Write("TEST END"); Wait(1);
SnTrace.Write("noise"); Wait(1);
SnTrace.Test.Write("noise"); Wait(1);
SnTrace.Test.Write("TEST START"); Wait(1); // (irrelevant)
SnTrace.Flush();
}
public void SnTrace_Operation_Nested()
{
CleanupAndEnableAll();
ResetOperationId();
using (var op1 = SnTrace.StartOperation("Op1"))
{
// ReSharper disable once UnusedVariable
using (var op2 = SnTrace.StartOperation("Op2"))
{
SnTrace.Write("asdf");
}
using (var op3 = SnTrace.StartOperation("Op3"))
{
SnTrace.Write("qwer");
op3.Successful = false;
}
using (var op4 = SnTrace.StartOperation("Op4"))
{
SnTrace.Write("yxcv");
op4.Successful = true;
}
op1.Successful = true;
}
var log = DisableAllAndGetLog();
Assert.AreEqual(11, log.Count);
var messages = string.Join(", ", log.Select(GetMessageFromLine));
Assert.AreEqual("Op1, Op2, asdf, Op2, Op3, qwer, Op3, Op4, yxcv, Op4, Op1", messages);
var operationData = string.Join(", ", log.Select(x => GetColumnFromLine(x, 5) + " " + GetColumnFromLine(x, 6)));
Assert.AreEqual("Op:1 Start, Op:2 Start, , Op:2 UNTERMINATED, Op:3 Start, , Op:3 UNTERMINATED, Op:4 Start, , Op:4 End, Op:1 End", operationData);
}
/// <summary>
/// a. Start a counter with 0.
/// b. Create one content (e.g. SystemFolder) and memorize its Id as "lastId".
/// c. If the counter greater than 1, delete the content by term "Id:{lastId-1}".
/// d. Increment the counter, wait a second and go to "b".
/// </summary>
public async Task WorkAsync(CancellationToken cancellationToken)
{
var lastId = 0;
var count = 0;
while (true)
{
// Exit if needed.
if (cancellationToken.IsCancellationRequested)
{
Console.WriteLine();
Console.WriteLine("Work finished");
return;
}
Console.Write("Work: {0}\r", ++count);
SnTrace.Write("#### wait");
await Task.Delay(TimeSpan.FromSeconds(0.2), cancellationToken).ConfigureAwait(false);
// Create one content (e.g. SystemFolder)...
var node = await CreateNode(cancellationToken);
SnTrace.Write("#### node created: " + node.Id);
// Delete the last created content.
if (lastId > 0)
{
Node.ForceDelete(lastId);
SnTrace.Write("#### node deleted: " + lastId);
}
// ... and memorize its Id as "lastId".
lastId = node.Id;
}
}
