rclone verbose logs cannot be parsed by NPBackup

[GuitarBilly]

npbackup-cli
W10 enterprise 64bit
confirmed on v3.0.0-rc14 and v3.0.0-rc15
This backup to OneDrive worked fine on rc12 and rc13.

I have set "Environment variables" RCLONE_VERBOSE to 2 to print extra information.
I have set "Additional backup only parameters" to --dry-run -o rclone.args="serve restic --stdio --b2-hard-delete --user-agent ISV|rclone.org|rclone/v1.65.2" in an attempt to get the --user-agent passed onto rclone.

steps to reproduce and terminal log:

C:\Users\guitarbilly\Downloads\npbackup-cli>npbackup-cli.exe -c ..\NPBACKUP_COMMON\npbackup.conf --repo-name OneDrive_via_rclone --backup
2025-02-20 22:14:10,166 :: INFO :: npbackup 3.0.0-rc15-windows-cli-x64-public-3.13-c 2025021701 - Copyright (C) 2022-2025 NetInvent running as AD\guitarbilly
2025-02-20 22:14:10,213 :: INFO :: Loaded config AA29C37A in C:\Users\guitarbilly\Downloads\npbackup-cli\..\NPBACKUP_COMMON\npbackup.conf
2025-02-20 22:14:10,219 :: INFO :: No extra information for repos x300server_laptop found
2025-02-20 22:14:10,332 :: INFO :: Searching for a backup newer than 1 day, 0:00:00 ago
2025-02-20 22:14:36,836 :: INFO :: Snapshots listed successfully
2025-02-20 22:14:36,838 :: ERROR :: Runner: Function has_recent_snapshot failed with: list indices must be integers or slices, not str
2025-02-20 22:14:36,840 :: ERROR :: Trace:
Traceback (most recent call last):
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\core\runner.py", line 669, in wrapper
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\core\runner.py", line 442, in wrapper
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\core\runner.py", line 653, in wrapper
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\core\runner.py", line 591, in wrapper
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\core\runner.py", line 512, in wrapper
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\core\runner.py", line 613, in wrapper
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\core\runner.py", line 1095, in has_recent_snapshot
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\restic_wrapper\__init__.py", line 1407, in has_recent_snapshot
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\restic_wrapper\__init__.py", line 1363, in _has_recent_snapshot
TypeError: list indices must be integers or slices, not str
2025-02-20 22:14:36,843 :: ERROR :: Backend finished with errors.
2025-02-20 22:14:36,843 :: WARNING :: Cannot get exec time from environment
2025-02-20 22:14:36,881 :: INFO :: Metrics pushed successfully.
2025-02-20 22:14:36,884 :: ERROR :: Runner: Function backup failed with: cannot unpack non-iterable bool object
2025-02-20 22:14:36,884 :: ERROR :: Trace:
Traceback (most recent call last):
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\core\runner.py", line 669, in wrapper
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\core\runner.py", line 442, in wrapper
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\core\runner.py", line 645, in wrapper
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\core\runner.py", line 591, in wrapper
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\core\runner.py", line 512, in wrapper
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\core\runner.py", line 613, in wrapper
  File "C:\Users\guitarbilly\DOWNLO~1\NP14FC~1\npbackup\core\runner.py", line 1261, in backup
TypeError: cannot unpack non-iterable bool object
2025-02-20 22:14:36,887 :: ERROR :: Cannot decode JSON from restic data: the JSON object must be str, bytes or bytearray, not bool
2025-02-20 22:14:36,887 :: ERROR :: Cannot find processed bytes: 'total_bytes_processed'
2025-02-20 22:14:36,888 :: ERROR :: Backend finished with errors.
2025-02-20 22:14:36,888 :: WARNING :: Cannot get exec time from environment
2025-02-20 22:14:36,983 :: INFO :: Metrics pushed successfully.
2025-02-20 22:14:36,984 :: ERROR :: Operation finished
2025-02-20 22:14:37,005 :: INFO :: ExecTime = 0:00:26.845940, finished, state is: errors.

C:\Users\guitarbilly\Downloads\npbackup-cli>

expected result:
npbackup should not crash but handle it gracefully with an error or warning to the user.

Note that with RCLONE_VERBOSE set to 2 the npbackup-gui hangs on listing snapshots for this OneDrive repo since rc14, hence my trial with npbackup-cli, here are the npbackup-gui messages in the GUI after loading the snapshots:
Last messages

:"d7b4e620"},{"time":"2025-02-20T11:59:51.622411+01:00","parent":"cc8c5b338923ee2dfadff7a63346d5d450f25db4a5a75952b2c66ab053755b58","tree":"9edaa6874f9dbcf82df0cd0aeb2bfa97925aee8f382ffc4fcde2836535d072c6","paths":["C:\\H"],"hostname":"MYLAPTOP","username":"AD\\guitarbilly","tags":["C_H"],"program_version":"restic 0.16.4","id":"34248f08f2093255a7ede7d8335851d269f9440ead3dad7b98e4b81ce410d516","short_id":"34248f08"},{"time":"2025-02-20T12:00:31.0987431+01:00","parent":"d7b4e6201cd5e34b3eb239050ded086f7a04437bd4a448749723347bccfc27ef","tree":"eadf8dcf458e678886274f9fc61e081a4a643db7dbf278460a6cd256881b466a","paths":["C:\\Program Files\\totalcmd\\Wciconex.dll","C:\\Program Files\\totalcmd\\plugins","C:\\Program Files\\totalcmd\\wciconex.inc","C:\\Users\\guitarbilly\\AppData\\Roaming\\GHISLER"],"hostname":"NLNIJ01NB0507","username":"AD\\guitarbilly","tags":["TC"],"program_version":"restic 0.16.4","id":"999e57510cb48cab1fc83abba1029a8e8c511b0a6609197ddcbe6df8de4fcbfe","short_id":"999e5751"}]
Snapshots listed successfully
Runner took 27.58145 seconds for snapshots

Error messages

rclone: 2025/02/20 22:30:46 DEBUG : rclone: Version "v1.65.2" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MyPreciousData\\abc"]
rclone: 2025/02/20 22:30:46 DEBUG : Creating backend with remote "onedrive:MyPreciousData\\abc"

rclone: 2025/02/20 22:30:46 DEBUG : rclone: Version "v1.65.2" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MyPreciousData\\abc"]
rclone: 2025/02/20 22:30:46 DEBUG : Creating backend with remote "onedrive:MyPreciousData\\abc"
rclone: 2025/02/20 22:30:46 DEBUG : Using config file from "C:\\Users\\guitarbilly\\AppData\\Roaming\\rclone\\rclone.conf"
rclone: 2025/02/20 22:30:47 DEBUG : fs cache: renaming cache item "onedrive:MyPreciousData\\abc" to be canonical "onedrive:MyPreciousData/abc"
rclone: 2025/02/20 22:30:47 DEBUG : file-15691317375884925585: GET request error: object not found
rclone: 2025/02/20 22:30:47 DEBUG : keys: list request

rclone: 2025/02/20 22:30:46 DEBUG : rclone: Version "v1.65.2" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MyPreciousData\\abc"]
rclone: 2025/02/20 22:30:46 DEBUG : Creating backend with remote "onedrive:MyPreciousData\\abc"
rclone: 2025/02/20 22:30:46 DEBUG : Using config file from "C:\\Users\\guitarbilly\\AppData\\Roaming\\rclone\\rclone.conf"
rclone: 2025/02/20 22:30:47 DEBUG : fs cache: renaming cache item "onedrive:MyPreciousData\\abc" to be canonical "onedrive:MyPreciousData/abc"
rclone: 2025/02/20 22:30:47 DEBUG : file-15691317375884925585: GET request error: object not found
rclone: 2025/02/20 22:30:47 DEBUG : keys: list request

rclone: 2025/02/20 22:30:46 DEBUG : rclone: Version "v1.65.2" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MyPreciousData\\abc"]
rclone: 2025/02/20 22:30:46 DEBUG : Creating backend with remote "onedrive:MyPreciousData\\abc"
rclone: 2025/02/20 22:30:46 DEBUG : Using config file from "C:\\Users\\guitarbilly\\AppData\\Roaming\\rclone\\rclone.conf"
rclone: 2025/02/20 22:30:47 DEBUG : fs cache: renaming cache item "onedrive:MyPreciousData\\abc" to be canonical "onedrive:MyPreciousData/abc"
rclone: 2025/02/20 22:30:47 DEBUG : file-15691317375884925585: GET request error: object not found
rclone: 2025/02/20 22:30:47 DEBUG : keys: list request

rclone: 2025/02/20 22:30:46 DEBUG : rclone: Version "v1.65.2" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MyPreciousData\\abc"]
rclone: 2025/02/20 22:30:46 DEBUG : Creating backend with remote "onedrive:MyPreciousData\\abc"
rclone: 2025/02/20 22:30:46 DEBUG : Using config file from "C:\\Users\\guitarbilly\\AppData\\Roaming\\rclone\\rclone.conf"
rclone: 2025/02/20 22:30:47 DEBUG : fs cache: renaming cache item "onedrive:MyPreciousData\\abc" to be canonical "onedrive:MyPreciousData/abc"
rclone: 2025/02/20 22:30:47 DEBUG : file-15691317375884925585: GET request error: object not found
rclone: 2025/02/20 22:30:47 DEBUG : keys: list request
rclone: 2025/02/20 22:30:51 DEBUG : locks: list request

rclone: 2025/02/20 22:30:46 DEBUG : rclone: Version "v1.65.2" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MyPreciousData\\abc"]
rclone: 2025/02/20 22:30:46 DEBUG : Creating backend with remote "onedrive:MyPreciousData\\abc"
rclone: 2025/02/20 22:30:46 DEBUG : Using config file from "C:\\Users\\guitarbilly\\AppData\\Roaming\\rclone\\rclone.conf"
rclone: 2025/02/20 22:30:47 DEBUG : fs cache: renaming cache item "onedrive:MyPreciousData\\abc" to be canonical "onedrive:MyPreciousData/abc"
rclone: 2025/02/20 22:30:47 DEBUG : file-15691317375884925585: GET request error: object not found
rclone: 2025/02/20 22:30:47 DEBUG : keys: list request
rclone: 2025/02/20 22:30:51 DEBUG : locks: list request
rclone: 2025/02/20 22:30:51 DEBUG : locks/55c6681445b7a516ccd2baab769ce2a9b70e5a7524a3e1d6ba23a8463dff66c9: Starting multipart upload
rclone: 2025/02/20 22:30:51 DEBUG : locks/55c6681445b7a516ccd2baab769ce2a9b70e5a7524a3e1d6ba23a8463dff66c9: Uploading segment 0/160 size 160

rclone: 2025/02/20 22:30:46 DEBUG : rclone: Version "v1.65.2" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MyPreciousData\\abc"]
rclone: 2025/02/20 22:30:46 DEBUG : Creating backend with remote "onedrive:MyPreciousData\\abc"
rclone: 2025/02/20 22:30:46 DEBUG : Using config file from "C:\\Users\\guitarbilly\\AppData\\Roaming\\rclone\\rclone.conf"
rclone: 2025/02/20 22:30:47 DEBUG : fs cache: renaming cache item "onedrive:MyPreciousData\\abc" to be canonical "onedrive:MyPreciousData/abc"
rclone: 2025/02/20 22:30:47 DEBUG : file-15691317375884925585: GET request error: object not found
rclone: 2025/02/20 22:30:47 DEBUG : keys: list request
rclone: 2025/02/20 22:30:51 DEBUG : locks: list request
rclone: 2025/02/20 22:30:51 DEBUG : locks/55c6681445b7a516ccd2baab769ce2a9b70e5a7524a3e1d6ba23a8463dff66c9: Starting multipart upload
rclone: 2025/02/20 22:30:51 DEBUG : locks/55c6681445b7a516ccd2baab769ce2a9b70e5a7524a3e1d6ba23a8463dff66c9: Uploading segment 0/160 size 160
rclone: 2025/02/20 22:30:52 DEBUG : locks: list request
rclone: 2025/02/20 22:30:52 DEBUG : snapshots: list request

rclone: 2025/02/20 22:30:46 DEBUG : rclone: Version "v1.65.2" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MyPreciousData\\abc"]
rclone: 2025/02/20 22:30:46 DEBUG : Creating backend with remote "onedrive:MyPreciousData\\abc"
rclone: 2025/02/20 22:30:46 DEBUG : Using config file from "C:\\Users\\guitarbilly\\AppData\\Roaming\\rclone\\rclone.conf"
rclone: 2025/02/20 22:30:47 DEBUG : fs cache: renaming cache item "onedrive:MyPreciousData\\abc" to be canonical "onedrive:MyPreciousData/abc"
rclone: 2025/02/20 22:30:47 DEBUG : file-15691317375884925585: GET request error: object not found
rclone: 2025/02/20 22:30:47 DEBUG : keys: list request
rclone: 2025/02/20 22:30:51 DEBUG : locks: list request
rclone: 2025/02/20 22:30:51 DEBUG : locks/55c6681445b7a516ccd2baab769ce2a9b70e5a7524a3e1d6ba23a8463dff66c9: Starting multipart upload
rclone: 2025/02/20 22:30:51 DEBUG : locks/55c6681445b7a516ccd2baab769ce2a9b70e5a7524a3e1d6ba23a8463dff66c9: Uploading segment 0/160 size 160
rclone: 2025/02/20 22:30:52 DEBUG : locks: list request
rclone: 2025/02/20 22:30:52 DEBUG : snapshots: list request

rclone: 2025/02/20 22:30:46 DEBUG : rclone: Version "v1.65.2" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MyPreciousData\\abc"]
rclone: 2025/02/20 22:30:46 DEBUG : Creating backend with remote "onedrive:MyPreciousData\\abc"
rclone: 2025/02/20 22:30:46 DEBUG : Using config file from "C:\\Users\\guitarbilly\\AppData\\Roaming\\rclone\\rclone.conf"
rclone: 2025/02/20 22:30:47 DEBUG : fs cache: renaming cache item "onedrive:MyPreciousData\\abc" to be canonical "onedrive:MyPreciousData/abc"
rclone: 2025/02/20 22:30:47 DEBUG : file-15691317375884925585: GET request error: object not found
rclone: 2025/02/20 22:30:47 DEBUG : keys: list request
rclone: 2025/02/20 22:30:51 DEBUG : locks: list request
rclone: 2025/02/20 22:30:51 DEBUG : locks/55c6681445b7a516ccd2baab769ce2a9b70e5a7524a3e1d6ba23a8463dff66c9: Starting multipart upload
rclone: 2025/02/20 22:30:51 DEBUG : locks/55c6681445b7a516ccd2baab769ce2a9b70e5a7524a3e1d6ba23a8463dff66c9: Uploading segment 0/160 size 160
rclone: 2025/02/20 22:30:52 DEBUG : locks: list request
rclone: 2025/02/20 22:30:52 DEBUG : snapshots: list request

rclone: 2025/02/20 22:30:46 DEBUG : rclone: Version "v1.65.2" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MyPreciousData\\abc"]
rclone: 2025/02/20 22:30:46 DEBUG : Creating backend with remote "onedrive:MyPreciousData\\abc"
rclone: 2025/02/20 22:30:46 DEBUG : Using config file from "C:\\Users\\guitarbilly\\AppData\\Roaming\\rclone\\rclone.conf"
rclone: 2025/02/20 22:30:47 DEBUG : fs cache: renaming cache item "onedrive:MyPreciousData\\abc" to be canonical "onedrive:MyPreciousData/abc"
rclone: 2025/02/20 22:30:47 DEBUG : file-15691317375884925585: GET request error: object not found
rclone: 2025/02/20 22:30:47 DEBUG : keys: list request
rclone: 2025/02/20 22:30:51 DEBUG : locks: list request
rclone: 2025/02/20 22:30:51 DEBUG : locks/55c6681445b7a516ccd2baab769ce2a9b70e5a7524a3e1d6ba23a8463dff66c9: Starting multipart upload
rclone: 2025/02/20 22:30:51 DEBUG : locks/55c6681445b7a516ccd2baab769ce2a9b70e5a7524a3e1d6ba23a8463dff66c9: Uploading segment 0/160 size 160
rclone: 2025/02/20 22:30:52 DEBUG : locks: list request
rclone: 2025/02/20 22:30:52 DEBUG : snapshots: list request

rclone: 2025/02/20 22:30:46 DEBUG : rclone: Version "v1.65.2" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MyPreciousData\\abc"]
rclone: 2025/02/20 22:30:46 DEBUG : Creating backend with remote "onedrive:MyPreciousData\\abc"
rclone: 2025/02/20 22:30:46 DEBUG : Using config file from "C:\\Users\\guitarbilly\\AppData\\Roaming\\rclone\\rclone.conf"
rclone: 2025/02/20 22:30:47 DEBUG : fs cache: renaming cache item "onedrive:MyPreciousData\\abc" to be canonical "onedrive:MyPreciousData/abc"
rclone: 2025/02/20 22:30:47 DEBUG : file-15691317375884925585: GET request error: object not found
rclone: 2025/02/20 22:30:47 DEBUG : keys: list request
rclone: 2025/02/20 22:30:51 DEBUG : locks: list request
rclone: 2025/02/20 22:30:51 DEBUG : locks/55c6681445b7a516ccd2baab769ce2a9b70e5a7524a3e1d6ba23a8463dff66c9: Starting multipart upload
rclone: 2025/02/20 22:30:51 DEBUG : locks/55c6681445b7a516ccd2baab769ce2a9b70e5a7524a3e1d6ba23a8463dff66c9: Uploading segment 0/160 size 160
rclone: 2025/02/20 22:30:52 DEBUG : locks: list request
rclone: 2025/02/20 22:30:52 DEBUG : snapshots: list request

EDIT : here is the npbackup-gui termnial log:

C:\Users\guitarbilly>Downloads\npbackup-gui\npbackup-gui.exe -c Downloads\NPBACKUP_COMMON\npbackup.conf --repo-name OneDrive_via_rclone
2025-02-20 22:29:48,671 :: INFO :: GUI: npbackup 3.0.0-rc15-windows-gui-x64-public-3.13-c 2025021701 - Copyright (C) 2022-2025 NetInvent running as AD\guitarbilly
2025-02-20 22:29:48,728 :: INFO :: Loaded config AA29C37A in C:\Users\guitarbilly\Downloads\NPBACKUP_COMMON\npbackup.conf
2025-02-20 22:29:48,734 :: INFO :: No extra information for repos x300server_MYLAPTOP found
2025-02-20 22:29:49,677 :: INFO :: Listing snapshots of repo OneDrive_via_rclone
2025-02-20 22:30:15,125 :: INFO :: Snapshots listed successfully
2025-02-20 22:30:15,125 :: INFO :: Runner took 25.448921 seconds for snapshots
2025-02-20 22:30:28,720 :: INFO :: Listing snapshots of repo OneDrive_via_rclone
2025-02-20 22:30:56,298 :: INFO :: Snapshots listed successfully
2025-02-20 22:30:56,300 :: INFO :: Runner took 27.58145 seconds for snapshots
2025-02-20 22:30:56,343 :: INFO :: Metrics pushed successfully.
2025-02-20 22:41:21,488 :: CRITICAL :: GUI Execution error list indices must be integers or slices, not str
2025-02-20 22:41:21,490 :: INFO :: Trace:
Traceback (most recent call last):
  File "C:\Users\guitarbilly\DOWNLO~1\NPAA0E~1\npbackup\gui\__main__.py", line 1238, in main_gui
  File "C:\Users\guitarbilly\DOWNLO~1\NPAA0E~1\npbackup\gui\__main__.py", line 1107, in _main_gui
  File "C:\Users\guitarbilly\DOWNLO~1\NPAA0E~1\npbackup\gui\__main__.py", line 659, in get_gui_data
  File "C:\Users\guitarbilly\DOWNLO~1\NPAA0E~1\npbackup\restic_wrapper\__init__.py", line 1363, in _has_recent_snapshot
TypeError: list indices must be integers or slices, not str
2025-02-20 22:41:21,538 :: INFO :: ExecTime = 0:11:32.869565, finished, state is: critical.

[GuitarBilly]

removing the RCLONE_VERBOSE = 2 variable makes the snapshot and backup work:

[deajan]

Happy to know that things work ;)

I'm pretty sure that rclone verbose just gives too much information which NPBackup cannot parse, although it does not crash, but just notices the error and still sends metrics.

I'd definitly need to have an output of this with --debug for better comprehension.
Also, would you mind sharing your anonymous yaml config ?

[deajan]

Since rclone works, this can wait until after a v3 release, but still I'd like to be able to filter rclone verbose output to parse only necessary data.

I've managed to update RC15 everywhere, and it seems to work well.
Probably going to release RTM soon unless a major block is found.

[GuitarBilly]

@deajan agree this is not a show stopper for RTM.
I will still create an anonymized config wtih --debug info for you.

p.s. Upon doing it I found a bug that deserves fixing. Will log an issue for that.

[GuitarBilly]

@deajan In my opinion this issue boils down to wanting to deal with RCLONE_VERBOSE=2 enabled which is fantastic for debugging but normally not required for regular backup situations.

Enough said; here my anonymized npbackup config file:
github.upload.npbackup.OneDrive_via_rclone.anon.conf.txt

Results from a fresh run with --debug output:

npbackup 3.0.0-linux-gui-x64-legacy-public-3.10-i 2025022301 - Copyright (C) 2022-2025 NetInvent running as linux
2025-02-23 19:06:51,141 :: INFO :: GUI: npbackup 3.0.0-linux-gui-x64-legacy-public-3.10-i 2025022301 - Copyright (C) 2022-2025 NetInvent running as linux
2025-02-23 19:06:51,156 :: INFO :: Loaded config BA602950 in /home/linux/npbackup.latest.github/npbackup/npbackup.OneDrive_via_rclone.anon.conf
2025-02-23 19:06:51,158 :: INFO :: No extra information for groups default_group found
2025-02-23 19:06:51,768 :: DEBUG :: gui_thread_runner runs snapshots without threads
2025-02-23 19:06:51,914 :: DEBUG :: Command "['/home/linux/npbackup.latest.github/npbackup/npbackup/../RESTIC_SOURCE_FILES/restic_0.17.3_linux_amd64', 'version']" returned with exit code "0". Command output was:
restic 0.17.3 compiled with go1.23.3 on linux/amd64

2025-02-23 19:06:51,914 :: DEBUG :: STDOUT: restic 0.17.3 compiled with go1.23.3 on linux/amd64

2025-02-23 19:06:51,915 :: INFO :: Using binary restic 0.17.3 compiled with go1.23.3 on linux/amd64
2025-02-23 19:06:51,915 :: INFO :: Listing snapshots of repo default
2025-02-23 19:06:51,915 :: DEBUG :: Setting environment variable "RCLONE_VERBOSE"
2025-02-23 19:06:51,915 :: DEBUG :: Setting GOMAXPROCS to 10
2025-02-23 19:06:56,311 :: DEBUG :: Command "['/home/linux/npbackup.latest.github/npbackup/npbackup/../RESTIC_SOURCE_FILES/restic_0.17.3_linux_amd64', '--limit-upload', '102400', '--json', 'snapshots']" returned with exit code "0". Command output was:
rclone: 2025/02/23 19:06:51 DEBUG : rclone: Version "v1.69.1" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MPD/npbackup.repo"]
rclone: 2025/02/23 19:06:51 DEBUG : Creating backend with remote "onedrive:MPD/npbackup.repo"
rclone: 2025/02/23 19:06:51 DEBUG : Using config file from "/home/linux/.config/rclone/rclone.conf"
rclone: 2025/02/23 19:06:52 DEBUG : file-8063075765049147397: GET request error: object not found
rclone: 2025/02/23 19:06:52 DEBUG : keys: list request
rclone: 2025/02/23 19:06:54 DEBUG : locks: list request
rclone: 2025/02/23 19:06:54 DEBUG : locks/51b078f641f4c082f682613e1a67d73b10a73a5d235819b5620f7aa019a50262: Starting multipart upload
rclone: 2025/02/23 19:06:54 DEBUG : locks/51b078f641f4c082f682613e1a67d73b10a73a5d235819b5620f7aa019a50262: Uploading segment 0/188 size 188
rclone: 2025/02/23 19:06:55 DEBUG : locks: list request
rclone: 2025/02/23 19:06:55 DEBUG : snapshots: list request
[{"time":"2025-02-23T19:01:47.980798989+01:00","tree":"c68f100920af8ae3b3a976c07e964cb996e4d774c0b7a72ccf214b0adbfa4b2c","paths":["/home/linux/npbackup.latest.github/npbackup/npbackup.OneDrive_via_rclone.anon.conf"],"hostname":"x300werkstation","username":"linux","uid":1000,"gid":1000,"program_version":"restic 0.17.3","summary":{"backup_start":"2025-02-23T19:01:47.980798989+01:00","backup_end":"2025-02-23T19:01:55.839219359+01:00","files_new":1,"files_changed":0,"files_unmodified":0,"dirs_new":4,"dirs_changed":0,"dirs_unmodified":0,"data_blobs":1,"tree_blobs":5,"data_added":4892,"data_added_packed":2975,"total_files_processed":1,"total_bytes_processed":2983},"id":"3baa9df07cd543e07b7715c6b0dde26295da989abf2dcc0cf1248850b31b21ef","short_id":"3baa9df0"}]

2025-02-23 19:06:56,311 :: DEBUG :: STDOUT: rclone: 2025/02/23 19:06:51 DEBUG : rclone: Version "v1.69.1" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MPD/npbackup.repo"]
rclone: 2025/02/23 19:06:51 DEBUG : Creating backend with remote "onedrive:MPD/npbackup.repo"
rclone: 2025/02/23 19:06:51 DEBUG : Using config file from "/home/linux/.config/rclone/rclone.conf"
rclone: 2025/02/23 19:06:52 DEBUG : file-8063075765049147397: GET request error: object not found
rclone: 2025/02/23 19:06:52 DEBUG : keys: list request
rclone: 2025/02/23 19:06:54 DEBUG : locks: list request
rclone: 2025/02/23 19:06:54 DEBUG : locks/51b078f641f4c082f682613e1a67d73b10a73a5d235819b5620f7aa019a50262: Starting multipart upload
rclone: 2025/02/23 19:06:54 DEBUG : locks/51b078f641f4c082f682613e1a67d73b10a73a5d235819b5620f7aa019a50262: Uploading segment 0/188 size 188
rclone: 2025/02/23 19:06:55 DEBUG : locks: list request
rclone: 2025/02/23 19:06:55 DEBUG : snapshots: list request
[{"time":"2025-02-23T19:01:47.980798989+01:00","tree":"c68f100920af8ae3b3a976c07e964cb996e4d774c0b7a72ccf214b0adbfa4b2c","paths":["/home/linux/npbackup.latest.github/npbackup/npbackup.OneDrive_via_rclone.anon.conf"],"hostname":"x300werkstation","username":"linux","uid":1000,"gid":1000,"program_version":"restic 0.17.3","summary":{"backup_start":"2025-02-23T19:01:47.980798989+01:00","backup_end":"2025-02-23T19:01:55.839219359+01:00","files_new":1,"files_changed":0,"files_unmodified":0,"dirs_new":4,"dirs_changed":0,"dirs_unmodified":0,"data_blobs":1,"tree_blobs":5,"data_added":4892,"data_added_packed":2975,"total_files_processed":1,"total_bytes_processed":2983},"id":"3baa9df07cd543e07b7715c6b0dde26295da989abf2dcc0cf1248850b31b21ef","short_id":"3baa9df0"}]

2025-02-23 19:06:56,311 :: DEBUG :: Running on_exit callable.
2025-02-23 19:06:56,311 :: DEBUG :: Setting environment variable "RCLONE_VERBOSE"
2025-02-23 19:06:56,312 :: DEBUG :: Setting GOMAXPROCS to 10
2025-02-23 19:07:00,589 :: DEBUG :: Command "['/home/linux/npbackup.latest.github/npbackup/npbackup/../RESTIC_SOURCE_FILES/restic_0.17.3_linux_amd64', '--limit-upload', '102400', '--json', 'snapshots']" returned with exit code "0". Command output was:
rclone: 2025/02/23 19:06:56 DEBUG : rclone: Version "v1.69.1" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MPD/npbackup.repo"]
rclone: 2025/02/23 19:06:56 DEBUG : Creating backend with remote "onedrive:MPD/npbackup.repo"
rclone: 2025/02/23 19:06:56 DEBUG : Using config file from "/home/linux/.config/rclone/rclone.conf"
rclone: 2025/02/23 19:06:56 DEBUG : file-9920421487873340252: GET request error: object not found
rclone: 2025/02/23 19:06:57 DEBUG : keys: list request
rclone: 2025/02/23 19:06:58 DEBUG : locks: list request
rclone: 2025/02/23 19:06:58 DEBUG : locks/0cf4574f55be0c864c0a355a7a36d959e6ea06308f39bfd483095709a9b17f0b: Starting multipart upload
rclone: 2025/02/23 19:06:58 DEBUG : locks/0cf4574f55be0c864c0a355a7a36d959e6ea06308f39bfd483095709a9b17f0b: Uploading segment 0/188 size 188
rclone: 2025/02/23 19:06:59 DEBUG : locks: list request
rclone: 2025/02/23 19:06:59 DEBUG : snapshots: list request
[{"time":"2025-02-23T19:01:47.980798989+01:00","tree":"c68f100920af8ae3b3a976c07e964cb996e4d774c0b7a72ccf214b0adbfa4b2c","paths":["/home/linux/npbackup.latest.github/npbackup/npbackup.OneDrive_via_rclone.anon.conf"],"hostname":"x300werkstation","username":"linux","uid":1000,"gid":1000,"program_version":"restic 0.17.3","summary":{"backup_start":"2025-02-23T19:01:47.980798989+01:00","backup_end":"2025-02-23T19:01:55.839219359+01:00","files_new":1,"files_changed":0,"files_unmodified":0,"dirs_new":4,"dirs_changed":0,"dirs_unmodified":0,"data_blobs":1,"tree_blobs":5,"data_added":4892,"data_added_packed":2975,"total_files_processed":1,"total_bytes_processed":2983},"id":"3baa9df07cd543e07b7715c6b0dde26295da989abf2dcc0cf1248850b31b21ef","short_id":"3baa9df0"}]

2025-02-23 19:07:00,589 :: DEBUG :: STDOUT: rclone: 2025/02/23 19:06:56 DEBUG : rclone: Version "v1.69.1" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MPD/npbackup.repo"]
rclone: 2025/02/23 19:06:56 DEBUG : Creating backend with remote "onedrive:MPD/npbackup.repo"
rclone: 2025/02/23 19:06:56 DEBUG : Using config file from "/home/linux/.config/rclone/rclone.conf"
rclone: 2025/02/23 19:06:56 DEBUG : file-9920421487873340252: GET request error: object not found
rclone: 2025/02/23 19:06:57 DEBUG : keys: list request
rclone: 2025/02/23 19:06:58 DEBUG : locks: list request
rclone: 2025/02/23 19:06:58 DEBUG : locks/0cf4574f55be0c864c0a355a7a36d959e6ea06308f39bfd483095709a9b17f0b: Starting multipart upload
rclone: 2025/02/23 19:06:58 DEBUG : locks/0cf4574f55be0c864c0a355a7a36d959e6ea06308f39bfd483095709a9b17f0b: Uploading segment 0/188 size 188
rclone: 2025/02/23 19:06:59 DEBUG : locks: list request
rclone: 2025/02/23 19:06:59 DEBUG : snapshots: list request
[{"time":"2025-02-23T19:01:47.980798989+01:00","tree":"c68f100920af8ae3b3a976c07e964cb996e4d774c0b7a72ccf214b0adbfa4b2c","paths":["/home/linux/npbackup.latest.github/npbackup/npbackup.OneDrive_via_rclone.anon.conf"],"hostname":"x300werkstation","username":"linux","uid":1000,"gid":1000,"program_version":"restic 0.17.3","summary":{"backup_start":"2025-02-23T19:01:47.980798989+01:00","backup_end":"2025-02-23T19:01:55.839219359+01:00","files_new":1,"files_changed":0,"files_unmodified":0,"dirs_new":4,"dirs_changed":0,"dirs_unmodified":0,"data_blobs":1,"tree_blobs":5,"data_added":4892,"data_added_packed":2975,"total_files_processed":1,"total_bytes_processed":2983},"id":"3baa9df07cd543e07b7715c6b0dde26295da989abf2dcc0cf1248850b31b21ef","short_id":"3baa9df0"}]

2025-02-23 19:07:00,589 :: DEBUG :: Running on_exit callable.
2025-02-23 19:07:00,589 :: INFO :: Snapshots listed successfully
2025-02-23 19:07:00,590 :: INFO :: Runner took 8.734447 seconds for snapshots
2025-02-23 19:07:00,590 :: DEBUG :: Metrics disabled for call snapshots
2025-02-23 19:07:00,597 :: DEBUG :: gui_thread_runner got stdout queue close signal
2025-02-23 19:07:00,598 :: DEBUG :: gui_thread_runner got stderr queue close signal

...which does not lead to a fatal error or crash, but this GUI state:

npbackup then does crash when you trigger the snapshot reading one more time either via opening/closing the configuration or by pressing the GUi repo 'Backup state' button, here the additional debug log:

2025-02-23 19:10:39,205 :: DEBUG :: gui_thread_runner runs snapshots without threads
2025-02-23 19:10:39,345 :: DEBUG :: Command "['/home/linux/npbackup.latest.github/npbackup/npbackup/../RESTIC_SOURCE_FILES/restic_0.17.3_linux_amd64', 'version']" returned with exit code "0". Command output was:
restic 0.17.3 compiled with go1.23.3 on linux/amd64

2025-02-23 19:10:39,345 :: DEBUG :: STDOUT: restic 0.17.3 compiled with go1.23.3 on linux/amd64

2025-02-23 19:10:39,345 :: INFO :: Using binary restic 0.17.3 compiled with go1.23.3 on linux/amd64
2025-02-23 19:10:39,345 :: INFO :: Listing snapshots of repo default
2025-02-23 19:10:39,346 :: DEBUG :: Setting environment variable "RCLONE_VERBOSE"
2025-02-23 19:10:39,346 :: DEBUG :: Setting GOMAXPROCS to 10
2025-02-23 19:10:43,614 :: DEBUG :: Command "['/home/linux/npbackup.latest.github/npbackup/npbackup/../RESTIC_SOURCE_FILES/restic_0.17.3_linux_amd64', '--limit-upload', '102400', '--json', 'snapshots']" returned with exit code "0". Command output was:
rclone: 2025/02/23 19:10:39 DEBUG : rclone: Version "v1.69.1" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MPD/npbackup.repo"]
rclone: 2025/02/23 19:10:39 DEBUG : Creating backend with remote "onedrive:MPD/npbackup.repo"
rclone: 2025/02/23 19:10:39 DEBUG : Using config file from "/home/linux/.config/rclone/rclone.conf"
rclone: 2025/02/23 19:10:39 DEBUG : file-11839853202405371980: GET request error: object not found
rclone: 2025/02/23 19:10:40 DEBUG : keys: list request
rclone: 2025/02/23 19:10:41 DEBUG : locks: list request
rclone: 2025/02/23 19:10:41 DEBUG : locks/6e23210173fdd007080e3e5ab8a77c687af072513cbca8544e97e83bd19d9c86: Starting multipart upload
rclone: 2025/02/23 19:10:41 DEBUG : locks/6e23210173fdd007080e3e5ab8a77c687af072513cbca8544e97e83bd19d9c86: Uploading segment 0/187 size 187
rclone: 2025/02/23 19:10:42 DEBUG : locks: list request
rclone: 2025/02/23 19:10:42 DEBUG : snapshots: list request
[{"time":"2025-02-23T19:01:47.980798989+01:00","tree":"c68f100920af8ae3b3a976c07e964cb996e4d774c0b7a72ccf214b0adbfa4b2c","paths":["/home/linux/npbackup.latest.github/npbackup/npbackup.OneDrive_via_rclone.anon.conf"],"hostname":"x300werkstation","username":"linux","uid":1000,"gid":1000,"program_version":"restic 0.17.3","summary":{"backup_start":"2025-02-23T19:01:47.980798989+01:00","backup_end":"2025-02-23T19:01:55.839219359+01:00","files_new":1,"files_changed":0,"files_unmodified":0,"dirs_new":4,"dirs_changed":0,"dirs_unmodified":0,"data_blobs":1,"tree_blobs":5,"data_added":4892,"data_added_packed":2975,"total_files_processed":1,"total_bytes_processed":2983},"id":"3baa9df07cd543e07b7715c6b0dde26295da989abf2dcc0cf1248850b31b21ef","short_id":"3baa9df0"}]

2025-02-23 19:10:43,614 :: DEBUG :: STDOUT: rclone: 2025/02/23 19:10:39 DEBUG : rclone: Version "v1.69.1" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MPD/npbackup.repo"]
rclone: 2025/02/23 19:10:39 DEBUG : Creating backend with remote "onedrive:MPD/npbackup.repo"
rclone: 2025/02/23 19:10:39 DEBUG : Using config file from "/home/linux/.config/rclone/rclone.conf"
rclone: 2025/02/23 19:10:39 DEBUG : file-11839853202405371980: GET request error: object not found
rclone: 2025/02/23 19:10:40 DEBUG : keys: list request
rclone: 2025/02/23 19:10:41 DEBUG : locks: list request
rclone: 2025/02/23 19:10:41 DEBUG : locks/6e23210173fdd007080e3e5ab8a77c687af072513cbca8544e97e83bd19d9c86: Starting multipart upload
rclone: 2025/02/23 19:10:41 DEBUG : locks/6e23210173fdd007080e3e5ab8a77c687af072513cbca8544e97e83bd19d9c86: Uploading segment 0/187 size 187
rclone: 2025/02/23 19:10:42 DEBUG : locks: list request
rclone: 2025/02/23 19:10:42 DEBUG : snapshots: list request
[{"time":"2025-02-23T19:01:47.980798989+01:00","tree":"c68f100920af8ae3b3a976c07e964cb996e4d774c0b7a72ccf214b0adbfa4b2c","paths":["/home/linux/npbackup.latest.github/npbackup/npbackup.OneDrive_via_rclone.anon.conf"],"hostname":"x300werkstation","username":"linux","uid":1000,"gid":1000,"program_version":"restic 0.17.3","summary":{"backup_start":"2025-02-23T19:01:47.980798989+01:00","backup_end":"2025-02-23T19:01:55.839219359+01:00","files_new":1,"files_changed":0,"files_unmodified":0,"dirs_new":4,"dirs_changed":0,"dirs_unmodified":0,"data_blobs":1,"tree_blobs":5,"data_added":4892,"data_added_packed":2975,"total_files_processed":1,"total_bytes_processed":2983},"id":"3baa9df07cd543e07b7715c6b0dde26295da989abf2dcc0cf1248850b31b21ef","short_id":"3baa9df0"}]

2025-02-23 19:10:43,615 :: DEBUG :: Running on_exit callable.
2025-02-23 19:10:43,615 :: DEBUG :: Setting environment variable "RCLONE_VERBOSE"
2025-02-23 19:10:43,615 :: DEBUG :: Setting GOMAXPROCS to 10
2025-02-23 19:10:48,735 :: DEBUG :: Command "['/home/linux/npbackup.latest.github/npbackup/npbackup/../RESTIC_SOURCE_FILES/restic_0.17.3_linux_amd64', '--limit-upload', '102400', '--json', 'snapshots']" returned with exit code "0". Command output was:
rclone: 2025/02/23 19:10:43 DEBUG : rclone: Version "v1.69.1" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MPD/npbackup.repo"]
rclone: 2025/02/23 19:10:43 DEBUG : Creating backend with remote "onedrive:MPD/npbackup.repo"
rclone: 2025/02/23 19:10:43 DEBUG : Using config file from "/home/linux/.config/rclone/rclone.conf"
rclone: 2025/02/23 19:10:44 DEBUG : file-2335515084405154304: GET request error: object not found
rclone: 2025/02/23 19:10:44 DEBUG : keys: list request
rclone: 2025/02/23 19:10:46 DEBUG : locks: list request
rclone: 2025/02/23 19:10:46 DEBUG : locks/b96968f20e84971c7c1b480681e14a1615b658955bc321f19bb75027191cde1b: Starting multipart upload
rclone: 2025/02/23 19:10:47 DEBUG : locks/b96968f20e84971c7c1b480681e14a1615b658955bc321f19bb75027191cde1b: Uploading segment 0/188 size 188
rclone: 2025/02/23 19:10:48 DEBUG : locks: list request
rclone: 2025/02/23 19:10:48 DEBUG : snapshots: list request
[{"time":"2025-02-23T19:01:47.980798989+01:00","tree":"c68f100920af8ae3b3a976c07e964cb996e4d774c0b7a72ccf214b0adbfa4b2c","paths":["/home/linux/npbackup.latest.github/npbackup/npbackup.OneDrive_via_rclone.anon.conf"],"hostname":"x300werkstation","username":"linux","uid":1000,"gid":1000,"program_version":"restic 0.17.3","summary":{"backup_start":"2025-02-23T19:01:47.980798989+01:00","backup_end":"2025-02-23T19:01:55.839219359+01:00","files_new":1,"files_changed":0,"files_unmodified":0,"dirs_new":4,"dirs_changed":0,"dirs_unmodified":0,"data_blobs":1,"tree_blobs":5,"data_added":4892,"data_added_packed":2975,"total_files_processed":1,"total_bytes_processed":2983},"id":"3baa9df07cd543e07b7715c6b0dde26295da989abf2dcc0cf1248850b31b21ef","short_id":"3baa9df0"}]

2025-02-23 19:10:48,735 :: DEBUG :: STDOUT: rclone: 2025/02/23 19:10:43 DEBUG : rclone: Version "v1.69.1" starting with parameters ["rclone" "serve" "restic" "--stdio" "--b2-hard-delete" "onedrive:MPD/npbackup.repo"]
rclone: 2025/02/23 19:10:43 DEBUG : Creating backend with remote "onedrive:MPD/npbackup.repo"
rclone: 2025/02/23 19:10:43 DEBUG : Using config file from "/home/linux/.config/rclone/rclone.conf"
rclone: 2025/02/23 19:10:44 DEBUG : file-2335515084405154304: GET request error: object not found
rclone: 2025/02/23 19:10:44 DEBUG : keys: list request
rclone: 2025/02/23 19:10:46 DEBUG : locks: list request
rclone: 2025/02/23 19:10:46 DEBUG : locks/b96968f20e84971c7c1b480681e14a1615b658955bc321f19bb75027191cde1b: Starting multipart upload
rclone: 2025/02/23 19:10:47 DEBUG : locks/b96968f20e84971c7c1b480681e14a1615b658955bc321f19bb75027191cde1b: Uploading segment 0/188 size 188
rclone: 2025/02/23 19:10:48 DEBUG : locks: list request
rclone: 2025/02/23 19:10:48 DEBUG : snapshots: list request
[{"time":"2025-02-23T19:01:47.980798989+01:00","tree":"c68f100920af8ae3b3a976c07e964cb996e4d774c0b7a72ccf214b0adbfa4b2c","paths":["/home/linux/npbackup.latest.github/npbackup/npbackup.OneDrive_via_rclone.anon.conf"],"hostname":"x300werkstation","username":"linux","uid":1000,"gid":1000,"program_version":"restic 0.17.3","summary":{"backup_start":"2025-02-23T19:01:47.980798989+01:00","backup_end":"2025-02-23T19:01:55.839219359+01:00","files_new":1,"files_changed":0,"files_unmodified":0,"dirs_new":4,"dirs_changed":0,"dirs_unmodified":0,"data_blobs":1,"tree_blobs":5,"data_added":4892,"data_added_packed":2975,"total_files_processed":1,"total_bytes_processed":2983},"id":"3baa9df07cd543e07b7715c6b0dde26295da989abf2dcc0cf1248850b31b21ef","short_id":"3baa9df0"}]

2025-02-23 19:10:48,735 :: DEBUG :: Running on_exit callable.
2025-02-23 19:10:48,736 :: INFO :: Snapshots listed successfully
2025-02-23 19:10:48,736 :: INFO :: Runner took 9.448468 seconds for snapshots
2025-02-23 19:10:48,736 :: DEBUG :: Metrics computed:
npbackup_exec_state{npversion="npbackup3.0.0-gui",action="snapshots",repo_name="default",timestamp="1740334248"} 0
npbackup_exec_time{npversion="npbackup3.0.0-gui",action="snapshots",repo_name="default",timestamp="1740334248"} 9.448468
2025-02-23 19:10:48,757 :: DEBUG :: gui_thread_runner got stdout queue close signal
2025-02-23 19:10:48,758 :: DEBUG :: gui_thread_runner got stderr queue close signal

and GUI state:

after pressing Close button:

then it crashes wth this final info in the terminal:

2025-02-23 19:17:31,800 :: CRITICAL :: GUI Execution error list indices must be integers or slices, not str
2025-02-23 19:17:31,801 :: INFO :: Trace:
Traceback (most recent call last):
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/gui/__main__.py", line 1239, in main_gui
    _main_gui(viewer_mode=viewer_mode)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/gui/__main__.py", line 1218, in _main_gui
    current_state, backup_tz, snapshot_list = get_gui_data(repo_config)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/gui/__main__.py", line 659, in get_gui_data
    current_state, backup_tz = ResticRunner._has_recent_snapshot(
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/restic_wrapper/__init__.py", line 1363, in _has_recent_snapshot
    last_snapshot["time"],
TypeError: list indices must be integers or slices, not str
2025-02-23 19:17:31,808 :: INFO :: ExecTime = 0:10:40.667726, finished, state is: critical.

[deajan]

@GuitarBilly There's a fix now in master for filtering rclone debug logs.
Would you mind giving it a test ride ?

[deajan]

Released in 3.0.1-rc1 comming out tomorrow morning.

[GuitarBilly]

@deajan, sure i'll try; realistically it will happen about two weeks from now (occupied with other things atm).

[deajan]

@GuitarBilly No worries, this is "a side quest" fix ;)
I'm just happy for all the feedback / help you provide making NPBackup user worthy.
I'll remove the milestone for now since v3.0.1 should release soonish.

[GuitarBilly]

@deajan, hope this help.
i have run the following command on the latest github development version:

venv/bin/python·bin/npbackup-gui·--dry-run·--config-file=/home/linux/npbackup/npbackup.v3.conf·--run-as-cli·--backup·--repo-name·OneDrive_via_rclone·--repo-group·OneDrive_via_rclone

terminal output (skipped the download part from github):

npbackup 3.0.1-linux-gui-x64-legacy-public-3.10-i 2025032101 - Copyright (C) 2022-2025 NetInvent running as linux
2025-03-26 18:47:29,436 :: INFO :: npbackup 3.0.1-linux-gui-x64-legacy-public-3.10-i 2025032101 - Copyright (C) 2022-2025 NetInvent running as linux
2025-03-26 18:47:29,461 :: INFO :: Loaded config 9CFC27FE in /home/linux/npbackup/npbackup.v3.conf
2025-03-26 18:47:29,526 :: INFO :: Using binary restic 0.17.3 compiled with go1.23.3 on linux/amd64
2025-03-26 18:47:29,526 :: INFO :: Searching for a backup newer than 1 day, 0:00:00 ago
2025-03-26 18:47:56,515 :: INFO :: Snapshots listed successfully
2025-03-26 18:47:56,515 :: ERROR :: Runner: Function has_recent_snapshot failed with: list indices must be integers or slices, not str
2025-03-26 18:47:56,515 :: ERROR :: Trace:
Traceback (most recent call last):
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/core/runner.py", line 698, in wrapper
    return fn(self, *args, **kwargs)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/core/runner.py", line 496, in wrapper
    result = fn(self, *args, **kwargs)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/core/runner.py", line 682, in wrapper
    result = fn(  # pylint: disable=E1102 (not-callable)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/core/runner.py", line 625, in wrapper
    return fn(self, *args, **kwargs)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/core/runner.py", line 566, in wrapper
    return fn(self, *args, **kwargs)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/core/runner.py", line 647, in wrapper
    return fn(self, *args, **kwargs)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/core/runner.py", line 1174, in has_recent_snapshot
    data = self.restic_runner.has_recent_snapshot(self.minimum_backup_age)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/restic_wrapper/__init__.py", line 1455, in has_recent_snapshot
    result, timestamp = self._has_recent_snapshot(snapshots, delta)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/restic_wrapper/__init__.py", line 1411, in _has_recent_snapshot
    last_snapshot["time"],
TypeError: list indices must be integers or slices, not str
2025-03-26 18:47:56,516 :: ERROR :: Backend finished with errors.
2025-03-26 18:47:56,516 :: WARNING :: Cannot get exec time from environment
2025-03-26 18:47:56,516 :: INFO :: Dry run mode. Not sending metrics.
2025-03-26 18:47:56,516 :: ERROR :: Runner: Function backup failed with: cannot unpack non-iterable bool object
2025-03-26 18:47:56,516 :: ERROR :: Trace:
Traceback (most recent call last):
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/core/runner.py", line 698, in wrapper
    return fn(self, *args, **kwargs)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/core/runner.py", line 496, in wrapper
    result = fn(self, *args, **kwargs)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/core/runner.py", line 674, in wrapper
    result = fn(self, *args, **kwargs)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/core/runner.py", line 625, in wrapper
    return fn(self, *args, **kwargs)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/core/runner.py", line 566, in wrapper
    return fn(self, *args, **kwargs)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/core/runner.py", line 647, in wrapper
    return fn(self, *args, **kwargs)
  File "/home/linux/npbackup.latest.github/npbackup/npbackup/core/runner.py", line 1340, in backup
    has_recent_snapshots, _ = self.has_recent_snapshot(
TypeError: cannot unpack non-iterable bool object
2025-03-26 18:47:56,516 :: ERROR :: Cannot decode JSON from restic data: the JSON object must be str, bytes or bytearray, not bool
2025-03-26 18:47:56,516 :: ERROR :: Cannot find processed bytes: 'total_bytes_processed'
2025-03-26 18:47:56,516 :: ERROR :: Backend finished with errors.
2025-03-26 18:47:56,517 :: WARNING :: Cannot get exec time from environment
2025-03-26 18:47:56,517 :: INFO :: Dry run mode. Not sending metrics.
2025-03-26 18:47:56,517 :: ERROR :: Operation finished
2025-03-26 18:47:56,524 :: INFO :: ExecTime = 0:00:27.089708, finished, state is: errors.
~/npbackup.latest.github

FYI - in the npbackup-gui then the snapshots command also throws an error (hence my trail to run a backup via --run-as-cli.

[deajan]

Thank you for the report. I guess this is still with RCLONE_VERBOSE set ?
Can you throw in --debug so I know what output I didn't filter properly ?