1.0.0-beta.2 error: "Failed to scan system volumes"

[Rodger]

Expected Behavior

I expect photostructure to run without crashing.

Current Behavior

Since I upgraded to 1.0.0-beta.2, photostructure will run for a short period of time (about 5 minutes or so, sometimes longer) and then it crashes. This error message comes up briefly but then goes away so it took me a while to capture the message: ChildService(web).onStdout(): ChildService(web).onStdout()Failed to scan system volumes.undefined 16

Steps to Reproduce

1. Open photostructure.
2. Wait a few minutes. (Sometimes 3 minutes, sometimes 25 minutes.)

Environment

Operating system and version: Windows 10 (10.0.19042) on x64

PhotoStructure edition: PhotoStructure for Desktops (beta channel) 1.0.0-beta.2

[mrm]

@Rodger

I expect photostructure to run without crashing.

This matches my expectations as well.

@Rodger

Failed to scan system volumes

Sorry this hit you: can you DM or email me the “volumes” table from your “About PhotoStructure” page?

FWIW, I’m going to change PhotoStructure to not shut down when it finds these sorts of errors in the future, and make logs accessible via the UI as well.

[mrm]

A bit more detail about this issue:

PhotoStructure uses a couple of PowerShell applets to fetch volume metadata, and these sometimes fail.

PhotoStructure does retry the commands on failure, but the Windows kernel doesn’t always seem to recover in time, at which point PhotoStructure throws a fatal error.

[Zirro]

This might not be Windows-specific, as I’m receiving the same error on macOS 10.15 (with 1.0.0-beta.2):

The error occurs after ~10 seconds just as the main window is being initialized, causing it to shut down before any interaction is possible. I’ve only completed the initial configuration of the application so far (it’s my first time trying out Photo Structure).

[mrm]

@Zirro

I’m receiving the same error on macOS 10.15 (with 1.0.0-beta.2)

Oof, sorry about the crappy first impression, and thanks for taking the time to report this!

Volume metadata collection is used to pause sync if the library or system volume gets too full, and is also used for stable file URIs, and it’s this volume metadata collection that’s failing for you two.

If you could collect debug logs and email them to support@photostructure.com that’ll help me figure out what’s going on:

https://photostructure.com/faq/error-reports/#how-to-manually-send-your-logs

[Zirro]

@mrm

Oof, sorry about the crappy first impression, and thanks for taking the time to report this!

No worries - I’m very excited about PhotoStructure for my use cases based on all I’ve read on your website. Other alternatives I found were either cloud-only or saddled with clunky non-flexible UIs

I had a look through the logs and believe there are two issues related to the command diskutil info -all which runs at one point. In the first case, it causes a (likely harmless) error to be emitted due to invalid code signatures of two disk-related kernel extensions I’m no longer using.

After I’ve removed those, the application is able to launch successfully but the ‘backend’ seems to timeout due to the 35s limit for child processes. I have quite a few USB drives (along with some network drives over SMB) attached to my computer and they’re often busy to the point of becoming unresponsive. Waiting for them appears to impact the diskutil info -all command particularly badly as I’m seeing completion times above 15 minutes for the entire output to print right now.

Perhaps there’s an alternative command (df?) you could use that provides the needed info faster?

(I opted not to send the logs for now since I saw a few private details/paths in there, but I can provide them later if they’re still needed.)

[mrm]

@Zirro

Waiting for them appears to impact the diskutil info -all command particularly badly as I’m seeing completion times above 15 minutes for the entire output to print right now.

Wow. Yup, this is the issue. I’ll think about how to work around this.

[mrm]

@zirro I’ll still try some workarounds for your 15-minute-long diskutil command, but until then, know that you can extend several critical timeout durations in v1.0.0-beta.2:

First startup error "Failed to scan system volumes.undefined"

v1.0.0-beta.2 added several new timeouts that may help you if you have several attached external drives, or lots of network mounted volumes, or if any of your volumes are especially slow to spin up from sleep. Open your system settings.toml and add the following lines: commandTimeoutMs=60000 mountpointsTtlMs=60000 volumeMetadataTtlMs=1200000 This will set your command and mountpoint timeouts to a minute, and volume metadata to be cached for 20 minutes. Here are descriptions for these setting…

[mrm]

I also just wrote this up:

Support for systems with many external drives

It seems that several beta users have a bunch (5+) external drives and remote filesystems mounted on their machines that run PhotoStructure. Currently, PhotoStructure (even v1.0.0-beta.2) collects all mounted volume metadata. This collection can take a while, which led to posts like this. I just had a user ask: why the heck does photostructure care about any of my other drives? and this is absolutely a fair question! Volume metadata extraction is expensive, so PhotoStructure actually only…

[Zirro]

Thanks! I’ve tried increasing these values in the settings, but doing so revealed a timeout in another module:

{"ts":1621151318886,"l":"warn","ctx":"Deferred(rpc.RequestResponse(volumes)#35NctjzJs-3)","msg":".reject()","meta":"TIMEOUT: rpc.RequestResponse(volumes)#35NctjzJs-3 after 30001ms"}
{"ts":1621151318897,"l":"warn","ctx":"Error","msg":"onError(): TIMEOUT: rpc.RequestResponse(volumes)#35NctjzJs-3 after 30001ms\nTIMEOUT: rpc.RequestResponse(volumes)#35NctjzJs-3 after 30001ms\n    at Object.t.asError (/Applications/PhotoStructure.app/Contents/Resources/app.asar/sync.js:9:563913)\n    at p.reject (/Applications/PhotoStructure.app/Contents/Resources/app.asar/sync.js:9:105243)\n    at Timeout.<anonymous> (/Applications/PhotoStructure.app/Contents/Resources/app.asar/sync.js:9:104507)\n    at listOnTimeout (internal/timers.js:554:17)\n    at processTimers (internal/timers.js:497:7)","meta":{"event":"nonFatal","message":"volumes() failed"}}
{"ts":1621151318898,"l":"warn","ctx":"Error","msg":"onError(): TIMEOUT: rpc.RequestResponse(volumes)#35NctjzJs-3 after 30001ms\nTIMEOUT: rpc.RequestResponse(volumes)#35NctjzJs-3 after 30001ms\n    at Object.t.asError (/Applications/PhotoStructure.app/Contents/Resources/app.asar/sync.js:9:563913)\n    at p.reject (/Applications/PhotoStructure.app/Contents/Resources/app.asar/sync.js:9:105243)\n    at Timeout.<anonymous> (/Applications/PhotoStructure.app/Contents/Resources/app.asar/sync.js:9:104507)\n    at listOnTimeout (internal/timers.js:554:17)\n    at processTimers (internal/timers.js:497:7)","meta":{"event":"nonFatal","message":"unhandledRejection"}}

[mrm]

@Zirro

onError(): TIMEOUT: rpc.RequestResponse(volumes)#35NctjzJs-3 after 30001ms\nTIMEOUT: rpc.RequestResponse(volumes)#35NctjzJs-3 after 30001ms\n    at Object.t.asError (/Applications/PhotoStructure.app/Contents/Resources/app.asar/sync.js:9:563913)\n    at p.reject (/Applications/PhotoStructure.app/Contents/Resources/app.asar/sync.js:9:105243)\n    at Timeout.<anonymous> (/Applications/PhotoStructure.app/Contents/Resources/app.asar/sync.js:9:104507)\n    at listOnTimeout (internal/timers.js:554:17)\n    at processTimers (internal/timers.js:497:7)","meta":{"event":"nonFatal","message":"volumes() failed"}}
{"ts":1621151318898,"l":"warn","ctx":"Error","msg":"onError(): TIMEOUT: rpc.RequestResponse(volumes)#35NctjzJs-3 after 30001ms\nTIMEOUT: rpc.RequestResponse(volumes)#35NctjzJs-3 after 30001ms\n    at Object.t.asError (/Applications/PhotoStructure.app/Contents/Resources/app.asar/sync.js:9:563913)\n    at p.reject (/Applications/PhotoStructure.app/Contents/Resources/app.asar/sync.js:9:105243)\n    at Timeout.<anonymous> (/Applications/PhotoStructure.app/Contents/Resources/app.asar/sync.js:9:104507)\n    at listOnTimeout (internal/timers.js:554:17)\n    at processTimers (internal/timers.js:497:7)","meta":{"event":"nonFatal","message":"unhandledRejection"}}

Thanks for reporting this, and sorry for the glitch! beta.3 will make that timeout defer to your overridden value.

Related:

from

Uncertain, lazy, forgetful, & impatient: It’s what you want your code to be.

[Rodger]

This “failed to scan system volumes” error has come back in beta.3. I confirmed my system settings.toml are still:

commandTimeoutMs=60000
mountpointsTtlMs=60000
volumeMetadataTtlMs=1200000

[mrm]

Thanks for sending me your logs. It’s taking 20+ seconds to run

Get-PSDrive -PSProvider FileSystem

I suspect one or more of your drives are spinning down, and it’s taking a while to spin all 9 of your platters back up to speed. It definitely adds some pressure for me to build out the more efficient volumes algorithm.

[stirlow]

I am having this error on v0.9.1. MacOS 11.4 Mac mini (M1, 2020).

I have 3 external drives connected however I know they’re spinning as I have just opened the drives in finder. Interestingly this bug occurred immediately after the welcome/setup dialog. It then prevents the app from starting correctly after that. Even clicking “preferences” seems to cause a crash or close of the app.

EDIT: One of these drives is used for Time Machine. I assume it might be this bug: Apple silicon support - #4 by mrm

[mrm]

@stirlow please try the beta build: I’ve fixed a bunch of issues with m1 and Big Sur.

[tommyB]

Hi, I was getting this error as well - I’ve added the following to my .bash_profile in Linux and this stops the error :

PHOTO STRUCTURE

export PS_COMMAND_TIMEOUT_MS=120000
export PS_MOUNTPOINTS_TTL_MS=120000
export PS_VOLUME_METADATA_TTL_MS=120000
export PS_SETUP_TIMEOUT_MS=120000

However it now doesn’t seem to be pulling in any additional directories I add after the initial populating with the contents of ~/Pictures ?

I’m on 1.0.0-beta.7-x86_64 AppImage on Elementary OS 5.1 (Linux)

Tom

[tommyB]

Update : reboot fixed the syncing - it looks like the shutdown is not always clean and on restart the sync may not be in a good state. Is there a recommended way to kill all parts (and restart) on Linux if it ends up hung in some way ?

[mrm]

@tommyB

Is there a recommended way to kill all parts (and restart) on Linux if it ends up hung in some way ?

First off: howdy, welcome to PhotoStructure!

Second: crap, sorry that the volume scanning glitched on you. The desktop build is really only supported on Ubuntu 20.04; I’ve never tried it on Elementary. If you can run it under docker, that might work better.

Third: all PhotoStructure processes register a sigint handler, so running something like killall -vw PhotoStructure will shut them down gracefully.

I haven’t had to (personally) do that (killall) for a year, though: I suspect something about Elementary is causing PhotoStructure’s gears to grind. If you launch the appimage from a terminal, and add --verbose to the end of the command, it’ll run with verbose info logging that may be enlightening.

[shrippen]

I’m also gettings this error on Beta9.

{“fatal”:true,“exit”:true,“status”:12,“pid”:26,“ppid”:19,“error”:“ChildService(sync).onStdout(): Error: ChildService(sync).onStdout()Failed to scan system volumes.¹⁶”}

I am running as a docker on Unraid.

[mrm]

@shrippen

I’m also gettings this error on Beta9.

Oof, apologies!

Can you shell into your docker container running PhotoStructure and email or dm me the output of

./photostructure info --debug --volumes

Thanks!