Выполнение AsyncTask doInBackground задерживается

Question

У меня есть странная проблема, когда я теперь ищу идеи, как ее отслеживать.

Проблема:
Для решения этой задачи приложение использует службы, потоки и AyncTasks. Все идет нормально. Все работало, как ожидалось, но недавно я ввел регресс.
У меня есть фрагмент, содержащий фрагмент Google Maps. В onStart-методе этого фрагмента я создаю и запускаю AsyncTask, который запрашивает мои контент-провайдеры для текущих данных, сохраняя их в частных переменных-членах для быстрого доступа при перерисовке.

Теперь у меня возникла проблема, что эта асинхронная задача внезапно задерживается, и я не знаю почему.

AFAIK AsyncTasks использует threadpool, и когда этот пул исчерпан, задачи задерживаются. Поэтому я проверил свой код для AsyncTasks - особенно длинных. Добавлена ​​куча журнальных сообщений, но никто из них, похоже, не работает в то время.

Затем я заметил, что задержка возникает только тогда, когда у меня активирована услуга, которая контролирует некоторые каталоги для изменений (используя FileObservers). Но в этой службе я не использую AsyncTasks или нити. Там я создаю FileObservers для интересующих меня каталогов и сохраняю их в приватном списке. Этот код вызывается непосредственно из onStartCommand. Таким образом, асинхронные задачи не должны зависеть от этого.
Во-вторых, это происходит только в особых обстоятельствах. В основном обновления выводятся немедленно. Только если я впервые запустил приложение после обновления из Play Маркета или запустил его из Android-Studio, произойдет задержка. Я могу удалить его из списка последних приложений (которые должны убивать потоки приложений (но не обрабатывать, если службы работают в этом процессе)), и обновления продолжают запрашиваться во времени (пока эта служба все еще остается Бег).
Если я остановлюсь, а затем перезапустите службу, у меня снова возникнет эта проблема.

Проблема, похоже, связана с началом этой службы filewatcher.

Похоже, что начало этой службы блокирует 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:00 - 54.679. Это завершено в 22:00: 55.268
Затем карта была готова, и первая попытка нарисовать данные на карте сделана в 22: 00: 55: 557. Данных нет - не проблема!
В 22: 00: 58.533 доступны просмотренные папки и вызываются обратные вызовы из файловых серверов.
Наконец, в 22: 01: 17.217 запускается AsyncTask из метода onStart фрагмента.

Таким образом, вопрос:
Что вызывает эту задержку в 22s?
Повторить: Это происходит только в том случае, если активна служба filewatcher.

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 следует использовать для короткого времени работы та SKS.

   AsyncTask предназначен для использования в качестве вспомогательного класса вокруг Thread and Handler и не является общей структурой резьбы. AsyncTasks в идеале должен использоваться для коротких операций (не более нескольких секунд). Если вам нужно поддерживать длительность потоков в течение длительного времени, настоятельно рекомендуется использовать различные API, предоставляемые пакетом java.util.concurrent, например Executor, ThreadPoolExecutor и FutureTask.

2. По умолчанию ваши Service работает на UI тему

   Обратите внимание, что услуги, как и другие объекты приложения, работают в основном потоке процесса их хостинга. Это означает, что если ваша служба будет делать какие-либо интенсивные работы с ЦП (например, воспроизведение MP3) или блокирование (например, сетевые), она должна создать собственный поток, в котором будет выполняться эта работа. Более подробную информацию об этом можно найти в разделе «Процессы и потоки». Класс IntentService доступен как стандартная реализация Службы, которая имеет свой собственный поток, где он планирует выполнить свою работу.

Запустите службу в отдельную тему или преобразовать его в IntentService. Если ваше AsyncTask занимает больше времени для выполнения задач, замените его на другие альтернативы, как рекомендовано в предположении 1.