2.0.4.27_canary_2019-09-03 - Stuck in loop Verifying Files (appears to be crashing)

Support
1

Since upgrading to the latest canary (2.0.4.27_canary_2019-09-03) from .26 my jobs are now stuck in a loop verifying files

The app also likes to kick me out every 5 minutes or so. It appears from syslog that duplicati keeps crashing

 tail -f /var/log/syslog
Sep  4 22:55:13 vm1 duplicati-server[10620]: used by your application.
Sep  4 22:55:13 vm1 duplicati-server[10620]: =================================================================
Sep  4 22:55:13 vm1 systemd[1]: duplicati.service: Main process exited, code=exited, status=134/n/a
Sep  4 22:55:13 vm1 systemd[1]: duplicati.service: Failed with result 'exit-code'.
Sep  4 22:55:13 vm1 systemd[1]: duplicati.service: Service hold-off time over, scheduling restart.
Sep  4 22:55:13 vm1 systemd[1]: duplicati.service: Scheduled restart job, restart counter is at 22.
Sep  4 22:55:13 vm1 systemd[1]: Stopped Duplicati web-server.
Sep  4 22:55:13 vm1 systemd[1]: Started Duplicati web-server.
Sep  4 22:56:11 vm1 systemd[1]: Started Session 15 of user jt.
Sep  4 22:56:14 vm1 systemd-resolved[795]: Server returned error NXDOMAIN, mitigating potential DNS violation DVE-2018-0001, retrying transaction with reduced feature level UDP.
2

full stack trace from syslog

Sep  4 22:55:13 vm1 duplicati-server[10620]: used by your application.
Sep  4 22:55:13 vm1 duplicati-server[10620]: =================================================================
Sep  4 22:55:13 vm1 systemd[1]: duplicati.service: Main process exited, code=exited, status=134/n/a
Sep  4 22:55:13 vm1 systemd[1]: duplicati.service: Failed with result 'exit-code'.
Sep  4 22:55:13 vm1 systemd[1]: duplicati.service: Service hold-off time over, scheduling restart.
Sep  4 22:55:13 vm1 systemd[1]: duplicati.service: Scheduled restart job, restart counter is at 22.
Sep  4 22:55:13 vm1 systemd[1]: Stopped Duplicati web-server.
Sep  4 22:55:13 vm1 systemd[1]: Started Duplicati web-server.
Sep  4 22:56:11 vm1 systemd[1]: Started Session 15 of user jt.
Sep  4 22:56:14 vm1 systemd-resolved[795]: Server returned error NXDOMAIN, mitigating potential DNS violation DVE-2018-0001, retrying transaction with reduced feature level UDP.
Sep  4 22:59:57 vm1 duplicati-server[10705]: * Assertion at local-propagation.c:330, condition `ins->opcode > MONO_CEE_LAST' not met
Sep  4 22:59:57 vm1 duplicati-server[10705]: Stacktrace:
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at <unknown> <0xffffffff>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at System.Collections.Generic.Dictionary`2<string, int>.Insert (string,int,bool) <0x0006b>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at System.Collections.Generic.Dictionary`2<string, int>.Add (string,int) <0x0001b>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at MimeKit.Utils.CharsetUtils.AddAliases (System.Collections.Generic.Dictionary`2<string, int>,int,int,string[]) <0x0006c>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at MimeKit.Utils.CharsetUtils..cctor () <0x002b3>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at (wrapper runtime-invoke) object.runtime_invoke_void (object,intptr,intptr,intptr) <0x00062>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at <unknown> <0xffffffff>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at (wrapper managed-to-native) object.__icall_wrapper_mono_generic_class_init (intptr) <0x00059>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at MimeKit.ParserOptions..ctor () <0x000cf>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at MimeKit.ParserOptions..cctor () <0x0007b>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at (wrapper runtime-invoke) object.runtime_invoke_void (object,intptr,intptr,intptr) <0x00062>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at <unknown> <0xffffffff>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at Duplicati.Library.Modules.Builtin.SendMail.SendMessage (string,string) <0x00157>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at Duplicati.Library.Modules.Builtin.ReportHelper.OnFinish (object) <0x00842>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at Duplicati.Library.Main.Controller.OnOperationComplete (object) <0x003b3>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at Duplicati.Library.Main.Controller.RunAction<T_REF> (T_REF,string[]&,Duplicati.Library.Utility.IFilter&,System.Action`1<T_REF>) <0x00747>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at Duplicati.Library.Main.Controller.Backup (string[],Duplicati.Library.Utility.IFilter) <0x002fb>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at Duplicati.Server.Runner.Run (Duplicati.Server.Runner/IRunnerData,bool) <0x011d7>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at Duplicati.Server.Program/<>c.<SetWorkerThread>b__45_0 (Duplicati.Server.Runner/IRunnerData) <0x00017>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at Duplicati.Library.Utility.WorkerThread`1<Tx_REF>.Runner () <0x005da>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at System.Threading.ThreadHelper.ThreadStart_Context (object) <0x00099>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext,System.Threading.ContextCallback,object,bool) <0x00178>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext,System.Threading.ContextCallback,object,bool) <0x00020>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext,System.Threading.ContextCallback,object) <0x00059>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at System.Threading.ThreadHelper.ThreadStart () <0x0002e>
Sep  4 22:59:57 vm1 duplicati-server[10705]:   at (wrapper runtime-invoke) object.runtime_invoke_void__this__ (object,intptr,intptr,intptr) <0x000d1>
Sep  4 22:59:57 vm1 duplicati-server[10705]: Native stacktrace:
Sep  4 22:59:57 vm1 duplicati-server[10705]: #011/usr/bin/mono-sgen(+0xc8514) [0x5559b48c5514]
Sep  4 22:59:57 vm1 duplicati-server[10705]: #011/lib/x86_64-linux-gnu/libpthread.so.0(+0x12890) [0x7fb9414c4890]
Sep  4 22:59:57 vm1 duplicati-server[10705]: #011/lib/x86_64-linux-gnu/libc.so.6(gsignal+0xc7) [0x7fb940ee7e97]
Sep  4 22:59:57 vm1 duplicati-server[10705]: #011/lib/x86_64-linux-gnu/libc.so.6(abort+0x141) [0x7fb940ee9801]
Sep  4 22:59:57 vm1 duplicati-server[10705]: #011/usr/bin/mono-sgen(+0x289769) [0x5559b4a86769]
Sep  4 22:59:57 vm1 duplicati-server[10705]: #011/usr/bin/mono-sgen(+0x2899fc) [0x5559b4a869fc]
Sep  4 22:59:57 vm1 duplicati-server[10705]: #011/usr/bin/mono-sgen(+0x289b93) [0x5559b4a86b93]
Sep  4 22:59:57 vm1 duplicati-server[10705]: #011/usr/bin/mono-sgen(+0x962ab) [0x5559b48932ab]
Sep  4 22:59:57 vm1 duplicati-server[10705]: #011/usr/bin/mono-sgen(+0x12d5da) [0x5559b492a5da]
Sep  4 22:59:57 vm1 duplicati-server[10705]: #011/usr/bin/mono-sgen(+0x12df39) [0x5559b492af39]
Sep  4 22:59:57 vm1 duplicati-server[10705]: #011/usr/bin/mono-sgen(+0x3c170) [0x5559b4839170]
Sep  4 22:59:57 vm1 duplicati-server[10705]: #011/usr/bin/mono-sgen(+0xc9ef6) [0x5559b48c6ef6]
Sep  4 22:59:57 vm1 duplicati-server[10705]: #011/usr/bin/mono-sgen(+0xcaaa5) [0x5559b48c7aa5]
Sep  4 22:59:57 vm1 duplicati-server[10705]: #011[0x41813698]
Sep  4 22:59:57 vm1 duplicati-server[10705]: Debug info from gdb:
Sep  4 22:59:57 vm1 duplicati-server[10705]: =================================================================
Sep  4 22:59:57 vm1 duplicati-server[10705]: Got a SIGABRT while executing native code. This usually indicates
Sep  4 22:59:57 vm1 duplicati-server[10705]: a fatal error in the mono runtime or one of the native libraries
Sep  4 22:59:57 vm1 duplicati-server[10705]: used by your application.
Sep  4 22:59:57 vm1 duplicati-server[10705]: =================================================================
Sep  4 22:59:58 vm1 systemd[1]: duplicati.service: Main process exited, code=exited, status=134/n/a
Sep  4 22:59:58 vm1 systemd[1]: duplicati.service: Failed with result 'exit-code'.
Sep  4 22:59:58 vm1 systemd[1]: duplicati.service: Service hold-off time over, scheduling restart.
Sep  4 22:59:58 vm1 systemd[1]: duplicati.service: Scheduled restart job, restart counter is at 23.
Sep  4 22:59:58 vm1 systemd[1]: Stopped Duplicati web-server.
Sep  4 22:59:58 vm1 systemd[1]: Started Duplicati web-server.
3

After reading some other forum posts I checked the version of mono i was running. Turns out this was version 4.x. Upgraded to the latest 6.x branch and touch wood, its working okay at the moment. Will report back if the backup job completes without issue.

Is it worth mentioning that Duplicati - 2.0.4.27_canary_2019-09-03 requires mono version 6?

Duplicati - 2.0.4.26 worked fine for me on the version 4 of mono. This is running on Ubuntu 18

4

Glad you got it sorted. Mono v5 and higher is required. Yes… some documentation needs to be updated.

5

In principle, Duplicati should run on any version of Mono (provided it supports the framework version).
But more recent versions have more bug-fixes, so I would recommend using updated versions.

The error, as you can see in the trace, is something related to sending email from the MimeKit library. Most likely it is calling a native library for handling charset encoding, and this broke.

6

for reference, this is what I had to do to install mono 6 on ubuntu 18.04

sudo apt install gnupg ca-certificates
sudo apt-key adv --keyserver hkp://keyserver.ubuntu.com:80 --recv-keys 3FA7E0328081BFF6A14DA29AA6A19B38D3D831EF
echo "deb https://download.mono-project.com/repo/ubuntu stable-bionic main" | sudo tee /etc/apt/sources.list.d/mono-official-stable.list
sudo apt update
sudo apt install mono-devel mono-complete
7

It’s weird, worked previously with zero issue on .26 - must be something in the code cleanup that changed

It might be worth adding to the release notes post?

8

The installation of mono is in the docs.
https://duplicati.readthedocs.io/en/latest/02-installation/

Though perhaps having a link to the mono installation on the download page would be helpful?

Annotation%202019-09-05%20070510
Annotation 2019-09-05 070510.png965×469 21 KB

9

Yep I see its in the docs. My VM was a setup a while ago and at a guess, the version of mono that ships with ubuntu (if you haven’t added the repo) is likely the out dated version.

I suggested adding the info to the release post for users that have current installs and are using the default mono shipped with ubuntu?

Edit: From https://launchpad.net/ubuntu/bionic/+source/mono, the current version shipped with Ubuntu 18.04 without the mono repo added is 4.6.2.7+dfsg-1ubuntu1

10

Future release notes should probably ask for mono v5 to match the new framework 4.6.2. Of course later v5.x.x likely work better than mono 5.0.0 which is very rare. Early v6 (maybe even latest) broke OneDrive, however mono developers have a workaround environment variable that maybe Duplicati should also use.

11

I imagine all these issues will be fixed by moving to dot net core? Is there somewhere to track progress on a dot net core implementation?

12

I would move all platforms to the single .net runtime.

There is a current PR being worked to move to stadnard2.0 and that runtme.