Invalid Handle to Path

I keep getting the following error whenever my backups run:

Failed to process path /home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf =>
Invalid handle to path “/home/myusername/.config/skypeforlinux/SkypeRD/ecs.conf”

I tried enabling snapshoting as an advanced option but when I do I get the following error:
Failed to create snapshot: System.Exception: The external command failed to start.
Error message: Duplicati.Library.Interface.UserInformationException: The script returned exit code 255, but 0 was expected: Exit code: 255
Error: unable to determine volume group (VG) for /home/myuser

I am using encryption for my home directory so perhaps that’s in some way contributing?

Please let me know if you need any more information.

Thanks!
Brad

Is that error a manual retype? I’m seeing a missing colon, and wondering about => and SkypeRT versus RD. There doesn’t even seem to be an “Invalid handle to path” in Duplicati source, though that might be external.
There are some signs on the web that it might be the error message associated with System.IO.IOException
Later on, I’ll ask you to try a manual read. If you can’t read it as the Duplicati user, that might show the issue.

Here’s the “Failed to process path:” I got when Duplicati was wandering and trying to back up improper files:

C: 2018-08-27 13:00:50 -04 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: C:\hiberfil.sys

The text on the left sometimes helps to understand context. You might need to use --log-file to get the prefix.

Are other parts of the backup OK? That might support or refute the theory about home directory encryption.

You can also try the bash script to look into what went wrong. It’s /usr/lib/duplicati/lvm-scripts/find-volume.sh

I can find little information on ecs.conf (and was it really SkypeRD, not SkypeRT, on the Invalid handle line?).

Can you read it manually from whatever user Duplicati runs as (which would probably be either root or you)?

If it turns out this is the only troublesome file (and you don’t care to debug some) you could try filtering it out.

Yes it was a manual retype - the system I was having trouble with was a virtual machine and I wasn’t able to copy paste. Here’s a direct copy/paste with my username redacted.

Sep 8, 2018 10:04 PM: Result
DeletedFiles: 10
DeletedFolders: 0
ModifiedFiles: 98
ExaminedFiles: 20630
OpenedFiles: 121
AddedFiles: 22
SizeOfModifiedFiles: 713481327
SizeOfAddedFiles: 11119994
SizeOfExaminedFiles: 10872907324
SizeOfOpenedFiles: 724864295
NotProcessedFiles: 0
AddedFolders: 2
TooLargeFiles: 0
FilesWithError: 1
ModifiedFolders: 0
ModifiedSymlinks: 0
AddedSymlinks: 0
DeletedSymlinks: 0
PartialBackup: False
Dryrun: False
MainOperation: Backup
CompactResults:
DeletedFileCount: 0
DownloadedFileCount: 0
UploadedFileCount: 0
DeletedFileSize: 0
DownloadedFileSize: 0
UploadedFileSize: 0
Dryrun: False
MainOperation: Compact
ParsedResult: Success
EndTime: 9/8/2018 10:04:45 PM (1536458685)
BeginTime: 9/8/2018 10:04:42 PM (1536458682)
Duration: 00:00:03.0509340
BackendStatistics:
RemoteCalls: 13
BytesUploaded: 65717377
BytesDownloaded: 32526983
FilesUploaded: 5
FilesDownloaded: 3
FilesDeleted: 3
FoldersCreated: 0
RetryAttempts: 0
UnknownFileSize: 0
UnknownFileCount: 0
KnownFileCount: 443
KnownFileSize: 10631585711
LastBackupDate: 9/8/2018 10:00:00 PM (1536458400)
BackupListCount: 11
TotalQuotaSpace: 0
FreeQuotaSpace: 0
AssignedQuotaSpace: -1
ReportedQuotaError: False
ReportedQuotaWarning: False
ParsedResult: Success
DeleteResults:
DeletedSets: [
Item1: 1
Item2: 9/8/2018 2:34:41 PM (1536431681),
Item1: 7
Item2: 9/1/2018 10:00:00 PM (1535853600),
Item1: 10
Item2: 8/11/2018 10:00:00 PM (1534039200)
]
Dryrun: False
MainOperation: Delete
ParsedResult: Success
EndTime: 9/8/2018 10:04:45 PM (1536458685)
BeginTime: 9/8/2018 10:04:33 PM (1536458673)
Duration: 00:00:12.3841030
RepairResults: null
TestResults:
MainOperation: Test
Verifications: [
Key: duplicati-20180909T020000Z.dlist.zip.aes
Value: ,
Key: duplicati-ib2c44799b31b45f3a39b00d178a5f2cd.dindex.zip.aes
Value: ,
Key: duplicati-b213bd6f8db7448b888aa375008936ddf.dblock.zip.aes
Value:
]
ParsedResult: Success
EndTime: 9/8/2018 10:04:54 PM (1536458694)
BeginTime: 9/8/2018 10:04:46 PM (1536458686)
Duration: 00:00:08.0268710
ParsedResult: Error
EndTime: 9/8/2018 10:04:54 PM (1536458694)
BeginTime: 9/8/2018 10:00:00 PM (1536458400)
Duration: 00:04:54.3910260
Messages: [
Deleting 3 remote fileset(s) …,
Deleted 3 remote fileset(s),
Compacting not required
]
Warnings: [
Failed to process path: /home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf => Invalid handle to path “/home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf”
]
Errors:

I tried running /usr/lib/duplicati/lvm-scripts/find-volume.sh manually but what I get is:

myusername@mycomputer:~/$ /usr/lib/duplicati/lvm-scripts/find-volume.sh
df: ‘’: No such file or directory
Error: unable to determine device for

I also tried to read the file manually and get:

$ cat /home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf
cat: /home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf: Input/output error

I tried ll on the file and got:

$ ll /home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf

-rw------- 1 myusername myusername 8192 Aug 10 18:24 /home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf

When I check ps it appears Duplicati is running as root:

root 941 0.0 0.0 455752 352 ? SNsl Sep07 0:01 DuplicatiServer /usr/lib/duplicati/Duplicati.Server.exe

root 1048 0.0 0.3 705048 14120 ? SNl Sep07 0:13 /usr/bin/mono-sgen /usr/lib/duplicati/Duplicati.Server.exe

myusername+ 1720 0.0 0.0 515168 736 ? Sl Sep07 0:00 Duplicati /usr/lib/duplicati/Duplicati.GUI.TrayIcon.exe

myusername+ 1858 0.2 1.9 988428 78892 ? Sl Sep07 5:55 /usr/bin/mono-sgen /usr/lib/duplicati/Duplicati.GUI.TrayIcon.exe

I am not sure that file is that critical but its bothering me that snapshots don’t appear to be working and I’m a little uncertain the repercussions of filtering it.

Thanks
Brad

Apologies for not having given enough script details. The message that you reported was:

The script returned exit code 255, but 0 was expected: Exit code: 255
Error: unable to determine volume group (VG) for /home/myuser

so it seemed like it might be:

if [ -z "$LVMID" ]
then
        EXIT_CODE=-1
        echo "Error: unable to determine volume group (VG) for $NAME"
        exit $EXIT_CODE
fi

-1 would be 255 as an unsigned 8-bit value. $NAME is /home/myuser, and goes after the name of the script:

#!/bin/bash

# This script returns the device on which the volume is mounted
# 
# Input is always:
#  $1 = name of the folder to locate the LVM device for

That will probably avoid the complaints from df (which expected $NAME).

For the file permissions, root should be able to get by that, but a locked file might still error. You could test it.
It’s disappointing that it’s not an empty file just used to lock. This claims it can be removed after a Skype exit. Perhaps it’s normally supposed to be removed? Or is it always there? In GitHub steps, you said Skype open.

Does a Skype exit let you see the file, or does it go away? If still there, you can examine it to guess what it is.
Filtering would be the workaround. Ideally we (and it might need someone else too) can figure this out some.

With skype closed the file still exists:

myusername@myworkstation:~/Downloads$ ll /home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf
-rw------- 1 myusername myusername 8192 Aug 10 18:24 /home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf

If I specify a path to the script I get the same error (just with a path):

myusername@myworkstation:~/Downloads$ /usr/lib/duplicati/lvm-scripts/find-volume.sh /home/myusername/.config/skypeforlinux/SkypeRT/
Error: unable to determine volume group (VG) for /home/myusername/.config/skypeforlinux/SkypeRT/

I’ve confirmed skype is definitely not running:

myusername@myworkstation:~/Downloads$ ps aux | grep skype
myusername+ 2487 0.0 0.0 38868 936 pts/1 S+ 12:15 0:00 grep --color=auto skype

Even with skype closed trying to cat the file doesn’t work:

myusername@myworkstation:~/Downloads$ cat /home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf
cat: /home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf: Input/output error

The error remains the same:

Warnings: [
Failed to process path: /home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf => Invalid handle to path “/home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf”
]

The script test failing adds confidence to the idea that this was in fact the script that ran. Must go deeper now.

How good are you with LVM? :grin: The script isn’t long. It could be instrumented (e.g. echo) or bits run by hand.

I’m not sure what’s up with ecs.conf. Does “fuser -v ecs.conf” show any process in it? Are you the file’s owner?

On top of this is the encryption setup. What type? Is it only your home directory, all of /home, something else?

Unless everything in reach is encrypted, you could probably have a user with an unencrypted home directory, have that user run Skype at least to the point of making an ecs.conf, then see how readable that version is…

I’m attempting to play with file locking to see if I can get a “cat” to fail just like yours did. Sadly no luck so far… Although I’d have thought an “ll” would show if it’s some unusual kind of file, can you inspect it any other way?

fuser -v ecs.conf results in

specified filename ecs.conf does not exist

So I am assuming that means the file isn’t in use?

I noticed if I change the script FROM:

LVMID=lvs "$1" --options vg_name,lv_name --noheadings 2>/dev/null | tail -1 | awk '{ print $1 "/" $2}'

TO:

LVMID=lvs --options vg_name,lv_name --noheadings 2>/dev/null | tail -1 | awk '{ print $1 "/" $2}'

(Removing “$1”)

That it will run manually and return:

mountpoint="/home/myusername"
device=“elementary-vg/swap_1”

Furthermore if I run the backup manually I get:

root@myworkstation:~# mono /usr/lib/duplicati/Duplicati.CommandLine.exe backup “s3://backups-myworkstation/?s3-server-name=s3.amazonaws.com&s3-location-constraint=us-east-1&s3-storage-class=STANDARD&auth-username=redacted&auth-password=redacted” /home/myusername/ --backup-name=myworkstation --dbpath=/home/myusername/.config/Duplicati/GZLCTHFAVK.sqlite --encryption-module=aes --compression-module=zip --dblock-size=50mb --passphrase=“redacted” --retention-policy=“1W:1D,4W:1W,12M:1M” --snapshot-policy=On --disable-module=console-password-input --exclude="*/.cache/google-chrome/Default/Cache/"

Backup started at 9/9/2018 12:52:21 PM
Failed to create a snapshot: System.Exception: The external command failed to start.
Error message: Duplicati.Library.Interface.UserInformationException: The script returned exit code 255, but 0 was expected: Exit code: 255
Error: Not enough free space for snapshot device “elementary-vg/swap_1”

at Duplicati.Library.Snapshots.LinuxSnapshot+SnapShot.ExecuteCommand (System.String program, System.String commandline, System.Int32 expectedExitCode) [0x000d3] in <2be220318a714f97a1ac5d13c83b05be>:0
Command: /usr/lib/duplicati/lvm-scripts/create-lvm-snapshot.sh “duplicati-7492d6a2-0c8b-4faa-bd9e-65b400992ebb” “elementary-vg/swap_1” “/tmp/”
at Duplicati.Library.Snapshots.LinuxSnapshot+SnapShot.ExecuteCommand (System.String program, System.String commandline, System.Int32 expectedExitCode) [0x000e4] in <2be220318a714f97a1ac5d13c83b05be>:0
at Duplicati.Library.Snapshots.LinuxSnapshot+SnapShot.CreateSnapshotVolume () [0x00041] in <2be220318a714f97a1ac5d13c83b05be>:0
at Duplicati.Library.Snapshots.LinuxSnapshot…ctor (System.String sources, System.Collections.Generic.Dictionary2[TKey,TValue] options) [0x000c2] in <2be220318a714f97a1ac5d13c83b05be>:0 at Duplicati.Library.Snapshots.SnapshotUtility.CreateLinuxSnapshot (System.String[] folders, System.Collections.Generic.Dictionary2[TKey,TValue] options) [0x00000] in <2be220318a714f97a1ac5d13c83b05be>:0
at Duplicati.Library.Snapshots.SnapshotUtility.CreateSnapshot (System.String folders, System.Collections.Generic.Dictionary`2[TKey,TValue] options) [0x0000f] in <2be220318a714f97a1ac5d13c83b05be>:0
at Duplicati.Library.Main.Operation.BackupHandler.GetSnapshot (System.String sources, Duplicati.Library.Main.Options options, Duplicati.Library.Main.ILogWriter log) [0x00010] in :0 => The external command failed to start.
Error message: Duplicati.Library.Interface.UserInformationException: The script returned exit code 255, but 0 was expected: Exit code: 255
Error: Not enough free space for snapshot device “elementary-vg/swap_1”

at Duplicati.Library.Snapshots.LinuxSnapshot+SnapShot.ExecuteCommand (System.String program, System.String commandline, System.Int32 expectedExitCode) [0x000d3] in <2be220318a714f97a1ac5d13c83b05be>:0
Command: /usr/lib/duplicati/lvm-scripts/create-lvm-snapshot.sh “duplicati-7492d6a2-0c8b-4faa-bd9e-65b400992ebb” “elementary-vg/swap_1” “/tmp/”
Checking remote backup …
Listing remote folder …
Scanning local files …
3752 files need to be examined (3.68 GB) (still counting)
6048 files need to be examined (7.56 GB) (still counting)
9951 files need to be examined (6.07 GB) (still counting)
14882 files need to be examined (6.18 GB) (still counting)
13981 files need to be examined (2.31 GB)
Failed to process path: /home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf => Invalid handle to path “/home/myusername/.config/skypeforlinux/SkypeRT/ecs.conf”
12961 files need to be examined (1.60 GB)
11392 files need to be examined (1.26 GB)
10207 files need to be examined (1.19 GB)
7577 files need to be examined (582.75 MB)
7576 files need to be examined (385.45 MB)
5766 files need to be examined (337.93 MB)
541 files need to be examined (30.54 MB)
0 files need to be examined (0 bytes)

So it sounds like perhaps the output of lvs isn’t what the script expects? But presumably I don’t want to snapshot swap?

If I try to do lvs --options vg_name, lv_name --noheadings I get:

elementary-vg root
elementary-vg swap_1

If I try to do lvs “/home/myusername” --options vg_name, lv_name --noheadings I get:

“/home/myusername”: Invalid path for Logical Volume

lvs --version
LVM version: 2.02.133(2) (2015-10-30)
Library version: 1.02.110 (2015-10-30)
Driver version: 4.37.0

Did you cd to the same directory where ll showed ecs.conf? If so, I don’t know why fuser isn’t seeing it therefore complaining (instead of the normal result for a not-in-use file where fuser just says nothing).

Keep going through the LVM debug please. I can’t help you much on it, but might try to catch up later.

Installing Skype for Linux here made an ecs.conf after initial login. An fuser didn’t find it in use, and this works:

$ ls -l ~/.config/skypeforlinux/SkypeRT/ecs.conf
-rw------- 1 ted ted 22 Sep  9 15:21 /home/ted/.config/skypeforlinux/SkypeRT/ecs.conf
$ cat ~/.config/skypeforlinux/SkypeRT/ecs.conf

Maybe that file would be longer if I could finish setting up Skype, but this is a test you can try on encrypted or unencrypted home directories to see whether the problem is (or is not) seemingly related to being encrypted. There are quite likely other differences between our systems though. Mine is a highly ordinary Linux Mint VM,