调用了startForeground还是报错Context.startForegroundService() did not then call Service.startForeground()

一.问题背景

出现问题的应用是开机自启的应用，测试人员反馈monkey测试教材时间后，服务A产生大量的crash：Context.startForegroundService() did not then call Service.startForeground()。

报错信息如下：

E  FATAL EXCEPTION: main
   Process: com.kxf.pushkeepalive, PID: 30658
   android.app.RemoteServiceException: Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{12d95e1 u0 com.kxf.pushkeepalive/.service.MyFgService}
   	at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2005)
   	at android.os.Handler.dispatchMessage(Handler.java:106)
   	at android.os.Looper.loop(Looper.java:223)
   	at android.app.ActivityThread.main(ActivityThread.java:7656)
   	at java.lang.reflect.Method.invoke(Native Method)
   	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:592)
   	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:947)

二.问题分析

        从代码分析，服务A采用了startForegroundService的方式启动，并且在Service#onCreate方法里面调用了startForeground。排除了startForeground代码漏写的原因。

        分析启动流程：

android.app.ContextImpl#startForegroundService
android.app.ContextImpl#startServiceCommon
com.android.server.am.ActivityManagerService#startService
com.android.server.am.ActiveServices#startServiceLocked
com.android.server.am.ActiveServices#startServiceInnerLocked
com.android.server.am.ActiveServices#bringUpServiceLocked
com.android.server.am.ActiveServices#sendServiceArgsLocked
com.android.server.am.ActiveServices#scheduleServiceForegroundTransitionTimeoutLocked
	com.android.server.am.ActivityManagerService#SERVICE_FOREGROUND_TIMEOUT_MSG
	com.android.server.am.ActiveServices#SERVICE_START_FOREGROUND_TIMEOUT
		SERVICE_START_FOREGROUND_TIMEOUT = 10*1000
com.android.server.am.ActiveServices#realStartServiceLocked
	已经启动过走com.android.server.am.ActiveServices#sendServiceArgsLocked
android.app.ActivityThread.ApplicationThread#scheduleCreateService
android.app.ActivityThread#sendMessage(int, java.lang.Object, int, int, boolean)
	android.app.ActivityThread.H#CREATE_SERVICE
android.app.ActivityThread#handleCreateService
	service.onCreate()

        scheduleServiceForegroundTransitionTimeoutLocked方法中发送了一个10s的延迟消息，10s内没有执行完成startForeground，就会crash。

        我们调用startForeground的时机一般是在service.onCreate方法中，从上面流程可以看出，从延时消息发送到正在创建服务，是由ActivityThread.H这个handler来处理的。也就是说，可能在我们调用完startForegroundService之后，主线程可能比较繁忙，导致CREATE_SERVICE的消息一直没法处理，如果超过10s再执行onCreate方法，就会导致SERVICE_FOREGROUND_TIMEOUT_MSG超时，从而导致crash。

三.验证猜想

我们可以在startForegroundService后立马在主线程休眠11s：

public void openFgService(View view) {
        if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.O) {
            startForegroundService(new Intent(this, MyFgService.class));
            Log.v("MainActivity", "startForegroundService=" + MyFgService.class);
            try {
                Thread.sleep(11000);
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
            Log.d("MainActivity", "Thread.sleep over");
        }
    }

结果确实报错，由此可以证明猜想正确。

四.解决问题

        经过排查，发现是application的onCreat方法在低内存等系统负载较高的情况下，执行时间超过了10s，才导致服务的crash。做了两方面的优化：1.将startForegroundService的执行顺序放在application的onCreat方法最后执行；2.优化application的onCreat方法。