dev: update log level on AttachStream (#228)

* dev: update log level on AttachStream
* ADO.NET & WriterTopic make Debug in tests

Author: KirillKurdyukov

CHANGELOG.md

@@ -1,3 +1,5 @@
+- Update log level on AttachStream
+
 ## v0.9.0
 - Writer client for YDB topics
 - Fix: delete default timeout grpc.deadline 

src/Ydb.Sdk/src/Pool/SessionPool.cs

@@ -208,25 +208,35 @@ private async ValueTask TryDriverDispose(int expectedCurrentCount)
 public abstract class SessionBase<T> where T : SessionBase<T>
 {
     private readonly SessionPool<T> _sessionPool;
+    private readonly ILogger _logger;
 
     public string SessionId { get; }
 
     internal long NodeId { get; }
 
     internal volatile bool IsActive = true;
 
-    internal SessionBase(SessionPool<T> sessionPool, string sessionId, long nodeId)
+    internal SessionBase(SessionPool<T> sessionPool, string sessionId, long nodeId, ILogger logger)
     {
         _sessionPool = sessionPool;
         SessionId = sessionId;
         NodeId = nodeId;
+        _logger = logger;
     }
 
     internal void OnStatus(Status status)
     {
-        if (status.StatusCode is StatusCode.BadSession or StatusCode.SessionBusy or StatusCode.InternalError
-            or StatusCode.ClientTransportTimeout or StatusCode.Unavailable or StatusCode.ClientTransportUnavailable)
+        // ReSharper disable once InvertIf
+        if (status.StatusCode is
+            StatusCode.BadSession or
+            StatusCode.SessionBusy or
+            StatusCode.InternalError or
+            StatusCode.ClientTransportTimeout or
+            StatusCode.Unavailable or
+            StatusCode.ClientTransportUnavailable)
         {
+            _logger.LogWarning("Session[{SessionId}] is deactivated. Reason: {Status}", SessionId, status);
+
             IsActive = false;
         }
     }

src/Ydb.Sdk/src/Services/Query/SessionPool.cs

@@ -22,26 +22,26 @@ internal sealed class SessionPool : SessionPool<Session>, IAsyncDisposable
 
     private readonly Driver _driver;
     private readonly bool _disposingDriver;
+    private readonly ILogger<Session> _loggerSession;
 
     internal SessionPool(Driver driver, int? maxSessionPool = null, bool disposingDriver = false)
         : base(driver.LoggerFactory.CreateLogger<SessionPool>(), maxSessionPool)
     {
         _driver = driver;
         _disposingDriver = disposingDriver;
+        _loggerSession = driver.LoggerFactory.CreateLogger<Session>();
     }
 
     protected override async Task<Session> CreateSession()
     {
         var response = await _driver.UnaryCall(QueryService.CreateSessionMethod, CreateSessionRequest,
             CreateSessionSettings);
 
-        var status = Status.FromProto(response.Status, response.Issues);
-
-        status.EnsureSuccess();
+        Status.FromProto(response.Status, response.Issues).EnsureSuccess();
 
         TaskCompletionSource<Status> completeTask = new();
 
-        var session = new Session(_driver, this, response.SessionId, response.NodeId);
+        var session = new Session(_driver, this, response.SessionId, response.NodeId, _loggerSession);
 
         _ = Task.Run(async () =>
         {
@@ -74,27 +74,26 @@ protected override async Task<Session> CreateSession()
                         // ReSharper disable once InvertIf
                         if (!session.IsActive)
                         {
-                            Logger.LogWarning("Session[{SessionId}] is deactivated", session.SessionId);
-
                             return;
                         }
                     }
 
+                    Logger.LogDebug("Session[{SessionId}]: Attached stream is closed", session.SessionId);
+
                     // attach stream is closed
                 }
-                catch (Driver.TransportException)
+                catch (Driver.TransportException e)
                 {
+                    Logger.LogWarning(e, "Session[{SessionId}] is deactivated by transport error", session.SessionId);
                 }
             }
-            catch (Exception e)
+            catch (Driver.TransportException e)
             {
                 completeTask.SetException(e);
             }
             finally
             {
                 session.IsActive = false;
-
-                Logger.LogTrace("Session[{SessionId}]: Attached stream is closed", session.SessionId);
             }
         });
 
@@ -134,8 +133,13 @@ internal class Session : SessionBase<Session>
 {
     private readonly Driver _driver;
 
-    internal Session(Driver driver, SessionPool<Session> sessionPool, string sessionId, long nodeId)
-        : base(sessionPool, sessionId, nodeId)
+    internal Session(
+        Driver driver,
+        SessionPool<Session> sessionPool,
+        string sessionId,
+        long nodeId,
+        ILogger<Session> logger
+    ) : base(sessionPool, sessionId, nodeId, logger)
     {
         _driver = driver;
     }

src/Ydb.Sdk/tests/Pool/SessionPoolTests.cs

@@ -1,4 +1,5 @@
 using Google.Protobuf.Collections;
+using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Logging.Abstractions;
 using Xunit;
 using Ydb.Issue;
@@ -106,7 +107,8 @@ protected override Task<Status> DeleteSession(TestSession session)
 
 public class TestSession : SessionBase<TestSession>
 {
-    internal TestSession(SessionPool<TestSession> sessionPool) : base(sessionPool, "0", 0)
+    internal TestSession(SessionPool<TestSession> sessionPool)
+        : base(sessionPool, "0", 0, Utils.GetLoggerFactory().CreateLogger<TestSession>())
     {
     }
 }

src/Ydb.Sdk/tests/Utils.cs

@@ -47,7 +47,13 @@ public static async Task<ExecuteSchemeQueryResponse> ExecuteSchemeQuery(
     internal static ILoggerFactory GetLoggerFactory()
     {
         return new ServiceCollection()
-            .AddLogging(configure => configure.AddConsole().SetMinimumLevel(LogLevel.Debug))
+            .AddLogging(configure =>
+            {
+                configure.AddConsole().SetMinimumLevel(LogLevel.Information);
+                configure.AddFilter("Ydb.Sdk.Ado", LogLevel.Debug);
+                configure.AddFilter("Ydb.Sdk.Services.Query", LogLevel.Debug);
+                configure.AddFilter("Ydb.Sdk.Services.Topic", LogLevel.Debug);
+            })
             .BuildServiceProvider()
             .GetService<ILoggerFactory>() ?? NullLoggerFactory.Instance;
     }