search

jellyfin / jellyfin-androidtv

Android TV Client for Jellyfin
https://jellyfin.org
GNU General Public License v2.0
2.77k stars 470 forks source link

Jellyfin Debug build crashes with java.lang.IllegalStateException: KoinApplication has not been started #1824

Closed kevgrig closed 1 year ago

kevgrig commented 2 years ago

Describe the bug

Main Jellyfin app works fine. I'm trying to build the Jellyfin Debug app to make some modifications (and hopefully pull requests!). I'm trying to start by just building and launching but it crashes:

  1. Pull and build (no local changes): 
    $ export ANDROID_SDK_ROOT=$HOME/Android/Sdk
$ export PATH=$ANDROID_SDK_ROOT:$ANDROID_SDK_ROOT/platform-tools/:${PATH}
$ git pull
[...]
$ git rev-parse HEAD
12a9997a4ad7c0fcfe93dc115b230beff0b699b7
$ ./gradlew assembleDebug
[...]
BUILD SUCCESSFUL in 4m 56s
  2. Start logcat in one window: 
    adb logcat -v time
  3. Install debug build onto FireTV in another window (finished around 07-07 13:47): 
    $ adb install -r ./app/build/outputs/apk/debug/jellyfin-androidtv-v0.0.0-dev.1-debug.apk
[...]
Success
  4. Start Jellyfin Debug on FireTV (around 07-07 13:51:33). It hangs at the following view: IMG_20220707_1552044
  5. It finally dies at around 07-07 13:52:24:
07-07 13:52:14.845 I/Process (14195): Sending signal. PID: 14195 SIG: 9

07-07 13:52:15.233 D/AndroidRuntime(14470): Shutting down VM
--------- beginning of crash
07-07 13:52:15.235 E/AndroidRuntime(14470): FATAL EXCEPTION: main
07-07 13:52:15.235 E/AndroidRuntime(14470): Process: org.jellyfin.androidtv.debug:acra, PID: 14470
07-07 13:52:15.235 E/AndroidRuntime(14470): java.lang.RuntimeException: Unable to create application org.jellyfin.androidtv.JellyfinApplication: java.lang.IllegalStateException: KoinApplication has not been started
07-07 13:52:15.235 E/AndroidRuntime(14470):     at android.app.ActivityThread.handleBindApplication(ActivityThread.java:4883)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at android.app.ActivityThread.access$1500(ActivityThread.java:160)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1382)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at android.os.Handler.dispatchMessage(Handler.java:102)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at android.os.Looper.loop(Looper.java:135)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at android.app.ActivityThread.main(ActivityThread.java:5597)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at java.lang.reflect.Method.invoke(Native Method)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at java.lang.reflect.Method.invoke(Method.java:372)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:984)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:779)
07-07 13:52:15.235 E/AndroidRuntime(14470): Caused by: java.lang.IllegalStateException: KoinApplication has not been started
07-07 13:52:15.235 E/AndroidRuntime(14470):     at org.koin.core.context.GlobalContext.get(GlobalContext.kt:36)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at org.koin.android.ext.android.AndroidKoinScopeExtKt.getKoinScope(AndroidKoinScopeExt.kt:18)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at org.jellyfin.androidtv.JellyfinApplication$onCreate$$inlined$inject$default$1.invoke(ComponentCallbackExt.kt:60)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at kotlin.SynchronizedLazyImpl.getValue(LazyJVM.kt:74)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at org.jellyfin.androidtv.JellyfinApplication.onCreate$lambda-0(JellyfinApplication.kt:39)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at org.jellyfin.androidtv.JellyfinApplication.onCreate(JellyfinApplication.kt:40)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at android.app.Instrumentation.callApplicationOnCreate(Instrumentation.java:1015)
07-07 13:52:15.235 E/AndroidRuntime(14470):     at android.app.ActivityThread.handleBindApplication(ActivityThread.java:4880)
07-07 13:52:15.235 E/AndroidRuntime(14470):     ... 9 more
07-07 13:52:15.235 I/AndroidRuntime(14470): To Report FATAL to activityManagerService
07-07 13:52:15.235 I/ActivityManager( 1841): handleApplicationCrash
07-07 13:52:15.301 W/ActivityManager( 1841):   Force finishing activity 1 org.jellyfin.androidtv.debug/org.acra.dialog.CrashReportDialog

firetvcrash.txt

Logs

Output was too large for this field so I attached it as firetvcrash.txt in the description above.

Application version

master

Where did you install the app from?

Sideloaded APK

Device information

Amazon Fire TV, Fire OS 5.2.7.4

Android version

$ adb shell getprop ro.build.version.release
5.1.1

Jellyfin server version

10.8.0

nielsvanvelzen commented 2 years ago

One thing that I find strange is that your screenshot shows the "normal" logo. The Jellyfin logo should look orange in debug builds. You could try clearing Gradle cache ./gradlew clean before attempting a new build.

In the log file I can see this exception:

07-07 13:52:14.181 E/ACRA    (14195): ACRA caught a HttpException for org.jellyfin.androidtv.debug
07-07 13:52:14.181 E/ACRA    (14195): org.jellyfin.apiclient.model.net.HttpException: VolleyError com.android.volley.TimeoutError:
07-07 13:52:14.181 E/ACRA    (14195):   at org.jellyfin.apiclient.interaction.VolleyErrorListener.onErrorResponse(VolleyErrorListener.java:25)
07-07 13:52:14.181 E/ACRA    (14195):   at com.android.volley.Request.deliverError(Request.java:648)
07-07 13:52:14.181 E/ACRA    (14195):   at com.android.volley.ExecutorDelivery$ResponseDeliveryRunnable.run(ExecutorDelivery.java:104)
07-07 13:52:14.181 E/ACRA    (14195):   at android.os.Handler.handleCallback(Handler.java:739)
07-07 13:52:14.181 E/ACRA    (14195):   at android.os.Handler.dispatchMessage(Handler.java:95)
07-07 13:52:14.181 E/ACRA    (14195):   at android.os.Looper.loop(Looper.java:135)
07-07 13:52:14.181 E/ACRA    (14195):   at android.app.ActivityThread.main(ActivityThread.java:5597)
07-07 13:52:14.181 E/ACRA    (14195):   at java.lang.reflect.Method.invoke(Native Method)
07-07 13:52:14.181 E/ACRA    (14195):   at java.lang.reflect.Method.invoke(Method.java:372)
07-07 13:52:14.181 E/ACRA    (14195):   at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:984)
07-07 13:52:14.181 E/ACRA    (14195):   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:779)
07-07 13:52:14.181 E/ACRA    (14195):   Suppressed: kotlinx.coroutines.DiagnosticCoroutineContextException: [StandaloneCoroutine{Cancelling}@15f81906, Dispatchers.IO]
07-07 13:52:14.181 E/ACRA    (14195): Caused by: com.android.volley.TimeoutError
07-07 13:52:14.181 E/ACRA    (14195):   at com.android.volley.toolbox.NetworkUtility.shouldRetryException(NetworkUtility.java:162)
07-07 13:52:14.181 E/ACRA    (14195):   at com.android.volley.toolbox.BasicNetwork.performRequest(BasicNetwork.java:145)
07-07 13:52:14.181 E/ACRA    (14195):   at com.android.volley.NetworkDispatcher.processRequest(NetworkDispatcher.java:132)
07-07 13:52:14.181 E/ACRA    (14195):   at com.android.volley.NetworkDispatcher.processRequest(NetworkDispatcher.java:111)
07-07 13:52:14.181 E/ACRA    (14195):   at com.android.volley.NetworkDispatcher.run(NetworkDispatcher.java:90)

So I think the app is unable to connect to your server. In that cache you can try clearing the app data and restart the app.

kevgrig commented 2 years ago

Thanks for taking a look!

That's odd that the logo isn't the expected one. I restarted my FireTV, uninstalled the app, cleaned, re-built, and re-installed. After launching, I tried to create a fresh connection to my server but it said:

Unable to connect to server, tried the following addresses: [...] - Server uses version 10.8.0 which is not supported

I guess I had upgraded my server since the last time I tried the debug build. Is it safe to try to bypass this error?

nielsvanvelzen commented 2 years ago

The app currently supports 10.8.1 and newer. So you should upgrade your server once more.

kevgrig commented 2 years ago

I ugpraded to 10.8.1 and I could log in but the same issue occurred (and the logo still isn't orange). Here is the logcat:

firetvcrash2.txt

I still saw the com.android.volley.TimeoutError so then I logged the main production Jellyfin app and that doesn't show the timeout:

firetvgood.txt

Next, I added $request_time $upstream_response_time to my nginx log_format to see how long requests are taking and re-launched Jellyfin Debug. Interestingly, now every time I try to launch Jellyfin Debug, it crashes nearly immediately (whereas before it would take 30 seconds or so) and now there is no timeout:

firetvcrash3.txt

By the way, here are the three requests in nginx from launch to crash (I removed the userId in case it's sensitive). All responses are 200 and fast:

192.168.1.254 - - [08/Jul/2022:09:42:25 -0500] "GET /Users/Me HTTP/2.0" 200 1954 "-" "Ktor client" "-" 0.013 0.013
192.168.1.254 - - [08/Jul/2022:09:42:26 -0500] "GET /DisplayPreferences/livetv?userId=[...]&client=jellyfin-androidtv HTTP/2.0" 200 459 "-" "Ktor client" "-" 0.009 0.010
192.168.1.254 - - [08/Jul/2022:09:42:26 -0500] "GET /DisplayPreferences/usersettings?userId=[...]&client=emby HTTP/2.0" 200 1393 "-" "Ktor client" "-" 0.006 0.006

It seems there's still the java.lang.IllegalStateException: KoinApplication has not been started exception, although maybe this is related to the CrashReportDialog? Is there a way to disable CrashReportDialog and just have it crash "normally"?

nielsvanvelzen commented 2 years ago

It's weird that the app crashes when signing in works fine. Do you use the Nginx config from docs.jellyfin.org?

It seems there's still the java.lang.IllegalStateException: KoinApplication has not been started exception, although maybe this is related to the CrashReportDialog? Is there a way to disable CrashReportDialog and just have it crash "normally"?

Yeah that's definitely caused by the crash reporting dialog, there is a PR that rewrites crash reporting (#1820) that removes the dialog. And another one that removes crash reporting for 0.13.7 (#1827).

kevgrig commented 2 years ago

Interesting, so I cleared data/cache, re-launched, and logged into the Jellyfin server directly to port 8096 (the FireTV is currently on the same LAN as the server), and it worked! So it seems to be proximately related to going through HTTPS/nginx.

It's weird that the app crashes when signing in works fine. Do you use the Nginx config from docs.jellyfin.org?

Yes:

nginx.conf ``` server { listen 443 ssl http2; listen [::]:443 ssl http2; server_name jellyfin.myplaceonline.com; # use a variable to store the upstream proxy # in this example we are using a hostname which is resolved via DNS # (if you aren't using DNS remove the resolver line and change the variable to point to an IP address e.g `set $jellyfin 127.0.0.1`) set $jellyfin 127.0.0.1; ssl_certificate /etc/letsencrypt/live/jellyfin.myplaceonline.com/fullchain.pem; ssl_certificate_key /etc/letsencrypt/live/jellyfin.myplaceonline.com/privkey.pem; #include /etc/letsencrypt/options-ssl-nginx.conf; #ssl_dhparam /etc/letsencrypt/ssl-dhparams.pem; add_header Strict-Transport-Security "max-age=31536000" always; ssl_trusted_certificate /etc/letsencrypt/live/jellyfin.myplaceonline.com/chain.pem; ssl_stapling on; ssl_stapling_verify on; # Security / XSS Mitigation Headers add_header X-Frame-Options "SAMEORIGIN"; add_header X-XSS-Protection "1; mode=block"; add_header X-Content-Type-Options "nosniff"; # Content Security Policy # See: https://developer.mozilla.org/en-US/docs/Web/HTTP/CSP # Enforces https content and restricts JS/CSS to origin # External Javascript (such as cast_sender.js for Chromecast) must be whitelisted. add_header Content-Security-Policy "default-src https: data: blob: http://image.tmdb.org; style-src 'self' 'unsafe-inline'; script-src 'self' 'unsafe-inline' https://www.gstatic.com/cv/js/sender/v1/cast_sender.js https://www.gstatic.com/eureka/clank/95/cast_sender.js https://www.gstatic.com/eureka/clank/96/cast_sender.js https://www.gstatic.com/eureka/clank/97/cast_sender.js https://www.youtube.com blob:; worker-src 'self' blob:; connect-src 'self'; object-src 'none'; frame-ancestors 'self'"; location = / { return 302 http://$host/web/; #return 302 https://$host/web/; } location / { # Proxy main Jellyfin traffic proxy_pass http://$jellyfin:8096; proxy_set_header Host $host; proxy_set_header X-Real-IP $remote_addr; proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for; proxy_set_header X-Forwarded-Proto $scheme; proxy_set_header X-Forwarded-Protocol $scheme; proxy_set_header X-Forwarded-Host $http_host; # Disable buffering when the nginx proxy gets very resource heavy upon streaming proxy_buffering off; } # location block for /web - This is purely for aesthetics so /web/#!/ works instead of having to go to /web/index.html/#!/ location = /web/ { # Proxy main Jellyfin traffic proxy_pass http://$jellyfin:8096/web/index.html; proxy_set_header Host $host; proxy_set_header X-Real-IP $remote_addr; proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for; proxy_set_header X-Forwarded-Proto $scheme; proxy_set_header X-Forwarded-Protocol $scheme; proxy_set_header X-Forwarded-Host $http_host; } location /socket { # Proxy Jellyfin Websockets traffic proxy_pass http://$jellyfin:8096; proxy_http_version 1.1; proxy_set_header Upgrade $http_upgrade; proxy_set_header Connection "upgrade"; proxy_set_header Host $host; proxy_set_header X-Real-IP $remote_addr; proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for; proxy_set_header X-Forwarded-Proto $scheme; proxy_set_header X-Forwarded-Protocol $scheme; proxy_set_header X-Forwarded-Host $http_host; } ```

Yeah that's definitely caused by the crash reporting dialog, there is a PR that rewrites crash reporting (https://github.com/jellyfin/jellyfin-androidtv/pull/1820) that removes the dialog. And another one that removes crash reporting for 0.13.7 (https://github.com/jellyfin/jellyfin-androidtv/pull/1827).

Thanks, I'll try one of them and report back.

kevgrig commented 2 years ago

I applied #1827, cleaned and rebuilt with gradle, pushed to the FireTV, cleared data and cache, re-launched and entered the https server and reproduced the crash. The IllegalStateException is gone but I don't see any obvious crash stack:

firetvcrash4.txt

I see the com.android.volley.TimeoutError again but nginx shows all responses below 500ms (and this is traffic on a LAN, so no internet latency).

192.168.1.254 - - [08/Jul/2022:10:28:34 -0500] "GET /System/Info/Public HTTP/2.0" 200 213 "-" "Ktor client" "-" 0.007 0.007
192.168.1.254 - - [08/Jul/2022:10:28:34 -0500] "GET /Branding/Configuration HTTP/2.0" 200 28 "-" "Ktor client" "-" 0.003 0.003
192.168.1.254 - - [08/Jul/2022:10:28:34 -0500] "GET /Users/Public HTTP/2.0" 200 2 "-" "Ktor client" "-" 0.001 0.001
192.168.1.254 - - [08/Jul/2022:10:28:34 -0500] "GET /Users/Public HTTP/2.0" 200 2 "-" "Ktor client" "-" 0.002 0.002
192.168.1.254 - - [08/Jul/2022:10:28:35 -0500] "GET /QuickConnect/Initiate HTTP/2.0" 401 27 "-" "Ktor client" "-" 0.002 0.002
192.168.1.254 - - [08/Jul/2022:10:29:28 -0500] "POST /Users/AuthenticateByName HTTP/2.0" 200 3048 "-" "Ktor client" "-" 0.162 0.162
192.168.1.254 - - [08/Jul/2022:10:29:29 -0500] "GET /Users/Me HTTP/2.0" 200 1954 "-" "Ktor client" "-" 0.015 0.014
192.168.1.254 - - [08/Jul/2022:10:29:29 -0500] "GET /DisplayPreferences/livetv?userId=[...]&client=jellyfin-androidtv HTTP/2.0" 200 459 "-" "Ktor client" "-" 0.009 0.009
192.168.1.254 - - [08/Jul/2022:10:29:29 -0500] "GET /DisplayPreferences/usersettings?userId=[...]&client=emby HTTP/2.0" 200 1393 "-" "Ktor client" "-" 0.005 0.004
192.168.1.254 - - [08/Jul/2022:10:29:29 -0500] "POST /Sessions/Capabilities?playableMediaTypes=Video%2CAudio&supportedCommands=DisplayMessage%2CSendString&supportsMediaControl=true&supportsSync=false&supportsPersistentIdentifier=true HTTP/2.0" 204 0 "-" "Ktor client" "-" 0.037 0.014
192.168.1.254 - - [08/Jul/2022:10:29:29 -0500] "GET /Playback/BitrateTest?size=4000000 HTTP/2.0" 200 4194304 "-" "Ktor client" "-" 0.491 0.492

Do you think this timeout is causing the crash? The exception is immediately followed by crash handling but no stack:

07-08 08:30:00.260 I/AndroidRuntime(26364): To Report FATAL to activityManagerService
07-08 08:30:00.262 I/ActivityManager( 1838): handleApplicationCrash
07-08 08:30:00.325 W/ActivityManager( 1838):   Force finishing activity 1 org.jellyfin.androidtv.debug/org.jellyfin.androidtv.ui.browsing.MainActivity
07-08 08:30:00.330 I/ActivityManager( 1838): addErrorToDropBox inserted hashcode=62a2f6b8ffcf2f0ad9f44c3c1c9afaeab7df31ee for eventType crash.
07-08 08:30:00.331 I/Vlog    ( 1838): 3p:fg_crash:fgtracking=false;DV;1,key=org.jellyfin.androidtv.debug;DV;1,Counter=1.0;CT;1,unit=count;DV;1,metadata=62a2f6b8ffcf2f0ad9f44c3c1c9afaeab7df31ee!{"d"#{"app_version"#"1"}};DV;1:HI
07-08 08:30:00.339 I/Vlog    ( 1838): 3p:fg_crash:fgtracking=false;DV;1,key=org.jellyfin.androidtv.debug;DV;1,Counter=1.0;CT;1,unit=count;DV;1,metadata=62a2f6b8ffcf2f0ad9f44c3c1c9afaeab7df31ee!{"d"#{"app_version"#"1"$"source"#"dropbox"}};DV;1:HI
07-08 08:30:00.353 I/AndroidRuntime(26364): Finished reporting FATAL to activityManagerService
07-08 08:30:00.353 I/Process (26364): Sending signal. PID: 26364 SIG: 9

My FireTV is old so during app launch it might just be bottlenecked on CPU. I don't see what the timeout value is that's popping.

kevgrig commented 2 years ago

I see this exception earlier which suggests an issue with WebSockets.

07-08 08:29:35.876 W/OkHttpWebsocketSession(26364): WebSocket has failed
07-08 08:29:35.876 W/OkHttpWebsocketSession(26364): java.net.SocketTimeoutException: failed to connect to jellyfin.myplaceonline.com/104.14.153.2 (port 443) after 6000ms
07-08 08:29:35.876 W/OkHttpWebsocketSession(26364):     at libcore.io.IoBridge.connectErrno(IoBridge.java:169)

I just tried accessing the https URL in my browser and I see something similar in my debug console:

Firefox can’t establish a connection to the server at wss://[...]

So I guess there's some issue with web sockets. Not sure how to debug that. The nginx config has the recommended configuration:

    location /socket {
        # Proxy Jellyfin Websockets traffic
        proxy_pass http://$jellyfin:8096;
        proxy_http_version 1.1;
        proxy_set_header Upgrade $http_upgrade;
        proxy_set_header Connection "upgrade";
        proxy_set_header Host $host;
        proxy_set_header X-Real-IP $remote_addr;
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_set_header X-Forwarded-Proto $scheme;
        proxy_set_header X-Forwarded-Protocol $scheme;
        proxy_set_header X-Forwarded-Host $http_host;
    }
kevgrig commented 2 years ago

With my browser, if I add a 127.0.0.1 mapping to /etc/hosts then I don't get the error. So it's probably something to do with my router not supporting web sockets. Anyway, I'll look into that at some point but for now I can just use the direct LAN port of 8096 for my FireTV, which works. Thanks for the help!

nielsvanvelzen commented 2 years ago

The app should keep working when the WebSocket connection fails, but it does indeed indicate some kind of network issue in your setup.

kevgrig commented 2 years ago

If you still want to investigate why the app crashes on the https link, I'm glad to switch back and gather additional diagnostics.

jellyfin-bot commented 1 year ago

This issue has gone 120 days without comment. To avoid abandoned issues, it will be closed in 21 days if there are no new comments.

If you're the original submitter of this issue, please comment confirming if this issue still affects you in the latest release or master branch, or close the issue if it has been fixed. If you're another user also affected by this bug, please comment confirming so. Either action will remove the stale label.

This bot exists to prevent issues from becoming stale and forgotten. Jellyfin is always moving forward, and bugs are often fixed as side effects of other changes. We therefore ask that bug report authors remain vigilant about their issues to ensure they are closed if fixed, or re-confirmed - perhaps with fresh logs or reproduction examples - regularly. If you have any questions you can reach us on Matrix or Social Media.