Test android-native performance.

[barbarosh]

@andpor Android-native implementation timing for 20k - 20200ms. Old implementation timing 13000ms. May be problem in verbose mode sqlite-native-driver. How to disable verbose mode ?

11-17 12:20:43.383 28403-28502/com.reactapp V/sqlg: sqlc_st_column_name 0xb3ac4928 1
11-17 12:20:43.383 28403-28502/com.reactapp V/sqlg: sqlc_st_column_type 0xb3ac4928 1
11-17 12:20:43.383 28403-28502/com.reactapp V/sqlg: sqlc_st_column_name 0xb3ac4928 3

[brodycj]

@andpor you will need a new version of the Android sqlite-connector.jar and native-driver*.so libraries. I will publish them soon and let you know.

[andpor]

ok. Hopefully the new libs will do the trick.

[brodycj]

@andpor I just published an update to Cordova-sqlite-storage with the new versions of sqlite-connector.jar and the native libraries. You should take them at the same time since there is now internal testing to make sure they do not go out of sync.

[andpor]

@brodybits should have it updated in my repo within next few hours

[andpor]

@barbarosh @brodybits - latest native libs + new connector are in the repo. Alex could you please try them out?

[barbarosh]

@brodybits @andpor I will make test new library during 1 hour.

[barbarosh]

@andpor @brodybits It work, but performance did not increased. Now speed 13000ms for 20k.

[andpor]

@barbarosh So it takes 13 seconds...is this pretty much the same result you got using the plain Java plugin to begin with? I would have thought going native would dramatically increase the speed..which does not seem to be the case. Are you seeing excessive logging still or anything else which could be contributing to this? ...and are you sure you are using the native and not the original by some odd chance :)

@brodybits Chris - any thoughts ?

[andpor]

@barbarosh Alex - what are the details of your test case - can you provide?

[barbarosh]

@andpor Yes it is the same result as the original plug-in, and I connect to the project folder "android-native", I noticed that in the verbose output to log many values by native lib. Test case details:

• I have table with 20k rows and autoindex
• Table have uuid, name, type, template, icon, images, subtitle - all columns text type
• SQL query "SELECT * FROM items"
• code

return this.databaseObject.transaction((tx)=> {
          tx.executeSql(sql, params).then(([tx,results]) => {
            //console.log(results)
            if (results.rowsAffected > 0) {
              queryResult = true // TEMP  After insert etc TODO: Fix this
            } else {
              var len = results.rows.length;
              for (let i = 0; i < len; i++) {
                queryResult.push(results.rows.item(i))
              }
            }
          })
        })

This criteria identical and to tests on IOS

[brodycj]

@barbarosh do you say that the "android-native" version continues to log extra verbose output after the most recent fix? Can you post some of the output if so?

[barbarosh]

@brodybits @andpor After the last update they seem to have disappeared. I now no way to verify but most likely yes gone, because the duration of the test back to the start mark. Within 4 hours I tested it.

[andpor]

Maybe you can try a native app only running these queries and see how performance is...is it isolated to the db interface or realized in react native ? Perhaps you can open an issue for performance on cordova-sqlite-storage?

[barbarosh]

@brodybits Verbose information now have disappeared. Thanks. @andpor I tried find place for check timing by debug code of android-native and set breakpoints but her don`t stoped and I investigate android-native code and found

        DBRunner(final String dbname, JSONObject options, CallbackContext cbc) {
            this.dbname = dbname;
            this.createFromAssets = options.has("createFromResource");
            this.oldImpl = options.has("androidOldDatabaseImplementation");
            Log.v(SQLitePlugin.class.getSimpleName(), "Android db implementation: " + (oldImpl ? "OLD" : "sqlite4java (NDK)"));
            this.bugWorkaround = this.oldImpl && options.has("androidBugWorkaround");
            if (this.bugWorkaround)
                Log.v(SQLitePlugin.class.getSimpleName(), "Android db closing/locking workaround applied");

            this.q = new LinkedBlockingQueue<DBQuery>();
            this.openCbc = cbc;
        }

May be runned old implementation in new module ? Because old timing.

[andpor]

do you see sqlite4java (NDK) or OLD string in the debug output ? it would run old impl only if you ask for androidOldDatabaseImplementation in params I think...

[andpor]

@barbarosh Alex, how does your parent project structure looks like i.e. how did you import the android-native module? Which version of Android Studio are you using?

[andpor]

@barbarosh Alex, is think I found the issue. The android-native works fine as stand-along project but when included as module the native libs do not get included for some reason form current location. I reorganized the project and added an enhancement to build.gradle to fix this. Tested on both Genymotion simulator and device and see that native library is definitely used.

Also, the ':app' is not needed when you are adding the react-native-sqlite to parent project. I removed it from instructions.

You are looking for the following debug log stmt to verify native is used:

11-19 04:15:20.174 6783-6849/com.citi.cira.author D/ReactNativeJS: 'OPEN database: test.db' 11-19 04:15:20.186 6783-6849/com.citi.cira.author D/ReactNativeJS: 'new transaction is waiting for open operation' 11-19 04:15:20.193 6783-6850/com.citi.cira.author V/SQLitePlugin: Android db implementation: sqlite4java (NDK)

Can you test it out on your side and see whether timing is improved. Thanks.

[barbarosh]

@andpor I check this today.

[barbarosh]

@andpor After your commits: for 20k timing 12600ms

[andpor]

not a huge difference...but not much I can do about it myself I am afraid...we can test whether it is caused react native overhead or internal SQLPlugin perf issue..

It could also be a function of the device spec and Android version... maybe you can send me you complete test case and I will run it on my S5 mini ? What device do you use?

[barbarosh]

I do not have time to test, it is possible to check up on the weekend.

[andpor]

@barbarosh Alex - not entirely sure what's going on on your side but I wrote a testcase with 20k rows which I then executed on a Genymotion simulator using basic non-native Android implementation, not even a device. I think timing is quite good. All in all, fetching 20k rows took ~ 4200 milliseconds.

Here is my table definition and timing results. I am sure the timing is going to be much better on a device.

Now I did once small improvement to the code I have to admit... :) Although I am not yet sure if that was the culprit

    tx.executeSql('CREATE TABLE IF NOT EXISTS User( '
        + 'name VARCHAR(55), '
        + 'country VARCHAR(55), '
        + 'id VARCHAR(10) PRIMARY KEY NOT NULL, '
        + 'email VARCHAR(30) );', []);

queryUser(tx) {
    console.log("Executing sql...");
    tx.executeSql('SELECT * from User', [],this.querySuccess,this.errorCB);
},

querySuccess(tx,results) {
    this.state.progress.push("Query completed");
    var len = results.rows.length;
    console.log(`rows retrieved: ${len}`)
    for (let i = 0; i < len; i++) {
        let row = results.rows.item(i);
    }
},

11-28 12:39:11.996 4086-9001/com.awesomeproject D/ReactNativeJS: 'SQLite.backgroundExecuteSqlBatch({"dbargs":{"dbname":"Test.db"},"executes":[{"qid":1111,"sql":"BEGIN","params":[]},{"qid":1111,"sql":"SELECT * from User","params":[]}]})' 11-28 12:39:12.125 4086-9005/com.awesomeproject W/CursorWindow: Window is full: requested allocation 48 bytes, free space 17 bytes, window size 2097152 bytes 11-28 12:39:12.438 4086-4098/com.awesomeproject I/art: Background sticky concurrent mark sweep GC freed 160895(4MB) AllocSpace objects, 0(0B) LOS objects, 6% free, 43MB/46MB, paused 3.372ms total 109.697ms 11-28 12:39:12.744 4086-4093/com.awesomeproject W/art: Suspending all threads took: 28.277ms 11-28 12:39:12.820 4086-4098/com.awesomeproject I/art: Background partial concurrent mark sweep GC freed 400565(13MB) AllocSpace objects, 0(0B) LOS objects, 31% free, 34MB/50MB, paused 3.633ms total 214.935ms 11-28 12:39:16.256 4086-9001/com.awesomeproject D/ReactNativeJS: 'rows retrieved: 20000' 11-28 12:39:16.286 4086-9001/com.awesomeproject D/ReactNativeJS: 'SQLite.backgroundExecuteSqlBatch({"dbargs":{"dbname":"Test.db"},"executes":[{"qid":1111,"sql":"COMMIT","params":[]}]})'

[andpor]

@barbarosh

The fix I applied seems imemtarial. These are the runtimes using the current codebase for pure Android plugin ~ 4500 millis. I am closing this issue.

11-28 12:57:38.672 16872-16987/com.awesomeproject D/ReactNativeJS: 'SQLite.backgroundExecuteSqlBatch({"dbargs":{"dbname":"Test.db"},"executes":[{"qid":1111,"sql":"BEGIN","params":[]},{"qid":1111,"sql":"SELECT * from User","params":[]}]})' 11-28 12:57:38.894 16872-17217/com.awesomeproject W/CursorWindow: Window is full: requested allocation 48 bytes, free space 17 bytes, window size 2097152 bytes 11-28 12:57:43.334 16872-16987/com.awesomeproject D/ReactNativeJS: 'rows retrieved: 20000' 11-28 12:57:43.359 16872-16987/com.awesomeproject D/ReactNativeJS: 'SQLite.backgroundExecuteSqlBatch({"dbargs":{"dbname":"Test.db"},"executes":[{"qid":1111,"sql":"COMMIT","params":[]}]})'

[andpor]

Running on device S5 Mini ...weird as it is slower than the simulator :) Overall still I think it is quite good..

First run - 7.4 sec

11-28 19:10:47.478 31597-31789/com.awesomeproject D/ReactNativeJS: 'Executing sql...' 11-28 19:10:47.478 31597-31789/com.awesomeproject D/ReactNativeJS: 'SQLite.backgroundExecuteSqlBatch({"dbargs":{"dbname":"Test.db"},"executes":[{"qid":1111,"sql":"BEGIN","params":[]},{"qid":1111,"sql":"SELECT * from User","params":[]}]})' 11-28 19:10:47.668 31597-31875/com.awesomeproject W/CursorWindow: Window is full: requested allocation 48 bytes, free space 17 bytes, window size 2097152 bytes 11-28 19:10:47.723 31597-31875/com.awesomeproject D/dalvikvm: GC_FOR_ALLOC freed 1905K, 24% free 10714K/14008K, paused 21ms, total 21ms 11-28 19:10:48.043 31597-31875/com.awesomeproject D/dalvikvm: GC_FOR_ALLOC freed 1119K, 16% free 13273K/15780K, paused 39ms, total 39ms 11-28 19:10:48.788 31597-31875/com.awesomeproject D/dalvikvm: GC_FOR_ALLOC freed 1825K, 15% free 19639K/22852K, paused 84ms, total 84ms 11-28 19:10:55.163 31597-31789/com.awesomeproject D/ReactNativeJS: 'rows retrieved: 20000' 11-28 19:10:55.248 31597-31789/com.awesomeproject D/ReactNativeJS: 'SQLite.backgroundExecuteSqlBatch({"dbargs":{"dbname":"Test.db"},"executes":[{"qid":1111,"sql":"COMMIT","params":[]}]})'

Second run: 7.1 secs

11-28 19:13:23.308 31597-31789/com.awesomeproject D/ReactNativeJS: 'Executing sql...' 11-28 19:13:23.308 31597-31789/com.awesomeproject D/ReactNativeJS: 'SQLite.backgroundExecuteSqlBatch({"dbargs":{"dbname":"Test.db"},"executes":[{"qid":1111,"sql":"BEGIN","params":[]},{"qid":1111,"sql":"SELECT * from User","params":[]}]})' 11-28 19:13:23.423 31597-31789/com.awesomeproject D/dalvikvm: GC_FOR_ALLOC freed 16247K, 61% free 11585K/29220K, paused 103ms, total 103ms 11-28 19:13:23.633 31597-31875/com.awesomeproject W/CursorWindow: Window is full: requested allocation 48 bytes, free space 17 bytes, window size 2097152 bytes 11-28 19:13:24.178 31597-31875/com.awesomeproject D/dalvikvm: GC_FOR_ALLOC freed 2676K, 48% free 15195K/29220K, paused 63ms, total 63ms 11-28 19:13:24.973 31597-31875/com.awesomeproject D/dalvikvm: GC_FOR_ALLOC freed 1844K, 27% free 21543K/29220K, paused 105ms, total 105ms 11-28 19:13:30.483 31597-31789/com.awesomeproject D/ReactNativeJS: 'rows retrieved: 20000' 11-28 19:13:30.553 31597-31789/com.awesomeproject D/ReactNativeJS: 'SQLite.backgroundExecuteSqlBatch({"dbargs":{"dbname":"Test.db"},"executes":[{"qid":1111,"sql":"COMMIT","params":[]}]})'

[andpor]

Here is the native-android running on device - 6.3 seconds

11-28 20:50:04.278 14420-14917/com.awesomeproject D/ReactNativeJS: 'OPEN database: Test.db' 11-28 20:50:04.278 14420-14917/com.awesomeproject D/ReactNativeJS: 'SQLite.open({"name":"Test.db","dblocation":"docs"})' 11-28 20:50:04.283 14420-14918/com.awesomeproject V/SQLitePlugin: Android db implementation: sqlite4java (NDK)

11-28 21:12:59.423 14420-14917/com.awesomeproject D/ReactNativeJS: 'Executing sql...' 11-28 21:12:59.423 14420-14917/com.awesomeproject D/ReactNativeJS: 'SQLite.backgroundExecuteSqlBatch({"dbargs":{"dbname":"Test.db"},"executes":[{"qid":1111,"sql":"BEGIN","params":[]},{"qid":1111,"sql":"SELECT * from User","params":[]}]})' 11-28 21:13:00.008 14420-16594/com.awesomeproject D/dalvikvm: GC_FOR_ALLOC freed 18291K, 53% free 17792K/37544K, paused 129ms, total 129ms 11-28 21:13:00.588 14420-16594/com.awesomeproject D/dalvikvm: GC_FOR_ALLOC freed 214K, 32% free 25769K/37544K, paused 110ms, total 110ms 11-28 21:13:05.713 14420-14917/com.awesomeproject D/ReactNativeJS: 'rows retrieved: 20000' 11-28 21:13:05.783 14420-14917/com.awesomeproject D/ReactNativeJS: 'SQLite.backgroundExecuteSqlBatch({"dbargs":{"dbname":"Test.db"},"executes":[{"qid":1111,"sql":"COMMIT","params":[]}]})' 11-29 10:17:47.313 14420-14420/? D/SensorManager: unregisterListener ::

[andpor]

@barbarosh - I eliminated all JSON conversions in the Android module which should improve the performance quite significantly. Would you be able to run your tests on the branch that has the changes?

asset-import-exception-handling is the branch name...

This is ordinary android package...not the native impl.

[barbarosh]

@andpor Thanks for work! ) But I don not have access to the project which uses this module, so I can`t test this branch. Sorry!