Re: After win2019 server reboot, Wireguard tunnel doesn't start

[Peter Selc <peter.selc@gmail.com>]

[-- Attachment #1.1: Type: text/plain, Size: 12907 bytes --]

Hello,

bellow is another occurance of the bug. At 17:19 server was rebooted
because of updates.

The process C:\windows\system32\svchost.exe (bserver) has initiated the
restart of computer bserver on behalf of user NT AUTHORITY\SYSTEM for the
following reason: Operating System: Service pack (Planned)
 Reason Code: 0x80020010
 Shutdown Type: restart
 Comment:

2020-02-11 14:13:29.084361: [TUN] [Server] peer(SuXT…9iko) - Sending
keepalive packet
2020-02-11 14:13:39.080286: [TUN] [Server] peer(SuXT…9iko) - Receiving
keepalive packet
2020-02-11 14:13:39.085654: [TUN] [Server] peer(SuXT…9iko) - Sending
keepalive packet
2020-02-11 14:22:18.562874: [TUN] [Server] peer(SuXT…9iko) - Removing all
keys, since we haven't received a new one in 540 seconds
2020-02-12 17:19:00.295842: [MGR] Exited UI process for user
'admin_user@bserver' for session 2 with status 40010004
2020-02-12 17:19:01.351433: [MGR] Starting UI process for user
‘admin_user@bserver’ for session 2
2020-02-12 17:19:02.508881: [MGR] Exited UI process for user
'admin_user@bserver' for session 2 with status c000026b
2020-02-12 17:20:46.494769: [TUN] [Server] Device closing
2020-02-12 17:20:46.532011: [TUN] [Server] Routine: TUN reader - stopped
2020-02-12 17:20:46.574511: [TUN] [Server] Routine: event worker - stopped
2020-02-12 17:20:46.579359: [TUN] [Server] Routine: receive incoming IPv4 -
stopped
2020-02-12 17:20:46.626363: [TUN] [Server] Routine: receive incoming IPv6 -
stopped
2020-02-12 17:20:46.627376: [TUN] [Server] peer(SuXT…9iko) - Stopping...
2020-02-12 17:20:46.627376: [TUN] [Server] peer(SuXT…9iko) - Routine:
sequential sender - stopped
2020-02-12 17:20:46.628361: [TUN] [Server] peer(SuXT…9iko) - Routine: nonce
worker - stopped
2020-02-12 17:20:46.629361: [TUN] [Server] Routine: encryption worker -
stopped
2020-02-12 17:20:46.630362: [TUN] [Server] Routine: decryption worker -
stopped
2020-02-12 17:20:46.630362: [TUN] [Server] Routine: decryption worker -
stopped
2020-02-12 17:20:46.630362: [TUN] [Server] Routine: handshake worker -
stopped
2020-02-12 17:20:46.631382: [TUN] [Server] Routine: handshake worker -
stopped
2020-02-12 17:20:46.631382: [TUN] [Server] Routine: encryption worker -
stopped
2020-02-12 17:20:46.631382: [TUN] [Server] peer(SuXT…9iko) - Routine:
sequential receiver - stopped
2020-02-12 17:20:46.631382: [TUN] [Server] peer(CbnY…MhkI) - Stopping...
2020-02-12 17:20:46.632362: [TUN] [Server] peer(CbnY…MhkI) - Routine:
sequential receiver - stopped
2020-02-12 17:20:46.633361: [TUN] [Server] peer(CbnY…MhkI) - Routine:
sequential sender - stopped
2020-02-12 17:20:46.633361: [TUN] [Server] peer(CbnY…MhkI) - Routine: nonce
worker - stopped
2020-02-12 17:20:46.633361: [TUN] [Server] peer(JRsL…401s) - Stopping...
2020-02-12 17:20:46.633361: [TUN] [Server] peer(JRsL…401s) - Routine:
sequential receiver - stopped
2020-02-12 17:20:46.634362: [TUN] [Server] peer(JRsL…401s) - Routine: nonce
worker - stopped
2020-02-12 17:20:46.634362: [TUN] [Server] peer(JRsL…401s) - Routine:
sequential sender - stopped
2020-02-12 17:20:46.635445: [TUN] [Server] peer(nLK/…f3mE) - Stopping...
2020-02-12 17:20:46.635445: [TUN] [Server] peer(nLK/…f3mE) - Routine:
sequential receiver - stopped
2020-02-12 17:20:46.635445: [TUN] [Server] peer(nLK/…f3mE) - Routine: nonce
worker - stopped
2020-02-12 17:20:46.636367: [TUN] [Server] peer(nLK/…f3mE) - Routine:
sequential sender - stopped
2020-02-12 17:20:46.636367: [TUN] [Server] peer(1WB6…G/xk) - Stopping...
2020-02-12 17:20:46.636367: [TUN] [Server] peer(1WB6…G/xk) - Routine:
sequential receiver - stopped
2020-02-12 17:20:46.637416: [TUN] [Server] peer(1WB6…G/xk) - Routine: nonce
worker - stopped
2020-02-12 17:20:46.638361: [TUN] [Server] peer(1WB6…G/xk) - Routine:
sequential sender - stopped
2020-02-12 17:20:46.638361: [TUN] [Server] peer(akUl…uaHM) - Stopping...
2020-02-12 17:20:46.639378: [TUN] [Server] peer(akUl…uaHM) - Routine:
sequential receiver - stopped
2020-02-12 17:20:46.639378: [TUN] [Server] peer(akUl…uaHM) - Routine: nonce
worker - stopped
2020-02-12 17:20:46.640362: [TUN] [Server] peer(akUl…uaHM) - Routine:
sequential sender - stopped
2020-02-12 17:20:46.640362: [TUN] [Server] peer(UUvS…DwEo) - Stopping...
2020-02-12 17:20:46.641361: [TUN] [Server] peer(UUvS…DwEo) - Routine:
sequential receiver - stopped
2020-02-12 17:20:46.641361: [TUN] [Server] peer(UUvS…DwEo) - Routine:
sequential sender - stopped
2020-02-12 17:20:46.641361: [TUN] [Server] peer(UUvS…DwEo) - Routine: nonce
worker - stopped
2020-02-12 17:20:46.641361: [TUN] [Server] Interface closed
2020-02-12 17:20:46.642361: [TUN] [Server] Shutting down
2020-02-12 17:21:56.974077: [TUN] [Server] Starting WireGuard/0.0.38
(Windows Server 10.0.17763; amd64)
2020-02-12 17:21:56.974077: [MGR] Starting WireGuard/0.0.38 (Windows Server
10.0.17763; amd64)
2020-02-12 17:21:57.199444: [TUN] [Server] SCM locked for 24s by .\NT
Service Control Manager, marking service as started
2020-02-12 17:21:57.203451: [TUN] [Server] Watching network interfaces
2020-02-12 17:21:57.223553: [TUN] [Server] Resolving DNS names
2020-02-12 17:21:57.272618: [TUN] [Server] Creating Wintun interface
2020-02-12 17:22:01.919561: [TUN] [Server] Unable to create Wintun
interface: Error creating interface:
SetupDiCallClassInstaller(DIF_REGISTERDEVICE) failed: winapi error
#3758096907
2020-02-12 17:22:01.920550: [TUN] [Server] Shutting down
2020-02-12 17:22:07.294542: [MGR] Removing Wintun interface ‘Local Area
Connection’ because determining tunnel service name failed: Tunnel name is
not valid
2020-02-14 07:56:43.399005: [MGR] Starting UI process for user
‘admin_user@bserver’ for session 2

Thanks,
Peter

On Sun, 26 Jan 2020 at 19:15, Peter Selc <peter.selc@gmail.com> wrote:

> After normal server reboot (manual), the tunnel comes up automatically.
> In past it happened several times, that suddenly clients were not able to
> connect, I thought it was a bug and would be solved in next version, so I
> didn't pay much attention to it.
> Just after the recent incident, It happened to be right after the reboot
> caused by windows updates and I started looking into the logs.
>
> The last updates were:
> - 2020-01 Cumulative Update for .NET
> - 2020-01 Cumulative update for window server 2019 (1809)
> - Windows malicious software removal tool x64 - january 2020
>
> I will watch more closely and collect logs by the next occurrence.
>
> Thanks
> Peter
>
> On Sun, 26 Jan 2020 at 10:57, Jason A. Donenfeld <Jason@zx2c4.com> wrote:
>
>> Thanks for the report. Is this reproducible every time you reboot your
>> system, or only that one time after Windows Update?
>>
>> If the latter, do you have a list of what was being updated?
>>
>> Thanks,
>> Jason
>>
>> On Wed, Jan 22, 2020, 20:51 Peter Selc <peter.selc@gmail.com> wrote:
>>
>>> Hello all,
>>>
>>> I'm running version 0.0.38 on Windows 2019 server. Admin user logs in,
>>> starts the tunnel via GUI, disconnects from RDP session. Clients can
>>> connect.
>>>
>>> After the server is rebooted (windows updates), the tunnel doesn't come
>>> up automatically as it should, error is:
>>>
>>> 2020-01-15 15:00:56.197: [TUN] [Server] peer(SuXT…9iko) - Sending
>>> keepalive packet
>>> 2020-01-15 15:01:06.198: [TUN] [Server] peer(SuXT…9iko) - Sending
>>> keepalive packet
>>> 2020-01-15 15:01:31.236: [TUN] [Server] peer(SuXT…9iko) - Receiving
>>> keepalive packet
>>> 2020-01-15 15:01:49.729: [TUN] [Server] peer(SuXT…9iko) - Sending
>>> keepalive packet
>>> 2020-01-15 15:09:43.727: [TUN] [Server] peer(SuXT…9iko) - Removing all
>>> keys, since we haven't received a new one in 540 seconds
>>>
>>> -- reboot happens here--
>>>
>>> 2020-01-15 17:19:00.356: [MGR] Exited UI process for user
>>> 'admin_user@winserver' for session 2 with status 40010004
>>> 2020-01-15 17:19:01.417: [MGR] Starting UI process for user
>>> ‘admin_user@winserver’ for session 2
>>> 2020-01-15 17:19:02.350: [MGR] Exited UI process for user
>>> 'admin_user@winserver' for session 2 with status 1
>>> 2020-01-15 17:19:46.142: [TUN] [Server] Device closing
>>> 2020-01-15 17:19:46.146: [TUN] [Server] Routine: TUN reader - stopped
>>> 2020-01-15 17:19:46.217: [TUN] [Server] Routine: event worker - stopped
>>> 2020-01-15 17:19:46.222: [TUN] [Server] Routine: receive incoming IPv4 -
>>> stopped
>>> 2020-01-15 17:19:46.223: [TUN] [Server] Routine: receive incoming IPv6 -
>>> stopped
>>> 2020-01-15 17:19:46.223: [TUN] [Server] Routine: decryption worker -
>>> stopped
>>> 2020-01-15 17:19:46.224: [TUN] [Server] peer(1WB6…G/xk) - Stopping...
>>> 2020-01-15 17:19:46.224: [TUN] [Server] peer(1WB6…G/xk) - Routine:
>>> sequential receiver - stopped
>>> 2020-01-15 17:19:46.225: [TUN] [Server] peer(1WB6…G/xk) - Routine: nonce
>>> worker - stopped
>>> 2020-01-15 17:19:46.225: [TUN] [Server] Routine: encryption worker -
>>> stopped
>>> 2020-01-15 17:19:46.225: [TUN] [Server] Routine: handshake worker -
>>> stopped
>>> 2020-01-15 17:19:46.226: [TUN] [Server] Routine: encryption worker -
>>> stopped
>>> 2020-01-15 17:19:46.228: [TUN] [Server] Routine: decryption worker -
>>> stopped
>>> 2020-01-15 17:19:46.228: [TUN] [Server] Routine: handshake worker -
>>> stopped
>>> 2020-01-15 17:19:46.229: [TUN] [Server] peer(1WB6…G/xk) - Routine:
>>> sequential sender - stopped
>>> 2020-01-15 17:19:46.229: [TUN] [Server] peer(akUl…uaHM) - Stopping...
>>> 2020-01-15 17:19:46.230: [TUN] [Server] peer(akUl…uaHM) - Routine:
>>> sequential receiver - stopped
>>> 2020-01-15 17:19:46.268: [TUN] [Server] peer(akUl…uaHM) - Routine:
>>> sequential sender - stopped
>>> 2020-01-15 17:19:46.280: [TUN] [Server] peer(akUl…uaHM) - Routine: nonce
>>> worker - stopped
>>> 2020-01-15 17:19:46.319: [TUN] [Server] peer(UUvS…DwEo) - Stopping...
>>> 2020-01-15 17:19:46.321: [TUN] [Server] peer(UUvS…DwEo) - Routine:
>>> sequential receiver - stopped
>>> 2020-01-15 17:19:46.321: [TUN] [Server] peer(UUvS…DwEo) - Routine:
>>> sequential sender - stopped
>>> 2020-01-15 17:19:46.322: [TUN] [Server] peer(UUvS…DwEo) - Routine: nonce
>>> worker - stopped
>>> 2020-01-15 17:19:46.322: [TUN] [Server] peer(SuXT…9iko) - Stopping...
>>> 2020-01-15 17:19:46.322: [TUN] [Server] peer(SuXT…9iko) - Routine:
>>> sequential receiver - stopped
>>> 2020-01-15 17:19:46.323: [TUN] [Server] peer(SuXT…9iko) - Routine: nonce
>>> worker - stopped
>>> 2020-01-15 17:19:46.323: [TUN] [Server] peer(SuXT…9iko) - Routine:
>>> sequential sender - stopped
>>> 2020-01-15 17:19:46.324: [TUN] [Server] peer(JRsL…401s) - Stopping...
>>> 2020-01-15 17:19:46.325: [TUN] [Server] peer(JRsL…401s) - Routine:
>>> sequential receiver - stopped
>>> 2020-01-15 17:19:46.325: [TUN] [Server] peer(JRsL…401s) - Routine: nonce
>>> worker - stopped
>>> 2020-01-15 17:19:46.326: [TUN] [Server] peer(JRsL…401s) - Routine:
>>> sequential sender - stopped
>>> 2020-01-15 17:19:46.326: [TUN] [Server] peer(mWrq…/Xnc) - Stopping...
>>> 2020-01-15 17:19:46.327: [TUN] [Server] peer(mWrq…/Xnc) - Routine:
>>> sequential receiver - stopped
>>> 2020-01-15 17:19:46.327: [TUN] [Server] peer(mWrq…/Xnc) - Routine:
>>> sequential sender - stopped
>>> 2020-01-15 17:19:46.328: [TUN] [Server] peer(mWrq…/Xnc) - Routine: nonce
>>> worker - stopped
>>> 2020-01-15 17:19:46.328: [TUN] [Server] Interface closed
>>> 2020-01-15 17:19:46.328: [TUN] [Server] Shutting down
>>> 2020-01-15 17:21:00.637: [MGR] Starting WireGuard/0.0.38 (Windows Server
>>> 10.0.17763; amd64)
>>> 2020-01-15 17:21:00.637: [TUN] [Server] Starting WireGuard/0.0.38
>>> (Windows Server 10.0.17763; amd64)
>>> 2020-01-15 17:21:00.760: [TUN] [Server] SCM locked for 27s by .\NT
>>> Service Control Manager, marking service as started
>>> 2020-01-15 17:21:00.784: [TUN] [Server] Watching network interfaces
>>> 2020-01-15 17:21:00.837: [TUN] [Server] Resolving DNS names
>>> 2020-01-15 17:21:01.033: [TUN] [Server] Creating Wintun interface
>>> 2020-01-15 17:21:08.159: [TUN] [Server] Unable to create Wintun
>>> interface: Error creating interface:
>>> SetupDiCallClassInstaller(DIF_REGISTERDEVICE) failed: winapi error
>>> #3758096907
>>> 2020-01-15 17:21:08.207: [TUN] [Server] Shutting down
>>> 2020-01-15 17:21:11.161: [MGR] Removing Wintun interface ‘Local Area
>>> Connection’ because determining tunnel service name failed: Tunnel name is
>>> not valid
>>>
>>> Is this some known behaviour with a known fix, or not supported yet?
>>> Many thanks,
>>>
>>> Peter
>>> _______________________________________________
>>> WireGuard mailing list
>>> WireGuard@lists.zx2c4.com
>>> https://lists.zx2c4.com/mailman/listinfo/wireguard
>>>
>>

[-- Attachment #1.2: Type: text/html, Size: 14186 bytes --]

[-- Attachment #2: Type: text/plain, Size: 148 bytes --]

_______________________________________________
WireGuard mailing list
WireGuard@lists.zx2c4.com
https://lists.zx2c4.com/mailman/listinfo/wireguard