Version 2.1.0-alpha.1 is ready for testing!

So… didn’t get to play with 2.1.0 alpha a lot, but after an initial upgrade noticed that a lot of my pictures aren’t there… tried to do a restart sync, and then a full rebuild and it just ignored me…

Things were a bit “messy” on my install, and it’s gone through a bunch of testing updates and things, so just started fresh. Blew it all away (config and all) and redownloaded the docker (I’m on unRaid).

Configured as before…

I have 4 directories it’s supposed to scan. Three of them it pulls in thousands of pictures (I haven’t checked closely, but looks like most all) - but those are the three “small” directories. Then there is the main archive. It started on it, chewed just a few minutes, pulled in just a 1000 or so and stopped.

Log shows (for example):

1652886758215,/pictures/Archive/2009/2009-01_January/2009-01-04–2009-01-04_Disney – travel/2009-01-01T18.03.08_Disney-IMG_3849.jpg,enqueued,
1652886758215,/pictures/Archive/2009/2009-01_January/2009-01-04–2009-01-04_Disney – travel/2009-01-01T18.03.24_Disney-IMG_3850.jpg,enqueued,
1652886758226,/pictures/Archive/2009/2009-01_January,canceled,DirectoryWalker was ended,1131
1652886758226,/pictures/Archive/2009,canceled,DirectoryWalker was ended,1132
1652886758226,/pictures/Archive,canceled,DirectoryWalker was ended,111489
1652886760151,/pictures/Archive/1989/1989-10_October/19891007-Dillahunty_Wedding/020-29-Scan-101007-0001.jpg,failed,“BatchCluster has ended, cannot enqueue {”“id”":438,"“method”":"“buildAssetPreviews_”","“args”":[{"“assetId”":199,"“assetFiles”":[{""$ctor"":"“models.AssetFile”","“id”":219,"“assetId”":199,"“shown”":false,"“uri”":"“psfile://37Ajd4ybC/Archive/1989/1989-10_October/19891007-Dillahunty_Wedding/02.:false,”“recountAllTags”":false}]}",http://127.0.0.1:1787/asset/199,2643
~ ~

Where should I look from here? Permissions look right - for example, it pulled 4 pictures from one folder that has about 20. All set the same permissions.

I’m still seeing two problems. Scans don’t seem to populate new images into the database, even with small manually run single date folder scans.

Secondly, I’m still getting weird file ownership problems that I didn’t get with the previous version. This time, I carefully shut everything down, checked file ownership, started again with a stock standard sudo docker-compose up -d

This is the result (the top level of this is the bind mount point for /ps/tmp:

$ sudo docker logs photostructure
Please wait, setting up...
Your library is at <file:///ps/library>
PhotoStructure is ready:
  - <http://127.0.0.1:1787/>
  - <http://172.18.0.2:1787/>
  - <http://f4b1f198ce13:1787/>

Shutting down PhotoStructure...
Please wait, setting up...
Please wait, setting up...
Please wait, setting up...
Please wait, setting up...
Please wait, setting up...
Please wait, setting up...



$ ll
total 0
drwxr-xr-x 5 containeruser containeruser  48 Mar 17 09:38 ./
drwxr-xr-x 3 root       root        28 Mar 16 02:51 ../
drwxrwxr-x 2 containeruser containeruser  19 Mar 16 02:54 backup/
drwxrwxr-x 6 containeruser containeruser 135 May 17 08:47 cache/
drwxrwxr-x 4 containeruser containeruser  70 Mar 17 09:54 samples/


/cache$ ll
total 8
drwxrwxr-x  6 containeruser containeruser 135 May 17 08:47 ./
drwxr-xr-x  5 containeruser containeruser  48 Mar 17 09:38 ../
drwxr-xr-x  2 containeruser containeruser   6 May 12 09:20 .cache-1000/
drwxr-xr-x 15 containeruser containeruser 136 May 17 09:21 imgcache/
drwxr-xr-x  3 containeruser containeruser  20 May 18 21:21 local-db-0885-rqph-1u41-rutf/
-rw-r--r--  1 containeruser containeruser 126 Mar 16 02:57 .NoMedia
drwxr-xr-x  3 containeruser containeruser  37 May 12 09:21 sync-state-kt27ebt2j7/
-rw-r--r--  1 containeruser containeruser  37 Mar 16 03:01 .uuid


/cache/local-db-0885-rqph-1u41-rutf$ ll
total 0
drwxr-xr-x 3 containeruser containeruser  20 May 18 21:21 ./
drwxrwxr-x 6 containeruser containeruser 135 May 17 08:47 ../
drwxr-xr-x 4 root       root        64 May 18 03:57 models/


/cache/local-db-0885-rqph-1u41-rutf/models$ ll
total 225200
drwxr-xr-x 4 root       root              64 May 18 03:57 ./
drwxr-xr-x 3 containeruser containeruser        20 May 18 21:21 ../
drwxr-xr-x 2 root       root               6 May 18 03:57 backup/
-rw-r--r-- 1 root       root       230604800 May 18 03:57 db.sqlite3
drwxr-xr-x 2 root       root               6 May 18 03:57 .db.sqlite3.pslock/

/cache/imgcache$ ll
total 0
drwxr-xr-x 15 containeruser containeruser 136 May 17 09:21 ./
drwxrwxr-x  6 containeruser containeruser 135 May 17 08:47 ../
drwxr-xr-x  3 root       root        16 May 17 09:18 2z/
drwxr-xr-x  3 root       root        16 May 17 09:20 30/
drwxr-xr-x  3 root       root        16 May 17 09:19 38/
drwxr-xr-x  3 root       root        16 May 17 09:18 4n/
drwxr-xr-x  3 root       root        16 May 17 09:16 5d/
drwxr-xr-x  3 root       root        16 May 17 09:19 75/
drwxr-xr-x  3 root       root        16 May 17 09:20 7x/
drwxr-xr-x  3 root       root        16 May 17 09:18 82/
drwxr-xr-x  3 root       root        16 May 17 09:20 92/
drwxr-xr-x  3 root       root        16 May 17 09:19 9t/
drwxr-xr-x  3 root       root        16 May 17 09:18 cq/
drwxr-xr-x  3 root       root        16 May 17 09:18 g9/
drwxr-xr-x  3 root       root        16 May 17 09:18 gf/

If the DirectoryWalker ended, that means the error rate was too high and the “yikes, things are bad, I better not continue” circuit breaker blew.

If you set your logging to info and send me your logs I can take a look at what’s going on.

@devon can you shell into your PhotoStructure container and send me a the result of env ; ps -ef please?

$ sudo docker exec -ti photostructure sh
/ps/app # env ; ps -ef
NODE_VERSION=16.15.0
HOSTNAME=34a43ee66ea4
YARN_VERSION=1.22.18
SHLVL=1
PS_IS_DOCKER=true
HOME=/root
PS_LOG_LEVEL=info
PGID=1000
TERM=xterm
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
PUID=1000
PWD=/ps/app
TZ=Pacific/Auckland
NODE_ENV=production
UID          PID    PPID  C STIME TTY          TIME CMD
root           1       0  0 09:29 ?        00:00:00 /sbin/tini -- /ps/app/docker-entrypoint.sh
root           7       1  0 09:29 ?        00:00:00 su --preserve-environment node --command /usr/local/bin/node /ps/app/photostructure
node          18       7  0 09:29 ?        00:00:00 /usr/local/bin/node /ps/app/photostructure
node          25      18  0 09:29 ?        00:00:07 photostructure main
node          36      25  1 09:29 ?        00:00:14 photostructure sync
node          54      25  3 09:30 ?        00:00:26 photostructure web
node          77      36  0 09:30 ?        00:00:00 findmnt --poll
node         308      54  2 09:43 ?        00:00:00 /usr/bin/perl -w /ps/app/node_modules/exiftool-vendored.pl/bin/exiftool -stay_open True -@ -
root         310       0  1 09:43 pts/0    00:00:00 sh
root         318     310  0 09:43 pts/0    00:00:00 ps -ef

Dang (or good?): that’s what I hoped we’d see–that node was the owner of all the PhotoStructure processes.

So… Docker does have usermap functionality which we might be fighting. How are you configuring the bind mount for /ps/library? What version of docker are you running, and what host OS? What’s the mount entry for that volume look like?

(Also, feel free to DM me any response that has anything you consider private)

$ cat /etc/lsb-release
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=20.04
DISTRIB_CODENAME=focal
DISTRIB_DESCRIPTION="Ubuntu 20.04.4 LTS"
$ docker --version
Docker version 20.10.16, build aa7e414
$ docker-compose --version
docker-compose version 1.29.2, build 5becea4c

Relevant parts of docker-compose.yml:

version: "3.7"
services:
  photostructure:
    # You can run alpha, beta, or stable builds. See
    # <https://forum.photostructure.com/t/274> for details.
    image: photostructure/server:alpha
    container_name: photostructure
    restart: on-failure
    stop_grace_period: 2m

    volumes:
      # This is where your PhotoStructure Library will be stored.
      # It must be readable, writable, and have sufficient free space.
      # If it is a remote volume, uncomment the PS_FORCE_LOCAL_DB_REPLICA
      # environment line below.

      - type: bind
        source: "/var/containers/photostructure/library/" # < CHANGE THIS LINE
        target: /ps/library/

      # This must be fast, local disk with many gigabytes free.
      # PhotoStructure will use this directory for file caching
      # and for storing a temporary database replica when your
      # library is on a remote volume.

      - type: bind
        source: "/media/bulkstorage/photostructure/cache/"
        target: /ps/tmp

      # This directory stores your "system settings"

      - type: bind
        source: "/var/containers/photostructure/config"
        target: /ps/config

      # This directory stores PhotoStructure logfiles.

      - type: bind
        source: "/var/containers/photostructure/logs"
        target: /ps/logs

<snip>

    ports:
      - 1787:1787/tcp

    environment:
      # PhotoStructure has _tons_ of settings. See
      # <https://photostructure.com/faq/environment-variables/>

      # This tells PhotoStructure to only log errors, which is the default:
      # - "PS_LOG_LEVEL=error"

      # If PhotoStructure is refusing to spin up, uncomment these lines to see what's going on:
      - "PS_LOG_LEVEL=info"
      # - "PS_LOG_STDOUT=true"

      # This is your local timezone. See <https://en.wikipedia.org/wiki/List_of_tz_database_time_zones>
      - "TZ=Pacific/Auckland" # < CHANGE THIS LINE

      # The userid to run PhotoStructure as:
      - "PUID=1000" # < CHANGE THIS LINE or delete this line to run as root. See below for details.

      # The groupid to run PhotoStructure as:
      - "PGID=1000" # < CHANGE THIS LINE or delete this line to run as root.


That’s exactly how my primary dev box is configured, so this should work.

What’s the fstype for "/var/containers/photostructure and /media/bulkstorage/?

Containers is an NFS 3 mount using TrueNAS Core (ZFS).

Bulkstorage is xfs and a local drive.

OK. xfs and the local drive shouldn’t be an issue, as long as UID 1000 can read and write to those dirs.

NFS user mapping can be surprising*: if you sudo -u 1000 can you read and write to the NFS volume?

* as in, I can’t tell you how many times I borked up my NFS usermaps, but it’s many.

$ sudo -u \#1000 touch /var/containers/photostructure/test.txt
$ ll /var/containers/photostructure/test*
-rwxrwxrwx 1 containeruser containeruser 0 May 19 04:41 /var/containers/photostructure/test.txt*

Works, although it’s not that location that I’m seeing problems, but in /ps/tmp, which is the local xfs drive.

(your umask defaults to setting the execute bit? You might want to adjust that)

Harumph. I really don’t get where something would (or even could) drop from userid 1000 back to userid 0. It’d be a huge privilege escalation issue with Alpine if I drop to uid 1000 at startup, and some random subprocess after that is able to revert to uid 0.

Another one - the app doesn’t regularly check for new images. Where should I look?

Sync information
path	status	last started	last completed
/media/photos	stale	2 days, 22 hours ago	2 days, 18 hours ago

I fixed sync scheduling in v2.0, but seem to have a regression in v2.1. I’ll get this fixed: thanks for the heads-up.

1 Like

Hi @mrm,

Just thought I’d let you know my favourite problem is back! The container has been up for a while, I’ve been manually running ./photostructure sync on new folders inside the container and it’s been working well enough. Last thing yesterday I hit the “restart sync” option from the web UI since I was lazy. Today I couldn’t access the web UI anymore, just got an error from the proxy in front.

I restarted the container but no dice, got this instead:

{"toast":{"text":"Well, darn, that didn't work","uuid":"SqliteError: SQLITE_READONLY: attempt to write a readonly database","details":"SqliteError: SQLITE_READONLY: attempt to write a readonly database","type":"warning","button1Text":"Return home","button1Url":"/tag#dismiss","button1Class":"info","onClickUrl":"#dismiss"}}

I stopped the container and went to rm -r the sqlite directory, since that’s gotten locked a couple of times in the past, but I got a permissions error. A bit of exploration below.

containeruser@host:/media/bulkstorage$ ll
total 4
drwxr-xr-x 3 root       root         28 Mar 16 02:51 ./
drwxr-xr-x 7 root       root       4096 May 26 08:08 ../
drwxr-xr-x 5 containeruser containeruser   48 Mar 17 09:38 photostructure/
containeruser@host:/media/bulkstorage$ cd photostructure/
containeruser@host:/media/bulkstorage/photostructure$ ll
total 0
drwxr-xr-x 5 containeruser containeruser  48 Mar 17 09:38 ./
drwxr-xr-x 3 root       root        28 Mar 16 02:51 ../
drwxrwxr-x 2 containeruser containeruser  19 Mar 16 02:54 backup/
drwxrwxr-x 7 containeruser containeruser 155 May 26 09:22 cache/
drwxrwxr-x 4 containeruser containeruser  70 Mar 17 09:54 samples/
containeruser@host:/media/bulkstorage/photostructure$ cd cache/
containeruser@host:/media/bulkstorage/photostructure/cache$ ll
total 8
drwxrwxr-x  7 containeruser containeruser 155 May 26 09:22 ./
drwxr-xr-x  5 containeruser containeruser  48 Mar 17 09:38 ../
drwxr-xr-x  2 containeruser containeruser   6 May 12 09:20 .cache-1000/
drwxr-xr-x 28 containeruser containeruser 266 Jun  4 22:39 imgcache/
drwxr-xr-x  3 containeruser containeruser  20 Jun  6 01:42 local-db-0885-rqph-1u41-rutf/
-rw-r--r--  1 containeruser containeruser 126 Mar 16 02:57 .NoMedia
drwxr-xr-x  4 containeruser containeruser  26 Jun  4 22:22 readdircache/
drwxr-xr-x  3 containeruser containeruser  37 May 12 09:21 sync-state-kt27ebt2j7/
-rw-r--r--  1 containeruser containeruser  37 Mar 16 03:01 .uuid
containeruser@host:/media/bulkstorage/photostructure/cache$ cd local-db-0885-rqph-1u41-rutf/
containeruser@host:/media/bulkstorage/photostructure/cache/local-db-0885-rqph-1u41-rutf$ ll
total 0
drwxr-xr-x 3 containeruser containeruser  20 Jun  6 01:42 ./
drwxrwxr-x 7 containeruser containeruser 155 May 26 09:22 ../
drwxr-xr-x 3 root       root        82 Jun  4 22:01 models/
containeruser@host:/media/bulkstorage/photostructure/cache/local-db-0885-rqph-1u41-rutf$ cd models/
containeruser@host:/media/bulkstorage/photostructure/cache/local-db-0885-rqph-1u41-rutf/models$ ll
total 562692
drwxr-xr-x 3 root       root              82 Jun  4 22:01 ./
drwxr-xr-x 3 containeruser containeruser        20 Jun  6 01:42 ../
drwxr-xr-x 2 root       root               6 Jun  4 22:39 backup/
-rw-r--r-- 1 root       root       287416320 Jun  4 22:39 db.sqlite3
-rw-r--r-- 1 root       root          589824 Jun  4 22:39 db.sqlite3-shm
-rw-r--r-- 1 root       root       288189912 Jun  4 22:39 db.sqlite3-wal
containeruser@host:/media/bulkstorage/photostructure/cache/local-db-0885-rqph-1u41-rutf/models$ ll ../../imgcache/
total 0
drwxr-xr-x 28 containeruser containeruser 266 Jun  4 22:39 ./
drwxrwxr-x  7 containeruser containeruser 155 May 26 09:22 ../
drwxr-xr-x  3 root       root        16 Jun  4 22:34 19/
drwxr-xr-x  3 root       root        16 Jun  4 22:36 1b/
drwxr-xr-x  3 root       root        16 Jun  4 22:39 3u/
drwxr-xr-x  3 root       root        16 Jun  4 22:38 6b/
drwxr-xr-x  3 root       root        16 Jun  4 22:34 7q/
drwxr-xr-x  3 root       root        16 Jun  4 22:38 7w/
drwxr-xr-x  3 root       root        16 Jun  4 22:37 8f/
drwxr-xr-x  3 root       root        16 Jun  4 22:35 92/
drwxr-xr-x  3 root       root        16 Jun  4 22:38 98/
drwxr-xr-x  3 root       root        16 Jun  4 22:34 99/
drwxr-xr-x  3 root       root        16 Jun  4 22:35 9n/
drwxr-xr-x  3 root       root        16 Jun  4 22:37 b6/
drwxr-xr-x  3 root       root        16 Jun  4 22:38 bq/
drwxr-xr-x  3 root       root        16 Jun  4 22:36 c6/
drwxr-xr-x  3 root       root        16 Jun  4 22:36 c7/
drwxr-xr-x  3 root       root        16 Jun  4 22:39 cw/
drwxr-xr-x  3 root       root        16 Jun  4 22:36 d7/
drwxr-xr-x  3 root       root        16 Jun  4 22:37 db/
drwxr-xr-x  3 root       root        16 Jun  4 22:34 dy/
drwxr-xr-x  3 root       root        16 Jun  4 22:39 e5/
drwxr-xr-x  3 root       root        16 Jun  4 22:37 eg/
drwxr-xr-x  3 root       root        16 Jun  4 22:39 ej/
drwxr-xr-x  3 root       root        16 Jun  4 22:36 fd/
drwxr-xr-x  3 root       root        16 Jun  4 22:39 gb/
drwxr-xr-x  3 root       root        16 Jun  4 22:38 gr/
drwxr-xr-x  3 root       root        16 Jun  4 22:37 gz/

I haven’t restarted the container again in case there’s something about its state or logs that could be useful…

@devon, the permission issue is really odd–are you sure there isn’t some sneaky second docker-compose.yml (that is being started by systemd on reboot)?

Pretty sure…

$ sudo systemctl status photostructure
Unit photostructure.service could not be found.

and

$ ll /etc/systemd/system
total 128
drwxr-xr-x 21 root root 4096 May 26 10:20  ./
drwxr-xr-x  5 root root 4096 May 12 07:56  ../
drwxr-xr-x  2 root root 4096 Aug 24  2021  cloud-final.service.wants/
drwxr-xr-x  2 root root 4096 Feb 21 03:37  cloud-init.target.wants/
lrwxrwxrwx  1 root root   40 Mar 13 04:55  dbus-org.freedesktop.ModemManager1.service -> /lib/systemd/system/ModemManager.service
lrwxrwxrwx  1 root root   44 Aug 24  2021  dbus-org.freedesktop.resolve1.service -> /lib/systemd/system/systemd-resolved.service
lrwxrwxrwx  1 root root   36 Feb 21 03:10  dbus-org.freedesktop.thermald.service -> /lib/systemd/system/thermald.service
lrwxrwxrwx  1 root root   45 Aug 24  2021  dbus-org.freedesktop.timesync1.service -> /lib/systemd/system/systemd-timesyncd.service
drwxr-xr-x  2 root root 4096 Aug 24  2021  default.target.wants/
drwxr-xr-x  2 root root 4096 Feb 21 03:10  emergency.target.wants/
drwxr-xr-x  2 root root 4096 Aug 24  2021  final.target.wants/
drwxr-xr-x  2 root root 4096 Aug 24  2021  getty.target.wants/
drwxr-xr-x  2 root root 4096 Aug 24  2021  graphical.target.wants/
lrwxrwxrwx  1 root root   38 Aug 24  2021  iscsi.service -> /lib/systemd/system/open-iscsi.service
drwxr-xr-x  2 root root 4096 Aug 24  2021  mdmonitor.service.wants/
lrwxrwxrwx  1 root root   38 Aug 24  2021  multipath-tools.service -> /lib/systemd/system/multipathd.service
drwxr-xr-x  2 root root 4096 May 26 10:20  multi-user.target.wants/
drwxr-xr-x  2 root root 4096 Aug 24  2021  network-online.target.wants/
drwxr-xr-x  2 root root 4096 Aug 24  2021  open-vm-tools.service.requires/
drwxr-xr-x  2 root root 4096 Aug 24  2021  paths.target.wants/
drwxr-xr-x  2 root root 4096 Feb 21 03:55  remote-fs.target.wants/
drwxr-xr-x  2 root root 4096 Feb 21 03:10  rescue.target.wants/
drwxr-xr-x  2 root root 4096 Feb 21 03:10  sleep.target.wants/
-rw-r--r--  1 root root  285 Mar 18 17:53  snap-core18-2344.mount
-rw-r--r--  1 root root  285 May 12 08:05  snap-core18-2409.mount
-rw-r--r--  1 root root  285 Apr 28 10:23  snap-core20-1434.mount
-rw-r--r--  1 root root  285 May 26 10:20  snap-core20-1494.mount
-rw-r--r--  1 root root  279 Feb 25 01:42  snap-lxd-22526.mount
-rw-r--r--  1 root root  279 Mar 25 05:41  snap-lxd-22753.mount
-rw-r--r--  1 root root  467 Mar 25 05:41  snap.lxd.activate.service
-rw-r--r--  1 root root  541 Mar 25 05:41  snap.lxd.daemon.service
-rw-r--r--  1 root root  330 Mar 25 05:41  snap.lxd.daemon.unix.socket
-rw-r--r--  1 root root  285 Apr 20 02:09  snap-snapd-15534.mount
-rw-r--r--  1 root root  285 May 24 23:15  snap-snapd-15904.mount
drwxr-xr-x  2 root root 4096 Mar 25 05:41  sockets.target.wants/
drwxr-xr-x  2 root root 4096 Mar 30 10:14 'sshd-keygen@.service.d'/
lrwxrwxrwx  1 root root   31 Feb 21 03:11  sshd.service -> /lib/systemd/system/ssh.service
drwxr-xr-x  2 root root 4096 Aug 24  2021  sysinit.target.wants/
lrwxrwxrwx  1 root root   35 Aug 24  2021  syslog.service -> /lib/systemd/system/rsyslog.service
drwxr-xr-x  2 root root 4096 Feb 21 03:37  timers.target.wants/
lrwxrwxrwx  1 root root   41 Aug 24  2021  vmtoolsd.service -> /lib/systemd/system/open-vm-tools.service

Agreed, that looks correct.

If you reboot and psgrep for photostructure, is it running as uid 1000 or 0? (Or not running?)

$ ps -ef|grep photostructure
root        1821    1581  0 20:05 ?        00:00:00 su --preserve-environment node --command /usr/local/bin/node /ps/app/photostructure
contain+    1843    1821  0 20:05 ?        00:00:00 /usr/local/bin/node /ps/app/photostructure
contain+    1946    1843  2 20:05 ?        00:00:02 photostructure main
contain+    2077    1946 16 20:05 ?        00:00:12 photostructure sync
contain+    2452    1946 42 20:06 ?        00:00:08 photostructure web
contain+    2499    2367  0 20:06 pts/0    00:00:00 grep --color=auto photostructure

$ uptime
 20:06:36 up 1 min,  1 user,  load average: 0.84, 0.40, 0.15

@devon thanks for the update. That sure seems like things are in order.

I’ll try to think of other scenarios that could result in inadvertent privilege escalation.

(Update: we figured it out: see this post)