Android crash: ForegroundServiceDidNotStartInTimeException

[binwiederhier]

Exception android.app.RemoteServiceException$ForegroundServiceDidNotStartInTimeException:
  at android.app.ActivityThread.generateForegroundServiceDidNotStartInTimeException (ActivityThread.java:2404)
  at android.app.ActivityThread.throwRemoteServiceException (ActivityThread.java:2372)
  at android.app.ActivityThread.-$$Nest$mthrowRemoteServiceException (Unknown Source)
  at android.app.ActivityThread$H.handleMessage (ActivityThread.java:2748)
  at android.os.Handler.dispatchMessage (Handler.java:110)
  at android.os.Looper.dispatchMessage (Looper.java:315)
  at android.os.Looper.loopOnce (Looper.java:251)
  at android.os.Looper.loop (Looper.java:349)
  at android.app.ActivityThread.main (ActivityThread.java:9041)
  at java.lang.reflect.Method.invoke
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:593)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:929)
Caused by android.app.StackTrace: Last startServiceCommon() call for this service was made here
  at android.app.ContextImpl.startServiceCommon (ContextImpl.java:2049)
  at android.app.ContextImpl.startForegroundService (ContextImpl.java:2003)
  at android.content.ContextWrapper.startForegroundService (ContextWrapper.java:860)
  at androidx.core.content.ContextCompat$Api26Impl.startForegroundService (ContextCompat.java:1091)
  at androidx.core.content.ContextCompat.startForegroundService (ContextCompat.java:749)
  at io.heckel.ntfy.service.SubscriberServiceManager$ServiceStartWorker$doWork$2.invokeSuspend (SubscriberServiceManager.kt:58)
  at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith (ContinuationImpl.kt:33)
  at kotlinx.coroutines.DispatchedTask.run (DispatchedTask.kt:106)
  at kotlinx.coroutines.internal.LimitedDispatcher$Worker.run (LimitedDispatcher.kt:115)
  at kotlinx.coroutines.scheduling.TaskImpl.run (Tasks.kt:100)
  at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely (CoroutineScheduler.kt:584)
  at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask (CoroutineScheduler.kt:793)
  at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker (CoroutineScheduler.kt:697)
  at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run (CoroutineScheduler.kt:684)```

[binwiederhier]

binwiederhier/ntfy-android@1cb765f

[binwiederhier]

  at android.app.ActivityThread.handleCreateService (ActivityThread.java:4787)
  at android.app.ActivityThread.-$$Nest$mhandleCreateService (Unknown Source)
  at android.app.ActivityThread$H.handleMessage (ActivityThread.java:2368)
  at android.os.Handler.dispatchMessage (Handler.java:111)
  at android.os.Looper.loopOnce (Looper.java:242)
  at android.os.Looper.loop (Looper.java:362)
  at android.app.ActivityThread.main (ActivityThread.java:8393)
  at java.lang.reflect.Method.invoke
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:552)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:992)
Caused by android.app.ForegroundServiceStartNotAllowedException: Service.startForeground() not allowed due to mAllowStartForeground false: service io.heckel.ntfy/.service.SubscriberService
  at android.app.ForegroundServiceStartNotAllowedException$1.createFromParcel (ForegroundServiceStartNotAllowedException.java:54)
  at android.app.ForegroundServiceStartNotAllowedException$1.createFromParcel (ForegroundServiceStartNotAllowedException.java:50)
  at android.os.Parcel.readParcelableInternal (Parcel.java:4892)
  at android.os.Parcel.readParcelable (Parcel.java:4874)
  at android.os.Parcel.createExceptionOrNull (Parcel.java:3074)
  at android.os.Parcel.createException (Parcel.java:3063)
  at android.os.Parcel.readException (Parcel.java:3046)
  at android.os.Parcel.readException (Parcel.java:2988)
  at android.app.IActivityManager$Stub$Proxy.setServiceForeground (IActivityManager.java:7154)
  at android.app.Service.startForeground (Service.java:862)
  at io.heckel.ntfy.util.UtilKt$$ExternalSyntheticApiModelOutline0.m (D8$$SyntheticClass)
  at io.heckel.ntfy.service.SubscriberService.onCreate (SubscriberService.kt:103)
  at android.app.ActivityThread.handleCreateService (ActivityThread.java:4774)

[binwiederhier]

This is still happening on 1.20.0. As far as I can see, fewer cases. But still there, so I'm re-opening.

[binwiederhier]

Still happening. This was after toggling the "Connection protocol" in the settings (which restarts the service):

It happened again after switching the connection protocol from JSON stream to WebSockets (which restarts the service):

2026-01-03 11:35:18.594 11243-11243 WM-Processor            io.heckel.ntfy.debug                 D  Processor 6b78eef4-c869-4281-b912-7ddce0660b19 executed; reschedule = false
2026-01-03 11:35:18.594 11243-11243 WM-SystemJobService     io.heckel.ntfy.debug                 D  6b78eef4-c869-4281-b912-7ddce0660b19 executed on JobScheduler
2026-01-03 11:35:18.599 11243-11258 WM-GreedyScheduler      io.heckel.ntfy.debug                 D  Cancelling work ID 6b78eef4-c869-4281-b912-7ddce0660b19
2026-01-03 11:35:18.728 11243-11243 VRI[DetailActivity]     io.heckel.ntfy.debug                 D  visibilityChanged oldVisibility=true newVisibility=false
2026-01-03 11:35:18.754 11243-11243 WindowOnBackDispatcher  io.heckel.ntfy.debug                 W  sendCancelIfRunning: isInProgress=false callback=android.app.Activity$$ExternalSyntheticLambda0@f32aa13
2026-01-03 11:35:18.756 11243-11243 ViewRootImpl            io.heckel.ntfy.debug                 D  Skipping stats log for color mode
2026-01-03 11:35:20.969 11243-11243 WindowOnBackDispatcher  io.heckel.ntfy.debug                 W  sendCancelIfRunning: isInProgress=false callback=android.widget.PopupWindow$PopupDecorView$$ExternalSyntheticLambda1@1d099d7
2026-01-03 11:35:20.982 11243-11243 NtfySettingsActivity    io.heckel.ntfy.debug                 D  Create io.heckel.ntfy.ui.SettingsActivity@729f3f9
2026-01-03 11:35:20.991 11243-11243 AutofillManager         io.heckel.ntfy.debug                 D  Fill dialog is enabled:false, hints=[]
2026-01-03 11:35:21.389 11243-11261 HWUI                    io.heckel.ntfy.debug                 D  endAllActiveAnimators on 0x70b77623cc60 (MenuPopupWindow$MenuDropDownListView) with handle 0x70b6e6209430
2026-01-03 11:35:21.412 11243-11243 InsetsController        io.heckel.ntfy.debug                 D  hide(ime(), fromIme=false)
2026-01-03 11:35:21.412 11243-11243 ImeTracker              io.heckel.ntfy.debug                 I  io.heckel.ntfy.debug:afe9adf: onCancelled at PHASE_CLIENT_ALREADY_HIDDEN
2026-01-03 11:35:21.525 11243-11243 VRI[MainActivity]       io.heckel.ntfy.debug                 D  visibilityChanged oldVisibility=true newVisibility=false
2026-01-03 11:35:25.600 10662-10700 NtfySubscriberConn      io.heckel.ntfy                       D  [http://10.0.2.2:2586/11] (Re-)starting connection for subscriptions: {11=6036667}
2026-01-03 11:35:25.600 10662-10700 NtfyApiService          io.heckel.ntfy                       D  Opening subscription connection to http://10.0.2.2:2586/11/json?since=none
2026-01-03 11:35:25.606 10662-10700 NtfySubscriberConn      io.heckel.ntfy                       D  [http://10.0.2.2:2586/11] Connection is active (failed=false, callCanceled=false, jobActive=true, serviceStarted=true
2026-01-03 11:35:25.619 10662-11376 NtfyApiService          io.heckel.ntfy                       E  Connection to http://10.0.2.2:2586/11/json?since=none failed (2): Failed to connect to /10.0.2.2:2586 (Explain with AI)
                                                                                                    java.net.ConnectException: Failed to connect to /10.0.2.2:2586
                                                                                                    	at okhttp3.internal.connection.ConnectPlan.connectSocket(ConnectPlan.kt:278)
                                                                                                    	at okhttp3.internal.connection.ConnectPlan.connectTcp(ConnectPlan.kt:135)
                                                                                                    	at okhttp3.internal.connection.FastFallbackExchangeFinder$launchTcpConnect$1.runOnce(FastFallbackExchangeFinder.kt:141)
                                                                                                    	at okhttp3.internal.concurrent.TaskRunner$runnable$1.run(TaskRunner.kt:81)
                                                                                                    	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1156)
                                                                                                    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:651)
                                                                                                    	at java.lang.Thread.run(Thread.java:1119)
                                                                                                    Caused by: java.net.ConnectException: failed to connect to /10.0.2.2 (port 2586) from /10.0.2.16 (port 40924) after 10000ms: isConnected failed: ECONNREFUSED (Connection refused)
                                                                                                    	at libcore.io.IoBridge.isConnected(IoBridge.java:347)
                                                                                                    	at libcore.io.IoBridge.connectErrno(IoBridge.java:237)
                                                                                                    	at libcore.io.IoBridge.connect(IoBridge.java:179)
                                                                                                    	at java.net.PlainSocketImpl.socketConnect(PlainSocketImpl.java:142)
                                                                                                    	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:390)
                                                                                                    	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:230)
                                                                                                    	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:212)
                                                                                                    	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:436)
                                                                                                    	at java.net.Socket.connect(Socket.java:646)
                                                                                                    	at okhttp3.internal.platform.Platform.connectSocket(Platform.kt:148)
                                                                                                    	at okhttp3.internal.connection.ConnectPlan.connectSocket(ConnectPlan.kt:276)
                                                                                                    	... 6 more
                                                                                                    Caused by: android.system.ErrnoException: isConnected failed: ECONNREFUSED (Connection refused)
                                                                                                    	at libcore.io.IoBridge.isConnected(IoBridge.java:334)
                                                                                                    	... 16 more
2026-01-03 11:35:27.387 11243-11243 WindowOnBackDispatcher  io.heckel.ntfy.debug                 W  sendCancelIfRunning: isInProgress=false callback=android.app.Dialog$$ExternalSyntheticLambda2@8006f0
2026-01-03 11:35:27.406 11243-11261 HWUI                    io.heckel.ntfy.debug                 D  endAllActiveAnimators on 0x70b776319420 (AlertController$RecycleListView) with handle 0x70b6e624bf10
2026-01-03 11:35:27.415 11243-11243 InputEventReceiver      io.heckel.ntfy.debug                 W  Attempted to finish an input event but the input event receiver has already been disposed.
2026-01-03 11:35:27.440 11243-11243 NtfySubscriberService   io.heckel.ntfy.debug                 D  Subscriber service has been destroyed
2026-01-03 11:35:27.441 11243-11243 NtfySubscriberService   io.heckel.ntfy.debug                 D  Stopping the foreground service
2026-01-03 11:35:27.441 11243-11243 NtfySubscriberConn      io.heckel.ntfy.debug                 D  [https://ntfy.sh/test123123123] Cancelling connection
2026-01-03 11:35:27.443 11243-11273 NtfySubscriberConn      io.heckel.ntfy.debug                 E  [https://ntfy.sh/test123123123] Connection failed: StandaloneCoroutine was cancelled
                                                                                                    kotlinx.coroutines.JobCancellationException: StandaloneCoroutine was cancelled; job=StandaloneCoroutine{Cancelling}@e177972
2026-01-03 11:35:27.443 11243-11273 NtfySubscriberConn      io.heckel.ntfy.debug                 D  [https://ntfy.sh/test123123123] Connection job SHUT DOWN
2026-01-03 11:35:27.455 11243-11365 NtfyApiService          io.heckel.ntfy.debug                 E  Connection to https://ntfy.sh/test123123123/json?since=none failed (1): stream was reset: CANCEL (Explain with AI)
                                                                                                    okhttp3.internal.http2.StreamResetException: stream was reset: CANCEL
                                                                                                    	at okhttp3.internal.http2.Http2Stream$FramingSource.read(Http2Stream.kt:398)
                                                                                                    	at okhttp3.internal.connection.Exchange$ResponseBodySource.read(Exchange.kt:346)
                                                                                                    	at okio.RealBufferedSource.exhausted(RealBufferedSource.kt:223)
                                                                                                    	at io.heckel.ntfy.msg.ApiService$subscribe$1.onResponse(ApiService.kt:167)
                                                                                                    	at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:576)
                                                                                                    	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1156)
                                                                                                    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:651)
                                                                                                    	at java.lang.Thread.run(Thread.java:1119)
2026-01-03 11:35:27.464 11243-11243 AndroidRuntime          io.heckel.ntfy.debug                 D  Shutting down VM
2026-01-03 11:35:27.465 11243-11243 AndroidRuntime          io.heckel.ntfy.debug                 E  FATAL EXCEPTION: main (Explain with AI)
                                                                                                    Process: io.heckel.ntfy.debug, PID: 11243
                                                                                                    android.app.RemoteServiceException$ForegroundServiceDidNotStartInTimeException: Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{cd5d441 u0 io.heckel.ntfy.debug/io.heckel.ntfy.service.SubscriberService c:io.heckel.ntfy.debug}
                                                                                                    	at android.app.ActivityThread.generateForegroundServiceDidNotStartInTimeException(ActivityThread.java:2391)
                                                                                                    	at android.app.ActivityThread.throwRemoteServiceException(ActivityThread.java:2359)
                                                                                                    	at android.app.ActivityThread.-$$Nest$mthrowRemoteServiceException(Unknown Source:0)
                                                                                                    	at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2741)
                                                                                                    	at android.os.Handler.dispatchMessage(Handler.java:110)
                                                                                                    	at android.os.Looper.loopOnce(Looper.java:248)
                                                                                                    	at android.os.Looper.loop(Looper.java:338)
                                                                                                    	at android.app.ActivityThread.main(ActivityThread.java:9067)
                                                                                                    	at java.lang.reflect.Method.invoke(Native Method)
                                                                                                    	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:593)
                                                                                                    	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:932)
                                                                                                    Caused by: android.app.StackTrace: Last startServiceCommon() call for this service was made here
                                                                                                    	at android.app.ContextImpl.startServiceCommon(ContextImpl.java:2055)
                                                                                                    	at android.app.ContextImpl.startForegroundService(ContextImpl.java:2009)
                                                                                                    	at android.content.ContextWrapper.startForegroundService(ContextWrapper.java:860)
                                                                                                    	at androidx.core.content.ContextCompat$Api26Impl.startForegroundService(ContextCompat.java:1124)
                                                                                                    	at androidx.core.content.ContextCompat.startForegroundService(ContextCompat.java:704)
                                                                                                    	at io.heckel.ntfy.service.SubscriberServiceManager$ServiceStartWorker$doWork$2.invokeSuspend(SubscriberServiceManager.kt:56)
                                                                                                    	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:34)
                                                                                                    	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:101)
                                                                                                    	at kotlinx.coroutines.internal.LimitedDispatcher$Worker.run(LimitedDispatcher.kt:113)
                                                                                                    	at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:89)
                                                                                                    	at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:589)
                                                                                                    	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:823)
                                                                                                    	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:720)
                                                                                                    	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:707)
2026-01-03 11:35:27.478 11243-11243 Process                 io.heckel.ntfy.debug                 I  Sending signal. PID: 11243 SIG: 9
2026-01-03 11:35:27.801 11384-11384 ckel.ntfy.debug         io.heckel.ntfy.debug                 I  Late-enabling -Xcheck:jni
2026-01-03 11:35:27.845 11384-11384 ckel.ntfy.debug         io.heckel.ntfy.debug                 I  Using CollectorTypeCMC GC.
2026-01-03 11:35:27.847 11384-11384 ckel.ntfy.debug         io.heckel.ntfy.debug                 W  Unexpected CPU variant for x86: x86_64.
                                                                                                    Known variants: atom, sandybridge, silvermont, goldmont, goldmont-plus, goldmont-without-sha-xsaves, tremont, kabylake, alderlake, default
2026-01-03 11:35:27.859 11384-11384 nativeloader            io.heckel.ntfy.debug                 D  Load libframework-connectivity-tiramisu-jni.so using APEX ns com_android_tethering for caller /apex/com.android.tethering/javalib/framework-connectivity-t.jar: ok
2026-01-03 11:35:27.887 11384-11384 ApplicationLoaders      io.heckel.ntfy.debug                 D  Returning zygote-cached class loader: /system_ext/framework/androidx.window.extensions.jar
2026-01-03 11:35:27.887 11384-11384 ApplicationLoaders      io.heckel.ntfy.debug                 D  Returning zygote-cached class loader: /system_ext/framework/androidx.window.sidecar.jar
2026-01-03 11:35:28.075 11384-11384 nativeloader            io.heckel.ntfy.debug                 D  Configuring clns-9 for other apk /data/app/~~v4El7z8pYIURKP1vEYotlg==/io.heckel.ntfy.debug-PNblKOPuOAQwiu72hdtnqQ==/base.apk. target_sdk_version=36, uses_libraries=, library_path=/data/app/~~v4El7z8pYIURKP1vEYotlg==/io.heckel.ntfy.debug-PNblKOPuOAQwiu72hdtnqQ==/lib/x86_64:/data/app/~~v4El7z8pYIURKP1vEYotlg==/io.heckel.ntfy.debug-PNblKOPuOAQwiu72hdtnqQ==/base.apk!/lib/x86_64, permitted_path=/data:/mnt/expand:/data/user/0/io.heckel.ntfy.debug
2026-01-03 11:35:28.079 11384-11384 ckel.ntfy.debug         io.heckel.ntfy.debug                 I  AssetManager2(0x70b7c61ed778) locale list changing from [] to [en-US]
2026-01-03 11:35:28.083 11384-11384 GraphicsEnvironment     io.heckel.ntfy.debug                 V  Currently set values for:
2026-01-03 11:35:28.083 11384-11384 GraphicsEnvironment     io.heckel.ntfy.debug                 V    angle_gl_driver_selection_pkgs=[]

[binwiederhier]

Here's my latest attempt to fix this: binwiederhier/ntfy-android@d064e75 -- Instead of restarting the foreground service, we simply refresh the connections when user, protocol or headers change.