From 5a77ad64f836a958a65264405e2ecb5c8ea7e068 Mon Sep 17 00:00:00 2001 From: Jorge Bay Gondra Date: Mon, 21 Nov 2016 10:54:05 +0100 Subject: [PATCH 1/4] Alternate LoggerProvider logging API --- src/Cassandra/Cassandra.csproj | 9 + src/Cassandra/Cassandra.project.json | 5 +- src/Cassandra/Diagnostics.cs | 41 ++++- src/Cassandra/Logger.cs | 247 +++++++++++++++++++-------- src/Cassandra/packages.config | 2 + src/Cassandra/project.json | 12 +- 6 files changed, 239 insertions(+), 77 deletions(-) diff --git a/src/Cassandra/Cassandra.csproj b/src/Cassandra/Cassandra.csproj index 81aa72e56..d70621b10 100644 --- a/src/Cassandra/Cassandra.csproj +++ b/src/Cassandra/Cassandra.csproj @@ -45,9 +45,18 @@ ..\packages\lz4net.1.0.10.93\lib\net4-client\LZ4.dll True + + ..\packages\Microsoft.Extensions.Logging.1.0.0\lib\netstandard1.1\Microsoft.Extensions.Logging.dll + True + + + ..\packages\Microsoft.Extensions.Logging.Abstractions.1.0.0\lib\netstandard1.1\Microsoft.Extensions.Logging.Abstractions.dll + True + + diff --git a/src/Cassandra/Cassandra.project.json b/src/Cassandra/Cassandra.project.json index 4e531d32b..27c1e28dd 100644 --- a/src/Cassandra/Cassandra.project.json +++ b/src/Cassandra/Cassandra.project.json @@ -8,11 +8,14 @@ "System": "", "System.Data": "", "System.Numerics": "", + "System.Runtime": "", "System.Xml": "" } } }, "dependencies": { - "lz4net": "1.0.10.93" + "lz4net": "1.0.10.93", + "Microsoft.Extensions.Logging": "1.0.0", + "Microsoft.Extensions.Logging.Abstractions": "1.0.0" } } \ No newline at end of file diff --git a/src/Cassandra/Diagnostics.cs b/src/Cassandra/Diagnostics.cs index 8e2081c35..0c25a340c 100644 --- a/src/Cassandra/Diagnostics.cs +++ b/src/Cassandra/Diagnostics.cs @@ -1,5 +1,5 @@ // -// Copyright (C) 2012-2014 DataStax Inc. +// Copyright (C) 2012-2016 DataStax Inc. // // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. @@ -15,22 +15,38 @@ // using System.Diagnostics; +using Microsoft.Extensions.Logging; namespace Cassandra { + /// + /// Provides a set of methods and properties related to logging in the driver. + /// public static class Diagnostics { /// - /// Specifies what messages should be passed to the output log. - /// + /// Determines if a API should be used to obtain a instance of logger. + /// + internal static volatile bool UseLoggerFactory; + + internal static readonly ILoggerFactory LoggerFactory = new LoggerFactory(); + + /// + /// Specifies what messages should be passed to the output log when using the API. + /// /// TraceLevel.Off - Output no tracing messages. /// TraceLevel.Error - Output error-handling messages. /// TraceLevel.Warning - Output warnings and error-handling messages. /// TraceLevel.Info - Output informational messages, warnings, and error-handling messages. /// TraceLevel.Verbose - Output all debugging and tracing messages. /// - public static readonly TraceSwitch CassandraTraceSwitch = new TraceSwitch("TraceSwitch", - "This switch lets the user choose which kind of messages should be included in log."); + /// + /// Consider using Microsoft.Extensions.Logging API instead by adding a + /// using the method. + /// + /// + public static readonly TraceSwitch CassandraTraceSwitch = new TraceSwitch( + "TraceSwitch", "This switch lets the user choose which kind of messages should be included in log."); /// /// Defines if exception StackTrace information should be printed by trace logger. @@ -43,5 +59,20 @@ public static class Diagnostics /// Default value is false. /// public static bool CassandraPerformanceCountersEnabled { get; set; } + + /// + /// Adds a to the logger factory used by the driver. + /// + /// Be sure to call this method before initializing the to ensure that + /// API is used as driver logging mechanism instead of + /// . + /// + /// + /// The logger provider to add to the logger factory + public static void AddLoggerProvider(ILoggerProvider provider) + { + UseLoggerFactory = true; + LoggerFactory.AddProvider(provider); + } } } diff --git a/src/Cassandra/Logger.cs b/src/Cassandra/Logger.cs index ac5e53b6f..a294bc22f 100644 --- a/src/Cassandra/Logger.cs +++ b/src/Cassandra/Logger.cs @@ -18,121 +18,230 @@ using System.Diagnostics; using System.Linq; using System.Text; +using Microsoft.Extensions.Logging; namespace Cassandra { + /// + /// Represents a driver Logger + /// public class Logger { - private const string DateFormat = "MM/dd/yyyy H:mm:ss.fff zzz"; - private readonly string _category; - private StringBuilder _sb; + // Implementation information: the Logger API has been leaked into the public API. + // To avoid introducing a breaking change, we will keep the Logger as a wrapper and factory of the + // actual logger + private readonly ILoggerHandler _loggerHandler; public Logger(Type type) { - _category = type.Name; + if (Diagnostics.UseLoggerFactory) + { + _loggerHandler = new FactoryBasedLoggerHandler(type); + } + else + { + _loggerHandler = new TraceBasedLoggerHandler(type); + } } - private static string PrintStackTrace(Exception ex) + public void Error(Exception ex) { - var sb = new StringBuilder(); - // ReSharper disable once AssignNullToNotNullAttribute - foreach (StackFrame frame in new StackTrace(ex, true).GetFrames().Skip(3)) - { - sb.Append(frame); - } - return sb.ToString(); + _loggerHandler.Error(ex); } - private string GetExceptionAndAllInnerEx(Exception ex, bool recur = false) + public void Error(string message, Exception ex = null) { - if (!recur || _sb == null) - _sb = new StringBuilder(); - _sb.Append(String.Format("( Exception! Source {0} \n Message: {1} \n StackTrace:\n {2} ", ex.Source, ex.Message, - (Diagnostics.CassandraStackTraceIncluded - ? (recur ? ex.StackTrace : PrintStackTrace(ex)) - : "To display StackTrace, change Debugging.StackTraceIncluded property value to true."))); - if (ex.InnerException != null) - GetExceptionAndAllInnerEx(ex.InnerException, true); - - _sb.Append(")"); - return _sb.ToString(); + _loggerHandler.Error(message, ex); } - public void Error(Exception ex) + public void Error(string message, params object[] args) + { + _loggerHandler.Error(message, args); + } + + public void Warning(string message, params object[] args) { - if (!Diagnostics.CassandraTraceSwitch.TraceError) + _loggerHandler.Warning(message, args); + } + + public void Info(string message, params object[] args) + { + _loggerHandler.Info(message, args); + } + + public void Verbose(string message, params object[] args) + { + _loggerHandler.Verbose(message, args); + } + + /// + /// Represents the actual logger + /// + internal interface ILoggerHandler + { + void Error(Exception ex); + void Error(string message, Exception ex = null); + void Error(string message, params object[] args); + void Verbose(string message, params object[] args); + void Info(string message, params object[] args); + void Warning(string message, params object[] args); + } + + internal class FactoryBasedLoggerHandler : ILoggerHandler + { + private readonly ILogger _logger; + + public FactoryBasedLoggerHandler(Type type) { - return; + _logger = Diagnostics.LoggerFactory.CreateLogger(type.FullName); } - if (ex == null) + + public void Error(Exception ex) { - return; + _logger.LogError(0, ex, ""); } - Trace.WriteLine( - String.Format("{0} #ERROR: {1}", DateTimeOffset.Now.DateTime.ToString(DateFormat), GetExceptionAndAllInnerEx(ex)), _category); - } - public void Error(string msg, Exception ex = null) - { - if (!Diagnostics.CassandraTraceSwitch.TraceError) + public void Error(string message, Exception ex = null) { - return; + _logger.LogError(0, ex, message); } - Trace.WriteLine( - String.Format("{0} #ERROR: {1}", DateTimeOffset.Now.DateTime.ToString(DateFormat), - msg + (ex != null ? "\nEXCEPTION:\n " + GetExceptionAndAllInnerEx(ex) : String.Empty)), _category); - } - public void Error(string message, params object[] args) - { - if (!Diagnostics.CassandraTraceSwitch.TraceError) + public void Error(string message, params object[] args) { - return; + _logger.LogError(message, args); } - if (args != null && args.Length > 0) + + public void Verbose(string message, params object[] args) { - message = String.Format(message, args); + _logger.LogDebug(message, args); } - Trace.WriteLine(String.Format("{0} #ERROR: {1}", DateTimeOffset.Now.DateTime.ToString(DateFormat), message), _category); - } - public void Warning(string message, params object[] args) - { - if (!Diagnostics.CassandraTraceSwitch.TraceWarning) + public void Info(string message, params object[] args) { - return; + _logger.LogInformation(message, args); } - if (args != null && args.Length > 0) + + public void Warning(string message, params object[] args) { - message = String.Format(message, args); + _logger.LogWarning(message, args); } - Trace.WriteLine(String.Format("{0} #WARNING: {1}", DateTimeOffset.Now.DateTime.ToString(DateFormat), message), _category); } - public void Info(string message, params object[] args) + internal class TraceBasedLoggerHandler : ILoggerHandler { - if (!Diagnostics.CassandraTraceSwitch.TraceInfo) + private const string DateFormat = "MM/dd/yyyy H:mm:ss.fff zzz"; + private readonly string _category; + private StringBuilder _sb; + + public TraceBasedLoggerHandler(Type type) { - return; + _category = type.Name; } - if (args != null && args.Length > 0) + + private static string PrintStackTrace(Exception ex) { - message = String.Format(message, args); + var sb = new StringBuilder(); + // ReSharper disable once AssignNullToNotNullAttribute + foreach (StackFrame frame in new StackTrace(ex, true).GetFrames().Skip(3)) + { + sb.Append(frame); + } + return sb.ToString(); } - Trace.WriteLine(String.Format("{0} : {1}", DateTimeOffset.Now.DateTime.ToString(DateFormat), message), _category); - } - public void Verbose(string message, params object[] args) - { - if (!Diagnostics.CassandraTraceSwitch.TraceVerbose) + private string GetExceptionAndAllInnerEx(Exception ex, bool recur = false) { - return; + if (!recur || _sb == null) + _sb = new StringBuilder(); + _sb.Append(String.Format("( Exception! Source {0} \n Message: {1} \n StackTrace:\n {2} ", ex.Source, ex.Message, + (Diagnostics.CassandraStackTraceIncluded + ? (recur ? ex.StackTrace : PrintStackTrace(ex)) + : "To display StackTrace, change Debugging.StackTraceIncluded property value to true."))); + if (ex.InnerException != null) + GetExceptionAndAllInnerEx(ex.InnerException, true); + + _sb.Append(")"); + return _sb.ToString(); } - if (args != null && args.Length > 0) + + public void Error(Exception ex) { - message = String.Format(message, args); + if (!Diagnostics.CassandraTraceSwitch.TraceError) + { + return; + } + if (ex == null) + { + return; + } + Trace.WriteLine( + String.Format("{0} #ERROR: {1}", DateTimeOffset.Now.DateTime.ToString(DateFormat), GetExceptionAndAllInnerEx(ex)), _category); + } + + public void Error(string msg, Exception ex = null) + { + if (!Diagnostics.CassandraTraceSwitch.TraceError) + { + return; + } + Trace.WriteLine( + String.Format("{0} #ERROR: {1}", DateTimeOffset.Now.DateTime.ToString(DateFormat), + msg + (ex != null ? "\nEXCEPTION:\n " + GetExceptionAndAllInnerEx(ex) : String.Empty)), _category); + } + + public void Error(string message, params object[] args) + { + if (!Diagnostics.CassandraTraceSwitch.TraceError) + { + return; + } + if (args != null && args.Length > 0) + { + message = String.Format(message, args); + } + Trace.WriteLine(String.Format("{0} #ERROR: {1}", DateTimeOffset.Now.DateTime.ToString(DateFormat), message), _category); + } + + public void Warning(string message, params object[] args) + { + if (!Diagnostics.CassandraTraceSwitch.TraceWarning) + { + return; + } + if (args != null && args.Length > 0) + { + message = String.Format(message, args); + } + Trace.WriteLine(String.Format("{0} #WARNING: {1}", DateTimeOffset.Now.DateTime.ToString(DateFormat), message), _category); + } + + public void Info(string message, params object[] args) + { + if (!Diagnostics.CassandraTraceSwitch.TraceInfo) + { + return; + } + if (args != null && args.Length > 0) + { + message = String.Format(message, args); + } + Trace.WriteLine(String.Format("{0} : {1}", DateTimeOffset.Now.DateTime.ToString(DateFormat), message), _category); + } + + public void Verbose(string message, params object[] args) + { + if (!Diagnostics.CassandraTraceSwitch.TraceVerbose) + { + return; + } + if (args != null && args.Length > 0) + { + message = String.Format(message, args); + } + Trace.WriteLine(String.Format("{0} {1}", DateTimeOffset.Now.DateTime.ToString(DateFormat), message), _category); } - Trace.WriteLine(String.Format("{0} {1}", DateTimeOffset.Now.DateTime.ToString(DateFormat), message), _category); } } + + } \ No newline at end of file diff --git a/src/Cassandra/packages.config b/src/Cassandra/packages.config index 722192917..2978964c8 100644 --- a/src/Cassandra/packages.config +++ b/src/Cassandra/packages.config @@ -1,4 +1,6 @@  + + \ No newline at end of file diff --git a/src/Cassandra/project.json b/src/Cassandra/project.json index 7cdd41f24..5dc13a3a1 100644 --- a/src/Cassandra/project.json +++ b/src/Cassandra/project.json @@ -18,15 +18,21 @@ "xmlDoc": true, "nowarn": [ "1591" ] }, + "dependencies": { + "Microsoft.Extensions.Logging": "1.0.0" + }, "frameworks": { "net45": { "frameworkAssemblies": { "System.Data": "", "System.Numerics": "", + "System.Runtime": "", "System.Xml": "" }, "dependencies": { - "lz4net": "1.0.10.93" + "lz4net": "1.0.10.93", + "Microsoft.Extensions.Logging": "1.0.0", + "Microsoft.Extensions.Logging.Abstractions": "1.0.0" } }, "netstandard1.5": { @@ -63,7 +69,9 @@ "System.Threading": "4.0.11", "System.Threading.Tasks": "4.0.11", "System.Threading.Thread": "4.0.0", - "System.Threading.Timer": "4.0.1" + "System.Threading.Timer": "4.0.1", + "Microsoft.Extensions.Logging": "1.0.0", + "Microsoft.Extensions.Logging.Abstractions": "1.0.0" } } } From b5550533bfc8a14783879ce1419c845bdc123def Mon Sep 17 00:00:00 2001 From: Jorge Bay Gondra Date: Mon, 21 Nov 2016 16:12:09 +0100 Subject: [PATCH 2/4] Test ILoggerHandler implementations --- src/Cassandra.Tests/Cassandra.Tests.csproj | 1 + src/Cassandra.Tests/LoggingTests.cs | 75 ++++++++++++++++++++++ 2 files changed, 76 insertions(+) create mode 100644 src/Cassandra.Tests/LoggingTests.cs diff --git a/src/Cassandra.Tests/Cassandra.Tests.csproj b/src/Cassandra.Tests/Cassandra.Tests.csproj index 37cc65cfd..ad442996d 100644 --- a/src/Cassandra.Tests/Cassandra.Tests.csproj +++ b/src/Cassandra.Tests/Cassandra.Tests.csproj @@ -74,6 +74,7 @@ + diff --git a/src/Cassandra.Tests/LoggingTests.cs b/src/Cassandra.Tests/LoggingTests.cs new file mode 100644 index 000000000..77b83d4f0 --- /dev/null +++ b/src/Cassandra.Tests/LoggingTests.cs @@ -0,0 +1,75 @@ +using System; +using System.Collections.Concurrent; +using System.Collections.Generic; +using System.Diagnostics; +using System.Linq; +using System.Text; +using System.Threading; +using System.Threading.Tasks; +using Microsoft.Extensions.Logging; +using NUnit.Framework; + +namespace Cassandra.Tests +{ + [TestFixture] + public class LoggingTests + { + [Test] + public void FactoryBasedLoggerHandler_Methods_Not_Throw() + { + UseAllMethods(new Logger.FactoryBasedLoggerHandler(typeof(int))); + } + + [Test] + public void FactoryBasedLoggerHandler_Methods_Should_Output_To_Trace() + { + var originalLevel = Diagnostics.CassandraTraceSwitch.Level; + Diagnostics.CassandraTraceSwitch.Level = TraceLevel.Verbose; + var listener = new TestTraceListener(); + Trace.Listeners.Add(listener); + UseAllMethods(new Logger.TraceBasedLoggerHandler(typeof(int))); + Trace.Listeners.Remove(listener); + Assert.AreEqual(6, listener.Messages.Count); + Diagnostics.CassandraTraceSwitch.Level = originalLevel; + var expectedMessages = new[] + { + "Test exception 1", + "Message 1", + "Message 2 Param1", + "Message 3 Param2", + "Message 4 Param3", + "Message 5 Param4" + }; + var messages = listener.Messages.Keys.OrderBy(k => k).Select(k => listener.Messages[k]).ToArray(); + for (var i = 0; i < expectedMessages.Length; i++) + { + StringAssert.Contains(expectedMessages[i], messages[i]); + } + } + + private void UseAllMethods(Logger.ILoggerHandler loggerHandler) + { + loggerHandler.Error(new Exception("Test exception 1")); + loggerHandler.Error("Message 1", new Exception("Test exception 1")); + loggerHandler.Error("Message 2 {0}", "Param1"); + loggerHandler.Info("Message 3 {0}", "Param2"); + loggerHandler.Verbose("Message 4 {0}", "Param3"); + loggerHandler.Warning("Message 5 {0}", "Param4"); + } + + private class TestTraceListener : TraceListener + { + public readonly ConcurrentDictionary Messages = new ConcurrentDictionary(); + private int _counter = -1; + + public override void Write(string message) + { + } + + public override void WriteLine(string message) + { + Messages.AddOrUpdate(Interlocked.Increment(ref _counter), message, (k, v) => message); + } + } + } +} \ No newline at end of file From c0e33b4c0d6e2d1f5dc99fa1ecc48133f862065e Mon Sep 17 00:00:00 2001 From: Jorge Bay Gondra Date: Mon, 21 Nov 2016 16:20:57 +0100 Subject: [PATCH 3/4] Remove unused `using` directives --- src/Cassandra.Tests/LoggingTests.cs | 4 ---- 1 file changed, 4 deletions(-) diff --git a/src/Cassandra.Tests/LoggingTests.cs b/src/Cassandra.Tests/LoggingTests.cs index 77b83d4f0..b2e893fbe 100644 --- a/src/Cassandra.Tests/LoggingTests.cs +++ b/src/Cassandra.Tests/LoggingTests.cs @@ -1,12 +1,8 @@ using System; using System.Collections.Concurrent; -using System.Collections.Generic; using System.Diagnostics; using System.Linq; -using System.Text; using System.Threading; -using System.Threading.Tasks; -using Microsoft.Extensions.Logging; using NUnit.Framework; namespace Cassandra.Tests From fb3a5ceed60d79711691c5d7b926060a00411549 Mon Sep 17 00:00:00 2001 From: Jorge Bay Gondra Date: Mon, 21 Nov 2016 17:13:29 +0100 Subject: [PATCH 4/4] Logging docs --- doc/faq/README.md | 27 ++++++++++++++++++++++++--- 1 file changed, 24 insertions(+), 3 deletions(-) diff --git a/doc/faq/README.md b/doc/faq/README.md index 9c5b6ba24..2ba6fc06d 100644 --- a/doc/faq/README.md +++ b/doc/faq/README.md @@ -5,7 +5,24 @@ Normally you should use one `ISession` instance per application. You should share that instance between classes within your application. -## How can I enable tracing in the driver? +## How can I enable logging in the driver? + +The driver allows you to plug in any [`ILoggerProvider`][logging-api] implementation, like [NLog][nlog] and +[Serilog][serilog] implementations. + +You should set the provider before initializing the cluster, using the `Diagnostics` class: + +```csharp +// Use the provider you prefer, in this case NLog +ILoggerProvider provider = new NLogLoggerProvider(); +// Add it before initializing the Cluster +Cassandra.Diagnostics.AddLoggerProvider(provider); +``` + +You can configure the log levels you want to output using the provider API. + +Alternatively, if you don't want to use a `ILoggerProvider` implementation, the driver can expose log events using +the .NET Tracing API. ```csharp // Specify the minimum trace level you want to see @@ -18,7 +35,7 @@ Trace.Listeners.Add(new ConsoleTraceListener()); It depends on the size of the requests and the number of tables affected by the BATCH. Large batches can cause a lot of stress on the coordinator. Consider that Cassandra batches are not suitable for bulk loading, there -are dedicated tools for that. batches allow you to group related updates in a single request, so keep the BATCH size +are dedicated tools for that. Batches allow you to group related updates in a single request, so keep the BATCH size small (in the order of tens). Starting from Cassandra version 2.0.8, the node issues a warning if the batch size is greater than 5K. @@ -26,4 +43,8 @@ Starting from Cassandra version 2.0.8, the node issues a warning if the batch si ## What is the best way to retrieve multiple rows that contain large-sized blobs? You can decrease the number of rows retrieved per page. By using the `SetPageSize()` method on a statement, you -instruct the driver to retrieve fewer rows per request (the default is 5000). \ No newline at end of file +instruct the driver to retrieve fewer rows per request (the default is 5000). + +[logging-api]: https://github.com/aspnet/Logging +[nlog]: https://github.com/NLog/NLog.Extensions.Logging +[serilog]: https://github.com/serilog/serilog-extensions-logging \ No newline at end of file