sqlite3-ruby icon indicating copy to clipboard operation
sqlite3-ruby copied to clipboard

ver1.5.0.rc1, execute method is 30% slower than ver1.4.4

Open Watson1978 opened this issue 2 years ago • 1 comments

Seems that execute method is 30% slower than ver1.4.4.

Environment

  • macOS
    • macOS 13.0 Beta(22A5321d)
    • Apple M1 Max
    • Apple clang version 14.0.0 (clang-1400.0.29.102)
    • ruby 3.2.0dev (2022-08-09T11:11:48Z master ff07e5c264) [arm64-darwin22]

1.5.0.rc1 result

*** SQLite3 1.5.0.rc1 ***
Warming up --------------------------------------
             execute     6.460k i/100ms
Calculating -------------------------------------
             execute     64.732k (± 0.3%) i/s -    329.460k in   5.089641s

1.4.4 result

*** SQLite3 1.4.4 ***
Warming up --------------------------------------
             execute     8.345k i/100ms
Calculating -------------------------------------
             execute     83.406k (± 0.5%) i/s -    417.250k in   5.002748s

Test code

require 'bundler/inline'
gemfile do
  source 'https://rubygems.org'
  gem 'benchmark-ips'
  gem 'sqlite3'
end

puts "*** SQLite3 #{SQLite3::VERSION} ***"

db = SQLite3::Database.new(':memory:')
db.execute(<<~SQL)
  create table users (
    id INTEGER PRIMARY KEY AUTOINCREMENT,
    name TEXT,
    email TEXT,
    created_at TIMESTAMP,
    updated_at TIMESTAMP
  )
SQL

5.times do |i|
  db.execute("insert into users (name, email, created_at, updated_at) values ('foo', '[email protected]', '#{Time.now.strftime("%Y-%m-%d %H:%M:%S")}', '#{Time.now.strftime("%Y-%m-%d %H:%M:%S")}')")
end


Benchmark.ips do |x|
  # x.time = 20

  query = 'select * from users'
  x.report('execute') {
    db.execute(query)
  }
end

Watson1978 avatar Aug 12 '22 17:08 Watson1978

Thanks for opening this issue, I will spend some time to try to reproduce and investigate before we cut a 1.5.0 final.

flavorjones avatar Aug 12 '22 20:08 flavorjones

Hi! Thanks for your patience. Because this gem previously used system libraries, benchmark results are going to heavily depend on what version of sqlite3 you're using and how it was built.

On my Ubuntu 20.04 (x86_64) system using libsqlite3-0 3.31.1-4ubuntu0.3, here are the results of this benchmark:

#! /usr/bin/env ruby

require 'bundler/inline'

gemfile do
  source 'https://rubygems.org'
  gem 'benchmark-ips'
  gem 'sqlite3', path: "."
end

puts "info: sqlite3-ruby version: #{SQLite3::VERSION}/#{SQLite3::VersionProxy::STRING}"
puts "info: sqlite3 version: #{SQLite3::SQLITE_VERSION}"
puts "info: sqlcipher?: #{SQLite3.sqlcipher?}"
puts "info: threadsafe?: #{SQLite3.threadsafe?}"

db = SQLite3::Database.new(':memory:')
db.execute(<<~SQL)
  create table users (
    id INTEGER PRIMARY KEY AUTOINCREMENT,
    name TEXT,
    email TEXT,
    created_at TIMESTAMP,
    updated_at TIMESTAMP
  )
SQL

5.times do |i|
  db.execute("insert into users (name, email, created_at, updated_at) values ('foo', '[email protected]', '#{Time.now.strftime('%Y-%m-%d %H:%M:%S')}', '#{Time.now.strftime('%Y-%m-%d %H:%M:%S')}')")
end

Benchmark.ips do |x|
  # x.time = 20

  query = 'select * from users'
  x.report('execute') do
    db.execute(query)
  end
end
info: sqlite3-ruby version: 1.4.4/1.4.4
info: sqlite3 version: 3.31.1
info: sqlcipher?: false
info: threadsafe?: true
Warming up --------------------------------------
             execute     3.636k i/100ms
Calculating -------------------------------------
             execute     36.846k (± 3.7%) i/s -    185.436k in   5.040116s

info: sqlite3-ruby version: 1.5.0.rc1/1.5.0.rc1
info: sqlite3 version: 3.39.2
info: sqlcipher?: false
info: threadsafe?: true
Warming up --------------------------------------
             execute     3.219k i/100ms
Calculating -------------------------------------
             execute     34.423k (± 2.9%) i/s -    173.826k in   5.054137s

Can you share a bit more about your system, version of sqlite, and how it was built?

flavorjones avatar Aug 28 '22 15:08 flavorjones

Also, when I build 1.5.0.rc1 against system libraries I get nearly the same results as 1.4.4.:

info: sqlite3-ruby version: 1.5.0.rc1/1.5.0.rc1
info: sqlite3 version: 3.31.1
info: sqlcipher?: false
info: threadsafe?: true
Warming up --------------------------------------
             execute     3.730k i/100ms
Calculating -------------------------------------
             execute     36.837k (± 4.0%) i/s -    186.500k in   5.072057s

(You can do this too by installing the gem with gem install sqlite3 --platform=ruby --pre -- --enable-system-libraries)

My conclusion right now is that you're seeing effects of using a newer version of sqlite3. Help me confirm or invalidate this conclusion?

flavorjones avatar Aug 28 '22 15:08 flavorjones

It certainly looks like a problem with SQLite itself, not this gem.

sqlite3-1.5.0.rc1 has good performance with --enable-system-libraries install option

$ rake clean
$ rake build
sqlite3 1.5.0.rc1 built to pkg/sqlite3-1.5.0.rc1.gem.
$ gem uninstall sqlite3
Successfully uninstalled sqlite3-1.5.0.rc1
$ gem install pkg/sqlite3-1.5.0.rc1.gem
$ ruby bench.rb
info: sqlite3-ruby version: 1.5.0.rc1/1.5.0.rc1
info: sqlite3 version: 3.39.2
info: sqlcipher?: false
info: threadsafe?: true
Warming up --------------------------------------
             execute     6.404k i/100ms
Calculating -------------------------------------
             execute     64.543k (± 0.3%) i/s -    326.604k in   5.060283s



$ gem uninstall sqlite3
Successfully uninstalled sqlite3-1.5.0.rc1
$ gem install pkg/sqlite3-1.5.0.rc1.gem --platform=ruby --pre -- --enable-system-libraries
Building native extensions with: '--enable-system-libraries'
This could take a while...
Successfully installed sqlite3-1.5.0.rc1
1 gem installed
$ ruby bench.rb
info: sqlite3-ruby version: 1.5.0.rc1/1.5.0.rc1
info: sqlite3 version: 3.39.0
info: sqlcipher?: false
info: threadsafe?: true
Warming up --------------------------------------
             execute     8.824k i/100ms
Calculating -------------------------------------
             execute     88.732k (± 0.5%) i/s -    450.024k in   5.071870s

Watson1978 avatar Aug 29 '22 19:08 Watson1978

Are there different optimizations when building SQLite 3.39.2 than what is built into the system?

Watson1978 avatar Aug 29 '22 19:08 Watson1978

Currently https://github.com/sparklemotion/sqlite3-ruby/blob/master/ext/sqlite3/extconf.rb isn't asking the compiler to do any optimizations, which is probably the issue.

I'll take a look in a bit, but if you want to play with this you can set your CFLAGS environment variable to adjust how sqlite3 is built, something like this will do:

CFLAGS=-O2 gem install sqlite3 --pre --platform=ruby -- --disable-system-libraries

flavorjones avatar Aug 29 '22 19:08 flavorjones

I updated the previous comment to correct the command to disable system libraries.

flavorjones avatar Aug 29 '22 20:08 flavorjones

TLDR with -O2 this benchmark is 33% faster on my machine.

Compiler optimization (or lack thereof) is definitely a contributing factor here. On my system here's the story:

$ gem uninstall sqlite3
Successfully uninstalled sqlite3-1.5.0.rc1

$ gem install sqlite3 --pre --platform=ruby -- --disable-system-libraries
Fetching sqlite3-1.5.0.rc1.gem
Building native extensions with: '--disable-system-libraries'
This could take a while...
Successfully installed sqlite3-1.5.0.rc1
1 gem installed

$ ./335-execute-benchmark.rb 
info: sqlite3-ruby version: 1.5.0.rc1/1.5.0.rc1
info: sqlite3 version: 3.39.0
info: sqlcipher?: false
info: threadsafe?: true
Warming up --------------------------------------
             execute     3.360k i/100ms
Calculating -------------------------------------
             execute     33.650k (± 4.2%) i/s -    168.000k in   5.001789s

$ gem uninstall sqlite3
Successfully uninstalled sqlite3-1.5.0.rc1

$ CFLAGS=-O2 gem install sqlite3 --pre --platform=ruby -- --disable-system-libraries
Fetching sqlite3-1.5.0.rc1.gem
Building native extensions with: '--disable-system-libraries'
This could take a while...
Successfully installed sqlite3-1.5.0.rc1
1 gem installed

$ ./335-execute-benchmark.rb 
info: sqlite3-ruby version: 1.5.0.rc1/1.5.0.rc1
info: sqlite3 version: 3.39.0
info: sqlcipher?: false
info: threadsafe?: true
Warming up --------------------------------------
             execute     4.521k i/100ms
Calculating -------------------------------------
             execute     44.722k (± 3.4%) i/s -    226.050k in   5.060751s

flavorjones avatar Aug 29 '22 20:08 flavorjones

I'll also note that -O3 isn't any faster than -O2 on my system.

I'm going to prepare a PR that sets -O2 for both the precompiled native gem payload and in the extconf used to compile from source during installation.

flavorjones avatar Aug 29 '22 20:08 flavorjones

See https://github.com/sparklemotion/sqlite3-ruby/pull/341

flavorjones avatar Aug 29 '22 20:08 flavorjones

Merged that PR, I will cut another 1.5.0 release candidate shortly just to make sure everything is as expected.

flavorjones avatar Aug 30 '22 01:08 flavorjones

v1.5.0.rc2 is out, let me know if you see any problems with it.

flavorjones avatar Aug 30 '22 19:08 flavorjones