1.log

{"ts":1633755531660,"l":"debug","ctx":"BaseFile(/ps/config/PhotoStructure)","msg":"resolve()","meta":{"sibs":[]}}
{"ts":1633755531662,"l":"debug","ctx":"BaseFile(/ps/config/PhotoStructure)","msg":"resolve()","meta":{"sibs":[]}}
{"ts":1633755531667,"l":"debug","ctx":"BaseFile(/ps/config)","msg":"resolve()","meta":{"result":{"nativePath":"/ps/config"},"sibs":[{"basename":"config","isFile":false,"isDirectory":true}]}}
{"ts":1633755531668,"l":"info","ctx":"mergeAndArchiveSystemSettingsDir_(/ps/config/PhotoStructure => /ps/config)","msg":"no-op, missing or same directory","meta":{"currentResolvedConfigDir":"/ps/config"}}
{"ts":1633755531671,"l":"debug","ctx":"BaseFile(/ps/config/photostructure)","msg":"resolve()","meta":{"sibs":[]}}
{"ts":1633755531672,"l":"debug","ctx":"BaseFile(/ps/config/photostructure)","msg":"resolve()","meta":{"sibs":[]}}
{"ts":1633755531672,"l":"debug","ctx":"BaseFile(/ps/config)","msg":"resolve()","meta":{"result":{"nativePath":"/ps/config"},"sibs":[{"basename":"config","isFile":false,"isDirectory":true}]}}
{"ts":1633755531672,"l":"info","ctx":"mergeAndArchiveSystemSettingsDir_(/ps/config/photostructure => /ps/config)","msg":"no-op, missing or same directory","meta":{"currentResolvedConfigDir":"/ps/config"}}
{"ts":1633755531673,"l":"debug","ctx":"BaseFile(/ps/photostructure)","msg":"resolve()","meta":{"sibs":[]}}
{"ts":1633755531674,"l":"debug","ctx":"BaseFile(/ps/photostructure)","msg":"resolve()","meta":{"sibs":[]}}
{"ts":1633755531676,"l":"debug","ctx":"BaseFile(/ps/config)","msg":"resolve()","meta":{"result":{"nativePath":"/ps/config"},"sibs":[{"basename":"config","isFile":false,"isDirectory":true}]}}
{"ts":1633755531676,"l":"info","ctx":"mergeAndArchiveSystemSettingsDir_(/ps/photostructure => /ps/config)","msg":"no-op, missing or same directory","meta":{"currentResolvedConfigDir":"/ps/config"}}
{"ts":1633755531676,"l":"info","ctx":"MergeConfigDirs","msg":"done"}
{"ts":1633755531703,"l":"info","ctx":"SettingsIO.importFileSettings(/ps/config/settings.toml)","msg":"loaded","meta":{"imported":{"copyAssetsToLibrary":false,"libraryDir":"/ps/library","scanAllDrives":false,"scanPaths":["/images"]}}}
{"ts":1633755531705,"l":"info","ctx":"SettingsIO","msg":"_libraryHasSettings","meta":{"result":false,"settings":"/ps/library","librarySettingsFile":"/ps/library/.photostructure/settings.toml"}}
{"ts":1633755531706,"l":"info","ctx":"Service(main)","msg":"setupErrorHandling(): not adding stdin/stdout/stderr close handlers: we're daemonized or in docker."}
{"ts":1633755532086,"l":"warn","ctx":"Sentry","msg":"Failed to set up sentry","meta":"Cannot read property 'init' of undefined\nTypeError: Cannot read property 'init' of undefined\n    at Object.t.installSentry (/ps/app/bin/main.js:9:671168)\n    at t.Service.setupErrorHandling (/ps/app/bin/main.js:9:681021)\n    at t.Service._setup (/ps/app/bin/main.js:9:678091)\n    at g.time (/ps/app/bin/main.js:9:116035)\n    at Object.t.asPromise (/ps/app/bin/main.js:9:600860)"}
{"ts":1633755532089,"l":"info","ctx":"Service(main)","msg":"setup(): starting main","meta":{"version":"2.0.0-alpha.1","start":1633755531003,"argv":["/usr/local/bin/node","/ps/app/bin/main.js"],"arch":"x64","platform":"linux","isDocker":true,"os":"Alpine Linux v3.13 on x64","isPacked":true,"isElectron":false,"versions":{"node":"16.2.0","v8":"9.0.257.25-node.16","uv":"1.41.0","zlib":"1.2.11","brotli":"1.0.9","ares":"1.17.1","modules":"93","nghttp2":"1.42.0","napi":"8","llhttp":"6.0.1","openssl":"1.1.1k+quic","cldr":"39.0","icu":"69.1","tz":"2021a","unicode":"13.0","ngtcp2":"0.1.0-DEV","nghttp3":"0.1.0-DEV"},"settings":{"logLevel":"debug","httpPort":1787,"rpcPort":1807,"libraryDir":"/ps/library"},"NODE_ENV":"production","PS_LOG_LEVEL":"debug"}}
{"ts":1633755532120,"l":"info","ctx":"RpcServer","msg":"Setting up RPC..."}
{"ts":1633755532121,"l":"debug","ctx":"rpc.Server","msg":"start(1807)"}
{"ts":1633755532123,"l":"info","ctx":"rpc.Server","msg":"listening on 1807"}
{"ts":1633755532123,"l":"info","ctx":"RpcServer","msg":"RPC service serving port 1807"}
{"ts":1633755532126,"l":"info","ctx":"ChildService","msg":"pathToService()","meta":{"result":{},"cmd":"web.js","isPacked":true,"dirs":["/ps/app/bin/web.js","/ps/app/app.asar/web.js","/ps/app/dist/app/web.js"]}}
{"ts":1633755532127,"l":"info","ctx":"WatchedChild(web)","msg":"_restart()","meta":{"stopped":false,"ended":false}}
{"ts":1633755532128,"l":"info","ctx":"WatchedChild(web)","msg":"_stop()","meta":{"stopped":false,"ended":false}}
{"ts":1633755532128,"l":"debug","ctx":"WatchedChild(web)","msg":"isErrorRateExceeded()","meta":{"result":false,"maxErrorsPerMin":3}}
{"ts":1633755532128,"l":"info","ctx":"WatchedChild(web)","msg":"restart()","meta":{"startRate":{"ttlMs":120000,"_eventCount":0,"_lastEventTime":0,"eventDeltas":{"ttlMs":120000,"times":[],"a":[]}},"maxErrorsPerMinute":3}}
{"ts":1633755532128,"l":"info","ctx":"WatchedChild(web)","msg":"_start()","meta":{"stopped":false,"ended":false}}
{"ts":1633755532133,"l":"debug","ctx":"ChildEnv","msg":"env","meta":{"NODE_VERSION":"16.2.0","HOSTNAME":"photostructure-server","YARN_VERSION":"1.22.5","SHLVL":"2","HOME":"/root","PS_IS_DOCKER":"1","PS_LOG_LEVEL":"debug","TERM":"xterm","PATH":"/bin:/usr/bin:/usr/local/bin:/usr/local/sbin:/usr/lib/libraw:/opt/local/bin:/opt/local/sbin:/usr/sbin:/sbin","GID":"100","UID":"1026","PWD":"/ps/app","NODE_ENV":"production","VIPS_MIN_STACK_SIZE":"2m","VIPSHOME":"/target"}}
{"ts":1633755532133,"l":"debug","ctx":"ChildProcess","msg":"spawn()","meta":{"command":"/usr/local/bin/node","args":["/ps/app/bin/web.js"],"maxAgeMs":-1}}
{"ts":1633755532141,"l":"info","ctx":"WatchedChild(web:40)","msg":"_start(): spawned pid 40"}
{"ts":1633755533483,"l":"info","ctx":"rpc.Server","msg":"Connection from IPv4:127.0.0.1:51518"}
{"ts":1633755533486,"l":"debug","ctx":"rpc.Server","msg":"onRequest()","meta":"{\"id\":\"rbKfJqbHp-1\",\"method\":\"ping\",\"params\":{\"serviceName\":\"web\",\"pid\":40}}"}
{"ts":1633755533487,"l":"debug","ctx":"rpc.Server","msg":"handle()","meta":{"elapsedMs":0,"method":"ping","conn":"web:40","id":"rbKfJqbHp-1","params":{"serviceName":"web","pid":40},"result":"pong to web@40 from main@27 at Sat Oct 09 2021 04:58:53 GMT+0000 (Coordinated Universal Time)"}}
{"ts":1633755533490,"l":"debug","ctx":"rpc.Server","msg":"onRequest()","meta":"{\"id\":\"rbKfJqbHp-2\",\"method\":\"paused\"}"}
{"ts":1633755533491,"l":"debug","ctx":"rpc.Server","msg":"handle()","meta":{"elapsedMs":0,"method":"paused","conn":"web:40","id":"rbKfJqbHp-2","result":false}}
{"ts":1633755533544,"l":"info","ctx":"MainService","msg":"Got HTTP port number from web service:1787"}
{"ts":1633755539146,"l":"debug","ctx":"Pids","msg":"addPid() wrote /ps/config/pids/40.json","meta":{"pid":40,"cmd":"node","maxAgeMs":-1,"ppid":27,"startTime":1633755532140}}
{"ts":1633755563071,"l":"debug","ctx":"rpc.Server","msg":"onRequest()","meta":"{\"id\":\"rbKfJqbHp-3\",\"method\":\"ping\",\"params\":{\"serviceName\":\"web\",\"pid\":40}}"}
{"ts":1633755563071,"l":"debug","ctx":"rpc.Server","msg":"handle()","meta":{"elapsedMs":0,"method":"ping","conn":"web:40","id":"rbKfJqbHp-3","params":{"serviceName":"web","pid":40},"result":"pong to web@40 from main@27 at Sat Oct 09 2021 04:59:23 GMT+0000 (Coordinated Universal Time)"}}
{"ts":1633755563073,"l":"debug","ctx":"rpc.Server","msg":"onRequest()","meta":"{\"id\":\"rbKfJqbHp-4\",\"method\":\"isVacuuming\"}"}
{"ts":1633755563074,"l":"debug","ctx":"RpcServiceHandlers","msg":"isVacuuming","meta":{"result":false}}
{"ts":1633755563074,"l":"debug","ctx":"rpc.Server","msg":"handle()","meta":{"elapsedMs":0,"method":"isVacuuming","conn":"web:40","id":"rbKfJqbHp-4","result":false}}
{"ts":1633755563130,"l":"info","ctx":"MainService.restartSync()","msg":"priorSync"}
{"ts":1633755563140,"l":"info","ctx":"SettingsIO.importFileSettings(/ps/config/settings.toml)","msg":"loaded","meta":{"imported":{"copyAssetsToLibrary":false,"libraryDir":"/ps/library","scanAllDrives":false,"scanPaths":["/images"]}}}
{"ts":1633755563141,"l":"info","ctx":"SettingsIO","msg":"_libraryHasSettings","meta":{"result":true,"settings":"/ps/library","librarySettingsFile":"/ps/library/.photostructure/settings.toml"}}
{"ts":1633755563142,"l":"info","ctx":"ChildService","msg":"pathToService()","meta":{"result":{},"cmd":"sync.js","isPacked":true,"dirs":["/ps/app/bin/sync.js","/ps/app/app.asar/sync.js","/ps/app/dist/app/sync.js"]}}
{"ts":1633755563142,"l":"info","ctx":"WatchedChild(sync)","msg":"_restart()","meta":{"stopped":false,"ended":false}}
{"ts":1633755563142,"l":"info","ctx":"WatchedChild(sync)","msg":"_stop()","meta":{"stopped":false,"ended":false}}
{"ts":1633755563142,"l":"debug","ctx":"WatchedChild(sync)","msg":"isErrorRateExceeded()","meta":{"result":false,"maxErrorsPerMin":3}}
{"ts":1633755563142,"l":"info","ctx":"WatchedChild(sync)","msg":"restart()","meta":{"startRate":{"ttlMs":120000,"_eventCount":0,"_lastEventTime":0,"eventDeltas":{"ttlMs":120000,"times":[],"a":[]}},"maxErrorsPerMinute":3}}
{"ts":1633755563142,"l":"info","ctx":"WatchedChild(sync)","msg":"_start()","meta":{"stopped":false,"ended":false}}
{"ts":1633755563143,"l":"info","ctx":"MainService.restartSync()","msg":"Started sync","meta":{"name":"ChildService(sync)"}}
{"ts":1633755563143,"l":"debug","ctx":"ChildProcess","msg":"spawn()","meta":{"command":"/usr/local/bin/node","args":["/ps/app/bin/sync.js"],"maxAgeMs":-1}}
{"ts":1633755563148,"l":"info","ctx":"WatchedChild(sync:68)","msg":"_start(): spawned pid 68"}
{"ts":1633755564161,"l":"info","ctx":"rpc.Server","msg":"Connection from IPv4:127.0.0.1:51536"}
{"ts":1633755564163,"l":"debug","ctx":"rpc.Server","msg":"onRequest()","meta":"{\"id\":\"3KMWXTraD-1\",\"method\":\"ping\",\"params\":{\"serviceName\":\"sync\",\"pid\":68}}"}
{"ts":1633755564164,"l":"debug","ctx":"rpc.Server","msg":"handle()","meta":{"elapsedMs":0,"method":"ping","conn":"sync:68","id":"3KMWXTraD-1","params":{"serviceName":"sync","pid":68},"result":"pong to sync@68 from main@27 at Sat Oct 09 2021 04:59:24 GMT+0000 (Coordinated Universal Time)"}}
{"ts":1633755564166,"l":"debug","ctx":"rpc.Server","msg":"onRequest()","meta":"{\"id\":\"3KMWXTraD-2\",\"method\":\"isVacuuming\"}"}
{"ts":1633755564166,"l":"debug","ctx":"RpcServiceHandlers","msg":"isVacuuming","meta":{"result":false}}
{"ts":1633755564166,"l":"debug","ctx":"rpc.Server","msg":"handle()","meta":{"elapsedMs":0,"method":"isVacuuming","conn":"sync:68","id":"3KMWXTraD-2","result":false}}
{"ts":1633755564169,"l":"debug","ctx":"rpc.Server","msg":"onRequest()","meta":"{\"id\":\"3KMWXTraD-3\",\"method\":\"volumes\"}"}
{"ts":1633755564172,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"df","args":["-k","-P"]}}
{"ts":1633755564172,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"df","args":["-k","-P"],"maxAgeMs":25000}}
{"ts":1633755564190,"l":"debug","ctx":"ignorablePath()","msg":"/","meta":{"hiddenPosix":false,"systemDir":false,"ignorableMountpoint":false,"ignorableRoot":false,"ignorableDirectory":false,"ignorablePath":false,"ignorablePattern":false}}
{"ts":1633755564190,"l":"debug","ctx":"ignorablePath()","msg":"/images","meta":{"pathIsNeverIgnored":false}}
{"ts":1633755564190,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"df","args":["-k","-P","-l"]}}
{"ts":1633755564190,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"df","args":["-k","-P","-l"],"maxAgeMs":25000}}
{"ts":1633755564200,"l":"debug","ctx":"ignorablePath()","msg":"/","meta":{"hiddenPosix":false,"systemDir":false,"ignorableMountpoint":false,"ignorableRoot":false,"ignorableDirectory":false,"ignorablePath":false,"ignorablePattern":false}}
{"ts":1633755564200,"l":"debug","ctx":"ignorablePath()","msg":"/images","meta":{"pathIsNeverIgnored":false}}
{"ts":1633755564203,"l":"info","ctx":"Volumes","msg":"validateMountpoints(): /images is not a directory"}
{"ts":1633755564204,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"lsblk","args":["--version"]}}
{"ts":1633755564204,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"lsblk","args":["--version"],"maxAgeMs":7000}}
{"ts":1633755564210,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"lsblk","args":["-P","-b","--output","mountpoint,label,uuid"]}}
{"ts":1633755564210,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"lsblk","args":["-P","-b","--output","mountpoint,label,uuid"],"maxAgeMs":25000}}
{"ts":1633755564223,"l":"debug","ctx":"LocalVolumesPosix","msg":"lsblk","meta":{"result":[{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"[SWAP]","label":"","uuid":"","ignorable":true},{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"[SWAP]","label":"","uuid":"","ignorable":true},{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"","label":"","uuid":"","ignorable":true},{"mountpoint":"[SWAP]","label":"","uuid":"","ignorable":true},{"mountpoint":"[SWAP]","label":"","uuid":"","ignorable":true},{"ignorable":true}]}}
{"ts":1633755564226,"l":"debug","ctx":"BaseFile(/.uuid)","msg":"trap: readFile() failed: Error: ENOENT: no such file or directory, open '/.uuid'"}
{"ts":1633755564226,"l":"debug","ctx":"Volumes","msg":"_volumes(): final result","meta":{"sorted":[{"filesystem":"none","mountpoint":"/","size":1962626523136,"used":1384010137600,"available":578494750720,"ignorable":false,"remote":false}]}}
{"ts":1633755564227,"l":"info","ctx":"Library(/ps/library)","msg":"new()"}
{"ts":1633755564227,"l":"debug","ctx":"Library(/ps/library)","msg":"setup() started"}
{"ts":1633755564228,"l":"debug","ctx":"OpenedByIO()","msg":"throwIfAvailable()","meta":{"from":"(library setup)"}}
{"ts":1633755564230,"l":"debug","ctx":"rpc.Server","msg":"handle()","meta":{"elapsedMs":59,"method":"volumes","conn":"sync:68","id":"3KMWXTraD-3","result":[{"filesystem":"none","mountpoint":"/","size":1962626523136,"used":1384010137600,"available":578494750720,"ignorable":false,"remote":false}]}}
{"ts":1633755564231,"l":"debug","ctx":"JsonFileStore","msg":"prior /ps/config/.system-uid.json","meta":{"uid":"mrm1-mcpt-udxh-vp1d","version":"2.0.0-alpha.1","type":"system","createdAt":1633755543436}}
{"ts":1633755564242,"l":"debug","ctx":"OpenedBy.maybeRemovePriorLock(/ps/library/.photostructure/opened-by/13nbuj7-27.json)","msg":"Retaining prior lockfile"}
{"ts":1633755564242,"l":"debug","ctx":"OpenedBy.maybeRemovePriorLock(/ps/library/.photostructure/opened-by/13nbuj7-40.json)","msg":"Retaining prior lockfile"}
{"ts":1633755564243,"l":"debug","ctx":"OpenedBy.maybeRemovePriorLock(/ps/library/.photostructure/opened-by/13nbuj7-68.json)","msg":"Retaining prior lockfile"}
{"ts":1633755564245,"l":"debug","ctx":"currentLibraryLockOwner(/ps/library/.photostructure)","msg":"read","meta":{"jsons":[{"file":{"nativePath":"/ps/library/.photostructure/opened-by/13nbuj7-27.json"},"serviceName":"main","createdAt":1633755564228,"updatedAt":1633755564229,"hostname":"photostructure-server","systemUID":"mrm1-mcpt-udxh-vp1d","v":"2.0.0-alpha.1","pid":27},{"file":{"nativePath":"/ps/library/.photostructure/opened-by/13nbuj7-40.json"},"serviceName":"web","createdAt":1633755562956,"updatedAt":1633755562956,"hostname":"photostructure-server","systemUID":"mrm1-mcpt-udxh-vp1d","v":"2.0.0-alpha.1","pid":40},{"file":{"nativePath":"/ps/library/.photostructure/opened-by/13nbuj7-68.json"},"serviceName":"sync","createdAt":1633755564030,"updatedAt":1633755564031,"hostname":"photostructure-server","systemUID":"mrm1-mcpt-udxh-vp1d","v":"2.0.0-alpha.1","pid":68}]}}
{"ts":1633755564246,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","27,40,68","-wwwo","pid,lstart,command"]}}
{"ts":1633755564246,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","27,40,68","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755564253,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[27,40,68],"result":[{"pid":27,"start":"2021-10-09T04:58:50.000Z","cmd":"photostructure main"},{"pid":40,"start":"2021-10-09T04:58:52.000Z","cmd":"photostructure web"},{"pid":68,"start":"2021-10-09T04:59:23.000Z","cmd":"photostructure sync"}]}}
{"ts":1633755564253,"l":"info","ctx":"currentLibraryLockOwner(/ps/library/.photostructure)","msg":"currentLibraryLockOwner","meta":{"result":{"file":{"nativePath":"/ps/library/.photostructure/opened-by/13nbuj7-27.json"},"serviceName":"main","createdAt":1633755564228,"updatedAt":1633755564229,"hostname":"photostructure-server","systemUID":"mrm1-mcpt-udxh-vp1d","v":"2.0.0-alpha.1","pid":27}}}
{"ts":1633755564253,"l":"debug","ctx":"OpenedByIO()","msg":"throwIfAvailable()","meta":{"from":"(library setup)","lockOwner":{"file":{"nativePath":"/ps/library/.photostructure/opened-by/13nbuj7-27.json"},"serviceName":"main","createdAt":1633755564228,"updatedAt":1633755564229,"hostname":"photostructure-server","systemUID":"mrm1-mcpt-udxh-vp1d","v":"2.0.0-alpha.1","pid":27}}}
{"ts":1633755564254,"l":"debug","ctx":"OpenedByIO()","msg":"throwIfAvailable()","meta":{"from":"(library setup)","json":{"serviceName":"main","createdAt":1633755564228,"updatedAt":1633755564229,"hostname":"photostructure-server","systemUID":"mrm1-mcpt-udxh-vp1d","v":"2.0.0-alpha.1","pid":27}}}
{"ts":1633755564275,"l":"info","ctx":"SettingsIO.importFileSettings(/ps/library/.photostructure/settings.toml)","msg":"loaded","meta":{"imported":{"reportErrors":false}}}
{"ts":1633755564281,"l":"debug","ctx":"JsonFileStore","msg":"prior /ps/library/.photostructure/.library-uid.json","meta":{"uid":"kb61-c7d2-keh1-0qx6","version":"2.0.0-alpha.1","type":"library","createdAt":1633755543433}}
{"ts":1633755564281,"l":"debug","ctx":"JsonFileStore","msg":"prior /ps/config/.system-uid.json","meta":{"uid":"mrm1-mcpt-udxh-vp1d","version":"2.0.0-alpha.1","type":"system","createdAt":1633755543436}}
{"ts":1633755564283,"l":"debug","ctx":"BaseFile(/ps/tmp/sync-state-47qhwx6ntd/README.txt)","msg":"applyIfEmpty(): non-empty"}
{"ts":1633755564285,"l":"info","ctx":"StatsDbDir","msg":"Set up statsDbDir dir /ps/tmp/sync-state-47qhwx6ntd"}
{"ts":1633755564288,"l":"debug","ctx":"Library(/ps/library)","msg":"isOnRemoteVolume()","meta":{"result":false}}
{"ts":1633755564290,"l":"info","ctx":"ModelDbJanitor(/ps/library/.photostructure)","msg":"Library on remote drive. Using local db replica.","meta":{"src":"/ps/library/.photostructure/models/db.sqlite3","local":{"nativePath":"/ps/tmp/local-db/models/db.sqlite3"}}}
{"ts":1633755564292,"l":"info","ctx":"Db(models)","msg":"setting up new db connection to /ps/tmp/local-db/models/db.sqlite3","meta":{"priorWasNull":true}}
{"ts":1633755564294,"l":"info","ctx":"mkdb()","msg":"Dynamically setting dbCacheSize to 192","meta":{"db":"/ps/tmp/local-db/models/db.sqlite3","dbFileSize":0}}
{"ts":1633755565298,"l":"info","ctx":"SQLite","msg":"verifyDb(/ps/tmp/local-db/models/db.sqlite3): OK"}
{"ts":1633755565303,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"renice","args":["9","-p","68"]}}
{"ts":1633755565304,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"renice","args":["9","-p","68"],"maxAgeMs":10000}}
{"ts":1633755565309,"l":"debug","ctx":"rpc.Server","msg":"onRequest()","meta":"{\"id\":\"3KMWXTraD-6\",\"method\":\"paused\"}"}
{"ts":1633755565309,"l":"debug","ctx":"rpc.Server","msg":"handle()","meta":{"elapsedMs":0,"method":"paused","conn":"sync:68","id":"3KMWXTraD-6","result":false}}
{"ts":1633755565310,"l":"info","ctx":"Renice","msg":"Renice pid 68 to BelowNormal"}
{"ts":1633755565312,"l":"debug","ctx":"FsLock(/ps/tmp/local-db/models/db.sqlite3)#2DttzCQna-1","msg":"Touched lockfile"}
{"ts":1633755565314,"l":"debug","ctx":"FsLock(/ps/tmp/local-db/models/db.sqlite3)#2DttzCQna-1","msg":"tryAcquire()","meta":{"lockfiles":["2DttzCQna-1"]}}
{"ts":1633755565314,"l":"info","ctx":"FsLock(/ps/tmp/local-db/models/db.sqlite3)#2DttzCQna-1","msg":"Acquired"}
{"ts":1633755565314,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20181030_models","migrationDate":"2018-10-30T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565314,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20190417_rotation","migrationDate":"2019-04-17T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565314,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20190425_merged_assets","migrationDate":"2019-04-25T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20190426_clean_sha","migrationDate":"2019-04-26T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20190426_lowercase_psnet_hostname","migrationDate":"2019-04-26T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20190727_find_by_ca_and_geo","migrationDate":"2019-07-27T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20190730_session","migrationDate":"2019-07-30T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20190922_numeric_captured_at","migrationDate":"2019-09-22T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20190923_asset_file_v2_nofk","migrationDate":"2019-09-23T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20191013_asset_v2_nofk","migrationDate":"2019-10-13T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20200104_video_duration","migrationDate":"2020-01-04T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20200116_heartbeat","migrationDate":"2020-01-16T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20200127_spread_modes","migrationDate":"2020-01-27T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20200128_asset_file_v3_nofk","migrationDate":"2020-01-28T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20200130_advisory_lock","migrationDate":"2020-01-30T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20200211_updateCount","migrationDate":"2020-02-11T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20200512_asset_file_v4_nofk","migrationDate":"2020-05-12T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565315,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20200515_drop_merged_asset","migrationDate":"2020-05-15T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20200816_normalize_asset_file_uris","migrationDate":"2020-08-16T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20200823_add_asset_excluded","migrationDate":"2020-08-23T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20200826_dedupe_tag_paths","migrationDate":"2020-08-26T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20200827_tag_v2_nofk","migrationDate":"2020-08-27T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20200923_suffix_tag_paths","migrationDate":"2020-09-23T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20200927_progress_v2","migrationDate":"2020-09-27T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20201006_progress_meta","migrationDate":"2020-10-06T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20201007_operation","migrationDate":"2020-10-07T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20201023_dedupe_tag_paths","migrationDate":"2020-10-23T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20201026_normalize_asset_file_uris","migrationDate":"2020-10-26T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20201030_add_tag_counts","migrationDate":"2020-10-30T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20201106_normalize_tag_paths","migrationDate":"2020-11-06T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20201112_tag_display_name","migrationDate":"2020-11-12T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20201113_drop_tc_tables","migrationDate":"2020-11-13T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20201211_tag_description","migrationDate":"2020-12-11T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20210322_sha_blocklist","migrationDate":"2021-03-22T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20210323_create_tag_fts","migrationDate":"2021-03-23T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20210324_asset_fave_delete","migrationDate":"2021-03-24T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565316,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20210531_asset_duration","migrationDate":"2021-05-31T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565317,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20210604_changed_tag","migrationDate":"2021-06-04T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565317,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20210627_changed_tag_updated_at","migrationDate":"2021-06-27T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565317,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20210827_asset_excluded_at","migrationDate":"2021-08-27T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565317,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20210930_asset_file_rating","migrationDate":"2021-09-30T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565317,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"migration filter","meta":{"migrationName":"20210930_asset_revision","migrationDate":"2021-09-30T00:00:00.000Z","gitDate":"2021-10-05T17:52:19.000Z"}}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20181030_models.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20190417_rotation.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20190425_merged_assets.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20190426_clean_sha.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20190426_lowercase_psnet_hostname.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20190727_find_by_ca_and_geo.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20190730_session.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20190922_numeric_captured_at.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20190923_asset_file_v2_nofk.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20191013_asset_v2_nofk.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20200104_video_duration.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20200116_heartbeat.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20200127_spread_modes.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20200128_asset_file_v3_nofk.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20200130_advisory_lock.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20200211_updateCount.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20200512_asset_file_v4_nofk.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20200515_drop_merged_asset.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20200816_normalize_asset_file_uris.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20200823_add_asset_excluded.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20200826_dedupe_tag_paths.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20200827_tag_v2_nofk.sql"}
{"ts":1633755565325,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20200923_suffix_tag_paths.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20200927_progress_v2.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20201006_progress_meta.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20201007_operation.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20201023_dedupe_tag_paths.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20201026_normalize_asset_file_uris.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20201030_add_tag_counts.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20201106_normalize_tag_paths.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20201112_tag_display_name.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20201113_drop_tc_tables.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20201211_tag_description.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20210322_sha_blocklist.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20210323_create_tag_fts.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20210324_asset_fave_delete.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20210531_asset_duration.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20210604_changed_tag.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20210627_changed_tag_updated_at.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20210827_asset_excluded_at.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20210930_asset_file_rating.sql"}
{"ts":1633755565326,"l":"debug","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"latest(): already applied 20210930_asset_revision.sql"}
{"ts":1633755565326,"l":"info","ctx":"Migration({\"schema\":\"models\",\"db\":\"/ps/tmp/local-db/models/db.sqlite3\"})","msg":"up to latest!","meta":{"appliedMigrations":[]}}
{"ts":1633755565326,"l":"debug","ctx":"FsLock(/ps/tmp/local-db/models/db.sqlite3)#2DttzCQna-1","msg":"release()"}
{"ts":1633755565328,"l":"info","ctx":"ModelDbJanitor(/ps/library/.photostructure)","msg":"Finished setup","meta":{"primaryDbDir":{"nativePath":"/ps/tmp/local-db"},"replaceDbDir":{"nativePath":"/ps/library/.photostructure/models"},"backupDir":{"nativePath":"/ps/library/.photostructure/models/backup"}}}
{"ts":1633755565328,"l":"info","ctx":"ModelDbJanitor(/ps/library/.photostructure)","msg":"ModelDb reading from /ps/tmp/local-db/models/db.sqlite3"}
{"ts":1633755565328,"l":"info","ctx":"Library(/ps/library)","msg":"Library.setup() finished."}
{"ts":1633755565426,"l":"debug","ctx":"rpc.Server","msg":"onRequest()","meta":"{\"id\":\"3KMWXTraD-7\",\"method\":\"volumes\"}"}
{"ts":1633755565427,"l":"debug","ctx":"rpc.Server","msg":"handle()","meta":{"elapsedMs":0,"method":"volumes","conn":"sync:68","id":"3KMWXTraD-7","result":[{"filesystem":"none","mountpoint":"/","size":1962626523136,"used":1384010137600,"available":578494750720,"ignorable":false,"remote":false}]}}
{"ts":1633755570151,"l":"debug","ctx":"Pids","msg":"addPid() wrote /ps/config/pids/68.json","meta":{"pid":68,"cmd":"node","maxAgeMs":-1,"ppid":27,"startTime":1633755563148}}
{"ts":1633755591127,"l":"debug","ctx":"\u001b[35mEndable\u001b[39m","msg":"vacuumEndables()","meta":[["first",["tagsCache stats","rawTagsCache stats","Idle","PosixFileCache stats","readdirCache stats","BaseFileCache stats","Server:1807","ChildService(web)","shutdown notice","logDirCleanup","MainService.setVolumesTTL()","ChildService(sync)"]],["logger",["LogWriter(/ps/logs)"]],["postdb",["stats logger","OpenedByIO()"]],["service",["web","sync"]],["predb",["ProcCleaner","Library(/ps/library)"]],["db",["ModelDbJanitor(/ps/library/.photostructure)","Db(models)"]]]}
{"ts":1633755591196,"l":"debug","ctx":"rpc.Server","msg":"onRequest()","meta":"{\"id\":\"rbKfJqbHp-6\",\"method\":\"volumes\"}"}
{"ts":1633755591196,"l":"debug","ctx":"rpc.Server","msg":"handle()","meta":{"elapsedMs":0,"method":"volumes","conn":"web:40","id":"rbKfJqbHp-6","result":[{"filesystem":"none","mountpoint":"/","size":1962626523136,"used":1384010137600,"available":578494750720,"ignorable":false,"remote":false}]}}
{"ts":1633755592130,"l":"debug","ctx":"ChildService(web)","msg":"healthCheck(): running..."}
{"ts":1633755592144,"l":"debug","ctx":"fs.logDirCleanup","msg":"Pruned 0 files and 0 directories."}
{"ts":1633755592146,"l":"debug","ctx":"httping","msg":"ping","meta":{"latencyMs":16,"statusCode":200}}
{"ts":1633755592151,"l":"debug","ctx":"ChildService(web)","msg":"healthCheck: all is well","meta":{"ok":["Library and support directories are OK","Memory by web (48 MB) is OK"],"warn":[],"bad":[],"fail":[],"ts":1633755592150}}
{"ts":1633755603373,"l":"info","ctx":"Service(main)","msg":"exit()","meta":{"status":0,"reason":"SIGTERM","waitForJobs":false,"ending":false}}
{"ts":1633755603373,"l":"info","ctx":"\u001b[35mEndable\u001b[39m","msg":"endEndables()","meta":{"isTest":false,"isSingleSpecTests":false}}
{"ts":1633755603373,"l":"debug","ctx":"\u001b[35mEndable\u001b[39m","msg":"vacuumEndables()","meta":[["first",["tagsCache stats","rawTagsCache stats","Idle","PosixFileCache stats","readdirCache stats","BaseFileCache stats","ChildService(web)","shutdown notice","logDirCleanup","MainService.setVolumesTTL()","ChildService(sync)"]],["logger",["LogWriter(/ps/logs)"]],["postdb",["stats logger","OpenedByIO()"]],["service",["web","sync"]],["predb",["ProcCleaner","Library(/ps/library)"]],["db",["ModelDbJanitor(/ps/library/.photostructure)","Db(models)"]]]}
{"ts":1633755603373,"l":"debug","ctx":"\u001b[35mEndable\u001b[39m","msg":"endEndables(): ending first"}
{"ts":1633755603374,"l":"info","ctx":"PosixFileCache","msg":"stats","meta":{"size":32,"cacheHitsSync":49,"cacheMisses":32}}
{"ts":1633755603375,"l":"info","ctx":"readdirCache","msg":"stats","meta":{"size":3,"cacheHitsSync":1,"cacheMisses":5}}
{"ts":1633755603375,"l":"info","ctx":"BaseFileCache","msg":"stats","meta":{"size":56,"cacheHitsSync":5,"cacheMisses":56}}
{"ts":1633755603376,"l":"info","ctx":"WatchedChild(web:40)","msg":"_stop()","meta":{"stopped":false,"ended":true}}
{"ts":1633755603376,"l":"info","ctx":"WatchedChild(sync:68)","msg":"_stop()","meta":{"stopped":false,"ended":true}}
{"ts":1633755603377,"l":"warn","ctx":"ChildProcess","msg":"endProcess(40)","meta":{"killed":false,"connected":false}}
{"ts":1633755603377,"l":"warn","ctx":"ChildProcess","msg":"endProcess(68)","meta":{"killed":false,"connected":false}}
{"ts":1633755603377,"l":"debug","ctx":"ChildProcess","msg":"endProcess(40)","meta":{"killResult":true,"childGotSigterm":true}}
{"ts":1633755603377,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"]}}
{"ts":1633755603378,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755603389,"l":"debug","ctx":"ChildProcess","msg":"endProcess(68)","meta":{"killResult":true,"childGotSigterm":true}}
{"ts":1633755603389,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","68,27","-wwwo","pid,lstart,command"]}}
{"ts":1633755603389,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","68,27","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755603400,"l":"info","ctx":"rpc.Server","msg":"Closing connection from IPv4:127.0.0.1:51536"}
{"ts":1633755603400,"l":"info","ctx":"rpc.Server","msg":"Closing connection from IPv4:127.0.0.1:51518"}
{"ts":1633755603401,"l":"info","ctx":"Service(main)","msg":"exit()","meta":{"status":0,"reason":"SIGTERM","waitForJobs":false,"ending":true}}
{"ts":1633755603402,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[40],"result":[{"pid":40,"start":"2021-10-09T04:58:52.000Z","cmd":"photostructure web"}]}}
{"ts":1633755603406,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[68],"result":[{"pid":68,"start":"2021-10-09T04:59:23.000Z","cmd":"photostructure sync"}]}}
{"ts":1633755603526,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","68,27","-wwwo","pid,lstart,command"]}}
{"ts":1633755603526,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","68,27","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755603534,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"]}}
{"ts":1633755603534,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755603545,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[68],"result":[{"pid":68,"start":"2021-10-09T04:59:23.000Z","cmd":"photostructure sync"}]}}
{"ts":1633755603546,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[40],"result":[{"pid":40,"start":"2021-10-09T04:58:52.000Z","cmd":"photostructure web"}]}}
{"ts":1633755603598,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"]}}
{"ts":1633755603598,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755603604,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[40],"result":[{"pid":40,"start":"2021-10-09T04:58:52.000Z","cmd":"photostructure web"}]}}
{"ts":1633755603623,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","68,27","-wwwo","pid,lstart,command"]}}
{"ts":1633755603623,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","68,27","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755603630,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[68],"result":[{"pid":68,"start":"2021-10-09T04:59:23.000Z","cmd":"photostructure sync"}]}}
{"ts":1633755603642,"l":"info","ctx":"WatchedChild(sync:68)","msg":"onExit","meta":{"code":0,"stopped":false,"ended":true}}
{"ts":1633755603642,"l":"info","ctx":"WatchedChild(sync:68)","msg":"_restart()","meta":{"stopped":false,"ended":true}}
{"ts":1633755603642,"l":"info","ctx":"WatchedChild(sync:68)","msg":"_stop()","meta":{"stopped":false,"ended":true}}
{"ts":1633755603643,"l":"info","ctx":"WatchedChild(sync:68)","msg":"onExit(): finished setting up new child undefined"}
{"ts":1633755603681,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"]}}
{"ts":1633755603681,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755603687,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[40],"result":[{"pid":40,"start":"2021-10-09T04:58:52.000Z","cmd":"photostructure web"}]}}
{"ts":1633755603719,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","68,27","-wwwo","pid,lstart,command"]}}
{"ts":1633755603720,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","68,27","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755603726,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[68],"result":[]}}
{"ts":1633755603726,"l":"debug","ctx":"ChildProcess","msg":"endProcess(): exitted","meta":{"pid":68,"killed":true,"connected":false,"exitCode":0}}
{"ts":1633755603790,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"]}}
{"ts":1633755603790,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755603796,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[40],"result":[{"pid":40,"start":"2021-10-09T04:58:52.000Z","cmd":"photostructure web"}]}}
{"ts":1633755603923,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"]}}
{"ts":1633755603924,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755603930,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[40],"result":[{"pid":40,"start":"2021-10-09T04:58:52.000Z","cmd":"photostructure web"}]}}
{"ts":1633755604083,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"]}}
{"ts":1633755604083,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755604091,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[40],"result":[{"pid":40,"start":"2021-10-09T04:58:52.000Z","cmd":"photostructure web"}]}}
{"ts":1633755604267,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"]}}
{"ts":1633755604267,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755604276,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[40],"result":[{"pid":40,"start":"2021-10-09T04:58:52.000Z","cmd":"[photostructure ] <defunct>"}]}}
{"ts":1633755604276,"l":"info","ctx":"WatchedChild(web:40)","msg":"onExit","meta":{"code":0,"stopped":false,"ended":true}}
{"ts":1633755604276,"l":"info","ctx":"WatchedChild(web:40)","msg":"_restart()","meta":{"stopped":false,"ended":true}}
{"ts":1633755604276,"l":"info","ctx":"WatchedChild(web:40)","msg":"_stop()","meta":{"stopped":false,"ended":true}}
{"ts":1633755604277,"l":"info","ctx":"WatchedChild(web:40)","msg":"onExit(): finished setting up new child undefined"}
{"ts":1633755604477,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"]}}
{"ts":1633755604477,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","40,27","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755604483,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[40],"result":[]}}
{"ts":1633755604484,"l":"debug","ctx":"ChildProcess","msg":"endProcess(): exitted","meta":{"pid":40,"killed":true,"connected":false,"exitCode":0}}
{"ts":1633755604484,"l":"debug","ctx":"\u001b[35mEndable\u001b[39m","msg":"endEndables(): ending service"}
{"ts":1633755604484,"l":"debug","ctx":"\u001b[35mEndable\u001b[39m","msg":"endEndables(): ending predb"}
{"ts":1633755604486,"l":"info","ctx":"OpenedByIO()","msg":"debug","meta":"onEnd(): unlinking /ps/library/.photostructure/opened-by/13nbuj7-27.json"}
{"ts":1633755604488,"l":"info","ctx":"Library(/ps/library)","msg":"onEnd(): finished."}
{"ts":1633755604489,"l":"debug","ctx":"ChildProcess","msg":"stdoutResult(): execFile","meta":{"cmd":"ps","args":["-p","40,68,27","-wwwo","pid,lstart,command"]}}
{"ts":1633755604490,"l":"debug","ctx":"ChildProcess","msg":"execFile()","meta":{"command":"ps","args":["-p","40,68,27","-wwwo","pid,lstart,command"],"maxAgeMs":15000}}
{"ts":1633755604496,"l":"debug","ctx":"Ps","msg":"pidInfo()","meta":{"pids":[40,68],"result":[]}}
{"ts":1633755604497,"l":"info","ctx":"Pids","msg":"killOldProcs(): pid no longer present: unlinking 40.json","meta":{"json":{"pid":40,"cmd":"node","maxAgeMs":-1,"ppid":27,"startTime":1633755532140}}}
{"ts":1633755604499,"l":"info","ctx":"Pids","msg":"killOldProcs(): pid no longer present: unlinking 68.json","meta":{"json":{"pid":68,"cmd":"node","maxAgeMs":-1,"ppid":27,"startTime":1633755563148}}}
{"ts":1633755604501,"l":"debug","ctx":"\u001b[35mEndable\u001b[39m","msg":"endEndables(): ending db"}
{"ts":1633755604501,"l":"info","ctx":"Db(models)","msg":"closing db","meta":{"name":"/ps/tmp/local-db/models/db.sqlite3","open":true,"inTransaction":false,"readonly":false,"memory":false}}
{"ts":1633755604598,"l":"debug","ctx":"\u001b[35mEndable\u001b[39m","msg":"endEndables(): ending postdb"}
{"ts":1633755604599,"l":"info","ctx":"Service(main)","msg":"timings:\n","meta":{"Service.startup()":{"sumSec":0.521,"mean":520,"k":1},"rpc.volumes":{"sumSec":0.061,"mean":61,"k":1},"vol.volumes":{"sumSec":0.06,"mean":60,"k":1},"vol.dfPosix":{"sumSec":0.03,"mean":30,"k":1},"vol.localVolumeInfoPosix":{"sumSec":0.02,"mean":20,"k":1}}}
{"ts":1633755604599,"l":"warn","ctx":"Service(main)","msg":"error counts:\n","meta":{"fs.readFile":1}}
{"ts":1633755604600,"l":"info","ctx":"Service(main)","msg":"memory use on exit","meta":{"ok":["Memory by main (33 MB) is OK"],"warn":[],"bad":[],"fail":[]}}
{"ts":1633755604601,"l":"debug","ctx":"\u001b[35mEndable\u001b[39m","msg":"endEndables(): ending logger"}