Occasional "item with the same key has been added" exceptions in Microsoft.ApplicationInsights.NLogTarget.ApplicationInsightsTarget.BuildPropertyBag

[ericjmooney]

I have noted the following exception to occur from within some web jobs (and therefore causing them to die) when a particular logging path takes place. I'm still trying to figure out exactly what is causing this path, but I believe that the BuildPropertyBag shouldn't cause an unhandled exception that crashes my web job.
Note that this occurs sometimes in the midst of otherwise normal logging (including Exceptions, Traces, etc).

Thank you!

[05/02/2016 21:14:30 > 2d9624: ERR ] Unhandled Exception: System.ArgumentException: An item with the same key has already been added. [05/02/2016 21:14:30 > 2d9624: ERR ] at System.ThrowHelper.ThrowArgumentException(ExceptionResource resource) [05/02/2016 21:14:30 > 2d9624: ERR ] at System.Collections.Generic.Dictionary``2.Insert(TKey key, TValue value, Boolean add) [05/02/2016 21:14:30 > 2d9624: ERR ] at System.Collections.Generic.Dictionary``2.Add(TKey key, TValue value) [05/02/2016 21:14:30 > 2d9624: ERR ] at Microsoft.ApplicationInsights.NLogTarget.ApplicationInsightsTarget.BuildPropertyBag(LogEventInfo logEvent, ITelemetry trace) [05/02/2016 21:14:30 > 2d9624: ERR ] at Microsoft.ApplicationInsights.NLogTarget.ApplicationInsightsTarget.SendException(LogEventInfo logEvent) [05/02/2016 21:14:30 > 2d9624: ERR ] at Microsoft.ApplicationInsights.NLogTarget.ApplicationInsightsTarget.Write(LogEventInfo logEvent) [05/02/2016 21:14:30 > 2d9624: ERR ] at NLog.Targets.Target.Write(AsyncLogEventInfo logEvent) [05/02/2016 21:14:30 > 2d9624: ERR ] at NLog.Targets.Target.Write(AsyncLogEventInfo[] logEvents) [05/02/2016 21:14:30 > 2d9624: ERR ] at NLog.Targets.Target.WriteAsyncLogEvents(AsyncLogEventInfo[] logEvents) [05/02/2016 21:14:30 > 2d9624: ERR ] at NLog.Targets.Wrappers.AsyncTargetWrapper.ProcessPendingEvents(Object state) [05/02/2016 21:14:30 > 2d9624: ERR ] at System.Threading.TimerQueueTimer.CallCallbackInContext(Object state) [05/02/2016 21:14:30 > 2d9624: ERR ] at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx) [05/02/2016 21:14:30 > 2d9624: ERR ] at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx) [05/02/2016 21:14:30 > 2d9624: ERR ] at System.Threading.TimerQueueTimer.CallCallback() [05/02/2016 21:14:30 > 2d9624: ERR ] at System.Threading.TimerQueueTimer.Fire() [05/02/2016 21:14:30 > 2d9624: ERR ] at System.Threading.TimerQueue.FireQueuedTimerCompletion(Object state) [05/02/2016 21:14:30 > 2d9624: ERR ] at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem() [05/02/2016 21:14:30 > 2d9624: ERR ] at System.Threading.ThreadPoolWorkQueue.Dispatch() [05/02/2016 21:14:30 > 2d9624: ERR ] at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback()

[abaranch]

Thank you for reporting the issue. We will investigate to fix.

[ericjmooney]

Doing some more research on this issue...when this problem occurs it is because the LogEventInfo parameter that is passed into BuildPropertyBag has a property "LoggerName" in its Properties collection (as well as having the same string value defined in its actual .LoggerName property). I cannot figure out why this happens (and why it only happens intermittently) but the exception then occurs in the foreach loop (around line 168 in ApplicationInsightsTargets.cs) when the propertyBag.Add is called as it has already added LoggerName back on line 149 or so.

[abaranch]

Pull request is accepted. Thank you for your contribution.
We plan to release it in the beginning of June when we'll update to the new Core SDK (which we ship this month).