Application Crashes (2.0.6.3)

I’m seeing the application crash from time to time with the following error. Is this useful to the devs?

Faulting application name: Duplicati.GUI.TrayIcon.exe, version: 2.0.6.3, time stamp: 0x60cb15ba
Faulting module name: KERNELBASE.dll, version: 10.0.19041.1706, time stamp: 0x458acb5b
Exception code: 0xe0434352
Fault offset: 0x0000000000034fd9
Faulting process ID: 0x1a6c
Faulting application start time: 0x01d869cb8e4afca5
Faulting application path: C:\ProgramData\Duplicati\updates\2.0.6.3\Duplicati.GUI.TrayIcon.exe
Faulting module path: C:\WINDOWS\System32\KERNELBASE.dll
Report ID: 965afd96-b74a-4306-b227-eff994ca1a4b
Faulting package full name:
Faulting package-relative application ID:

I have uploaded an application crash dump to my OneDrive. Hopefully it’s of some use.

Are you exposing Duplicati to the public internet by chance? (eg, set up port forwarding on your router for port 8200)

Reason I ask is there was another thread recently where a similar issue was reported and public exposure is one possible explanation.

The webserver is not exposed to the internet.

Ok, good to know.

Have you noticed any pattern? Like does this crash happen while Duplicati is running a job?

There’s no pattern in the Application Logs that I can see. This particular time it looks like the application faulted at the beginning of the backup job.

Does it ever happen while no backup job is running (Duplicati should just be idle)?

What OS including version are you running Duplicati on? What back end storage type are you using?

a crash in a system library, with no particular pattern. How about the hardware ? Did you run an advanced memory test, ?

It might need someone who’s good at reading Windows crash dumps. Anybody here able to do that?
Duplicati is written in C#, and so runs almost entirely as managed code under .NET Framework CLR.

One difference is that there the CLR survived long enough to report something about it:

Application: Duplicati.GUI.TrayIcon.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: System.UriFormatException

I think that’s the CLR. You can check yours with About → System info, e.g. mine reports

An interesting lead someone (especially if you know Windows well – I don’t) can check is:

“Exception code: 0xe0434352” in Google gets somewhere, and suggests a CLR problem.

FYI - This catch-all is easy to remember because “434352” is the ASCII for “CCR”. I saw that on MSDN video about debugging CLR.
Kevin S. Miller
Sep 16, 2021 at 20:45

Anybody want to try chasing down what CLR is complaining about (through native code)?

Whatever this is, it seems rare here. It might be environmental, or maybe system-specific.
Repair the .NET Framework might help, and there’s some other troubleshooting info near.

I think the library might just be reporting the CLR problem, but feel free to see if you agree.

Failing that, we can try general system diagnostics (as you suggest) or try to narrow down.

I’m almost certain that this is going to need some help to solve. Anybody who can, go for it.

If @samw is willing to attach a debugger, there’s a chance it will catch something at crash.
dnSpy is one I have used. If you need a newer version, beware that there have been fakes.

I provided the crash dump which can be analysed using any Windows debug tool.

I think Duplicati developers (who are usually on GitHub in the Duplicati C# code) don’t use those.
C# debugging is very different from native debugging. CLR crashes may also need internals info.

Even if you asked Microsoft, they might ask you to try .NET Framework repair or troubleshooting.
I’m asking you, because I don’t have much confidence that dump analysis will get to bottom here.

If you do Windows native debug (I don’t), feel free to have at it. My attempts so far seem to show
internals of CLR state plus only slightest hints of the situation at the Duplicati level. Here’s output:

Microsoft (R) Windows Debugger Version 10.0.22549.1000 AMD64
Copyright (c) Microsoft Corporation. All rights reserved.


Loading Dump File [C:\Users\Me\Downloads\duplicati.application-crashes-2-0-6-314412\Duplicati.GUI.TrayIcon.exe.14220.dmp]
User Mini Dump File: Only registers, stack and portions of memory are available

Symbol search path is: srv*
Executable search path is: 
Windows 10 Version 17134 MP (8 procs) Free x64
Product: WinNt, suite: SingleUserTS
Edition build lab: 17134.1.amd64fre.rs4_release.180410-1804
Machine Name:
Debug session time: Sat Jan 12 07:55:00.000 2019 (UTC - 4:00)
System Uptime: not available
Process Uptime: 0 days 0:00:47.000
......

Press ctrl-c (cdb, kd, ntsd) or ctrl-break (windbg) to abort symbol loads that take too long.
Run !sym noisy before .reload to track down problems loading symbols.

..........................................................
..................
Loading unloaded module list
..
This dump file has an exception of interest stored in it.
The stored exception information can be accessed via .ecxr.
(378c.2368): CLR exception - code e0434352 (first/second chance not available)
For analysis of this file, run !analyze -v
ntdll!NtWaitForMultipleObjects+0x14:
00007fff`eb8cb4f4 c3              ret
0:028> !analyze -v
*******************************************************************************
*                                                                             *
*                        Exception Analysis                                   *
*                                                                             *
*******************************************************************************

DEBUG_FLR_EXCEPTION_CODE(80070015) and the ".exr -1" ExceptionCode(e0434352) don't match

KEY_VALUES_STRING: 1

    Key  : Analysis.CPU.mSec
    Value: 60640

    Key  : Analysis.DebugAnalysisManager
    Value: Create

    Key  : Analysis.Elapsed.mSec
    Value: 114869

    Key  : Analysis.Init.CPU.mSec
    Value: 4046

    Key  : Analysis.Init.Elapsed.mSec
    Value: 114838

    Key  : Analysis.Memory.CommitPeak.Mb
    Value: 267

    Key  : CLR.BuiltBy
    Value: NET472REL1LAST_C

    Key  : CLR.Engine
    Value: CLR

    Key  : CLR.Exception.System.IO.IOException._message
    Value: The device is not ready.

    Key  : CLR.Exception.Type
    Value: System.IO.IOException

    Key  : CLR.Version
    Value: 4.7.3260.0

    Key  : Timeline.Process.Start.DeltaSec
    Value: 47

    Key  : WER.OS.Branch
    Value: rs4_release

    Key  : WER.OS.Timestamp
    Value: 2018-04-10T18:04:00Z

    Key  : WER.OS.Version
    Value: 10.0.17134.1

    Key  : WER.Process.Version
    Value: 2.0.2.1


FILE_IN_CAB:  Duplicati.GUI.TrayIcon.exe.14220.dmp

NTGLOBALFLAG:  0

PROCESS_BAM_CURRENT_THROTTLED: 0

PROCESS_BAM_PREVIOUS_THROTTLED: 0

APPLICATION_VERIFIER_FLAGS:  0

CONTEXT:  (.ecxr)
rax=000001c244532c21 rbx=0000000000000001 rcx=00007fffb043a510
rdx=00007fffb045d230 rsi=000000e1bc87b558 rdi=0000000000000005
rip=00007fffe7c3a388 rsp=000000e1bc87b3e0 rbp=0000023738b0cc48
 r8=00007fffa23b6938  r9=00007fffa23b6938 r10=0000023736b09690
r11=00007fff51aa58b8 r12=0000000000004000 r13=0000023738b0b520
r14=00000000e0434352 r15=0000023738b0b588
iopl=0         nv up ei pl nz na pe nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000202
KERNELBASE!RaiseException+0x68:
00007fff`e7c3a388 488b8c24c0000000 mov     rcx,qword ptr [rsp+0C0h] ss:000000e1`bc87b4a0=00005a075cb1c1c5
Resetting default scope

EXCEPTION_RECORD:  (.exr -1)
ExceptionAddress: 00007fffe7c3a388 (KERNELBASE!RaiseException+0x0000000000000068)
   ExceptionCode: e0434352 (CLR exception)
  ExceptionFlags: 00000001
NumberParameters: 5
   Parameter[0]: ffffffff80070015
   Parameter[1]: 0000000000000000
   Parameter[2]: 0000000000000000
   Parameter[3]: 0000000000000000
   Parameter[4]: 00007fffafd20000

PROCESS_NAME:  Duplicati.GUI.TrayIcon.exe

EXCEPTION_CODE_STR:  80070015

FAULTING_THREAD:  ffffffff

STACK_TEXT:  
000000e1`bc87b770 00007fff`a2743a03 mscorlib_ni!System.IO.__Error.WinIOError+0x443
000000e1`bc87b7c0 00007fff`a357e19e mscorlib_ni!System.IO.FileStream.WriteCore+0xe02aae
000000e1`bc87b830 00007fff`a277b6d8 mscorlib_ni!System.IO.FileStream.FlushWrite+0x28
000000e1`bc87b880 00007fff`a277b861 mscorlib_ni!System.IO.FileStream.Flush+0x21
000000e1`bc87b8c0 00007fff`a277bb7a mscorlib_ni!System.IO.StreamWriter.Flush+0x8a
000000e1`bc87b920 00007fff`a277de37 mscorlib_ni!System.IO.StreamWriter.Write+0xc7
000000e1`bc87b980 00007fff`515efa36 Duplicati.Library.Main.dll!Unknown+0xa6
000000e1`bc87b9e0 00007fff`50e2fdb2 Duplicati.Library.Logging.dll!Unknown+0xd2
000000e1`bc87ba70 00007fff`51aa565a Duplicati.Library.Main.dll!Unknown+0x1da
000000e1`bc87bb20 00007fff`51aa54d2 Duplicati.Library.Main.dll!Unknown+0x52
000000e1`bc87bbd0 00007fff`51a7bf26 Duplicati.Library.Main.dll!Unknown+0xaa6
000000e1`bc87e2d0 00007fff`a27b3a63 mscorlib_ni!System.Threading.ExecutionContext.RunInternal+0x163
000000e1`bc87e3a0 00007fff`a27b38f4 mscorlib_ni!System.Threading.ExecutionContext.Run+0x14
000000e1`bc87e3d0 00007fff`a27b38c2 mscorlib_ni!System.Threading.ExecutionContext.Run+0x52
000000e1`bc87e420 00007fff`a27ad072 mscorlib_ni!System.Threading.ThreadHelper.ThreadStart+0x52


STACK_COMMAND:  !C:\ProgramData\Dbg\sym\SOS_AMD64_AMD64_4.7.3260.00.dll\5BB7BBFD236000\SOS_AMD64_AMD64_4.7.3260.00.dll.pe 0x23738b0cc48 ; ** Pseudo Context ** ManagedPseudo ** Value: ffffffff ** ; kb

SYMBOL_NAME:  mscorlib_ni!System.IO.__Error.WinIOError+443

MODULE_NAME: mscorlib

IMAGE_NAME:  mscorlib.dll

FAILURE_BUCKET_ID:  CLR_EXCEPTION_System.IO.IOException_80070015_mscorlib.dll!System.IO.__Error.WinIOError

BUCKET_ID_MODPRIVATE: 1

OS_VERSION:  10.0.17134.1

BUILDLAB_STR:  rs4_release

OSPLATFORM_TYPE:  x64

OSNAME:  Windows 10

FAILURE_ID_HASH:  {8aecb93e-b0fb-cefc-095d-f47ef3856794}

Followup:     MachineOwner
---------

That was from WinDbg Preview from Microsoft Store, which I tried after Visual Studio 2022 choked:

$exception {The metadata for ‘mscorlib’ is invalid. If you are debugging a minidump, you may be able to fix this problem by collecting a new minidump with heap and evaluating the expression again.} System.IO.IOException

but it chokes less after WinDbg Preview downloaded many files from Microsoft. Still lacks info though.
Or maybe CLR put some clues in the dump. If so, I haven’t found them yet, beyond what’s I just gave.

There, points of interest are the WinIOError (does that look like a failure while writing the dump?), and
seeing Duplicati.Library.Logging present (which might write, but is on other side of a WriteCore).

might apply, including some disk checking, maybe including running SMART tools like CrystalDiskInfo.

EDIT:

CLR_EXCEPTION_System.IO.IOException_80070015_mscorlib.dll!System.IO.__Error.WinIOError

is interpreted below by an HRESULT lookup tool that I found (matches my understanding of 0x15 too)

https://errorcodelookup.com/?q=80070015

image

HRESULT Error Codes is a 7 minute video (I only watched lightly). There’s also some explanation at
2.1 HRESULT which looks pretty good. One interesting thing is the 0x07, FACILITY_WIN32, and not
0x13 (a.k.a. 19) which would be FACILITY_URT “The source of the error code is .NET CLR.”, so did
CLR perhaps die unexpectedly due to a device not ready condition reported by the Win32 API level?

Any Windows developers out there?

interesting. I’d first try to think about what kind of device could be not ready, if the backup is to a USB drive it would be a perfect suspect, if it’s on a cloud backup it would be an unlikely error code (unless it’s accessed as a network drive). Another approach would be to check Windows system (and maybe) application logs at the time of the problem. If a device has failed, it’s very possible that it’s logged there.

Nice debugging.
Somewhere in the code, there’s an unhandled File IO exception (most likely in a thread).

Does Duplicati log the exception in debug mode?
(Settings → Add advanced option → select Debug-output)

Otherwise I’d suggest to add logging unhandled exceptions in debug-output. .net - KERNELBASE.dll Exception 0xe0434352 offset 0x000000000000a49d - Stack Overflow

I haven’t been able to replicate it as yet, but I have noticed this occurs only on first backup or initial run.

@ts678 @gpatel-fr The backup source is a Microsoft Storage Space with drives attached via a USB3 JBOD and the target is a remote SFTP server. I noticed the crashes occur only if the computer is booted after the scheduled backup time (this means Duplicati runs the backup immediately). I suspect the Storage Spaces drives would not have spun up in time. I will try ‘Settings > Pause after startup or hibernation’ feature to see if this will address it. Either way @michael9dk is right that a condition is happening that Dup doesn’t do error handling for.

Are you or @michael9dk C# or Windows developers? I’m not, so this needs some developer help.

Ordinarily I’d have said isolate it to reliable steps that anybody can do, and open an Issue with that.
Nobody has time to search the entire code base, so reproducible issues are more likely to be fixed.

Currently volunteers are needed in all areas of this community effort. Lack of those slows progress.
I’ve made a little myself, and am thinking that the WriteCore was from here in the Microsoft source.

which seems to match the stack showing FlushWrite calling WriteCore which then gets the IOError:

STACK_TEXT:
000000e1bc87b770 00007fffa2743a03 mscorlib_ni!System.IO.__Error.WinIOError+0x443
000000e1bc87b7c0 00007fffa357e19e mscorlib_ni!System.IO.FileStream.WriteCore+0xe02aae
000000e1bc87b830 00007fffa277b6d8 mscorlib_ni!System.IO.FileStream.FlushWrite+0x28

meaning the Core is just an internal name, and has nothing to do with what might be a “core” dump.

I also used an old test program (probably based on Microsoft’s example) with no exception catching.
I can get stack trace output to the console (wouldn’t apply to a Duplicati background server I guess):

C:\VirtualBox shared folder\backup\Linux Mint 19.3>.\GetDirectories.exe \\127.0.0.1\missing

Unhandled Exception: System.IO.IOException: The network name cannot be found.

   at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
   at System.IO.FileSystemEnumerableIterator`1.CommonInit()
   at System.IO.FileSystemEnumerableIterator`1..ctor(String path, String originalUserPath, String searchPattern, SearchOption searchOption, SearchResultHandler`1 resultHandler, Boolean checkHost)
   at System.IO.Directory.GetDirectories(String path)
   at RecursiveFileProcessor.ProcessDirectory(String targetDirectory)
   at RecursiveFileProcessor.Main(String[] args)

C:\VirtualBox shared folder\backup\Linux Mint 19.3>

I got two Application event log entries, Source .NET Runtime and then Source Application Error.
Are you getting both? Reporting differences might account for the seemingly different issue reporting.

Application: GetDirectories.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: System.IO.IOException
   at System.IO.__Error.WinIOError(Int32, System.String)
   at System.IO.FileSystemEnumerableIterator`1[[System.__Canon, mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089]].CommonInit()
   at System.IO.FileSystemEnumerableIterator`1[[System.__Canon, mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089]]..ctor(System.String, System.String, System.String, System.IO.SearchOption, System.IO.SearchResultHandler`1<System.__Canon>, Boolean)
   at System.IO.Directory.GetDirectories(System.String)
   at RecursiveFileProcessor.ProcessDirectory(System.String)
   at RecursiveFileProcessor.Main(System.String[])

then

Faulting application name: GetDirectories.exe, version: 0.0.0.0, time stamp: 0x600cd8b1
Faulting module name: KERNELBASE.dll, version: 10.0.19041.1706, time stamp: 0x458acb5b
Exception code: 0xe0434352
Fault offset: 0x0000000000034fd9
Faulting process id: 0x7a94
Faulting application start time: 0x01d8705050f37e0b
Faulting application path: C:\VirtualBox shared folder\backup\Linux Mint 19.3\GetDirectories.exe
Faulting module path: C:\Windows\System32\KERNELBASE.dll
Report Id: 38732e4d-5c55-4e65-b276-988620091489
Faulting package full name: 
Faulting package-relative application ID: 

Do you use a log-file Advanced option? I see Duplicati.Library.Logging.dll on your dump stack.

Trying to search through all of the source code files, I’m not finding that debug mode does a whole lot.
The uses I saw seemed to Output.WriteLine an Exception.ToString instead of the Exception.Message.

Generally though, exceptions act caught, handled, and logged if one sets a log file at the level for that.
If event log is truly a useful supplement (was it in this case, after a look?), that would be good to know.

Default Duplicati logging goes to the overly-summarized-for-good-debugging ordinary backup job logs,
less organized server logs at About → Show log → Stored for major fails (annoying split – open issue).

For manual analysis of an easily repeatable issue, there’s also the server live log. For harder-to-catch problems, setting up a log file is best, but these can get huge over time at detailed levels, e.g. profiling.

I tried looking for an unhandled exception catcher. Found a possible, but maybe just for command line.
Seeming handler is here (do you agree that’s the unhandled exception catcher?), and setup for it here.

I don’t think debug-output gets much use, but we’re always moving the regular log levels up and down.
Warning level (which it seems is default for a log file anyway) “might” catch something during the crash assuming there’s something spotted before it all goes down. Information level is a bit more but not bad.

  --log-file-log-level (Enumeration): Log file information level
    Log file information level
    * values: ExplicitOnly, Profiling, Verbose, Retry, Information, DryRun,
    Warning, Error
    * default value: Warning

I have added a pause after start up and not seen the issue since. In the interest of getting this identified I have disabled the pause, enabled debug mode. I’m not sure where debug mode output gets logged?

I have log output on my job with informational logging. I don’t see any errors in the log at all and I believe the crash occurs before the job even writes anything to disk.

I’ll keep you posted.

and all such uses are in a source file at CommandLine\ConsoleOutput.cs, which I doubt applies here.
This sounds like what Duplicati.CommandLine.exe may use, i.e. when it’s run at a Command Prompt.

Console.WriteLine Method looks like what it winds up doing, based on my attempt to trace to its base.
Getting output back from background processes is more involved. Duplicati has logs, but there’s also

as discussed earlier, and now I notice that there’s a third entry made. Which of these are you finding?

It’s a somewhat extreme step, but Sysinternals Process Monitor gives a pretty good view of file action.
If logging to virtual memory, be careful or you might swamp your system. Acronis gave some tips here.

1 Like

So I can replicate the behaviour and it crashes always at the beginning of the backup. It doesn’t look like it gets to the stage where it’s actually reading data from the drive at all. This is most likely caused by either BitLocker or Storage Spaces not making the drive available at the time of the backup. Almost like the volume exists, but is not accessible when Duplicati attempts to access it.

I can mitigate this behaviour by using the pause on start up/hibernate feature and pause the backup job for a few minutes.

I’m not sure whether there’s something that can be added to Duplicati to catch this sort of event. I suppose this thread can be closed and archived in case a developer comes across it.

Thanks for the input everyone and especially @ts678 for the debugging.