locked
We migrated from Self-hosted to OWIN, then FATAL error System.IndexOutOfRangeException RRS feed

  • Question

  • User2082812578 posted

    Hi,

    We had Self-hosted Web API with log4net logging handler. Then we migrated to OWIN and add one LoggingMiddleware wiht log4net and deploy to PROD

    One hour API was working ok, but after we got FATAL error

    [Logentries Log Appender] FATAL Topshelf.Runtime.Windows.WindowsServiceHost The service threw an unhandled exception 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.SyncTextWriter.Write(Char[] buffer, Int32 index, Int32 count)
    at Microsoft.Owin.Hosting.Tracing.DualWriter.Write(Char[] buffer, Int32 index, Int32 count)
    at System.IO.TextWriter.WriteLine(String value)
    at System.Diagnostics.TextWriterTraceListener.WriteLine(String message)
    at System.Diagnostics.TraceInternal.WriteLine(String message)
    at LogentriesCore.Net.AsyncLogger.WriteDebugMessages(String message)
    at LogentriesCore.Net.AsyncLogger.Run()
    at System.Threading.ThreadHelper.ThreadStart_Context(Object state)
    at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
    at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
    at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
    at System.Threading.ThreadHelper.ThreadStart()

    INFO XXXXXService ClientAPI TcpConnection closed:

    Received bytes: 539304, Sent bytes: 127013
    Send calls: 491, callbacks: 491
    Receive calls: 549, callbacks: 549
    Close reason: [Success] Socket closed

    And then our API didn't response and every time we have error in log:

    ERROR XXXX.WebApi.Host Exception thrown by subscription callback

    Exception:

    System.AggregateException: One or more errors occurred. ---> Microsoft.Practices.Unity.ResolutionFailedException: Resolution of the dependency failed, type = "YYYYYYYYYYYYY", name = "(none)".
    Exception occurred while: while resolving.
    Exception is: InvalidOperationException - The current type, ZZZZZZZZZZZZZZZZZ, is an interface and cannot be constructed. Are you missing a type mapping?

    ---> System.InvalidOperationException: The current type, XXXXXXXXXXXX, is an interface and cannot be constructed. Are you missing a type mapping?

    at Microsoft.Practices.ObjectBuilder2.DynamicMethodConstructorStrategy.ThrowForAttemptingToConstructInterface(IBuilderContext context)
    at lambda_method(Closure , IBuilderContext )
    at Microsoft.Practices.ObjectBuilder2.DynamicBuildPlanGenerationContext.<>c__DisplayClass1.<GetBuildMethod>b__0(IBuilderContext context)
    at Microsoft.Practices.ObjectBuilder2.DynamicMethodBuildPlan.BuildUp(IBuilderContext context)
    at Microsoft.Practices.ObjectBuilder2.BuildPlanStrategy.PreBuildUp(IBuilderContext context)
    at Microsoft.Practices.ObjectBuilder2.StrategyChain.ExecuteBuildUp(IBuilderContext context)
    at Microsoft.Practices.ObjectBuilder2.BuilderContext.NewBuildUp(NamedTypeBuildKey newBuildKey)
    at Microsoft.Practices.Unity.ObjectBuilder.NamedTypeDependencyResolverPolicy.Resolve(IBuilderContext context)
    at lambda_method(Closure , IBuilderContext )
    at Microsoft.Practices.ObjectBuilder2.DynamicBuildPlanGenerationContext.<>c__DisplayClass1.<GetBuildMethod>b__0(IBuilderContext context)
    at Microsoft.Practices.ObjectBuilder2.DynamicMethodBuildPlan.BuildUp(IBuilderContext context)
    at Microsoft.Practices.ObjectBuilder2.BuildPlanStrategy.PreBuildUp(IBuilderContext context)
    at Microsoft.Practices.ObjectBuilder2.StrategyChain.ExecuteBuildUp(IBuilderContext context)
    at Microsoft.Practices.ObjectBuilder2.BuilderContext.NewBuildUp(NamedTypeBuildKey newBuildKey)
    at Microsoft.Practices.Unity.ObjectBuilder.NamedTypeDependencyResolverPolicy.Resolve(IBuilderContext context)
    at lambda_method(Closure , IBuilderContext )
    at Microsoft.Practices.ObjectBuilder2.DynamicBuildPlanGenerationContext.<>c__DisplayClass1.<GetBuildMethod>b__0(IBuilderContext context)
    at Microsoft.Practices.ObjectBuilder2.DynamicMethodBuildPlan.BuildUp(IBuilderContext context)
    at Microsoft.Practices.ObjectBuilder2.BuildPlanStrategy.PreBuildUp(IBuilderContext context)
    at Microsoft.Practices.ObjectBuilder2.StrategyChain.ExecuteBuildUp(IBuilderContext context)
    at Microsoft.Practices.Unity.UnityContainer.DoBuildUp(Type t, Object existing, String name, IEnumerable`1 resolverOverrides)
    --- End of inner exception stack trace ---
    at Microsoft.Practices.Unity.UnityContainer.DoBuildUp(Type t, Object existing, String name, IEnumerable`1 resolverOverrides)
    at Microsoft.Practices.Unity.UnityContainer.Resolve(Type t, String name, ResolverOverride[] resolverOverrides)
    at Microsoft.Practices.Unity.UnityContainerExtensions.Resolve[T](IUnityContainer container, ResolverOverride[] overrides)

    Friday, September 9, 2016 12:33 PM

Answers

All replies

  • User-782232518 posted

    The first exception shows a coding issue (bad code for multithreading),

    at LogentriesCore.Net.AsyncLogger.WriteDebugMessages(String message)
    at LogentriesCore.Net.AsyncLogger.Run()

    while the second shows a wrong Unity configuration. Based on the exception messages and call stacks, none of them shows any relationship to OWIN yet. You'd better debug your own code carefully in VS.

    Sunday, September 11, 2016 1:12 PM
  • User36583972 posted

    Hi olegmkr,

    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

    It means - your Thread is not thread safe and breaks when accessed from several threads. You need to make your thread safe or find a way to ensure that only one thread accesses any particular instance.

    One way to make them thread safe is to use a synchronized queue and make all your calls enqueue data items to the queue.

    You can catch all unhandled exceptions in ASP.NET Web Api and to find out which code cause your error.

    Create one or more implementations of IExceptionLogger:

    public class TraceExceptionLogger : ExceptionLogger
    {
        public override void Log(ExceptionLoggerContext context)
        {
            Trace.TraceError(context.ExceptionContext.Exception.ToString());
        }
    }

    Register inside config file:

     config.Services.Add(typeof(IExceptionLogger), new TraceExceptionLogger());
    

    Best regards,

    Yohann Lu

    Monday, September 12, 2016 6:32 AM
  • User2082812578 posted

    Hi,

    How to imitate exception to test this handler http://www.asp.net/web-api/overview/error-handling/web-api-global-error-handling?

    I e.g. write this code in first middleware:

    int i = 0;
    int j = 1 / i;

    with fiddler I get HTTP/1.1 500 Internal Server Error, but I couldn't catch with global handler. 

    In Visual studio debug mode in output tab I see

    Exception thrown: 'System.DivideByZeroException' in XXXX.dll
    Exception thrown: 'System.DivideByZeroException' in mscorlib.dll

    Could somebody help me? As I understood, global exception handler doesn't handle exceptions in middleware :(

    Monday, September 19, 2016 10:51 AM
  • User36583972 posted

    Hi olegmkr,

    Your thread is not thread safe and breaks when accessed from several threads. You need to make your thread safe or find a way to ensure that only one thread accesses any particular instance.

    You may can use the lock keyword for your sensitive resources.

      lock (your objects)
        {
            // Access thread-sensitive resources.
        }

    please debug your code to find which code causes the error. You could also share us more relevant code to help us reproduce the problem.

    Best Regards,

    Yohann Lu

    Tuesday, September 20, 2016 10:00 AM
  • User2082812578 posted

    Hi,

    Problem with internal debug https://github.com/rapid7/le_dotnet/blob/1b2443a581a6f1a877bf90f472a44eaf5ffe0fa5/src/LogentriesCore/AsyncLogger.cs#L596

    When we changed debug to false appender works.

    Oleg

    • Marked as answer by Anonymous Thursday, October 7, 2021 12:00 AM
    Wednesday, September 21, 2016 9:16 AM