FilterEngine is created for too long

[asmirnov]

Background

We need FilterEngine instance for AdblockWebView to perform resource loading filtering and element hiding.
Currently FilterEngine instance is created for 4 seconds (tested with Samsung Note 3) and it looks not good as the user will be unable to load webpages until it's created.

What to change

One need to understand the reason and optimize it (probably replace sync invocation with async one or smth else).

[asmirnov]

It's C++ FilterEngine instance who is created for too long:

code:

static jlong JNICALL JniCtor(JNIEnv* env, jclass clazz, jlong enginePtr)
{
  try
  {
    AdblockPlus::JsEnginePtr& jsEngine = *JniLongToTypePtr<AdblockPlus::JsEnginePtr>(enginePtr);

    __android_log_print(ANDROID_LOG_VERBOSE, APPNAME, "Creating FilterEngine");
    AdblockPlus::FilterEngine *filtetEngine = new AdblockPlus::FilterEngine(jsEngine);
    __android_log_print(ANDROID_LOG_VERBOSE, APPNAME, "Created");

    return JniPtrToLong(filtetEngine);
  }
  CATCH_THROW_AND_RETURN(env, 0)
}

log:

09-15 12:00:45.371  29354-29354/org.adblockplus.libadblockplus.webviewapp W/AdblockWebView﹕ Creating FilterEngine
09-15 12:00:45.411  29354-29354/org.adblockplus.libadblockplus.webviewapp V/JNI﹕ Creating FilterEngine
09-15 12:00:50.351  29354-29354/org.adblockplus.libadblockplus.webviewapp V/JNI﹕ Created
09-15 12:00:50.351  29354-29354/org.adblockplus.libadblockplus.webviewapp D/AdblockWebView﹕ FilterEngine created

[asmirnov]

It's because of JS init done:
​https://hg.adblockplus.org/libadblockplus/file/tip/src/FilterEngine.cpp#l145

sleeping:
​https://hg.adblockplus.org/libadblockplus/file/tip/src/FilterEngine.cpp#l164

java JsEngine is created with the same file root context.getCacheDir() (so probably it could perform loading once):

/**
   * Build JsEngine required to build FilterEngine
   * @param context context
   * @param developmentBuild if it's dev build
   * @return JsEngine
   */
  public static JsEngine buildJsEngine(Context context, boolean developmentBuild)
  {
    JsEngine jsEngine = new JsEngine(buildAppInfo(context, developmentBuild));
    jsEngine.setDefaultFileSystem(context.getCacheDir().getAbsolutePath()); // js engine fs root
    jsEngine.setWebRequest(new AndroidWebRequest(true)); // 'true' because we need element hiding
    return jsEngine;
  }

[asmirnov]

11-17 13:04:47.451 3510-3510 D/Adblock: Creating adblock engine ...
11-17 13:04:47.471 3510-3510 W/AdblockEngine: Create
11-17 13:04:47.471 3510-3510 W/AdblockEngine: Create JsEngine
11-17 13:04:47.521 3510-3510 D/AdblockJni: Creating c++ JsEngine
11-17 13:04:47.541 3510-3510 D/AdblockJni: Creating c++ JsEngine done
11-17 13:04:47.551 3510-3510 W/AdblockEngine: Create JsEngine done
11-17 13:04:47.561 3510-3510 W/AdblockEngine: Create FilterEngine
11-17 13:04:47.581 3510-3510 D/AdblockJni: Creating c++ FilterEngine
11-17 13:04:54.321 3510-3510 D/AdblockJni: Creating c++ FilterEngine done
11-17 13:04:54.321 3510-3510 W/AdblockEngine: Create FilterEngine done
11-17 13:04:54.321 3510-3510 W/AdblockEngine: Updating subscription URLs
11-17 13:04:55.121 3510-3510 W/AdblockEngine: Updating subscription URLs done
11-17 13:04:55.121 3510-3510 D/Adblock: Adblock engine created

[asmirnov]

log with FS routines (see FS::):

11-17 15:06:17.001 2893-2893 D/Adblock: Creating adblock engine ...
11-17 15:06:17.021 2893-2893 W/AdblockEngine: Create
11-17 15:06:17.021 2893-2893 W/AdblockEngine: Create JsEngine
11-17 15:06:17.071 2893-2893 D/AdblockJni: Creating c++ JsEngine
11-17 15:06:17.111 2893-2893 D/AdblockJni: Creating c++ JsEngine done
11-17 15:06:17.121 2893-2893 W/AdblockEngine: Create JsEngine done
11-17 15:06:17.141 2893-2893 W/AdblockEngine: Create FilterEngine
11-17 15:06:17.141 2893-2893 D/AdblockJni: Creating c++ FilterEngine
11-17 15:06:17.161 2893-3000 D/AdblockJni: FS::Read from /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/prefs.json
11-17 15:06:17.161 2893-3000 D/AdblockJni: FS::Read from /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/prefs.json done
11-17 15:06:17.221 2893-3002 D/AdblockJni: FS::Stat /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns.ini
11-17 15:06:17.221 2893-3002 D/AdblockJni: FS::Stat /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns.ini done
11-17 15:06:17.301 2893-3007 D/AdblockJni: FS::Read from /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns.ini
11-17 15:06:17.301 2893-3007 D/AdblockJni: FS::Read from /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns.ini done
11-17 15:06:22.001 2893-2893 D/AdblockJni: Creating c++ FilterEngine done
11-17 15:06:22.001 2893-2893 W/AdblockEngine: Create FilterEngine done
11-17 15:06:22.001 2893-2893 W/AdblockEngine: Updating subscription URLs
11-17 15:06:22.011 2893-3328 D/AdblockJni: FS::Stat /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns.ini
11-17 15:06:22.011 2893-3328 D/AdblockJni: FS::Stat /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns.ini done
11-17 15:06:22.011 2893-3329 D/AdblockJni: FS::Stat /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns-backup1.ini
11-17 15:06:22.021 2893-3329 D/AdblockJni: FS::Stat /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns-backup1.ini done
11-17 15:06:22.361 2893-2893 W/AdblockEngine: Updating subscription URLs done
11-17 15:06:22.361 2893-2893 D/Adblock: Adblock engine created
11-17 15:06:22.381 2893-2893 D/Adblock: Applying saved adblock settings to adblock engine
11-17 15:06:22.381 2893-2893 D/Activity: performCreate Call secproduct feature valuefalse
11-17 15:06:22.381 2893-2893 D/Activity: performCreate Call debug elastic valuetrue
11-17 15:06:22.401 2893-3341 D/OpenGLRenderer: Render dirty regions requested: true
11-17 15:06:22.411 2893-3339 D/AdblockJni: FS::Write to /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns.ini
11-17 15:06:22.461 2893-3341 I/OpenGLRenderer: Initialized EGL, version 1.4
11-17 15:06:22.461 2893-3341 I/OpenGLRenderer: HWUI protection enabled for context ,  &this =0xaf5170b0 ,&mEglDisplay = 1 , &mEglConfig = 8 
11-17 15:06:22.461 2893-3341 D/OpenGLRenderer: Enabling debug mode 0
11-17 15:06:22.501 2893-3339 D/AdblockJni: FS::Write to /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns.ini done
11-17 15:06:22.511 2893-3346 D/AdblockJni: FS::Stat /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns.ini
11-17 15:06:22.511 2893-3346 D/AdblockJni: FS::Stat /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns.ini done
11-17 15:06:22.511 2893-3347 D/AdblockJni: FS::Stat /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns-backup1.ini
11-17 15:06:22.511 2893-3347 D/AdblockJni: FS::Stat /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns-backup1.ini done
11-17 15:06:22.621 2893-2893 I/Timeline: Timeline: Activity_idle id: android.os.BinderProxy@37ec6ca9 time:45821
11-17 15:06:23.121 2893-3387 D/AdblockJni: FS::Write to /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns.ini
11-17 15:06:23.191 2893-3387 D/AdblockJni: FS::Write to /data/data/org.adblockplus.libadblockplus.android.webviewapp/cache/patterns.ini done

[asmirnov]

Systrace with Trace.beginSection("AdblockPlus")