PS alpha upgraded: db-info.json expecting sqlite file in different location

tim_w_photography · November 23, 2023, 11:11pm

I have just updated PS Alpha to the latest GIT version 2023.11.0-alpha.1

Actually, PS appears to have updated itself, and I am getting the following in UI on start.

/mnt/nfs/Photos/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-live-db/4e04-c0qq-a7j3-0xjj-b81x-99kh/db.sqlite3 but the live db is pslib:/.photostructure/models/db.sqlite3

How I got here
I restarted my dedicated Ubuntu LTS 22.04 VM with PS for servers installed. When it came back up, it complained about a few things and I noticed it was now running a very new version (I’d never seen the /health endpoint before).

From memory it warned that I did not have 8GB free on my VM and that Node was old (16.18.something if remember correctly). I think there might have been another complaint too. However, after clicking “restart” in the UI it was then showing photos so I assumed it was working other than the warnings.

I then ran an apt-get upgrade and then a apt-get dist-upgrade hoping that might get me a newer node and I resized the Virtualbox disk, increased the LVM PV and LVs and resized ext4.

Node was still old, so I followed the instructions for installing node using apt and I tried to restart the systemd target.

Part of the above is specific config for node and npm module locations. I suspect that was the reason that it complained about yarn not found. So I installed it using the instructions I found here.

Now PS is starting and I get the health page load up with the above error.

Notes

My photos store is on NFS on another server backed by mirrored ZFS. This is backed up regularly.
My PS library is also located there too (I think I understand the difference). I’m trying to not have too much on the VM because it’s not backed up.

mrm · November 24, 2023, 5:52am

Howdy!

One of the things I really wanted to avoid from v2.1 was issues stemming from inconsistent “local db replica mode”.

When running, PhotoStructure (actually the web service) runs some heuristics to determine if SQLite can use the library database directly, or of it needs to use a db replica stored in local disk.

It does these heuristics when it’s starting up, and writes a “db-info.json” file in your /ps/library/.photostructure/models/ directory, and should delete the file when it is shut down gracefully.

Make sure PhotoStructure is shut down, then manually delete that json file, then restart your PhotoStructure container. Things should work.

Also verify that your system is shutting down PhotoStructure gracefully. If you see this error again, or your library is suddenly empty, or you see database errors, it’s probably from not shutting down cleanly.

tim_w_photography · November 24, 2023, 6:13am

Thanks @mrm. That’s fixed it.

I shutdown from the button on the UI, checked that nothing was running, and then restarted the systemd service.

All my photos are back. Thank you!

mrm · November 25, 2023, 6:20pm

Excellent, thanks taking the time to say it worked.

If this happens again, please do notify me: we can dig into your config and make sure it’s letting PhotoStructure shut down gracefully.

tim_w_photography · January 23, 2024, 1:51am

I still get this from time to time. I get two errors fairly regularly.

This error. Sometimes just restarting PS gets it going again, other times it needs the above file removed. I am using the .photostructure on NFS and have the setting for forceLocalDbReplica set to true in settings.toml
I then get Something's amiss with ExifTool: ExifTool timed out so I don’t think imports are working at the moment.

I have PS for Servers installed on a dedicated VM. I recently upgraded the VM with 2023.12.0-alpha.7.
I had to update node and some other stuff to get it working again.

Prior to that, it was quite stable. The underlying machine is starting show its age. I am wondering if it’s just too slow. The VM has 12 vCPUs (Xeons) and 8GB of RAM. The PS library location and the actual images are NFS mounted in the client to an export on the host which is running ZFS mirrored disks.

tim_w_photography · March 28, 2024, 9:15pm

Thanks for the updated PS. I am now running.

Version: 2024.3.3-beta
Edition: PhotoStructure for Servers

This seems to have solved the issue with it starting up, or rather has moved the issue so that I can at least use the UI, but can’t add any new photos. My lastest are all from October 2023.

Looking at the logs, I see this when I start PS, or I manually run the sync.

2024-03-28T21:06:28.495Z sync-1475035 warn_ library.Library(/opt/Media/Pictures/PhotoStructure) Library previews are on a remote volume. Setting maxSyncFileJobsMax to 2.
2024-03-28T21:06:28.570Z sync-1475035 warn_ fs.FsLock(.photostructure/models/db-info.json)#2 withLock_() rejected '/opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-live-db/4e04-c0qq-a7j3-0x…ite3 but the live db is pslib:/.…or-servers/bin/sync.js:9:1044073'
2024-03-28T21:06:28.600Z sync-1475035 error_ db.DbModelSetup Failed to set up model db { error:
   '/opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-live-db/4e04-c0qq-a7j3-0x…ite3 but the live db is pslib:/.…or-servers/bin/sync.js:9:1044073' }
2024-03-28T21:06:28.612Z sync-1475035 warn_ library.Library(/opt/Media/Pictures/PhotoStructure) setup() failed: { error:
   '/opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-live-db/4e04-c0qq-a7j3-0x…ite3 but the live db is pslib:/.…or-servers/bin/sync.js:9:1044073' }
2024-03-28T21:06:28.718Z sync-1475035 warn_ Exit exit() { error:
   'g: SyncService.setup() failed: Failed to start library: /opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-li…or-servers/bin/sync.js:9:1044073',
  status: 12,
  ending: false }
2024-03-28T21:06:28.732Z sync-1475035 error_ Error onError() { event: 'fatal',
  error:
   'g: SyncService.setup() failed: Failed to start library: /opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-li…or-servers/bin/sync.js:9:1044073' }
2024-03-28T21:06:33.789Z sync-1475035 warn_ async.Endable EventFilter.end() failed 'timeout (00:00:05.000) at c (/home/photostructure/photostructure-for-servers/bin/sync.js:9:1044221); w (/home/photostructure/photostructure-for-servers/bin/sync.js:9:139588); async Promise.allSettled (index 2); h.thunk (/ho…or-servers/bin/sync.js:9:146127)'

I did do a systemd stop, and tried to remove the db-info.json file, but it was no longer there.
Restarting I see the errors show in the log.

Please let me know if there is anything I can try next to get the indexer working again.

mrm · March 29, 2024, 5:26pm

Howdy @tim_w_photography – a couple days ago we discovered on discord that the newer version of SQLite in that build may not fail as it’s expected to when the library is on an NFS mount.

SQLite is supposed to require a local disk, but because everyone had PS_FORCE_LOCAL_DB_REPLICA set to true on docker, and that proved to be a performance hit, I changed the code (last august-ish) to automatically attempt to both read and write from the library database. If that works, PhotoStructure decides to ignore PS_FORCE_LOCAL_DB_REPLICA, and just use the local library directly.

This works great on SMB and AFS mounts where SQLite consistently doesn’t work–but NFS started to unexpectedly pass my health check for some versions of NFS servers and clients (I’ve reproduced this issue with my Synology as a server and Ubuntu as a client).

For now, you can work around this issue by running your library in “hybrid” mode:

Shut down PhotoStructure
Copy /opt/Media/Pictures/PhotoStructure/.photostructure/models to a local directory (say, /home/photostructure/library/models, assuming that’s on a local and fast disk, ideally SSD)
cd /opt/Media/Pictures/PhotoStructure/.photostructure && mv models models-old
ln -s /home/photostructure/library/models /opt/Media/Pictures/PhotoStructure/.photostructure
restart PhotoStructure

The next release is focused on fixing the desktop builds–I’ll be able to look at this some time next week, and get a fix out in a subsequent release.

tim_w_photography · March 29, 2024, 8:57pm

Thanks @mrm for the prompt reply. However it still appears to be trying to load from the NFS device (in my uneducated guess).

BTW, my “local” drive is ZFS rust underneath and then a virtual disk on the VM. So also not overly performant.

2024-03-29T20:54:15.737Z sync-1608514 warn_ library.Library(/opt/Media/Pictures/PhotoStructure) setup() failed: { error:
   '/opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-live-db/4e04-c0qq-a7j3-0x…ite3 but the live db is pslib:/.…or-servers/bin/sync.js:9:1044073' }
2024-03-29T20:54:15.832Z sync-1608514 warn_ Exit exit() { error:
   'g: SyncService.setup() failed: Failed to start library: /opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-li…or-servers/bin/sync.js:9:1044073',
  status: 12,
  ending: false }
2024-03-29T20:54:15.847Z sync-1608514 error_ Error onError() { event: 'fatal',
  error:
   'g: SyncService.setup() failed: Failed to start library: /opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-li…or-servers/bin/sync.js:9:1044073' }
2024-03-29T20:54:15.848Z sync-1608514 warn_ Exit exit() { reason:
   'g: SyncService.setup() failed: Failed to start library: /opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-li…hotostructure/models/db.sqlite3¹',
  status: 13,
  ending: true }
2024-03-29T20:54:20.882Z sync-1608514 warn_ async.Endable EventFilter.end() failed 'timeout (00:00:05.000) at c (/home/photostructure/photostructure-for-servers/bin/sync.js:9:1044221); w (/home/photostructure/photostructure-for-servers/bin/sync.js:9:139588); async Promise.allSettled (index 2); h.thunk (/ho…or-servers/bin/sync.js:9:146127)'
2024-03-29T20:54:23.569Z web-1606715 warn_ express.ServerToastHelpers sendServerToast() { requestedURI:
   { '$mid': 1,
     path: '/api/system',
     scheme: 'http',
     authority: 'photostructure.local.lan' },
  toast: { type: 'info', text: 'Sync force-restart was requested' },
  httpStatusCode: null }
2024-03-29T20:54:26.141Z main-1606703 warn_ WatchedChild(sync:1608540) onError() 'ChildService(sync).onStdout(): {"fatal":true,"error":{"_ctor":"WrappedError","causes":[{"_ctor":"WrappedError","causes":[{"_ctor":"Error","message":"/opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json exp…or-servers/bin/main.js:9:172117)'
2024-03-29T20:54:26.160Z main-1606703 warn_ WatchedChild(sync:1608540) onError() 'ChildService(sync).onStdout(): {"fatal":true,"reason":"g: SyncService.setup() failed: Failed to start library: /opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3U…or-servers/bin/main.js:9:172117)'
2024-03-29T20:54:25.891Z sync-1608540 warn_ library.Library(/opt/Media/Pictures/PhotoStructure) Library previews are on a remote volume. Setting maxSyncFileJobsMax to 2.
2024-03-29T20:54:25.915Z sync-1608540 warn_ fs.FsLock(.photostructure/models/db-info.json)#2 withLock_() rejected '/opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-live-db/4e04-c0qq-a7j3-0x…ite3 but the live db is pslib:/.…or-servers/bin/sync.js:9:1044073'
2024-03-29T20:54:25.935Z sync-1608540 error_ db.DbModelSetup Failed to set up model db { error:
   '/opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-live-db/4e04-c0qq-a7j3-0x…ite3 but the live db is pslib:/.…or-servers/bin/sync.js:9:1044073' }
2024-03-29T20:54:25.938Z sync-1608540 warn_ library.Library(/opt/Media/Pictures/PhotoStructure) setup() failed: { error:
   '/opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-live-db/4e04-c0qq-a7j3-0x…ite3 but the live db is pslib:/.…or-servers/bin/sync.js:9:1044073' }
2024-03-29T20:54:26.043Z sync-1608540 warn_ Exit exit() { error:
   'g: SyncService.setup() failed: Failed to start library: /opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-li…or-servers/bin/sync.js:9:1044073',
  status: 12,
  ending: false }
2024-03-29T20:54:26.057Z sync-1608540 error_ Error onError() { event: 'fatal',
  error:
   'g: SyncService.setup() failed: Failed to start library: /opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-li…or-servers/bin/sync.js:9:1044073' }
2024-03-29T20:54:26.058Z sync-1608540 warn_ Exit exit() { reason:
   'g: SyncService.setup() failed: Failed to start library: /opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3UzRs/home/photostructure/.cache/photostructure/models-li…hotostructure/models/db.sqlite3¹',
  status: 13,
  ending: true }
2024-03-29T20:54:31.110Z sync-1608540 warn_ async.Endable EventFilter.end() failed 'timeout (00:00:05.000) at c (/home/photostructure/photostructure-for-servers/bin/sync.js:9:1044221); w (/home/photostructure/photostructure-for-servers/bin/sync.js:9:139588); async Promise.allSettled (index 2); h.thunk (/ho…or-servers/bin/sync.js:9:146127)'
2024-03-29T20:54:34.264Z main-1606703 warn_ WatchedChild(sync:1608553) onError() 'ChildService(sync).onStdout(): {"fatal":true,"error":{"_ctor":"WrappedError","causes":[{"_ctor":"WrappedError","causes":[{"_ctor":"Error","message":"/opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json exp…or-servers/bin/main.js:9:172117)'
2024-03-29T20:54:34.282Z main-1606703 warn_ WatchedChild(sync:1608553) onError() 'ChildService(sync).onStdout(): {"fatal":true,"reason":"g: SyncService.setup() failed: Failed to start library: /opt/Media/Pictures/PhotoStructure/.photostructure/models/db-info.json expects the live db to be psfile://3DaL3U…or-servers/bin/main.js:9:172117)'