Merge pull request #29 from vtex/vtexsplunklogger/implement_kpi_concept

Implemented VTEX Kpi concept
Small code refactoring for some VTEX log entries

Author: Caldas

src/VTEXSplunkLogger/DateTimeExtensions.cs

@@ -0,0 +1,20 @@
+using System;
+
+namespace Vtex
+{
+    /// <summary>
+    /// This class contains DateTime extension method to simplify small DateTime usage.
+    /// </summary>
+    public static class DateTimeExtensions
+    {
+        /// <summary>
+        /// Return informed DateTime without seconds and milisecond.
+        /// </summary>
+        /// <returns>The second mili second.</returns>
+        /// <param name="baseDate">Base date.</param>
+        public static DateTime RemoveSecondMiliSecond(this DateTime baseDate)
+        {
+            return new DateTime(baseDate.Year, baseDate.Month, baseDate.Day, baseDate.Hour, baseDate.Minute, 0);
+        }
+    }
+}

src/VTEXSplunkLogger/ILoggerExtensions.cs

@@ -1,15 +1,23 @@
 using System;
+using System.Collections.Concurrent;
 using Microsoft.Extensions.Logging;
 using Vtex.SplunkLogger;
 
 namespace Vtex
 {
     /// <summary>
-    /// This class contains ILogger extension method to simplify the process to record a VTEX log.
+    /// This class contains ILogger extension method to simplify the process to record VTEX Logs and Kpis.
     /// </summary>
     public static class ILoggerExtensions
     {
-        static readonly EventId EmptyEventId = new EventId();
+        static readonly EventId emptyEventId = new EventId();
+        static readonly ConcurrentDictionary<ILogger, MetricManager> metricManagers = new ConcurrentDictionary<ILogger, MetricManager>();
+
+        static void KpiReady(object sender, VTEXKpiEntry kpiEntry)
+        {
+            if(sender is ILogger)
+                ((ILogger)sender).Log(LogLevel.Critical, emptyEventId, kpiEntry, null, null);
+        }
 
         /// <summary>
         /// Log to Splunk.
@@ -25,9 +33,9 @@ public static void DefineVTEXLog(this ILogger logger, LogLevel logLevel, string
         {
             string formattedMessage = string.Empty;
             logger.Log(logLevel,
-                        EmptyEventId,
-                        new VTEXSplunkEntry(workflowType, workflowInstance, account, exception, extraParameters),
-                        exception, (VTEXSplunkEntry arg1, Exception arg2) =>
+                        emptyEventId,
+                        new VTEXLogEntry(workflowType, workflowInstance, account, exception, extraParameters),
+                        exception, (VTEXLogEntry arg1, Exception arg2) =>
                         {
                             if (string.IsNullOrWhiteSpace(formattedMessage))
                             {
@@ -41,5 +49,18 @@ public static void DefineVTEXLog(this ILogger logger, LogLevel logLevel, string
                             return formattedMessage;
                         });
         }
+
+        /// <summary>
+        /// Generate performance indicator.
+        /// </summary>
+        /// <param name="logger">Logger.</param>
+        /// <param name="kpiName">Kpi name.</param>
+        /// <param name="kpiValue">Kpi value.</param>
+        /// <param name="account">Account.</param>
+        /// <param name="extraParameters">Extra parameters.</param>
+        public static void DefineVTEXKpi(this ILogger logger, string kpiName, float kpiValue, string account = "", params Tuple<string, string>[] extraParameters)
+        {
+            metricManagers.GetOrAdd(logger, new MetricManager(logger, KpiReady)).RegisterKpi(kpiName, kpiValue, account, extraParameters);
+        }
     }
 }

src/VTEXSplunkLogger/LoggerFactoryExtensions.cs

@@ -3,7 +3,7 @@
 using Splunk.Configurations;
 using Splunk;
 
-namespace Vtex.SplunkLogger
+namespace Vtex
 {
     /// <summary>
     /// This class contains ILoggerFactory extension method to simplify the process to add a Splunk logger provider.

src/VTEXSplunkLogger/MetricManager.cs

@@ -0,0 +1,218 @@
+using System;
+using System.Collections.Concurrent;
+using System.Collections.Generic;
+using System.Text;
+using System.Threading.Tasks;
+using System.Timers;
+using System.Linq;
+using Microsoft.Extensions.Logging;
+
+namespace Vtex.SplunkLogger
+{
+    /// <summary>
+    /// This class contains all methods and logics necessary to control kpi process.
+    /// </summary>
+    /// <remarks>
+    /// MetricManager is used to summarize performance indicators during one minute
+    /// and them dispatch those entries to Splunk as a "custom" log.
+    /// </remarks>
+    class MetricManager
+    {
+        #region [ Private Constants ]
+
+        internal const string METRIC_SPLIT = "-#-";
+        internal const string OPTIONAL_SPLIT = ":#:";
+        internal const string DIMENSION_SPLIT = "|#|";
+
+        #endregion
+
+        #region [ Private Kpi Ready Event ]
+
+        event EventHandler<VTEXKpiEntry> kpiReady = delegate { };
+
+        #endregion
+
+        #region [ Private Static Fields ]
+
+        static readonly ConcurrentDictionary<string, Tuple<ulong, float>> items = new ConcurrentDictionary<string, Tuple<ulong, float>>();
+        static readonly ConcurrentDictionary<string, float> itemsMax = new ConcurrentDictionary<string, float>();
+        static readonly ConcurrentDictionary<string, float> itemsMin = new ConcurrentDictionary<string, float>();
+
+        #endregion
+
+        #region [ Private Fields ]
+
+        readonly OnMinuteClockTimer summarizerTimer;
+        readonly ILogger logger;
+
+        #endregion
+
+        #region [ Internal Constructor ]
+
+        internal MetricManager(ILogger logger, EventHandler<VTEXKpiEntry> kpiReady)
+        {
+            this.logger = logger;
+
+            summarizerTimer = new OnMinuteClockTimer();
+            summarizerTimer.Elapsed += SummarizerTimer_Elapsed;
+            summarizerTimer.Start();
+
+            this.kpiReady = kpiReady;
+        }
+
+        #endregion
+
+        #region [ Internal Methods ]
+
+        internal void RegisterKpi(string kpiName, float kpiValue, string account = "", params Tuple<string, string>[] extraParameters)
+        {
+
+            var extraFields = new Dictionary<string, string>();
+
+            if (extraParameters != null && extraParameters.Length > 0)
+                extraParameters.ToList().ForEach(tuple => extraFields.Add(tuple.Item1, tuple.Item2));
+
+            if (!string.IsNullOrWhiteSpace(account))
+                extraFields.Add("account", account); 
+
+            RegisterKpi(kpiName, kpiValue, extraFields);
+        }
+
+        #endregion
+
+        #region [ Private Methods ]
+
+        void RegisterKpi(string metricName, float metricValue, Dictionary<string, string> extraFields)
+        {
+            var clonedExtraFields = new Dictionary<string, string>();
+            extraFields.All(a => { clonedExtraFields.Add(a.Key, a.Value); return true; });
+
+            string itemKey = GetKey(metricName, clonedExtraFields);
+            Tuple<ulong, float> metricItem = new Tuple<ulong, float>(1, metricValue);
+
+            items.AddOrUpdate(itemKey, metricItem, (key, metric) =>
+            {
+                return new Tuple<ulong, float>(metric.Item1 + metricItem.Item1, metric.Item2 + metricItem.Item2);
+            });
+
+            itemsMax.AddOrUpdate(itemKey, metricValue, (key, metric) =>
+            {
+                if (itemsMax.ContainsKey(itemKey))
+                {
+                    float oldValue = itemsMax[itemKey];
+                    return metricValue > oldValue ? metricValue : oldValue;
+                }
+
+                return metric;
+            });
+
+            itemsMin.AddOrUpdate(itemKey, metricValue, (key, metric) =>
+            {
+                if (itemsMin.ContainsKey(itemKey))
+                {
+                    float oldValue = itemsMin[itemKey];
+                    return metricValue < oldValue ? metricValue : oldValue;
+                }
+
+                return metric;
+            });
+        }
+
+        void SummarizerTimer_Elapsed(object sender, ElapsedEventArgs e)
+        {
+            if (items.Keys.Count > 0)
+            {
+                List<VTEXKpiEntry> kpiMetrics = new List<VTEXKpiEntry>();
+                Parallel.ForEach(items.Keys, key =>
+                {
+                    if (!string.IsNullOrWhiteSpace(key))
+                    {
+                        Tuple<ulong, float> valueTuple = null;
+                        items.TryRemove(key, out valueTuple);
+
+                        float maxValue = 0;
+                        itemsMax.TryRemove(key, out maxValue);
+
+                        float minValue = 0;
+                        itemsMin.TryRemove(key, out minValue);
+
+                        var kpiEntry = GenerateEntry(key, valueTuple, maxValue, minValue);
+                        kpiReady(logger, kpiEntry);
+                    }
+                });
+            }
+        }
+
+        VTEXKpiEntry GenerateEntry(string key, Tuple<ulong, float> valueTuple, float maxValue, float minValue)
+        {
+            string metricName = string.Empty;
+            Dictionary<string, string> extraFields = null;
+            RetreiveKeyItems(key, out metricName, out extraFields);
+
+            VTEXKpiEntry entry = new VTEXKpiEntry(metricName)
+            {
+                Count = valueTuple.Item1,
+                Name = metricName,
+                Sum = valueTuple.Item2,
+                Max = maxValue,
+                Min = minValue
+            };
+
+            if (extraFields != null && extraFields.Count > 0)
+            {
+                if (extraFields.ContainsKey("account"))
+                {
+                    entry.Account = extraFields["account"];
+                    extraFields.Remove("account");
+                }
+            }
+
+            entry.ExtraParameters = extraFields;
+
+            return entry;
+        }
+
+        void RetreiveKeyItems(string key, out string metricName, out Dictionary<string, string> customFields)
+        {
+            metricName = string.Empty;
+            customFields = null;
+            string[] parts = key.Split(new string[] { METRIC_SPLIT }, StringSplitOptions.RemoveEmptyEntries);
+            metricName = parts[0];
+            if (parts.Length > 1)
+            {
+                customFields = new Dictionary<string, string>();
+                string[] metricParts = parts[1].Split(new string[] { OPTIONAL_SPLIT }, StringSplitOptions.RemoveEmptyEntries);
+                string[] dimensionParts = null;
+                foreach (string metricPart in metricParts)
+                {
+                    dimensionParts = metricPart.Split(new string[] { DIMENSION_SPLIT }, StringSplitOptions.RemoveEmptyEntries);
+                    if (dimensionParts.Length == 2)
+                        customFields.Add(dimensionParts[0], dimensionParts[1]);
+                    else
+                        customFields.Add(dimensionParts[0], string.Empty);
+                }
+            }
+        }
+
+        string GetKey(string metricName, Dictionary<string, string> extraFields = null)
+        {
+            if (extraFields != null && extraFields.Count > 0)
+            {
+                StringBuilder stringBuilder = new StringBuilder();
+
+                foreach (KeyValuePair<string, string> item in extraFields)
+                {
+                    stringBuilder.AppendFormat("{0}{1}{2}", item.Key, DIMENSION_SPLIT, item.Value);
+                    stringBuilder.Append(OPTIONAL_SPLIT);
+                }
+                string itemString = stringBuilder.ToString();
+                itemString = string.Format("{0}{1}{2}", metricName, METRIC_SPLIT, itemString.Remove(itemString.Length - OPTIONAL_SPLIT.Length, OPTIONAL_SPLIT.Length));
+                return itemString;
+            }
+
+             return metricName;
+        }
+
+        #endregion
+    }
+}

src/VTEXSplunkLogger/OnMinuteClockTimer.cs

@@ -0,0 +1,59 @@
+using System;
+using System.ComponentModel;
+using System.Timers;
+
+namespace Vtex.SplunkLogger
+{
+    /// <summary>
+    /// This class contains all methods and logics necessary to control a timer that should
+    /// aways be triggered when minute reach 00 seconds.
+    /// </summary>
+    /// <remarks>
+    /// OnMinuteClockTimer is used to always triggers at same time.
+    /// </remarks>
+    class OnMinuteClockTimer
+    {
+        Timer SummarizerTimer;
+        int lastExecutedMinute = -1;
+
+        [Category("Behavior")]
+        [TimersDescription("TimerIntervalElapsed")]
+        internal event ElapsedEventHandler Elapsed = delegate { };
+
+        internal OnMinuteClockTimer()
+        {
+            SummarizerTimer = new Timer();
+            SummarizerTimer.Elapsed += SummarizerTimer_Elapsed;
+        }
+
+        internal void Start()
+        {
+            SummarizerTimer.Interval = GetTimerInterval();
+            SummarizerTimer.Start();
+        }
+
+        internal void Stop()
+        {
+            SummarizerTimer.Stop();
+        }
+
+        void SummarizerTimer_Elapsed(object sender, ElapsedEventArgs e)
+        {
+            var currentMinute = DateTime.Now.Minute;
+            if (currentMinute != lastExecutedMinute)
+            {
+                Stop();
+                Elapsed(sender, e);
+                lastExecutedMinute = currentMinute;
+                Start();
+            }
+        }
+
+        double GetTimerInterval()
+        {
+            var dateTimeNow = DateTime.Now;
+            var nextTickDateTime = dateTimeNow.AddMinutes(1).RemoveSecondMiliSecond();
+            return (nextTickDateTime - dateTimeNow).TotalMilliseconds;
+        }
+    }
+}