public void CouldWriteReadLog0MoveGT()
{
#pragma warning disable 618
Settings.DoAdditionalCorrectnessChecks = false;
#pragma warning restore 618
var path = TestUtils.GetPath();
var repoName = "CouldWriteAndReadLog0";
var processConfig = new ProcessConfig(path);
StartupConfig.StreamLogBufferPoolFlags = LMDBEnvironmentFlags.NoSync;
StartupConfig.StreamBlockIndexFlags = LMDBEnvironmentFlags.NoSync;
var slm = new StreamLogManager(processConfig, repoName, null, 10 * 1024, true, true);
var log0 = new NotificationLog(slm);
// will disable packing
log0.ActiveBuffer.Increment();
var count = 3_000_000;
using (Benchmark.Run("Log0.Append", count))
{
for (long i = 1; i <= count; i++)
{
log0.Append((StreamLogNotification)(ulong)i);
}
}
using (Benchmark.Run("Log0 MoveGT", count))
{
using (var reader = new NotificationLog.Reader(log0, CancellationToken.None, false))
{
for (long i = 0; i < count; i++)
{
if (reader.MoveGT((ulong)i))
{
if (reader.CurrentVersion != (ulong)(i + 1))
{
Assert.Fail($"reader.CurrentVersion {reader.CurrentVersion} != [(ulong) (i + 1)] {i + 1}");
}
}
}
}
}
// readerTask.Wait();
Benchmark.Dump();
slm.BufferPool.PrintBuffersAfterPoolDispose = true;
log0.Dispose();
slm.Dispose();
}
public void CouldReadWriteZeroLogViaThreadPool()
{
Console.WriteLine("Starting test");
Console.Out.Flush();
#pragma warning disable 618
Settings.DoAdditionalCorrectnessChecks = false;
#pragma warning restore 618
var path = TestUtils.GetPath(clear: true);
var repoName = "CouldWriteAndReadLog0";
var processConfig = new ProcessConfig(path);
StartupConfig.StreamLogBufferPoolFlags = LMDBEnvironmentFlags.NoSync;
StartupConfig.StreamBlockIndexFlags = LMDBEnvironmentFlags.NoSync;
var slm = new StreamLogManager(processConfig, repoName, null, 20 * 1024, false, true);
var count = TestUtils.GetBenchCount(200 * 1024 * 1024L, 1000);
var tp = new SpreadsThreadPool(new ThreadPoolSettings(6, ThreadType.Foreground, "Log0Pool",
ApartmentState.Unknown, null, 0, ThreadPriority.AboveNormal));
var writer = new Thread(() =>
{
for (int i = 1; i <= count; i++)
{
var x = i;
ThreadPool.UnsafeQueueUserWorkItem(o =>
{
(o as NotificationLog).Append((StreamLogNotification)(ulong)x);
}
, slm.Log0);
}
});
writer.Priority = ThreadPriority.Highest;
writer.Start();
var reader = new Thread(() =>
{
try
{
var c = 0L;
using (Benchmark.Run("ZL Read", count, true))
{
var zlr = new NotificationLog.Reader(slm.Log0, CancellationToken.None);
var sw = new SpinWait();
while (zlr.MoveNext())
{
// if (zlr.MoveNext())
{
// Thread.SpinWait(1);
c++;
if (c % 10_000_000 == 0)
{
Console.WriteLine($"{c:N0} | MQL {zlr.MissedQueueLength}");
}
if (c >= count - 1000)
{
if (zlr.MissedQueueLength > 0)
{
Console.WriteLine("Missed queue non empty");
continue;
}
Console.WriteLine(
$"Finished at CurrentVersion: " + zlr.CurrentVersion.ToString("N"));
break;
}
}
//else
//{
// sw.SpinOnce();
// if (sw.NextSpinWillYield)
// {
// sw.Reset();
// if (zlr.CurrentVersion > slm.Log0.State.GetZeroLogVersion())
// {
// Console.WriteLine("Reached the end");
// // break;
// }
// // Console.WriteLine($"Spinning in ZLMN: " + zlr.CurrentVersion.ToString("N"));
// }
//}
}
if (zlr.MaxStall > MaxStall)
{
MaxStall = zlr.MaxStall;
}
Console.WriteLine("STALLS: " + zlr.StallCount);
Console.WriteLine("-------------------------");
Console.WriteLine("MAX STALL: " + zlr.MaxStall.ToString("N"));
Console.WriteLine("GLOBAL MAX STALL: " + MaxStall.ToString("N"));
Console.WriteLine("-------------------------");
zlr.Dispose();
}
Console.WriteLine("Read count: " + c.ToString("N"));
}
catch (Exception ex)
{
Console.WriteLine("Reader exception: " + ex);
}
});
reader.Priority = ThreadPriority.Highest;
reader.Start();
reader.Join();
tp.Dispose();
tp.WaitForThreadsExit();
Benchmark.Dump();
Thread.Sleep(100);
Console.WriteLine("ROTATE CNT: " + (slm.Log0.RotateCount));
Console.WriteLine("STALE VERSION CNT: " + (slm.Log0.StaleVersionCount));
//slm.Dispose();
//slm2.Dispose();
GC.KeepAlive(slm); GC.KeepAlive(slm);
slm.Dispose();
Thread.Sleep(1000);
}
public void CouldWriteReadLog0(bool delete)
{
#pragma warning disable 618
Settings.DoAdditionalCorrectnessChecks = false;
Settings.DoDetectBufferLeaks = false;
#pragma warning restore 618
var path = TestUtils.GetPath(clear: delete);
var repoName = "CouldWriteAndReadLog0";
var processConfig = new ProcessConfig(path);
StartupConfig.StreamLogBufferPoolFlags = LMDBEnvironmentFlags.NoSync;
StartupConfig.StreamBlockIndexFlags = LMDBEnvironmentFlags.NoSync;
var slm = new StreamLogManager(processConfig, repoName, null, 10 * 1024, disableNotificationLog: false, disablePacker: false);
// var log0 = new NotificationLog(slm);
// will disable packing: log0._activeBuffer.Increment();
var count = TestUtils.GetBenchCount(100_000_000, 1000);
var readerTask = Task.Run(() =>
{
try
{
var step = count / 10;
var stat = Benchmark.Run("Read", step);
{
using (var reader = new NotificationLog.Reader(slm.Log0, CancellationToken.None, false))
{
var previous = 0UL;
while (reader.MoveNext())
{
var current = (ulong)reader.Current;
//if (current != previous + 1)
//{
// Assert.Fail($"current {current} != [previous + 1] {previous + 1}");
//}
previous = current;
if (_couldWriteReadLog0Finished)
{
break;
}
if ((reader.CurrentVersion % (ulong)(step)) == 0)
{
stat.Dispose();
stat = Benchmark.Run("Read", step);
Console.WriteLine($"Running total: {reader.CurrentVersion:N0}");
}
}
Console.WriteLine("Reader done");
//if (previous != (ulong)count)
//{
// Assert.Fail($"previous {previous} != count {count}");
//}
}
}
stat.Dispose();
}
catch (Exception ex)
{
Console.WriteLine("READER EX: " + ex);
}
});
var writerTask = Task.Run(() =>
{
try
{
var stat = Benchmark.Run("Write to Log0", count);
{
for (long i = 1; i <= count; i++)
{
if (_couldWriteReadLog0Finished)
{
break;
}
slm.Log0.Append((StreamLogNotification)(ulong)i);
//if (i % 10_000_000 == 0)
//{
// stat.Dispose();
// stat = Benchmark.Run("Write to Log0", 10_000_000);
//}
}
Console.WriteLine("W1 Done");
_couldWriteReadLog0Finished = true;
}
stat.Dispose();
}
catch (Exception ex)
{
Console.WriteLine("EX: " + ex);
}
});
var writerTask2 = Task.Run(() =>
{
try
{
using (Benchmark.Run("Write to Log0", count))
{
for (long i = 1; i <= count; i++)
{
if (_couldWriteReadLog0Finished)
{
break;
}
slm.Log0.Append((StreamLogNotification)(ulong)i);
}
Console.WriteLine("W2 Done");
_couldWriteReadLog0Finished = true;
}
}
catch (Exception ex)
{
Console.WriteLine("EX: " + ex);
}
});
writerTask2.Wait();
readerTask.Wait();
writerTask.Wait();
Benchmark.Dump();
slm.BufferPool.PrintBuffersAfterPoolDispose = true;
// log0.Dispose();
slm.Dispose();
}
public void CouldReadWriteZeroLog()
{
Console.WriteLine("Starting test");
Console.Out.Flush();
#pragma warning disable 618
Settings.DoAdditionalCorrectnessChecks = false;
#pragma warning restore 618
var path = TestUtils.GetPath(clear: true);
var repoName = "CouldWriteAndReadLog0";
var processConfig = new ProcessConfig(path);
var processConfig2 = new ProcessConfig(path);
StartupConfig.StreamLogBufferPoolFlags = LMDBEnvironmentFlags.NoSync;
StartupConfig.StreamBlockIndexFlags = LMDBEnvironmentFlags.NoSync;
var slm = new StreamLogManager(processConfig, repoName, null, 20 * 1024, disableNotificationLog: false, true);
var slm2 = new StreamLogManager(processConfig2, repoName, null, 20 * 1024, disableNotificationLog: false, true);
slm.Log0.ActiveBlock.SharedMemory.Increment();
slm2.Log0.ActiveBlock.SharedMemory.Increment();
if (slm.Log0.State.StreamLogId != slm2.Log0.State.StreamLogId)
{
Assert.Fail("slm.Log0.State.StreamLogId != slm2.Log0.State.StreamLogId");
}
var count = TestUtils.GetBenchCount(200 * 1024 * 1024L, 1000);
// must be pow2 because we divide count by it
var taskPerProcessCount = 6;
//var tasks1 = new List<Task>();
//var tasks2 = new List<Task>();
var threads1 = new List <Thread>();
var threads2 = new List <Thread>();
for (int t = 0; t < taskPerProcessCount; t++)
{
var x = t;
threads1.Add(new Thread(() =>
{
Thread.CurrentThread.Name = "W1_" + x;
using (Benchmark.Run("ZL Write", count / (2 * taskPerProcessCount), false))
{
for (long i = 1; i <= count / (2 * taskPerProcessCount); i++)
{
try
{
{
if (slm.Log0.Append((StreamLogNotification)(ulong)i) == 0)
{
Assert.Fail("Cannot append");
}
// Thread.SpinWait(5);
//if (i % 50 == 0)
//{
// if (!Thread.Yield())
// {
// Thread.Sleep(0);
// }
//}
}
}
catch (Exception ex)
{
Console.WriteLine(ex);
}
}
Console.WriteLine("W1 done");
}
}));
}
for (int t = 0; t < taskPerProcessCount; t++)
{
var x = t;
threads2.Add(new Thread(() =>
{
try
{
Thread.CurrentThread.Name = "W2_" + x;
using (Benchmark.Run("ZL Write", count / (2 * taskPerProcessCount), false))
{
for (long i = 1; i <= count / (2 * taskPerProcessCount); i++)
{
try
{
{
if (slm2.Log0.Append((StreamLogNotification)(ulong)i) == 0)
{
Assert.Fail("Cannot Append: " + i);
}
;
// Thread.SpinWait(5);
//if (i % 50 == 0)
//{
// if (!Thread.Yield())
// {
// Thread.Sleep(0);
// }
//}
}
}
catch (Exception ex)
{
Console.WriteLine(ex);
}
}
Console.WriteLine("W2 done");
//slm2.Log0.Dispose();
}
}
catch (Exception ex)
{
Console.WriteLine(ex);
}
}));
}
foreach (var thread in threads1)
{
thread.Priority = ThreadPriority.Normal;
thread.Start();
}
foreach (var thread in threads2)
{
thread.Priority = ThreadPriority.Normal;
thread.Start();
}
var reader = new Thread(() =>
{
try
{
var c = 0L;
using (Benchmark.Run("ZL Read", count, true))
{
var zlr = new NotificationLog.Reader(slm.Log0, CancellationToken.None);
var sw = new SpinWait();
while (zlr.MoveNext())
{
// if (zlr.MoveNext())
{
// Thread.SpinWait(1);
c++;
if (c % 10_000_000 == 0)
{
Console.WriteLine($"{c:N0} | MQL {zlr.MissedQueueLength}");
}
if (c >= count - 2 * taskPerProcessCount - 1000)
{
if (zlr.MissedQueueLength > 0)
{
Console.WriteLine("Missed queue non empty");
continue;
}
Console.WriteLine(
$"Finished at CurrentVersion: " + zlr.CurrentVersion.ToString("N"));
break;
}
}
//else
//{
// sw.SpinOnce();
// if (sw.NextSpinWillYield)
// {
// sw.Reset();
// if (zlr.CurrentVersion > slm.Log0.State.GetZeroLogVersion())
// {
// Console.WriteLine("Reached the end");
// // break;
// }
// // Console.WriteLine($"Spinning in ZLMN: " + zlr.CurrentVersion.ToString("N"));
// }
//}
}
if (zlr.MaxStall > MaxStall)
{
MaxStall = zlr.MaxStall;
}
Console.WriteLine("STALLS: " + zlr.StallCount);
Console.WriteLine("-------------------------");
Console.WriteLine("MAX STALL: " + zlr.MaxStall.ToString("N"));
Console.WriteLine("GLOBAL MAX STALL: " + MaxStall.ToString("N"));
Console.WriteLine("-------------------------");
zlr.Dispose();
}
Console.WriteLine("Read count: " + c.ToString("N"));
}
catch (Exception ex)
{
Console.WriteLine("Reader exception: " + ex);
}
});
reader.Priority = ThreadPriority.Normal;
reader.Start();
foreach (var thread in threads1)
{
thread.Join();
}
foreach (var thread in threads2)
{
thread.Join();
}
reader.Join();
//using (Benchmark.Run("Log0 MoveNext", count))
//{
// var readCount = 0;
// try
// {
// var chunkCursor =
// slm.Log0.State.StreamLogManager.LogChunkIndex.GetChunkRecordCursor(StreamLogId.Log0Id);
// using (var txn = slm.Log0.State.StreamLogManager.LogChunkIndex._env.BeginReadOnlyTransaction())
// {
// var chunks = slm.Log0.State.StreamLogManager.LogChunkIndex._chunksDb
// .AsEnumerable<long, StreamLogChunkRecord>(txn, -1).ToArray();
// var previous = 0UL;
// foreach (var r in chunks)
// {
// var chunk = slm.Log0.RentChunkFromRecord(r);
// if (chunk.IsValid)
// {
// Console.WriteLine(
// $"SLCR: version {r.Version} - chunk first version: {chunk.FirstVersion}");
// if (r.Version != chunk.FirstVersion &&
// r.Version != StreamLogChunkIndex.ReadyChunkVersion)
// {
// Assert.Fail("Bad versions");
// }
// chunk.DisposeFree();
// if (previous != 0 && previous == r.Version)
// {
// Assert.Fail("Duplicate SLCR");
// }
// previous = r.Version;
// }
// }
// }
// slm.BufferPool.PrintBuffers();
// Console.WriteLine("Move next");
// while (chunkCursor.MoveNext())
// {
// var record = chunkCursor.Current.Value;
// Console.WriteLine("Record version: " + record.Version);
// if ((long)record.Version >= count)
// {
// Console.WriteLine("Break");
// break;
// }
// var chunk = slm.Log0.RentChunkFromRecord(record);
// Console.WriteLine("Chunk first version: " + chunk.FirstVersion);
// for (ulong i = 0; i < 1024 * 1024; i++)
// {
// var position = NotificationLog.Log0ItemPosition(chunk._pointer,
// (long)(chunk.FirstVersion + i), out _);
// var value = *(ulong*)position;
// if (value == 0)
// {
// Assert.Fail("Zero value at: " + (chunk.FirstVersion + i));
// // Console.WriteLine("Zero value at: " + (chunk.FirstVersion + i));
// }
// // Console.WriteLine("OK");
// readCount++;
// }
// chunk.DisposeFree();
// }
// //var c = log0.GetContainerCursor(false);
// //while (c.MoveNext())
// //{
// // if (c.CurrentValue.ReadUInt64(0) == 0)
// // {
// // // Console.WriteLine($"c.CurrentValue == 0 at {c.CurrentKey}");
// // Assert.Fail($"c.CurrentValue == 0 at {c.CurrentKey}");
// // }
// // readCount++;
// //}
// //c.Dispose();
// // Assert.AreEqual(count, readCount);
// }
// catch (Exception ex)
// {
// Console.WriteLine("EX: " + ex);
// }
// Console.WriteLine("READ COUNT M: " + readCount * 1.0 / (1024 * 1024));
//}
//Console.ReadLine();
//slm.Log0.Dispose();
//slm2.Log0.Dispose();
//slm.Dispose();
//slm2.Dispose();
Benchmark.Dump();
Thread.Sleep(100);
Console.WriteLine("ROTATE CNT: " + (slm.Log0.RotateCount + slm2.Log0.RotateCount));
Console.WriteLine("STALE VERSION CNT: " + (slm.Log0.StaleVersionCount + slm2.Log0.StaleVersionCount));
slm.Dispose();
slm2.Dispose();
GC.KeepAlive(slm);
GC.KeepAlive(slm2);
}
public StreamLogManager(ProcessConfig processConfig,
string dataStoreName,
string dataStorePath = null,
uint maxLogSizeMb = 1024,
bool disableNotificationLog = false,
bool disablePacker = false,
IStreamBlockStorage blockStorage = null)
{
if (LeaksDetection.Enabled)
{
Spreads.Buffers.BufferPool.PinnedArrayMemoryPool.AddStackTraceOnRent = true;
}
DataStorePath = dataStorePath ?? Path.Combine(processConfig.DataRootPath, dataStoreName);
ProcessConfig = processConfig;
_wpidValue = ProcessConfig.Wpid;
DisableNotificationLog = disableNotificationLog;
DisablePacker = disablePacker;
var bufferPoolPath = Path.Combine(DataStorePath, "log", "logbuffer");
var bufferPoolFlags = StartupConfig.StreamLogBufferPoolFlags;
BufferPool = new BlockMemoryPool(bufferPoolPath, maxLogSizeMb, bufferPoolFlags, processConfig.Wpid,
maxBufferLength: MaxBufferSize,
maxBuffersPerBucket: Environment.ProcessorCount * 4);
if (blockStorage == null)
{
var dataStoragePath = Path.Combine(DataStorePath, "storage");
Directory.CreateDirectory(dataStoragePath);
var path = Path.GetFullPath(Path.Combine(dataStoragePath, "data.db"));
var uri = new Uri(path);
var absoluteUri = uri.AbsoluteUri;
blockStorage = new SQLiteStorage($@"Data Source={absoluteUri}?cache=shared");
}
var blockIndexPath = Path.Combine(DataStorePath, "log", "blockindex");
var blockIndexFlags = StartupConfig.StreamBlockIndexFlags;
var blockIndexSizeMb = Math.Max(StartupConfig.StreamBlockTableMaxSizeMb, 128);
BlockIndex = new StreamBlockIndex(blockIndexPath, blockIndexSizeMb, blockIndexFlags, BufferPool, blockStorage);
var logStateStoragePath = Path.Combine(DataStorePath, "log", "logstate");
StateStorage = new StreamLogStateStorage(logStateStoragePath);
// For Log0 tests we need state but we removed it from Log0 ctor, so always init it.
// In real code _disableNotificationLog is always false.
Log0State = StateStorage.GetState(StreamLogId.Log0Id);
Log0State.CheckInit(StreamLogId.Log0Id, StreamLogNotification.Size, StreamLogFlags.IsBinary | StreamLogFlags.NoTimestamp | StreamLogFlags.DropPacked | StreamLogFlags.Pow2Payload);
Log0State.HintRatePerMinute(MaxBufferSize);
if (!DisableNotificationLog)
{
Log0 = new NotificationLog(this);
OpenStreams.TryAdd((long)StreamLogId.Log0Id, Log0);
Log0Reader = new NotificationLog.Reader(Log0, Cts.Token);
var lastVersion = (ulong)Log0.CurrentVersion;
if (lastVersion > 1)
{
Log0Reader.MoveGT(lastVersion - 1);
}
}
Packer = new Packer(this, StateStorage, disablePacker);
StartLog0(dataStoreName);
// TODO we need more general unlocking locking that detects missed updates
// and works for all waiters, not only for ack. See Log0.Reader comments.
//_unlockTimer = new Timer(o =>
//{
// TryCompleteAckRequests();
//}, null, 0, 1000);
}