liveprocessingstarted raised very late

EventStoreDB
1

Hello,

I am trying
to decrease the number of statistical events in the $all stream. I tried to do
this by increasing the following setting: EVENTSTORE_STATS_PERIOD_SEC.
I increased it from the default value of 30 to 7200.

After changing this setting my
Catchupsubscription liveprocessingstarted event is taking a long time to be
raised. When I change the EVENTSTORE_STATS_PERIOD_SEC setting back to the
default

value the event is raised pretty fast.

Are these settings related?

Kind regards,

Walter Wisselo

2

My guess from your description is you are running very low numbers of events and not having one during this period. Is this correct?

I believe the live processing event might be getting triggered on the first event that shows up after catch-up… Can you verify?

Cheers,

Greg

3

Thanks for the quick response.

My readside has logged handling all initial events (50 or so). Even minutes after the last event has been processed by the readside, onprocessingstarted is still not being raised, unfortunately. I am not possible to manually raise an event after thos e initial ones. When changing the setting back to 30 there is no problem at all.

Met vriendelijke groet,

Walter Wisselo

4

Hello,
To clarify my case I did 3 runs with some logging on the last processed initial event (FunctionCreated) and the time it takes for the LiveProcessingStarted event to be raised. Only thing changed between runs is the setting.

Setting at default value:

EVENTSTORE_STATS_PERIOD_SEC=30

Last processed event logged:

[19:29:18 Rigger.Generic.QueryServer.Projecting.ProjectionManager [Debug]: QSASS_Configurator.FunctionAggregateProjection handled the following event(s) in 584 msecs:

Function.FunctionCreated.1

AggregateId: function-4fc8b348-e6df-4dc3-8f84-7b12b309009a, AggregateEventSequenceNumber: 1, Created: 2019-07-04 19:29:12:73, EventId: event-92990bba-4421-5f70-9666-285d86203b01

LiveProcessingStarted logged:

[19:29:28 Rigger.Generic.QueryServer.Projecting.EventSourceSubscription [Information]: QSASS_Configurator EventSourceSubscription: now processing live events. Last processed event PreparePosition = 116803.

[19:29:28 Rigger.Queries.AdminSelfService.ProjectionManager.Host.WriteSideHostedService [Information]: Replaying for QSASS_Configurator took: 0:16:198

Setting changed to 120:

EVENTSTORE_STATS_PERIOD_SEC=120

Last processed event logged:

[19:14:06 Rigger.Generic.QueryServer.Projecting.ProjectionManager [Debug]: QSASS_Configurator.FunctionAggregateProjection handled the following event(s) in 320 msecs:
Function.FunctionCreated.1
AggregateId: function-4fc8b348-e6df-4dc3-8f84-7b12b309009a, AggregateEventSequenceNumber: 1, Created: 2019-07-04 19:13:54:992, EventId: event-92990bba-4421-5f70-9666-285d86203b01
[19:15:02 Rigger.Generic.QueryServer.Projecting.EventSourceSubscription [Information]: QSASS_Configurator EventSourceSubscription: now processing live events. Last processed event PreparePosition = 100602.

LiveProcessingStarted logged:

[19:15:02 Rigger.Queries.AdminSelfService.ProjectionManager.Host.WriteSideHostedService [Information]: Replaying for QSASS_Configurator took: 1:3:739

Setting changed to 240:

EVENTSTORE_STATS_PERIOD_SEC=240

Last processed event logged:

[19:19:46 Rigger.Generic.QueryServer.Projecting.ProjectionManager [Debug]: QSASS_Configurator.FunctionAggregateProjection handled the following event(s) in 326 msecs:

Function.FunctionCreated.1

AggregateId: function-4fc8b348-e6df-4dc3-8f84-7b12b309009a, AggregateEventSequenceNumber: 1, Created: 2019-07-04 19:19:45:447, EventId: event-92990bba-4421-5f70-9666-285d86203b01

The thread 58 has exited with code 0 (0x0).

The thread ‘’ (0x3a) has exited with code 0 (0x0).

The thread 60 has exited with code 0 (0x0).

The thread ‘’ (0x3c) has exited with code 0 (0x0).

The thread 48 has exited with code 0 (0x0).

The thread ‘’ (0x30) has exited with code 0 (0x0).

[19:22:57 Rigger.Generic.QueryServer.Projecting.EventSourceSubscription [Information]: QSASS_Configurator EventSourceSubscription: now processing live events. Last processed event PreparePosition = 100564.

LiveProcessingStarted logged:

[19:22:57 Rigger.Queries.AdminSelfService.ProjectionManager.Host.WriteSideHostedService [Information]: Replaying for QSASS_Configurator took: 3:17:211

5

With verbose logging on, I now see that the liveProcessingStarted event is only raised when the next ‘live’ stats event is added to the @all stream. With my setting at 240 this almost takes 240 additional seconds. This event therefore seems not suitable for me to use as the moment to conclude that my readside has ‘replayed’ all the events in the $all stream.

What is the best way for me to conclude that all ‘historical’ events in the $all stream were processed by the catchupsubscription?

6

Hello,

What is the best way for me to conclude that all 'historical' events in the $all stream were processed by the catchupsubscription, without having to wait for a live event being processed?

Kind regards,
Walter

7

There is a callback for LiveProcessingStarted

https://github.com/EventStore/EventStore/blob/master/src/EventStore.ClientAPI/EventStoreCatchUpSubscription.cs#L120

8

Hello,
Thanks for the response. That event is only raised once a live event get’s processed. I want to know when the last historical events has been processed and not wait for another live (stats) event. I’d like to keep my stats event low and therefore only want one every 2 hours. After the last historical event has been processed, therefore there are no live events, the next two hours.

9

You can always just read the last event…