I’m running Duplicati 2.0.5.1_beta_2020-01-18 on Ubuntu 20.04 on a tinkerboard. It has been working for for quite some time. However recently I’ve been getting crash messages in my system log. It appears to be crashing while constructing email messages. I’m running a local Postfix mail server and that is working fine for other applications.
Did that go in when the problem began? That would be very solid evidence of a link. Check file times.
Possibly ls -lcrt /usr/lib/libmono* will give you a date. I’m far from a mono internals expert…
If mono had a regression, you can watch their issue for a response, and also try downgrading mono.
Duplicati 2.0.5.1 Beta needs at least mono version 5, and the next Beta will need at least mono 5.10.
Download at bottom has official advice on old mono versions. I’d note they also have newer previews.
There is unofficial advice elsewhere on the Internet about old mono versions. Maybe some will fit you.
The mono files were written December 19th, 2020. I don’t believe I had problems for that long. Although it appears that duplicati only crashes when trying to send an email.
Looking at logs over the past week my recent backups have been working, but I do have a warning that I haven’t seen before.
[Warning-Duplicati.Library.DynamicLoader.DynamicLoader`1-SoftError]: Failed to load process type System.Reactive.Concurrency.DispatcherScheduler assembly /usr/lib/duplicati/System.Reactive.dll, error message: Could not load type of field 'System.Reactive.Concurrency.DispatcherScheduler:<Dispatcher>k__BackingField' (0) due to: Could not load file or assembly 'WindowsBase, Version=4.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35' or one of its dependencies.
This backup would have tried to generate an email due to the warnings and duplicati crashed again trying to send an email.
The SEND-MAIL command can test that by itself, and you can probably watch About → Show log → Live → Profiling to see a backup-free log of interactions with the mail server, but I’m not certain it ran that long.
Sometimes true CLI puts out additional messages, so you could Export As Command-line and either just run regular backup (or backup enhanced with –send-mail-level=all) or convert the command to send-mail.
You could test a profiling log with a small backup, because a big backup will produce an enormous log file. As mentioned before, doing the small backup on true CLI might also reveal more, but no promises on that.
I installed mono-complete and restarted duplicati.
I then did a small backup and told it to always send email and added a profiling log.
This is the end of the log
2021-02-19 20:18:00 -06 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: Starting - RemoteOperationGet
2021-02-19 20:18:00 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b2063ce4f26ec48c790656c8cbbdb11e2.dblock.zip.aes (33.38 MB)
2021-02-19 20:18:04 -06 - [Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed]: Downloaded 33.38 MB in 00:00:04.4141050, 7.56 MB/s
2021-02-19 20:18:04 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b2063ce4f26ec48c790656c8cbbdb11e2.dblock.zip.aes (33.38 MB)
2021-02-19 20:18:04 -06 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: RemoteOperationGet took 0:00:00:04.427
2021-02-19 20:18:04 -06 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: Starting - ExecuteNonQuery: UPDATE "RemoteVolume" SET "VerificationCount" = MAX(1, CASE WHEN "VerificationCount" <= 0 THEN (SELECT MAX("VerificationCount") FROM "RemoteVolume") ELSE "VerificationCount" + 1 END) WHERE "Name" = "duplicati-b2063ce4f26ec48c790656c8cbbdb11e2.dblock.zip.aes"
2021-02-19 20:18:04 -06 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: ExecuteNonQuery: UPDATE "RemoteVolume" SET "VerificationCount" = MAX(1, CASE WHEN "VerificationCount" <= 0 THEN (SELECT MAX("VerificationCount") FROM "RemoteVolume") ELSE "VerificationCount" + 1 END) WHERE "Name" = "duplicati-b2063ce4f26ec48c790656c8cbbdb11e2.dblock.zip.aes" took 0:00:00:00.008
2021-02-19 20:18:05 -06 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: Starting - ExecuteNonQuery: DELETE FROM "LogData" WHERE "Timestamp" < 1611195485
2021-02-19 20:18:05 -06 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: ExecuteNonQuery: DELETE FROM "LogData" WHERE "Timestamp" < 1611195485 took 0:00:00:00.001
2021-02-19 20:18:05 -06 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: Starting - ExecuteNonQuery: DELETE FROM "RemoteOperation" WHERE "Timestamp" < 1611195485
2021-02-19 20:18:05 -06 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: ExecuteNonQuery: DELETE FROM "RemoteOperation" WHERE "Timestamp" < 1611195485 took 0:00:00:00.001
2021-02-19 20:18:05 -06 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: Starting - ExecuteNonQuery: PRAGMA optimize
2021-02-19 20:18:05 -06 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: ExecuteNonQuery: PRAGMA optimize took 0:00:00:00.000
2021-02-19 20:18:05 -06 - [Profiling-Timer.Finished-Duplicati.Library.Main.Controller-RunBackup]: Running Backup took 0:00:02:08.215
This is my system log for that time period:
Feb 19 20:18:05 tinker duplicati-server[2694]: =================================================================
Feb 19 20:18:05 tinker duplicati-server[2694]: #011Native Crash Reporting
Feb 19 20:18:05 tinker duplicati-server[2694]: =================================================================
Feb 19 20:18:05 tinker duplicati-server[2694]: Got a SIGSEGV while executing native code. This usually indicates
Feb 19 20:18:05 tinker duplicati-server[2694]: a fatal error in the mono runtime or one of the native libraries
Feb 19 20:18:05 tinker duplicati-server[2694]: used by your application.
Feb 19 20:18:05 tinker duplicati-server[2694]: =================================================================
Feb 19 20:18:05 tinker duplicati-server[2694]: =================================================================
Feb 19 20:18:05 tinker duplicati-server[2694]: #011Native stacktrace:
Feb 19 20:18:05 tinker duplicati-server[2694]: =================================================================
Feb 19 20:18:05 tinker duplicati-server[2694]: #011 (No frames)
Feb 19 20:18:05 tinker duplicati-server[2694]: =================================================================
Feb 19 20:18:05 tinker duplicati-server[2694]: #011Telemetry Dumper:
Feb 19 20:18:05 tinker duplicati-server[2694]: =================================================================
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2973754416x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2966410288x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2982143024x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2962220080x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2997875760x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2968515632x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x3060397104x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2903499824x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2978985008x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x3003409456x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2974807088x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2981090352x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2967462960x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2983195696x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2977932336x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x3069987264x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2963272752x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2904552496x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2991584304x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x3001021488x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2985907248x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2980037680x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Pkilling 0x2960114736x from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[3247]: Could not exec mono-hang-watchdog, expected on path '/etc/../bin/mono-hang-watchdog' (errno 2)
Feb 19 20:18:05 tinker duplicati-server[2694]: Entering thread summarizer pause from 0x2994730032x
Feb 19 20:18:05 tinker duplicati-server[2694]: Finished thread summarizer pause from 0x2994730032x.
Feb 19 20:18:05 tinker duplicati-server[2694]: Failed to create breadcrumb file (null)/crash_hash_0x7f75a5a7c
Feb 19 20:18:05 tinker duplicati-server[2694]: Waiting for dumping threads to resume
Feb 19 20:18:06 tinker duplicati-server[3249]: =================================================================
Feb 19 20:18:06 tinker duplicati-server[3249]: #011External Debugger Dump:
Feb 19 20:18:06 tinker duplicati-server[3249]: =================================================================
Feb 19 20:18:06 tinker duplicati-server[3249]: mono_gdb_render_native_backtraces not supported on this platform, unable to find gdb or lldb
Feb 19 20:18:06 tinker duplicati-server[2694]: =================================================================
Feb 19 20:18:06 tinker duplicati-server[2694]: #011Basic Fault Address Reporting
Feb 19 20:18:06 tinker duplicati-server[2694]: =================================================================
Feb 19 20:18:06 tinker duplicati-server[2694]: Memory around native instruction pointer (0xb6f42d64):0xb6f42d54 00 01 30 bc 70 47 00 bf 2d e9 f0 4f 87 b0 00 bf ..0.pG..-..O....
Feb 19 20:18:06 tinker duplicati-server[2694]: 0xb6f42d64 45 6a eb 08 00 f0 9a 81 15 f0 01 05 06 46 56 f8 Ej...........FV.
Feb 19 20:18:06 tinker duplicati-server[2694]: 0xb6f42d74 20 3f 04 46 18 bf 80 25 0e e0 43 f0 01 01 56 e8 ?.F...%..C...V.
Feb 19 20:18:06 tinker duplicati-server[2694]: 0xb6f42d84 00 2f 9a 42 05 d1 46 e8 00 10 00 28 f7 d1 bf f3 ./.B..F....(....
Feb 19 20:18:06 tinker duplicati-server[2694]: =================================================================
Feb 19 20:18:06 tinker duplicati-server[2694]: #011Managed Stacktrace:
Feb 19 20:18:06 tinker duplicati-server[2694]: =================================================================
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at <unknown> <0xffffffff>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at System.Object:__icall_wrapper_mono_generic_class_init <0x00037>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at MimeKit.ParserOptions:.ctor <0x000a3>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at MimeKit.ParserOptions:.cctor <0x00077>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at System.Object:runtime_invoke_void <0x0007b>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at <unknown> <0xffffffff>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at Duplicati.Library.Modules.Builtin.SendMail:SendMessage <0x00117>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at Duplicati.Library.Modules.Builtin.ReportHelper:OnFinish <0x00657>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at Duplicati.Library.Main.Controller:OnOperationComplete <0x0023f>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at Duplicati.Library.Main.Controller:RunAction <0x006d3>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at Duplicati.Library.Main.Controller:Backup <0x002bf>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at Duplicati.Server.Runner:Run <0x01133>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at <>c:<SetWorkerThread>b__45_0 <0x0001b>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at Duplicati.Library.Utility.WorkerThread`1:Runner <0x00623>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at System.Threading.ThreadHelper:ThreadStart_Context <0x000df>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at System.Threading.ExecutionContext:RunInternal <0x0021b>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at System.Threading.ExecutionContext:Run <0x0002b>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at System.Threading.ExecutionContext:Run <0x0005f>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at System.Threading.ThreadHelper:ThreadStart <0x00047>
Feb 19 20:18:06 tinker duplicati-server[2694]: #011 at System.Object:runtime_invoke_void__this__ <0x000eb>
Feb 19 20:18:06 tinker duplicati-server[2694]: =================================================================
Feb 19 20:18:06 tinker systemd[1]: duplicati.service: Main process exited, code=exited, status=134/n/a
Feb 19 20:18:06 tinker systemd[1]: duplicati.service: Failed with result 'exit-code'.
Feb 19 20:18:06 tinker systemd[1]: duplicati.service: Scheduled restart job, restart counter is at 1.
Feb 19 20:18:06 tinker systemd[1]: Stopped Duplicati web-server.