AsyncTask doInBackground的执行被延迟

Question

我有一个奇怪的问题，我现在寻找如何追踪它的想法。

问题是：

为了提高性能，应用程序使用服务、线程和AyncTasks。到现在为止还好。一切都如期而至，但最近我引入了回归。

我有一个片段，其中包含谷歌地图片段。在该片段的onStart方法中，我创建并启动了一个AsyncTask，它查询我的内容提供者获取当前数据，并将其存储在私有成员变量中，以便在重绘时进行快速访问。

现在我遇到了一个问题，这个异步任务突然被延迟了，我不知道为什么。

AFAIK AsyncTasks使用线程池，当这个池耗尽时，任务会延迟。所以我检查了我的AsyncTasks代码，特别是长时间运行的代码。添加了一堆日志消息，但当时似乎没有人在运行。

然后，我注意到，只有当我激活了一个服务来监视某些目录的更改(使用FileObservers)时，延迟才会发生。但在该服务中，我不使用任何AsyncTasks或线程。在这里，我为我感兴趣的目录创建了FileObservers，并将这些目录存储在一个私有列表中。该代码直接从onStartCommand调用。因此，异步任务不应受此影响。

第二，这似乎只有在特殊情况下才会发生。大多数情况下，更新是立即绘制的。只有当我第一次从Play Store启动应用程序或从启动应用程序时，才会出现延迟。我可以将其从最近的应用程序列表中删除(这些应用程序应该会杀死应用程序线程(但如果服务在该进程中运行，则不会处理)，并且更新将继续被及时查询(只要该服务仍在运行)。

如果我停止并重新启动服务，我就会再次遇到这个问题。

这个问题似乎与这种文件服务的启动有关。

因此，该服务的启动似乎阻止了AsyncTasks一段时间。..。但是为什么呢？

下面是应用程序第一次启动时日志文件的摘录：

(我插入了一些空行以提高可读性)

02-05 22:00:54.361 24041-24041/de.leo.android.buddy_tracker I/Fragment_Map: onStart

02-05 22:00:54.672 24041-24041/de.leo.android.buddy_tracker I/TextToSpeech: Connected to ComponentInfo{com.google.android.tts/com.google.android.tts.service.GoogleTTSService}
02-05 22:00:54.679 24041-24041/de.leo.android.buddy_tracker I/Receive_SharedFolderService: onStartCommand: Start service (with intent)
02-05 22:00:54.700 24041-24045/de.leo.android.buddy_tracker I/art: Do full code cache collection, code=125KB, data=92KB
02-05 22:00:54.702 24041-24045/de.leo.android.buddy_tracker I/art: Starting a blocking GC JitCodeCache
02-05 22:00:54.702 24041-24045/de.leo.android.buddy_tracker I/art: After code cache collection, code=112KB, data=67KB
02-05 22:00:54.774 24041-24041/de.leo.android.buddy_tracker I/Receive_SharedFolderService: initWatchers
02-05 22:00:54.899 24041-24041/de.leo.android.buddy_tracker I/Receive_SharedFolderService: initWatchers1: Watcher for root /storage/emulated/0/Sync/BT-Shares/Leo intern created
02-05 22:00:54.973 24041-24041/de.leo.android.buddy_tracker I/Receive_SharedFolderService: initWatchers1: Watcher for subdirectory /storage/emulated/0/Sync/BT-Shares/Leo intern/Leo#GN created
02-05 22:00:55.047 24041-24041/de.leo.android.buddy_tracker I/Receive_SharedFolderService: initWatchers1: Watcher for subdirectory /storage/emulated/0/Sync/BT-Shares/Leo intern/Leo#N5x created
02-05 22:00:55.194 24041-24041/de.leo.android.buddy_tracker I/Receive_SharedFolderService: initWatchers finished
02-05 22:00:55.268 24041-24041/de.leo.android.buddy_tracker I/Receive_SharedFolderService: onStartCommand finished

02-05 22:00:55.350 24041-24041/de.leo.android.buddy_tracker I/SpeechHandler: startTextToSpeechService
02-05 22:00:55.515 24041-24041/de.leo.android.buddy_tracker I/TextToSpeech: Sucessfully bound to com.google.android.tts
02-05 22:00:55.557 24041-24041/de.leo.android.buddy_tracker I/Fragment_Map: drawContents (onMapReady)
02-05 22:00:55.800 24041-24041/de.leo.android.buddy_tracker I/Fragment_Map: drawContents: calculate bounds and move camera
02-05 22:00:55.891 24041-24041/de.leo.android.buddy_tracker I/Choreographer: Skipped 72 frames!  The application may be doing too much work on its main thread.
02-05 22:00:56.040 24041-24211/de.leo.android.buddy_tracker I/Adreno: QUALCOMM build                   : 6818200, Idb2b4cb785
                                                                      Build Date                       : 11/18/16
                                                                      OpenGL ES Shader Compiler Version: XE031.09.00.04
                                                                      Local Branch                     : N25
                                                                      Remote Branch                    : 
                                                                      Remote Branch                    : 
                                                                      Reconstruct Branch               : 
02-05 22:00:56.047 24041-24211/de.leo.android.buddy_tracker I/OpenGLRenderer: Initialized EGL, version 1.4
02-05 22:00:56.047 24041-24211/de.leo.android.buddy_tracker D/OpenGLRenderer: Swap behavior 1
02-05 22:00:56.248 24041-24045/de.leo.android.buddy_tracker I/art: Do partial code cache collection, code=124KB, data=101KB
02-05 22:00:56.249 24041-24045/de.leo.android.buddy_tracker I/art: After code cache collection, code=122KB, data=99KB
02-05 22:00:56.249 24041-24045/de.leo.android.buddy_tracker I/art: Increasing code cache capacity to 512KB
02-05 22:00:56.367 24041-24199/de.leo.android.buddy_tracker W/DynamiteModule: Local module descriptor class for com.google.android.gms.googlecertificates not found.
02-05 22:00:56.379 24041-24041/de.leo.android.buddy_tracker I/TextToSpeech: Connected to ComponentInfo{com.google.android.tts/com.google.android.tts.service.GoogleTTSService}
02-05 22:00:56.380 24041-24199/de.leo.android.buddy_tracker I/DynamiteModule: Considering local module com.google.android.gms.googlecertificates:0 and remote module com.google.android.gms.googlecertificates:2
02-05 22:00:56.380 24041-24199/de.leo.android.buddy_tracker I/DynamiteModule: Selected remote version of com.google.android.gms.googlecertificates, version >= 2
02-05 22:00:56.404 24041-24253/de.leo.android.buddy_tracker W/f: Suppressed StrictMode policy violation: StrictModeDiskReadViolation
02-05 22:00:56.553 24041-24045/de.leo.android.buddy_tracker I/art: Compiler allocated 7MB to compile void android.widget.TextView.<init>(android.content.Context, android.util.AttributeSet, int, int)
02-05 22:00:56.704 24041-24041/de.leo.android.buddy_tracker W/f: Suppressed StrictMode policy violation: StrictModeDiskReadViolation
02-05 22:00:56.704 24041-24041/de.leo.android.buddy_tracker W/f: Suppressed StrictMode policy violation: StrictModeDiskWriteViolation
02-05 22:00:58.533 24041-24213/de.leo.android.buddy_tracker I/Receive_SharedFolderService: Leo#N5x was opened
02-05 22:00:58.577 24041-24213/de.leo.android.buddy_tracker I/Receive_SharedFolderService: Leo#N5x was closed (no write)
02-05 22:00:58.600 24041-24213/de.leo.android.buddy_tracker I/Receive_SharedFolderService: Leo#N5x was opened
02-05 22:00:58.695 24041-24213/de.leo.android.buddy_tracker I/Receive_SharedFolderService: Leo#N5x was closed (no write)
02-05 22:00:59.522 24041-24048/de.leo.android.buddy_tracker W/art: Suspending all threads took: 7.092ms
02-05 22:01:00.344 24041-24045/de.leo.android.buddy_tracker I/art: Do full code cache collection, code=241KB, data=221KB
02-05 22:01:00.345 24041-24045/de.leo.android.buddy_tracker I/art: Starting a blocking GC JitCodeCache
02-05 22:01:00.346 24041-24045/de.leo.android.buddy_tracker I/art: After code cache collection, code=217KB, data=173KB
02-05 22:01:00.346 24041-24045/de.leo.android.buddy_tracker I/art: Compiler allocated 6MB to compile void android.view.ViewRootImpl.performTraversals()
02-05 22:01:02.259 24041-24045/de.leo.android.buddy_tracker I/art: Do partial code cache collection, code=249KB, data=197KB
02-05 22:01:02.260 24041-24045/de.leo.android.buddy_tracker I/art: After code cache collection, code=247KB, data=197KB
02-05 22:01:02.260 24041-24045/de.leo.android.buddy_tracker I/art: Increasing code cache capacity to 1024KB

02-05 22:01:17.217 24041-24969/de.leo.android.buddy_tracker I/Fragment_Map: UpdateData.doInBackground (--start)
02-05 22:01:17.256 24041-24969/de.leo.android.buddy_tracker I/BuddyTrackerHelper: readBuddyPositions from 04.02.2017 22:01 to 17.08.292278994 08:12
02-05 22:01:17.518 24041-24041/de.leo.android.buddy_tracker I/Fragment_Map: drawContents (UpdateData.onPostExecute)
02-05 22:01:17.549 24041-24978/de.leo.android.buddy_tracker I/TextToSpeech: Set up connection to ComponentInfo{com.google.android.tts/com.google.android.tts.service.GoogleTTSService}
02-05 22:01:17.560 24041-24979/de.leo.android.buddy_tracker I/TextToSpeech: Set up connection to ComponentInfo{com.google.android.tts/com.google.android.tts.service.GoogleTTSService}
02-05 22:01:18.150 24041-24041/de.leo.android.buddy_tracker I/Fragment_Map: drawTrack: Track Leo#GN mit 77 Punkten eingetragen
02-05 22:01:18.601 24041-24041/de.leo.android.buddy_tracker I/Fragment_Map: drawTrack: Track Leo#N5x mit 239 Punkten eingetragen
02-05 22:01:18.618 24041-24041/de.leo.android.buddy_tracker I/Fragment_Map: drawContents: calculate bounds and move camera

有趣的部分：

在22:00:54.361，输入了我的地图片段的onStart方法。此方法以调用AsyncTask查询我的数据结束。

在后台，其他任务正在运行。其中之一是我在22点54.679分开始了我的文件处理服务。这是在22:55.268结束。

然后地图准备就绪，第一次尝试在22:00:55:557将数据绘制到地图上。那里没有数据-没问题！

在22:00:58.533，将访问被监视的文件夹，并触发来自文件观察者的回调。

最后，在22:01:17.217启动片段的onStart方法中的AsyncTask。

所以问题是：

是什么导致了22s的延迟？

重复一遍:只有当文件处理程序服务处于活动状态时才会发生这种情况。

onStart方法：

@Override
public void onStart() {
//noinspection ConstantConditions
if (DEBUG_LEVEL >= DEBUGLEVEL_EXTENDED) LeoLog.i(LOG_TAG, "onStart");

super.onStart();

if (Application_Buddy_Tracker.getLocationProvider() != null)
    Application_Buddy_Tracker.getLocationProvider().registerClientIfLocationhandlerActive(this);

getActivity().getContentResolver().registerContentObserver(CONTENT_POSITIONS_URI, true, buddyPositionContentObserver);
new UpdateData().execute("--start");

LeoCommunication.collectGarbage(getActivity());

final SharedPreferences prefs = Application_Buddy_Tracker.getPreferences(getActivity());
setMapType(prefs);

//noinspection ConstantConditions
if (DEBUG_LEVEL >= DEBUGLEVEL_VERBOSE) LeoLog.i(LOG_TAG, "onStart completed");

}

我的服务：

public class Receive_SharedFolderService extends Service {
    private final static String LOG_TAG = Receive_SharedFolderService.class.getSimpleName();
    private final static @GlobalConstants.Debuglevels int DEBUG_LEVEL = DEBUGLEVEL_VERBOSE;


    public class MyFileObserver extends FileObserver {
        String absolutePath;

        MyFileObserver(String path) {
            super(path, FileObserver.ALL_EVENTS);
            absolutePath = path;
        }


        @Override
        public void onEvent(int event, String path) {
            if (path == null) return;

            //noinspection ConstantConditions
            if (DEBUG_LEVEL >= DEBUGLEVEL_VERBOSE) {
                if ((FileObserver.ACCESS & event) != 0)        LeoLog.i(LOG_TAG, absolutePath + "/" + path + " was accessed/read");     //data was read from a file
                if ((FileObserver.ATTRIB & event) != 0)        LeoLog.i(LOG_TAG, absolutePath + "/" + path + " was changed (permissions, owner, timestamp)");   //Metadata (permissions, owner, timestamp) was changed explicitly
                if ((FileObserver.CLOSE_NOWRITE & event) != 0) LeoLog.i(LOG_TAG, path + " was closed (no write)");          //someone has a file or directory open read-only, and closed it
                if ((FileObserver.DELETE_SELF & event) != 0)   LeoLog.i(LOG_TAG, absolutePath + "/" + " was deleted");      //the monitored file or directory was deleted, monitoring effectively stops
                if ((FileObserver.MODIFY & event) != 0)        LeoLog.i(LOG_TAG, absolutePath + "/" + path + " was modified");      //data was written to a file
                if ((FileObserver.MOVED_FROM & event) != 0)    LeoLog.i(LOG_TAG, absolutePath + "/" + path + " was moved to somewhere");    //a file or subdirectory was moved from the monitored directory
                if ((FileObserver.MOVE_SELF & event) != 0)     LeoLog.i(LOG_TAG, path + " was moved");                      //the monitored file or directory was moved; monitoring continues
                if ((FileObserver.OPEN & event) != 0)          LeoLog.i(LOG_TAG, path + " was opened");                     //a file or directory was opened

                    //TODO: consider combine this one with one below
                    //a file was deleted from the monitored directory
                if ((FileObserver.DELETE & event) != 0) {
                    //for testing copy file
//                    FileUtils.copyFile(absolutePath + "/" + path);
                    LeoLog.i(LOG_TAG, absolutePath + "/" + path + " was deleted");
                }
            }

            if ((FileObserver.CREATE & event) != 0) {
                //noinspection ConstantConditions
                if (DEBUG_LEVEL >= DEBUGLEVEL_EXTENDED) LeoLog.i(LOG_TAG, absolutePath + "/" + path + " was created");      //a new file or subdirectory was created under the monitored directory

                if ((new File(absolutePath + "/" + path)).isDirectory()) {
                    final SharedPreferences prefs = Application_Buddy_Tracker.getPreferences(getApplicationContext());
                    initWatchers(getApplicationContext(), prefs.getString(getString(R.string.prefs_buddymessages_share_folder_root_key), ""));
                }
            }

            //a file or subdirectory was moved to the monitored directory
            if ((FileObserver.MOVED_TO & event) != 0) {
                //noinspection ConstantConditions
                if (DEBUG_LEVEL >= DEBUGLEVEL_EXTENDED) LeoLog.i(LOG_TAG, "File was moved to " + absolutePath + "/" + path);

                if (path.endsWith(".json")) newMessage(absolutePath, path);     // Final action for new file in Bittorrent-Sync
            }

            //someone has a file or directory open for writing, and closed it
            if ((FileObserver.CLOSE_WRITE & event) != 0) {
                //noinspection ConstantConditions
                if (DEBUG_LEVEL >= DEBUGLEVEL_EXTENDED) LeoLog.i(LOG_TAG, absolutePath + "/" + path + " was written and closed (== changed)");

                if (path.endsWith(".json")) newMessage(absolutePath, path);     // Final action for new file in Bittorrent-Sync
            }
        }


        private void newMessage(String absolutePath, String path) {
            //noinspection ConstantConditions
            if (DEBUG_LEVEL >= DEBUGLEVEL_EXTENDED) LeoLog.i(LOG_TAG, "Check if received message is new: " + path);

            if (BuddyMessage.addMessage(getApplicationContext(), absolutePath + "/" + path)) {
                //noinspection ConstantConditions
                if (DEBUG_LEVEL > DEBUGLEVEL_NONE) LeoLog.i(LOG_TAG, "New message added to message-store: " + path);

                LeoCommunication.notifyNewMsg(getApplicationContext(), Application_Buddy_Tracker.RQ_NEW_MESSAGE_ARRIVED, Application_Buddy_Tracker.ID_NOTIFICATION_BUDDYTRACKER_MESSAGE_RECEIVED);
            }
        }
    }


    private static boolean _isRunning = false;

    public static boolean isRunning() { return _isRunning; }


    /**
     * FileObservers that monior shared folders.
     * <p>Important: Keep (this) reference in order to not have the observers garbage collected!</p>
     */
    private final List<MyFileObserver> fileObservers = new ArrayList<>();


    @Override
    public IBinder onBind(Intent intent) { return null; }


    @Override
    public int onStartCommand(Intent intent, int flags, int startId) {
        if (intent == null) {
            //noinspection ConstantConditions
            if (DEBUG_LEVEL >= DEBUGLEVEL_STANDARD) LeoLog.i(LOG_TAG, "onStartCommand: Restarting Service (without intent)");
        } else {
            //noinspection ConstantConditions
            if (DEBUG_LEVEL >= DEBUGLEVEL_STANDARD) LeoLog.i(LOG_TAG, "onStartCommand: Start service (with intent)");
        }


        final Context context = getApplicationContext();

        final NotificationCompat.Builder nb = new NotificationCompat.Builder(context)
            .setSmallIcon(context.getApplicationInfo().icon)
            .setWhen(System.currentTimeMillis())                // Zeitpunkt der Notification
            .setContentTitle(context.getText(context.getApplicationInfo().labelRes))
            .setContentText(getResources().getString(de.leo.android.buddy_tracker.R.string.app_receiving_by_shared_folder))
            .setTicker(getResources().getString(de.leo.android.buddy_tracker.R.string.app_receiving_by_shared_folder));

        if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.LOLLIPOP)   nb.setCategory(Notification.CATEGORY_SERVICE);
        if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.JELLY_BEAN) nb.setPriority(Notification.PRIORITY_MIN);

        final Intent intent1 = new Intent(context, Activity_Main.class);
        intent1.putExtra(DISPLAY_TAB, Activity_Main.TABPOSITION_SHARE);

        final PendingIntent pIntent = PendingIntent.getActivity(context, Application_Buddy_Tracker.RQ_SERVICE_RECEIVE_POSITIONS, intent1, PendingIntent.FLAG_UPDATE_CURRENT);
        nb.setContentIntent(pIntent);

        this.startForeground(Application_Buddy_Tracker.ID_NOTIFICATION_BUDDYTRACKER_RECEIVE, nb.build());

        final SharedPreferences prefs = Application_Buddy_Tracker.getPreferences(context);
        final String buddyMessages_Root = prefs.getString(getString(R.string.prefs_buddymessages_share_folder_root_key), "");

        if (!initWatchers(context, buddyMessages_Root)) {
            LeoLog.e(LOG_TAG, "onStartCommand: initWatchers failed - stopping Service");
            stopSelf(startId);
            return Service.START_NOT_STICKY;
        }

        _isRunning = true;

        //noinspection ConstantConditions
        if (DEBUG_LEVEL >= DEBUGLEVEL_VERBOSE) LeoLog.i(LOG_TAG, "onStartCommand finished");

        return Service.START_STICKY;
    }


    @Override
    public void onDestroy() {
        synchronized (fileObservers) {
            for (FileObserver fileObserver : fileObservers)
                fileObserver.stopWatching();
            fileObservers.clear();
        }

        //noinspection ConstantConditions
        if (DEBUG_LEVEL >= DEBUGLEVEL_STANDARD) LeoLog.i(LOG_TAG, "disconnect: Fileobservers and Service stopped");

        _isRunning = false;
        stopForeground(true);
    }


    private boolean initWatchers(Context context, String buddyMessages_Root) {
        //noinspection ConstantConditions
        if (DEBUG_LEVEL >= DEBUGLEVEL_EXTENDED) LeoLog.i(LOG_TAG, "initWatchers");

        if (buddyMessages_Root == null || buddyMessages_Root.length() == 0) return false;

        final File rootDir = new File(buddyMessages_Root);

        synchronized (fileObservers) {
            fileObservers.clear();

            initWatchers1(rootDir.getAbsolutePath());

            final Cursor c = context.getContentResolver().query(CONTENT_BUDDIES_URI, new String[]{COL_BUDDY_SHARED_FOLDER},
                    COL_BUDDY_ACTIVE + " != 0 AND " + COL_BUDDY_SHARED_FOLDER_RECEIVE + " != 0 AND " + COL_BUDDY_SHARED_FOLDER + " IS NOT NULL",
                    null,
                    null);
            assert c != null;
            while (c.moveToNext())
                initWatchers1(c.getString(0));
            c.close();
        }

        //noinspection ConstantConditions
        if (DEBUG_LEVEL >= DEBUGLEVEL_VERBOSE) LeoLog.i(LOG_TAG, "initWatchers finished");

        return true;
    }


    private boolean initWatchers1(String rootpath) {
        if (rootpath == null) return true;

            // Watcher for the rootdir -> monitor add and remove of buddies
        final MyFileObserver fileObserver1 = new MyFileObserver(rootpath);
        fileObservers.add(fileObserver1);
        fileObserver1.startWatching();
        //noinspection ConstantConditions
        if (DEBUG_LEVEL >= DEBUGLEVEL_VERBOSE) LeoLog.i(LOG_TAG, "initWatchers1: Watcher for root " + rootpath + " created");

        File dir1 = new File(rootpath);

        for (File f : dir1.listFiles())
            if (f.isDirectory()) {
                MyFileObserver fileObserver = new MyFileObserver(f.getAbsolutePath());
                fileObservers.add(fileObserver);
                fileObserver.startWatching();

                //noinspection ConstantConditions
                if (DEBUG_LEVEL >= DEBUGLEVEL_VERBOSE) LeoLog.i(LOG_TAG, "initWatchers1: Watcher for subdirectory " + f.getAbsolutePath() + " created");
            }

        return  true;
    }
}

Answer 1

很少有建议：

1. AsyncTask应该用于短时间运行的任务。 AsyncTask被设计成一个围绕线程和Handler的帮助类，并不构成一个通用的线程框架。理想情况下，AsyncTasks应该用于较短的操作(最多几秒钟)。如果需要让线程长时间运行，强烈建议您使用java.util.concurrent包提供的各种API，如Executor、ThreadPoolExecutor和FutureTask。
2. 默认情况下，您的服务运行在UI线程上 请注意，与其他应用程序对象一样，服务在其宿主进程的主线程中运行。这意味着，如果您的服务要执行任何CPU密集型操作(如MP3回放)或阻塞操作(如网络)，则它应该生成自己的线程来执行该工作。有关此问题的更多信息可以在进程和线程中找到。IntentService类可以作为服务的标准实现使用，它有自己的线程，可以在其中安排要完成的工作。

以单独的线程启动您的服务，或将其转换为IntentService。如果您的AsyncTask执行任务所需的时间较长，请按照建议1中的建议将其替换为其他替代方案。