Probable I/O race condition detected while copying memory

[anhhnguyen206]

Describe the bug
Today we noticed this error message went through our logging system:

Unhandled exception while executing task: System.IndexOutOfRangeException: Probable I/O race condition detected while copying memory. The I/O package is not thread safe by default. In multithreaded applications, a stream must be accessed in a thread-safe way, such as a thread-safe wrapper returned by TextReader's or TextWriter's Synchronized methods. This also applies to classes like StreamWriter and StreamReader. at System.Buffer.InternalBlockCopy(Array src, Int32 srcOffsetBytes, Array dst, Int32 dstOffsetBytes, Int32 byteCount) at System.IO.StreamWriter.Write(Char[] buffer, Int32 index, Int32 count) at System.IO.TextWriter.WriteLine(String value) at System.IO.TextWriter.SyncTextWriter.WriteLine(String value) at Microsoft.Azure.WebJobs.Host.CompositeTraceWriter.InvokeTextWriter(TraceEvent traceEvent) at Microsoft.Azure.WebJobs.Host.ConsoleTraceWriter.InvokeTextWriter(TraceEvent traceEvent) at Microsoft.Azure.WebJobs.Host.CompositeTraceWriter.Trace(TraceEvent traceEvent) at Microsoft.Azure.WebJobs.Host.Loggers.TraceWriterFunctionInstanceLogger.LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken) at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.<TryExecuteAsync>d__13.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.Azure.WebJobs.Host.Executors.TriggeredFunctionExecutor1.d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.Azure.WebJobs.Extensions.DurableTask.TaskActivityShim.d__4.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at DurableTask.Core.TaskActivityDispatcher.<>c__DisplayClass12_1.<b__1>d.MoveNext()
at System.Buffer.InternalBlockCopy(Array src, Int32 srcOffsetBytes, Array dst, Int32 dstOffsetBytes, Int32 byteCount)
at System.IO.StreamWriter.Write(Char[] buffer, Int32 index, Int32 count)
at System.IO.TextWriter.WriteLine(String value)
at System.IO.TextWriter.SyncTextWriter.WriteLine(String value)
at Microsoft.Azure.WebJobs.Host.CompositeTraceWriter.InvokeTextWriter(TraceEvent traceEvent)
at Microsoft.Azure.WebJobs.Host.ConsoleTraceWriter.InvokeTextWriter(TraceEvent traceEvent)
at Microsoft.Azure.WebJobs.Host.CompositeTraceWriter.Trace(TraceEvent traceEvent)
at Microsoft.Azure.WebJobs.Host.Loggers.TraceWriterFunctionInstanceLogger.LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.d__13.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.Azure.WebJobs.Host.Executors.TriggeredFunctionExecutor1.<TryExecuteAsync>d__6.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.Azure.WebJobs.Extensions.DurableTask.TaskActivityShim.<RunAsync>d__4.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at DurableTask.Core.TaskActivityDispatcher.<>c__DisplayClass12_1.<<OnProcessWorkItemAsync>b__1>d.MoveNext()

Right after this our function gets into a funky state where nothing appear to work until we restart our function app. We couldn't make call to normal HttpTrigger as well.

I've been doing a little bit of digging myself and found a similar issue at: Azure/azure-webjobs-sdk#1533 . Note that there were 2 attempts to fix the issue: first attempt went to 2.2.0 release, but then some reported it's still an issue, second attempt then went to 2.3.0 release (i assumed).

I attempted to install webjobs sdk 2.3.0 via nuget to see if I can resolve the problem, but Microsoft.NET.Sdk.Function complain about it couldn't find webjobs 2.2.0 so perhaps this 2.2.0 dependency is locked?

'System.IO.FileNotFoundException: Could not load file or assembly 'Microsoft.Azure.WebJobs, Version=2.2.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35' or one of its dependencies. The system cannot find the file specified.
File name: 'Microsoft.Azure.WebJobs, Version=2.2.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35'
at System.ModuleHandle.ResolveType(RuntimeModule module, Int32 typeToken, IntPtr* typeInstArgs, Int32 typeInstCount, IntPtr* methodInstArgs, Int32 methodInstCount, ObjectHandleOnStack type)
at System.ModuleHandle.ResolveTypeHandleInternal(RuntimeModule module, Int32 typeToken, RuntimeTypeHandle[] typeInstantiationContext, RuntimeTypeHandle[] methodInstantiationContext)
at System.Reflection.RuntimeModule.ResolveType(Int32 metadataToken, Type[] genericTypeArguments, Type[] genericMethodArguments)
at System.Reflection.CustomAttribute.FilterCustomAttributeRecord(CustomAttributeRecord caRecord, MetadataImport scope, Assembly& lastAptcaOkAssembly, RuntimeModule decoratedModule, MetadataToken decoratedToken, RuntimeType attributeFilterType, Boolean mustBeInheritable, Object[] attributes, IList derivedAttributes, RuntimeType& attributeType, IRuntimeMethodInfo& ctor, Boolean& ctorHasParameters, Boolean& isVarArg)
at System.Reflection.CustomAttribute.GetCustomAttributes(RuntimeModule decoratedModule, Int32 decoratedMetadataToken, Int32 pcaCount, RuntimeType attributeFilterType, Boolean mustBeInheritable, IList derivedAttributes, Boolean isDecoratedTargetSecurityTransparent)
at System.Reflection.CustomAttribute.GetCustomAttributes(RuntimeType type, RuntimeType caType, Boolean inherit)
at System.Attribute.InternalGetAttributeUsage(Type type)
at System.Attribute.InternalParamGetCustomAttributes(ParameterInfo param, Type type, Boolean inherit)
at MakeFunctionJson.ParameterInfoExtensions.GetDisabledAttribute(ParameterInfo parameterInfo)
at System.Linq.Enumerable.WhereSelectArrayIterator2.MoveNext() at System.Linq.Enumerable.WhereEnumerableIterator1.MoveNext()
at System.Linq.Enumerable.FirstOrDefault[TSource](IEnumerable1 source) at MakeFunctionJson.MethodInfoExtensions.GetDisabled(MethodInfo method) at MakeFunctionJson.MethodInfoExtensions.HasUnsuportedAttributes(MethodInfo method, String& error) at MakeFunctionJson.FunctionJsonConverter.<GenerateFunctions>d__9.MoveNext() at System.Collections.Generic.List1..ctor(IEnumerable1 collection) at System.Linq.Enumerable.ToList[TSource](IEnumerable1 source)
at MakeFunctionJson.FunctionJsonConverter.TryGenerateFunctionJsons()
at MakeFunctionJson.FunctionJsonConverter.TryRun()'

Investigative information

• Durable Functions extension version: 1.7.1
• Function App version (1.0 or 2.0): 1.0
• Programming language used: C#

If JavaScript

• durable-functions npm module version:

If deployed to Azure

• Timeframe issue observed: 2019-04-05T19:12:46.799Z
• Function App name:
• Function name(s):
• Region: east-us
• Orchestration instance ID(s): c37538098b2e4a2c8ecf9d2ef5ddce87:2

If you don't want to share your Function App name or Functions names on GitHub, please be sure to provide your Invocation ID, Timestamp, and Region - we can use this to look up your Function App/Function. Provide an invocation id per Function. See the Functions Host wiki for more details.

To Reproduce
Steps to reproduce the behavior:

1. It's hard to reproduce but we saw this error pop up in our logging right before our function app gets into a funky state and appear to be not working until we restart the function app from portal.azure.com.

2. It also looks like it has something to do with logging - from the stack trace.

While not required, providing your orchestrator's source code in anonymized form is often very helpful when investigating unexpected orchestrator behavior.

Expected behavior
ILogger should not throw exception.

Actual behavior
ILogger sometimes throw a concurrency error.

Screenshots
If applicable, add screenshots to help explain your problem.

Known workarounds
Provide a description of any known workarounds you used.

Additional context

• Development environment (ex. Visual Studio)
• Links to source
• Additional bindings used
• Function invocation IDs

[dsm0880]

There is a fix in Azure WebJobs 2,3.0 but this library is set to use only 2.2.x it appears. Anyway you can upgrade to 2.3.0? It's completely crashing our app each time this occurs.

[cgillum]

I'm opening a separate issue to track updating our webjobs dependency, since it sounds like that will resolve the issue: #771