search

dotnet / android

.NET for Android provides open-source bindings of the Android SDK for use with .NET managed languages such as C#
MIT License
1.94k stars 533 forks source link

.NET 6 app crashes on start in Debug mode #6961

Closed jonathanpeppers closed 2 years ago

jonathanpeppers commented 2 years ago

Android application type

Android for .NET (net6.0-android, etc.)

Affected platform version

.NET 6 / MAUI RC 1

Description

From @RedChops here: https://github.com/dotnet/maui/issues/6460#issuecomment-1108713166

I can't get any iteration of HttpClient working (managed or native). Native crashes the app immediately on launch, Managed acts incredibly strangely. It appears to crash from a NullReferenceException, but sometimes it crashes silently, causing all code that would otherwise use the result of SendAsync to be skipped.

For example:

  1. var result = await client.SendAsync(...);
  2. var content = await result.Content.ReadAsStringAsync()
  3. [something else]

If I set a breakpoint on line 2, that breakpoint will get skipped and code will continue to execute on line 3, causing both result and content to be null.

I spent a large part of the day uninstalling all VS versions, clearing out the dotnet folder of all SDKs, reinstalling everything, etc, so everything should be clean and at the latest version.

Steps to Reproduce

I've attached here a small reproduction project.

NetworkTest.zip

Did you find any workaround?

No

Relevant log output

The first is AndroidClientHandler.adb.txt which is the output from using the Android HttpClient.

The second is HttpClientHandler.adb.txt. This of course includes the output from the AndroidClientHandler log since it's the same emulator boot.

Both of these logs were generated off that sample project which I created fresh specifically for this bug, so there shouldn't be anything else weird going on there. They also both were run in Debug mode with <RunAOTCompilation>False</RunAOTCompilation> set in the csproj.

RedChops commented 2 years ago

I can also reproduce this in a pure Xamarin Android project, but it's a little more difficult. The app doesn't crash on the first request, but it will crash on the second. Adb log here: adb.txt

The specific workflow here is a request is made to an auth token generator (request succeeds), a link is sent to the email address which contains a deep link to the app. When the deep link is entered, the uri is processed and a second request is made to get user details. This second request fails.

RedChops commented 2 years ago

This issue seems to be one expressly of timing.

My situation: On app start, auth needs to initialize. If a user is signed in but their access token is expired, that token needs to be refreshed via network request.

Since I'm most familiar with Forms/MAUI, I'll have to describe the scenarios in terms of them.

Failing scenario: I put the auth initialization code anywhere before MainPage is set in the Application class. This includes the Application constructor or anywhere in CreateMauiApp().

A workaround: I set a secondary "splash screen" ContentPage. In Application's OnStart override, I initialize Auth then set MainPage to the AppShell.

In the failing scenarios, I can see that the refresh network request is made in the server logs. The application never returns from this network request though, the app hangs. I'm assuming that an exception/crash is occurring somewhere down-thread, possibly in native code, and this is not getting handled anywhere. This crash is probably the one shown in the adb logs.

Ideally, I'd like to initialize Auth before setting Application's MainPage so that I don't have to show a split-second intermediate splash page, but at least I have a workaround for now.

grendello commented 2 years ago

@RedChops does it happen only when debugging the app? Or will it crash when you start its Debug build without debugger attached?

steveisok commented 2 years ago

@thaystg can you please take a look at this?

lambdageek commented 2 years ago

One thought: the sample has this in the MainPage.xaml.cs

    private static readonly HttpClient client = new HttpClient();

I wonder if there is some static constructor initialization issue here. Does the issue repro if client is a local variable in MakeRequest instead?

akoeplinger commented 2 years ago

One other thing to note is that "Managed" HttpClient doesn't make sense in .NET 6 since we only have the sockets http or the native platform handler. I think I've seen something about VS property pages needing to be updated on some Teams channel discussion.

RedChops commented 2 years ago

@grendello If I start the app without attaching the debugger (just launching it from the app drawer), it hangs completely at the native splash screen. The logs are completely full of lines like

04-26 11:30:04.044 22575 22575 W monodroid-assembly: typemap: called from
04-26 11:30:04.044 22575 22575 W monodroid-assembly: at Java.Interop.TypeManager.GetJavaToManagedType(String class_name)04-26 11:30:04.045 22575 22575 W monodroid-assembly:    at Java.Interop.TypeManager.CreateInstance(IntPtr handle, JniHandleOwnership transfer, Type targetType)
04-26 11:30:04.045 22575 22575 W monodroid-assembly:    at Java.Lang.Object.GetObject(IntPtr handle, JniHandleOwnership transfer, Type type)
04-26 11:30:04.045 22575 22575 W monodroid-assembly:    at Java.Lang.Object._GetObject[URLConnection](IntPtr handle, JniHandleOwnership transfer)
04-26 11:30:04.045 22575 22575 W monodroid-assembly:    at Java.Lang.Object.GetObject[URLConnection](IntPtr handle, JniHandleOwnership transfer)
04-26 11:30:04.045 22575 22575 W monodroid-assembly:    at Java.Net.URL.OpenConnection()
04-26 11:30:04.046 22575 22575 W monodroid-assembly:    at Xamarin.Android.Net.AndroidMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
04-26 11:30:04.046 22575 22575 W monodroid-assembly:    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[<SendAsync>d__119](<SendAsync>d__119& stateMachine)
04-26 11:30:04.046 22575 22575 W monodroid-assembly:    at Xamarin.Android.Net.AndroidMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
04-26 11:30:04.046 22575 22575 W monodroid-assembly:    at System.Net.Http.HttpClientHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
04-26 11:30:04.046 22575 22575 W monodroid-assembly:    at System.Net.Http.HttpMessageInvoker.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
04-26 11:30:04.046 22575 22575 W monodroid-assembly:    at System.Net.Http.HttpClient.<>n__0(HttpRequestMessage request, CancellationToken cancellationToken)
04-26 11:30:04.047 22575 22575 W monodroid-assembly:    at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
04-26 11:30:04.047 22575 22575 W monodroid-assembly:    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[<<SendAsync>g__Core|83_0>d](<<SendAsync>g__Core|83_0>d& stateMachine)
04-26 11:30:04.047 22575 22575 W monodroid-assembly:    at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
04-26 11:30:04.047 22575 22575 W monodroid-assembly:    at System.Net.Http.HttpClient.SendAsync(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationToken cancellationToken)
04-26 11:30:04.047 22575 22575 W monodroid-assembly:    at System.Net.Http.HttpClient.SendAsync(HttpRequestMessage request)
04-26 11:30:04.047 22575 22575 W monodroid-assembly:    at Supabase.Gotrue.Helpers.MakeRequest(HttpMethod method, String url, Object data, Dictionary`2 headers)
04-26 11:30:04.047 22575 22575 W monodroid-assembly:    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[<MakeRequest>d__7](<MakeRequest>d__7& stateMachine)
04-26 11:30:04.048 22575 22575 W monodroid-assembly:    at Supabase.Gotrue.Helpers.MakeRequest(HttpMethod method, String url, Object data, Dictionary`2 headers)
04-26 11:30:04.048 22575 22575 W monodroid-assembly:    at Supabase.Gotrue.Helpers.<MakeRequest>d__6`1[[Supabase.Gotrue.Session, Gotrue, Version=2.4.2.0, Culture=neutral, PublicKeyToken=null]].MoveNext()
04-26 11:30:04.048 22575 22575 W monodroid-assembly:    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[<MakeRequest>d__6`1](<MakeRequest>d__6`1& stateMachine)
04-26 11:30:04.048 22575 22575 W monodroid-assembly:    at Supabase.Gotrue.Helpers.MakeRequest[Session](HttpMethod method, String url, Object data, Dictionary`2 headers)
04-26 11:30:04.048 22575 22575 W monodroid-assembly:    at Supabase.Gotrue.Api.RefreshAccessToken(String refreshToken)
04-26 11:30:04.048 22575 22575 W monodroid-assembly:    at Supabase.Gotrue.Client.RefreshToken()
04-26 11:30:04.048 22575 22575 W monodroid-assembly:    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[<RefreshToken>d__70](<RefreshToken>d__70& stateMachine)
04-26 11:30:04.048 22575 22575 W monodroid-assembly:    at Supabase.Gotrue.Client.RefreshToken()
04-26 11:30:04.049 22575 22575 W monodroid-assembly:    at Supabase.Gotrue.Client.RetrieveSessionAsync()
04-26 11:30:04.049 22575 22575 W monodroid-assembly:    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[<RetrieveSessionAsync>d__67](<RetrieveSessionAsync>d__67& stateMachine)
04-26 11:30:04.049 22575 22575 W monodroid-assembly:    at Supabase.Gotrue.Client.RetrieveSessionAsync()
04-26 11:30:04.049 22575 22575 W monodroid-assembly:    at Supabase.Gotrue.Client.InitializeAsync(ClientOptions options)04-26 11:30:04.049 22575 22575 W monodroid-assembly:    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[<InitializeAsync>d__46](<InitializeAsync>d__46& stateMachine)
04-26 11:30:04.049 22575 22575 W monodroid-assembly:    at Supabase.Gotrue.Client.InitializeAsync(ClientOptions options)04-26 11:30:04.049 22575 22575 W monodroid-assembly:    at Supabase.Client.InitializeAsync(String supabaseUrl, String supabaseKey, SupabaseOptions options)
04-26 11:30:04.049 22575 22575 W monodroid-assembly:    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[<InitializeAsync>d__50](<InitializeAsync>d__50& stateMachine)
04-26 11:30:04.050 22575 22575 W monodroid-assembly:    at Supabase.Client.InitializeAsync(String supabaseUrl, String supabaseKey, SupabaseOptions options)
04-26 11:30:04.050 22575 22575 W monodroid-assembly:    at Contract_Planner.Util.SupabaseInit.Initialize()
04-26 11:30:04.050 22575 22575 W monodroid-assembly:    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[<Initialize>d__0](<Initialize>d__0& stateMachine)
04-26 11:30:04.050 22575 22575 W monodroid-assembly:    at Contract_Planner.Util.SupabaseInit.Initialize()
04-26 11:30:04.050 22575 22575 W monodroid-assembly:    at Contract_Planner.MauiProgram.CreateMauiApp()
04-26 11:30:04.050 22575 22575 W monodroid-assembly:    at Contract_Planner.MainApplication.CreateMauiApp()
04-26 11:30:04.051 22575 22575 W monodroid-assembly:    at Microsoft.Maui.MauiApplication.OnCreate()
04-26 11:30:04.051 22575 22575 W monodroid-assembly:    at Android.App.Application.n_OnCreate(IntPtr jnienv, IntPtr native__this)
04-26 11:30:04.051 22575 22575 W monodroid-assembly:    at Android.Runtime.JNINativeWrapper.Wrap_JniMarshal_PP_V(_JniMarshal_PP_V callback, IntPtr jnienv, IntPtr klazz)
04-26 11:30:04.051 22575 22575 I monodroid-assembly: typemap: unable to find mapping to a managed type from Java type 'com/android/okhttp/internal/huc/DelegatingHttpsURLConnection'

But I'm not seeing any Fatals or Errors related to my application at least.

@lambdageek in the sample app I left that initialization of HttpClient like that because that's how it's declared in the static class that line originates from. Basically for the sample app I ripped a small chunk of code from the library I'm using for authentication: https://github.com/supabase-community/gotrue-csharp/blob/master/Gotrue/Helpers.cs#L50

RedChops commented 2 years ago

I'm pretty sure I see those warnings in the adb logs even when I move the auth initialization outside of the app initialization code and the whole thing works though as well.

grendello commented 2 years ago

I can reproduce one of the crashes with the test app:

04-26 19:55:48.967 20188 20188 I MonoDroid: Android.Runtime.JavaProxyThrowable: Exception of type 'Android.Runtime.JavaProxyThrowable' was thrown.
04-26 19:55:48.967 20188 20188 I MonoDroid: 
04-26 19:55:48.967 20188 20188 I MonoDroid:   --- End of managed Android.Runtime.JavaProxyThrowable stack trace ---
04-26 19:55:48.967 20188 20188 I MonoDroid: android.runtime.JavaProxyThrowable: System.NullReferenceException: Object reference not set to an instance of an object.
04-26 19:55:48.967 20188 20188 I MonoDroid:    at System.Net.Http.HttpClientHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
04-26 19:55:48.967 20188 20188 I MonoDroid:    at System.Net.Http.HttpMessageInvoker.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
04-26 19:55:48.967 20188 20188 I MonoDroid:    at System.Net.Http.HttpClient.<>n__0(HttpRequestMessage request, CancellationToken cancellationToken)
04-26 19:55:48.967 20188 20188 I MonoDroid:    at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenS
ource pendingRequestsCts, CancellationToken originalCancellationToken)
04-26 19:55:48.967 20188 20188 I MonoDroid:    at NetworkTest.MainPage.MakeRequest()
04-26 19:55:48.967 20188 20188 I MonoDroid:    at NetworkTest.MainPage.OnCounterClicked(Object sender, EventArgs e)
04-26 19:55:48.967 20188 20188 I MonoDroid:    at System.Threading.Tasks.Task.<>c.<ThrowAsync>b__128_0(Object state)
04-26 19:55:48.967 20188 20188 I MonoDroid:    at Android.App.SyncContext.<>c__DisplayClass2_0.<Post>b__0()
04-26 19:55:48.967 20188 20188 I MonoDroid:    at Java.Lang.Thread.RunnableImplementor.Run()
04-26 19:55:48.967 20188 20188 I MonoDroid:    at Java.Lang.IRunnableInvoker.n_Run(IntPtr jnienv, IntPtr native__this)
04-26 19:55:48.967 20188 20188 I MonoDroid:    at Android.Runtime.JNINativeWrapper.Wrap_JniMarshal_PP_V(_JniMarshal_PP_V callback, IntPtr jnienv, IntPtr klazz)
04-26 19:55:48.967 20188 20188 I MonoDroid:     at mono.java.lang.RunnableImplementor.n_run(Native Method)
04-26 19:55:48.967 20188 20188 I MonoDroid:     at mono.java.lang.RunnableImplementor.run(RunnableImplementor.java:30)
04-26 19:55:48.967 20188 20188 I MonoDroid:     at android.os.Handler.handleCallback(Handler.java:938)
04-26 19:55:48.967 20188 20188 I MonoDroid:     at android.os.Handler.dispatchMessage(Handler.java:99)
04-26 19:55:48.967 20188 20188 I MonoDroid:     at android.os.Looper.loopOnce(Looper.java:201)
04-26 19:55:48.967 20188 20188 I MonoDroid:     at android.os.Looper.loop(Looper.java:288)
04-26 19:55:48.967 20188 20188 I MonoDroid:     at android.app.ActivityThread.main(ActivityThread.java:7870)
04-26 19:55:48.967 20188 20188 I MonoDroid:     at java.lang.reflect.Method.invoke(Native Method)
04-26 19:55:48.967 20188 20188 I MonoDroid:     at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
04-26 19:55:48.967 20188 20188 I MonoDroid:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1003)

The exception is thrown regardless of whether HttpClient instance is in a local or class static variable. /cc @lambdageek

Commenting out <AndroidHttpClientHandlerType>System.Net.Http.HttpClientHandler</AndroidHttpClientHandlerType> in the csproj causes yet another crash. It somehow affects typemap generation+lookup:

04-26 20:05:06.875 20773 20818 D com.companyname.networktest: ---- DEBUG ASSERTION FAILED ----
04-26 20:05:06.875 20773 20818 D com.companyname.networktest: ---- Assert Short Message ----
04-26 20:05:06.875 20773 20818 D com.companyname.networktest: ManagedPeerType <=> JniTypeName Mismatch! javaVM.GetJniTypeInfoForType(typeof(Android.Runtime.JavaList)).JniTypeName="java/util/ArrayList" != "java/util/List"
04-26 20:05:06.875 20773 20818 D com.companyname.networktest: ---- Assert Long Message ----
04-26 20:05:06.875 20773 20818 D com.companyname.networktest: 
04-26 20:05:06.875 20773 20818 D com.companyname.networktest:    at System.Diagnostics.DebugProvider.Fail(String message, String detailMessage)
04-26 20:05:06.875 20773 20818 D com.companyname.networktest:    at System.Diagnostics.Debug.Fail(String message, String detailMessage)
04-26 20:05:06.875 20773 20818 D com.companyname.networktest:    at System.Diagnostics.Debug.Assert(Boolean condition, String message, String detailMessage)
04-26 20:05:06.875 20773 20818 D com.companyname.networktest:    at System.Diagnostics.Debug.Assert(Boolean condition, String message)
04-26 20:05:06.875 20773 20818 D com.companyname.networktest:    at Java.Interop.JniPeerMembers..ctor(String jniPeerTypeName, Type managedPeerType, Boolean checkManagedPeerType, Boolean isInterface)
04-26 20:05:06.875 20773 20818 D com.companyname.networktest:    at Java.Interop.JniPeerMembers..ctor(String jniPeerTypeName, Type managedPeerType, Boolean isInterface)
04-26 20:05:06.875 20773 20818 D com.companyname.networktest:    at Android.Runtime.XAPeerMembers..ctor(String jniPeerTypeName, Type managedPeerType, Boolean isInterface)
04-26 20:05:06.875 20773 20818 D com.companyname.networktest:    at Android.Runtime.JavaList..cctor()
04-26 20:05:06.875 20773 20818 D com.companyname.networktest:    at Android.Runtime.JavaList`1[[System.String, Sys
04-26 20:05:06.876 20773 20818 W ame.networktes: Process terminated due to "ManagedPeerType <=> JniTypeName Mismatch! javaVM.GetJniTypeInfoForType(typeof(Android.Runtime.JavaList)).JniTypeName="java/util/ArrayList" != "java/util/List"
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Diagnostics.DebugProvider.Fail(String message, String detailMessage)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Diagnostics.Debug.Fail(String message, String detailMessage)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Diagnostics.Debug.Assert(Boolean condition, String message, String detailMessage)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Diagnostics.Debug.Assert(Boolean condition, String message)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at Java.Interop.JniPeerMembers..ctor(String jniPeerTypeName, Type managedPeerType, Boolean checkManagedPeerType, Boolean isInterface)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at Java.Interop.JniPeerMembers..ctor(String jniPeerTypeName, Type managedPeerType, Boolean isInterface)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at Android.Runtime.XAPeerMembers..ctor(String jniPeerTypeName, Type managedPeerType, Boolean isInterface)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at Android.Runtime.JavaList..cctor()
04-26 20:05:06.876 20773 20818 W ame.networktes:    at Android.Runtime.JavaList`1[[System.String, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]]..ctor(IntPtr handle, JniHandleOwnership trans
fer)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at Android.Runtime.JavaList`1[[System.String, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].FromJniHandle(IntPtr handle, JniHandleOwnersh
ip transfer)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at Java.Interop.JavaConvert.FromJniHandle[IList`1](IntPtr handle, JniHandleOwnership transfer, Boolean& set)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at Java.Interop.JavaConvert.FromJniHandle[IList`1](IntPtr handle, JniHandleOwnership transfer)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at Android.Runtime.JavaDictionary`2[[System.String, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Collections.Generic.IList`1[[Sys
tem.String, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].Get(String key)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at Android.Runtime.JavaDictionary`2[[System.String, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Collections.Generic.IList`1[[Sys
tem.String, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].get_Item(String key)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at Xamarin.Android.Net.AndroidMessageHandler.CopyHeaders(HttpURLConnection httpConnection, HttpResponseMessage response)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at Xamarin.Android.Net.AndroidMessageHandler.DoProcessRequest(HttpRequestMessage request, URL javaUrl, HttpURLConnection httpConnection, CancellationToken cancellationToken, RequestRe
directionState redirectState)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1[[System.Net.Http.HttpResponseMessage, System.Net.Http, Version=6.0.0.0, Culture=neutral, PublicKeyTo
ken=b03f5f7f11d50a3a],[Xamarin.Android.Net.AndroidMessageHandler.<DoProcessRequest>d__128, Mono.Android, Version=0.0.0.0, Culture=neutral, PublicKeyToken=84e04ff9cfb79065]].ExecutionContextCallback(Object s)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1[[System.Net.Http.HttpResponseMessage, System.Net.Http, Version=6.0.0.0, Culture=neutral, PublicKeyTo
ken=b03f5f7f11d50a3a],[Xamarin.Android.Net.AndroidMessageHandler.<DoProcessRequest>d__128, Mono.Android, Version=0.0.0.0, Culture=neutral, PublicKeyToken=84e04ff9cfb79065]].MoveNext(Thread threadPoolThread)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1[[System.Net.Http.HttpResponseMessage, System.Net.Http, Version=6.0.0.0, Culture=neutral, PublicKeyTo
ken=b03f5f7f11d50a3a],[Xamarin.Android.Net.AndroidMessageHandler.<DoProcessRequest>d__128, Mono.Android, Version=0.0.0.0, Culture=neutral, PublicKeyToken=84e04ff9cfb79065]].MoveNext()
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(IAsyncStateMachineBox box, Boolean allowInlining)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Threading.Tasks.Task.RunContinuations(Object continuationObject)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Threading.Tasks.Task.FinishContinuations()
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Threading.Tasks.Task.FinishStageThree()
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Threading.Tasks.Task.FinishStageTwo()
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Threading.Tasks.Task.FinishSlow(Boolean userDelegateExecute)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Threading.Tasks.Task.Finish(Boolean userDelegateExecute)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Threading.Tasks.Task.ExecuteEntryUnsafe(Thread threadPoolThread)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Threading.Tasks.Task.ExecuteFromThreadPool(Thread threadPoolThread)
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Threading.ThreadPoolWorkQueue.Dispatch()
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
04-26 20:05:06.876 20773 20818 W ame.networktes:    at System.Threading.Thread.StartCallback()"
grendello commented 2 years ago

The typemaps crash is a red herring, please ignore it (it's because the assertion is incorrectly triggered for the types mentioned in the message for Debug builds of Xamarin.Android itself)

grendello commented 2 years ago

So, it seems the problem lies somewhere within System.Net.Http.HttpClient and friends when an attempt is made to use the native client handler. Adding the following to .csproj makes the app work for me:

<PropertyGroup>
  <UseNativeHttpHandler>false</UseNativeHttpHandler>
</PropertyGroup>

@RedChops would you mind testing :arrow_up:?

grendello commented 2 years ago

With <UseNativeHttpHandler>true</UseNativeHttpHandler> I get

04-26 20:38:11.678 22465 22465 I MonoDroid: UNHANDLED EXCEPTION:
04-26 20:38:11.680 22465 22465 I MonoDroid: Android.Runtime.JavaProxyThrowable: Exception of type 'Android.Runtime.JavaProxyThrowable' was thrown.
04-26 20:38:11.680 22465 22465 I MonoDroid: 
04-26 20:38:11.680 22465 22465 I MonoDroid:   --- End of managed Android.Runtime.JavaProxyThrowable stack trace ---
04-26 20:38:11.680 22465 22465 I MonoDroid: android.runtime.JavaProxyThrowable: System.NullReferenceException: Object reference not set to an instance of an object.
04-26 20:38:11.680 22465 22465 I MonoDroid:    at System.Net.Http.HttpClientHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
04-26 20:38:11.680 22465 22465 I MonoDroid:    at System.Net.Http.HttpMessageInvoker.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
04-26 20:38:11.680 22465 22465 I MonoDroid:    at System.Net.Http.HttpClient.<>n__0(HttpRequestMessage request, CancellationToken cancellationToken)
04-26 20:38:11.680 22465 22465 I MonoDroid:    at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenS
ource pendingRequestsCts, CancellationToken originalCancellationToken)
04-26 20:38:11.680 22465 22465 I MonoDroid:    at NetworkTest.MainPage.MakeRequest()
04-26 20:38:11.680 22465 22465 I MonoDroid:    at NetworkTest.MainPage.OnCounterClicked(Object sender, EventArgs e)
04-26 20:38:11.680 22465 22465 I MonoDroid:    at System.Threading.Tasks.Task.<>c.<ThrowAsync>b__128_0(Object state)
04-26 20:38:11.680 22465 22465 I MonoDroid:    at Android.App.SyncContext.<>c__DisplayClass2_0.<Post>b__0()
04-26 20:38:11.680 22465 22465 I MonoDroid:    at Java.Lang.Thread.RunnableImplementor.Run()
04-26 20:38:11.680 22465 22465 I MonoDroid:    at Java.Lang.IRunnableInvoker.n_Run(IntPtr jnienv, IntPtr native__this)
04-26 20:38:11.680 22465 22465 I MonoDroid:    at Android.Runtime.JNINativeWrapper.Wrap_JniMarshal_PP_V(_JniMarshal_PP_V callback, IntPtr jnienv, IntPtr klazz)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at mono.java.lang.RunnableImplementor.n_run(Native Method)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at mono.java.lang.RunnableImplementor.run(RunnableImplementor.java:30)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at android.os.Handler.handleCallback(Handler.java:938)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at android.os.Handler.dispatchMessage(Handler.java:99)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at android.os.Looper.loopOnce(Looper.java:201)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at android.os.Looper.loop(Looper.java:288)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at android.app.ActivityThread.main(ActivityThread.java:7870)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at java.lang.reflect.Method.invoke(Native Method)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1003)
04-26 20:38:11.680 22465 22465 I MonoDroid: 
04-26 20:38:11.680 22465 22465 I MonoDroid:   --- End of managed Android.Runtime.JavaProxyThrowable stack trace ---
04-26 20:38:11.680 22465 22465 I MonoDroid: android.runtime.JavaProxyThrowable: System.NullReferenceException: Object reference not set to an instance of an object.
04-26 20:38:11.680 22465 22465 I MonoDroid:    at System.Net.Http.HttpClientHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
04-26 20:38:11.680 22465 22465 I MonoDroid:    at System.Net.Http.HttpMessageInvoker.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
04-26 20:38:11.680 22465 22465 I MonoDroid:    at System.Net.Http.HttpClient.<>n__0(HttpRequestMessage request, CancellationToken cancellationToken)
04-26 20:38:11.680 22465 22465 I MonoDroid:    at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
04-26 20:38:11.680 22465 22465 I MonoDroid:    at NetworkTest.MainPage.MakeRequest()
04-26 20:38:11.680 22465 22465 I MonoDroid:    at NetworkTest.MainPage.OnCounterClicked(Object sender, EventArgs e)
04-26 20:38:11.680 22465 22465 I MonoDroid:    at System.Threading.Tasks.Task.<>c.<ThrowAsync>b__128_0(Object state)
04-26 20:38:11.680 22465 22465 I MonoDroid:    at Android.App.SyncContext.<>c__DisplayClass2_0.<Post>b__0()
04-26 20:38:11.680 22465 22465 I MonoDroid:    at Java.Lang.Thread.RunnableImplementor.Run()
04-26 20:38:11.680 22465 22465 I MonoDroid:    at Java.Lang.IRunnableInvoker.n_Run(IntPtr jnienv, IntPtr native__this)
04-26 20:38:11.680 22465 22465 I MonoDroid:    at Android.Runtime.JNINativeWrapper.Wrap_JniMarshal_PP_V(_JniMarshal_PP_V callback, IntPtr jnienv, IntPtr klazz)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at mono.java.lang.RunnableImplementor.n_run(Native Method)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at mono.java.lang.RunnableImplementor.run(RunnableImplementor.java:30)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at android.os.Handler.handleCallback(Handler.java:938)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at android.os.Handler.dispatchMessage(Handler.java:99)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at android.os.Looper.loopOnce(Looper.java:201)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at android.os.Looper.loop(Looper.java:288)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at android.app.ActivityThread.main(ActivityThread.java:7870)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at java.lang.reflect.Method.invoke(Native Method)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
04-26 20:38:11.680 22465 22465 I MonoDroid:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1003)
RedChops commented 2 years ago

@grendello So interestingly enough this was a two-stage fix. Setting that prop in my csproj alone wasn't enough to make the network calls not hang when called in the CreateMauiApp function, but it's strange.

In the NetworkTest project, I moved all of the async network request stuff that was in ContentPage to the CreateMauiApp function around where I call Auth initialization to somewhat simulate the ideal flow. Since these calls are async and CreateMauiApp cannot be, I used .Result on all the calls. Setting that prop fixed the hang completely in this case - without <UseNativeHttpHandler>false</UseNativeHttpHandler> the app hung on launch, but with it the app was able to launch successfully.

In my primary project, I added <UseNativeHttpHandler>false</UseNativeHttpHandler> but the app still hung on launch. I tried using .Wait(), having the initializer return a Task to use .Result, none of those worked. My initializer called https://github.com/supabase-community/gotrue-csharp/blob/master/Gotrue/Client.cs#L197, an async function. By changing it to use https://github.com/supabase-community/gotrue-csharp/blob/master/Gotrue/Client.cs#L178 instead, the app was able to launch.

This is really weird to me though, because the only difference between those two methods is in Initialize, the library code creates and runs a task instead of awaiting the async version in my code. Not sure why awaiting library code would still cause it to hang.

lambdageek commented 2 years ago

With <UseNativeHttpHandler>true</UseNativeHttpHandler> I get

@grendello just to clarify you get a crash if you set both properties like this:

  <UseNativeHttpHandler>true</UseNativeHttpHandler>
   <AndroidHttpClientHandlerType>System.Net.Http.HttpClientHandler</AndroidHttpClientHandlerType>

That's the only way I get a crash. setting UseNativeHttpClientHandler to true and leaving AndroidHttpClientHandlerType unset works as expected.

Honestly that we crash in the case where is System.Net.Http.HttpClientHandler makes sense given https://github.com/dotnet/runtime/blob/main/src/libraries/System.Net.Http/src/System/Net/Http/HttpClientHandler.AnyMobile.InvokeNativeHandler.cs#L149-L157 because the HttpClientHandler type doesn't have a GetHttpMessageHandler method, it's not a valid value for the client handler type.

I think there are two things we should do here:

  1. HttpClientHandler should throw some more sensible exception if the given type doesn't have the right method.
  2. XA should fail the build if AndroidHttpClientHandlerType is System.Net.Http.HttpClientHandler
lambdageek commented 2 years ago

In the NetworkTest project, I moved all of the async network request stuff that was in ContentPage to the CreateMauiApp function around where I call Auth initialization to somewhat simulate the ideal flow. Since these calls are async and CreateMauiApp cannot be, I used .Result on all the calls. Setting that prop fixed the hang completely in this case - without false the app hung on launch, but with it the app was able to launch successfully.

@RedChops I can get the NetworkTest.cs to hang even if I set 

<UseNativeHttpHandler>false</UseNativeHttpHandler>

and don't set < AndroidHttpClientHandlerType>. if I do the following in CreateMauiApp:

    public static MauiApp CreateMauiApp()
    {
        var builder = MauiApp.CreateBuilder();
        builder
            .UseMauiApp<App>()
            .ConfigureFonts(fonts =>
            {
                fonts.AddFont("OpenSans-Regular.ttf", "OpenSansRegular");
                fonts.AddFont("OpenSans-Semibold.ttf", "OpenSansSemibold");
            });
        Console.WriteLine ("request at startup: {0}", MakeRequest().Result);
        return builder.Build();
    }

    public static async Task<string> MakeRequest()
    {
        Console.WriteLine("@@@ before delay");
        string content = "123";
        await Task.Delay(250);
        Console.WriteLine("@@@ after delay");
        return content;
    }

I get this in the adb log:

04-27 14:32:08.905 12605 12605 I DOTNET  : @@@ before delay
04-27 14:32:08.905 12605 12605 D Mono    : Running class .cctor for System.Threading.Tasks.Task/DelayPromise from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.905 12605 12605 D Mono    : Running class .cctor for System.Threading.Tasks.TplEventSource from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.905 12605 12605 D Mono    : Running class .cctor for System.Threading.TimerQueueTimer from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.905 12605 12605 D Mono    : Running class .cctor for System.Threading.TimerQueueTimer/<>c from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.905 12605 12605 D Mono    : Running class .cctor for System.Threading.TimerQueue from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.906 12605 12605 D Mono    : Running class .cctor for System.DateTime from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.906 12605 12605 D Mono    : Running class .cctor for System.Threading.WaitHandle from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.906 12605 12605 D Mono    : Running class .cctor for System.Threading.WaitSubsystem from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.906 12605 12605 D Mono    : Running class .cctor for System.Diagnostics.Tracing.FrameworkEventSource from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.906 12605 12605 D Mono    : Running class .cctor for System.Collections.Generic.List`1<System.Threading.TimerQueue> from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.907 12605 12605 D Mono    : Running class .cctor for System.Threading.Thread/StartHelper from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.908 12605 12605 D Mono    : Running class .cctor for System.Threading.ExecutionContext from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.908 12605 12605 D Mono    : Running class .cctor for System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1/AsyncStateMachineBox`1<string, NetworkTest.MauiProgram/<MakeRequest>d__3> from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.908 12605 12605 D Mono    : Running class .cctor for System.Threading.Tasks.Task`1<string> from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.908 12605 12605 D Mono    : Running class .cctor for System.Threading.Tasks.SynchronizationContextAwaitTaskContinuation from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.908 12605 12605 D Mono    : Running class .cctor for System.Threading.Tasks.SynchronizationContextAwaitTaskContinuation/<>c from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.908 12605 12605 D Mono    : Running class .cctor for System.Threading.Tasks.AwaitTaskContinuation from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.909 12605 12605 D Mono    : Running class .cctor for System.Threading.Tasks.AwaitTaskContinuation/<>c from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.909 12605 12605 D Mono    : Running class .cctor for System.Threading.SpinWait from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.909 12605 12605 D Mono    : Running class .cctor for System.Threading.ManualResetEventSlim from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.909 12605 12605 D Mono    : Running class .cctor for System.Threading.ThreadPool from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.910 12605 12605 D Mono    : Running class .cctor for System.Threading.ThreadPool/<>c from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.910 12605 12605 D Mono    : Running class .cctor for System.Threading.PortableThreadPool from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.910 12605 12605 D Mono    : Running class .cctor for System.Threading.ThreadInt64PersistentCounter from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.910 12605 12605 D Mono    : Running class .cctor for System.Threading.PortableThreadPool/BlockingConfig from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:08.911 12605 12605 D Mono    : event_create: creating Event handle
04-27 14:32:08.911 12605 12605 D Mono    : mono_w32handle_new: create Event handle 0xb4000079dc657af8
04-27 14:32:08.911 12605 12605 D Mono    : mono_w32handle_ref_core: ref Event handle 0xb4000079dc657af8, ref: 1 -> 2
04-27 14:32:08.911 12605 12605 D Mono    : event_handle_create: created Event handle 0xb4000079dc657af8
04-27 14:32:08.911 12605 12605 D Mono    : mono_w32handle_unref_core: unref Event handle 0xb4000079dc657af8, ref: 2 -> 1 destroy: false
04-27 14:32:08.911 12605 12605 D Mono    : mono_w32handle_ref_core: ref Event handle 0xb4000079dc657af8, ref: 1 -> 2
04-27 14:32:08.911 12605 12605 D Mono    : mono_w32handle_test_capabilities: testing 0x3 against 0x8 (0)
04-27 14:32:08.911 12605 12605 D Mono    : mono_w32handle_test_capabilities: testing 0x3 against 0x1 (1)
04-27 14:32:08.911 12605 12605 D Mono    : mono_w32handle_test_capabilities: testing 0x3 against 0x4 (0)
04-27 14:32:08.911 12605 12605 D Mono    : mono_w32handle_timedwait_signal_handle: waiting for 0xb4000079dc657af8 (type Event)
04-27 14:32:08.911 12605 12605 D Mono    : mono_w32handle_ref_core: ref Event handle 0xb4000079dc657af8, ref: 2 -> 3
04-27 14:32:09.157 12605 12629 D Mono    : Running class .cctor for System.Threading.PortableThreadPool/WorkerThread from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:09.157 12605 12629 D Mono    : Running class .cctor for System.Threading.PortableThreadPool/WorkerThread/<>c from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:09.159 12605 12629 D Mono    : Running class .cctor for System.Threading.PortableThreadPool/GateThread from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:09.160 12605 12630 D Mono    : Running class .cctor for System.Diagnostics.Tracing.NativeRuntimeEventSource from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:09.166 12605 12630 D Mono    : Running class .cctor for System.Threading.ThreadPoolWorkQueue/WorkStealingQueueList from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:09.167 12605 12630 D Mono    : Running class .cctor for System.Collections.Generic.List`1<System.Threading.ThreadInt64PersistentCounter/ThreadLocalNodeFinalizationHelper> from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:09.172 12605 12630 D Mono    : Requesting loading reference 6 (of 7) of /data/data/com.companyname.networktest/files/.__override__/Java.Interop.dll
04-27 14:32:09.172 12605 12630 D Mono    : Loading reference 6 of /data/data/com.companyname.networktest/files/.__override__/Java.Interop.dll asmctx DEFAULT, looking for System.Linq, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a
04-27 14:32:09.172 12605 12630 D Mono    : Request to load System.Linq in alc 0xb40000789c61e950
04-27 14:32:09.172 12605 12630 D Mono    : Assembly already loaded in the active ALC: 'System.Linq'.
04-27 14:32:09.172 12605 12630 D Mono    : Assembly Ref addref Java.Interop[0xb40000787c645750] -> System.Linq[0xb40000787c621680]: 3
04-27 14:32:09.174 12605 12630 D Mono    : Running class .cctor for Java.Lang.Thread/RunnableImplementor from '/data/data/com.companyname.networktest/files/.__override__/Mono.Android.dll'
04-27 14:32:09.175 12605 12630 D Mono    : Running class .cctor for System.Array/EmptyArray`1<Android.Runtime.JValue> from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:09.175 12605 12630 I monodroid-timing: Runtime.register: registering type `Java.Lang.Thread+RunnableImplementor, Mono.Android`
04-27 14:32:09.176 12605 12630 D Mono    : Request to load Mono.Android in alc 0xb40000789c61e950
04-27 14:32:09.176 12605 12630 D Mono    : Assembly already loaded in the active ALC: 'Mono.Android'.
04-27 14:32:09.176 12605 12630 I monodroid-timing: Typemap.managed_to_java: end, total time; elapsed: 0s:0::9417
04-27 14:32:09.176 12605 12630 D Mono    : Request to load Mono.Android in alc 0xb40000789c61e950
04-27 14:32:09.176 12605 12630 D Mono    : Assembly already loaded in the active ALC: 'Mono.Android'.
04-27 14:32:09.176 12605 12630 D Mono    : Running class .cctor for Java.Lang.IRunnableInvoker from '/data/data/com.companyname.networktest/files/.__override__/Mono.Android.dll'
04-27 14:32:09.176 12605 12630 I monodroid-timing: Runtime.register: end time; elapsed: 0s:0::598041
04-27 14:32:09.180 12605 12630 D Mono    : Running class .cctor for System.Threading.PortableThreadPool/HillClimbing from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:09.181 12605 12630 D Mono    : Running class .cctor for System.Random from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:09.182 12605 12630 D Mono    : Running class .cctor for System.Diagnostics.Stopwatch from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
04-27 14:32:09.183 12605 12630 D Mono    : Running class .cctor for System.BitConverter from '/data/data/com.companyname.networktest/files/.__override__/System.Private.CoreLib.dll'
lambdageek commented 2 years ago

Hmm... if I do this:

        await Task.Delay(1).ConfigureAwait(false);

in MakeRequest() called from CreateMauiApp, then the app starts.

I see that when CreateMauiApp the synchronization context is SynchronizationContext.Current?.GetType() is Android.App.SyncContext. Both Task.Run() and awaiting with ConfigureAwait(false) will not use the synchronization context, so it makes sense that they would both behave the same and not hang.

But if we are using the synchronization context, i'm not sure why we hang:

  1. maybe we're not allowed to block the thread at that point?
  2. It's the first time that SynchronizationContextAwaitTaskContinuation and that entire threadpool codepath is getting used, so maybe there's still some initialization deadlock?
lambdageek commented 2 years ago

I'm wondering:

  1. if there's a Looper when Application.OnCreate is called?
  2. if for some reason the Logger.Log call here doesn't work yet.

Is there a Looper when Application.OnCreate is called? If I call await Task.Delay(1) (without a ConfigureAwait). from CreateMauiApp it looks like it just ends up getting called from an Application.OnCreate override. Is it possible that this Logger.Log call doesn't happen for some reason?

simonrozsival commented 2 years ago

If I understand this thread correctly, the main problem was that the $(AndroidHttpClientHandlerType) property was set to an invalid value (System.Net.Http.HttpClientHandler) and since we don't validate that the native handler was instantiated correctly in the constructor of HttpClientHandler the first time the handler is used a confusing NullReferenceException is thrown.

~I think the best way to fix this would be to do what xamarin-macios does and throw an exception if the configured type is not found. I'll create a PR.~

EDIT: I think the best way to fix this would be to do what xamarin-macios does and fall back to AndroidMessageHandler + log a warning message. I'll create a PR.

The second problem with the app hanging when there's a network request in CreateMauiApp is quite strange. I would expect the app to crash with NetworkOnMainThreadException but since there's the same issue with the delay I don't know what the actual problem could be. Is it worth investigating when any blocking IO on the main thread is bad practice and should be avoided anyway?