Foreground service stops while running a long task

2019-04-11 08:56发布

站内问答 / Android
603 0 6

I have a foreground service that should execute a long-running (~20 minutes) task in a single go (a file transfer using Bluetooth). However, the service gets stopped after a while.

As a simple test app that reproduces the issue, I did the following, first the activity:

public class MainActivity extends AppCompatActivity {

    private ServiceConnection connection = new ServiceConnection() {
        @Override
        public void onServiceConnected(ComponentName name, IBinder service) {
            TestService serv = ((TestService.TestServiceBinder) service).getService();
            serv.startLongProcess();
        }

        @Override
        public void onServiceDisconnected(ComponentName name) {

        }
    };

    @Override
    protected void onCreate(Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);
        setContentView(R.layout.activity_main);
        Intent i = new Intent(this, TestService.class);
        ContextCompat.startForegroundService(this, i);
        bindService(i, connection, Service.BIND_AUTO_CREATE);
    }
}

And then the service:

public class TestService extends Service {

    private static final String TAG = "TestService";

    public static class TestServiceBinder extends Binder {
        private final TestService service;

        public TestServiceBinder(TestService service) {
            this.service = service;
        }

        public TestService getService() {
            return service;
        }
    }

    @Nullable
    @Override
    public IBinder onBind(Intent intent) {
        return new TestServiceBinder(this);
    }

    @Override
    public void onCreate() {
        super.onCreate();

        NotificationManager nm = (NotificationManager) getSystemService(Context.NOTIFICATION_SERVICE);
        if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.O) {
            nm.createNotificationChannel(new NotificationChannel("channel", "channel", NotificationManager.IMPORTANCE_LOW));
        }

        startForeground(42, new NotificationCompat.Builder(this, "channel")
                .setContentTitle("Title")
                .setContentText("Content")
                .setSmallIcon(R.drawable.ic_launcher_foreground)
                .setOngoing(true)
                .build());
    }

    public void startLongProcess() {
        PowerManager pm = (PowerManager) getSystemService(Context.POWER_SERVICE);
        PowerManager.WakeLock wakeLock = pm.newWakeLock(PowerManager.PARTIAL_WAKE_LOCK, "com.example.longrunningproject");
        wakeLock.acquire(1000 * 60 * 30);
        new Thread(() -> {
            int i = 0;
            while (true) {
                Log.d(TAG, "Doing work: " + i);
                i++;
                try {
                    Thread.sleep(1000);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        }).start();
    }
}

Now, I launch the app, but it on background (the notification persists) and turn the screen off. As I observe the logcat output, I see the following:

2018-10-25 13:58:26.982 10768-10794/com.example.longrunningproject D/TestService: Doing work: 964
2018-10-25 13:58:28.027 10768-10794/com.example.longrunningproject D/TestService: Doing work: 965
2018-10-25 13:58:29.068 10768-10794/com.example.longrunningproject D/TestService: Doing work: 966
2018-10-25 13:58:29.552 886-1358/? V/AlarmManager: Triggering alarm #0: 2 when =3493022 package =android operation = null listenTag =*job.delay* flags =0x0
2018-10-25 13:58:30.114 10768-10794/com.example.longrunningproject D/TestService: Doing work: 967
2018-10-25 13:58:31.157 10768-10794/com.example.longrunningproject D/TestService: Doing work: 968
2018-10-25 13:58:32.198 10768-10794/com.example.longrunningproject D/TestService: Doing work: 969
2018-10-25 13:58:33.242 10768-10794/com.example.longrunningproject D/TestService: Doing work: 970
2018-10-25 13:58:34.287 10768-10794/com.example.longrunningproject D/TestService: Doing work: 971
2018-10-25 13:58:34.655 886-11349/? E/OHPD: [BgDetect] AppForkedProc kworker/2:0H pid 11129 uid 0 can't find pkgName
2018-10-25 13:58:35.330 10768-10794/com.example.longrunningproject D/TestService: Doing work: 972
2018-10-25 13:58:36.374 10768-10794/com.example.longrunningproject D/TestService: Doing work: 973
2018-10-25 13:58:37.419 10768-10794/com.example.longrunningproject D/TestService: Doing work: 974
2018-10-25 13:58:37.869 4682-4697/? I/Finsky: [50] com.google.android.finsky.bo.ad.run(6): Stats for Executor: BlockingExecutor com.google.android.finsky.bo.ae@5d7ffa9[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 6]
2018-10-25 13:58:37.871 4682-4697/? I/Finsky: [50] com.google.android.finsky.bo.ad.run(6): Stats for Executor: LightweightExecutor com.google.android.finsky.bo.ae@293892e[Running, pool size = 4, active threads = 0, queued tasks = 0, completed tasks = 44]
2018-10-25 13:58:37.872 4682-4697/? I/Finsky: [50] com.google.android.finsky.bo.ad.run(6): Stats for Executor: bgExecutor com.google.android.finsky.bo.ae@4319ccf[Running, pool size = 4, active threads = 0, queued tasks = 0, completed tasks = 8]
2018-10-25 13:58:38.464 10768-10794/com.example.longrunningproject D/TestService: Doing work: 975
2018-10-25 13:58:39.490 10768-10794/com.example.longrunningproject D/TestService: Doing work: 976
2018-10-25 13:58:39.983 11212-11232/? W/CrashLoopRemedyLog: unable to delete remedy log, instaCrash: true
2018-10-25 13:58:40.535 10768-10794/com.example.longrunningproject D/TestService: Doing work: 977
2018-10-25 13:58:41.580 10768-10794/com.example.longrunningproject D/TestService: Doing work: 978
2018-10-25 13:58:42.625 10768-10794/com.example.longrunningproject D/TestService: Doing work: 979
2018-10-25 13:58:43.669 10768-10794/com.example.longrunningproject D/TestService: Doing work: 980
2018-10-25 13:58:44.714 10768-10794/com.example.longrunningproject D/TestService: Doing work: 981
2018-10-25 13:58:45.735 10768-10794/com.example.expell.longrunningproject D/TestService: Doing work: 982
2018-10-25 13:58:46.752 10768-10794/com.example.longrunningproject D/TestService: Doing work: 983
2018-10-25 13:58:47.773 10768-10794/com.example.longrunningproject D/TestService: Doing work: 984
2018-10-25 13:58:48.794 10768-10794/com.example.longrunningproject D/TestService: Doing work: 985
2018-10-25 13:58:48.938 911-1030/? I/ThermalEngine: Monitor : quiet_therm = 28899, msm_therm = 29311, xo_therm = 29403, battery_therm = 283,current_now = -442000 
2018-10-25 13:58:49.804 10768-10794/com.example.longrunningproject D/TestService: Doing work: 986
2018-10-25 13:58:52.887 886-1358/? V/AlarmManager: Triggering alarm #0: 3 when =3516357 package =com.google.android.gms operation =*alarm*:com.google.android.gms/.lockbox.LockboxAlarmReceiver flags =0x0
2018-10-25 13:59:00.004 886-1358/? V/AlarmManager: Triggering alarm #0: 3 when =3523475 package =android operation =*alarm*:android.intent.action.TIME_TICK flags =0x1
2018-10-25 13:59:35.512 886-1358/? V/AlarmManager: Triggering alarm #0: 2 when =3558982 package =com.google.android.gms operation =*walarm*:com.google.android.gms.gcm.HEARTBEAT_ALARM flags =0x5
2018-10-25 13:59:35.545 748-970/? D/AudioPolicyService: setRecordSilenced() uid 99910027 on silenced 0
2018-10-25 13:59:35.551 2408-8056/? E/WakeLock: GCM_HB_ALARM release without a matched acquire!
2018-10-25 13:59:35.867 709-2516/? I/WifiHAL: event received NL80211_CMD_VENDOR, vendor_id = 0x1374, subcmd = 0xa
2018-10-25 13:59:35.870 2496-2496/? I/wpa_supplicant: wlan0: CTRL-EVENT-AVOID-FREQ ranges=5180-5320,5500-5640
2018-10-25 13:59:35.871 2496-2496/? I/wpa_supplicant: wlan0: CTRL-EVENT-AVOID-FREQ ignore
2018-10-25 13:59:37.902 4682-4697/? I/Finsky: [50] com.google.android.finsky.bo.ad.run(6): Stats for Executor: BlockingExecutor com.google.android.finsky.bo.ae@5d7ffa9[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 6]
2018-10-25 13:59:37.903 4682-4697/? I/Finsky: [50] com.google.android.finsky.bo.ad.run(6): Stats for Executor: LightweightExecutor com.google.android.finsky.bo.ae@293892e[Running, pool size = 4, active threads = 0, queued tasks = 0, completed tasks = 44]
2018-10-25 13:59:37.904 4682-4697/? I/Finsky: [50] com.google.android.finsky.bo.ad.run(6): Stats for Executor: bgExecutor com.google.android.finsky.bo.ae@4319ccf[Running, pool size = 4, active threads = 0, queued tasks = 0, completed tasks = 8]
2018-10-25 13:59:40.722 886-893/? W/System: A resource failed to call close. 
2018-10-25 13:59:48.953 911-1030/? I/ThermalEngine: Monitor : quiet_therm = 28899, msm_therm = 29266, xo_therm = 29403, battery_therm = 284,current_now = -443000 
2018-10-25 13:59:52.732 886-1358/? V/AlarmManager: Triggering alarm #0: 1 when =1540465192731 package =android operation =*alarm*:com.oneplus.android.screenOffCheckProcessState flags =0x9
2018-10-25 14:00:00.000 886-1358/? V/AlarmManager: Triggering alarm #0: 3 when =3583475 package =android operation =*alarm*:android.intent.action.TIME_TICK flags =0x1
2018-10-25 14:00:01.004 886-1358/? V/AlarmManager: Triggering alarm #0: 1 when =1540465201000 package =com.oneplus.deskclock operation =*alarm*:com.android.deskclock.ON_QUARTER_HOUR flags =0x1
2018-10-25 14:00:27.192 886-1358/? V/AlarmManager: Triggering alarm #0: 3 when =3610662 package =android operation =*alarm*:android/com.android.server.stats.StatsCompanionService$PullingAlarmReceiver flags =0x9
2018-10-25 14:00:27.922 692-754/? E/CHRE: Couldn't connect client socket to 'chre': Connection refused
2018-10-25 14:00:27.925 692-754/? W/CHRE: Failed to (re)connect, next try in 300000 ms

So, basically after 16 minutes of running, everything halts. On another run, it halted after 5 minutes. When the screen is turned back on (even without bringing the activity to foreground), the service will continue execution. How do I get the service to function correctly for the full duration of the operation?

0条回答
登录 后发表回答
相关问题
查看全部
相关文章
查看全部
收藏的人(6)