Activate downloaded upgrade sometimes fail


#1

There are 3 things.

1)bug - download succeed everytime, but activation works 1 of 10 cases. It log me out forcing relogin and than again same version of app. Even multiple time press dont work. Only way is to stop process and start again, than new version loads ok.
2)cosmetic - after pressing activate button it should say something or disable pushing again not to allow user to push it multiple time
3)cosmetic - after update (app restart) still offering update to same version
image


Easy way to delete old backups
Release: 2.0.3.12 (canary) 2018-10-23
Release: 2.0.3.13 (canary) 2018-10-31
#2

What OS? GitHub issue also doesn’t say. Does that imply it fails on all tried (still would be helpful to know)?

Duplicati not automatically restarting after update on MacOS might be a related issue, but yours is manual.

If this is Windows, is Duplicati a Windows service (where I get an always-fails, but have ideas) or Tray Icon?

Do you ever reinstall the base version of Duplicati (as seen in About --> System info), or just do upgrades?

Is the 1 of 10 a recollection over history, or a test e.g. by using Downgrading / reverting to a lower version?


#3

I’ve had the “can click activate multiple times” and “offering update to just activated version” issues in Windows 10, MacOS, and Linux (Docker) on multiple versions of Duplicati.

I used to get the “won’t activate” on Windows, but that was many Duplicati versions ago (currently in 2.0.3.11) and mostly (all?) Windows.

Not that in all instances I’m running as a service / daemon.

I suspect the “offering update to just activated version” issue is browser cache related but always forget to test it in the rush to play with my shiny new Duplicati. :slight_smile:


#4

Windows 10.
No on all tries. In fact after restart if there is update it works ok.
After some days when it find update sometimes it fails.
Windows service mode is used.


#5

There might be a typo (“Note” as “Not”) in the report from @JonMikelV but I wonder if those Duplicati service processes are two Duplicati.WindowsService.exe plus a Duplicati.Server.exe? Which ones restart at activate? Viewing in Process Explorer is easier (plus one can see where executable is from), but Task Manager suffices. Process Monitor is a good way to see the exit code attempt (which goes to a spot that doesn’t process those).

Here, the Duplicati.Server.exe is just restarted in its original version by the child Duplicati.WindowsService.exe because the exit code it uses to request an update-restart only works between a paired child and parent, e.g.:

Duplicati.Server twice? (which is maybe not quite correct because it can also just pass the exit code upwards)
[SOLVED] Is it ok that I see 5 processes of Duplicati in Windows Task manager?

I don’t know if it was intentional for Windows service to have a single Duplicati.Server.exe as well, but see this, and another possibility might be for the child Duplicati.WindowsService.exe to return special exit to ITS parent, thereby starting the newer version of Duplicati.WindowsService.exe and (I hope) the new Duplicati.Server.exe.

The only way here for a Windows service Duplicati to activate the update is to restart the service, reboot, etc.

Starting a Windows.Server.exe from the Command Prompt causes the paired parent/child, and activates fine. Stopping with Control-C is not so good because it only kills the update-runner parent, leaving its server child.


#6

The idea is that Duplicati.WindowsService.exe is never restarted, and always runs the base install version.

It should then start Duplicati.Server.exe in the base install version, which will immediately start a new Duplicati.Server.exe in the latest version.

When installing an update, only the lastest version Duplicati.Server.exe should exit, and return the exit magic code to the base install version of Duplicati.Server.exe which should then simply re-launch the latest (now updated) version.

I know that a number of people have reported restart failures, but I have not seen this on any of my own installs, and it is very difficult to debug.

One thing that could cause problems is that Duplicati will do an integrity check on the latest version. If the updated folder is not exactly as described in the signed manifest, it will refuse to start the update. This is done to prevent attacks where the update package is tainted. I have a suspicion that “something” fiddles with the update folder (locked files, temp folders, quarantine stuff, etc) which cause the update to be rejected but have not leads on what could cause it.


#7

Thank you for the explanation, and software :smiley:. Are you describing how you wish it to work (to help guide its development)? Current behavior (for me and others) is two WindowsService and one Server, as explained by you in [SOLVED] Is it ok that I see 5 processes of Duplicati in Windows Task manager?. Seen using Process Explorer, below is how a very fresh (empty standby list) service start of base version 2.0.3.10 plus update to 2.0.3.11 comes up. The (too big for me) 80 MB read in the parent WindowsService is the integrity check and update selection for child WindowsService, and I think that path is concatenated here to set the Server path.

On shakier ground (haven’t had this in debugger lately), if Server should be paired (so MAGIC_EXIT_CODE works) that was my test to prevent AUTOUPDATER_Duplicati_INSTALL_ROOT=C:\Program Files\Duplicati 2 from inheriting down from child WindowsService. Its absence in Server stops the child prevention found here. Another possible path to activation would be to have child WindowsService propagate special exit code from Server up to parent WindowsService to then repeat its choose-and-launch. Currently restart is a simple loop which seems like it should just repeat the original launch, which is what it seems to do for me. Earlier picture:

where I now notice Server has done a lot of reads too (integrity checking?) even though it didn’t launch child. Still trying to sort out wishes from actuals, but seemingly actuals vary. @mnaiman and I see solid failures… For anyone seeing a radically different process view, I wish I could see it. Are some really getting Server pair from a WindowsService install? Pairing is fine for direct TrayIcon or Server starts, but that’s not this article…


#8

Ok, same bug during update now to version 3.12.
My process explorer tree look like:
“D:\Software\Duplicati\Duplicati\Duplicati.WindowsService.exe” --portable-mode
->“D:\Software\Duplicati\Duplicati\updates\2.0.3.11\Duplicati.WindowsService.exe” --portable-mode
->->“D:\Software\Duplicati\Duplicati\updates\2.0.3.11\Duplicati.Server.exe” “–ping-pong-keepalive=true” --portable-mode

When I click on activate Duplicati.Server.exe exit with Exit Status: 126
Immediately Duplicati.Server.exe is spawned again from 2.0.3.11 folder.

No corruption of files or integrity problems because I stopped whole tree, started service and everything is running fine from 2.0.3.12 :frowning:


#9

I thought I was describing how it works, but it looks like I was wrong :smiley:.

Then a possible explanation is that Duplicati.Server.exe exits, but WindowsService.exe just thinks it has crashed and restarts it.

I have added this support code to handle this case:

Edit: If I had read the full post, I would have seen that is exactly what you describe here:


#10

Thought I might add what I’ve encountered so far.

There is comment which adds a nice insight on why it probably the magic exit code doesn’t quite work with windows services.

That last commit got me really excited because I am trying to get a way to activate updates on services without manually restarting them (or the computer in general) for some time, my current solution is to launch an external program that asks for admin permission and calls ServiceProcess to restart the service.

I tested it but, at least for me, the behavior continues. Usually nothing happens and occasionally the service is stopped.


#11

In don’t believe that code is in 2.0.3.12 as it was released on the 23rd but the code update was submitted on the 26th.

Hopefully it will appear in the next release and you can test again. :slight_smile:


#12

Sure, however I did test it on a separated branch that included that code. Not on a release build


#13

Ah. Well that makes a difference then. :slight_smile:

I’m hoping a new release will be out quite soon and others can be confirm your experience.


#14

I was actually hoping NOT to confirm it, but I sort of confirmed it with a probably-illegal configuration of the 2.0.3.13 Duplicati.WindowsService.exe transplanted into a 2.0.3.12 base install, then remove the 2.0.3.13 update folder and let the blended Duplicati try to get 2.0.3.13 again. Press Activate and processes vanish.

I’m not even sure this is the right way to fake it, so I’m wondering how @mikaelmello and others tested…


#15

I am working on a fork of Duplicati that installs it as a Windows Service, so I cherry picked the commit with the fix into my branch and generated a new installer.

Behaviour stayed the same.

For now I am using a different executable that is launched by the Server and restarts the service.

However I’m not quite pleased with this approach yet and will test this fix using the latest canary release instead of the commit.


#16

In latest test, the parent Duplicati.WindowsService.exe restarts its child Duplicati.WindowsService.exe from the new updates/2.0.3.13 folder, then the child exits after a few seconds. It’s the child that Windows considers the service (highlighted pink in Process Explorer). One guess is that Windows was upset by this replaced process. Will have to look further to see if I can find what happened. Regardless, I’m wondering whether 2.0.3.13 has a latent problem that will show up when people start updating to 2.0.3.14. Or maybe this test method is just bad, however perhaps it’s time to seek input from @kenkendk, or at least send an FYI in case this is a regression.


#17

So I did test it right now, twice.

In the first attempt, the parent Duplicati.WindowsService.exe, the child Duplicati.WindowsService.exe and its child Duplicati.Server.exe are all terminated. Since my service has recovery set to restart after 1 minute, it did restart and update. So it kind of worked.

In the second attempt, the behavior stayed the same. I guess this is the same behavior you got

Edit: I got it to work really nicely by setting the restart time to 0 minutes


#18

We were testing and writing simultaneously, so I’ll just post how mine failed, and you can see what you think.

The Activate button is killing Duplicati service differently and more completely in further testing with my questionable blended system with 2.0.3.13 WindowsService in 2.0.3.12 base, trying to Install then Activate a 2.0.3.13 update. Before, there was a lingering WindowsService parent which I killed manually (not sure that I had to though). Now, the whole Duplicati stack exits. Unfortunately I haven’t been able to get a debugger on the new child WindowsService to figure out why it exits (which would also require learning more about code-level details and procedures of Windows service installations), so for now I watch WindowsService and Server with Sysinternals Process Monitor. Results below.

Press web UI Activate button at around 7:00:00.

Server exits with MAGIC_EXIT_CODE, as expected:
7:00:01.5788265 AM	Duplicati.Server.exe	9884	Process Exit		SUCCESS	Exit Status: 126, User Time: 4.3750000 seconds, Kernel Time: 4.0156250 seconds, Private Bytes: 58,867,712, Peak Private Bytes: 60,911,616, Working Set: 26,505,216, Peak Working Set: 87,224,320

WindowsService child exits with MAGIC_EXIT_CODE, as expected:
7:00:01.5942378 AM	Duplicati.WindowsService.exe	11508	Process Exit		SUCCESS	Exit Status: 126, User Time: 0.2812500 seconds, Kernel Time: 0.1250000 seconds, Private Bytes: 23,306,240, Peak Private Bytes: 23,625,728, Working Set: 8,998,912, Peak Working Set: 28,745,728

WindowsService parent picks an update, as expected:
7:00:01.5989967 AM	Duplicati.WindowsService.exe	30872	QueryDirectory	C:\ProgramData\Duplicati\updates\*	SUCCESS	Filter: *, 1: .

WindowsService child runs as 2.0.3.13, as expected:
7:00:02.6066800 AM	Duplicati.WindowsService.exe	32008	Load Image	C:\ProgramData\Duplicati\updates\2.0.3.13\Duplicati.WindowsService.exe	SUCCESS	Image Base: 0x2507db60000, Image Size: 0xa000

WindowsService child logs an error event. BAD NEWS:
Log Name:      Application
Source:        Duplicati
Date:          11/2/2018 7:00:03 AM
Event ID:      0
Task Category: None
Level:         Error
Keywords:      Classic
User:          N/A
Computer:      HP4
Description:
Service cannot be started. The service process could not connect to the service controller
Event Xml:
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
  <System>
    <Provider Name="Duplicati" />
    <EventID Qualifiers="0">0</EventID>
    <Level>2</Level>
    <Task>0</Task>
    <Keywords>0x80000000000000</Keywords>
    <TimeCreated SystemTime="2018-11-02T11:00:03.233040800Z" />
    <EventRecordID>1208575</EventRecordID>
    <Channel>Application</Channel>
    <Computer>HP4</Computer>
    <Security />
  </System>
  <EventData>
    <Data>Service cannot be started. The service process could not connect to the service controller</Data>
  </EventData>
</Event>

WindowsService next child exits 0. Not expected, but reasonable (except maybe exit 0 is wrong) given error:
7:00:03.2368398 AM	Duplicati.WindowsService.exe	32008	Process Exit		SUCCESS	Exit Status: 0, User Time: 0.2343750 seconds, Kernel Time: 0.1406250 seconds, Private Bytes: 22,634,496, Peak Private Bytes: 22,990,848, Working Set: 28,078,080, Peak Working Set: 28,090,368

WindowsService parent exits 0. I wonder if non-0 child exit would differ? Also, should service try harder?:
7:00:03.2539239 AM	Duplicati.WindowsService.exe	30872	Process Exit		SUCCESS	Exit Status: 0, User Time: 0.7968750 seconds, Kernel Time: 0.4843750 seconds, Private Bytes: 29,921,280, Peak Private Bytes: 29,995,008, Working Set: 23,064,576, Peak Working Set: 30,334,976

Service Control Managers logs an error event:
Log Name:      System
Source:        Service Control Manager
Date:          11/2/2018 7:00:03 AM
Event ID:      7034
Task Category: None
Level:         Error
Keywords:      Classic
User:          N/A
Computer:      HP4
Description:
The Duplicati service service terminated unexpectedly.  It has done this 8 time(s).
Event Xml:
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
  <System>
    <Provider Name="Service Control Manager" Guid="{555908d1-a6d7-4695-8e1e-26931d2012f4}" EventSourceName="Service Control Manager" />
    <EventID Qualifiers="49152">7034</EventID>
    <Version>0</Version>
    <Level>2</Level>
    <Task>0</Task>
    <Opcode>0</Opcode>
    <Keywords>0x8080000000000000</Keywords>
    <TimeCreated SystemTime="2018-11-02T11:00:03.258424400Z" />
    <EventRecordID>49386</EventRecordID>
    <Correlation />
    <Execution ProcessID="804" ThreadID="24956" />
    <Channel>System</Channel>
    <Computer>HP4</Computer>
    <Security />
  </System>
  <EventData>
    <Data Name="param1">Duplicati service</Data>
    <Data Name="param2">8</Data>
    <Binary>4400750070006C00690063006100740069000000</Binary>
  </EventData>
</Event>

Aside from whether or not disaster handling is optimal, the error is WindowsService update had some issue with Windows and quit. The 2.0.3.13 WindowsService in the base and the update are the same (aside from debug hacks in the base), so I still suspect that the code is up to an initial start as a service, but not another self-initiated start as a service (launched as a new process). My concern is whether it’s from my odd test, or will Activate kill the service on 2.0.3.13 to 2.0.3.14, which I would consider a worse failure than we now have.


#19

I didn’t trace each process but I’m pretty sure that is what happened here too. On Event Viewer I can see the same very generic error message:

So I still suspect that the code is up to an initial start as a service, but not another self-initiated start as a service (launched as a new process)

Probably. I don’t remember the code exactly but my guess (purely speculation) is that the child WindowsService could be trying to start another service instead of just launching Server.exe.

My concern is whether it’s from my odd test, or will Activate kill the service on 2.0.3.13 to 2.0.3.14, which I would consider a worse failure than we now have.

I particularly like this more than the old behavior that did absolutely nothing. If the whole Duplicati stack is terminated, then the service recovery picks up and restarts it


#20

Is this turned on by default in a way that makes things better? For me, the service just stops and that’s all, silently leaving me with no Duplicati and no backups. Again, I have no way of testing an actual 2.0.3.13 to 2.0.3.14 update, and update verification plus tight timing constraints keep me from debugging the process.
EDIT: Not actually silent if one returns to the web UI to see it saying “The connection to the server is lost”…