3.14.2 significantly slower than 3.8.11.2

[cordje]

Thanks for updating this project to the latest SQLite version.

Unfortunately, I've noticed a significant regression in performance from the previous builds.

Since upgrading to the latest sqlite-jdbc jar (3.14.2), I've noticed that all of my queries are roughly a third slower than the previous version.

I was wondering if the new way of compiling SQLite native binaries has something to do with this, since I can't imagine that SQLite itself has become this much slower (they have unit tests written in TCL to benchmark their performance on every release).

For example:

"SELECT lat,long FROM latlong WHERE postcode=?"
10 million of these very simple SELECT queries are performed in:

• 20 seconds in 3.8.11.2
• 30 seconds in 3.14.2

The speed difference exists across the variety of possible PRAGMA settings, and across queries of varying complexity.

While I'm not expecting a fix or an investigation any time soon, it'd be useful if other people could add their own experience on performance here.

[gitblit]

Hmm. We did change some compiler flags for #104 and #59.

Across a single-threaded multi-statement benchmark I'm generally seeing improvements but I don't have performance numbers on large data sets; mine are all quite small.

3.8.11

Name        Config           Version                   Stats/sec  Runtime
-------------------------------------------------------------------------------
SQLite      memory           3.8.11                    18249      0.3s  (1.0x)
SQLite      wal,no_sync      3.8.11                    16791      0.3s  (1.1x)
SQLite      wal,norm_sync    3.8.11                    10628      0.5s  (1.7x)
SQLite      delete,no_sync   3.8.11                    10012      0.5s  (1.8x)
SQLite      wal,full_sync    3.8.11                      412     11.7s  (44.2x)
SQLite      delete,norm_sync 3.8.11                      178     27.2s  (102.5x)
SQLite      delete,full_sync 3.8.11                      128     37.6s  (142.0x)

3.14.2

Name        Config           Version                   Stats/sec  Runtime
-------------------------------------------------------------------------------
SQLite      wal,no_sync      3.14.2                    19214      0.3s  (1.0x)
SQLite      memory           3.14.2                    16844      0.3s  (1.1x)
SQLite      delete,no_sync   3.14.2                    12873      0.4s  (1.5x)
SQLite      wal,norm_sync    3.14.2                    12653      0.4s  (1.5x)
SQLite      wal,full_sync    3.14.2                      997      5.2s  (19.3x)
SQLite      delete,norm_sync 3.14.2                      481     10.8s  (39.9x)
SQLite      delete,full_sync 3.14.2                      350     14.8s  (54.8x)

[xerial]

@cordje Interesting. Is it possible to compare the performance using the original sqlite command line to isolate the problem from sqlite's version iteself?

[cordje]

@xerial Hi. Yes, no problem. I just compared performance of "sqlite-tools-win32-x86-3140200/sqlite3.exe" and "sqlite-shell-win32-x86-3081101/sqlite3.exe" with 200k SELECT queries and I got roughly the same performance between them.

I've created a single file test script that replicates the issue: https://gist.github.com/cordje/4e66781de4b84ee74eea2d5fe2aff377

On sqlite-jdbc-3.8.7.jar I get:

Time to create & insert: 2393 ms
Time to select: 3375 ms
Time to select & get resultset values: 4342 ms

On sqlite-jdbc-3.8.11.2.jar I get:

Time to create & insert: 2201 ms
Time to select: 3283 ms
Time to select & get resultset values: 4196 ms

On sqlite-jdbc-**3.14.2.**jar (THREADSAFE=1) I get:

Time to create & insert: 2243 ms
Time to select: 4905 ms
Time to select & get resultset values: 6043 ms

On sqlite-jdbc-3.14.2.1-20160928.160101-3.jar (THREADSAFE=0) I get:

Time to create & insert: 2182 ms
Time to select: 4404 ms
Time to select & get resultset values: 5868 ms

Thanks

[xerial]

@cordje OK. So you are using sqlite-jdbc in windows. I'll check how the compiler change (to a docker based one #153) affect the performance.

[xerial]

@cordje Just from curiosity, I built sqlite-jdbc without HAVE_USLEEP flag #104 for windows:
https://oss.sonatype.org/content/repositories/snapshots/org/xerial/sqlite-jdbc/3.14.2.1-SNAPSHOT/sqlite-jdbc-3.14.2.1-20160928.034634-1.jar

[cordje]

@xerial Thanks.

Unfortunately, there's no difference with this change. Upon looking at SQLite's source, perhaps the reason why is that main.c overrides HAVE_USLEEP if SQLITE_OS_WIN is true. See: sqliteDefaultBusyCallback method in https://www.sqlite.org/src/artifact/c9e49e376820bccc

My best guess from the changes @gitblit cited is: 217597d

DSQLITE_THREADSAFE=0
to
DSQLITE_THREADSAFE=1

From https://www.sqlite.org/compile.html#threadsafe

To put it another way, SQLITE_THREADSAFE=1 sets the default threading mode to Serialized. SQLITE_THREADSAFE=2 sets the default threading mode to Multi-threaded. And SQLITE_THREADSAFE=0 sets the threading mode to Single-threaded.

Note that when SQLite is compiled with SQLITE_THREADSAFE=0, the code to make SQLite threadsafe is omitted from the build.

Is it possible that the previous sqlite-jdbc versions' choice of single threaded mode (and hence omission of the mutexing logic) provided better performance on a single thread, than the current configuration (which is better for multi thread)?
I've seen similar in the past, especially on Windows (e.g., a 40% performance hit is mentioned here http://www.iis-aid.com/articles/my_word/difference_between_php_thread_safe_and_non_thread_safe_binaries )

If this does turn out to be the cause, then providing the option to the sqlite-jdbc end-user would be ideal, as there are some cases where single thread performance is more important than being able to multi thread.

[xerial]

Now that building native libraries are easy, providing a version for single thread mode can be an option. Or creating API to set threading mode at run time.

[cordje]

That would be great, but still worth verifying to see if it's the cause before spending that effort.
Could you build a snapshot without the changes in 217597d ?

Thanks

[xerial]

Sure. Created a jar for Windows with -DSQLITE_THREADSAFE=0:
https://oss.sonatype.org/content/repositories/snapshots/org/xerial/sqlite-jdbc/3.14.2.1-SNAPSHOT/sqlite-jdbc-3.14.2.1-20160928.160101-3.jar

[cordje]

Good news: Perhaps two versions (non & threadsafe) are not required from a single-thread performance viewpoint.

Bad news: Still not sure why this latest release is slower. The only thing to suspect now, is the compiler/docker change. I compared the output of the SQL "pragma compile_options" between the sqlite-jdbc versions. The only difference except the thread safety is that these latest 3.14.2 releases have "COMPILER=gcc-4.9.3". All the other versions (i.e. faster ones) don't return a COMPILER field.

(I updated my previous comment to include the new run times, since there was a marginal performance improvement from non-thread safety).

Thanks again for pursuing these two possibilities.

[xerial]

Thanks for the report. One more try: https://oss.sonatype.org/content/repositories/snapshots/org/xerial/sqlite-jdbc/3.14.2.1-SNAPSHOT/sqlite-jdbc-3.14.2.1-20160928.195228-4.jar

I built this with gcc-4.6.3 on Ubuntu. The other options are the same with 3.14.2

[cordje]

Unfortunately it's performing the same.

Now I'm wondering whether the sqlite3.exe command line benchmark can be used reliably to test performance. Ie whether the drop in performance is due to the sqlite upgrade.

If there are no other ideas, at some point soon I'll write the same benchmark in C using the native library to compare the performance of 3.14.2 and 3.8.11

[xerial]

@cordje JVM usually requires warm-up time to produce stable results because of JIT compilation that runs in the background.

There might be the other changes that affect the performance, but your tests have been good enough to isolate the problem from compilation or THREADSAFE mode.

[patcheng]

I think it might be related to this change: c30fe3e
which calls from JNI to Java.

I experimented with a potential fix, see my PR. Not sure if it will have similar performance improve on Windows.

[xerial]

Nice catch. I should have reviewed this inefficient code :)

[cordje]

Great. I look forward to having a snapshot I can try. (I really ought to try building it myself..)
Cheers

[xerial]

Here is the windows binary with #162: http://oss.sonatype.org/content/repositories/snapshots/org/xerial/sqlite-jdbc/3.14.2.1-SNAPSHOT/sqlite-jdbc-3.14.2.1-20160929.213916-5.jar

[cordje]

Excellent :) - fixed, and it has the best performance of any version so far, which is great considering it's the first sqlite-jdbc release to be compiled with thread safety.

sqlite-jdbc-3.14.2.1-20160929.213916-5.jar:

Time to create & insert: 2331 ms
Time to select: 3265 ms
Time to select & get resultset values: 4084 ms

Also, @patcheng's original multithreaded performance test is running as expected on my PC (Win 10 x64, i5 6600k 4 cores).

Threads: 1 Time: 283 ms
Threads: 4 Time: 269 ms
Threads: 8 Time: 504 ms
(test code from: #59 (comment))

Thanks to everyone for getting this fixed so quickly.

[xerial]

Just released sqlite-jdbc-3.14.2.1 with this fix. Let me close this ticket. Thanks!