WireGuard for Windows failed to start after update to v0.2.1

WireGuard for Windows failed to start after update to v0.2.1

[Joshua Sjoding]

I attempted to update my WireGuard for Windows installation from 0.1.1
to 0.2.1 today. Unfortunately the service failed to restart after the
install and left me without a functional WireGuard tunnel. I'm on a
laptop running Windows 10 2004 (OS Build 19041.630).

From the Windows event logs it looks like it couldn't remove the old
wintun driver. I believe I saw some patches on the list from Marc
Becker recently that may or may not be related.

These events are from the Windows Application event log on my
computer, in order of occurrence:

----

Error, Event 1013, MsiInstaller, 11/17/2020 8:41:49 AM

Product: WireGuard -- Wintun error: Unable to remove existing driver:
The system cannot find the file specified. (Code 0x00000002)

----

Error, Event 1013, MsiInstaller, 11/17/2020 8:41:49 AM

Product: WireGuard -- Wintun error: Failed to uninstall driver: The
operation completed successfully. (Code 0x00000000)

----

Info, Event 11708, MsiInstaller, 11/17/2020 8:41:49 AM

Product: WireGuard -- Installation failed.

----

Info, Event 1033, MsiInstaller, 11/17/2020 8:41:49 AM

Windows Installer installed the product. Product Name: WireGuard.
Product Version: 0.2.1. Product Language: 1033. Manufacturer:
WireGuard LLC. Installation success or error status: 1603.

----

Joshua Sjoding
SCJ Alliance
IT Specialist
www.scjalliance.com

Re: WireGuard for Windows failed to start after update to v0.2.1

[Jason A. Donenfeld]

Hi Joshua,

Does your subsequent email obsolete this one? Trying to keep track of what's up.

Jason

Re: WireGuard for Windows failed to start after update to v0.2.1

[Joshua Sjoding]

I think they're separate issues both related to the new version, which
is why I opted to send in separate emails. The other email is about an
issue first encountered on two other computers within the company.

In my case I was able to get WireGuard working again. Here's what happened:

1. I manually started the WireGuard desktop app. It immediately
prompted for elevated privileges, which is atypical. I provided it
with administrative credentials.
2. The WireGuard desktop app launched, but lacked any of my configured
tunnels and still was prompting me to upgrade. I see that there's a
config data migration recorded in the log, so my guess is that
WireGuard was still running the old executable and didn't know to look
for the configuration data in the new location yet.
3. I told WireGuard to run the updater again and this time it went through fine.
4. When WireGuard came back up it had the tunnel configuration again.
The tunnel was left in a shut off state, even though it was on prior
to the first upgrade attempt. I switched the tunnel back on and it
seems to be working fine now.

I got my own tunnel back in a working condition easily enough, but
we'll need to be cautious as we upgrade our WireGuard clients across
the company. We have over 100 installations of WireGuard for Windows,
so we'll see what sort of success rate we get.

On Tue, Nov 17, 2020 at 12:59 PM Jason A. Donenfeld <Jason@zx2c4.com> wrote:
>
> Hi Joshua,
>
> Does your subsequent email obsolete this one? Trying to keep track of what's up.
>
> Jason

Re: WireGuard for Windows failed to start after update to v0.2.1

[Jason A. Donenfeld]

Hi Joshua,

On Tue, Nov 17, 2020 at 10:20 PM Joshua Sjoding
<joshua.sjoding@scjalliance.com> wrote:
>
> I think they're separate issues both related to the new version, which
> is why I opted to send in separate emails. The other email is about an
> issue first encountered on two other computers within the company.
>
> In my case I was able to get WireGuard working again. Here's what happened:
>
> 1. I manually started the WireGuard desktop app. It immediately
> prompted for elevated privileges, which is atypical. I provided it
> with administrative credentials.
> 2. The WireGuard desktop app launched, but lacked any of my configured
> tunnels and still was prompting me to upgrade. I see that there's a
> config data migration recorded in the log, so my guess is that
> WireGuard was still running the old executable and didn't know to look
> for the configuration data in the new location yet.
> 3. I told WireGuard to run the updater again and this time it went through fine.
> 4. When WireGuard came back up it had the tunnel configuration again.
> The tunnel was left in a shut off state, even though it was on prior
> to the first upgrade attempt. I switched the tunnel back on and it
> seems to be working fine now.

It's unclear to me where the timeline begins in this one. Here's my
present understanding:

1. It's a normal Tuesday at SCJ, the coffee is roasting, the pens are
clicking, when WireGuard innocently informs you that there's an update
available.

2. You click update, it downloads the installer, and runs it. After
hanging for a bit, the installer seems to run in reverse, and you're
kicked back to the WireGuard app, not-updated, except all your config
files are gone, which is weird.

3. You click update again. It succeeds, and the new WireGuard version
comes up, and your configs are all there.

4. The tunnels aren't started, so you press start, and everything
works, but there are these messages in your log, which you sent me in
the other thread.

Is that an accurate story?

If so, my current best guess is that:
- MSI stops manager, stops tunnel, installs new version, starts new
manager (thereby initiating the config migration), starts new tunnel.
- New tunnel fails to start [a]. We flipped on the MSI rollback switch
in v0.2, so that tunnel bug now causes the installer to move in
reverse [b].
- New manager stopped, old version installed, old manager started, old
tunnel started, but config has been migrated already [c], so the
tunnel doesn't come up and you can't see it.
- You press update again, stops manager, new version installed, starts manager.
- You start the tunnel service manually.

Current status based on the above is:
- [a] and [c] were fixed by
https://git.zx2c4.com/wireguard-windows/commit/?id=2edb9007c820656514a0e9b07c9f83ad86593866
and https://go-review.googlesource.com/c/sys/+/270897 .
- [c] is fixed by
https://git.zx2c4.com/wireguard-windows/commit/?id=2edb9007c820656514a0e9b07c9f83ad86593866
.
- [b] we can either fix by getting rid of rollback again, or keeping
it, and arguing that [c] is the more proper fix.

Can you confirm this corresponds?

Jason

Re: WireGuard for Windows failed to start after update to v0.2.1

[Jason A. Donenfeld]

On Tue, Nov 17, 2020 at 10:56 PM Jason A. Donenfeld <Jason@zx2c4.com> wrote:
> If so, my current best guess is that:
> - MSI stops manager, stops tunnel, installs new version, starts new
> manager (thereby initiating the config migration), starts new tunnel.
> - New tunnel fails to start [a]. We flipped on the MSI rollback switch
> in v0.2, so that tunnel bug now causes the installer to move in
> reverse [b].
> - New manager stopped, old version installed, old manager started, old
> tunnel started, but config has been migrated already [c], so the
> tunnel doesn't come up and you can't see it.
> - You press update again, stops manager, new version installed, starts manager.
> - You start the tunnel service manually.

Alternative interpretation would be that the MSI starts new tunnel,
which uninstalls old Wintun, then old MSI tries to uninstall old
Wintun and fails, and then new installer jumps into rollback mode.
Either way, it seems like the solution is to go back to disabling
rollback.

Re: WireGuard for Windows failed to start after update to v0.2.1

[Jason A. Donenfeld]

https://git.zx2c4.com/wireguard-windows/commit/?id=e70cabae68bd9f12d64b2b269bd80a8b617c338c

We'll see if this stays, but present solution seems to be this.

Re: WireGuard for Windows failed to start after update to v0.2.1

[Joshua Sjoding]

Here's a more complete view of what happened:

1. I heard reports of two of our users having issues updating
WireGuard this morning. Their issue was a firewall warning (now
hopefully resolved in a separate thread).
2. I decided to try updating WireGuard on my own laptop to see if I
got the same behavior.
3. I opened the WireGuard UI through the icon in the system
notification area and saw that WireGuard was offering me an update.
4. I told Wireguard to update and it started to go through the usual
update process.
5. The WireGuard UI closed and the icon in the system notification
area disappeared, which is typical as it does an update.
6. The WireGuard UI never came back and the tunnel never came back up.
There were no error messages, just silent failure.
7. I checked the Windows application log and saw the error messages
listed earlier. In particular this message seemed pertinent: "Product:
WireGuard -- Wintun error: Unable to remove existing driver: The
system cannot find the file specified. (Code 0x00000002)"
8. I compared my experience with the other two cases and determined
that mine was different. I started this thread and another on the
WireGuard mailing list to address the issues.
9. I had some tea. I love tea. Tea is wonderful.
10. I manually started the WireGuard desktop app. It immediately
prompted for elevated privileges, which is atypical. I provided it
with administrative credentials.
11. The WireGuard UI opened and the icon appeared in the system
notification area.
12. I saw that WireGuard was missing my configured tunnel. It was also
still prompting me to update it, which was very surprising.
13. I told WireGuard to run the update again.
14. The UI closed as the update took effect, but this time it opened
back up on its own after the update finished, which is what usually
happens. I saw that the icon was present in the system notification
area as well.
15. I saw that my tunnel configuration was back, but the tunnel was deactivated.
16. I activated the tunnel and everything was happy again.

If the MSI system was supposed to rollback in the case of failure, it
failed to do so. Perhaps the MSI system thought the update succeeded
when it didn't? I found it odd that the MSI reported that it had
installed the product immediately after it reported that it had
failed.

Here are the events from the Windows Application event log again for
convenience, taken at step 7, in order of occurrence:

----

Error, Event 1013, MsiInstaller, 11/17/2020 8:41:49 AM

Product: WireGuard -- Wintun error: Unable to remove existing driver:
The system cannot find the file specified. (Code 0x00000002)

----

Error, Event 1013, MsiInstaller, 11/17/2020 8:41:49 AM

Product: WireGuard -- Wintun error: Failed to uninstall driver: The
operation completed successfully. (Code 0x00000000)

----

Info, Event 11708, MsiInstaller, 11/17/2020 8:41:49 AM

Product: WireGuard -- Installation failed.

----

Info, Event 1033, MsiInstaller, 11/17/2020 8:41:49 AM

Windows Installer installed the product. Product Name: WireGuard.
Product Version: 0.2.1. Product Language: 1033. Manufacturer:
WireGuard LLC. Installation success or error status: 1603.

----

On Tue, Nov 17, 2020 at 1:56 PM Jason A. Donenfeld <Jason@zx2c4.com> wrote:
>
> Hi Joshua,
>
> On Tue, Nov 17, 2020 at 10:20 PM Joshua Sjoding
> <joshua.sjoding@scjalliance.com> wrote:
> >
> > I think they're separate issues both related to the new version, which
> > is why I opted to send in separate emails. The other email is about an
> > issue first encountered on two other computers within the company.
> >
> > In my case I was able to get WireGuard working again. Here's what happened:
> >
> > 1. I manually started the WireGuard desktop app. It immediately
> > prompted for elevated privileges, which is atypical. I provided it
> > with administrative credentials.
> > 2. The WireGuard desktop app launched, but lacked any of my configured
> > tunnels and still was prompting me to upgrade. I see that there's a
> > config data migration recorded in the log, so my guess is that
> > WireGuard was still running the old executable and didn't know to look
> > for the configuration data in the new location yet.
> > 3. I told WireGuard to run the updater again and this time it went through fine.
> > 4. When WireGuard came back up it had the tunnel configuration again.
> > The tunnel was left in a shut off state, even though it was on prior
> > to the first upgrade attempt. I switched the tunnel back on and it
> > seems to be working fine now.
>
> It's unclear to me where the timeline begins in this one. Here's my
> present understanding:
>
> 1. It's a normal Tuesday at SCJ, the coffee is roasting, the pens are
> clicking, when WireGuard innocently informs you that there's an update
> available.
>
> 2. You click update, it downloads the installer, and runs it. After
> hanging for a bit, the installer seems to run in reverse, and you're
> kicked back to the WireGuard app, not-updated, except all your config
> files are gone, which is weird.
>
> 3. You click update again. It succeeds, and the new WireGuard version
> comes up, and your configs are all there.
>
> 4. The tunnels aren't started, so you press start, and everything
> works, but there are these messages in your log, which you sent me in
> the other thread.
>
> Is that an accurate story?
>
> If so, my current best guess is that:
> - MSI stops manager, stops tunnel, installs new version, starts new
> manager (thereby initiating the config migration), starts new tunnel.
> - New tunnel fails to start [a]. We flipped on the MSI rollback switch
> in v0.2, so that tunnel bug now causes the installer to move in
> reverse [b].
> - New manager stopped, old version installed, old manager started, old
> tunnel started, but config has been migrated already [c], so the
> tunnel doesn't come up and you can't see it.
> - You press update again, stops manager, new version installed, starts manager.
> - You start the tunnel service manually.
>
> Current status based on the above is:
> - [a] and [c] were fixed by
> https://git.zx2c4.com/wireguard-windows/commit/?id=2edb9007c820656514a0e9b07c9f83ad86593866
> and https://go-review.googlesource.com/c/sys/+/270897 .
> - [c] is fixed by
> https://git.zx2c4.com/wireguard-windows/commit/?id=2edb9007c820656514a0e9b07c9f83ad86593866
> .
> - [b] we can either fix by getting rid of rollback again, or keeping
> it, and arguing that [c] is the more proper fix.
>
> Can you confirm this corresponds?
>
> Jason

Re: WireGuard for Windows failed to start after update to v0.2.1

[Jason A. Donenfeld]

On 11/17/20, Joshua Sjoding <joshua.sjoding@scjalliance.com> wrote:
> Here's a more complete view of what happened:
>
> 1. I heard reports of two of our users having issues updating
> WireGuard this morning. Their issue was a firewall warning (now
> hopefully resolved in a separate thread).
> 2. I decided to try updating WireGuard on my own laptop to see if I
> got the same behavior.
> 3. I opened the WireGuard UI through the icon in the system
> notification area and saw that WireGuard was offering me an update.
> 4. I told Wireguard to update and it started to go through the usual
> update process.
> 5. The WireGuard UI closed and the icon in the system notification
> area disappeared, which is typical as it does an update.
> 6. The WireGuard UI never came back and the tunnel never came back up.
> There were no error messages, just silent failure.
> 7. I checked the Windows application log and saw the error messages
> listed earlier. In particular this message seemed pertinent: "Product:
> WireGuard -- Wintun error: Unable to remove existing driver: The
> system cannot find the file specified. (Code 0x00000002)"
> 8. I compared my experience with the other two cases and determined
> that mine was different. I started this thread and another on the
> WireGuard mailing list to address the issues.
> 9. I had some tea. I love tea. Tea is wonderful.
> 10. I manually started the WireGuard desktop app. It immediately
> prompted for elevated privileges, which is atypical. I provided it
> with administrative credentials.
> 11. The WireGuard UI opened and the icon appeared in the system
> notification area.
> 12. I saw that WireGuard was missing my configured tunnel. It was also
> still prompting me to update it, which was very surprising.
> 13. I told WireGuard to run the update again.
> 14. The UI closed as the update took effect, but this time it opened
> back up on its own after the update finished, which is what usually
> happens. I saw that the icon was present in the system notification
> area as well.
> 15. I saw that my tunnel configuration was back, but the tunnel was
> deactivated.
> 16. I activated the tunnel and everything was happy again.
>
> If the MSI system was supposed to rollback in the case of failure, it
> failed to do so. Perhaps the MSI system thought the update succeeded
> when it didn't? I found it odd that the MSI reported that it had
> installed the product immediately after it reported that it had
> failed.
>
> Here are the events from the Windows Application event log again for
> convenience, taken at step 7, in order of occurrence:
>
> ----
>
> Error, Event 1013, MsiInstaller, 11/17/2020 8:41:49 AM
>
> Product: WireGuard -- Wintun error: Unable to remove existing driver:
> The system cannot find the file specified. (Code 0x00000002)
>
> ----
>
> Error, Event 1013, MsiInstaller, 11/17/2020 8:41:49 AM
>
> Product: WireGuard -- Wintun error: Failed to uninstall driver: The
> operation completed successfully. (Code 0x00000000)
>
> ----
>
> Info, Event 11708, MsiInstaller, 11/17/2020 8:41:49 AM
>
> Product: WireGuard -- Installation failed.
>
> ----
>
> Info, Event 1033, MsiInstaller, 11/17/2020 8:41:49 AM
>
> Windows Installer installed the product. Product Name: WireGuard.
> Product Version: 0.2.1. Product Language: 1033. Manufacturer:
> WireGuard LLC. Installation success or error status: 1603.
>
> ----

Thanks. We've reproduced this, understand the race condition that led
to it, and are working on a fix for 0.2.2. Turns out to be quite
tricky MSI internals at play. Your detailed reports were extremely
useful. I'll keep you posted when we have a fix confirmed.

Re: WireGuard for Windows failed to start after update to v0.2.1

[Jason A. Donenfeld]

On 11/18/20, Jason A. Donenfeld <Jason@zx2c4.com> wrote:
> On 11/17/20, Joshua Sjoding <joshua.sjoding@scjalliance.com> wrote:
>> Here's a more complete view of what happened:
>>
>> 1. I heard reports of two of our users having issues updating
>> WireGuard this morning. Their issue was a firewall warning (now
>> hopefully resolved in a separate thread).
>> 2. I decided to try updating WireGuard on my own laptop to see if I
>> got the same behavior.
>> 3. I opened the WireGuard UI through the icon in the system
>> notification area and saw that WireGuard was offering me an update.
>> 4. I told Wireguard to update and it started to go through the usual
>> update process.
>> 5. The WireGuard UI closed and the icon in the system notification
>> area disappeared, which is typical as it does an update.
>> 6. The WireGuard UI never came back and the tunnel never came back up.
>> There were no error messages, just silent failure.
>> 7. I checked the Windows application log and saw the error messages
>> listed earlier. In particular this message seemed pertinent: "Product:
>> WireGuard -- Wintun error: Unable to remove existing driver: The
>> system cannot find the file specified. (Code 0x00000002)"
>> 8. I compared my experience with the other two cases and determined
>> that mine was different. I started this thread and another on the
>> WireGuard mailing list to address the issues.
>> 9. I had some tea. I love tea. Tea is wonderful.
>> 10. I manually started the WireGuard desktop app. It immediately
>> prompted for elevated privileges, which is atypical. I provided it
>> with administrative credentials.
>> 11. The WireGuard UI opened and the icon appeared in the system
>> notification area.
>> 12. I saw that WireGuard was missing my configured tunnel. It was also
>> still prompting me to update it, which was very surprising.
>> 13. I told WireGuard to run the update again.
>> 14. The UI closed as the update took effect, but this time it opened
>> back up on its own after the update finished, which is what usually
>> happens. I saw that the icon was present in the system notification
>> area as well.
>> 15. I saw that my tunnel configuration was back, but the tunnel was
>> deactivated.
>> 16. I activated the tunnel and everything was happy again.
>>
>> If the MSI system was supposed to rollback in the case of failure, it
>> failed to do so. Perhaps the MSI system thought the update succeeded
>> when it didn't? I found it odd that the MSI reported that it had
>> installed the product immediately after it reported that it had
>> failed.
>>
>> Here are the events from the Windows Application event log again for
>> convenience, taken at step 7, in order of occurrence:
>>
>> ----
>>
>> Error, Event 1013, MsiInstaller, 11/17/2020 8:41:49 AM
>>
>> Product: WireGuard -- Wintun error: Unable to remove existing driver:
>> The system cannot find the file specified. (Code 0x00000002)
>>
>> ----
>>
>> Error, Event 1013, MsiInstaller, 11/17/2020 8:41:49 AM
>>
>> Product: WireGuard -- Wintun error: Failed to uninstall driver: The
>> operation completed successfully. (Code 0x00000000)
>>
>> ----
>>
>> Info, Event 11708, MsiInstaller, 11/17/2020 8:41:49 AM
>>
>> Product: WireGuard -- Installation failed.
>>
>> ----
>>
>> Info, Event 1033, MsiInstaller, 11/17/2020 8:41:49 AM
>>
>> Windows Installer installed the product. Product Name: WireGuard.
>> Product Version: 0.2.1. Product Language: 1033. Manufacturer:
>> WireGuard LLC. Installation success or error status: 1603.
>>
>> ----
>
> Thanks. We've reproduced this, understand the race condition that led
> to it, and are working on a fix for 0.2.2. Turns out to be quite
> tricky MSI internals at play. Your detailed reports were extremely
> useful. I'll keep you posted when we have a fix confirmed.
>

Looks like no big hacks required. We can plow right through the error
and continue onward without penalty:

https://git.zx2c4.com/wireguard-windows/commit/?id=60caaba12d08eb4227b9af868fd428134bfe7dce
https://git.zx2c4.com/wireguard-windows/commit/?id=e70cabae68bd9f12d64b2b269bd80a8b617c338c

So, I think this issue here is resolved now. Hopefully we'll have
v0.2.2 out tomorrow.

Jason

Re: WireGuard for Windows failed to start after update to v0.2.1

[Jason A. Donenfeld]

Hi Joshua,

A new version is now released, which should address all the issues you
found. Let me know how things go...

Jason

Re: WireGuard for Windows failed to start after update to v0.2.1

[Joshua Sjoding]

I ran WireGuard for Windows version 0.2.2 all day yesterday and I've
been running 0.2.3 today. Since the 0.2.2 release we've had no issues
with the update process.

If we run into any more issues we'll let you know. If you don't hear
back you can assume all is well.

Cheers!

Joshua Sjoding
SCJ Alliance
IT Specialist
www.scjalliance.com
On Wed, Nov 18, 2020 at 5:41 AM Jason A. Donenfeld <Jason@zx2c4.com> wrote:
>
> Hi Joshua,
>
> A new version is now released, which should address all the issues you
> found. Let me know how things go...
>
> Jason

Re: WireGuard for Windows failed to start after update to v0.2.1

[Jason A. Donenfeld]

On Thu, Nov 19, 2020 at 8:39 PM Joshua Sjoding
<joshua.sjoding@scjalliance.com> wrote:
>
> I ran WireGuard for Windows version 0.2.2 all day yesterday and I've
> been running 0.2.3 today. Since the 0.2.2 release we've had no issues
> with the update process.
>
> If we run into any more issues we'll let you know. If you don't hear
> back you can assume all is well.

Great to hear! Thanks for the update on the update.

Jason