Skip to content

Instantly share code, notes, and snippets.

@rofr

rofr/EventStoreWriter.cs

Created November 5, 2014 13:16
Show Gist options
  • Save rofr/9061b221fccafdc3a932 to your computer and use it in GitHub Desktop.
Save rofr/9061b221fccafdc3a932 to your computer and use it in GitHub Desktop.
Download ZIP
wtf did I screw up now?
Raw
es3 console output
[35352,15,13:05:22.010] SLOW QUEUE MSG [Projection Core #0]: ReadStreamEventsBac
kwardCompleted - 50ms. Q: 0/2.
[35352,05,13:05:22.080] SLOW QUEUE MSG [MonitoringQueue]: SystemInit - 2050ms. Q
: 0/5.
[35352,18,13:05:22.120] Created stats stream '$stats-127.0.0.1:2113', code = Suc
cess
Segments count: 1, buffers count: 512, should be when full: 512
[35352,03,13:05:25.702] External TCP connection accepted: [Normal, 127.0.0.1:196
3, L127.0.0.1:1113, {151584a1-a467-4e9b-8ece-0fa630e3a45b}].
[35352,12,13:05:28.822] Closing connection 'external-normal' [127.0.0.1:1963, L1
27.0.0.1:1113, {151584a1-a467-4e9b-8ece-0fa630e3a45b}] cleanly. Reason: HEARTBEA
T TIMEOUT at msgNum 0
[35352,12,13:05:28.888] ES TcpConnection closed [13:05:28.828: N127.0.0.1:1963,
L127.0.0.1:1113, {151584a1-a467-4e9b-8ece-0fa630e3a45b}]:
Received bytes: 0, Sent bytes: 22
Send calls: 1, callbacks: 1
Receive calls: 1, callbacks: 0
Close reason: [Success] HEARTBEAT TIMEOUT at msgNum 0
[35352,12,13:05:28.894] Connection 'external-normal' [127.0.0.1:1963, {151584a1-
a467-4e9b-8ece-0fa630e3a45b}] closed: Success.
^C
C:\EventStore-OSS-Win-v3.0.0>EventStore.ClusterNode.exe
[35348,01,13:07:45.990]
ES VERSION: 3.0.0.0 (master/51cef1881b1c5ab5e3962fb61bffac1dc99ec5
06, Wed, 17 Sep 2014 16:42:34 +0100)
OS: Windows (Microsoft Windows NT 6.1.7601 Service Pack 1)
RUNTIME: .NET 4.0.30319.18444 (64-bit)
GC: 3 GENERATIONS
LOGS: C:\Users\rofr\AppData\Local\Temp\EventStore\2014-11-05
_13.07.44.715915-Node2113-logs
HELP: False (<DEFAULT>)
VERSION: False (<DEFAULT>)
LOG: <empty> (<DEFAULT>)
CONFIG: <empty> (<DEFAULT>)
DEFINES: <empty> (<DEFAULT>)
WHAT IF: False (<DEFAULT>)
INT IP: 127.0.0.1 (<DEFAULT>)
EXT IP: 127.0.0.1 (<DEFAULT>)
INT HTTP PORT: 2112 (<DEFAULT>)
EXT HTTP PORT: 2113 (<DEFAULT>)
INT TCP PORT: 1112 (<DEFAULT>)
INT SECURE TCP PORT: 0 (<DEFAULT>)
EXT TCP PORT: 1113 (<DEFAULT>)
EXT SECURE TCP PORT: 0 (<DEFAULT>)
INT TCP HEARTBEAT TIMEOUT: 700 (<DEFAULT>)
EXT TCP HEARTBEAT TIMEOUT: 1000 (<DEFAULT>)
INT TCP HEARTBEAT INTERVAL: 700 (<DEFAULT>)
EXT TCP HEARTBEAT INTERVAL: 2000 (<DEFAULT>)
FORCE: False (<DEFAULT>)
CLUSTER SIZE: 1 (<DEFAULT>)
NODE PRIORITY: 0 (<DEFAULT>)
MIN FLUSH DELAY MS: 2 (<DEFAULT>)
COMMIT COUNT: -1 (<DEFAULT>)
PREPARE COUNT: -1 (<DEFAULT>)
ADMIN ON EXT: True (<DEFAULT>)
STATS ON EXT: True (<DEFAULT>)
GOSSIP ON EXT: True (<DEFAULT>)
DISABLE SCAVENGE MERGING: False (<DEFAULT>)
DISCOVER VIA DNS: True (<DEFAULT>)
CLUSTER DNS: fake.dns (<DEFAULT>)
CLUSTER GOSSIP PORT: 30777 (<DEFAULT>)
GOSSIP SEED: <empty> (<DEFAULT>)
STATS PERIOD SEC: 30 (<DEFAULT>)
CACHED CHUNKS: -1 (<DEFAULT>)
CHUNKS CACHE SIZE: 536871424 (<DEFAULT>)
MAX MEM TABLE SIZE: 1000000 (<DEFAULT>)
DB: <empty> (<DEFAULT>)
MEM DB: False (<DEFAULT>)
SKIP DB VERIFY: False (<DEFAULT>)
RUN PROJECTIONS: System (<DEFAULT>)
PROJECTION THREADS: 3 (<DEFAULT>)
WORKER THREADS: 5 (<DEFAULT>)
HTTP PREFIXES: <empty> (<DEFAULT>)
ENABLE TRUSTED AUTH: False (<DEFAULT>)
CERTIFICATE STORE LOCATION: <empty> (<DEFAULT>)
CERTIFICATE STORE NAME: <empty> (<DEFAULT>)
CERTIFICATE SUBJECT NAME: <empty> (<DEFAULT>)
CERTIFICATE THUMBPRINT: <empty> (<DEFAULT>)
CERTIFICATE FILE: <empty> (<DEFAULT>)
CERTIFICATE PASSWORD: <empty> (<DEFAULT>)
USE INTERNAL SSL: False (<DEFAULT>)
SSL TARGET HOST: n/a (<DEFAULT>)
SSL VALIDATE SERVER: True (<DEFAULT>)
AUTHENTICATION TYPE: internal (<DEFAULT>)
PREPARE TIMEOUT MS: 2000 (<DEFAULT>)
COMMIT TIMEOUT MS: 2000 (<DEFAULT>)
UNSAFE DISABLE FLUSH TO DISK: False (<DEFAULT>)
GOSSIP INTERVAL MS: 1000 (<DEFAULT>)
GOSSIP ALLOWED DIFFERENCE MS: 60000 (<DEFAULT>)
GOSSIP TIMEOUT MS: 500 (<DEFAULT>)
[35348,01,13:07:46.210] Quorum size set to 1
[35348,01,13:07:46.225] Can't find plugins path: C:\EventStore-OSS-Win-v3.0.0\pl
ugins
[35348,01,13:07:46.237]
INSTANCE ID: 60f17615-4af9-4d52-a54a-5040b31ec83b
DATABASE: C:\Users\rofr\AppData\Local\Temp\EventStore\2014-11-05
_13.07.44.715915-Node2113
WRITER CHECKPOINT: 0 (0x0)
CHASER CHECKPOINT: 0 (0x0)
EPOCH CHECKPOINT: -1 (0xFFFFFFFFFFFFFFFF)
TRUNCATE CHECKPOINT: -1 (0xFFFFFFFFFFFFFFFF)
[35348,01,13:07:46.596] MessageHierarchy initialization took 00:00:00.1966092.
[35348,01,13:07:46.932] CACHED TFChunk #0-0 (chunk-000000.000000) in 00:00:00.01
86801.
[35348,01,13:07:47.462] Starting MiniWeb for /web/es/js/projections ==> C:\Event
Store-OSS-Win-v3.0.0\projections
[35348,01,13:07:47.462] Starting MiniWeb for /web/es/js/projections/v8/Prelude =
=> C:\EventStore-OSS-Win-v3.0.0\Prelude
[35348,01,13:07:47.462] Starting MiniWeb for /web/es/js/projections/resources ==
> C:\EventStore-OSS-Win-v3.0.0\web-resources\js
[35348,01,13:07:47.483] Binding MiniWeb to /web/es/js/projections/{*remaining_pa
th}
[35348,01,13:07:47.483] Binding MiniWeb to /web/es/js/projections/v8/Prelude/{*r
emaining_path}
[35348,01,13:07:47.483] Binding MiniWeb to /web/es/js/projections/resources/{*re
maining_path}
[35348,01,13:07:47.528] Starting MiniWeb for /web ==> C:\EventStore-OSS-Win-v3.0
.0\clusternode-web\src
[35348,01,13:07:47.528] Binding MiniWeb to /web/{*remaining_path}
[35348,01,13:07:47.566] Starting MiniWeb for /web/users ==> C:\EventStore-OSS-Wi
n-v3.0.0\Users\web
[35348,01,13:07:47.566] Binding MiniWeb to /web/users/{*remaining_path}
[35348,16,13:07:47.641] ========== [127.0.0.1:2112] SYSTEM INIT...
[35348,16,13:07:47.771] Starting Normal TCP listening on TCP endpoint: 127.0.0.1
:1113.
[35348,19,13:07:47.831] TableIndex initialization...
[35348,19,13:07:47.866] ReadIndex building...
[35348,19,13:07:47.873] ReadIndex rebuilding done: total processed 0 records, ti
me elapsed: 00:00:00.0050003.
[35348,16,13:07:47.896] SLOW BUS MSG [MainBus]: SystemInit - 75ms. Handler: TcpS
ervice.
[35348,16,13:07:47.969] Starting HTTP server on [http://127.0.0.1:2113/]...
[35348,16,13:07:47.969] HTTP server is up and listening on [http://127.0.0.1:211
3/]
[35348,16,13:07:47.969] SLOW BUS MSG [MainBus]: SystemInit - 77ms. Handler: Http
Service.
[35348,16,13:07:48.119] SLOW QUEUE MSG [MainQueue]: SystemInit - 404ms. Q: 0/6.
[35348,16,13:07:48.120] ========== [127.0.0.1:2112] Service 'StorageWriter' init
ialized.
[35348,16,13:07:48.120] ========== [127.0.0.1:2112] Service 'StorageReader' init
ialized.
[35348,16,13:07:48.156] ========== [127.0.0.1:2112] Service 'StorageChaser' init
ialized.
[35348,16,13:07:48.156] ========== [127.0.0.1:2112] SYSTEM START...
[35348,16,13:07:48.174] ========== [127.0.0.1:2112] IS UNKNOWN!!! WHOA!!!
[35348,16,13:07:48.314] ELECTIONS: STARTING ELECTIONS.
[35348,16,13:07:48.334] ELECTIONS: (V=0) SHIFT TO LEADER ELECTION.
[35348,16,13:07:48.334] ELECTIONS: (V=0) VIEWCHANGE FROM [127.0.0.1:2112, {60f17
615-4af9-4d52-a54a-5040b31ec83b}].
[35348,16,13:07:48.334] ELECTIONS: (V=0) MAJORITY OF VIEWCHANGE.
[35348,16,13:07:48.340] ELECTIONS: (V=0) SHIFT TO PREPARE PHASE.
[35348,16,13:07:48.340] ELECTIONS: (V=0) PREPARE_OK FROM [127.0.0.1:2112,{60f176
15-4af9-4d52-a54a-5040b31ec83b}](L=-1,W=0,C=0,E-1@-1:{00000000-0000-0000-0000-00
0000000000}).
[35348,16,13:07:48.340] ELECTIONS: (V=0) SHIFT TO REG_LEADER.
[35348,16,13:07:48.402] ELECTIONS: (V=0) SENDING PROPOSAL CANDIDATE: [127.0.0.1:
2112,{60f17615-4af9-4d52-a54a-5040b31ec83b}](L=-1,W=0,C=0,E-1@-1:{00000000-0000-
0000-0000-000000000000}), ME: [127.0.0.1:2112,{60f17615-4af9-4d52-a54a-5040b31ec
83b}](L=-1,W=0,C=0,E-1@-1:{00000000-0000-0000-0000-000000000000}).
[35348,16,13:07:48.402] ELECTIONS: (V=0) ACCEPT FROM [127.0.0.1:2112,{60f17615-4
af9-4d52-a54a-5040b31ec83b}] M=[127.0.0.1:2112,{60f17615-4af9-4d52-a54a-5040b31e
c83b}]).
[35348,16,13:07:48.402] ELECTIONS: (V=0) DONE. ELECTED MASTER = [127.0.0.1:2112,
{60f17615-4af9-4d52-a54a-5040b31ec83b}](L=-1,W=0,C=0,E-1@-1:{00000000-0000-0000-
0000-000000000000}). ME=[127.0.0.1:2112,{60f17615-4af9-4d52-a54a-5040b31ec83b}](
L=-1,W=0,C=0,E-1@-1:{00000000-0000-0000-0000-000000000000}).
[35348,16,13:07:48.402] SLOW BUS MSG [MainBus]: StartElections - 196ms. Handler:
ElectionsService.
[35348,16,13:07:48.402] SLOW QUEUE MSG [MainQueue]: StartElections - 196ms. Q: 0
/4.
[35348,16,13:07:48.422] ========== [127.0.0.1:2112] PRE-MASTER STATE, WAITING FO
R CHASER TO CATCH UP...
[35348,16,13:07:48.434] ========== [127.0.0.1:2112] IS MASTER!!! SPARTA!!!
[35348,16,13:07:48.544] SLOW BUS MSG [MainBus]: ReadStreamEventsBackwardComplete
d - 107ms. Handler: RequestResponseDispatcher`2.
[35348,16,13:07:48.544] SLOW QUEUE MSG [MainQueue]: ReadStreamEventsBackwardComp
leted - 108ms. Q: 0/3.
[35348,17,13:07:48.544] SLOW BUS MSG [manager input bus]: Starting - 100ms. Hand
ler: ProjectionManagerResponseReader.
[35348,17,13:07:48.544] SLOW QUEUE MSG [Projections Master]: Starting - 100ms. Q
: 0/1.
[35348,18,13:07:48.568] SLOW BUS MSG [bus]: StartCore - 107ms. Handler: Projecti
onCoreServiceCommandReader.
[35348,18,13:07:48.568] SLOW QUEUE MSG [Projection Core #0]: StartCore - 107ms.
Q: 1/3.
[35348,14,13:07:48.978] === Writing E0@0:{16e9639f-e314-41ac-bc5e-ccd2cc303773}
(previous epoch at -1).
[35348,14,13:07:48.978] === Update Last Epoch E0@0:{16e9639f-e314-41ac-bc5e-ccd2
cc303773} (previous epoch at -1).
[35348,14,13:07:48.978] SLOW QUEUE MSG [StorageWriterQueue]: BecomeMaster - 554m
s. Q: 0/4.
[35348,18,13:07:49.166] SLOW BUS MSG [bus]: UnwrapEnvelopeMessage - 60ms. Handle
r: UnwrapEnvelopeHandler.
[35348,18,13:07:49.166] SLOW QUEUE MSG [Projection Core #0]: UnwrapEnvelopeMessa
ge - 60ms. Q: 0/4.
[35348,16,13:07:49.395] SLOW BUS MSG [MainBus]: WriteEventsCompleted - 67ms. Han
dler: RequestResponseDispatcher`2.
[35348,16,13:07:49.395] SLOW QUEUE MSG [MainQueue]: WriteEventsCompleted - 70ms.
Q: 1/6.
[35348,16,13:07:49.601] 'admin' user account has been created
[35348,16,13:07:49.602] SLOW BUS MSG [MainBus]: WriteEventsCompleted - 146ms. Ha
ndler: RequestResponseDispatcher`2.
[35348,16,13:07:49.602] SLOW QUEUE MSG [MainQueue]: WriteEventsCompleted - 146ms
. Q: 1/7.
[35348,17,13:07:49.677] Projection manager is initializing from the empty $proje
ctions-$all stream
[35348,17,13:07:49.682] SLOW BUS MSG [manager input bus]: ReadStreamEventsBackwa
rdCompleted - 79ms. Handler: ProjectionManager.
[35348,17,13:07:49.682] SLOW QUEUE MSG [Projections Master]: ReadStreamEventsBac
kwardCompleted - 79ms. Q: 0/3.
[35348,18,13:07:49.893] SLOW BUS MSG [bus]: ReadStreamEventsForwardCompleted - 8
0ms. Handler: RequestResponseDispatcher`2.
[35348,18,13:07:49.893] SLOW QUEUE MSG [Projection Core #0]: ReadStreamEventsFor
wardCompleted - 80ms. Q: 0/4.
[35348,18,13:07:50.077] SLOW BUS MSG [bus]: CreateAndPrepare - 183ms. Handler: P
rojectionCoreService.
[35348,18,13:07:50.077] SLOW QUEUE MSG [Projection Core #0]: CreateAndPrepare -
183ms. Q: 7/10.
[35348,09,13:07:50.252] SLOW QUEUE MSG [MonitoringQueue]: SystemInit - 2511ms. Q
: 0/5.
[35348,17,13:07:50.317] SLOW BUS MSG [manager input bus]: Prepared - 50ms. Handl
er: ProjectionManager.
[35348,17,13:07:50.317] SLOW QUEUE MSG [Projections Master]: Prepared - 50ms. Q:
9/11.
[35348,17,13:07:50.324] '$stream_by_category' projection source has been written
[35348,17,13:07:50.324] '$streams' projection source has been written
[35348,17,13:07:50.324] '$by_category' projection source has been written
[35348,17,13:07:50.324] '$by_event_type' projection source has been written
[35348,17,13:07:50.324] '$users' projection source has been written
[35348,06,13:07:50.352] Created stats stream '$stats-127.0.0.1:2113', code = Suc
cess
[35348,18,13:07:50.417] SLOW BUS MSG [bus]: CheckpointLoaded - 49ms. Handler: Pr
ojectionCoreService.
[35348,18,13:07:50.417] SLOW QUEUE MSG [Projection Core #0]: CheckpointLoaded -
49ms. Q: 8/13.
[35348,18,13:07:50.510] SLOW BUS MSG [bus]: Subscribe - 56ms. Handler: EventRead
erCoreService.
[35348,18,13:07:50.510] SLOW QUEUE MSG [Projection Core #0]: Subscribe - 56ms. Q
: 1/6.
[35348,18,13:07:50.808] SLOW BUS MSG [bus]: CoreTick - 156ms. Handler: Projectio
nCoreService.
[35348,18,13:07:50.808] SLOW QUEUE MSG [Projection Core #0]: CoreTick - 156ms. Q
: 7/10.
[35348,18,13:07:50.916] SLOW BUS MSG [bus]: ReadStreamEventsBackwardCompleted -
94ms. Handler: RequestResponseDispatcher`2.
[35348,18,13:07:50.916] SLOW QUEUE MSG [Projection Core #0]: ReadStreamEventsBac
kwardCompleted - 94ms. Q: 5/9.
Segments count: 1, buffers count: 512, should be when full: 512
[35348,03,13:09:55.521] External TCP connection accepted: [Normal, 127.0.0.1:210
5, L127.0.0.1:1113, {e3680962-309a-40f8-88df-099a788a0b96}].
[35348,15,13:09:58.596] Closing connection 'external-normal' [127.0.0.1:2105, L1
27.0.0.1:1113, {e3680962-309a-40f8-88df-099a788a0b96}] cleanly. Reason: HEARTBEA
T TIMEOUT at msgNum 0
[35348,15,13:09:58.637] ES TcpConnection closed [13:09:58.601: N127.0.0.1:2105,
L127.0.0.1:1113, {e3680962-309a-40f8-88df-099a788a0b96}]:
Received bytes: 0, Sent bytes: 22
Send calls: 1, callbacks: 1
Receive calls: 1, callbacks: 0
Close reason: [Success] HEARTBEAT TIMEOUT at msgNum 0
[35348,15,13:09:58.637] Connection 'external-normal' [127.0.0.1:2105, {e3680962-
309a-40f8-88df-099a788a0b96}] closed: Success.
[35348,03,13:10:03.470] External TCP connection accepted: [Normal, 127.0.0.1:211
6, L127.0.0.1:1113, {1523b429-4c6c-4bc6-be0c-610f331b4a06}].
Segments count: 2, buffers count: 512, should be when full: 1024
Segments count: 3, buffers count: 512, should be when full: 1536
Segments count: 4, buffers count: 512, should be when full: 2048
[35348,15,13:10:08.471] Closing connection 'external-normal' [127.0.0.1:2116, L1
27.0.0.1:1113, {1523b429-4c6c-4bc6-be0c-610f331b4a06}] cleanly. Reason: HEARTBEA
T TIMEOUT at msgNum 2200
[35348,15,13:10:08.471] ES TcpConnection closed [13:10:08.471: N127.0.0.1:2116,
L127.0.0.1:1113, {1523b429-4c6c-4bc6-be0c-610f331b4a06}]:
Received bytes: 3150022, Sent bytes: 387666
Send calls: 1944, callbacks: 1944
Receive calls: 4020, callbacks: 4019
Close reason: [Success] HEARTBEAT TIMEOUT at msgNum 2200
[35348,15,13:10:08.471] Connection 'external-normal' [127.0.0.1:2116, {1523b429-
4c6c-4bc6-be0c-610f331b4a06}] closed: Success.
[35348,03,13:11:03.421] External TCP connection accepted: [Normal, 127.0.0.1:214
2, L127.0.0.1:1113, {33f76523-f4d7-49fa-9fae-84c9fe833288}].
[35348,15,13:11:06.421] Closing connection 'external-normal' [127.0.0.1:2142, L1
27.0.0.1:1113, {33f76523-f4d7-49fa-9fae-84c9fe833288}] cleanly. Reason: HEARTBEA
T TIMEOUT at msgNum 0
[35348,15,13:11:06.421] ES TcpConnection closed [13:11:06.421: N127.0.0.1:2142,
L127.0.0.1:1113, {33f76523-f4d7-49fa-9fae-84c9fe833288}]:
Received bytes: 0, Sent bytes: 22
Send calls: 1, callbacks: 1
Receive calls: 1, callbacks: 0
Close reason: [Success] HEARTBEAT TIMEOUT at msgNum 0
[35348,15,13:11:06.421] Connection 'external-normal' [127.0.0.1:2142, {33f76523-
f4d7-49fa-9fae-84c9fe833288}] closed: Success.
Raw
EventStoreWriter.cs
public class EventStoreWriter : IJournalWriter
{
private readonly IEventStoreConnection _eventStore;
private readonly IFormatter _formatter;
public EventStoreWriter(IEventStoreConnection connection, IFormatter formatter = null)
{
_formatter = formatter ?? new BinaryFormatter();
_eventStore = connection;
}
public Task AppendAsync(IEnumerable<Command> commands)
{
return _eventStore.AppendToStreamAsync("origo", ExpectedVersion.Any, ToEventData(commands));
}
private EventData ToEventData(IEnumerable<Command> commands)
{
var id = Guid.NewGuid();
var stream = new MemoryStream();
_formatter.Serialize(stream, new CommandBatch(commands));
return new EventData(id, "origo-batch", false, stream.ToArray(), null);
}
public void Dispose()
{
//_eventStore.Close();
}
/// <summary>
/// create an instance with an open connection to an event store instance
/// </summary>
/// <returns></returns>
public static IJournalWriter Create()
{
var endPoint = new IPEndPoint(IPAddress.Parse("127.0.0.1"), 1113);
var connection = EventStoreConnection.Create(endPoint);
connection.ConnectAsync().Wait();
return new EventStoreWriter(connection);
}
}
Raw
Test.cs
[Test]
public void SingleEventPerEventStoreCall()
{
var journalWriter = EventStoreWriter.Create();
var sw = new Stopwatch();
Command[] commands = new Command[1];
sw.Start();
var tasks = Enumerable
.Range(0, 10000)
.Select(i => journalWriter.AppendAsync(commands)).ToArray();
Task.WaitAll(tasks);
sw.Stop();
Console.WriteLine("elapsed: " + sw.Elapsed);
}
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment