search

UXDivers / Gorilla-Player-Support

This is the public Gorilla Player support website
http://gorillaplayer.com
115 stars 17 forks source link

Gorilla SDK app doesn't connect and crashes after ~8 seconds #127

Open ghost opened 8 years ago

ghost commented 8 years ago

Hi,

I tried integrating the Gorilla SDK into my app: I installed the NuGet in my Android project, added registred assemblies for two project it depends on, added Gorilla.json, made a seperate configuration which #if's in the Gorilla Player code.

When I open the app, it shows that it's connecting but then crashes after ~8 seconds. I don't see anything useful in the console output. Here's my code in MainActivity.cs:

#if GORILLA
            // Assemblies Gorilla player needs
            List<Assembly> assemblies = new List<Assembly>
            {
                typeof(Test.Apps.Controls.CircleImage).Assembly,
                typeof(Test.Apps.SpecificApp.App).Assembly
            };

            // Gorilla Player config
            UXDivers.Gorilla.Config gorillaConfig = new UXDivers.Gorilla.Config("Gorilla Willem");

            // Add assemblies to config
            foreach (Assembly assembly in assemblies)
            {
                gorillaConfig.RegisterAssembly(assembly);
            }

            // Load Gorilla application
            LoadApplication(
                UXDivers.Gorilla.Droid.Player.CreateApplication(
                    ApplicationContext,
                    gorillaConfig
                    ));
#else
            LoadApplication(new App(containerBuilder));
#endif

How do I debug this and get this working? I tried manually entering the IP but I haven't managed to type in the IP before the app crashes.

LeoHere commented 8 years ago

Hi, please check server logs. Clients exceptions are reported to the server. Read this document for more info of where are the logs stored. https://github.com/UXDivers/Gorilla-Player-Support/wiki/Gorilla-Player-logs-location

ghost commented 8 years ago

What log file am I supposed to look at? There's a gorillaPlayer.log, gorillaHost.log, visualStudio.log, xamarinStudio.log and a bunch of what look like GUID-named logs.

ghost commented 8 years ago

I believe this is the relevant part of gorillaHost.log:

[
  {
    "level": "info",
    "message": "Gorilla Server: info: Adding solution (from VS - 14.0): D:\\work\\test\\TestApps.sln \r\n",
    "timestamp": "2016-06-22T15:38:15.140Z"
  },
  {
    "level": "error",
    "message": "Gorilla Server: error: Could not found assembly Test.Apps.SpecificApp with version <ANY>. It will be ignored.\r\n",
    "timestamp": "2016-06-22T15:38:15.194Z"
  },
  {
    "level": "error",
    "message": "Gorilla Server: error: Could not found assembly Test.Apps with version <ANY>. It will be ignored.\r\nerror: Could not found assembly Test.Apps.SpecificApp with version <ANY>. It will be ignored.\r\n",
    "timestamp": "2016-06-22T15:38:15.195Z"
  },
  {
    "level": "error",
    "message": "Gorilla Server: error: Could not found assembly Test.Apps with version <ANY>. It will be ignored.\r\n",
    "timestamp": "2016-06-22T15:38:15.196Z"
  },
  {
    "level": "info",
    "message": "Gorilla Server: info: Notifing issues found (errors: 0, warnings: 0) contextInstanceId=34, targetId=13, sampleDataId=0\r\n",
    "timestamp": "2016-06-22T15:38:15.225Z"
  },
  {
    "level": "info",
    "message": "Gorilla Server: info: Adding solution (from VS - 14.0): D:\\work\\test\\TestApps.sln \r\n",
    "timestamp": "2016-06-22T15:38:58.625Z"
  },
  {
    "level": "info",
    "message": "Exiting Gorilla Server with exit code 1073807364",
    "timestamp": "2016-06-22T16:24:52.248Z"
  }
]
LeoHere commented 8 years ago

Client errors usually should be present in both GorillaHost and GorillaPlayer logs. So you look in the right place. However, none of the errors included were reported by the client. Errors reported by the client includes the text Client reported error at some point. And usually are followed by a .NET like stack trace.The errors you sent does not seems to be related to the crash.

After rereading your original post, now I see you mentioned that it crashes before you actually connect to the server. That implies that exceptions will not be sent to the server in this case, so server logs are useless. :(

If you run your app (which includes the SDK) in debug mode, and you wait those 8 secs, what happen? Don't you get an exception in XS/VS? Is XS or VS configured to stop when an exception occurs?

Another thing you can try is to register to the Player's logger. The player's Logger is a undocumented work in progress class where errors and other log messages are centralised.

The full name for the class is UXDivers.Gorilla.Logger. You can register to the NewMessage event. In your handler just set a breakpoint or use Debug.WriteLine to write messages to the console.

Register to this event before the LoadApplication.

Please let me know how it goes.

ghost commented 8 years ago

I grep'd all the logs and none contained "Client reported error" (today, some older logs from using the player APK did show it).

Logger.NewMessage is never called, and the debug output didn't look useful, here's the end of it:

06-23 18:38:14.562 I/dalvikvm(14134): Could not find method android.view.ViewGroup.<init>, referenced from method md5b60ffeb829f638581ab2bb9b1a7f4f3f.ListViewRenderer_Container.<init>
06-23 18:38:14.562 W/dalvikvm(14134): VFY: unable to resolve direct method 20726: Landroid/view/ViewGroup;.<init> (Landroid/content/Context;Landroid/util/AttributeSet;II)V
06-23 18:38:14.562 D/dalvikvm(14134): VFY: replacing opcode 0x70 at 0x0000
06-23 18:38:14.592 I/dalvikvm(14134): Could not find method android.widget.EditText.<init>, referenced from method md5b60ffeb829f638581ab2bb9b1a7f4f3f.EntryEditText.<init>
06-23 18:38:14.592 W/dalvikvm(14134): VFY: unable to resolve direct method 21281: Landroid/widget/EditText;.<init> (Landroid/content/Context;Landroid/util/AttributeSet;II)V
06-23 18:38:14.592 D/dalvikvm(14134): VFY: replacing opcode 0x70 at 0x0000
06-23 18:38:14.652 D/dalvikvm(14134): GC_CONCURRENT freed 76K, 4% free 4019K/4164K, paused 2ms+0ms, total 5ms
06-23 18:38:14.662 D/dalvikvm(14134): GC_EXPLICIT freed 77K, 6% free 3947K/4164K, paused 0ms+0ms, total 3ms
06-23 18:38:14.662 D/Mono    (14134): GC_OLD_BRIDGE num-objects 24 num_hash_entries 26 sccs size 26 init 0.00ms df1 0.03ms sort 0.01ms dfs2 0.14ms setup-cb 0.02ms free-data 0.02ms links 3/3/3/1 dfs passes 53/29
06-23 18:38:14.662 D/Mono    (14134): GC_MINOR: (Nursery full) pause 7.44ms, total 7.71ms, bridge 0.03ms promoted 1344K major 1344K los 483K
06-23 18:38:14.732 D/Mono    (14134): DllImport searching in: '__Internal' ('(null)').
06-23 18:38:14.732 D/Mono    (14134): Searching for 'java_interop_jnienv_call_nonvirtual_float_method_a'.
06-23 18:38:14.732 D/Mono    (14134): Probing 'java_interop_jnienv_call_nonvirtual_float_method_a'.
06-23 18:38:14.732 D/Mono    (14134): Found as 'java_interop_jnienv_call_nonvirtual_float_method_a'.
06-23 18:38:14.742 D/Mono    (14134): DllImport searching in: '__Internal' ('(null)').
06-23 18:38:14.742 D/Mono    (14134): Searching for 'java_interop_jnienv_call_nonvirtual_int_method_a'.
06-23 18:38:14.742 D/Mono    (14134): Probing 'java_interop_jnienv_call_nonvirtual_int_method_a'.
06-23 18:38:14.742 D/Mono    (14134): Found as 'java_interop_jnienv_call_nonvirtual_int_method_a'.
06-23 18:38:14.762 D/Mono    (14134): DllImport searching in: '__Internal' ('(null)').
06-23 18:38:14.762 D/Mono    (14134): Searching for 'java_interop_jnienv_call_static_int_method_a'.
06-23 18:38:14.762 D/Mono    (14134): Probing 'java_interop_jnienv_call_static_int_method_a'.
06-23 18:38:14.762 D/Mono    (14134): Found as 'java_interop_jnienv_call_static_int_method_a'.
06-23 18:38:14.802 D/        (14134): HostConnection::get() New Host Connection established 0xb979e410, tid 14134
06-23 18:38:14.842 D/OpenGLRenderer(14134): Enabling debug mode 0
Thread started: <Thread Pool> #6
06-23 18:38:15.282 D/Mono    (14134): [0xb8f483e0] hill climbing, change max number of threads 3
Thread started: <Thread Pool> #7
06-23 18:38:17.302 D/Mono    (14134): [0xb992a410] worker starting
06-23 18:38:33.292 D/Mono    (14134): [0xb8f483e0] hill climbing, change max number of threads 2
06-23 18:38:42.302 D/Mono    (14134): [0xb992a410] hill climbing, change max number of threads 3
06-23 18:39:00.322 D/Mono    (14134): [0xb8f19140] hill climbing, change max number of threads 2
Resolved pending breakpoint at 'D:\work\Test\Apps\SpecificApp\SpecificApp.Droid\MainActivity.cs:69,1' to void Test.Apps.SpecificApp.Droid.MainActivity.<>c.<OnCreate>b__0_1 (object sender, UXDivers.Gorilla.LogEventArgs args) [0x00000].
Resolved pending breakpoint at 'D:\work\Test\Apps\SpecificApp\SpecificApp.Droid\MainActivity.cs:71,1' to void Test.Apps.SpecificApp.Droid.MainActivity.<>c.<OnCreate>b__0_1 (object sender, UXDivers.Gorilla.LogEventArgs args) [0x00022].
Resolved pending breakpoint at 'D:\work\Test\Apps\SpecificApp\SpecificApp.Droid\MainActivity.cs:70,1' to void Test.Apps.SpecificApp.Droid.MainActivity.<>c.<OnCreate>b__0_1 (object sender, UXDivers.Gorilla.LogEventArgs args) [0x00001].
06-23 18:39:09.322 D/Mono    (14134): [0xb8f483e0] hill climbing, change max number of threads 3
06-23 18:39:13.232 D/dalvikvm(14134): GC_CONCURRENT freed 168K, 7% free 4166K/4460K, paused 2ms+0ms, total 7ms
Thread finished: <Thread Pool> #2
The thread 'Unknown' (0x2) has exited with code 0 (0x0).
Thread started: <Thread Pool> #9
06-23 18:39:20.422 D/Mono    (14134): [0xb9860a90] hill climbing, change max number of threads 4
06-23 18:39:20.772 D/Mono    (14134): Assembly Ref addref SocketIoClientDotNet[0xb8614900] -> System[0xb86f8fa0]: 12
06-23 18:39:20.772 D/Mono    (14134): Assembly Ref addref UXDivers.Gorilla.SDK.Droid[0xb861d850] -> EngineIoClientDotNet[0xb8609040]: 3
06-23 18:39:20.772 D/Mono    (14134): Assembly Ref addref EngineIoClientDotNet[0xb8609040] -> System.Core[0xb88dfb50]: 10
06-23 18:39:20.912 D/Mono    (14134): Assembly Ref addref EngineIoClientDotNet[0xb8609040] -> System[0xb86f8fa0]: 13
06-23 18:39:20.912 D/Mono    (14134): Assembly Ref addref EngineIoClientDotNet[0xb8609040] -> WebSocket4Net[0xb861e5b0]: 2
06-23 18:39:20.952 D/Mono    (14134): DllImport attempting to load: '__Internal'.
06-23 18:39:20.952 D/Mono    (14134): DllImport loaded library '(null)'.
06-23 18:39:20.952 D/Mono    (14134): DllImport searching in: '__Internal' ('(null)').
06-23 18:39:20.952 D/Mono    (14134): Searching for 'monodroid_get_system_property'.
06-23 18:39:20.952 D/Mono    (14134): Probing 'monodroid_get_system_property'.
06-23 18:39:20.952 D/Mono    (14134): Found as 'monodroid_get_system_property'.
06-23 18:39:20.952 D/Mono    (14134): DllImport searching in: '__Internal' ('(null)').
06-23 18:39:20.952 D/Mono    (14134): Searching for 'monodroid_free'.
06-23 18:39:20.952 D/Mono    (14134): Probing 'monodroid_free'.
06-23 18:39:20.952 D/Mono    (14134): Found as 'monodroid_free'.
06-23 18:39:20.982 D/dalvikvm(14134): GC_EXPLICIT freed 120K, 7% free 4184K/4460K, paused 1ms+1ms, total 10ms
06-23 18:39:20.982 D/Mono    (14134): GC_OLD_BRIDGE num-objects 113 num_hash_entries 114 sccs size 114 init 0.00ms df1 0.06ms sort 0.02ms dfs2 2.86ms setup-cb 0.54ms free-data 1.56ms links 1/1/1/1 dfs passes 228/115
06-23 18:39:20.982 D/Mono    (14134): GC_MINOR: (Nursery full) pause 2.27ms, total 2.39ms, bridge 0.01ms promoted 192K major 1536K los 1067K
06-23 18:39:20.992 D/Mono    (14134): Assembly Ref addref HockeySDK[0xb8610510] -> System[0xb86f8fa0]: 14
06-23 18:39:21.062 D/Mono    (14134): Assembly Ref addref Mono.Android[0xb86525b0] -> System[0xb86f8fa0]: 15

I don't get an exception in VS (I don't use XS), the app just stops and VS returns from debug to normal mode.

About the 8 seconds number: that isn't quite accurate. If I don't interact with the app, it will just say 'Looking for server named "Gorilla Willem", please wait...', and stay like that indefinitely (or at least for 2 minutes, that's how long I waited).

If, however, I switch back and forth between the tabs Manual and Automatic, the app crashes within 5 seconds. If I type in the IP address box too quickly for too long (i,.e. add 8 characters in ~3 seconds) it will crash.

All my tests so far have been on a lowend emulator, 480x720, 768mb ram, Android API 19. I then tried it on a high-res, Android API 23, 3gb ram emulator, and got the same results. For both my emulators I use the x86 Intel HAXM image (because otherwise emulation is insufferably slow).

But then! I found out that sometimes HockeyApp's crash reporting would still work, and it gave me these exception:

Xamarin caused by: android.runtime.JavaProxyThrowable: System.AggregateException: A Task's exception(s) were not observed either by Waiting on the Task or accessing its Exception property. As a result, the unobserved exception was rethrown by the finalizer thread. ---> System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'System.Net.Sockets.UdpClient'.
  at System.Net.Sockets.UdpClient.CheckDisposed () [0x0000b] in /Users/builder/data/lanes/2923/52635947/source/mono/mcs/class/System/System.Net.Sockets/UdpClient.cs:601 
  at System.Net.Sockets.UdpClient.EndReceive (IAsyncResult asyncResult, System.Net.IPEndPoint& remoteEP) [0x00000] in /Users/builder/data/lanes/2923/52635947/source/mono/mcs/class/System/System.Net.Sockets/UdpClient.cs:475 
  at System.Net.Sockets.UdpClient.<ReceiveAsync>m__0 (IAsyncResult r) [0x00002] in /Users/builder/data/lanes/2923/52635947/source/mono/mcs/class/System/System.Net.Sockets/UdpClient.cs:610 
  at (wrapper delegate-invoke) System.Func`2[System.IAsyncResult,System.Net.Sockets.UdpReceiveResult]:invoke_TResult_T (System.IAsyncResult)
  at System.Threading.Tasks.TaskFactory`1[TResult].FromAsyncCoreLogic (IAsyncResult iar, System.Func`2 endFunction, System.Action`1 endAction, System.Threading.Tasks.Task`1 promise, Boolean requiresSynchronization) [0x00014] in /Users/builder/data/lanes/2923/52635947/source/mono/external/referencesource/mscorlib/system/threading/Tasks/FutureFactory.cs:550 
  --- End of inner exception stack trace ---
---> (Inner Exception #0) System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'System.Net.Sockets.UdpClient'.
  at System.Net.Sockets.UdpClient.CheckDisposed () [0x0000b] in /Users/builder/data/lanes/2923/52635947/source/mono/mcs/class/System/System.Net.Sockets/UdpClient.cs:601 
  at System.Net.Sockets.UdpClient.EndReceive (IAsyncResult asyncResult, System.Net.IPEndPoint& remoteEP) [0x00000] in /Users/builder/data/lanes/2923/52635947/source/mono/mcs/class/System/System.Net.Sockets/UdpClient.cs:475 
  at System.Net.Sockets.UdpClient.<ReceiveAsync>m__0 (IAsyncResult r) [0x00002] in /Users/builder/data/lanes/2923/52635947/source/mono/mcs/class/System/System.Net.Sockets/UdpClient.cs:610 
  at (wrapper delegate-invoke) System.Func`2[System.IAsyncResult,System.Net.Sockets.UdpReceiveResult]:invoke_TResult_T (System.IAsyncResult)
  at System.Threading.Tasks.TaskFactory`1[TResult].FromAsyncCoreLogic (IAsyncResult iar, System.Func`2 endFunction, System.Action`1 endAction, System.Threading.Tasks.Task`1 promise, Boolean requiresSynchronization) [0x00014] in /Users/builder/data/lanes/2923/52635947/source/mono/external/referencesource/mscorlib/system/threading/Tasks/FutureFactory.cs:550 <---

    at dalvik.system.NativeStart.run(Native Method)

Another variants it found:

Xamarin caused by: android.runtime.JavaProxyThrowable: System.AggregateException: A Task's exception(s) were not observed either by Waiting on the Task or accessing its Exception property. As a result, the unobserved exception was rethrown by the finalizer thread. ---> System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'System.Net.Sockets.UdpClient'.
  at System.Net.Sockets.UdpClient.CheckDisposed () <0xa20dee30 + 0x00043> in <filename unknown>:0 
  at System.Net.Sockets.UdpClient.EndReceive (IAsyncResult asyncResult, System.Net.IPEndPoint& remoteEP) <0xa1f86550 + 0x0001b> in <filename unknown>:0 
  at System.Net.Sockets.UdpClient.<ReceiveAsync>m__0 (IAsyncResult r) <0xa1f86270 + 0x0002f> in <filename unknown>:0 
  at (wrapper delegate-invoke) System.Func`2[System.IAsyncResult,System.Net.Sockets.UdpReceiveResult]:invoke_TResult_T (System.IAsyncResult)
  at System.Threading.Tasks.TaskFactory`1[TResult].FromAsyncCoreLogic (IAsyncResult iar, System.Func`2 endFunction, System.Action`1 endAction, System.Threading.Tasks.Task`1 promise, Boolean requiresSynchronization) <0xa1f85fb8 + 0x0006e> in <filename unknown>:0 
  --- End of inner exception stack trace ---
---> (Inner Exception #0) System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'System.Net.Sockets.UdpClient'.
  at System.Net.Sockets.UdpClient.CheckDisposed () <0xa20dee30 + 0x00043> in <filename unknown>:0 
  at System.Net.Sockets.UdpClient.EndReceive (IAsyncResult asyncResult, System.Net.IPEndPoint& remoteEP) <0xa1f86550 + 0x0001b> in <filename unknown>:0 
  at System.Net.Sockets.UdpClient.<ReceiveAsync>m__0 (IAsyncResult r) <0xa1f86270 + 0x0002f> in <filename unknown>:0 
  at (wrapper delegate-invoke) System.Func`2[System.IAsyncResult,System.Net.Sockets.UdpReceiveResult]:invoke_TResult_T (System.IAsyncResult)
  at System.Threading.Tasks.TaskFactory`1[TResult].FromAsyncCoreLogic (IAsyncResult iar, System.Func`2 endFunction, System.Action`1 endAction, System.Threading.Tasks.Task`1 promise, Boolean requiresSynchronization) <0xa1f85fb8 + 0x0006e> in <filename unknown>:0 <---

    at dalvik.system.NativeStart.run(Native Method)

And a more interesting different exception:

Xamarin caused by: android.runtime.JavaProxyThrowable: System.UriFormatException: Invalid URI: The Authority/Host could not be parsed.
  at System.Uri.Parse (UriKind kind, System.String uriString) <0xa218b4a0 + 0x0008f> in <filename unknown>:0 
  at System.Uri.ParseUri (UriKind kind) <0xa218b3c8 + 0x0001f> in <filename unknown>:0 
  at System.Uri..ctor (System.String uriString, Boolean dontEscape) <0xa218b230 + 0x00127> in <filename unknown>:0 
  at System.Uri..ctor (System.String uriString) <0xa218b200 + 0x0001f> in <filename unknown>:0 
  at UXDivers.Gorilla.ConnectPageViewModel.ConnectDisconnect () <0xa218b028 + 0x000e3> in <filename unknown>:0 
  at Xamarin.Forms.Command+<>c__DisplayClass5_0.<.ctor>b__0 (System.Object o) <0xa218b008 + 0x00014> in <filename unknown>:0 
  at Xamarin.Forms.Command.Execute (System.Object parameter) <0xa218a960 + 0x0001b> in <filename unknown>:0 
  at Xamarin.Forms.Button.Xamarin.Forms.IButtonController.SendClicked () <0xa218a900 + 0x00034> in <filename unknown>:0 
  at Xamarin.Forms.Platform.Android.AppCompat.ButtonRenderer+ButtonClickListener.OnClick (Android.Views.View v) <0xa218a7b8 + 0x0005f> in <filename unknown>:0 
  at Android.Views.View+IOnClickListenerInvoker.n_OnClick_Landroid_view_View_ (IntPtr jnienv, IntPtr native__this, IntPtr native_v) <0xa218a548 + 0x00059> in <filename unknown>:0 
  at (wrapper dynamic-method) System.Object:d7015ff6-e5ee-485d-86cc-6da2544a9ae3 (intptr,intptr,intptr)
    at md5270abb39e60627f0f200893b490a1ade.ButtonRenderer_ButtonClickListener.n_onClick(Native Method)
    at md5270abb39e60627f0f200893b490a1ade.ButtonRenderer_ButtonClickListener.onClick(ButtonRenderer_ButtonClickListener.java:30)
    at android.view.View.performClick(View.java:4438)
    at android.view.View$PerformClick.run(View.java:18422)
    at android.os.Handler.handleCallback(Handler.java:733)
    at android.os.Handler.dispatchMessage(Handler.java:95)
    at android.os.Looper.loop(Looper.java:136)
    at android.app.ActivityThread.main(ActivityThread.java:5017)
    at java.lang.reflect.Method.invokeNative(Native Method)
    at java.lang.reflect.Method.invoke(Method.java:515)
    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:779)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:595)
    at dalvik.system.NativeStart.main(Native Method)

I hope this helps!

LeoHere commented 8 years ago

Couple of things to try:

UXDivers.Gorilla.Config gorillaConfig = new UXDivers.Gorilla.Config();
gorillaConfig.DiscoveryMode = false;
gorillaConfig.AutoConnect = false;
gorillaConfig.RememberLastConnectedServerAddress = false;

Any chance I can access the solution you are using? I might be able to help you faster.