Email problem and Backup lock

Support
1

Hi, i think i have found a problem, i’m using Duplicati - 2.0.3.6_canary_2018-04-23 and setting up a local backup with email sending in the absence of Internet connection the backup so freezes as from this image.

Immagine%20001
Immagine 001.png1036×320 23.6 KB

At this point Duplicati seems completely blocked, no longer performs subsequent backups, even with the restored connection the situation does not change and the only way to unlock the situation is to terminate Duplicati from Taskmanager or restarting the PC .

The options set are:

To reproduce the problem just remove the network cable.

2

That’s odd - I disabled my network interface (too hard to get to the cable to pull it) and ran a local backup job that includes email notifications and got a Live Profiling log entry that said “Failed to send message”, but otherwise the backup started & stopped just fine. I’m using 2.0.3.7, but I doubt that will make a difference.

If you go to main menu “About” -> “Show log” -> “Live” and select “Verbose” what are the last few log entries you see?

You should be able to copy / paste them into your post - note that some of them can be clicked on to expand for additional details.

Here’s what mine looked like (without details):


Jun 19, 2018 12:26 PM: The operation Backup has completed
Jun 19, 2018 12:26 PM: Failed to send message: MailKit.Net.Smtp.SmtpCommandException: Cannot connect to SMTP server ###.###.###.### (###.###.###.###:##), connect error 10051
Jun 19, 2018 12:26 PM: Backend event: Get - Completed: duplicati-be8809f9c528e4261bb12c988044f7ba7.dblock.zip (609 bytes)
Jun 19, 2018 12:26 PM: Backend event: Get - Started: duplicati-be8809f9c528e4261bb12c988044f7ba7.dblock.zip (609 bytes)
3

Hi, sorry if i answer only now but i was away for work.

The verbose Log is as follows:

Jun 22, 2018 9:31 AM: Backend event: Get - Completed: duplicati-bab6d1dfe389544dc9097edaa65526fb6.dblock.zip (965 bytes)
Jun 22, 2018 9:31 AM: Backend event: Get - Started: duplicati-bab6d1dfe389544dc9097edaa65526fb6.dblock.zip (965 bytes)
Jun 22, 2018 9:31 AM: Backend event: Get - Completed: duplicati-i2fd886caba014b909af072b61d386820.dindex.zip (652 bytes)
Jun 22, 2018 9:31 AM: Backend event: Get - Started: duplicati-i2fd886caba014b909af072b61d386820.dindex.zip (652 bytes)
Jun 22, 2018 9:31 AM: Backend event: Get - Completed: duplicati-20180622T073108Z.dlist.zip (1,69 KB)
Jun 22, 2018 9:31 AM: Backend event: Get - Started: duplicati-20180622T073108Z.dlist.zip (1,69 KB)

By configuring the email section as indicated in this post by Marc_Aronson:

the problem does not occur, the backup ends by giving the warning and Duplicati continues to work properly.

–snapshot-policy=auto
–send-mail-url=smtp://smtp.gmail.com:587/?starttls=when-available
–send-mail-any-operation=true
–send-mail-subject=Duplicati %PARSEDRESULT%, %OPERATIONNAME% report for %backup-name%
--send-mail-to=MYACCOUNT@gmail.com
--send-mail-username=MYACCOUNT@gmail.com
–send-mail-password=MYPASSWORD
–send-mail-from=BK PC MYACCOUNT@gmail.com

It would be useful to be able to add this configuration in some way to the email configuration guidelines.

PS: Disabling the network interface the problem does not occur, it only happens by unplugging the network cable. I found the problem because there was a fault on the ADSL line and i stayed almost a week without Internet connection.

4

Thanks for the information - and don’t worry about taking time to respond - we all have the real world to deal with. :slight_smile:

The Log lines you provided confirm that the backup got to the final testing step where it checks one each of dblock, dlist, and dindex files after each backup to make sure they’re still valid.

I’m not sure which guidelines you mean, do you have a link to the configuration guidelines you think should be updated?

I tested again using a physical cable pull as you suggested but still am not seeing the issue you reported. (Though I did pull the cable before I started the job, not while it was running.)

My test job was to a local folder and finished without problem, though it did display a “1 warning” message. By going to main menu “About” → “Show log” → “Live” and selecting “Warning” I saw the (expected) error below.

In your first screenshot it looks like Duplicati is stuck “Waiting for upload”. Are you sure your backup job was to a local (to the computer) destination?

I ask because there is a known issue where if the network connection is interrupted DURING an upload, then Duplicati can get stuck waiting for the interrupted upload to finish. But I’ve only see that be an issue during uploads, not during emails.

Jun 22, 2018 10:50 AM: Failed to send message: MailKit.Net.Smtp.SmtpCommandException: Cannot connect to SMTP server ###.###.###.### (###.###.###.###:##), connect error 10065
{"ClassName":"MailKit.Net.Smtp.SmtpCommandException",
"Message":"Cannot connect to SMTP server ###.###.###.### (###.###.###.###:##), connect error 10065",
"Data":null,
"InnerException":null,
"HelpURL":"https://github.com/jstedfast/MailKit/blob/master/FAQ.md#ProtocolLog",
"StackTraceString":"   at Duplicati.Library.Modules.Builtin.SendMail.SendMessage(String subject, String body)
   at Duplicati.Library.Modules.Builtin.ReportHelper.OnFinish(Object result)",
"RemoteStackTraceString":null,
"RemoteStackIndex":0,
"ExceptionMethod":"8
SendMessage
Duplicati.Library.Modules.Builtin, Version=2.0.3.7, Culture=neutral, PublicKeyToken=null
Duplicati.Library.Modules.Builtin.SendMail
Void SendMessage(System.String, System.String)",
"HResult":-2146233088,
"Source":"Duplicati.Library.Modules.Builtin",
"WatsonBuckets":null,
"Mailbox":"",
"ErrorCode":"UnexpectedStatusCode",
"StatusCode":"ServiceNotAvailable"}
5

Hi, yes the backup is completed correctly but Duplicati remains locked as an image and no longer performs subsequent backups.

For the guide i was thinking of a pop-up when you activate the email part, to give an example of basic configuration to users.

You corrected, the cable i removed it before starting the backup that is in local, i created a test task where i copy C:\Temp\BK1 in C:\Temp\BK2.

It’s not going to show up, i can reproduce the problem on 3 PCs and 1 Laptop, can it depend on the email address used?

The strange thing is that if i use this configuration:

--send-mail-from=BK PC <MYACCOUNT@gmail.com>
--send-mail-to=MYACCOUNT@gmail.com
--snapshot-policy=auto

the problem arises, whereas if i use this configuration:

--snapshot-policy=auto
--send-mail-url=smtp://smtp.gmail.com:587/?starttls=when-available
--send-mail-any-operation=true
--send-mail-subject=Duplicati %PARSEDRESULT%, %OPERATIONNAME% report for %backup-name%
--send-mail-to=MYACCOUNT@gmail.com
--send-mail-username=MYACCOUNT@gmail.com
--send-mail-password=MYPASSWORD
--send-mail-from=BK PC <MYACCOUNT@gmail.com>

i have the same result as you.

6

I will test with a configuration like yours.

The send-mail-url parameter should be required for emails to work, but if not provided should not cause Duplicati to lock up.

7

If you need me to do some tests ask as well.

8

Thanks for the offer but I have confirmed the problem and flagged this topic as a #bug and entered an issue over at GitHub. Note that due to the likely low “in the wild” occurrence of this scenario I expect this won’t be super high on the “to-do” list right now.

Running a backup (such as to a local drive) with email settings such as --send-mail-from and --send-mail-to but WITHOUT --send-mail-url or a network connection finishes the backup but the server is left in a broken state with the GUI (incorrectly) stuck on “Waiting for upload”.

Stopping the task does NOT resolve the state and only restarting the Duplicati server allows for recovery.

Note that this only seems to happen when there is a LAN connection configured but it is not physically connected. If the network adapter is simply disabled then the expected warning message is shown with the actual message shown in the global Live Profiling log.

Got 1 warning(s) image

Jun 25, 2018 9:30 AM: The operation Backup has completed
Jun 25, 2018 9:30 AM: Failed to send message: System.Net.Sockets.SocketException: A socket operation was attempted to an unreachable network 8.8.8.8:53
{
"NativeErrorCode":10051,
"ClassName":"System.Net.Sockets.SocketException",
"Message":"A socket operation was attempted to an unreachable network",
"Data":null,
"InnerException":null,
"HelpURL":null,
"StackTraceString":"
   at System.Net.Sockets.UdpClient.Connect(String hostname, Int32 port)
   at DnsLib.DnsLite.getMXRecords(String host, String serverAddress)
   at Duplicati.Library.Modules.Builtin.SendMail.SendMessage(String subject, String body)
   at Duplicati.Library.Modules.Builtin.ReportHelper.OnFinish(Object result)",
"RemoteStackTraceString":null,
"RemoteStackIndex":0,
"ExceptionMethod":"8
Connect
System, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089
System.Net.Sockets.UdpClient
Void Connect(System.String, Int32)",
"HResult":-2147467259,
"Source":"System",
"WatsonBuckets":null
}
Jun 25, 2018 9:30 AM: Running Backup took 0:00:01:39.047
9

Thanks for the availability, there is no hurry also because the problem occurs only in particular cases.

1 Like