AsyncTask doInBackground 的执行被延迟答案

【问题标题】：Execution of AsyncTask doInBackground is delayedAsyncTask doInBackground 的执行被延迟
【发布时间】：2023-03-15 17:33:01
【问题描述】：

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

问题：
为了解决性能问题，该应用程序使用服务、线程和 AyncTasks。到目前为止，一切都很好。一切都按预期工作，但最近我引入了回归。
我有一个包含谷歌地图片段的片段。在该片段的 onStart 方法中，我创建并启动了一个 AsyncTask，它向我的内容提供者查询当前数据，并将其存储在私有成员变量中以便在重绘时快速访问。

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

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

然后我注意到延迟仅在我激活了监视某些目录更改的服务时发生（使用 FileObservers）。但在该服务中，我不使用任何 AsyncTasks 或线程。在那里，我为我感兴趣的目录创建 FileObservers，并将它们存储在一个私人列表中。该代码直接从 onStartCommand 调用。所以异步任务不应该受此影响。
其次，这似乎只发生在特殊情况下。大多数情况下，更新是立即绘制的。只有当我从 Play 商店更新后第一次启动应用程序或从 Android-Studio 启动它时，才会出现延迟。我可以将其从最近的应用程序列表中删除（这应该会杀死应用程序线程（但如果服务正在该进程中运行，则不会处理））并且更新会继续及时查询（只要该服务仍在运行） )。
如果我停止然后重新启动服务，我又会遇到这个问题。

问题似乎与这个 filewatcher-service 的启动有关。

因此，该服务的启动似乎会阻塞 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 来查询我的数据结束。
在后台其他任务正在运行。其中之一是我的 filewatcher 服务在 22:00:54.679 开始。结束于 22:00:55.268
然后地图准备就绪，并在 22:00:55:557 首次尝试将数据绘制到地图上。那里没有可用的数据 - 没问题！
在 22:00:58.533 访问被监视的文件夹并触发来自文件观察器的回调。
最终在 22:01:17.217 从片段的 onStart 方法启动 AsyncTask。

所以问题：
是什么导致了这种 22 秒的延迟？
重复一遍：这只发生在 filewatcher-service 处于活动状态时。

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;
    }
}

【问题讨论】：

由于您使用线程和 AsyncTask，因此无法保证执行时间。
我知道线程的属性等。请注意，当文件观察服务不活动时，任务以最小延迟启动。 22s的延迟一定是有原因的。除了已启动的服务（之前已启动 21），该设备大多处于空闲状态。所以我的 AsyncTask 没有理由延迟那么长时间。

标签： java android multithreading android-asynctask

【解决方案1】：

一些建议：

AsyncTask 应该用于短期运行的任务。

AsyncTask 被设计成一个围绕 Thread 和 Handler 的辅助类，并不构成一个通用的线程框架。 AsyncTasks 最好用于短操作（最多几秒钟）。如果您需要保持线程长时间运行，强烈建议您使用 java.util.concurrent 包提供的各种 API比如Executor、ThreadPoolExecutor和FutureTask。
默认情况下，Service 在 UI 线程上运行

请注意，服务与其他应用程序对象一样，在其托管进程的主线程中运行。这意味着，如果您的服务要执行任何 CPU 密集型（例如 MP3 播放）或阻塞（例如网络）操作，它应该生成自己的线程来完成这项工作。更多信息可以在进程和线程中找到。 IntentService 类可作为 Service 的标准实现使用，它有自己的线程来安排要完成的工作。

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

【讨论】：

自从我发布这个消息以来已经很久了...... Async-Task 用于短期运行的任务。该服务正在 UI 线程上运行 - 是的。但它只是用来启动一些 File-Watchers 并且很久以前就完成了。 File-Watchers 本身是异步的 - 所以我不希望它们对 UI 线程有害。否则应该在文档中提到。我的问题是，为什么在我的 AsycTask 启动之前会有如此大的延迟 - 我看不到任何可能导致该延迟的原因。