Fixed a bug where a format exception could be thrown while running plugins

niemyjski · niemyjski · commit eb6be527286e · 2016-09-16T19:59:08.000-05:00
diff --git a/src/Exceptionless.Tests/Plugins/PluginTests.cs b/src/Exceptionless.Tests/Plugins/PluginTests.cs
@@ -726,7 +726,7 @@ public void VerifyDeduplication() {
             var errorPlugin = new ErrorPlugin();
 
             EventPluginContext mergedContext = null;
-            using (var duplicateCheckerPlugin = new DuplicateCheckerPlugin(TimeSpan.FromMilliseconds(20))) {
+            using (var duplicateCheckerPlugin = new DuplicateCheckerPlugin(TimeSpan.FromMilliseconds(40))) {
                 for (int index = 0; index < 10; index++) {
                     var builder = GetException().ToExceptionless();
                     var context = new EventPluginContext(client, builder.Target, builder.PluginContextData);
@@ -745,7 +745,7 @@ public void VerifyDeduplication() {
                 }
             }
 
-            Thread.Sleep(50);
+            Thread.Sleep(100);
             Assert.Equal(9, mergedContext.Event.Count.GetValueOrDefault());
         }
         
diff --git a/src/Exceptionless.Tests/project.json b/src/Exceptionless.Tests/project.json
@@ -8,7 +8,7 @@
         }
     },
     "dependencies": {
-        "BenchmarkDotNet": "0.9.8",
+        "BenchmarkDotNet": "0.9.9",
         "Exceptionless": {
             "target": "project"
         },
diff --git a/src/Exceptionless/Configuration/SettingsManager.cs b/src/Exceptionless/Configuration/SettingsManager.cs
@@ -71,7 +71,7 @@ public static void CheckVersion(int version, ExceptionlessConfiguration config)
         public static void UpdateSettings(ExceptionlessConfiguration config, int? version = null) {
             if (config == null || !config.IsValid || !config.Enabled)
                 return;
-            
+
             try {
                 if (!version.HasValue || version < 0)
                     version = GetVersion(config);
diff --git a/src/Exceptionless/ExceptionlessClient.cs b/src/Exceptionless/ExceptionlessClient.cs
@@ -203,7 +203,7 @@ public void SubmitEvent(Event ev, ContextData pluginContextData = null) {
             _queue.Value.Enqueue(ev);
 
             if (!String.IsNullOrEmpty(ev.ReferenceId)) {
-                _log.Value.FormattedTrace(typeof(ExceptionlessClient), "Setting last reference id '{0}'", ev.ReferenceId);
+                _log.Value.FormattedTrace(typeof(ExceptionlessClient), "Setting last reference id: {0}", ev.ReferenceId);
                 _lastReferenceIdManager.Value.SetLast(ev.ReferenceId);
             }
 
diff --git a/src/Exceptionless/Logging/ExceptionlessLogExtensions.cs b/src/Exceptionless/Logging/ExceptionlessLogExtensions.cs
@@ -11,71 +11,79 @@ public static void Error(this IExceptionlessLog log, Type source, Exception exce
         }
 
         public static void FormattedError(this IExceptionlessLog log, Type source, Exception exception, string format, params object[] args) {
-            log.Error(String.Format(format, args), GetSourceName(source), exception);
+            log.Error(GetMessage(format, args), GetSourceName(source), exception);
         }
 
         public static void FormattedError(this IExceptionlessLog log, Type source, string format, params object[] args) {
-            log.Error(String.Format(format, args), GetSourceName(source));
+            log.Error(GetMessage(format, args), GetSourceName(source));
         }
 
         public static void Info(this IExceptionlessLog log, Type source, string message) {
             log.Info(message, GetSourceName(source));
         }
 
         public static void FormattedInfo(this IExceptionlessLog log, Type source, string format, params object[] args) {
-            log.Info(String.Format(format, args), GetSourceName(source));
+            log.Info(GetMessage(format, args), GetSourceName(source));
         }
 
         public static void Debug(this IExceptionlessLog log, Type source, string message) {
             log.Debug(message, GetSourceName(source));
         }
 
         public static void FormattedDebug(this IExceptionlessLog log, Type source, string format, params object[] args) {
-            log.Debug(String.Format(format, args), GetSourceName(source));
+            log.Debug(GetMessage(format, args), GetSourceName(source));
         }
 
         public static void Warn(this IExceptionlessLog log, Type source, string message) {
             log.Warn(message, GetSourceName(source));
         }
 
         public static void FormattedWarn(this IExceptionlessLog log, Type source, string format, params object[] args) {
-            log.Warn(String.Format(format, args), GetSourceName(source));
+            log.Warn(GetMessage(format, args), GetSourceName(source));
         }
 
         public static void Trace(this IExceptionlessLog log, Type source, string message) {
             log.Trace(message, GetSourceName(source));
         }
 
         public static void FormattedTrace(this IExceptionlessLog log, Type source, string format, params object[] args) {
-            log.Trace(String.Format(format, args), GetSourceName(source));
+            log.Trace(GetMessage(format, args), GetSourceName(source));
         }
 
         public static void Error(this IExceptionlessLog log, Exception exception, string message) {
             log.Error(message, exception: exception);
         }
 
         public static void FormattedError(this IExceptionlessLog log, Exception exception, string format, params object[] args) {
-            log.Error(String.Format(format, args), exception: exception);
+            log.Error(GetMessage(format, args), exception: exception);
         }
 
         public static void FormattedError(this IExceptionlessLog log, string format, params object[] args) {
-            log.Error(String.Format(format, args));
+            log.Error(GetMessage(format, args));
         }
 
         public static void FormattedInfo(this IExceptionlessLog log, string format, params object[] args) {
-            log.Info(String.Format(format, args));
+            log.Info(GetMessage(format, args));
         }
 
         public static void FormattedDebug(this IExceptionlessLog log, string format, params object[] args) {
-            log.Debug(String.Format(format, args));
+            log.Debug(GetMessage(format, args));
         }
 
         public static void FormattedWarn(this IExceptionlessLog log, string format, params object[] args) {
-            log.Warn(String.Format(format, args));
+            log.Warn(GetMessage(format, args));
         }
 
         private static string GetSourceName(Type type) {
             return type.Name;
         }
+
+        private static string GetMessage(string format, params object[] args) {
+            try {
+                return String.Format(format, args);
+            } catch (Exception) {
+                return format;
+            }
+        }
     }
 }
diff --git a/src/Exceptionless/Plugins/Default/1010_DuplicateCheckerPlugin.cs b/src/Exceptionless/Plugins/Default/1010_DuplicateCheckerPlugin.cs
@@ -32,29 +32,29 @@ public DuplicateCheckerPlugin(TimeSpan? interval) {
         public void Run(EventPluginContext context) {
             int hashCode = context.Event.GetHashCode();
             int count = context.Event.Count ?? 1;
-            context.Log.FormattedTrace(typeof(DuplicateCheckerPlugin), String.Concat("Checking event: ", context.Event.Message, " with hash: ", hashCode));
+            context.Log.FormattedTrace(typeof(DuplicateCheckerPlugin), "Checking event: {0} with hash: {1}", context.Event.Message, hashCode);
 
             lock (_lock) {
                 // Increment the occurrence count if the event is already queued for submission.
                 var merged = _mergedEvents.FirstOrDefault(s => s.HashCode == hashCode);
                 if (merged != null) {
                     merged.IncrementCount(count);
                     merged.UpdateDate(context.Event.Date);
-                    context.Log.FormattedInfo(typeof(DuplicateCheckerPlugin), String.Concat("Ignoring duplicate event with hash:", hashCode));
+                    context.Log.FormattedInfo(typeof(DuplicateCheckerPlugin), "Ignoring duplicate event with hash: {0}", hashCode);
                     context.Cancel = true;
                     return;
                 }
 
                 DateTimeOffset repeatWindow = DateTimeOffset.UtcNow.Subtract(_interval);
                 if (_processed.Any(s => s.Item1 == hashCode && s.Item2 >= repeatWindow)) {
-                    context.Log.FormattedInfo(typeof(DuplicateCheckerPlugin), String.Concat("Adding event with hash:", hashCode, " to cache."));
+                    context.Log.FormattedInfo(typeof(DuplicateCheckerPlugin), "Adding event with hash: {0} to cache.", hashCode);
                     // This event is a duplicate for the first time, lets save it so we can delay it while keeping count
                     _mergedEvents.Enqueue(new MergedEvent(hashCode, context, count));
                     context.Cancel = true;
                     return;
                 }
 
-                context.Log.FormattedInfo(typeof(DuplicateCheckerPlugin), String.Concat("Enqueueing event with hash:", hashCode, " to cache."));
+                context.Log.FormattedInfo(typeof(DuplicateCheckerPlugin), "Enqueueing event with hash: {0} to cache.", hashCode);
                 _processed.Enqueue(Tuple.Create(hashCode, DateTimeOffset.UtcNow));
                 
                 while (_processed.Count > 50)
@@ -116,7 +116,7 @@ public void Resubmit() {
                 _context.Resolver.GetEventQueue().Enqueue(_context.Event);
 
                 if (!String.IsNullOrEmpty(_context.Event.ReferenceId)) {
-                    _context.Log.FormattedTrace(typeof(DuplicateCheckerPlugin), "Setting last reference id '{0}'", _context.Event.ReferenceId);
+                    _context.Log.FormattedTrace(typeof(DuplicateCheckerPlugin), "Setting last reference id: {0}", _context.Event.ReferenceId);
                     _context.Resolver.GetLastReferenceIdManager().SetLast(_context.Event.ReferenceId);
                 }
 
diff --git a/src/Exceptionless/Services/DefaultEnvironmentInfoCollector.cs b/src/Exceptionless/Services/DefaultEnvironmentInfoCollector.cs
@@ -24,7 +24,7 @@ public DefaultEnvironmentInfoCollector(IExceptionlessLog log) {
         public EnvironmentInfo GetEnvironmentInfo() {
             if (_environmentInfo != null) {
                 PopulateThreadInfo(_environmentInfo);
-                PopulateMemoryInfo(_environmentInfo);            
+                PopulateMemoryInfo(_environmentInfo);
                 return _environmentInfo;
             }
 
@@ -178,7 +178,7 @@ private void PopulateRuntimeInfo(EnvironmentInfo info) {
 #if NETSTANDARD
                 computerInfo = Microsoft.Extensions.PlatformAbstractions.PlatformServices.Default;
 #elif NET45
-                computerInfo = new Microsoft.VisualBasic.Devices.ComputerInfo();                
+                computerInfo = new Microsoft.VisualBasic.Devices.ComputerInfo();
 #endif
             } catch (Exception ex) {
                 _log.FormattedInfo(typeof(DefaultEnvironmentInfoCollector), "Unable to get computer info. Error message: {0}", ex.Message);
diff --git a/src/Platforms/Exceptionless.NLog/project.json b/src/Platforms/Exceptionless.NLog/project.json
@@ -48,7 +48,7 @@
                 "define": [ "NET45" ]
             },
             "dependencies": {
-                "NLog": "4.3.6"
+                "NLog": "4.3.8"
             }
         }
     }

Original file line number	Diff line number	Diff line change
`@@ -726,7 +726,7 @@ public void VerifyDeduplication() {`
`726`	`726`	`var errorPlugin = new ErrorPlugin();`
`727`	`727`
`728`	`728`	`EventPluginContext mergedContext = null;`
`729`		`- using (var duplicateCheckerPlugin = new DuplicateCheckerPlugin(TimeSpan.FromMilliseconds(20))) {`
	`729`	`+ using (var duplicateCheckerPlugin = new DuplicateCheckerPlugin(TimeSpan.FromMilliseconds(40))) {`
`730`	`730`	`for (int index = 0; index < 10; index++) {`
`731`	`731`	`var builder = GetException().ToExceptionless();`
`732`	`732`	`var context = new EventPluginContext(client, builder.Target, builder.PluginContextData);`
`@@ -745,7 +745,7 @@ public void VerifyDeduplication() {`
`745`	`745`	`}`
`746`	`746`	`}`
`747`	`747`
`748`		`- Thread.Sleep(50);`
	`748`	`+ Thread.Sleep(100);`
`749`	`749`	`Assert.Equal(9, mergedContext.Event.Count.GetValueOrDefault());`
`750`	`750`	`}`
`751`	`751`
Original file line number	Diff line number	Diff line change
`@@ -8,7 +8,7 @@`
`8`	`8`	`}`
`9`	`9`	`},`
`10`	`10`	`"dependencies": {`
`11`		`- "BenchmarkDotNet": "0.9.8",`
	`11`	`+ "BenchmarkDotNet": "0.9.9",`
`12`	`12`	`"Exceptionless": {`
`13`	`13`	`"target": "project"`
`14`	`14`	`},`
Original file line number	Diff line number	Diff line change
`@@ -203,7 +203,7 @@ public void SubmitEvent(Event ev, ContextData pluginContextData = null) {`
`203`	`203`	`_queue.Value.Enqueue(ev);`
`204`	`204`
`205`	`205`	`if (!String.IsNullOrEmpty(ev.ReferenceId)) {`
`206`		`- _log.Value.FormattedTrace(typeof(ExceptionlessClient), "Setting last reference id '{0}'", ev.ReferenceId);`
	`206`	`+ _log.Value.FormattedTrace(typeof(ExceptionlessClient), "Setting last reference id: {0}", ev.ReferenceId);`
`207`	`207`	`_lastReferenceIdManager.Value.SetLast(ev.ReferenceId);`
`208`	`208`	`}`
`209`	`209`
Original file line number	Diff line number	Diff line change
`@@ -11,71 +11,79 @@ public static void Error(this IExceptionlessLog log, Type source, Exception exce`
`11`	`11`	`}`
`12`	`12`
`13`	`13`	`public static void FormattedError(this IExceptionlessLog log, Type source, Exception exception, string format, params object[] args) {`
`14`		`- log.Error(String.Format(format, args), GetSourceName(source), exception);`
	`14`	`+ log.Error(GetMessage(format, args), GetSourceName(source), exception);`
`15`	`15`	`}`
`16`	`16`
`17`	`17`	`public static void FormattedError(this IExceptionlessLog log, Type source, string format, params object[] args) {`
`18`		`- log.Error(String.Format(format, args), GetSourceName(source));`
	`18`	`+ log.Error(GetMessage(format, args), GetSourceName(source));`
`19`	`19`	`}`
`20`	`20`
`21`	`21`	`public static void Info(this IExceptionlessLog log, Type source, string message) {`
`22`	`22`	`log.Info(message, GetSourceName(source));`
`23`	`23`	`}`
`24`	`24`
`25`	`25`	`public static void FormattedInfo(this IExceptionlessLog log, Type source, string format, params object[] args) {`
`26`		`- log.Info(String.Format(format, args), GetSourceName(source));`
	`26`	`+ log.Info(GetMessage(format, args), GetSourceName(source));`
`27`	`27`	`}`
`28`	`28`
`29`	`29`	`public static void Debug(this IExceptionlessLog log, Type source, string message) {`
`30`	`30`	`log.Debug(message, GetSourceName(source));`
`31`	`31`	`}`
`32`	`32`
`33`	`33`	`public static void FormattedDebug(this IExceptionlessLog log, Type source, string format, params object[] args) {`
`34`		`- log.Debug(String.Format(format, args), GetSourceName(source));`
	`34`	`+ log.Debug(GetMessage(format, args), GetSourceName(source));`
`35`	`35`	`}`
`36`	`36`
`37`	`37`	`public static void Warn(this IExceptionlessLog log, Type source, string message) {`
`38`	`38`	`log.Warn(message, GetSourceName(source));`
`39`	`39`	`}`
`40`	`40`
`41`	`41`	`public static void FormattedWarn(this IExceptionlessLog log, Type source, string format, params object[] args) {`
`42`		`- log.Warn(String.Format(format, args), GetSourceName(source));`
	`42`	`+ log.Warn(GetMessage(format, args), GetSourceName(source));`
`43`	`43`	`}`
`44`	`44`
`45`	`45`	`public static void Trace(this IExceptionlessLog log, Type source, string message) {`
`46`	`46`	`log.Trace(message, GetSourceName(source));`
`47`	`47`	`}`
`48`	`48`
`49`	`49`	`public static void FormattedTrace(this IExceptionlessLog log, Type source, string format, params object[] args) {`
`50`		`- log.Trace(String.Format(format, args), GetSourceName(source));`
	`50`	`+ log.Trace(GetMessage(format, args), GetSourceName(source));`
`51`	`51`	`}`
`52`	`52`
`53`	`53`	`public static void Error(this IExceptionlessLog log, Exception exception, string message) {`
`54`	`54`	`log.Error(message, exception: exception);`
`55`	`55`	`}`
`56`	`56`
`57`	`57`	`public static void FormattedError(this IExceptionlessLog log, Exception exception, string format, params object[] args) {`
`58`		`- log.Error(String.Format(format, args), exception: exception);`
	`58`	`+ log.Error(GetMessage(format, args), exception: exception);`
`59`	`59`	`}`
`60`	`60`
`61`	`61`	`public static void FormattedError(this IExceptionlessLog log, string format, params object[] args) {`
`62`		`- log.Error(String.Format(format, args));`
	`62`	`+ log.Error(GetMessage(format, args));`
`63`	`63`	`}`
`64`	`64`
`65`	`65`	`public static void FormattedInfo(this IExceptionlessLog log, string format, params object[] args) {`
`66`		`- log.Info(String.Format(format, args));`
	`66`	`+ log.Info(GetMessage(format, args));`
`67`	`67`	`}`
`68`	`68`
`69`	`69`	`public static void FormattedDebug(this IExceptionlessLog log, string format, params object[] args) {`
`70`		`- log.Debug(String.Format(format, args));`
	`70`	`+ log.Debug(GetMessage(format, args));`
`71`	`71`	`}`
`72`	`72`
`73`	`73`	`public static void FormattedWarn(this IExceptionlessLog log, string format, params object[] args) {`
`74`		`- log.Warn(String.Format(format, args));`
	`74`	`+ log.Warn(GetMessage(format, args));`
`75`	`75`	`}`
`76`	`76`
`77`	`77`	`private static string GetSourceName(Type type) {`
`78`	`78`	`return type.Name;`
`79`	`79`	`}`
	`80`	`+`
	`81`	`+ private static string GetMessage(string format, params object[] args) {`
	`82`	`+ try {`
	`83`	`+ return String.Format(format, args);`
	`84`	`+ } catch (Exception) {`
	`85`	`+ return format;`
	`86`	`+ }`
	`87`	`+ }`
`80`	`88`	`}`
`81`	`89`	`}`
Original file line number	Diff line number	Diff line change
`@@ -48,7 +48,7 @@`
`48`	`48`	`"define": [ "NET45" ]`
`49`	`49`	`},`
`50`	`50`	`"dependencies": {`
`51`		`- "NLog": "4.3.6"`
	`51`	`+ "NLog": "4.3.8"`
`52`	`52`	`}`
`53`	`53`	`}`
`54`	`54`	`}`