brechtm / thriftybackup

Cloud backup for the bandwidth-conscious
https://forum.rclone.org/t/thriftybackup-simple-incremental-cloud-backup-app-for-macos/40820/1
MIT License
8 stars 0 forks source link

AssertionError #1

Closed shenzo1 closed 9 months ago

shenzo1 commented 9 months ago

Thanks for this great project!

I am on Ventura 13.2 and I have an AssertionError when trying to use app.py

Traceback (most recent call last):
  File "/Users/shenzo/thriftybackup/app.py", line 412, in <module>
    app(echo=args.echo, progress=args.progress, dry_run=args.dry_run)
  File "/Users/shenzo/thriftybackup/app.py", line 399, in app
    app = MenuBarApp(echo, progress, dry_run)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/shenzo/thriftybackup/app.py", line 117, in __init__
    self.idle()
  File "/Users/shenzo/thriftybackup/app.py", line 151, in idle
    for snapshot, size, sync_json in backup.last_backups():
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 171, in last_backups
    assert snapshots.pop() == 'latest'
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError

I have setup the config.toml in this way:

## General settings
## (uncomment and adjust)

rclone = "/usr/local/bin/rclone"
bwlimit = "1000K"

## Backup configurations

[test]
##passes ~/.config/thriftybackup/test.exclude as exclude file to rclone
source = "/Users/me/Downloads"
##'test' below is the name of a remote configured for rclone
destination = "remote:backups"
#interval = "4 hours"
#threshold = "100 MB"

Appreciate your help!

brechtm commented 9 months ago

Hi @shenzo1. Thanks for test-driving ThriftyBackup 😃

ThriftyBackup assumes it's the only one writing to the destination directory. I assume you already have directories under remote:backups? Please create a new directory remote:backups/Downloads and adjust the configuration file to point to it.

This situation should of course be handled in a better way, so please do not close this ticket yet.

brechtm commented 9 months ago

BTW I just pushed some changes that fix some issues with first-time backups.

shenzo1 commented 9 months ago

Hey @brechtm, appreciate the pointer here. I have tried creating the directory on the remote side so source = "/Users/me/Downloads" and remote = "remote:backups/Downloads". Still an error:

Exception in thread Thread-3 (_main_loop):
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/threading.py", line 982, in run
    self._target(*self._args, **self._kwargs)
  File "/Users/shenzo/thriftybackup/app.py", line 70, in _main_loop
    backup.backup(self._proxy, force=True)
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 194, in backup
    device, snapshot = self.get_last_snapshot()
                       ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 151, in get_last_snapshot
    snapshot = plistlib.loads(output)['Snapshots'][-1]['SnapshotName']
               ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^
IndexError: list index out of range

I am wondering if my setup is correct? — Updated to the latest changes with git pull — In Time Machine settings, I have set backups to a small SD card that is not inserted. — I have git clone the repository and launching app.py with python 3.11.7

brechtm commented 9 months ago

No, I think this a bug I haven't encountered because of differences between your system and mine.

Can you paste the output of df -h /Users? ThriftyBackup assumes Mounted on equals/System/Volumes/Data. If so, please post the output for diskutil info -plist /System/Volumes/Data?

shenzo1 commented 9 months ago

Here it is:

df -h /Users
Filesystem     Size   Used  Avail Capacity iused     ifree %iused  Mounted on
/dev/disk3s5  926Gi  851Gi   41Gi    96% 5134138 432788520    1%   /System/Volumes/Data
diskutil info -plist /System/Volumes/Data
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
    <key>AESHardware</key>
    <true/>
    <key>APFSContainerFree</key>
    <integer>44314529792</integer>
    <key>APFSContainerReference</key>
    <string>disk3</string>
    <key>APFSContainerSize</key>
    <integer>994662584320</integer>
    <key>APFSPhysicalStores</key>
    <array>
        <dict>
            <key>APFSPhysicalStore</key>
            <string>disk0s2</string>
        </dict>
    </array>
    <key>APFSSnapshot</key>
    <false/>
    <key>APFSVolumeGroupID</key>
    <string>EA097131-A286-41EF-B2DD-A1D98090605B</string>
    <key>Bootable</key>
    <true/>
    <key>BooterDeviceIdentifier</key>
    <string>disk3s2</string>
    <key>BusProtocol</key>
    <string>Apple Fabric</string>
    <key>CanBeMadeBootable</key>
    <false/>
    <key>CanBeMadeBootableRequiresDestroy</key>
    <false/>
    <key>CapacityInUse</key>
    <integer>913523015680</integer>
    <key>Content</key>
    <string>41504653-0000-11AA-AA11-00306543ECAC</string>
    <key>DeviceBlockSize</key>
    <integer>4096</integer>
    <key>DeviceIdentifier</key>
    <string>disk3s5</string>
    <key>DeviceNode</key>
    <string>/dev/disk3s5</string>
    <key>DeviceTreePath</key>
    <string>IODeviceTree:/arm-io/ans@8F400000/iop-ans-nub/AppleANS3NVMeController</string>
    <key>DiskUUID</key>
    <string>EA097131-A286-41EF-B2DD-A1D98090605B</string>
    <key>Ejectable</key>
    <false/>
    <key>EjectableMediaAutomaticUnderSoftwareControl</key>
    <false/>
    <key>EjectableOnly</key>
    <false/>
    <key>Encryption</key>
    <true/>
    <key>EncryptionThisVolumeProper</key>
    <true/>
    <key>FileVault</key>
    <false/>
    <key>FilesystemName</key>
    <string>APFS</string>
    <key>FilesystemType</key>
    <string>apfs</string>
    <key>FilesystemUserVisibleName</key>
    <string>APFS</string>
    <key>FreeSpace</key>
    <integer>0</integer>
    <key>Fusion</key>
    <false/>
    <key>GlobalPermissionsEnabled</key>
    <true/>
    <key>IOKitSize</key>
    <integer>994662584320</integer>
    <key>IORegistryEntryName</key>
    <string>Data</string>
    <key>Internal</key>
    <true/>
    <key>Locked</key>
    <false/>
    <key>MediaName</key>
    <string></string>
    <key>MediaType</key>
    <string>Generic</string>
    <key>MountPoint</key>
    <string>/System/Volumes/Data</string>
    <key>OSInternalMedia</key>
    <false/>
    <key>ParentWholeDisk</key>
    <string>disk3</string>
    <key>PartitionMapPartition</key>
    <false/>
    <key>RAIDMaster</key>
    <false/>
    <key>RAIDSlice</key>
    <false/>
    <key>RecoveryDeviceIdentifier</key>
    <string>disk3s3</string>
    <key>Removable</key>
    <false/>
    <key>RemovableMedia</key>
    <false/>
    <key>RemovableMediaOrExternalDevice</key>
    <false/>
    <key>SMARTDeviceSpecificKeysMayVaryNotGuaranteed</key>
    <dict>
        <key>AVAILABLE_SPARE</key>
        <integer>100</integer>
        <key>AVAILABLE_SPARE_THRESHOLD</key>
        <integer>99</integer>
        <key>CONTROLLER_BUSY_TIME_0</key>
        <integer>0</integer>
        <key>CONTROLLER_BUSY_TIME_1</key>
        <integer>0</integer>
        <key>DATA_UNITS_READ_0</key>
        <integer>368646716</integer>
        <key>DATA_UNITS_READ_1</key>
        <integer>0</integer>
        <key>DATA_UNITS_WRITTEN_0</key>
        <integer>135673074</integer>
        <key>DATA_UNITS_WRITTEN_1</key>
        <integer>0</integer>
        <key>HOST_READ_COMMANDS_0</key>
        <integer>12832764869</integer>
        <key>HOST_READ_COMMANDS_1</key>
        <integer>0</integer>
        <key>HOST_WRITE_COMMANDS_0</key>
        <integer>2379029687</integer>
        <key>HOST_WRITE_COMMANDS_1</key>
        <integer>0</integer>
        <key>MEDIA_ERRORS_0</key>
        <integer>0</integer>
        <key>MEDIA_ERRORS_1</key>
        <integer>0</integer>
        <key>NUM_ERROR_INFO_LOG_ENTRIES_0</key>
        <integer>0</integer>
        <key>NUM_ERROR_INFO_LOG_ENTRIES_1</key>
        <integer>0</integer>
        <key>PERCENTAGE_USED</key>
        <integer>3</integer>
        <key>POWER_CYCLES_0</key>
        <integer>212</integer>
        <key>POWER_CYCLES_1</key>
        <integer>0</integer>
        <key>POWER_ON_HOURS_0</key>
        <integer>3018</integer>
        <key>POWER_ON_HOURS_1</key>
        <integer>0</integer>
        <key>TEMPERATURE</key>
        <integer>307</integer>
        <key>UNSAFE_SHUTDOWNS_0</key>
        <integer>35</integer>
        <key>UNSAFE_SHUTDOWNS_1</key>
        <integer>0</integer>
    </dict>
    <key>SMARTStatus</key>
    <string>Verified</string>
    <key>Sealed</key>
    <string>No</string>
    <key>Size</key>
    <integer>994662584320</integer>
    <key>SolidState</key>
    <true/>
    <key>SupportsGlobalPermissionsDisable</key>
    <true/>
    <key>SystemImage</key>
    <false/>
    <key>TotalSize</key>
    <integer>994662584320</integer>
    <key>VolumeAllocationBlockSize</key>
    <integer>4096</integer>
    <key>VolumeName</key>
    <string>Data</string>
    <key>VolumeSize</key>
    <integer>0</integer>
    <key>VolumeUUID</key>
    <string>EA097131-A286-41EF-B2DD-A1D98090605B</string>
    <key>WholeDisk</key>
    <false/>
    <key>Writable</key>
    <true/>
    <key>WritableMedia</key>
    <true/>
    <key>WritableVolume</key>
    <true/>
</dict>
</plist>
brechtm commented 9 months ago

Thanks. That's all good so far. I suspect ThriftyBackup currently may expect there to be a first backup made by Time Machine.

If you provide me the output of this, I can handle that case:

/usr/sbin/diskutil apfs listSnapshots -plist disk3s5
shenzo1 commented 9 months ago

Yes that's correct. I don't have a first backup yet.

/usr/sbin/diskutil apfs listSnapshots -plist disk3s5
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
    <key>Snapshots</key>
    <array/>
</dict>
</plist>
brechtm commented 9 months ago

@shenzo1 Please try again with the current main branch.

shenzo1 commented 9 months ago

Thanks. I know have a different error

python3 app.py
Exception in thread Thread-3 (_main_loop):
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/threading.py", line 982, in run
    self._target(*self._args, **self._kwargs)
  File "/Users/shenzo/thriftybackup/app.py", line 70, in _main_loop
    backup.backup(self._proxy, force=True)
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 200, in backup
    device, snapshot = self.get_last_snapshot()
                       ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 146, in get_last_snapshot
    du_info = self._run([DISKUTIL, 'info', '-plist', self.source_volume],
                                                     ^^^^^^^^^^^^^^^^^^
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/functools.py", line 1001, in __get__
    val = self.func(instance)
          ^^^^^^^^^^^^^^^^^^^
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 132, in source_volume
    df = self._run([DF, '--libxo', 'json', self.source], echo=self.echo,
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 65, in _run
    return run(args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/subprocess.py", line 571, in run
    raise CalledProcessError(retcode, process.args,
subprocess.CalledProcessError: Command '['/bin/df', '--libxo', 'json', PosixPath('/Users/shenzo')]' returned non-zero exit status 64.
brechtm commented 9 months ago

I can't find any information on what df's exit code of 64 would mean. Maybe it's due to a security setting in MacOS, but that should pop up notification. Does /bin/df --libxo json /Users/shenzo output something?

Note that you can pass --echo app.py to see which commands are being executed.

shenzo1 commented 9 months ago
/bin/df --libxo json /Users/shenzo
/bin/df: illegal option -- -

I tried --echo but get this:

python3 --echo app.py
unknown option --echo
brechtm commented 9 months ago

I just added the --libxo argument a couple of days ago. Perhaps it's not supported by macOS Ventura's df? I'm on Sonoma 14.2.1 myself...

Please paste the output of df --help.

python3 --echo app.py unknown option --echo

--echo needs to come after app.py (it's an argument to app.py, not to python).

shenzo1 commented 9 months ago

Ah yes, of course.

python3 app.py --echo
/usr/local/bin/rclone lsf --use-json-log pMD_plex:backups/shenzo --dir-slash=false --dirs-only
/bin/df --libxo json /Users/shenzo
Exception in thread Thread-3 (_main_loop):
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/threading.py", line 982, in run
    self._target(*self._args, **self._kwargs)
  File "/Users/shenzo/thriftybackup/app.py", line 70, in _main_loop
    backup.backup(self._proxy, force=True)
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 200, in backup
    device, snapshot = self.get_last_snapshot()
                       ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 146, in get_last_snapshot
    du_info = self._run([DISKUTIL, 'info', '-plist', self.source_volume],
                                                     ^^^^^^^^^^^^^^^^^^
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/functools.py", line 1001, in __get__
    val = self.func(instance)
          ^^^^^^^^^^^^^^^^^^^
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 132, in source_volume
    df = self._run([DF, '--libxo', 'json', self.source], echo=self.echo,
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 65, in _run
    return run(args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/subprocess.py", line 571, in run
    raise CalledProcessError(retcode, process.args,
subprocess.CalledProcessError: Command '['/bin/df', '--libxo', 'json', PosixPath('/Users/shenzo')]' returned non-zero exit status 64.
/bin/df --help
/bin/df: illegal option -- -
usage: df [-b | -H | -h | -k | -m | -g | -P] [-ailn] [-T type] [-t] [filesystem ...]
brechtm commented 9 months ago

Indeed, --libxo is missing! I have pushed a new commit that should fix this.

And then hopefully you can finally do a first backup. 🤞 I recommend you first test with a backup source of a relatively small size... You might want to pass --progress in addition to --echo in order to see rclone's progress on the command line.

shenzo1 commented 9 months ago

It seems now to go to the next stage! But the AFPS volume can't be mounted. Really appreciate your time on that, Brecht!

python3 app.py --echo --progress
/usr/local/bin/rclone lsf --use-json-log remote:backups/shenzo/context --dir-slash=false --dirs-only
/bin/df /Users/shenzo/context
/usr/sbin/diskutil apfs listSnapshots -plist /dev/disk3s5
/usr/local/bin/rclone lsf --use-json-log remote:backups/shenzo/context --dir-slash=false --files-only --include /test_*_sync.log
Mounting com.apple.TimeMachine.2024-02-10-094233.local at /var/folders/9n/kpv_7r9116nccgczvmvmh93w0000gp/T/tmpjyz0rvpd
/sbin/mount_apfs -s com.apple.TimeMachine.2024-02-10-094233.local -o nobrowse /dev/disk3s5 /var/folders/9n/kpv_7r9116nccgczvmvmh93w0000gp/T/tmpjyz0rvpd
mount_apfs: volume could not be mounted: Operation not permitted
Exception in thread Thread-3 (_main_loop):
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/threading.py", line 982, in run
    self._target(*self._args, **self._kwargs)
  File "/Users/shenzo/thriftybackup/app.py", line 70, in _main_loop
    backup.backup(self._proxy, force=True)
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 211, in backup
    task = BackupTask(self, device, snapshot, last_log, app)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 239, in __init__
    self.mount_point = self.mount_snapshot(device, snapshot)
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 302, in mount_snapshot
    self._run([MOUNT_APFS, '-s', snapshot, '-o', 'nobrowse', device,
  File "/Users/shenzo/thriftybackup/thriftybackup/backup.py", line 65, in _run
    return run(args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/subprocess.py", line 571, in run
    raise CalledProcessError(retcode, process.args,
subprocess.CalledProcessError: Command '['/sbin/mount_apfs', '-s', 'com.apple.TimeMachine.2024-02-10-094233.local', '-o', 'nobrowse', '/dev/disk3s5', PosixPath('/var/folders/9n/kpv_7r9116nccgczvmvmh93w0000gp/T/tmpjyz0rvpd')]' returned non-zero exit status 77.
brechtm commented 9 months ago

I think you need to grant Terminal (or the terminal app you use) Full Disk Access in System Preferences (Privacy & Security) to solve this issue. If you later switch to using ThriftyBackup.app, you need to grant it this permission too.

Really appreciate your time on that, Brecht!

And thank you for your time and perseverance! This helps making this a smoother experience for others.

shenzo1 commented 9 months ago

I think you need to grant Terminal (or the terminal app you use) Full Disk Access in System Preferences (Privacy & Security) to solve this issue. If you later switch to using ThriftyBackup.app, you need to grant it this permission too.

It's working! Thanks for your help! Is the ThriftyBackup.app also updated to the latest version? I had downloaded the version you've posted on rclone's forum.

And thank you for your time and perseverance! This helps making this a smoother experience for others.

Thanks so much for making a much needed piece of software!

brechtm commented 9 months ago

I think you need to grant Terminal (or the terminal app you use) Full Disk Access in System Preferences (Privacy & Security) to solve this issue. If you later switch to using ThriftyBackup.app, you need to grant it this permission too.

It's working! Thanks for your help! Is the ThriftyBackup.app also updated to the latest version? I had downloaded the version you've posted on rclone's forum.

No, the app on GitHub hasn't been updated yet. You can build it yourself using python setup.py py2app and find it in the dist directory.

Please note that you're likely to encounter other issues still. Please create a new ticket when you do.