dotnet/orleans

Regular logging for IAsyncEnumerable

Opened this issue · 4 comments

Tragetaschen commented

While looking at my logs, I noticed that Orleans will frequently give status updates for long-running IAsyncEnumerables.
It's basically this

orleans/src/Orleans.Core/Runtime/OutsideRuntimeClient.cs

Line 302 in 92c6785

this.logger.LogInformation("Received status update for pending request, Request: {RequestMessage}. Status: {Diagnostics}", request, diagnosticsString);

and the corresponding code in InsideRuntimeClient, that now frequently logs

…Orleans.Runtime.IAsyncEnumerableGrainExtension[(Orleans.Runtime.IAsyncEnumerableGrainExtension)Orleans.Runtime.AsyncEnumerableGrainExtension].MoveNext<T>(e4d07967-3ba5-4d78-b6fd-2e1ec2ee21c0)
    #12077 has been executing for 00:00:10.0480000."

Should this really be an Information-level message in that case?

chutchinson-dynics commented

We're also experiencing this issue. We can filter the messages, but it is unclear if these messages are intended. As a developer, it's not unusual for an IAsyncEnumerable interface to produce items indefinitely. It's surprising / noisy to me for Orleans to issue status updates for such a method.

Unfortunately finding documentation on using IAsyncEnumerable in a grain is difficult / incomplete.

willg1983 commented

What would the expectation here be?

Would the consensus be all status update messages should be debug or trace level? or just status updates pertaining to IAsyncEnumerable?

Tragetaschen commented

IMHO (but I'm certainly not qualified enough to make a call here), Information-level logs of Orleans should not be O(#grains) or even O(#grain-method-calls)

  • 👍1
ReubenBond commented

@Tragetaschen agreed, we should fix this. Those status requests are mainly for diagnosing very-long-running requests

  • ❤️1