search

dotnet / orleans

Cloud Native application framework for .NET
https://docs.microsoft.com/dotnet/orleans
MIT License
10.04k stars 2.02k forks source link

MemoryStream subscriber not receive message when publish interval > 30min #8542

Open vrecluse opened 1 year ago

vrecluse commented 1 year ago

I encountered this problem in my project. Wrote a simple project that reproduced it:

var builder = WebApplication.CreateBuilder();
builder.Host.UseOrleans(siloBuilder =>
{
    siloBuilder.UseLocalhostClustering();
    siloBuilder.AddMemoryGrainStorage(ProviderConstants.DEFAULT_STORAGE_PROVIDER_NAME);
    siloBuilder.AddMemoryStreams("Notify");
    siloBuilder.AddMemoryGrainStorage("PubSubStore");
});

builder.Services.AddHostedService<BackgroundSubStreamService>(); // subscribe to stream and print message
builder.Services.AddHostedService<BackgroundPubStreamService>(); // publish to stream every 31 min

var app = builder.Build();
await app.RunAsync();

internal class BackgroundPubStreamService : BackgroundService
{
    private readonly IClusterClient _client;
    private readonly ILogger<BackgroundPubStreamService> _logger;

    public BackgroundPubStreamService(ILogger<BackgroundPubStreamService> logger, IClusterClient client)
    {
        _logger = logger;
        _client = client;
    }

    protected override async Task ExecuteAsync(CancellationToken stoppingToken)
    {
        var delay = 31 * 60 * 1000;
        while (true)
        {
            var streamProvider = _client.GetStreamProvider("Notify");
            var id = Guid.Empty;
            var stream = streamProvider.GetStream<string>(StreamId.Create("Notify", id));

            var message = $"Publish: {DateTime.Now}";
            _logger.LogInformation(">>>>>>>>>>> Send: {Message}", message);
            await stream.OnNextAsync(message);
            await Task.Delay(delay);
        }
    }
}

internal class BackgroundSubStreamService : BackgroundService
{
    private readonly IClusterClient _client;
    private readonly ILogger<BackgroundSubStreamService> _logger;

    public BackgroundSubStreamService(ILogger<BackgroundSubStreamService> logger, IClusterClient client)
    {
        _logger = logger;
        _client = client;
    }

    protected override async Task ExecuteAsync(CancellationToken stoppingToken)
    {
        var streamProvider = _client.GetStreamProvider("Notify");
        var id = Guid.Empty;
        var stream = streamProvider.GetStream<string>(StreamId.Create("Notify", id));
        var handle = await stream.SubscribeAsync(
            async (message, token) => _logger.LogInformation("<<<<<<<<<< Stream {Id} receive: {Message}", id, message),
            async exception => _logger.LogError(exception, "Stream {Id} error", id),
            () =>
            {
                _logger.LogInformation("Stream {Id} completed", id);
                return Task.CompletedTask;
            }
        );

        while (true) await Task.Delay(1000);

        await handle.UnsubscribeAsync();
    }
}

When silo starts, stream message received successfully:

info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 14:47:12
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/12 14:47:12

After 31min, publish message again:

info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 15:18:12

No log

<<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive:  ....

anymore.

vrecluse commented 1 year ago

Whole log:

info: Orleans.Runtime.InsideRuntimeClient[100452]
      Start InsideRuntimeClient took 0 milliseconds
info: Orleans.Runtime.Silo[100401]
      Silo Start()
info: Orleans.Runtime.GrainDirectory.LocalGrainDirectory[0]
      Start
info: Orleans.Runtime.Silo[100452]
      Start local grain directory took 0 milliseconds to finish
info: Orleans.Runtime.MembershipService.MembershipTableManager[100603]
      MembershipOracle starting on host jszj-liao with SiloAddress S127.0.0.1:11111:48149232 at 2023-07-12 06:47:12.456 GMT
info: Orleans.Runtime.MembershipService.SystemTargetBasedMembershipTable[100635]
      Creating in-memory membership table
info: Orleans.Runtime.Silo[100452]
      Init grain services took 0 milliseconds to finish
info: Orleans.Runtime.MembershipService.MembershipTableSystemTarget[100637]
      GrainBasedMembershipTable Activated.
info: Orleans.Runtime.Silo[100452]
      Start deployment load collector took 7 milliseconds to finish
info: Orleans.Runtime.Watchdog[0]
      Starting Silo Watchdog.
info: Orleans.Runtime.MembershipService.SystemTargetBasedMembershipTable[100631]
      Connected to membership table provider.
info: Orleans.Runtime.MembershipService.MembershipAgent[100663]
      Joining
info: Orleans.Storage.MemoryGrainStorage[0]
      Init: Name=Default NumStorageGrains=10
info: Orleans.Runtime.MembershipService.MembershipAgent[100604]
      -BecomeActive
info: Orleans.Runtime.MembershipService.MembershipAgent[100605]
      -Finished BecomeActive.
info: Orleans.Runtime.Providers.SiloProviderRuntime[0]
      Successfully created queue balancer of type Orleans.Streams.ConsistentRingQueueBalancer for stream provider Notify
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103501]
      Created PersistentStreamPullingManager for Stream Provider Notify.
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103502]
      Init.
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103503]
      Initialize: I am now responsible for 8 queues: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103517]
      Starting agents for 8 queues: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7]
info: Orleans.Streams.Notify[103301]
      Created PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_1_notify-0-0x00000000 for Stream Provider Notify on silo S127.0.0.1:11111:48149232 for Queue notify-0-0x00000000.
info: Orleans.Streams.Notify[103301]
      Created PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_2_notify-1-0x20000001 for Stream Provider Notify on silo S127.0.0.1:11111:48149232 for Queue notify-1-0x20000001.
info: Orleans.Streams.Notify[103301]
      Created PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_3_notify-2-0x40000002 for Stream Provider Notify on silo S127.0.0.1:11111:48149232 for Queue notify-2-0x40000002.
info: Orleans.Streams.Notify[103301]
      Created PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_4_notify-3-0x60000003 for Stream Provider Notify on silo S127.0.0.1:11111:48149232 for Queue notify-3-0x60000003.
info: Orleans.Streams.Notify[103301]
      Created PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_5_notify-4-0x80000004 for Stream Provider Notify on silo S127.0.0.1:11111:48149232 for Queue notify-4-0x80000004.
info: Orleans.Streams.Notify[103301]
      Created PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_6_notify-5-0xA0000005 for Stream Provider Notify on silo S127.0.0.1:11111:48149232 for Queue notify-5-0xA0000005.
info: Orleans.Streams.Notify[103301]
      Created PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_7_notify-6-0xC0000006 for Stream Provider Notify on silo S127.0.0.1:11111:48149232 for Queue notify-6-0xC0000006.
info: Orleans.Streams.Notify[103301]
      Created PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_8_notify-7-0xE0000007 for Stream Provider Notify on silo S127.0.0.1:11111:48149232 for Queue notify-7-0xE0000007.
info: Orleans.Streams.Notify[103302]
      Init of PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_1_notify-0-0x00000000 on silo S127.0.0.1:11111:48149232 for queue notify-0-0x00000000.
info: Orleans.Streams.Notify[103302]
      Init of PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_3_notify-2-0x40000002 on silo S127.0.0.1:11111:48149232 for queue notify-2-0x40000002.
info: Orleans.Streams.Notify[103302]
      Init of PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_2_notify-1-0x20000001 on silo S127.0.0.1:11111:48149232 for queue notify-1-0x20000001.
info: Orleans.Streams.Notify[103302]
      Init of PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_4_notify-3-0x60000003 on silo S127.0.0.1:11111:48149232 for queue notify-3-0x60000003.
info: Orleans.Streams.Notify[103302]
      Init of PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_6_notify-5-0xA0000005 on silo S127.0.0.1:11111:48149232 for queue notify-5-0xA0000005.
info: Orleans.Streams.Notify[103302]
      Init of PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_5_notify-4-0x80000004 on silo S127.0.0.1:11111:48149232 for queue notify-4-0x80000004.
info: Orleans.Streams.Notify[103302]
      Init of PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_7_notify-6-0xC0000006 on silo S127.0.0.1:11111:48149232 for queue notify-6-0xC0000006.
info: Orleans.Streams.Notify[103302]
      Init of PersistentStreamPullingAgent sys.svc.stream.agent/127.0.0.1:11111@48149232+Notify_8_notify-7-0xE0000007 on silo S127.0.0.1:11111:48149232 for queue notify-7-0xE0000007.
info: Orleans.Streams.Notify[103304]
      Taking queue notify-6-0xC0000006 under my responsibility.
info: Orleans.Streams.Notify[103304]
      Taking queue notify-5-0xA0000005 under my responsibility.
info: Orleans.Streams.Notify[103304]
      Taking queue notify-0-0x00000000 under my responsibility.
info: Orleans.Streams.Notify[103304]
      Taking queue notify-3-0x60000003 under my responsibility.
info: Orleans.Streams.Notify[103304]
      Taking queue notify-1-0x20000001 under my responsibility.
info: Orleans.Streams.Notify[103304]
      Taking queue notify-2-0x40000002 under my responsibility.
info: Orleans.Streams.Notify[103304]
      Taking queue notify-4-0x80000004 under my responsibility.
info: Orleans.Streams.Notify[103304]
      Taking queue notify-7-0xE0000007 under my responsibility.
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103508]
      Added 8 new queues: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7]. Now own total of 8 queues: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7]
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103519]
      Started agents.
info: Orleans.Hosting.SiloHostedService[0]
      Orleans Silo started.
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 14:47:12
info: Orleans.Storage.MemoryGrainStorage[0]
      Init: Name=PubSubStore NumStorageGrains=10
info: Microsoft.Hosting.Lifetime[14]
      Now listening on: http://localhost:5000
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Production
info: Microsoft.Hosting.Lifetime[0]
      Content root path: D:\dev\TestOrleansStream\TestOrleansStream\bin\Debug\net7.0
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/12 14:47:12
warn: Orleans.Runtime.MembershipService.MembershipTableCleanupAgent[100662]
      CleanupDefunctSiloEntries operation is not supported by the current implementation of IMembershipTable. Disabling the timer now.
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Runtime.ActivationCollector[100509]
      DeactivateActivationsFromCollector: total 1 to promptly Destroy.
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 15:18:12
vrecluse commented 1 year ago

If change interval smaller than 30min, eg. 1sec, the log seems normal:

info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 15:24:34
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/12 15:24:34
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 15:24:35
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/12 15:24:35
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 15:24:36
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/12 15:24:36
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 15:24:37
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/12 15:24:37

interval = 29min is normal, too:

info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 15:26:50
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/12 15:26:50
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
warn: Orleans.Runtime.MembershipService.MembershipTableCleanupAgent[100662]
      CleanupDefunctSiloEntries operation is not supported by the current implementation of IMembershipTable. Disabling the timer now.
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Runtime.ActivationCollector[100509]
      DeactivateActivationsFromCollector: total 1 to promptly Destroy.
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 15:55:50
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/12 15:55:50
vrecluse commented 1 year ago

@ReubenBond @benjaminpetit @sergeybykov
Please help... Orleans version: 7.1.2

benjaminpetit commented 1 year ago

Can you try to set GrainCollectionOptions.CollectionAge to something like 2 hours and retry?

vrecluse commented 1 year ago

When interval = 31min, the pattern looks like not received, received, received, not received, received, received, not received ...

info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 18:06:14
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Runtime.ActivationCollector[100509]
      DeactivateActivationsFromCollector: total 1 to promptly Destroy.
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 18:37:14
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/12 18:37:14
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 19:08:14
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/12 19:08:14
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 19:39:14
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Runtime.ActivationCollector[100509]
      DeactivateActivationsFromCollector: total 1 to promptly Destroy.
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 20:10:14
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/12 20:10:14
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 20:41:14
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/12 20:41:14
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 21:12:14
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
vrecluse commented 1 year ago

Can you try to set GrainCollectionOptions.CollectionAge to something like 2 hours and retry?

Ok, I'll try. Like this?

builder.Host.UseOrleans(siloBuilder =>
{
    siloBuilder.UseLocalhostClustering();
    siloBuilder.AddMemoryGrainStorage(ProviderConstants.DEFAULT_STORAGE_PROVIDER_NAME);
    siloBuilder.AddMemoryStreams("Notify");
    siloBuilder.AddMemoryGrainStorage("PubSubStore");
    siloBuilder.Configure<GrainCollectionOptions>(options =>
    {
        options.CollectionAge = TimeSpan.FromHours(2);
    });
});
benjaminpetit commented 1 year ago

Yes

vrecluse commented 1 year ago

Yes

The problem remains:

warn: Orleans.Runtime.MembershipService.MembershipTableCleanupAgent[100662]
      CleanupDefunctSiloEntries operation is not supported by the current implementation of IMembershipTable. Disabling the timer now.
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 21:47:45
benjaminpetit commented 1 year ago

Can you run again with logging set to Debug for everything inside Orleans.Streams namespace?

vrecluse commented 1 year ago

Can you run again with logging set to Debug for everything inside Orleans.Streams namespace?

info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 23:11:47
dbug: Orleans.Streams.PersistentStreamProducer[0]
      Created PersistentStreamProducer for stream Notify/Notify/00000000000000000000000000000000, of type System.String, and with Adapter: Notify.
dbug: Orleans.Streams.PubSubGrainStateStorageFactory[0]
      Trying to find storage provider Notify
dbug: Orleans.Streams.PubSubGrainStateStorageFactory[0]
      Fallback to storage provider PubSubStore
info: Orleans.Storage.MemoryGrainStorage[0]
      Init: Name=PubSubStore NumStorageGrains=10
info: Microsoft.Hosting.Lifetime[14]
      Now listening on: http://localhost:5233
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.Hosting.Lifetime[0]
      Content root path: C:\Dev\TestStream\TestStream
dbug: Orleans.Streams.PubSubRendezvousGrain[0]
      OnActivateAsync. Now have total of 0 producers and 0 consumers. All Consumers = [], All Producers = []
dbug: Orleans.Streams.PubSubRendezvousGrain[0]
      RegisterConsumer sys.client/hosted-127.0.0.1:11111@48179506+a5a857c95f414820bfd8bb66ba2f6ded. Now have total of 0 producers and 1 consumers. All Consumers = [PubSubSubscriptionState:SubscriptionId=ff9dabde-c84b-465e-8ad1-7db18e837d21,StreamId=Notify/Notify/00000000000000000000000000000000,Consumer=sy
s.client/hosted-127.0.0.1:11111@48179506+a5a857c95f414820bfd8bb66ba2f6ded.], All Producers = []
dbug: Orleans.Streams.PubSubRendezvousGrain[0]
      RegisterProducer sys.svc.stream.agent/127.0.0.1:11111@48179506+Notify_5_notify-4-0x80000004. Now have total of 1 producers and 1 consumers. All Consumers = [PubSubSubscriptionState:SubscriptionId=ff9dabde-c84b-465e-8ad1-7db18e837d21,StreamId=Notify/Notify/00000000000000000000000000000000,Consumer=sys
      RegisterProducer sys.svc.stream.agent/127.0.0.1:11111@48179506+Notify_5_notify-4-0x80000004. Now have total of 1 producers and 1 consumers. All Consumers = [PubSubSubscriptionState:SubscriptionId
=ff9dabde-c84b-465e-8ad1-7db18e837d21,StreamId=Notify/Notify/00000000000000000000000000000000,Consumer=sys.client/hosted-127.0.0.1:11111@48179506+a5a857c95f414820bfd8bb66ba2f6ded.], All Producers = [Pu
bSubPublisherState:StreamId=Notify/Notify/00000000000000000000000000000000,Producer=sys.svc.stream.agent/127.0.0.1:11111@48179506+Notify_5_notify-4-0x80000004.]
dbug: Orleans.Streams.Notify[103316]
      Got back 1 subscribers for stream Notify/Notify/00000000000000000000000000000000.
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/12 23:11:47
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://localhost:5233/swagger - -
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished HTTP/1.1 GET http://localhost:5233/swagger - - - 404 0 - 3.2172ms
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
warn: Orleans.Runtime.MembershipService.MembershipTableCleanupAgent[100662]
      CleanupDefunctSiloEntries operation is not supported by the current implementation of IMembershipTable. Disabling the timer now.
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: Orleans.Streams.PersistentStreamPullingManager.Notify[103523]
      I am responsible for a total of 8 queues on stream provider Notify: [notify-0, notify-1, notify-2, notify-3, notify-4, notify-5, notify-6, notify-7].
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/12 23:42:47
dbug: Orleans.Streams.PubSubRendezvousGrain[0]
      RegisterProducer sys.svc.stream.agent/127.0.0.1:11111@48179506+Notify_5_notify-4-0x80000004. Now have total of 1 producers and 1 consumers. All Consumers = [PubSubSubscriptionState:SubscriptionId=ff9dabde-c84b-465e-8ad1-7db18e837d21,Strea
mId=Notify/Notify/00000000000000000000000000000000,Consumer=sys.client/hosted-127.0.0.1:11111@48179506+a5a857c95f414820bfd8bb66ba2f6ded.], All Producers = [PubSubPublisherState:StreamId=Notify/Notify/00000000000000000000000000000000,Producer=sy
s.svc.stream.agent/127.0.0.1:11111@48179506+Notify_5_notify-4-0x80000004.]
dbug: Orleans.Streams.Notify[103316]
      Got back 1 subscribers for stream Notify/Notify/00000000000000000000000000000000.
vrecluse commented 1 year ago

The sample project: TestOrleansStream.zip

vrecluse commented 1 year ago

@benjaminpetit Any ideas?

kengiczhangchao commented 1 year ago

I has same problem ,I think is a bug .

you can update code like:

                .AddMemoryStreams<DefaultMemoryMessageBodySerializer>("StreamProvider", b =>
                {

                    b.ConfigurePullingAgent(ob => ob.Configure(options =>
                    {
                        options.StreamInactivityPeriod = TimeSpan.FromDays(3650);
                        options.GetQueueMsgsTimerPeriod = TimeSpan.FromMilliseconds(10);
                    }));

                })
kengiczhangchao commented 1 year ago

sream default 30 min InactivityPeriod

vrecluse commented 1 year ago

I has same problem ,I think is a bug .

you can update code like:

                .AddMemoryStreams<DefaultMemoryMessageBodySerializer>("StreamProvider", b =>
                {

                    b.ConfigurePullingAgent(ob => ob.Configure(options =>
                    {
                        options.StreamInactivityPeriod = TimeSpan.FromDays(3650);
                        options.GetQueueMsgsTimerPeriod = TimeSpan.FromMilliseconds(10);
                    }));

                })

But this may cause memory leak, if their are lots of dynamic short lived streams.

vrecluse commented 1 year ago

I has same problem ,I think is a bug .

you can update code like:

                .AddMemoryStreams<DefaultMemoryMessageBodySerializer>("StreamProvider", b =>
                {

                    b.ConfigurePullingAgent(ob => ob.Configure(options =>
                    {
                        options.StreamInactivityPeriod = TimeSpan.FromDays(3650);
                        options.GetQueueMsgsTimerPeriod = TimeSpan.FromMilliseconds(10);
                    }));

                })

It's definitely a bug...

vrecluse commented 1 year ago

It's quite easy to reproduce if configure with:

    siloBuilder.AddMemoryStreams("Notify", (b) =>
    {
        b.ConfigureCacheEviction(ob =>
        {
            ob.Configure(options =>
            {
                options.DataMaxAgeInCache = TimeSpan.FromSeconds(5);
                options.DataMinTimeInCache = TimeSpan.FromSeconds(5);
                options.MetadataMinTimeInCache = TimeSpan.FromSeconds(10);
            });
        });
        b.ConfigurePullingAgent(ob =>
        {
            ob.Configure(options => options.StreamInactivityPeriod = TimeSpan.FromSeconds(5));
        });
    });

and set interval = 6s.

logs:

info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/14 10:55:02
dbug: Orleans.Streams.PubSubRendezvousGrain[0]
      RegisterProducer sys.svc.stream.agent/127.0.0.1:11111@48308096+Notify_5_notify-4-0x80000004. Now have total of 1 producers and 1 consumers. All Consumers = [PubSubSubscriptionState:SubscriptionId=b6d6ce2a-85cd-4c4d-b934-6585eb8d1807,StreamId=Notify/Notify/00000000000000000000000000000000,Consumer=sys.clie
nt/hosted-127.0.0.1:11111@48308096+c050eccc413942e7ba8e31741c5550b0.], All Producers = [PubSubPublisherState:StreamId=Notify/Notify/00000000000000000000000000000000,Producer=sys.svc.stream.agent/127.0.0.1:11111@48308096+Notify_5_notify-4-0x80000004.]
dbug: Orleans.Streams.Notify[103316]
      Got back 1 subscribers for stream Notify/Notify/00000000000000000000000000000000.
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/14 10:55:08
dbug: Orleans.Streams.PubSubRendezvousGrain[0]
      RegisterProducer sys.svc.stream.agent/127.0.0.1:11111@48308096+Notify_5_notify-4-0x80000004. Now have total of 1 producers and 1 consumers. All Consumers = [PubSubSubscriptionState:SubscriptionId=b6d6ce2a-85cd-4c4d-b934-6585eb8d1807,StreamId=Notify/Notify/00000000000000000000000000000000,Consumer=sys.clie
nt/hosted-127.0.0.1:11111@48308096+c050eccc413942e7ba8e31741c5550b0.], All Producers = [PubSubPublisherState:StreamId=Notify/Notify/00000000000000000000000000000000,Producer=sys.svc.stream.agent/127.0.0.1:11111@48308096+Notify_5_notify-4-0x80000004.]
dbug: Orleans.Streams.Notify[103316]
      Got back 1 subscribers for stream Notify/Notify/00000000000000000000000000000000.
fail: BackgroundSubStreamService[0]
      Stream 00000000-0000-0000-0000-000000000000 error
      Orleans.Streams.QueueCacheMissException: Item not found in cache.  Requested: [EventSequenceToken: SeqNum=638249000964462711, EventIndex=0], Low: [EventSequenceToken: SeqNum=638249000964462713, EventIndex=0], High: [EventSequenceToken: SeqNum=638249000964462713, EventIndex=0]
         at Orleans.Providers.Streams.Common.PooledQueueCache.SetCursor(Cursor cursor, StreamSequenceToken sequenceToken) in /_/src/Orleans.Streaming/Common/PooledCache/PooledQueueCache.cs:line 215
         at Orleans.Providers.Streams.Common.PooledQueueCache.GetCursor(StreamId streamId, StreamSequenceToken sequenceToken) in /_/src/Orleans.Streaming/Common/PooledCache/PooledQueueCache.cs:line 118
         at Orleans.Providers.MemoryPooledCache`1.Cursor..ctor(PooledQueueCache cache, StreamId streamId, StreamSequenceToken token) in /_/src/Orleans.Streaming/MemoryStreams/MemoryPooledCache.cs:line 107
         at Orleans.Providers.MemoryPooledCache`1.GetCacheCursor(StreamId streamId, StreamSequenceToken token) in /_/src/Orleans.Streaming/MemoryStreams/MemoryPooledCache.cs:line 170
         at Orleans.Streams.PersistentStreamPullingAgent.DoHandshakeWithConsumer(StreamConsumerData consumerData, StreamSequenceToken cacheToken) in /_/src/Orleans.Streaming/PersistentStreams/PersistentStreamPullingAgent.cs:line 305
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/14 10:55:08
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/14 10:55:14
dbug: Orleans.Streams.PubSubRendezvousGrain[0]
      RegisterProducer sys.svc.stream.agent/127.0.0.1:11111@48308096+Notify_5_notify-4-0x80000004. Now have total of 1 producers and 1 consumers. All Consumers = [PubSubSubscriptionState:SubscriptionId=b6d6ce2a-85cd-4c4d-b934-6585eb8d1807,StreamId=Notify/Notify/00000000000000000000000000000000,Consumer=sys.clie
nt/hosted-127.0.0.1:11111@48308096+c050eccc413942e7ba8e31741c5550b0.], All Producers = [PubSubPublisherState:StreamId=Notify/Notify/00000000000000000000000000000000,Producer=sys.svc.stream.agent/127.0.0.1:11111@48308096+Notify_5_notify-4-0x80000004.]
dbug: Orleans.Streams.Notify[103316]
      Got back 1 subscribers for stream Notify/Notify/00000000000000000000000000000000.
info: BackgroundPubStreamService[0]
      >>>>>>>>>>> Send: Publish: 2023/7/14 10:55:20
dbug: Orleans.Streams.PubSubRendezvousGrain[0]
      RegisterProducer sys.svc.stream.agent/127.0.0.1:11111@48308096+Notify_5_notify-4-0x80000004. Now have total of 1 producers and 1 consumers. All Consumers = [PubSubSubscriptionState:SubscriptionId=b6d6ce2a-85cd-4c4d-b934-6585eb8d1807,StreamId=Notify/Notify/00000000000000000000000000000000,Consumer=sys.clie
nt/hosted-127.0.0.1:11111@48308096+c050eccc413942e7ba8e31741c5550b0.], All Producers = [PubSubPublisherState:StreamId=Notify/Notify/00000000000000000000000000000000,Producer=sys.svc.stream.agent/127.0.0.1:11111@48308096+Notify_5_notify-4-0x80000004.]
dbug: Orleans.Streams.Notify[103316]
      Got back 1 subscribers for stream Notify/Notify/00000000000000000000000000000000.
fail: BackgroundSubStreamService[0]
      Stream 00000000-0000-0000-0000-000000000000 error
      Orleans.Streams.QueueCacheMissException: Item not found in cache.  Requested: [EventSequenceToken: SeqNum=638249000964462713, EventIndex=0], Low: [EventSequenceToken: SeqNum=638249000964462715, EventIndex=0], High: [EventSequenceToken: SeqNum=638249000964462715, EventIndex=0]
         at Orleans.Providers.Streams.Common.PooledQueueCache.SetCursor(Cursor cursor, StreamSequenceToken sequenceToken) in /_/src/Orleans.Streaming/Common/PooledCache/PooledQueueCache.cs:line 215
         at Orleans.Providers.Streams.Common.PooledQueueCache.GetCursor(StreamId streamId, StreamSequenceToken sequenceToken) in /_/src/Orleans.Streaming/Common/PooledCache/PooledQueueCache.cs:line 118
         at Orleans.Providers.MemoryPooledCache`1.Cursor..ctor(PooledQueueCache cache, StreamId streamId, StreamSequenceToken token) in /_/src/Orleans.Streaming/MemoryStreams/MemoryPooledCache.cs:line 107
         at Orleans.Providers.MemoryPooledCache`1.GetCacheCursor(StreamId streamId, StreamSequenceToken token) in /_/src/Orleans.Streaming/MemoryStreams/MemoryPooledCache.cs:line 170
         at Orleans.Streams.PersistentStreamPullingAgent.DoHandshakeWithConsumer(StreamConsumerData consumerData, StreamSequenceToken cacheToken) in /_/src/Orleans.Streaming/PersistentStreams/PersistentStreamPullingAgent.cs:line 305
info: BackgroundSubStreamService[0]
      <<<<<<<<<< Stream 00000000-0000-0000-0000-000000000000 receive: Publish: 2023/7/14 10:55:20
vrecluse commented 1 year ago

Still no updates after two months? @ReubenBond @benjaminpetit @sergeybykov

benjaminpetit commented 1 year ago

With the last config you provided, it's expected to have cache miss exceptions: the cache was designed for high trouput scenarios, where event N and N+1 are in the cache.

Here you configured the pulling agent to "forget" about a stream after 5 seconds, but you fire an event every 6 seconds. So when the subscriber asks to start from event N (the latest one received by the subscriber), Orleans cannot find it in cache and send an error.

StreamInactivityPeriod should be set a value superior to the value from grain idleness for deactivation, and when the grain is reactivated you should resume the subscription if the token is older than the max cache duration.

oising commented 1 year ago

With the last config you provided, it's expected to have cache miss exceptions: the cache was designed for high trouput scenarios, where event N and N+1 are in the cache.

Here you configured the pulling agent to "forget" about a stream after 5 seconds, but you fire an event every 6 seconds. So when the subscriber asks to start from event N (the latest one received by the subscriber), Orleans cannot find it in cache and send an error.

StreamInactivityPeriod should be set a value superior to the value from grain idleness for deactivation, and when the grain is reactivated you should resume the subscription if the token is older than the max cache duration.

Some of these things seem like footguns that needn't be. Wouldn't it make sense to warn about conflicting settings?

vrecluse commented 1 year ago

With the last config you provided, it's expected to have cache miss exceptions: the cache was designed for high trouput scenarios, where event N and N+1 are in the cache.

Here you configured the pulling agent to "forget" about a stream after 5 seconds, but you fire an event every 6 seconds. So when the subscriber asks to start from event N (the latest one received by the subscriber), Orleans cannot find it in cache and send an error.

StreamInactivityPeriod should be set a value superior to the value from grain idleness for deactivation, and when the grain is reactivated you should resume the subscription if the token is older than the max cache duration.

I'm not using grain as subscriber, ClusterClient instead. ClusterClient shouldn't be idle, right? Or is there any config to keep ClusterClient subscriber active?

orionstudt commented 6 months ago

@ReubenBond @benjaminpetit can we get some acknowledgement that this is a bug? Why would the stream stop receiving messages after some duration?

Lillskogen commented 4 months ago

We are also seeing issues with QueueCacheMissException's and have confirmed that it happens when the interval between events is greater than the StreamInactivityPeriod. We have also confirmed that we already have handled the message for the sequence number of the failing message (QueueCacheMissException).

So somehow Orleans does not manage to update the cursor of the stream to the latest event and tries to handle the same message again when the next message appear (often hours later).

Can you give a recommendation on how to configure the streaming (EventHub based) to support events with long durations between events without loosing scalability benifits (setting StreamInactivityPeriod to a huge value) and without fill our logs.

oising commented 4 months ago

We are also seeing issues with QueueCacheMissException's and have confirmed that it happens when the interval between events is greater than the StreamInactivityPeriod. We have also confirmed that we already have handled the message for the sequence number of the failing message (QueueCacheMissException).

So somehow Orleans does not manage to update the cursor of the stream to the latest event and tries to handle the same message again when the next message appear (often hours later).

Can you give a recommendation on how to configure the streaming (EventHub based) to support events with long durations between events without loosing scalability benifits (setting StreamInactivityPeriod to a huge value) and without fill our logs.

Orleans streaming needs to be able to "see" the last message received in order to figure out whether or not it's missed messages since receiving the current one. Previously, this meant that both the current and the last message needed to be still alive in the cache window; this mean that if you had infrequent messages, the cache would have a long duration window which may put a lot of memory pressure on the silo. However, newer versions of Orleans now keep a separate "metadata cache" which holds the "latest seen message" for an individual subscription. The expiry for this metadata cache is controlled by https://github.com/dotnet/orleans/blob/488b2db1f2fee2f4575348706f39c9c3f9ef5d7e/src/Orleans.Streaming/Common/RecoverableStreamOptions.cs#L36 -- ensure it is long enough to cover the maximum duration between two subsequent messages.