search

Berimor66 / duplicati

Automatically exported from code.google.com/p/duplicati
0 stars 0 forks source link

Failed after uploading x volume(s). Error message: Exception has been thrown by the target of an invocation. #747

Open GoogleCodeExporter opened 9 years ago

GoogleCodeExporter commented 9 years ago 
What steps will reproduce the problem?
1. Define Backup for directory with content >10MB
2. start backup
3. after some volumes (1-14 seen) backup fails, error message in log: "Failed 
after uploading 7 volume(s). Error message: Exception has been thrown by the 
target of an invocation."

What is the expected output? What do you see instead?
Backup works.                Backup fails.

What version of Duplicati are you using? On what operating system?
Version=1.3.3.1457 on Win XP SP3.
.NETs installed:
1.1
2.0 SP2
3.0 SP2
3.5 SP1

What backend (destination) are you using?
Local Disk, unencrypted

Please provide any additional information below.
Tried multiple times, backup fails every time. First I suspected virus scanner 
(Avira), but turning it off makes no difference. VSS test using 
Duplicati.Library.Snapshots.exe passes ok, so that could also be ruled out.

Interesting enough, when I active encryption by setting a password, the error 
message changes sometimes to "Failed after uploading 2 volume(s). Error 
message: The process cannot access the file 
'F:\tmp\63cfb056-22c7-4f35-9e60-a8d9d145fe09' because it is being used by 
another process." Seems like encrypting the temporary zipfile fails?

Rebooted, re-installed, tried Version=1.3.2, tried different targets (NAS), 
different sources. No luck.

Alway reproducible.

Original issue reported on code.google.com by soski...@gmail.com on 10 Nov 2012 at 10:43

GoogleCodeExporter commented 9 years ago 
ProcMon shows error on

360485  23:58:30,9612164    Duplicati.exe   2448    CreateFile  F:\tmp\253ae9c4-0bbd-4932-
a671-5bc1bc2aac0a   SHARING VIOLATION   Desired Access: Generic Read/Write, 
Disposition: OverwriteIf, Options: Synchronous IO Non-Alert, Non-Directory 
File, Open No Recall, Attributes: n/a, ShareMode: None, AllocationSize: 0

Different file name now, but it's always the one from the duplicati error 
message, which shows up as sharing violation in ProcMon

Original comment by soski...@gmail.com on 10 Nov 2012 at 11:03

GoogleCodeExporter commented 9 years ago 
Great debugging!

The "Sharing Violation" means that multiple processes are trying to access the 
file.

This can occurs for a number of reasons. Can you try to filter ProcMon to see 
what which processes (and operations) are performed on that exact file?

I would like to know if any other process has touched the file, as that would 
rule out any internal stuff in Duplicati. The encryption changes can trigger 
different stuff because it will touch the file multiple times when encrypting 
it.

The error message "Exception has been thrown by the target of an invocation." 
is an annoying message that actually hides the real error message. Try setting 
the advanced option "debug-output" to "true", and there will be more detail 
reported for that error.

Original comment by kenneth@hexad.dk on 13 Nov 2012 at 9:36

GoogleCodeExporter commented 9 years ago 
Seems like the AV programs gets in the way (although it's deactivated and the 
folder excluded, but that's a different story I'll sort out with the AV 
company):

88548   14:43:06,6556082    avguard.exe 532 CreateFile  F:\tmp\0e5217bd-b4f6-45ab-b965
-23285735adc5   SUCCESS Desired Access: Generic Read, Disposition: Open, Options: 
Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, 
Write, Delete, AllocationSize: n/a, OpenResult: Opened
88549   14:43:06,6556652    avguard.exe 532 ReadFile    F:\tmp\0e5217bd-b4f6-45ab-b965-2
3285735adc5 END OF FILE Offset: 0, Length: 1.024
88551   14:43:06,6558079    Duplicati.exe   3912    CreateFile  F:\tmp\830e87f3-779b-4cb5-a
d27-ba71271c53ec    SUCCESS Desired Access: Generic Read, Disposition: Open, 
Options: Synchronous IO Non-Alert, Non-Directory File, Open No Recall, 
Attributes: n/a, ShareMode: Read, AllocationSize: n/a, OpenResult: Opened
88552   14:43:06,6559348    Duplicati.exe   3912    CreateFile  F:\tmp\0e5217bd-b4f6-45ab-b
965-23285735adc5    SHARING VIOLATION   Desired Access: Generic Read/Write, 
Disposition: OverwriteIf, Options: Synchronous IO Non-Alert, Non-Directory 
File, Open No Recall, Attributes: n/a, ShareMode: None, AllocationSize: 0
88553   14:43:06,6560420    Duplicati.exe   3912    CreateFile  F:\tmp  SUCCESS Desired 
Access: Synchronize, Disposition: Open, Options: Directory, Synchronous IO 
Non-Alert, Open For Backup, Attributes: N, ShareMode: Read, Write, 
AllocationSize: n/a, OpenResult: Opened
88554   14:43:06,6560856    Duplicati.exe   3912    CloseFile   F:\tmp  SUCCESS 
88556   14:43:06,6563591    Duplicati.exe   3912    CloseFile   F:\tmp\830e87f3-779b-4cb5-ad
27-ba71271c53ec SUCCESS 
88558   14:43:06,6564622    Duplicati.exe   3912    QueryOpen   F:\tmp\0e5217bd-b4f6-45ab-b9
65-23285735adc5 SUCCESS CreationTime: 18.11.2012 14:43:06, LastAccessTime: 
18.11.2012 14:43:06, LastWriteTime: 18.11.2012 14:43:06, ChangeTime: 18.11.2012 
14:43:06, AllocationSize: 0, EndOfFile: 0, FileAttributes: A
88559   14:43:06,6565379    Duplicati.exe   3912    ReadFile    F:\tmp\7073c13a-fbaa-4ffc-bce
9-d6162e55508d  SUCCESS Offset: 262.144, Length: 65.536
88561   14:43:06,6570179    Duplicati.exe   3912    WriteFile   F:\Temp\1\dc\duplicati-inc-c
ontent.20121118T134258Z.vol1.zip.aes    FAST IO DISALLOWED  Offset: 262.144, 
Length: 65.536
88563   14:43:06,6571081    Duplicati.exe   3912    WriteFile   F:\Temp\1\dc\duplicati-inc-c
ontent.20121118T134258Z.vol1.zip.aes    SUCCESS Offset: 262.144, Length: 65.536
88564   14:43:06,6572165    Duplicati.exe   3912    ReadFile    F:\tmp\7073c13a-fbaa-4ffc-bce
9-d6162e55508d  SUCCESS Offset: 327.680, Length: 65.536
88566   14:43:06,6573576    Duplicati.exe   3912    WriteFile   F:\Temp\1\dc\duplicati-inc-c
ontent.20121118T134258Z.vol1.zip.aes    FAST IO DISALLOWED  Offset: 327.680, 
Length: 65.536
88568   14:43:06,6574433    Duplicati.exe   3912    WriteFile   F:\Temp\1\dc\duplicati-inc-c
ontent.20121118T134258Z.vol1.zip.aes    SUCCESS Offset: 327.680, Length: 65.536
88569   14:43:06,6575350    Duplicati.exe   3912    ReadFile    F:\tmp\7073c13a-fbaa-4ffc-bce
9-d6162e55508d  SUCCESS Offset: 393.216, Length: 65.536
88571   14:43:06,6579962    Duplicati.exe   3912    WriteFile   F:\Temp\1\dc\duplicati-inc-c
ontent.20121118T134258Z.vol1.zip.aes    FAST IO DISALLOWED  Offset: 393.216, 
Length: 65.536
88573   14:43:06,6580848    Duplicati.exe   3912    WriteFile   F:\Temp\1\dc\duplicati-inc-c
ontent.20121118T134258Z.vol1.zip.aes    SUCCESS Offset: 393.216, Length: 65.536
88574   14:43:06,6581878    Duplicati.exe   3912    ReadFile    F:\tmp\7073c13a-fbaa-4ffc-bce
9-d6162e55508d  SUCCESS Offset: 458.752, Length: 65.536
88576   14:43:06,6586401    Duplicati.exe   3912    WriteFile   F:\Temp\1\dc\duplicati-inc-c
ontent.20121118T134258Z.vol1.zip.aes    FAST IO DISALLOWED  Offset: 458.752, 
Length: 65.536
88577   14:43:06,6587195    Duplicati.exe   3912    WriteFile   F:\Temp\1\dc\duplicati-inc-c
ontent.20121118T134258Z.vol1.zip.aes    SUCCESS Offset: 458.752, Length: 65.536
88578   14:43:06,6588784    Duplicati.exe   3912    ReadFile    F:\tmp\7073c13a-fbaa-4ffc-bce
9-d6162e55508d  SUCCESS Offset: 524.288, Length: 65.536
88580   14:43:06,6590212    Duplicati.exe   3912    WriteFile   F:\Temp\1\dc\duplicati-inc-c
ontent.20121118T134258Z.vol1.zip.aes    FAST IO DISALLOWED  Offset: 524.288, 
Length: 65.536
88582   14:43:06,6590821    avguard.exe 532 CloseFile   F:\tmp\0e5217bd-b4f6-45ab-b965-
23285735adc5    SUCCESS 

Duplicati Log:
Error: The process cannot access the file 
'F:\tmp\0e5217bd-b4f6-45ab-b965-23285735adc5' because it is being used by 
another process.

Error: System.IO.IOException: The process cannot access the file 
'F:\tmp\0e5217bd-b4f6-45ab-b965-23285735adc5' because it is being used by 
another process.
   at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
   at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy)
   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options)
   at Duplicati.Library.Encryption.EncryptionBase.Encrypt(String inputfile, String outputfile)
   at Duplicati.Library.Main.BackendWrapper.Put(BackupEntryBase remote, String filename, Boolean forcesync)
   at Duplicati.Library.Main.Interface.Backup(String[] sources)
   at Duplicati.GUI.DuplicatiRunner.ExecuteTask(IDuplicityTask task)
Cleanup output:

I think the problem is that the AV program opened with Read access but 
Duplicati requested also Read "exclusive". 
Is it possible to change the access mode of Duplicate so it's only Write 
Exclusive and not Read Exclusive? Or some other way "virus scanner aware"?

Original comment by soski...@gmail.com on 18 Nov 2012 at 7:15

GoogleCodeExporter commented 9 years ago 
Yes, that is possible, but I think there will be other problems then, because 
Duplicati will eventually try to delete the file which cannot happen while it 
is open.

One solution would be to change the Duplicati temp folder and then setup the AV 
to exclude that particular folder.

Original comment by kenneth@hexad.dk on 20 Nov 2012 at 10:19

GoogleCodeExporter commented 9 years ago 
Yes, that is possible, but I think there will be other problems then, because 
Duplicati will eventually try to delete the file which cannot happen while it 
is open.

One solution would be to change the Duplicati temp folder and then setup the AV 
to exclude that particular folder.

Original comment by kenneth@hexad.dk on 20 Nov 2012 at 10:20