Better-sqlite3: Handling many small inserts

[johnelliott]

Hi. I'm making a local photo catalog importer with sqlite as my metadata store. I don't know any other node folks using sqlite so I'm hoping others can guide me to making my setup more fast and robust.

My app takes an SD card filled with around 500 5-megabye camera jpeg images (2.5GB). I extract the DateTimeCreated from the camera EXIF data and put that in sqlite with the filename and file basename.

my db schema

CREATE TABLE image (
  id INTEGER PRIMARY KEY,
  file_name NOT NULL,
  date_time_created datetime NOT NULL,
  full_path UNIQUE NOT NULL
);

/media/storage/D1000078.JPG

my db connections

These implementations make two database invocations in extract-transform-load.js and web server.js, one per file as the node module loads. The db object is then closed over by other functions. I call db.prepare(...).run() from other functions.

const db = new Database(path.join(__dirname, 'cab.db'))
try {
  const result = db.prepare(createImages).run()
  debug('db create result', result)
} catch (err) {
  if (err && err.message.match(/table image already exists/)) {
    debug('image table exists')
  } else if (err) {
    debug('db create image table error', err)
    console.error(err)
    process.exit(1)
  }
}

my db queries

Most select statements are like this come from web server.js, every few seconds at most:

const rows = db.prepare(`SELECT file_name, date_time_created FROM image ORDER BY date_time_created DESC LIMIT 36`).all()

or this one as the user fetches more pages of data

    const rows = db.prepare(
      `select file_name, date_time_created,
      (select date_time_created from image where file_name = '${since}') as sinceDateTime
      from image
      where date_time_created < sinceDateTime
      order by date_time_created desc
      limit 36`
    ).all()

the implementations I'm trying

implementation 1

• node-sqlite3 (async)
• node-exiftool (spawns child processes)
• worker-farm

494 images in 400+s?
This one is slow-ish but stable, it lets the system have enough resources for the nginx and node servers to work and the db is available for the select queries when adding ~30 photos @ 1.5/sec. There's some minimal db locking when larger jobs run.

implementation 2

• better-sqlite
• node-exiftool (spawns child processes)
• worker-farm

494 images in 400s
This seems about the same as the other library, so I decided node-exiftool was now the bottleneck. I could remove it now since I am no longer extracting thumbnail data. It doesn't seem much faster but it certainly locks the db more. Perhaps the cached bit of node-sqlite.

implementation 3

• better-sqlite
• exiftool.js

494 images in 220s
It's great that this implementation got all the images loaded without worker farm's retrying/waiting. The blocking enabled this :) This is the fastest overall, but the db is totally locked and the select queries from the web server are 100% blocked until it's done and then they are 100% available. It's not useable because users won't stand for the service being 'down' for 3 minutes as the import happens. Basically I'm back to square one with the long lock.

questions I'm wondering

• why is my db locking? Exif extraction takes about 5ms when isolated, so what gives?
• Am I making 'connections' not often enough?
• what is WAL and is that something that'd help me?
• does my use fit the intended profile?
• are all these individual inserts triggered by node-watch just stupid in general?

I would be happy to make up some tutorials to contribute, since I've done a bunch of different attempts at making this all go, but I need help with some tips on the aspects I'm unaware of that could be big performance factors.

[JoshuaWise]

You should use "Implementation 3" but modified slightly:

• Only use 1 database connection per database per process
• Definitely use WAL mode: db.pragma('journal_mode = WAL');

Read more about these things here and here.

[JoshuaWise]

If you're expecting a lot of concurrent heavy writes, then you might want to consider a full-fledged RDBMS like mysql or postgres.

Things SQLite is good at:

• Heavy concurrent reads
• Heavy single-user writes
• Light concurrent writes
• Heavy concurrent reads while handling heavy single-user writes (if using WAL mode)
• Heavy concurrent reads while handling light concurrent writes (if using WAL mode)

Things SQLite is NOT good at:

• Heavy concurrent reads while handling heavy concurrent writes (in any mode)

[johnelliott]

Hey Joshua, thank you for replying. I have a follow-up question about using WAL mode.

• I am using "implementation 3", the one with pure-js exif data extraction and better-sqlite
• I have one connection per process for the (only) database file. 👍
• this is on a raspberry pi, so a busy disk may be in play (more below)

how to avoid WAL errors?
I read up on WAL mode before posting and tried it, but I ran into the following issue when I close/restart the processes with the database open:

After running WAL mode pragma, if I close the processes with ^c I get an error when re-running again:

SqliteError: unable to open database file
    at Object.<anonymous> (/home/pi/image-hub/server.js:43:21)
    at Module._compile (module.js:652:30)
    at Object.Module._extensions..js (module.js:663:10)
    at Module.load (module.js:565:32)
    at tryModuleLoad (module.js:505:12)
    at Function.Module._load (module.js:497:3)
    at Module.require (module.js:596:17)
    at require (internal/module.js:11:18)
    at Object.<anonymous> (/home/pi/image-hub/bin/www:7:13)
    at Module._compile (module.js:652:30)

Could this happen if I stop the process before a checkpoint happens? I don't move that much data through, so I am worried I'm not even getting to an auto-checkpoint before the process ends. I clearly have no idea when to checkpoint: perhaps on a process exit event, or a time interval, or after each insert. I will just have to try some.

disk access contention?!
With regard to the 'database is locked' errors, the inserts queries are a maximum of 1.75 per second, and they seem to take under 100ms as judged by the debug module. Since exif extraction is similarly brief there seems to be plenty of time for things to happen in between queries. I'm not sure this is 'concurrency' per se if I don't have any queries that overlap in time.

This all makes me worry that I'm actually dealing with a _low_ amount of DB traffic and that the problem may be system-level resource contention for disk access.

Raspberry Pi has an internal microSD card over a USB-2 bus, so the CPU is relatively powerful by comparison. The rsync process seems to nearly saturate the SD card's write bandwidth (11MB/sec of 13MB/sec measured). There's also a lot of reading going on with rsync and the node process reading images in to get the EXIF data out.

I would like to get WAL sorted out so I can determine if it's a solution to my problem, or if I need to spread reads and writes across more disks to get more bandwidth.

[JoshuaWise]

The error you're seeing could be from a number of things:

• You cannot open WAL mode databases on read-only media, or without write permissions
• In WAL mode, sqlite needs write access to the entire folder where the database lives
  
  
  
  • try sudo chown my_webserver_user directory_with_db
  
  
• Perhaps the database isn't being properly closed when you exit the process
  
  
  
  • try process.on('exit', () => { db.checkpoint(); db.close(); });
  
  

If you are only writing to the database from one process at a time, you shouldn't need to do manual checkpoints beyond that. But if you are, then you should periodically check the file size of the wal file (cab.db-wal):

setInterval(async () => {
  const walFileExists = await fs.access('cab.db-wal').then(() => true, () => false);
  if (walFileExists) {
    const { size } = await fs.stat('cab.db-wal');
    if (size >= someUnacceptableSize) db.checkpoint();
  }
}, 30 * 1000 /* this may need to be tweaked, depending on your usage rate */);

(note that for brevity i'm using promisified versions of the fs module functions)

Also, make sure you're using the more recent version of better-sqlite3, version 4.1.0.

[johnelliott]

This is really helpful Joshua, I will verify points 1 and 2 tonight. As for point 3, I was calling checkpoint but never closing the database this way.

I didn't know much about how the WAL file was stored other than knowing the filename. This interval check is much better than simply calling checkpoint every X seconds.

Thank you for your help on this :)

[johnelliott]

Ok quick update:

Changes:

1. made sure I am on v4.1.0
2. added interval checkpointing is on at 10 seconds (decided to just take it wholesale even though I'm not using async/await anywhere else):

  setInterval(async () => {
    const walFileExists = await fsAccess('cab.db-wal').then(() => true, () => false)
    debug('walFileExists', walFileExists)
    if (walFileExists) {
      const { size } = await fsStat('cab.db-wal')
      debug('size', size)
      if (size >= 1000) {
        debug('checkpointing')
        db.checkpoint()
      }
    }
  }, 11 * 1000 /* this may need to be tweaked, depending on your usage rate */)

1. added closing on exit by checking db.open

process.on('exit', code => {
  debug(`process exit with code ${code}`)
  try {
    db.checkpoint()
    if (db.open) {
      db.close()
    }
  } catch (err) {
    console.error(err)
  }
})

Current behavior:
Those three have eliminated the db open errors I was having, but the size of the checkpoint file only continues to grow. Here's the debug log output from the process doing most of the writes:

  hub:etl checkpointing +0ms
  hub:etl walFileExists true +10s
  hub:etl size 679832 +0ms
  hub:etl checkpointing +1ms
  hub:etl walFileExists true +10s
  hub:etl size 679832 +1ms
  hub:etl checkpointing +0ms
  hub:etl walFileExists true +10s
  hub:etl size 679832 +0ms
  hub:etl checkpointing +1ms
  hub:etl walFileExists true +10s
  hub:etl size 679832 +1ms
  hub:etl checkpointing +0ms
  hub:etl walFileExists true +10s
  hub:etl size 679832 +1ms
  hub:etl checkpointing +0ms

Is the checkpoint growth on disk normal?

Thanks for helping me get my connection set up with WAL.

---

I found that my overall performance problems were mostly due to RSYNC hogging the disk.