Bug 18629

Summary: Exception.ToString() crashes with NullReferenceException
Product: iOS Reporter: Jahmai <jahmai>
Component: Xamarin.iOS.dllAssignee: Zoltan Varga <vargaz>
Status: RESOLVED FIXED    
Severity: normal CC: garakul93, jahmai, masafa, mono-bugs+monotouch, rolf, sadika, tj
Priority: Normal    
Version: 7.2.0   
Target Milestone: 8.13 (C6 alpha)   
Hardware: PC   
OS: Windows   
Tags: Is this bug a regression?: ---
Last known good build:
Bug Depends on: 24647    
Bug Blocks:    
Attachments: Reproduction project for iOS

Description Jahmai 2014-03-28 03:53:30 UTC
Rarely, I get a NullReferenceException when calling ToString() on an exception.

Example stack:

Thread : Crashed: com.apple.root.default-overcommit-priority 
0 OmniGuard 0x002f580c mscorlib__System_Exception_AddFrames_System_Text_StringBuilder_string_string_System_Diagnostics_StackTrace 
1 OmniGuard 0x002f56bc mscorlib__System_Exception_get_StackTrace 
2 OmniGuard 0x002f56bc mscorlib__System_Exception_get_StackTrace 
3 OmniGuard 0x002f5d00 mscorlib__System_Exception_ToString 
4 OmniGuard 0x002f5cc0 mscorlib__System_Exception_ToString 
5 OmniGuard 0x003776f8 System_AggregateException_ToString_0 (AggregateException.cs:281) 
6 OmniGuard 0x003092d0 mscorlib__string_FormatHelper_System_Text_StringBuilder_System_IFormatProvider_string_object__ 
7 OmniGuard 0x00308f88 p_154_plt_string_Format_System_IFormatProvider_string_object___llvm 
8 OmniGuard 0x00201d74 Intrinsic_Core__Intrinsic_Diagnostics_Tracer_Critical_string_object__ 
9 OmniGuard 0x0014554c CriticalArc_Core__CriticalArc_OmniGuard_OmniGuardApplication_OnTaskSchedulerUnobservedTaskException_object_System_Threading_Tasks_UnobservedTaskExceptionEventArgs
10 OmniGuard 0x002d846c mscorlib__System_Threading_Tasks_TaskScheduler_FireUnobservedEvent_System_Threading_Tasks_Task_System_AggregateException
11 OmniGuard 0x00373fe4 System_Threading_Tasks_TaskExceptionSlot_Finalize_0 (TaskExceptionSlot.cs:105) 
12 OmniGuard 0x003c5a98 wrapper_runtime_invoke_object_runtime_invoke_virtual_void__this___object_intptr_intptr_intptr_0 
13 OmniGuard 0x0095781f mono_gc_run_finalize (gc.c:218) 
14 OmniGuard 0x009bdb05 GC_invoke_finalizers (finalize.c:880) 
15 OmniGuard 0x0093f869 mono_gc_invoke_finalizers (boehm-gc.c:597) 
16 OmniGuard 0x009587a5 finalizer_thread (gc.c:1102) 
17 OmniGuard 0x0099028d start_wrapper (threads.c:609) 
18 OmniGuard 0x009a63eb thread_start_routine (wthreads.c:294) 
19 OmniGuard 0x009ae4e5 inner_start_thread (mono-threads-posix.c:49) 
20 OmniGuard 0x009c37f3 GC_start_routine (pthread_support.c:1502) 
21 libsystem_pthread.dylib 0x3935dc1d _pthread_body + 140 
22 libsystem_pthread.dylib 0x3935db8f _pthread_start + 102

Our code in the stack there is logging the exception, and therefore calling ToString().

I looked into this a bit myself, and I believe the it is occurring because the StackTrace parameter of AddFrames(...) is null.

My theory of how this happens is as follows;

In Exception.StackTrace.get:

        if (this.captured_traces != null)
        {
          foreach (StackTrace st in this.captured_traces)
          {
            if (this.AddFrames(sb, newline, text, st))
            {
              sb.Append(Environment.NewLine);
              sb.Append("--- End of stack trace from previous location where exception was thrown ---");
              sb.Append(Environment.NewLine);
            }
          }
        }

Note the enumeration of this.captured_traces, which is initialized from Exception.CaptureTrace():

    internal void CaptureTrace()
    {
      if (this.captured_traces != null)
        Array.Resize<StackTrace>(ref this.captured_traces, this.captured_traces.Length + 1);
      else
        this.captured_traces = new StackTrace[1];
// [1]
      this.captured_traces[this.captured_traces.Length - 1] = new StackTrace(this, 0, true, true);
      this.trace_ips = (IntPtr[]) null;
    }

Which is called by ExceptionDispatchInfo.Throw():

    public void Throw()
    {
      this.exception.CaptureTrace();
      throw this.exception;
    }

Which seems to be called by every 'await' on a faulted Task.

In our codebase, we share Task's between threads, therefore multiple threads can 'await' on the same faulted Task that contains the same exception instance.

I think that multiple threads are calling Exception.CaptureTrace() on the same exception concurrently, causing this.capture_traces to be resized multiple times at [1], but both threads only set the last element (this.captured_traces.Length - 1) of the array to a StackFrame instance, meaning there is an uninitialized (null) element at this.captured_traces.Length - 2.

I think the solution to this is the make CaptureTrace() thread safe.
Comment 1 Sadik Ali 2014-04-02 03:45:01 UTC
I have tried to reproduce this issue I followed below steps:

1. Created A console project.
2. added below code to generate NullReferenceException exception.

String value = null;
try{
    if (value.Length == 0) {
        Console.WriteLine (value);
    }
}
catch(NullReferenceException ex ){
	Console.WriteLine ("Trace "+ex.StackTrace);
	ex.ToString ();  
} 

3. I debug above code but unable to reproduce this issue.

Please provide some sample code or steps so that I can verify this issue.

Screen cast: http://www.screencast.com/t/oLFg8CMK

Build Info:

=== Xamarin Studio ===
Version 4.2.3 (build 60)

=== Build Information ===
Release ID: 402030060
30c4afc300c2a39ec5300851357ce02e49dd217e
Xamarin addins: f8a9589b57c2bfab2ccd73c880e7ad81e3ecf044

=== Operating System ===
Windows 6.1.7601.65536 (64-bit)
Comment 2 Jahmai 2014-04-02 03:49:19 UTC
I'm pretty sure you misunderstood the issue.
It has nothing to do with catching a NullReferenceException.

The issue is Excepion.ToString() is generating a NullReferenceException in multithreaded scenarios.

I'll attach a project shortly.
Comment 3 Jahmai 2014-04-02 04:14:33 UTC
Created attachment 6454 [details]
Reproduction project for iOS

Ok I have attached a reproduction project for iOS.

This can be reproduced in the simulator quite easily.

The application will automatically break in the debugger once the NullReferenceException is triggered.
Comment 4 Jahmai 2014-04-02 04:14:59 UTC
Changing to in progress as I have attached repro.
Comment 5 Jahmai 2014-04-02 04:23:44 UTC
Actually perhaps this needs to be CONFIRMED status. I am confused :S
Comment 6 Sadik Ali 2014-04-02 05:07:59 UTC
I have checked this issue with attached project and noticed that Exception.ToString() crashed with NullReferenceException
Comment 7 Rolf Bjarne Kvinge [MSFT] 2014-04-02 13:31:42 UTC
Zoltan, this looks related to your commit:

https://github.com/mono/mono/commit/b867b4e2c8e74da7a9a6472f2bfa3d22e5f3e8dd
Comment 8 Jahmai 2014-11-18 04:41:11 UTC
Any progress on this? It is still happening for us and we have had to disable exception logging to work around it.
Comment 9 Zoltan Varga 2014-11-18 17:36:56 UTC
This looks like a race in Exception.CaptureTrace (), which is called by two ExceptionDispatchInfo () instances at the same time.
Comment 10 Zoltan Varga 2014-11-18 18:56:15 UTC
Mareks, this seems to be a problem with the code in TaskAwaiter.GetResult ():

	ExceptionDispatchInfo.Capture (HandleUnexpectedTaskResult (task)).Throw ();

This code is not thread safe, since it modifies the exception stored in ExceptionDispatchInfo, and that exception is shared between the threads which call GetResult (). Also, every time this is called, we are appending one set of stack traces to the exception. MS seems to replace the last trace with a new one, i.e.:

The testcase below prints:

System.Exception: Exception of type 'System.Exception' was thrown.
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Tests.<Main>c__AnonStorey7.<Main>c__async6.MoveNext()
System.Exception: Exception of type 'System.Exception' was thrown.
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Tests.<foo>c__async0.MoveNext()

While with mono, it prints:

System.Exception: Exception of type 'System.Exception' was thrown.
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x00000] in <filename unknown>:0 
  at System.Runtime.CompilerServices.TaskAwaiter`1[System.Object].GetResult () [0x00000] in <filename unknown>:0 
  at Tests+<Main>c__AnonStorey7+<Main>c__async6.MoveNext () [0x00000] in <filename unknown>:0 
System.Exception: Exception of type 'System.Exception' was thrown.
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x00000] in <filename unknown>:0 
  at System.Runtime.CompilerServices.TaskAwaiter`1[System.Object].GetResult () [0x00000] in <filename unknown>:0 
  at Tests+<Main>c__AnonStorey7+<Main>c__async6.MoveNext () [0x00000] in <filename unknown>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x00000] in <filename unknown>:0 
  at System.Runtime.CompilerServices.TaskAwaiter`1[System.Object].GetResult () [0x00000] in <filename unknown>:0 
  at Tests+<foo>c__async0.MoveNext () [0x00000] in <filename unknown>:0 

<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
using System;
using System.Diagnostics;
using System.Reflection;
using System.Threading.Tasks;
using System.Runtime.ExceptionServices;

public class Tests
{
	public static void Main (String[] args) {
		TaskCompletionSource<object> faultedSource = new TaskCompletionSource<object>();

		faultedSource.SetException(new Exception());

		Task.Run(async () =>
            {
				try
                    {
                        await faultedSource.Task;
                    }
                    catch (Exception ex)
                    {
						Console.WriteLine (ex);
					}
				foo (faultedSource);
			});

		Console.ReadLine ();
	}

		static async void foo (TaskCompletionSource<object> faultedSource) {
				try
                    {
                        await faultedSource.Task;
                    }
                    catch (Exception ex)
                    {
						Console.WriteLine (ex);
					}
	}
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
Comment 11 T.J. Purtell 2015-03-13 18:50:01 UTC
Having unreliable exception logging is quite troublesome :(.  Hitting this on Android and iOS with latest versions 4.20 / 8.8.
Comment 12 Marek Safar 2015-04-08 03:49:53 UTC
The race was fixed in master/mono 4.0. Bad stack trace is duplicate of #24647
Comment 13 Jahmai 2015-07-31 01:04:01 UTC
This is still broken in Xamarin.iOS 8.10.3. Unclear whether the fix is supposed to be included in this release.
Comment 14 Rolf Bjarne Kvinge [MSFT] 2015-07-31 04:16:35 UTC
@Marek, can you give the mono hash where this was fixed? That'll allow me to tell which XI version will have the fix.
Comment 15 Marek Safar 2015-07-31 08:03:21 UTC
@rolf, it was not single commit. The changes came from reference sources import. However, anything newer than ff9226422d8fa44ca9718065baae437c3ddeacd0 should work
Comment 16 Rolf Bjarne Kvinge [MSFT] 2015-07-31 09:18:10 UTC
@Jahmai, this will be fixed in Xamarin.iOS 8.12.
Comment 17 Jahmai 2015-07-31 09:20:49 UTC
Thanks, Rolf.
Comment 18 Artem 2017-01-24 08:15:51 UTC
Seems to be reproduced in Xamarin.iOS 9.8.2.22.

Stacktrace:

Warning: Unhandled exception: System.NullReferenceException: Object reference not set to an instance of an object
  at System.Exception.ToString () <0x100aa5e24 + 0x000dc> in <filename unknown>:0 
  at System.AggregateException.ToString () <0x10095d450 + 0x00027> in <filename unknown>:0 
  at System.Text.StringBuilder.AppendFormatHelper (IFormatProvider provider, System.String format, ParamsArray args) <0x100a20e9c + 0x0059f> in <filename unknown>:0 
  at System.String.FormatHelper (IFormatProvider provider, System.String format, ParamsArray args) <0x100a131dc + 0x0005b> in <filename unknown>:0 
  at System.String.Format (System.String format, System.Object[] args) <0x100a12fc4 + 0x0003f> in <filename unknown>:0 
  at News.Logging.LoggerImpl.News.Logging.ILogger.Debug (System.String format, System.Object[] args) <0x10073d3b8 + 0x0001f> in <filename unknown>:0 
  at News.UpdateService+<PerformUpdateWithTimerReschedulingAsync>c__async3.MoveNext () <0x1008a8fa0 + 0x006ff> in <filename unknown>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.CompilerServices.AsyncMethodBuilderCore.<ThrowAsync>m__1 (System.Object state) <0x1009dfdc0 + 0x00050> in <filename unknown>:0 
  at System.Threading.QueueUserWorkItemCallback.WaitCallback_Context (System.Object state) <0x100a42970 + 0x00043> in <filename unknown>:0 
  at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, Boolean preserveSyncCtx) <0x100a40154 + 0x00217> in <filename unknown>:0 
  at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem () <0x100a42914 + 0x00033> in <filename unknown>:0 
  at System.Threading.ThreadPoolWorkQueue.Dispatch () <0x100b5c540 + 0x001df> in <filename unknown>:0 
  at ObjCRuntime.Runtime.ThreadPoolDispatcher (System.Func`1 callback) <0x101560a90 + 0x0003b> in <filename unknown>:0 
  at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback () <0x100a42784 + 0x00077> in <filename unknown>:0
Comment 19 Rolf Bjarne Kvinge [MSFT] 2017-01-24 09:15:37 UTC
@Artem, this is an old bug, so please open a new bug and attach a project we can use to reproduce this, and we'll have a look.