Docker Community Forums

Share and learn in the Docker community.

Docker Desktop starting is slow - takes minutes

Hi,

docker takes very long to start. It takes about 10 minutes! Can you suggest what to do? Thank You!

Logs:

Version: 2.2.0.5 (43884)
Channel: stable
Sha1: 758e889f2c543b35d0bdfa51e811744f686d81b3
Started on: 2020/04/04 13:21:47.581
Resources: C:\Program Files\Docker\Docker\resources
OS: Windows 10 Pro
Edition: Professional
Id: 1909
Build: 18363
BuildLabName: 18362.1.amd64fre.19h1_release.190318-1202
File: C:\Users\Max\AppData\Local\Docker\log.txt
CommandLine: “C:\Program Files\Docker\Docker\Docker Desktop.exe”
You can send feedback, including this log file, at
[13:21:47.772][GUI ][Info ] Starting…
[13:21:47.881][ComponentVersions ][Info ] Edition community
[13:21:48.022][ComponentVersions ][Info ] Edition community
[13:21:48.543][AppMigrator ][Info ] Current version: 5. Latest version: 5
[13:21:48.793][TrackingSettings ][Info ] Crash report and usage statistics are disabled
[13:21:49.610][ApplicationTemplatesTracking][Info ] Cannot list templates
[13:21:49.610][SegmentApi ][Info ] Usage statistic: heartbeat
[13:21:49.923][NamedPipeClient ][Info ] Sending app/version()…
[13:21:49.938][NamedPipeClient ][Info ] Received response for app/version
[13:21:49.938][NamedPipeClient ][Info ] Sending app/migrate()…
[13:21:49.938][NamedPipeClient ][Info ] Received response for app/migrate
[13:21:49.938][NamedPipeServer ][Info ] app/version done in 00:00:00.
[13:21:49.938][NamedPipeServer ][Info ] app/migrate()
[13:21:49.938][NamedPipeServer ][Info ] app/migrate done in 00:00:00.
[13:21:49.970][NamedPipeClient ][Info ] Sending app/version()…
[13:21:49.970][NamedPipeClient ][Info ] Received response for app/version
[13:21:49.970][NamedPipeClient ][Info ] Sending version-packs/enable(community, Docker.Core.Settings)…
[13:21:49.970][NamedPipeServer ][Info ] app/version()
[13:21:49.970][NamedPipeServer ][Info ] app/version done in 00:00:00.
[13:21:49.970][NamedPipeClient ][Info ] Received response for version-packs/enable
[13:21:49.970][NamedPipeServer ][Info ] version-packs/enable(community, Docker.Core.Settings)
[13:21:49.970][NamedPipeServer ][Info ] version-packs/enable done in 00:00:00.
[13:21:50.016][NamedPipeClient ][Info ] Sending app/version()…
[13:21:50.016][NamedPipeClient ][Info ] Received response for app/version
[13:21:50.016][NamedPipeClient ][Info ] Sending engine/start(Linux, Docker.Core.Settings, Docker.Core.DaemonOptions, )…
[13:21:50.016][NamedPipeServer ][Info ] app/version()
[13:21:50.016][NamedPipeServer ][Info ] app/version done in 00:00:00.
[13:21:50.016][NamedPipeServer ][Info ] engine/start(Linux, Docker.Core.Settings, Docker.Core.DaemonOptions, )
[13:21:50.079][Linux ][Info ] Setting container engine status to Starting
[13:21:50.325][HyperV ][Info ] Stop
[13:21:50.344][PowerShell ][Info ] Run script with parameters: -Stop True -VmName DockerDesktopVM -SwitchName DockerNAT -Verbose True -ErrorAction Stop
[13:21:50.444][HyperV ][Info ] VM DockerDesktopVM does not exist
[13:21:50.444][HyperV ][Debug ] [stop] took 00:00:00.1199848 to run
[13:21:50.444][OptimizeDisk ][Info ] Optimize
[13:21:50.444][PowerShell ][Info ] Run script…
[13:21:50.544][APIRequestLogger ][Info ] [2b19560c] GET
[13:21:50.550][GoBackendClient ][Warning] HttpOS Client: connection timed out.
[13:21:50.641][GoBackendClient ][Error ] Error fetching experimental features: System.TimeoutException: Timeout für den Vorgang wurde überschritten.
bei System.IO.Pipes.NamedPipeClientStream.ConnectInternal(Int32 timeout, CancellationToken cancellationToken, Int32 startTime)
bei System.Threading.Tasks.Task.Execute()
— Ende der Stapelüberwachung vom vorhergehenden Ort, an dem die Ausnahme ausgelöst wurde —
bei System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
bei System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
bei HttpOverStream.NamedPipe.NamedPipeDialer.d__7.MoveNext()
— Ende der Stapelüberwachung vom vorhergehenden Ort, an dem die Ausnahme ausgelöst wurde —
bei System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
bei System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
bei HttpOverStream.Client.DialMessageHandler.d__9.MoveNext()
— Ende der Stapelüberwachung vom vorhergehenden Ort, an dem die Ausnahme ausgelöst wurde —
bei System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
bei System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
bei Docker.Core.Logging.APIRequestLogger.d__3.MoveNext()
— Ende der Stapelüberwachung vom vorhergehenden Ort, an dem die Ausnahme ausgelöst wurde —
bei System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
bei System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
bei System.Net.Http.HttpClient.d__58.MoveNext()
— Ende der Stapelüberwachung vom vorhergehenden Ort, an dem die Ausnahme ausgelöst wurde —
bei System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
bei System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
bei Docker.Core.GoBackend.GoBackendClient.d__9.MoveNext()
[13:21:50.656][VpnKitBridge ][Info ] Starting C:\Program Files\Docker\Docker\resources\vpnkit-bridge.exe --addr listen://00000000-0000-0000-0000-000000000000/000007CF-FACB-11E6-BD58-64006A7986D3 host
[13:21:50.656][VpnKitBridge ][Info ] Started
[13:21:50.656][HyperVGuids ][Info ] Installing GUIDs…
[13:21:50.656][HyperV ][Info ] Create
[13:21:50.656][HyperVGuids ][Info ] GUIDs installed
[13:21:50.656][Firewall ][Info ] Removing all existing rules…
[13:21:50.656][HyperV ][Info ] filesharing does not need a Hyper-V NIC so omitting it
[13:21:50.656][PowerShell ][Info ] Run script with parameters: -Create True -VmName DockerDesktopVM -VhdPathOverride C:\ProgramData\DockerDesktop\vm-data\DockerDesktop.vhdx -VhdSize 68719476736 -SwitchSubnetAddress 10.0.75.0 -SwitchSubnetMaskSize 28 -PreferredIPAddress -CPUs 2 -Memory 2048 -IsoFile C:\Program Files\Docker\Docker\resources\docker-desktop.iso -SwitchName -Verbose True -ErrorAction Stop
[13:21:50.760][Firewall ][Info ] All existing rules are removed.
[13:21:50.760][Firewall ][Info ] Opening ports for SMB…
[13:21:50.775][Firewall ][Info ] Ports are opened
[13:21:50.854][VpnKitBridge ][Info ] time=“2020-04-04T13:21:50+02:00” msg=“listening on listen://00000000-0000-0000-0000-000000000000/000007CF-FACB-11E6-BD58-64006A7986D3…”
[13:21:50.862][VpnKitBridge ][Info ] time=“2020-04-04T13:21:50+02:00” msg=“waiting for connection on listen://00000000-0000-0000-0000-000000000000/000007CF-FACB-11E6-BD58-64006A7986D3…”
[13:21:52.431][APIRequestLogger ][Info ] [5c12dc62] GET **tp://unix/versions
[13:21:52.556][APIRequestLogger ][Info ] [5c12dc62] GET **tp://unix/versions -> 200 OK (took 122ms)
[13:21:52.648][GoBackendProcess ][Info ] ⇨ http server started on \.\pipe\dockerVpnKitControl
[13:21:52.710][HyperV ][Info ] Creating VM DockerDesktopVM…
[13:21:52.718][GoBackendProcess ][Info ] time=“2020-04-04T13:21:52+02:00” msg=“started port-forwarding control server on \\.\pipe\dockerVpnKitControl”
[13:21:52.722][GoBackendProcess ][Info ] time=“2020-04-04T13:21:52+02:00” msg=“listening on unix:\\.\pipe\dockerVpnkitData for data connection”
[13:21:52.729][APIRequestLogger ][Info ] [ce34ed01] GET **tp://unix/settings
[13:21:52.722][GoBackendProcess ][Info ] time=“2020-04-04T13:21:52+02:00” msg=“grpcfuseV2 feature-flag set so enabling FUSE cache invalidation and event injection”
[13:21:52.726][GoBackendProcess ][Info ] ⇨ http server started on \.\pipe\dockerBackendApiServerForGuest
[13:21:52.728][GoBackendProcess ][Info ] ⇨ http server started on \.\pipe\dockerBackendApiServer
[13:21:52.794][APIRequestLogger ][Info ] [ce34ed01] GET **tp://unix/settings -> 200 OK (took 77ms)
[13:21:52.873][APIRequestLogger ][Info ] [bbb9ab61] GET **tp://unix/settings
[13:21:52.883][APIRequestLogger ][Info ] [bbb9ab61] GET **tp://unix/settings -> 200 OK (took 10ms)
[13:21:52.887][GoBackendProcess ][Info ] time=“2020-04-04T13:21:52+02:00” msg=“Adding filesystem export C:\”
[13:21:52.888][GoBackendProcess ][Info ] time=“2020-04-04T13:21:52+02:00” msg=“enabling filesystem caching”
[13:21:52.888][GoBackendProcess ][Info ] time=“2020-04-04T13:21:52+02:00” msg=“enabling inotify event injection”
[13:21:52.888][GoBackendProcess ][Info ] time=“2020-04-04T13:21:52+02:00” msg=“filesystem exports are: C:\ (2)”
[13:21:52.890][GoBackendProcess ][Info ] time=“2020-04-04T13:21:52+02:00” msg=“volume control server listening on \\.\pipe\dockerVolume”
[13:21:52.895][GoBackendProcess ][Info ] time=“2020-04-04T13:21:52+02:00” msg=“filesystem server listening on 00000000-0000-0000-0000-000000000000:00001003-facb-11e6-bd58-64006a7986d3”
[13:21:52.896][GoBackendProcess ][Info ] time=“2020-04-04T13:21:52+02:00” msg=“file ownership will be determined by the calling user (“fake owner” mode)”
[13:21:52.896][GoBackendProcess ][Info ] time=“2020-04-04T13:21:52+02:00” msg=“using mfsymlinks”
[13:30:49.002][HyperV ][Info ] Setting CPUs to 2 and Memory to 2048 MB
[13:30:49.585][HyperV ][Info ] Attach VHD C:\ProgramData\DockerDesktop\vm-data\DockerDesktop.vhdx
[13:30:51.246][HyperV ][Info ] Attach DVD C:\Program Files\Docker\Docker\resources\docker-desktop.iso
[13:30:52.466][HyperV ][Info ] Disabled Gastdienstschnittstelle
[13:30:52.513][HyperV ][Info ] Enabled Takt
[13:30:52.574][HyperV ][Info ] Disabled Austausch von Schlüsselwertepaaren
[13:30:52.605][HyperV ][Info ] Enabled Herunterfahren
[13:30:52.652][HyperV ][Info ] Enabled Zeitsynchronisierung
[13:30:52.709][HyperV ][Info ] Disabled VSS
[13:30:53.223][HyperV ][Info ] VM created.
[13:30:53.223][HyperV ][Debug ] [create] took 00:09:02.5664507 to run
[13:30:53.223][PowerShell ][Info ] Run script ‘(Hyper-V\Get-VM DockerDesktopVM).Id.Guid’…
[13:30:53.285][IsoConfig ][Info ] Generating CA Cert Bundle
[13:30:53.317][IsoConfig ][Info ] CA Cert Bundle Generated
[13:31:00.715][HyperV ][Info ] Start
[13:31:00.715][PowerShell ][Info ] Run script with parameters: -Start True -VmName DockerDesktopVM -IsoFile C:\Program Files\Docker\Docker\resources\docker-desktop.iso -confIsoFile C:\ProgramData\DockerDesktop\tmp-d4w\config.iso -VhdPathOverride C:\ProgramData\DockerDesktop\vm-data\DockerDesktop.vhdx -DockerIsoFile C:\Program Files\Docker\Docker\resources\docker.iso -Verbose True -ErrorAction Stop
[13:31:00.809][HyperV ][Info ] Starting VM DockerDesktopVM…
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Setting handler to ignore all SIGPIPE signals
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Version is 218f01482560cba2fa863f9ad872ad51d1e717fc
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: System SOMAXCONN is 2147483647
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Will use a listen backlog of 32
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: No periodic Gc.compact enabled
[13:31:00.856][VpnKit ][Error ] vpnkit.exe: Starting to watch : EINVAL
[13:31:00.856][VpnKit ][Error ] vpnkit.exe: Failed to watch hosts file : invalid argument
[13:31:00.856][VpnKit ][Warning] vpnkit.exe: There is no database: using hardcoded network configuration values
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: DNS server configured with no builtin DNS names; everything will be forwarded
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: 2 upstream DNS servers are configured
[13:31:00.856][VpnKit ][Error ] vpnkit.exe: While watching /etc/resolv.conf: ENOENT
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Disabling transparent HTTP redirection
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Updating resolvers to use host resolver
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Secure random number generator is available
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Add(3): DNS configuration changed to: use host resolver
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: DNS server configured with builtin DNS names [ gateway.docker.internal -> 192.168.65.1, docker.for.win.gateway.internal -> 192.168.65.1, docker.for.win.http.internal -> 192.168.65.1, host.docker.internal -> 192.168.65.2, docker.for.win.host.internal -> 192.168.65.2, docker.for.win.localhost -> 192.168.65.2, vm.internal -> 192.168.65.3 ]
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Will use the host’s DNS resolver
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Transparent HTTP redirection configuration file C:\Users\Max\AppData\Roaming\Docker\http_proxy.json has changed
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Reading transparent HTTP redirection from C:\Users\Max\AppData\Roaming\Docker\http_proxy.json
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Watching transparent HTTP redirection configuration file C:\Users\Max\AppData\Roaming\Docker\http_proxy.json for changes
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: New Gateway forward configuration:
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Gateway forwards file C:\Users\Max\AppData\Roaming\Docker\gateway_forwards.json has changed
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Reading gateway forwards file from C:\Users\Max\AppData\Roaming\Docker\gateway_forwards.json
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Watching gateway forwards file C:\Users\Max\AppData\Roaming\Docker\gateway_forwards.json for changes
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Configuration server_macaddr = f6:16:36:bc:f9:c6; max_connection = None; dns_path = None; dns = ; resolver = Host; domain = None; allowed_bind_addresses = 0.0.0.0; gateway_ip = 192.168.65.1; host_ip = 192.168.65.2; lowest_ip = 192.168.65.3; highest_ip = 192.168.65.14; dhcp_json_path = None; dhcp_configuration = None; mtu = 1500; http_intercept = None; http_intercept_path = C:\Users\Max\AppData\Roaming\Docker\http_proxy.json; port_max_idle_time = 300; host_names = host.docker.internal, docker.for.win.host.internal, docker.for.win.localhost; gateway_names = gateway.docker.internal, docker.for.win.gateway.internal, docker.for.win.http.internal; vm_names = vm.internal; udpv4_forwards = ; tcpv4_forwards = ; gateway_forwards_path = C:\Users\Max\AppData\Roaming\Docker\gateway_forwards.json; pcap_snaplen = 128
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: Updating transparent HTTP redirection: {
[13:31:00.856][VpnKit ][Info ] “exclude”: “”,
[13:31:00.856][VpnKit ][Info ] “transparent_http_ports”: [
[13:31:00.856][VpnKit ][Info ] 80
[13:31:00.856][VpnKit ][Info ] ],
[13:31:00.856][VpnKit ][Info ] “transparent_https_ports”: [
[13:31:00.856][VpnKit ][Info ] 443
[13:31:00.856][VpnKit ][Info ] ]
[13:31:00.856][VpnKit ][Info ] }
[13:31:00.856][VpnKit ][Info ] vpnkit.exe: New Gateway forward configuration: [{“protocol”:“udp”,“external_port”:53,“internal_ip”:“127.0.0.1”,“internal_port”:59610},{“protocol”:“tcp”,“external_port”:53,“internal_ip”:“127.0.0.1”,“internal_port”:50608}]
[13:31:01.353][HyperV ][Info ] Remove existing DVDs
[13:31:02.027][HyperV ][Info ] Attach DVD C:\Program Files\Docker\Docker\resources\docker-desktop.iso
[13:31:02.416][HyperV ][Info ] Attach Config ISO C:\ProgramData\DockerDesktop\tmp-d4w\config.iso
[13:31:03.837][HyperV ][Info ] Attach Docker ISO C:\Program Files\Docker\Docker\resources\docker.iso
[13:31:07.506][HyperV ][Debug ] [start] took 00:00:06.7904462 to run
[13:31:07.521][LifecycleClient ][Info ] Waiting for lifecycle-server for up to 00:10:00
[13:31:07.521][APIRequestLogger ][Info ] [71bacb2e] GET **tp://localhost/ping
[13:31:07.873][APIRequestLogger ][Info ] [ffaf3f6a] GET **tp://unix/versions
[13:31:07.874][APIRequestLogger ][Info ] [ffaf3f6a] GET **tp://unix/versions -> 200 OK (took 0ms)
[13:31:07.968][ApiProxy ][Info ] time=“2020-04-04T13:31:07+02:00” msg=“🍀 socket server listening : \\.\pipe\dockerGuiToDriver”
[13:31:07.974][ApiProxy ][Info ] time=“2020-04-04T13:31:07+02:00” level=info msg=waitForDockerUp
[13:31:07.977][ApiProxy ][Info ] time=“2020-04-04T13:31:07+02:00” msg=“Static DNS lookup table: map[docker-desktop.:192.168.65.3 docker-for-desktop.:192.168.65.3 docker.for.win.gateway.internal.:192.168.65.1 docker.for.win.host.internal.:192.168.65.2 docker.for.win.http.internal.:192.168.65.1 docker.for.win.localhost.:192.168.65.2 gateway.docker.internal.:192.168.65.1 host.docker.internal.:192.168.65.2 kubernetes.docker.internal.:192.168.65.3 vm.docker.internal.:192.168.65.3]”
[13:31:07.977][ApiProxy ][Info ] time=“2020-04-04T13:31:07+02:00” msg=“🍀 socket server starting : \\.\pipe\dockerGuiToDriver”
[13:31:07.982][ApiProxy ][Info ] time=“2020-04-04T13:31:07+02:00” msg=“Writing C:\Users\Max\AppData\Roaming\Docker\gateway_forwards.json”
[13:31:10.861][VpnKit ][Info ] vpnkit.exe: Gateway forwards file C:\Users\Max\AppData\Roaming\Docker\gateway_forwards.json has changed
[13:31:10.861][VpnKit ][Info ] vpnkit.exe: Reading gateway forwards file from C:\Users\Max\AppData\Roaming\Docker\gateway_forwards.json
[13:31:10.861][VpnKit ][Info ] vpnkit.exe: New Gateway forward configuration: [{“protocol”:“udp”,“external_port”:53,“internal_ip”:“127.0.0.1”,“internal_port”:59686},{“protocol”:“tcp”,“external_port”:53,“internal_ip”:“127.0.0.1”,“internal_port”:53914}]
[13:31:12.108][VpnKitBridge ][Info ] time=“2020-04-04T13:31:12+02:00” msg=“connected!”
[13:31:12.118][VpnKitBridge ][Info ] time=“2020-04-04T13:31:12+02:00” msg=“Proxy lifecycle-server: waiting for remote service to be available”
[13:31:12.119][VpnKitBridge ][Info ] time=“2020-04-04T13:31:12+02:00” msg=“Proxy filesystem-event: waiting for remote service to be available”
[13:31:12.119][VpnKitBridge ][Info ] time=“2020-04-04T13:31:12+02:00” msg=“Proxy diagnosticd: waiting for remote service to be available”
[13:31:12.119][VpnKitBridge ][Info ] time=“2020-04-04T13:31:12+02:00” msg=“Proxy docker: waiting for remote service to be available”
[13:31:12.119][VpnKitBridge ][Info ] time=“2020-04-04T13:31:12+02:00” msg=“Proxy log: waiting for remote service to be available”
[13:31:12.125][VpnKitBridge ][Info ] time=“2020-04-04T13:31:12+02:00” msg=“Proxy wsl2-bootstrap-expose-ports: waiting for remote service to be available”
[13:31:12.152][VpnKit ][Error ] vpnkit.exe: Pipe.listen: caught (Failure “Failed to connect vmnet device”)
[13:31:12.159][GoBackendProcess ][Info ] time=“2020-04-04T13:31:12+02:00” msg=“accepted data connection on unix:\\.\pipe\dockerVpnkitData”
[13:31:12.159][VpnKitBridge ][Info ] time=“2020-04-04T13:31:12+02:00” msg=“received ack for service log, publishing locally”
[13:31:12.160][GoBackendProcess ][Error ] time=“2020-04-04T13:31:12+02:00” msg=“error accepting multiplexer data connection: EOF”
[13:31:12.160][GoBackendProcess ][Info ] time=“2020-04-04T13:31:12+02:00” msg=“listening on unix:\\.\pipe\dockerVpnkitData for data connection”
[13:31:12.168][VpnKitBridge ][Info ] time=“2020-04-04T13:31:12+02:00” msg=“cannot find service “ssh-auth””
[13:31:40.789][VpnKitBridge ][Info ] time=“2020-04-04T13:31:40+02:00” msg=“received ack for service diagnosticd, publishing locally”
[13:31:40.935][GoBackendProcess ][Info ] time=“2020-04-04T13:31:40+02:00” msg=“internal: GET /ping 200 “Go-http-client/1.1” “””
[13:31:40.940][GoBackendProcess ][Info ] time=“2020-04-04T13:31:40+02:00” msg=“internal: GET /goos 200 “Go-http-client/1.1” “””
[13:31:40.976][GoBackendProcess ][Info ] time=“2020-04-04T13:31:40+02:00” msg=“internal: POST /events 200 “Go-http-client/1.1” “””
[13:31:41.022][APIRequestLogger ][Info ] [1f1ca926] POST **tp://unix/docker
[13:31:41.134][APIRequestLogger ][Info ] [1f1ca926] POST **tp://unix/docker -> 204 NoContent (took 112ms)
[13:31:41.135][GoBackendProcess ][Info ] time=“2020-04-04T13:31:41+02:00” msg=“internal: POST /events 200 “Go-http-client/1.1” “””
[13:31:41.297][VpnKitBridge ][Info ] time=“2020-04-04T13:31:41+02:00” msg=“received ack for service filesystem-event, publishing locally”
[13:31:41.303][VpnKitBridge ][Info ] time=“2020-04-04T13:31:41+02:00” msg=“received ack for service lifecycle-server, publishing locally”
[13:31:41.316][APIRequestLogger ][Info ] [71bacb2e] GET **tp://localhost/ping -> 200 OK (took 33781ms)
[13:31:41.317][LifecycleClient ][Info ] Lifecycle-server is responding.
[13:31:41.318][Linux ][Info ] Attempting to mount drive C
[13:31:41.318][GrpcFuse ][Info ] Mount C
[13:31:41.319][APIRequestLogger ][Info ] [62c04933] POST **tp://localhost/mount
[13:31:41.343][GoBackendProcess ][Info ] time=“2020-04-04T13:31:41+02:00” msg=“filesystem watcher supports cache invalidation: setting long FUSE timeouts”
[13:31:41.361][APIRequestLogger ][Info ] [62c04933] POST **tp://localhost/mount -> 200 OK (took 42ms)
[13:31:41.361][Linux ][Info ] All drives mounted, starting the Docker engine
[13:31:41.370][APIRequestLogger ][Info ] [fcfd54c8] GET **tp://unix/settings
[13:31:41.362][APIRequestLogger ][Info ] [16197883] GET **tp://localhost/docker/start
[13:31:41.376][APIRequestLogger ][Info ] [fcfd54c8] GET **tp://unix/settings -> 200 OK (took 5ms)
[13:31:41.377][GoBackendProcess ][Info ] time=“2020-04-04T13:31:41+02:00” msg=“internal: GET /engine/daemon.json 200 “Go-http-client/1.1” “””
[13:31:41.389][APIRequestLogger ][Info ] [16197883] GET **tp://localhost/docker/start -> 200 OK (took 27ms)
[13:31:41.390][Linux ][Info ] Docker engine is starting
[13:31:42.003][GoBackendProcess ][Info ] time=“2020-04-04T13:31:42+02:00” msg=“accepted data connection on unix:\\.\pipe\dockerVpnkitData”
[13:31:42.004][GoBackendProcess ][Info ] time=“2020-04-04T13:31:42+02:00” msg=“established connection to vpnkit-forwarder”
[13:31:42.200][VpnKit ][Info ] vpnkit.exe: Vmnet.Server.negotiate: received { magic = VMN3T; version = 22; commit = }
[13:31:42.204][VpnKit ][Info ] vpnkit.exe: Generated UUID on behalf of client: 9ff6ed2f-7e5e-4bb1-b7c3-70bac4bd54f0
[13:31:42.204][VpnKit ][Info ] vpnkit.exe: Vmnet.Server.negotiate: received Ethernet 9ff6ed2f-7e5e-4bb1-b7c3-70bac4bd54f0
[13:31:42.204][VpnKit ][Info ] vpnkit.exe: Vmnet.Server.negotiate: sending { mtu = 1500; max_packet_size = 1550; client_macaddr = 02:50:00:00:00:01 }
[13:31:42.204][VpnKit ][Info ] vpnkit.exe: Vmnet.Server.listen: rebinding the primary listen callback
[13:31:42.204][VpnKit ][Info ] vpnkit.exe: Vmnet.Server.listen: starting event loop
[13:31:42.204][VpnKit ][Info ] vpnkit.exe: Connected Ethernet interface f6:16:36:bc:f9:c6
[13:31:42.205][VpnKit ][Info ] vpnkit.exe: Client mac: 02:50:00:00:00:01 server mac: f6:16:36:bc:f9:c6
[13:31:42.205][VpnKit ][Info ] vpnkit.exe: TCP/IP ready
[13:31:42.205][VpnKit ][Info ] vpnkit.exe: TCP/IP stack connected
[13:31:42.205][VpnKit ][Info ] vpnkit.exe: Starting diagnostics server on: \.\pipe\dockerVpnKitDiagnostics
[13:31:42.313][VpnKitBridge ][Info ] time=“2020-04-04T13:31:42+02:00” msg=“received ack for service docker, publishing locally”
[13:31:43.557][VpnKit ][Info ] vpnkit.exe: Connected Ethernet interface f6:16:36:bc:f9:c6
[13:31:43.557][VpnKit ][Info ] vpnkit.exe: UDP interface connected on 192.168.65.1
[13:31:44.644][ApiProxy ][Info ] time=“2020-04-04T13:31:44+02:00” msg=“Docker is responding”
[13:31:44.684][APIRequestLogger ][Info ] [8a2e7631] POST **tp://unix/docker
[13:31:44.685][NamedPipeClient ][Info ] Sending app/version()…
[13:31:44.686][NamedPipeClient ][Info ] Received response for app/version
[13:31:44.686][NamedPipeClient ][Info ] Sending engine/notify-linux-status(DaemonStarted)…
[13:31:44.690][NamedPipeClient ][Info ] Received response for engine/notify-linux-status
[13:31:44.691][APIRequestLogger ][Info ] [8a2e7631] POST **tp://unix/docker -> 204 NoContent (took 6ms)
[13:31:44.686][NamedPipeServer ][Info ] app/version()
[13:31:44.686][NamedPipeServer ][Info ] app/version done in 00:00:00.
[13:31:44.690][NamedPipeServer ][Info ] engine/notify-linux-status(DaemonStarted)
[13:31:44.690][Linux ][Info ] Setting container engine status to DaemonStarted
[13:31:44.690][NamedPipeServer ][Info ] engine/notify-linux-status done in 00:00:00.
[13:31:44.691][GoBackendProcess ][Info ] time=“2020-04-04T13:31:44+02:00” msg=“internal: POST /events 200 “Go-http-client/1.1” “””
[13:31:51.663][ApiProxy ][Info ] time=“2020-04-04T13:31:51+02:00” msg=“proxy >> HEAD /_ping\n”
[13:31:51.666][ApiProxy ][Info ] time=“2020-04-04T13:31:51+02:00” msg=“proxy << HEAD /_ping (5.0865ms)\n”
[13:31:51.687][ApiProxy ][Info ] time=“2020-04-04T13:31:51+02:00” msg=“proxy >> GET /v1.40/containers/json\n”
[13:31:51.691][ApiProxy ][Info ] time=“2020-04-04T13:31:51+02:00” msg=“proxy << GET /v1.40/containers/json (5.0022ms)\n”
[13:31:51.702][NamedPipeClient ][Info ] Received response for engine/start
[13:31:51.702][DockerDaemonChecker][Info ] Docker daemon is running
[13:31:51.702][Linux ][Info ] Setting container engine status to Started
[13:31:51.702][NamedPipeServer ][Info ] engine/start done in 00:10:01.6856629.
[13:31:51.722][Notifications ][Info ] Docker Desktop is running
[13:31:51.952][ApiProxy ][Info ] time=“2020-04-04T13:31:51+02:00” msg=“proxy >> HEAD /_ping\n”
[13:31:51.955][ApiProxy ][Info ] time=“2020-04-04T13:31:51+02:00” msg=“proxy << HEAD /_ping (2.9959ms)\n”
[13:31:51.980][ApiProxy ][Info ] time=“2020-04-04T13:31:51+02:00” msg=“proxy >> GET /v1.40/info\n”
[13:31:52.002][ApiProxy ][Info ] time=“2020-04-04T13:31:52+02:00” msg=“proxy << GET /v1.40/info (23.009ms)\n”
[13:31:52.408][ApiProxy ][Info ] time=“2020-04-04T13:31:52+02:00” msg=“proxy >> HEAD /_ping\n”
[13:31:52.411][ApiProxy ][Info ] time=“2020-04-04T13:31:52+02:00” msg=“proxy << HEAD /_ping (2.9971ms)\n”
[13:31:52.494][ApiProxy ][Info ] time=“2020-04-04T13:31:52+02:00” msg=“proxy >> GET /v1.40/version\n”
[13:31:52.509][ApiProxy ][Info ] time=“2020-04-04T13:31:52+02:00” msg=“proxy << GET /v1.40/version (14.9782ms)\n”
[13:31:52.521][Actions ][Debug ] Start took 00:10:02.5669785
[13:31:52.533][NamedPipeClient ][Info ] Sending app/version()…
[13:31:52.534][NamedPipeClient ][Info ] Received response for app/version
[13:31:52.535][NamedPipeClient ][Info ] Sending filesharing/get-protocol()…
[13:31:52.534][NamedPipeServer ][Info ] app/version()
[13:31:52.534][NamedPipeServer ][Info ] app/version done in 00:00:00.
[13:31:52.535][NamedPipeServer ][Info ] filesharing/get-protocol()
[13:31:52.541][NamedPipeClient ][Info ] Received response for filesharing/get-protocol
[13:31:52.535][APIRequestLogger ][Info ] [1be11f00] GET **tp://localhost/features
[13:31:52.537][GoBackendProcess ][Info ] time=“2020-04-04T13:31:52+02:00” msg=“external: GET /features 200 “” “””
[13:31:52.541][APIRequestLogger ][Info ] [1be11f00] GET **tp://localhost/features -> 200 OK (took 5ms)
[13:31:52.541][NamedPipeServer ][Info ] filesharing/get-protocol done in 00:00:00.0060054.
[13:31:52.659][ApiProxy ][Info ] time=“2020-04-04T13:31:52+02:00” msg=“proxy >> HEAD /_ping\n”
[13:31:52.663][ApiProxy ][Info ] time=“2020-04-04T13:31:52+02:00” msg=“proxy << HEAD /_ping (3.0048ms)\n”
[13:31:52.682][ApiProxy ][Info ] time=“2020-04-04T13:31:52+02:00” msg=“proxy >> GET /v1.40/info\n”
[13:31:52.696][ApiProxy ][Info ] time=“2020-04-04T13:31:52+02:00” msg=“proxy << GET /v1.40/info (14.9829ms)\n”
[13:31:53.074][ApiProxy ][Info ] time=“2020-04-04T13:31:53+02:00” msg=“proxy >> HEAD /_ping\n”
[13:31:53.077][ApiProxy ][Info ] time=“2020-04-04T13:31:53+02:00” msg=“proxy << HEAD /_ping (4.0144ms)\n”
[13:31:53.153][ApiProxy ][Info ] time=“2020-04-04T13:31:53+02:00” msg=“proxy >> GET /v1.40/version\n”
[13:31:53.165][ApiProxy ][Info ] time=“2020-04-04T13:31:53+02:00” msg=“proxy << GET /v1.40/version (12.1378ms)\n”