Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

com.docker.hyperkit 100% cpu usage is back again #3499

Closed
2 tasks done
stephenc opened this issue Jan 31, 2019 · 621 comments
Closed
2 tasks done

com.docker.hyperkit 100% cpu usage is back again #3499

stephenc opened this issue Jan 31, 2019 · 621 comments

Comments

@stephenc
Copy link

@stephenc stephenc commented Jan 31, 2019

Summary

This is an issue with a lot of comments and rumors of fixes and confusion over what the exact issue underlying this bug is.

False leads

Here is what we know, because it can get lost in the comments.

  • This issue is not k8s related. The root cause of the issue is reported to be triggered more often when using Docker's k8s provider, so one way to reduce how often you are hit by the issue is to turn off Docker's k8s provider and use k3d instead
  • This issue is not related to container workload. I have had this issue trip while Docker was running with 0 containers.... and then suddenly Docker CPU spikes to 100% and I have not touched it at all.
  • Restarting Docker is a temporary workaround. WARNING If you think you have "fixed" this issue by changing the CPU cores in the Docker preferences (up or down) or changing the RAM allocation (up or down)... congratulations, you have just restarted Docker... please wait for the issue to repeat itself. Your changing settings has not fixed it, only stopped the current CPU spike

Current hypothesis

There is an edge case in the filesystem synchronization code and when triggered it causes the receiver process in the Docker VM to go into an infinite loop and suck all the CPU cycles of one CPU core.

As of 2020-05-28, the leading candidate for this hypothesis is around this line of code: https://github.com/moby/hyperkit/blob/79c6a4d95e3f8a59f774eb66e3ea333a277292c6/src/lib/mirage_block_ocaml.ml#L422 and see this comment: #3499 (comment)

Mitigations

Things that can cause the infinite loop seem to involve syncing of file system events between OS-X and the docker VM. The fewer file system shares you have, the less likely this is to occur. Similarly, if you can switch your filesystem mounts to :cached then that means there will be fewer notifications being sent back and forth between the Docker VM and OS-X, just less chance of the issue.

The native Docker K8s implementation seems to involve a lot of this kind of sync, so you are more likely to trip over the issue.

Stuff I have found that makes life easier:

  1. Remove all unnecessary file sharing mounts. I had this issue a lot when I included the default /Volumes but once I removed that the frequency of occurrence was greatly reduced:
    Screenshot 2020-05-12 at 11 09 44 I leave /private and /tmp because some of the projects I work on have tests that use TempDirs as docker volume mounts.
  2. Ensure there is more than one CPU core allocated to Docker. If you have more than 1 core then you can quit docker without a reboot (NOTE: in extreme cases you may need to force quit docker processes from Activity Monitor's process window
    Screenshot 2020-05-12 at 11 13 15
  3. Switching to k3d in place of Docker's native K8s implementation.
  4. I recommend quitting the Docker application before suspending OS-X and at the end of your work-day. The longer the process runs for the more likely to hit the infinite loop. If you quit it daily there is less risk

Hope this helps.

P.S. Remember your actual containers that you are running may be causing their own CPU usage spikes... that is not what this bug is about... those CPU spikes are likely the result of bugs in your containers or perhaps how you have configured volume mounts causing your containers to see excessive file system changes. This bug is for Docker CPU spiking when not running any containers or pods at all

P.P.S. I have heard interesting things about using Multipass to run k3s on OS-X without docker at all: https://medium.com/@zhimin.wen/running-k3s-with-multipass-on-mac-fbd559966f7c but that would, AIUI, force me to use something like Kaniko to actually build docker images within the k3s and that gets really ugly really fast. My current recommendation is to use k3d as my usage patters of Docker with k3d is only spiking the CPU about once a week for me.


Original bug report

  • I have tried with the latest version of my channel (Stable or Edge)
  • I have uploaded Diagnostics
  • Diagnostics ID: 15FB3F5E-F133-4986-BEC0-CE7AC6E63C2D/20190131145829

Expected behavior

com.docker.hyperkit should not turn my Mac into a space heater with megawatt output when stopping all running containers

Actual behavior

com.docker.hyperkit process jumps to use all available CPU resources multiple times per day, some times when only vaguely interacting with docker.

All docker commands lock up, e.g. docker ps

Information

  • macOS Version:

Diagnostic logs

This seems relevant

2019-01-31 14:47:08.250611+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Discards have finished, 15975 clusters have been discarded
2019-01-31 14:47:08.283415+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 15975 clusters are junk, 10743 moves are possible
2019-01-31 14:47:10.602322+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: resize to 377443 clusters
2019-01-31 14:47:16.712836+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: triggering background flush: 360157 used; 4494 junk; 740 erased; 1308 available; 10741 copies; 0 roots; 0 Copying; 10741 Copied; 0 Flushed; 0 Referenced; max_cluster = 377442
2019-01-31 14:47:16.722716+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 10741 cluster copies flushed; 0 cluster copies complete; 740 clusters erased
2019-01-31 14:47:16.727609+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: flush: 360157 used; 4494 junk; 0 erased; 2048 available; 10741 copies; 0 roots; 0 Copying; 0 Copied; 10741 Flushed; 0 Referenced; max_cluster = 377442
2019-01-31 14:47:16.727780+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: need to update references to blocks
2019-01-31 14:47:16.732415+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 1 references in cluster 2
2019-01-31 14:47:16.732432+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: Dropping cache for cluster 368156
2019-01-31 14:47:16.732439+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Cluster 2 is L1: we must remap L2 references
2019-01-31 14:47:16.964145+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 4961 references in cluster 3
2019-01-31 14:47:16.991882+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 334 references in cluster 87
2019-01-31 14:47:16.994487+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 9 references in cluster 90
2019-01-31 14:47:16.994651+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 2 references in cluster 92
2019-01-31 14:47:16.994763+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 117 references in cluster 95
2019-01-31 14:47:16.995756+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 164 references in cluster 105
2019-01-31 14:47:16.996729+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 1 references in cluster 107
2019-01-31 14:47:16.996911+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 5 references in cluster 109
2019-01-31 14:47:16.997141+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 1 references in cluster 111
2019-01-31 14:47:16.997289+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 29 references in cluster 4211
2019-01-31 14:47:16.997646+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 2 references in cluster 4240
2019-01-31 14:47:16.997860+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 127 references in cluster 109307
2019-01-31 14:47:16.998964+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 6 references in cluster 110607
2019-01-31 14:47:16.999131+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 11 references in cluster 110904
2019-01-31 14:47:16.999304+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 271 references in cluster 110906
2019-01-31 14:47:17.001597+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 32 references in cluster 111201
2019-01-31 14:47:17.002278+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 159 references in cluster 112694
2019-01-31 14:47:17.003679+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 1144 references in cluster 122599
2019-01-31 14:47:17.010500+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 168 references in cluster 123535
2019-01-31 14:47:17.011438+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 18 references in cluster 123983
2019-01-31 14:47:17.011659+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 1707 references in cluster 301260
2019-01-31 14:47:17.021248+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 1472 references in cluster 302216
2019-01-31 14:47:17.029988+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 10741 block references updated
2019-01-31 14:47:21.739205+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: triggering background flush: 360157 used; 15235 junk; 0 erased; 2048 available; 10741 copies; 0 roots; 0 Copying; 0 Copied; 0 Flushed; 10741 Referenced; max_cluster = 377442
2019-01-31 14:47:21.754135+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 0 cluster copies flushed; 10741 cluster copies complete; 0 clusters erased
2019-01-31 14:47:21.758504+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: flush: 360157 used; 15235 junk; 0 erased; 2048 available; 0 copies; 0 roots; 0 Copying; 0 Copied; 0 Flushed; 0 Referenced; max_cluster = 368723
2019-01-31 14:47:21.758520+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Discards (15235) over threshold (2048): waiting for discards to finish before beginning compaction
2019-01-31 14:47:26.765152+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: triggering background flush: 360157 used; 15235 junk; 0 erased; 2048 available; 0 copies; 0 roots; 0 Copying; 0 Copied; 0 Flushed; 0 Referenced; max_cluster = 368723
2019-01-31 14:47:26.765175+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Discards have finished, 15235 clusters have been discarded
2019-01-31 14:47:26.765798+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 15235 clusters are junk, 2 moves are possible
2019-01-31 14:47:26.766289+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: resize to 368724 clusters
2019-01-31 14:47:57.263519+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [ERROR] write sector = 2064 length = 4096: I/O deadline exceeded
2019-01-31 14:47:57.263532+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] ()
2019-01-31 14:47:58.284984+0000  localhost com.docker.hyperkit[83014]: [84655.248677] ata1.00: exception Emask 0x0 SAct 0x7800007f SErr 0x0 action 0x6 frozen
2019-01-31 14:47:58.286729+0000  localhost com.docker.hyperkit[83014]: [84655.250432] ata1.00: cmd 61/08:00:40:2c:80/00:00:01:00:00/40 tag 0 ncq dma 4096 out
2019-01-31 14:47:58.287798+0000  localhost com.docker.hyperkit[83014]: [84655.250432]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
2019-01-31 14:47:58.288931+0000  localhost com.docker.hyperkit[83014]: [84655.252637] ata1.00: cmd 61/08:08:f8:2e:80/00:00:01:00:00/40 tag 1 ncq dma 4096 out
2019-01-31 14:47:58.290108+0000  localhost com.docker.hyperkit[83014]: [84655.252637]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
2019-01-31 14:47:58.291471+0000  localhost com.docker.hyperkit[83014]: [84655.255038] ata1.00: cmd 61/08:10:40:64:89/00:00:01:00:00/40 tag 2 ncq dma 4096 out
2019-01-31 14:47:58.292520+0000  localhost com.docker.hyperkit[83014]: [84655.255038]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
2019-01-31 14:47:58.293670+0000  localhost com.docker.hyperkit[83014]: [84655.257371] ata1.00: cmd 61/08:18:b8:f2:89/00:00:01:00:00/40 tag 3 ncq dma 4096 out
2019-01-31 14:47:58.294738+0000  localhost com.docker.hyperkit[83014]: [84655.257371]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
2019-01-31 14:47:58.296000+0000  localhost com.docker.hyperkit[83014]: [84655.259576] ata1.00: cmd 61/08:20:18:ce:8b/00:00:01:00:00/40 tag 4 ncq dma 4096 out
2019-01-31 14:47:58.297102+0000  localhost com.docker.hyperkit[83014]: [84655.259576]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
2019-01-31 14:47:58.298233+0000  localhost com.docker.hyperkit[83014]: [84655.261941] ata1.00: cmd 61/10:28:40:08:c0/00:00:03:00:00/40 tag 5 ncq dma 8192 out
2019-01-31 14:47:58.299301+0000  localhost com.docker.hyperkit[83014]: [84655.261941]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
2019-01-31 14:47:58.300502+0000  localhost com.docker.hyperkit[83014]: [84655.264139] ata1.00: cmd 61/08:30:28:08:80/00:00:04:00:00/40 tag 6 ncq dma 4096 out
2019-01-31 14:47:58.301660+0000  localhost com.docker.hyperkit[83014]: [84655.264139]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
2019-01-31 14:47:58.303143+0000  localhost com.docker.hyperkit[83014]: [84655.266602] ata1.00: cmd 61/08:d8:10:08:00/00:00:00:00:00/40 tag 27 ncq dma 4096 out
2019-01-31 14:47:58.304193+0000  localhost com.docker.hyperkit[83014]: [84655.266602]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
2019-01-31 14:47:58.305354+0000  localhost com.docker.hyperkit[83014]: [84655.269045] ata1.00: cmd 61/10:e0:20:08:00/00:00:00:00:00/40 tag 28 ncq dma 8192 out
2019-01-31 14:47:58.306427+0000  localhost com.docker.hyperkit[83014]: [84655.269045]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
2019-01-31 14:47:58.307576+0000  localhost com.docker.hyperkit[83014]: [84655.271265] ata1.00: cmd 61/08:e8:18:08:80/00:00:01:00:00/40 tag 29 ncq dma 4096 out
2019-01-31 14:47:58.308647+0000  localhost com.docker.hyperkit[83014]: [84655.271265]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
2019-01-31 14:47:58.309876+0000  localhost com.docker.hyperkit[83014]: [84655.273485] ata1.00: cmd 61/10:f0:00:09:80/00:00:01:00:00/40 tag 30 ncq dma 8192 out
2019-01-31 14:47:58.310924+0000  localhost com.docker.hyperkit[83014]: [84655.273485]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
2019-01-31 14:47:58.311799+0000  localhost com.docker.hyperkit[83014]: [84655.275896] ata1: hard resetting link
2019-01-31 14:48:12.351756+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: triggering background flush: 360157 used; 6514 junk; 153 erased; 1895 available; 2 copies; 0 roots; 0 Copying; 2 Copied; 0 Flushed; 0 Referenced; max_cluster = 368723
2019-01-31 14:48:12.351796+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 2 cluster copies flushed; 0 cluster copies complete; 153 clusters erased
2019-01-31 14:48:12.355540+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: flush: 360157 used; 6514 junk; 0 erased; 2048 available; 2 copies; 0 roots; 0 Copying; 0 Copied; 2 Flushed; 0 Referenced; max_cluster = 368723
2019-01-31 14:48:12.355560+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: need to update references to blocks
2019-01-31 14:48:12.355569+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 2 references in cluster 302216
2019-01-31 14:48:12.355673+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 2 block references updated
2019-01-31 14:48:17.363777+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: triggering background flush: 360157 used; 6516 junk; 0 erased; 2048 available; 2 copies; 0 roots; 0 Copying; 0 Copied; 0 Flushed; 2 Referenced; max_cluster = 368723
2019-01-31 14:48:17.364232+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 0 cluster copies flushed; 2 cluster copies complete; 0 clusters erased
2019-01-31 14:48:17.368042+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: flush: 360157 used; 6516 junk; 0 erased; 2048 available; 0 copies; 0 roots; 0 Copying; 0 Copied; 0 Flushed; 0 Referenced; max_cluster = 360917
2019-01-31 14:48:17.368054+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Discards (6516) over threshold (2048): waiting for discards to finish before beginning compaction
2019-01-31 14:48:22.374180+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: triggering background flush: 360157 used; 6516 junk; 0 erased; 2048 available; 0 copies; 0 roots; 0 Copying; 0 Copied; 0 Flushed; 0 Referenced; max_cluster = 360917
2019-01-31 14:48:22.374211+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] Discards have finished, 6516 clusters have been discarded
2019-01-31 14:48:22.374369+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 6516 clusters are junk, 0 moves are possible
2019-01-31 14:48:22.374390+0000  localhost com.docker.driver.amd64-linux[83008]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: resize to 360918 clusters
2019-01-31 14:48:28.144519+0000  localhost com.docker.hyperkit[83014]: [84685.108358] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [sntpc:1432]

A second log after restarting docker from previous one. Only docker commands executed in between restart and this lock-up:

$ docker system df
TYPE                TOTAL               ACTIVE              SIZE                RECLAIMABLE
Images              369                 2                   18.3GB              18.23GB (99%)
Containers          2                   0                   119B                119B (100%)
Local Volumes       148                 2                   3.145GB             3.006GB (95%)
Build Cache         0                   0                   0B                  0B
$ docker system prune
WARNING! This will remove:
        - all stopped containers
        - all networks not used by at least one container
        - all dangling images
        - all dangling build cache
Are you sure you want to continue? [y/N] y
Deleted Containers:
40936e28cc8979872bd219393517c57985672e18d496b9a822c2c789c9304cd4
87b67542060055fc7711d502f591f723685f5392edc4901941dcfb6c414ec34f

Deleted Networks:
developer-env_default
[...snip...]

Deleted Images:
deleted: sha256:8d3ca4a665ad4910e0cb141992ad77f912013431eacc12cad2dc726adab863d3
[...snip...]
deleted: sha256:c192137e0442419bd675f5dde9897ae2c3994d7ff75506756842a722637a04b1

Total reclaimed space: 6.181GB
$ docker system df
TYPE                TOTAL               ACTIVE              SIZE                RECLAIMABLE
Images              79                  0                   12.12GB             12.12GB (100%)
Containers          0                   0                   0B                  0B
Local Volumes       148                 0                   3.145GB             3.145GB (100%)
Build Cache         0                   0                   0B                  0B

And the logs:

Timestamp                       (process)[PID]    
2019-01-31 15:12:00.357270+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: resize to 358711 clusters
2019-01-31 15:12:19.018687+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: triggering background flush: 254228 used; 85553 junk; 7 erased; 2041 available; 16879 copies; 0 roots; 0 Copying; 16879 Copied; 0 Flushed; 0 Referenced; max_cluster = 358710
2019-01-31 15:12:19.033440+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 16879 cluster copies flushed; 0 cluster copies complete; 7 clusters erased
2019-01-31 15:12:19.037595+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: flush: 254228 used; 85553 junk; 0 erased; 2048 available; 16879 copies; 0 roots; 0 Copying; 0 Copied; 16879 Flushed; 0 Referenced; max_cluster = 358710
2019-01-31 15:12:19.037945+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: need to update references to blocks
2019-01-31 15:12:19.043450+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 5 references in cluster 2
2019-01-31 15:12:19.043467+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: Dropping cache for cluster 339635
2019-01-31 15:12:19.043475+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: Dropping cache for cluster 322529
2019-01-31 15:12:19.043481+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: Dropping cache for cluster 302216
2019-01-31 15:12:19.043487+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: Dropping cache for cluster 301260
2019-01-31 15:12:19.043493+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: Dropping cache for cluster 277152
2019-01-31 15:12:19.043500+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Cluster 2 is L1: we must remap L2 references
2019-01-31 15:12:19.170059+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 1 references in cluster 3
2019-01-31 15:12:19.170129+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 13 references in cluster 90
2019-01-31 15:12:19.170313+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 11 references in cluster 95
2019-01-31 15:12:19.170497+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 3241 references in cluster 99
2019-01-31 15:12:19.183546+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 375 references in cluster 101
2019-01-31 15:12:19.185108+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 784 references in cluster 105
2019-01-31 15:12:19.188340+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 355 references in cluster 111
2019-01-31 15:12:19.189763+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 473 references in cluster 113
2019-01-31 15:12:19.191759+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 1350 references in cluster 4211
2019-01-31 15:12:19.197097+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 1790 references in cluster 4214
2019-01-31 15:12:19.203773+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 3414 references in cluster 4216
2019-01-31 15:12:19.215698+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 769 references in cluster 4218
2019-01-31 15:12:19.219065+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 1 references in cluster 41742
2019-01-31 15:12:19.219252+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 4134 references in cluster 78405
2019-01-31 15:12:19.237168+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 128 references in cluster 110906
2019-01-31 15:12:19.237937+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 1 references in cluster 124070
2019-01-31 15:12:19.238064+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 32 references in cluster 240803
2019-01-31 15:12:19.238624+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 2 references in cluster 13176
2019-01-31 15:12:19.238821+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 16879 block references updated
2019-01-31 15:12:24.044672+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: triggering background flush: 254228 used; 102432 junk; 0 erased; 2048 available; 16879 copies; 0 roots; 0 Copying; 0 Copied; 0 Flushed; 16879 Referenced; max_cluster = 358710
2019-01-31 15:12:24.062490+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 0 cluster copies flushed; 16879 cluster copies complete; 0 clusters erased
2019-01-31 15:12:24.066273+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: flush: 254228 used; 102432 junk; 0 erased; 2048 available; 0 copies; 0 roots; 0 Copying; 0 Copied; 0 Flushed; 0 Referenced; max_cluster = 302028
2019-01-31 15:12:24.066307+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Discards (102432) over threshold (2048): waiting for discards to finish before beginning compaction
2019-01-31 15:12:29.071976+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: triggering background flush: 254228 used; 102432 junk; 0 erased; 2048 available; 0 copies; 0 roots; 0 Copying; 0 Copied; 0 Flushed; 0 Referenced; max_cluster = 302028
2019-01-31 15:12:29.072001+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Discards have finished, 102432 clusters have been discarded
2019-01-31 15:12:29.075070+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 102432 clusters are junk, 2 moves are possible
2019-01-31 15:12:29.075503+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: resize to 302029 clusters
2019-01-31 15:13:08.657787+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [ERROR] write sector = 117988448 length = 4096: I/O deadline exceeded
2019-01-31 15:13:08.657802+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] ()
2019-01-31 15:13:09.134968+0000  localhost com.docker.hyperkit[74256]: [ 1056.051160] ata1.00: exception Emask 0x0 SAct 0x30 SErr 0x0 action 0x6 frozen
2019-01-31 15:13:09.136017+0000  localhost com.docker.hyperkit[74256]: [ 1056.052161] ata1.00: cmd 61/08:20:60:5c:08/00:00:07:00:00/40 tag 4 ncq dma 4096 out
2019-01-31 15:13:09.136979+0000  localhost com.docker.hyperkit[74256]: [ 1056.052161]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
2019-01-31 15:13:09.138007+0000  localhost com.docker.hyperkit[74256]: [ 1056.054170] ata1.00: cmd 61/10:28:18:b5:86/00:00:03:00:00/40 tag 5 ncq dma 8192 out
2019-01-31 15:13:09.138972+0000  localhost com.docker.hyperkit[74256]: [ 1056.054170]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
2019-01-31 15:13:09.139483+0000  localhost com.docker.hyperkit[74256]: [ 1056.056168] ata1: hard resetting link
2019-01-31 15:14:00.768764+0000  localhost com.docker.hyperkit[74256]: [ 1107.684976] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [sntpc:1417]
2019-01-31 15:14:00.769472+0000  localhost com.docker.hyperkit[74256]: [ 1107.685953] Modules linked in: xfrm_user xfrm_algo
2019-01-31 15:14:00.770385+0000  localhost com.docker.hyperkit[74256]: [ 1107.686662] CPU: 0 PID: 1417 Comm: sntpc Not tainted 4.9.125-linuxkit #1
2019-01-31 15:14:00.771088+0000  localhost com.docker.hyperkit[74256]: [ 1107.687574] Hardware name:  BHYVE, BIOS 1.00 03/14/2014
2019-01-31 15:14:00.771879+0000  localhost com.docker.hyperkit[74256]: [ 1107.688276] task: ffff96c969603000 task.stack: ffffb90d019d8000
2019-01-31 15:14:00.773101+0000  localhost com.docker.hyperkit[74256]: [ 1107.689067] RIP: 0010:[<ffffffff9b13c208>]  [<ffffffff9b13c208>] smp_call_function_many+0x1f1/0x204
2019-01-31 15:14:00.773814+0000  localhost com.docker.hyperkit[74256]: [ 1107.690289] RSP: 0018:ffffb90d019dbdf8  EFLAGS: 00000202
2019-01-31 15:14:00.774766+0000  localhost com.docker.hyperkit[74256]: [ 1107.691002] RAX: 0000000000000001 RBX: ffff96c97fc1a008 RCX: 0000000000000001
2019-01-31 15:14:00.775728+0000  localhost com.docker.hyperkit[74256]: [ 1107.691954] RDX: ffff96c97fc9c918 RSI: 0000000000000000 RDI: ffff96c97fc1a008
2019-01-31 15:14:00.776676+0000  localhost com.docker.hyperkit[74256]: [ 1107.692916] RBP: ffff96c97fc1a000 R08: ffffffffffffffff R09: 000000000000000e
2019-01-31 15:14:00.777627+0000  localhost com.docker.hyperkit[74256]: [ 1107.693864] R10: ffffb90d019dbdf8 R11: 0000000000000000 R12: 0000000000000001
2019-01-31 15:14:00.778578+0000  localhost com.docker.hyperkit[74256]: [ 1107.694815] R13: 0000000000019fc0 R14: 0000000000000000 R15: ffffffff9ba433e0
2019-01-31 15:14:00.779657+0000  localhost com.docker.hyperkit[74256]: [ 1107.695766] FS:  00007f7da32dcb88(0000) GS:ffff96c97fc00000(0000) knlGS:0000000000000000
2019-01-31 15:14:00.780425+0000  localhost com.docker.hyperkit[74256]: [ 1107.696845] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
2019-01-31 15:14:00.781393+0000  localhost com.docker.hyperkit[74256]: [ 1107.697613] CR2: 000000c420177010 CR3: 0000000306a24000 CR4: 0000000000060630
2019-01-31 15:14:00.781679+0000  localhost com.docker.hyperkit[74256]: [ 1107.698582] Stack:
2019-01-31 15:14:00.782745+0000  localhost com.docker.hyperkit[74256]: [ 1107.698868]  ffffffff9b12bd86 00000003017e75f0 ffffffff9b12bd86 0000000000000000
2019-01-31 15:14:00.783809+0000  localhost com.docker.hyperkit[74256]: [ 1107.699933]  0000000000000202 0000000000000000 0000000000000000 0000000000000000
2019-01-31 15:14:00.784872+0000  localhost com.docker.hyperkit[74256]: [ 1107.700996]  ffffffff9b13c239 ffffffff9b13c252 ffffb90d019dbef8 ffffb90d019dbe98
2019-01-31 15:14:00.785212+0000  localhost com.docker.hyperkit[74256]: [ 1107.702060] Call Trace:
2019-01-31 15:14:00.786072+0000  localhost com.docker.hyperkit[74256]: [ 1107.702402]  [<ffffffff9b12bd86>] ? __hrtimer_get_remaining+0x6d/0x6d
2019-01-31 15:14:00.786931+0000  localhost com.docker.hyperkit[74256]: [ 1107.703261]  [<ffffffff9b12bd86>] ? __hrtimer_get_remaining+0x6d/0x6d
2019-01-31 15:14:00.787723+0000  localhost com.docker.hyperkit[74256]: [ 1107.704120]  [<ffffffff9b13c239>] ? smp_call_function+0x1e/0x21
2019-01-31 15:14:00.788446+0000  localhost com.docker.hyperkit[74256]: [ 1107.704911]  [<ffffffff9b13c252>] ? on_each_cpu+0x16/0x40
2019-01-31 15:14:00.789191+0000  localhost com.docker.hyperkit[74256]: [ 1107.705634]  [<ffffffff9b12c392>] ? clock_was_set+0x18/0x1d
2019-01-31 15:14:00.789984+0000  localhost com.docker.hyperkit[74256]: [ 1107.706381]  [<ffffffff9b130d3a>] ? do_settimeofday64+0xe6/0xf2
2019-01-31 15:14:00.790824+0000  localhost com.docker.hyperkit[74256]: [ 1107.707173]  [<ffffffff9b1294f6>] ? do_sys_settimeofday64+0x98/0xf1
2019-01-31 15:14:00.791613+0000  localhost com.docker.hyperkit[74256]: [ 1107.708022]  [<ffffffff9b129607>] ? SyS_settimeofday+0xb8/0xda
2019-01-31 15:14:00.792386+0000  localhost com.docker.hyperkit[74256]: [ 1107.708806]  [<ffffffff9b0033f4>] ? do_syscall_64+0x6f/0x7f
2019-01-31 15:14:00.793317+0000  localhost com.docker.hyperkit[74256]: [ 1107.709577]  [<ffffffff9b7e74ce>] ? entry_SYSCALL_64_after_swapgs+0x58/0xc6
2019-01-31 15:14:00.797134+0000  localhost com.docker.hyperkit[74256]: [ 1107.710505] Code: 48 89 de 89 c7 e8 12 f9 ff ff 3b 05 77 96 c0 00 7d 1d 48 63 c8 48 8b 55 00 48 03 14 cd e0 33 a4 9b 8b 4a 18 80 e1 01 74 04 f3 90 <eb> f4 eb d1 48 83 c4 10 5b 5d 41 5c 41 5d 41 5e 41 5f c3 0f 1f
2019-01-31 15:14:09.170792+0000  localhost com.docker.hyperkit[74256]: [ 1116.087082] INFO: rcu_sched detected stalls on CPUs/tasks:
2019-01-31 15:14:09.172088+0000  localhost com.docker.hyperkit[74256]: [ 1116.087985] 	1-...: (1 GPs behind) idle=b17/140000000000000/0 softirq=11952/11952 fqs=2992
2019-01-31 15:14:09.173073+0000  localhost com.docker.hyperkit[74256]: [ 1116.089278] 	(detected by 0, t=6002 jiffies, g=2946, c=2945, q=14)
2019-01-31 15:14:09.173590+0000  localhost com.docker.hyperkit[74256]: [ 1116.090264] Task dump for CPU 1:
2019-01-31 15:14:09.174738+0000  localhost com.docker.hyperkit[74256]: [ 1116.090781] scsi_eh_0       R  running task        0   267      2 0x00000008
2019-01-31 15:14:09.175987+0000  localhost com.docker.hyperkit[74256]: [ 1116.091930]  0000000000000000 ffffffff9b55fc51 0000000000000000 ffff96c96f2dc000
2019-01-31 15:14:09.177229+0000  localhost com.docker.hyperkit[74256]: [ 1116.093177]  ffffb90d0086be00 ffff96c96f36c000 ffffb90d0086be78 ffff96c96f698580
2019-01-31 15:14:09.178473+0000  localhost com.docker.hyperkit[74256]: [ 1116.094419]  0000000000000246 ffffffff9b56001f ffff96c96dec3618 ffff96c96dc40098
2019-01-31 15:14:09.178872+0000  localhost com.docker.hyperkit[74256]: [ 1116.095663] Call Trace:
2019-01-31 15:14:09.179983+0000  localhost com.docker.hyperkit[74256]: [ 1116.096068]  [<ffffffff9b55fc51>] ? ata_scsi_port_error_handler+0x231/0x55c
2019-01-31 15:14:09.180942+0000  localhost com.docker.hyperkit[74256]: [ 1116.097182]  [<ffffffff9b56001f>] ? ata_scsi_error+0xa3/0xdb
2019-01-31 15:14:09.181964+0000  localhost com.docker.hyperkit[74256]: [ 1116.098143]  [<ffffffff9b52f356>] ? scsi_error_handler+0xb2/0x478
2019-01-31 15:14:09.182969+0000  localhost com.docker.hyperkit[74256]: [ 1116.099175]  [<ffffffff9b100ab9>] ? finish_task_switch+0x115/0x194
2019-01-31 15:14:09.183832+0000  localhost com.docker.hyperkit[74256]: [ 1116.100164]  [<ffffffff9b7e4913>] ? __schedule+0x36c/0x470
2019-01-31 15:14:09.184763+0000  localhost com.docker.hyperkit[74256]: [ 1116.101025]  [<ffffffff9b52f2a4>] ? scsi_eh_get_sense+0xdd/0xdd
2019-01-31 15:14:09.185561+0000  localhost com.docker.hyperkit[74256]: [ 1116.101955]  [<ffffffff9b0f9f9a>] ? kthread+0xb6/0xbe
2019-01-31 15:14:09.186459+0000  localhost com.docker.hyperkit[74256]: [ 1116.102753]  [<ffffffff9b7e75f0>] ? __switch_to_asm+0x40/0x70
2019-01-31 15:14:09.187356+0000  localhost com.docker.hyperkit[74256]: [ 1116.103651]  [<ffffffff9b0f9ee4>] ? init_completion+0x1d/0x1d
2019-01-31 15:14:09.188228+0000  localhost com.docker.hyperkit[74256]: [ 1116.104548]  [<ffffffff9b7e7677>] ? ret_from_fork+0x57/0x70
2019-01-31 15:14:36.741096+0000  localhost com.docker.hyperkit[74256]: [ 1143.657309] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [sntpc:1417]
2019-01-31 15:14:36.741805+0000  localhost com.docker.hyperkit[74256]: [ 1143.658285] Modules linked in: xfrm_user xfrm_algo
2019-01-31 15:14:36.742854+0000  localhost com.docker.hyperkit[74256]: [ 1143.658994] CPU: 0 PID: 1417 Comm: sntpc Tainted: G             L  4.9.125-linuxkit #1
2019-01-31 15:14:36.743554+0000  localhost com.docker.hyperkit[74256]: [ 1143.660042] Hardware name:  BHYVE, BIOS 1.00 03/14/2014
2019-01-31 15:14:36.744351+0000  localhost com.docker.hyperkit[74256]: [ 1143.660743] task: ffff96c969603000 task.stack: ffffb90d019d8000
2019-01-31 15:14:36.745699+0000  localhost com.docker.hyperkit[74256]: [ 1143.661540] RIP: 0010:[<ffffffff9b13c208>]  [<ffffffff9b13c208>] smp_call_function_many+0x1f1/0x204
2019-01-31 15:14:36.746484+0000  localhost com.docker.hyperkit[74256]: [ 1143.662894] RSP: 0018:ffffb90d019dbdf8  EFLAGS: 00000202
2019-01-31 15:14:36.747595+0000  localhost com.docker.hyperkit[74256]: [ 1143.663677] RAX: 0000000000000001 RBX: ffff96c97fc1a008 RCX: 0000000000000001
2019-01-31 15:14:36.748567+0000  localhost com.docker.hyperkit[74256]: [ 1143.664794] RDX: ffff96c97fc9c918 RSI: 0000000000000000 RDI: ffff96c97fc1a008
2019-01-31 15:14:36.749529+0000  localhost com.docker.hyperkit[74256]: [ 1143.665756] RBP: ffff96c97fc1a000 R08: ffffffffffffffff R09: 000000000000000e
2019-01-31 15:14:36.750497+0000  localhost com.docker.hyperkit[74256]: [ 1143.666718] R10: ffffb90d019dbdf8 R11: 0000000000000000 R12: 0000000000000001
2019-01-31 15:14:36.751452+0000  localhost com.docker.hyperkit[74256]: [ 1143.667687] R13: 0000000000019fc0 R14: 0000000000000000 R15: ffffffff9ba433e0
2019-01-31 15:14:36.752538+0000  localhost com.docker.hyperkit[74256]: [ 1143.668654] FS:  00007f7da32dcb88(0000) GS:ffff96c97fc00000(0000) knlGS:0000000000000000
2019-01-31 15:14:36.753311+0000  localhost com.docker.hyperkit[74256]: [ 1143.669730] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
2019-01-31 15:14:36.754257+0000  localhost com.docker.hyperkit[74256]: [ 1143.670499] CR2: 000000c420177010 CR3: 0000000306a24000 CR4: 0000000000060630
2019-01-31 15:14:36.754542+0000  localhost com.docker.hyperkit[74256]: [ 1143.671446] Stack:
2019-01-31 15:14:36.755610+0000  localhost com.docker.hyperkit[74256]: [ 1143.671731]  ffffffff9b12bd86 00000003017e75f0 ffffffff9b12bd86 0000000000000000
2019-01-31 15:14:36.756677+0000  localhost com.docker.hyperkit[74256]: [ 1143.672797]  0000000000000202 0000000000000000 0000000000000000 0000000000000000
2019-01-31 15:14:36.757748+0000  localhost com.docker.hyperkit[74256]: [ 1143.673865]  ffffffff9b13c239 ffffffff9b13c252 ffffb90d019dbef8 ffffb90d019dbe98
2019-01-31 15:14:36.758089+0000  localhost com.docker.hyperkit[74256]: [ 1143.674935] Call Trace:
2019-01-31 15:14:36.758956+0000  localhost com.docker.hyperkit[74256]: [ 1143.675281]  [<ffffffff9b12bd86>] ? __hrtimer_get_remaining+0x6d/0x6d
2019-01-31 15:14:36.759815+0000  localhost com.docker.hyperkit[74256]: [ 1143.676146]  [<ffffffff9b12bd86>] ? __hrtimer_get_remaining+0x6d/0x6d
2019-01-31 15:14:36.760606+0000  localhost com.docker.hyperkit[74256]: [ 1143.677004]  [<ffffffff9b13c239>] ? smp_call_function+0x1e/0x21
2019-01-31 15:14:36.761338+0000  localhost com.docker.hyperkit[74256]: [ 1143.677795]  [<ffffffff9b13c252>] ? on_each_cpu+0x16/0x40
2019-01-31 15:14:36.762085+0000  localhost com.docker.hyperkit[74256]: [ 1143.678528]  [<ffffffff9b12c392>] ? clock_was_set+0x18/0x1d
2019-01-31 15:14:36.762876+0000  localhost com.docker.hyperkit[74256]: [ 1143.679274]  [<ffffffff9b130d3a>] ? do_settimeofday64+0xe6/0xf2
2019-01-31 15:14:36.763713+0000  localhost com.docker.hyperkit[74256]: [ 1143.680066]  [<ffffffff9b1294f6>] ? do_sys_settimeofday64+0x98/0xf1
2019-01-31 15:14:36.764494+0000  localhost com.docker.hyperkit[74256]: [ 1143.680902]  [<ffffffff9b129607>] ? SyS_settimeofday+0xb8/0xda
2019-01-31 15:14:36.765240+0000  localhost com.docker.hyperkit[74256]: [ 1143.681682]  [<ffffffff9b0033f4>] ? do_syscall_64+0x6f/0x7f
2019-01-31 15:14:36.766169+0000  localhost com.docker.hyperkit[74256]: [ 1143.682430]  [<ffffffff9b7e74ce>] ? entry_SYSCALL_64_after_swapgs+0x58/0xc6
2019-01-31 15:14:36.770010+0000  localhost com.docker.hyperkit[74256]: [ 1143.683357] Code: 48 89 de 89 c7 e8 12 f9 ff ff 3b 05 77 96 c0 00 7d 1d 48 63 c8 48 8b 55 00 48 03 14 cd e0 33 a4 9b 8b 4a 18 80 e1 01 74 04 f3 90 <eb> f4 eb d1 48 83 c4 10 5b 5d 41 5c 41 5d 41 5e 41 5f c3 0f 1f
2019-01-31 15:14:40.028247+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Discards (45750) over threshold (2048): waiting for discards to finish before beginning compaction
2019-01-31 15:14:44.971259+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: triggering background flush: 254228 used; 45750 junk; 1368 erased; 680 available; 0 copies; 0 roots; 0 Copying; 0 Copied; 0 Flushed; 0 Referenced; max_cluster = 302028
2019-01-31 15:14:44.971294+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 0 cluster copies flushed; 0 cluster copies complete; 1368 clusters erased
2019-01-31 15:14:44.974849+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: flush: 254228 used; 45750 junk; 0 erased; 2048 available; 0 copies; 0 roots; 0 Copying; 0 Copied; 0 Flushed; 0 Referenced; max_cluster = 302028
2019-01-31 15:14:45.030025+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Discards have finished, 45750 clusters have been discarded
2019-01-31 15:14:45.031205+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 45750 clusters are junk, 2 moves are possible
2019-01-31 15:14:45.031709+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: resize to 302029 clusters
2019-01-31 15:14:49.982256+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: triggering background flush: 254228 used; 45748 junk; 0 erased; 2048 available; 2 copies; 0 roots; 0 Copying; 2 Copied; 0 Flushed; 0 Referenced; max_cluster = 302028
2019-01-31 15:14:49.982281+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 2 cluster copies flushed; 0 cluster copies complete; 0 clusters erased
2019-01-31 15:14:49.985425+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: flush: 254228 used; 45748 junk; 0 erased; 2048 available; 2 copies; 0 roots; 0 Copying; 0 Copied; 2 Flushed; 0 Referenced; max_cluster = 302028
2019-01-31 15:14:49.985436+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: need to update references to blocks
2019-01-31 15:14:49.985447+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 1 references in cluster 4240
2019-01-31 15:14:49.985685+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Updating 1 references in cluster 13246
2019-01-31 15:14:49.985768+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 2 block references updated
2019-01-31 15:14:54.311895+0000  localhost launchservicesd[94]: (LaunchServices) [com.apple.launchservices:cas] Moving App:"Docker" asn:0x0-8fc8fc pid:74212 refs=8 @ 0x7fb1f0a2b040 to front of visible list.
2019-01-31 15:14:54.312029+0000  localhost launchservicesd[94]: (LaunchServices) [com.apple.launchservices:cas] Making App:"Docker" asn:0x0-8fc8fc pid:74212 refs=8 @ 0x7fb1f0a2b040 into menu bar owning process, oldOwner=App:"Terminal" asn:0x0-425425 pid:34206 refs=7 @ 0x7fb1eee174e0
2019-01-31 15:14:54.312036+0000  localhost launchservicesd[94]: (LaunchServices) [com.apple.launchservices:cas] POLICY: Setting application App:"Docker" asn:0x0-8fc8fc pid:74212 refs=9 @ 0x7fb1f0a2b040, pid=74212 to PRIO_DARWIN_ROLE_UI_FOCAL
2019-01-31 15:14:54.319587+0000  localhost Docker[74212]: (LaunchServices) [com.apple.launchservices:cas] Removing cached information for app [ 0x0/0x425425]  "Terminal", as its seed is different from that in shared memory ( 1266 vs 1268)
2019-01-31 15:14:54.988855+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: triggering background flush: 254228 used; 45750 junk; 0 erased; 2048 available; 2 copies; 0 roots; 0 Copying; 0 Copied; 0 Flushed; 2 Referenced; max_cluster = 302028
2019-01-31 15:14:54.989357+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 0 cluster copies flushed; 2 cluster copies complete; 0 clusters erased
2019-01-31 15:14:54.992541+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: flush: 254228 used; 45750 junk; 0 erased; 2048 available; 0 copies; 0 roots; 0 Copying; 0 Copied; 0 Flushed; 0 Referenced; max_cluster = 254299
2019-01-31 15:14:54.992555+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Discards (45750) over threshold (2048): waiting for discards to finish before beginning compaction
2019-01-31 15:14:56.353116+0000  localhost launchservicesd[94]: (LaunchServices) [com.apple.launchservices:cas] Making App:"Google Chrome" asn:0x0-413413 pid:2824 refs=8 @ 0x7fb1eef29d50 into menu bar owning process, oldOwner=App:"Docker" asn:0x0-8fc8fc pid:74212 refs=7 @ 0x7fb1f0a2b040
2019-01-31 15:14:56.353807+0000  localhost launchservicesd[94]: (LaunchServices) [com.apple.launchservices:cas] POLICY: Setting application App:"Docker" asn:0x0-8fc8fc pid:74212 refs=6 @ 0x7fb1f0a2b040, pid=74212 to PRIO_DARWIN_ROLE_UI_NON_FOCAL
2019-01-31 15:14:56.356357+0000  localhost Docker[74212]: (LaunchServices) 27366555: RECEIVED OUT-OF-SEQUENCE NOTIFICATION: 0 vs 9203, 513, <private>
2019-01-31 15:15:00.000622+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: triggering background flush: 254228 used; 45750 junk; 0 erased; 2048 available; 0 copies; 0 roots; 0 Copying; 0 Copied; 0 Flushed; 0 Referenced; max_cluster = 254299
2019-01-31 15:15:00.000645+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] Discards have finished, 45750 clusters have been discarded
2019-01-31 15:15:00.001765+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: 45750 clusters are junk, 0 moves are possible
2019-01-31 15:15:00.001774+0000  localhost com.docker.driver.amd64-linux[74250]: hyperkit: stderr: com.docker.hyperkit: [INFO] block recycler: resize to 254300 clusters
2019-01-31 15:15:04.720689+0000  localhost com.docker.hyperkit[74256]: [ 1171.636898] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [sntpc:1417]
2019-01-31 15:15:04.721403+0000  localhost com.docker.hyperkit[74256]: [ 1171.637878] Modules linked in: xfrm_user xfrm_algo
2019-01-31 15:15:04.722460+0000  localhost com.docker.hyperkit[74256]: [ 1171.638592] CPU: 0 PID: 1417 Comm: sntpc Tainted: G             L  4.9.125-linuxkit #1
2019-01-31 15:15:04.723164+0000  localhost com.docker.hyperkit[74256]: [ 1171.639648] Hardware name:  BHYVE, BIOS 1.00 03/14/2014
2019-01-31 15:15:04.723959+0000  localhost com.docker.hyperkit[74256]: [ 1171.640352] task: ffff96c969603000 task.stack: ffffb90d019d8000
2019-01-31 15:15:04.725184+0000  localhost com.docker.hyperkit[74256]: [ 1171.641147] RIP: 0010:[<ffffffff9b13c208>]  [<ffffffff9b13c208>] smp_call_function_many+0x1f1/0x204
2019-01-31 15:15:04.725900+0000  localhost com.docker.hyperkit[74256]: [ 1171.642373] RSP: 0018:ffffb90d019dbdf8  EFLAGS: 00000202
2019-01-31 15:15:04.726853+0000  localhost com.docker.hyperkit[74256]: [ 1171.643088] RAX: 0000000000000001 RBX: ffff96c97fc1a008 RCX: 0000000000000001
2019-01-31 15:15:04.727806+0000  localhost com.docker.hyperkit[74256]: [ 1171.644041] RDX: ffff96c97fc9c918 RSI: 0000000000000000 RDI: ffff96c97fc1a008
2019-01-31 15:15:04.728758+0000  localhost com.docker.hyperkit[74256]: [ 1171.644993] RBP: ffff96c97fc1a000 R08: ffffffffffffffff R09: 000000000000000e
2019-01-31 15:15:04.729713+0000  localhost com.docker.hyperkit[74256]: [ 1171.645946] R10: ffffb90d019dbdf8 R11: 0000000000000000 R12: 0000000000000001
2019-01-31 15:15:04.730665+0000  localhost com.docker.hyperkit[74256]: [ 1171.646900] R13: 0000000000019fc0 R14: 0000000000000000 R15: ffffffff9ba433e0
2019-01-31 15:15:04.731745+0000  localhost com.docker.hyperkit[74256]: [ 1171.647854] FS:  00007f7da32dcb88(0000) GS:ffff96c97fc00000(0000) knlGS:0000000000000000
2019-01-31 15:15:04.732517+0000  localhost com.docker.hyperkit[74256]: [ 1171.648933] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
2019-01-31 15:15:04.733491+0000  localhost com.docker.hyperkit[74256]: [ 1171.649705] CR2: 000000c420177010 CR3: 0000000306a24000 CR4: 0000000000060630
2019-01-31 15:15:04.733779+0000  localhost com.docker.hyperkit[74256]: [ 1171.650680] Stack:
2019-01-31 15:15:04.734873+0000  localhost com.docker.hyperkit[74256]: [ 1171.650975]  ffffffff9b12bd86 00000003017e75f0 ffffffff9b12bd86 0000000000000000
2019-01-31 15:15:04.735961+0000  localhost com.docker.hyperkit[74256]: [ 1171.652065]  0000000000000202 0000000000000000 0000000000000000 0000000000000000
2019-01-31 15:15:04.737040+0000  localhost com.docker.hyperkit[74256]: [ 1171.653150]  ffffffff9b13c239 ffffffff9b13c252 ffffb90d019dbef8 ffffb90d019dbe98
2019-01-31 15:15:04.737387+0000  localhost com.docker.hyperkit[74256]: [ 1171.654228] Call Trace:
2019-01-31 15:15:04.738260+0000  localhost com.docker.hyperkit[74256]: [ 1171.654579]  [<ffffffff9b12bd86>] ? __hrtimer_get_remaining+0x6d/0x6d
2019-01-31 15:15:04.739135+0000  localhost com.docker.hyperkit[74256]: [ 1171.655451]  [<ffffffff9b12bd86>] ? __hrtimer_get_remaining+0x6d/0x6d
2019-01-31 15:15:04.739937+0000  localhost com.docker.hyperkit[74256]: [ 1171.656325]  [<ffffffff9b13c239>] ? smp_call_function+0x1e/0x21
2019-01-31 15:15:04.740669+0000  localhost com.docker.hyperkit[74256]: [ 1171.657127]  [<ffffffff9b13c252>] ? on_each_cpu+0x16/0x40
2019-01-31 15:15:04.741426+0000  localhost com.docker.hyperkit[74256]: [ 1171.657859]  [<ffffffff9b12c392>] ? clock_was_set+0x18/0x1d
2019-01-31 15:15:04.742234+0000  localhost com.docker.hyperkit[74256]: [ 1171.658616]  [<ffffffff9b130d3a>] ? do_settimeofday64+0xe6/0xf2
2019-01-31 15:15:04.743099+0000  localhost com.docker.hyperkit[74256]: [ 1171.659424]  [<ffffffff9b1294f6>] ? do_sys_settimeofday64+0x98/0xf1
2019-01-31 15:15:04.743908+0000  localhost com.docker.hyperkit[74256]: [ 1171.660290]  [<ffffffff9b129607>] ? SyS_settimeofday+0xb8/0xda
2019-01-31 15:15:04.744694+0000  localhost com.docker.hyperkit[74256]: [ 1171.661100]  [<ffffffff9b0033f4>] ? do_syscall_64+0x6f/0x7f
2019-01-31 15:15:04.745688+0000  localhost com.docker.hyperkit[74256]: [ 1171.661888]  [<ffffffff9b7e74ce>] ? entry_SYSCALL_64_after_swapgs+0x58/0xc6
2019-01-31 15:15:04.749579+0000  localhost com.docker.hyperkit[74256]: [ 1171.662880] Code: 48 89 de 89 c7 e8 12 f9 ff ff 3b 05 77 96 c0 00 7d 1d 48 63 c8 48 8b 55 00 48 03 14 cd e0 33 a4 9b 8b 4a 18 80 e1 01 74 04 f3 90 <eb> f4 eb d1 48 83 c4 10 5b 5d 41 5c 41 5d 41 5e 41 5f c3 0f 1f
2019-01-31 15:15:32.700584+0000  localhost com.docker.hyperkit[74256]: [ 1199.616795] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [sntpc:1417]
2019-01-31 15:15:32.701296+0000  localhost com.docker.hyperkit[74256]: [ 1199.617773] Modules linked in: xfrm_user xfrm_algo
2019-01-31 15:15:32.702352+0000  localhost com.docker.hyperkit[74256]: [ 1199.618486] CPU: 0 PID: 1417 Comm: sntpc Tainted: G             L  4.9.125-linuxkit #1
2019-01-31 15:15:32.703063+0000  localhost com.docker.hyperkit[74256]: [ 1199.619540] Hardware name:  BHYVE, BIOS 1.00 03/14/2014
2019-01-31 15:15:32.703859+0000  localhost com.docker.hyperkit[74256]: [ 1199.620252] task: ffff96c969603000 task.stack: ffffb90d019d8000
2019-01-31 15:15:32.705091+0000  localhost com.docker.hyperkit[74256]: [ 1199.621047] RIP: 0010:[<ffffffff9b13c208>]  [<ffffffff9b13c208>] smp_call_function_many+0x1f1/0x204
2019-01-31 15:15:32.705807+0000  localhost com.docker.hyperkit[74256]: [ 1199.622279] RSP: 0018:ffffb90d019dbdf8  EFLAGS: 00000202
2019-01-31 15:15:32.706760+0000  localhost com.docker.hyperkit[74256]: [ 1199.622995] RAX: 0000000000000001 RBX: ffff96c97fc1a008 RCX: 0000000000000001
2019-01-31 15:15:32.707713+0000  localhost com.docker.hyperkit[74256]: [ 1199.623948] RDX: ffff96c97fc9c918 RSI: 0000000000000000 RDI: ffff96c97fc1a008
2019-01-31 15:15:32.708668+0000  localhost com.docker.hyperkit[74256]: [ 1199.624901] RBP: ffff96c97fc1a000 R08: ffffffffffffffff R09: 000000000000000e
2019-01-31 15:15:32.709621+0000  localhost com.docker.hyperkit[74256]: [ 1199.625856] R10: ffffb90d019dbdf8 R11: 0000000000000000 R12: 0000000000000001
2019-01-31 15:15:32.710574+0000  localhost com.docker.hyperkit[74256]: [ 1199.626809] R13: 0000000000019fc0 R14: 0000000000000000 R15: ffffffff9ba433e0
2019-01-31 15:15:32.711653+0000  localhost com.docker.hyperkit[74256]: [ 1199.627763] FS:  00007f7da32dcb88(0000) GS:ffff96c97fc00000(0000) knlGS:0000000000000000
2019-01-31 15:15:32.712432+0000  localhost com.docker.hyperkit[74256]: [ 1199.628841] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
2019-01-31 15:15:32.713388+0000  localhost com.docker.hyperkit[74256]: [ 1199.629620] CR2: 000000c420177010 CR3: 0000000306a24000 CR4: 0000000000060630
2019-01-31 15:15:32.713674+0000  localhost com.docker.hyperkit[74256]: [ 1199.630576] Stack:
2019-01-31 15:15:32.714745+0000  localhost com.docker.hyperkit[74256]: [ 1199.630863]  ffffffff9b12bd86 00000003017e75f0 ffffffff9b12bd86 0000000000000000
2019-01-31 15:15:32.715823+0000  localhost com.docker.hyperkit[74256]: [ 1199.631933]  0000000000000202 0000000000000000 0000000000000000 0000000000000000
2019-01-31 15:15:32.716893+0000  localhost com.docker.hyperkit[74256]: [ 1199.633011]  ffffffff9b13c239 ffffffff9b13c252 ffffb90d019dbef8 ffffb90d019dbe98
2019-01-31 15:15:32.717235+0000  localhost com.docker.hyperkit[74256]: [ 1199.634081] Call Trace:
2019-01-31 15:15:32.718109+0000  localhost com.docker.hyperkit[74256]: [ 1199.634433]  [<ffffffff9b12bd86>] ? __hrtimer_get_remaining+0x6d/0x6d
2019-01-31 15:15:32.718978+0000  localhost com.docker.hyperkit[74256]: [ 1199.635301]  [<ffffffff9b12bd86>] ? __hrtimer_get_remaining+0x6d/0x6d
2019-01-31 15:15:32.719774+0000  localhost com.docker.hyperkit[74256]: [ 1199.636168]  [<ffffffff9b13c239>] ? smp_call_function+0x1e/0x21
2019-01-31 15:15:32.720502+0000  localhost com.docker.hyperkit[74256]: [ 1199.636963]  [<ffffffff9b13c252>] ? on_each_cpu+0x16/0x40
2019-01-31 15:15:32.721253+0000  localhost com.docker.hyperkit[74256]: [ 1199.637691]  [<ffffffff9b12c392>] ? clock_was_set+0x18/0x1d
2019-01-31 15:15:32.722049+0000  localhost com.docker.hyperkit[74256]: [ 1199.638442]  [<ffffffff9b130d3a>] ? do_settimeofday64+0xe6/0xf2
2019-01-31 15:15:32.722889+0000  localhost com.docker.hyperkit[74256]: [ 1199.639238]  [<ffffffff9b1294f6>] ? do_sys_settimeofday64+0x98/0xf1
2019-01-31 15:15:32.723676+0000  localhost com.docker.hyperkit[74256]: [ 1199.640079]  [<ffffffff9b129607>] ? SyS_settimeofday+0xb8/0xda
2019-01-31 15:15:32.724426+0000  localhost com.docker.hyperkit[74256]: [ 1199.640865]  [<ffffffff9b0033f4>] ? do_syscall_64+0x6f/0x7f
2019-01-31 15:15:32.725360+0000  localhost com.docker.hyperkit[74256]: [ 1199.641617]  [<ffffffff9b7e74ce>] ? entry_SYSCALL_64_after_swapgs+0x58/0xc6
2019-01-31 15:15:32.729206+0000  localhost com.docker.hyperkit[74256]: [ 1199.642548] Code: 48 89 de 89 c7 e8 12 f9 ff ff 3b 05 77 96 c0 00 7d 1d 48 63 c8 48 8b 55 00 48 03 14 cd e0 33 a4 9b 8b 4a 18 80 e1 01 74 04 f3 90 <eb> f4 eb d1 48 83 c4 10 5b 5d 41 5c 41 5d 41 5e 41 5f c3 0f 1f
2019-01-31 15:16:00.680483+0000  localhost com.docker.hyperkit[74256]: [ 1227.596695] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [sntpc:1417]
2019-01-31 15:16:00.681193+0000  localhost com.docker.hyperkit[74256]: [ 1227.597672] Modules linked in: xfrm_user xfrm_algo
2019-01-31 15:16:00.682248+0000  localhost com.docker.hyperkit[74256]: [ 1227.598383] CPU: 0 PID: 1417 Comm: sntpc Tainted: G             L  4.9.125-linuxkit #1
2019-01-31 15:16:00.682950+0000  localhost com.docker.hyperkit[74256]: [ 1227.599436] Hardware name:  BHYVE, BIOS 1.00 03/14/2014
2019-01-31 15:16:00.683743+0000  localhost com.docker.hyperkit[74256]: [ 1227.600139] task: ffff96c969603000 task.stack: ffffb90d019d8000
2019-01-31 15:16:00.684967+0000  localhost com.docker.hyperkit[74256]: [ 1227.600931] RIP: 0010:[<ffffffff9b13c208>]  [<ffffffff9b13c208>] smp_call_function_many+0x1f1/0x204
2019-01-31 15:16:00.685681+0000  localhost com.docker.hyperkit[74256]: [ 1227.602155] RSP: 0018:ffffb90d019dbdf8  EFLAGS: 00000202
2019-01-31 15:16:00.686633+0000  localhost com.docker.hyperkit[74256]: [ 1227.602869] RAX: 0000000000000001 RBX: ffff96c97fc1a008 RCX: 0000000000000001
2019-01-31 15:16:00.687588+0000  localhost com.docker.hyperkit[74256]: [ 1227.603821] RDX: ffff96c97fc9c918 RSI: 0000000000000000 RDI: ffff96c97fc1a008
2019-01-31 15:16:00.688540+0000  localhost com.docker.hyperkit[74256]: [ 1227.604776] RBP: ffff96c97fc1a000 R08: ffffffffffffffff R09: 000000000000000e
2019-01-31 15:16:00.689491+0000  localhost com.docker.hyperkit[74256]: [ 1227.605727] R10: ffffb90d019dbdf8 R11: 0000000000000000 R12: 0000000000000001
2019-01-31 15:16:00.690443+0000  localhost com.docker.hyperkit[74256]: [ 1227.606679] R13: 0000000000019fc0 R14: 0000000000000000 R15: ffffffff9ba433e0
2019-01-31 15:16:00.691519+0000  localhost com.docker.hyperkit[74256]: [ 1227.607631] FS:  00007f7da32dcb88(0000) GS:ffff96c97fc00000(0000) knlGS:0000000000000000
2019-01-31 15:16:00.692290+0000  localhost com.docker.hyperkit[74256]: [ 1227.608707] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
2019-01-31 15:16:00.693241+0000  localhost com.docker.hyperkit[74256]: [ 1227.609478] CR2: 000000c420177010 CR3: 0000000306a24000 CR4: 0000000000060630
2019-01-31 15:16:00.693526+0000  localhost com.docker.hyperkit[74256]: [ 1227.610429] Stack:
2019-01-31 15:16:00.694595+0000  localhost com.docker.hyperkit[74256]: [ 1227.610715]  ffffffff9b12bd86 00000003017e75f0 ffffffff9b12bd86 0000000000000000
2019-01-31 15:16:00.695663+0000  localhost com.docker.hyperkit[74256]: [ 1227.611783]  0000000000000202 0000000000000000 0000000000000000 0000000000000000
2019-01-31 15:16:00.696739+0000  localhost com.docker.hyperkit[74256]: [ 1227.612851]  ffffffff9b13c239 ffffffff9b13c252 ffffb90d019dbef8 ffffb90d019dbe98
2019-01-31 15:16:00.697081+0000  localhost com.docker.hyperkit[74256]: [ 1227.613927] Call Trace:
2019-01-31 15:16:00.697954+0000  localhost com.docker.hyperkit[74256]: [ 1227.614272]  [<ffffffff9b12bd86>] ? __hrtimer_get_remaining+0x6d/0x6d
2019-01-31 15:16:00.698829+0000  localhost com.docker.hyperkit[74256]: [ 1227.615144]  [<ffffffff9b12bd86>] ? __hrtimer_get_remaining+0x6d/0x6d
2019-01-31 15:16:00.699635+0000  localhost com.docker.hyperkit[74256]: [ 1227.616019]  [<ffffffff9b13c239>] ? smp_call_function+0x1e/0x21
2019-01-31 15:16:00.700365+0000  localhost com.docker.hyperkit[74256]: [ 1227.616825]  [<ffffffff9b13c252>] ? on_each_cpu+0x16/0x40
2019-01-31 15:16:00.701126+0000  localhost com.docker.hyperkit[74256]: [ 1227.617563]  [<ffffffff9b12c392>] ? clock_was_set+0x18/0x1d
2019-01-31 15:16:00.701925+0000  localhost com.docker.hyperkit[74256]: [ 1227.618319]  [<ffffffff9b130d3a>] ? do_settimeofday64+0xe6/0xf2
2019-01-31 15:16:00.702765+0000  localhost com.docker.hyperkit[74256]: [ 1227.619115]  [<ffffffff9b1294f6>] ? do_sys_settimeofday64+0x98/0xf1
2019-01-31 15:16:00.703548+0000  localhost com.docker.hyperkit[74256]: [ 1227.619954]  [<ffffffff9b129607>] ? SyS_settimeofday+0xb8/0xda
2019-01-31 15:16:00.704297+0000  localhost com.docker.hyperkit[74256]: [ 1227.620737]  [<ffffffff9b0033f4>] ? do_syscall_64+0x6f/0x7f
2019-01-31 15:16:00.705227+0000  localhost com.docker.hyperkit[74256]: [ 1227.621487]  [<ffffffff9b7e74ce>] ? entry_SYSCALL_64_after_swapgs+0x58/0xc6
2019-01-31 15:16:00.709061+0000  localhost com.docker.hyperkit[74256]: [ 1227.622415] Code: 48 89 de 89 c7 e8 12 f9 ff ff 3b 05 77 96 c0 00 7d 1d 48 63 c8 48 8b 55 00 48 03 14 cd e0 33 a4 9b 8b 4a 18 80 e1 01 74 04 f3 90 <eb> f4 eb d1 48 83 c4 10 5b 5d 41 5c 41 5d 41 5e 41 5f c3 0f 1f
2019-01-31 15:16:28.660360+0000  localhost com.docker.hyperkit[74256]: [ 1255.576571] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [sntpc:1417]
2019-01-31 15:16:28.661070+0000  localhost com.docker.hyperkit[74256]: [ 1255.577549] Modules linked in: xfrm_user xfrm_algo
2019-01-31 15:16:28.662123+0000  localhost com.docker.hyperkit[74256]: [ 1255.578260] CPU: 0 PID: 1417 Comm: sntpc Tainted: G             L  4.9.125-linuxkit #1
2019-01-31 15:16:28.662825+0000  localhost com.docker.hyperkit[74256]: [ 1255.579311] Hardware name:  BHYVE, BIOS 1.00 03/14/2014
2019-01-31 15:16:28.663618+0000  localhost com.docker.hyperkit[74256]: [ 1255.580013] task: ffff96c969603000 task.stack: ffffb90d019d8000
2019-01-31 15:16:28.664846+0000  localhost com.docker.hyperkit[74256]: [ 1255.580806] RIP: 0010:[<ffffffff9b13c208>]  [<ffffffff9b13c208>] smp_call_function_many+0x1f1/0x204
2019-01-31 15:16:28.665559+0000  localhost com.docker.hyperkit[74256]: [ 1255.582034] RSP: 0018:ffffb90d019dbdf8  EFLAGS: 00000202
2019-01-31 15:16:28.666512+0000  localhost com.docker.hyperkit[74256]: [ 1255.582747] RAX: 0000000000000001 RBX: ffff96c97fc1a008 RCX: 0000000000000001
2019-01-31 15:16:28.667545+0000  localhost com.docker.hyperkit[74256]: [ 1255.583700] RDX: ffff96c97fc9c918 RSI: 0000000000000000 RDI: ffff96c97fc1a008
2019-01-31 15:16:28.668518+0000  localhost com.docker.hyperkit[74256]: [ 1255.584739] RBP: ffff96c97fc1a000 R08: ffffffffffffffff R09: 000000000000000e
2019-01-31 15:16:28.669488+0000  localhost com.docker.hyperkit[74256]: [ 1255.585707] R10: ffffb90d019dbdf8 R11: 0000000000000000 R12: 0000000000000001
2019-01-31 15:16:28.670453+0000  localhost com.docker.hyperkit[74256]: [ 1255.586677] R13: 0000000000019fc0 R14: 0000000000000000 R15: ffffffff9ba433e0
2019-01-31 15:16:28.671559+0000  localhost com.docker.hyperkit[74256]: [ 1255.587642] FS:  00007f7da32dcb88(0000) GS:ffff96c97fc00000(0000) knlGS:0000000000000000
2019-01-31 15:16:28.672341+0000  localhost com.docker.hyperkit[74256]: [ 1255.588749] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
2019-01-31 15:16:28.673317+0000  localhost com.docker.hyperkit[74256]: [ 1255.589530] CR2: 000000c420177010 CR3: 0000000306a24000 CR4: 0000000000060630
2019-01-31 15:16:28.673607+0000  localhost com.docker.hyperkit[74256]: [ 1255.590506] Stack:
2019-01-31 15:16:28.674698+0000  localhost com.docker.hyperkit[74256]: [ 1255.590797]  ffffffff9b12bd86 00000003017e75f0 ffffffff9b12bd86 0000000000000000
2019-01-31 15:16:28.675850+0000  localhost com.docker.hyperkit[74256]: [ 1255.591887]  0000000000000202 0000000000000000 0000000000000000 0000000000000000
2019-01-31 15:16:28.676962+0000  localhost com.docker.hyperkit[74256]: [ 1255.593041]  ffffffff9b13c239 ffffffff9b13c252 ffffb90d019dbef8 ffffb90d019dbe98
2019-01-31 15:16:28.677311+0000  localhost com.docker.hyperkit[74256]: [ 1255.594151] Call Trace:
2019-01-31 15:16:28.678196+0000  localhost com.docker.hyperkit[74256]: [ 1255.594505]  [<ffffffff9b12bd86>] ? __hrtimer_get_remaining+0x6d/0x6d
2019-01-31 15:16:28.679071+0000  localhost com.docker.hyperkit[74256]: [ 1255.595388]  [<ffffffff9b12bd86>] ? __hrtimer_get_remaining+0x6d/0x6d
2019-01-31 15:16:28.679868+0000  localhost com.docker.hyperkit[74256]: [ 1255.596261]  [<ffffffff9b13c239>] ? smp_call_function+0x1e/0x21
2019-01-31 15:16:28.680595+0000  localhost com.docker.hyperkit[74256]: [ 1255.597057]  [<ffffffff9b13c252>] ? on_each_cpu+0x16/0x40
2019-01-31 15:16:28.681345+0000  localhost com.docker.hyperkit[74256]: [ 1255.597784]  [<ffffffff9b12c392>] ? clock_was_set+0x18/0x1d
2019-01-31 15:16:28.682139+0000  localhost com.docker.hyperkit[74256]: [ 1255.598534]  [<ffffffff9b130d3a>] ? do_settimeofday64+0xe6/0xf2
2019-01-31 15:16:28.682980+0000  localhost com.docker.hyperkit[74256]: [ 1255.599329]  [<ffffffff9b1294f6>] ? do_sys_settimeofday64+0x98/0xf1
2019-01-31 15:16:28.683764+0000  localhost com.docker.hyperkit[74256]: [ 1255.600169]  [<ffffffff9b129607>] ? SyS_settimeofday+0xb8/0xda
2019-01-31 15:16:28.684523+0000  localhost com.docker.hyperkit[74256]: [ 1255.600962]  [<ffffffff9b0033f4>] ? do_syscall_64+0x6f/0x7f
2019-01-31 15:16:28.685457+0000  localhost com.docker.hyperkit[74256]: [ 1255.601716]  [<ffffffff9b7e74ce>] ? entry_SYSCALL_64_after_swapgs+0x58/0xc6
2019-01-31 15:16:28.689288+0000  localhost com.docker.hyperkit[74256]: [ 1255.602646] Code: 48 89 de 89 c7 e8 12 f9 ff ff 3b 05 77 96 c0 00 7d 1d 48 63 c8 48 8b 55 00 48 03 14 cd e0 33 a4 9b 8b 4a 18 80 e1 01 74 04 f3 90 <eb> f4 eb d1 48 83 c4 10 5b 5d 41 5c 41 5d 41 5e 41 5f c3 0f 1f
2019-01-31 15:16:56.640280+0000  localhost com.docker.hyperkit[74256]: [ 1283.556490] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [sntpc:1417]
2019-01-31 15:16:56.640994+0000  localhost com.docker.hyperkit[74256]: [ 1283.557469] Modules linked in: xfrm_user xfrm_algo
2019-01-31 15:16:56.642085+0000  localhost com.docker.hyperkit[74256]: [ 1283.558184] CPU: 0 PID: 1417 Comm: sntpc Tainted: G             L  4.9.125-linuxkit #1
2019-01-31 15:16:56.642830+0000  localhost com.docker.hyperkit[74256]: [ 1283.559276] Hardware name:  BHYVE, BIOS 1.00 03/14/2014
2019-01-31 15:16:56.643644+0000  localhost com.docker.hyperkit[74256]: [ 1283.560020] task: ffff96c969603000 task.stack: ffffb90d019d8000
2019-01-31 15:16:56.644872+0000  localhost com.docker.hyperkit[74256]: [ 1283.560832] RIP: 0010:[<ffffffff9b13c208>]  [<ffffffff9b13c208>] smp_call_function_many+0x1f1/0x204
2019-01-31 15:16:56.645589+0000  localhost com.docker.hyperkit[74256]: [ 1283.562060] RSP: 0018:ffffb90d019dbdf8  EFLAGS: 00000202
2019-01-31 15:16:56.646543+0000  localhost com.docker.hyperkit[74256]: [ 1283.562777] RAX: 0000000000000001 RBX: ffff96c97fc1a008 RCX: 0000000000000001
2019-01-31 15:16:56.647644+0000  localhost com.docker.hyperkit[74256]: [ 1283.563731] RDX: ffff96c97fc9c918 RSI: 0000000000000000 RDI: ffff96c97fc1a008
2019-01-31 15:16:56.648601+0000  localhost com.docker.hyperkit[74256]: [ 1283.564833] RBP: ffff96c97fc1a000 R08: ffffffffffffffff R09: 000000000000000e
2019-01-31 15:16:56.649557+0000  localhost com.docker.hyperkit[74256]: [ 1283.565789] R10: ffffb90d019dbdf8 R11: 0000000000000000 R12: 0000000000000001
2019-01-31 15:16:56.650518+0000  localhost com.docker.hyperkit[74256]: [ 1283.566745] R13: 0000000000019fc0 R14: 0000000000000000 R15: ffffffff9ba433e0
2019-01-31 15:16:56.651613+0000  localhost com.docker.hyperkit[74256]: [ 1283.567707] FS:  00007f7da32dcb88(0000) GS:ffff96c97fc00000(0000) knlGS:0000000000000000
2019-01-31 15:16:56.652399+0000  localhost com.docker.hyperkit[74256]: [ 1283.568801] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
2019-01-31 15:16:56.653366+0000  localhost com.docker.hyperkit[74256]: [ 1283.569587] CR2: 000000c420177010 CR3: 0000000306a24000 CR4: 0000000000060630
2019-01-31 15:16:56.653656+0000  localhost com.docker.hyperkit[74256]: [ 1283.570554] Stack:
2019-01-31 15:16:56.654743+0000  localhost com.docker.hyperkit[74256]: [ 1283.570845]  ffffffff9b12bd86 00000003017e75f0 ffffffff9b12bd86 0000000000000000
2019-01-31 15:16:56.655829+0000  localhost com.docker.hyperkit[74256]: [ 1283.571931]  0000000000000202 0000000000000000 0000000000000000 0000000000000000
2019-01-31 15:16:56.656915+0000  localhost com.docker.hyperkit[74256]: [ 1283.573017]  ffffffff9b13c239 ffffffff9b13c252 ffffb90d019dbef8 ffffb90d019dbe98
2019-01-31 15:16:56.657262+0000  localhost com.docker.hyperkit[74256]: [ 1283.574103] Call Trace:
2019-01-31 15:16:56.658140+0000  localhost com.docker.hyperkit[74256]: [ 1283.574453]  [<ffffffff9b12bd86>] ? __hrtimer_get_remaining+0x6d/0x6d
2019-01-31 15:16:56.659017+0000  localhost com.docker.hyperkit[74256]: [ 1283.575330]  [<ffffffff9b12bd86>] ? __hrtimer_get_remaining+0x6d/0x6d
2019-01-31 15:16:56.659825+0000  localhost com.docker.hyperkit[74256]: [ 1283.576206]  [<ffffffff9b13c239>] ? smp_call_function+0x1e/0x21
2019-01-31 15:16:56.660566+0000  localhost com.docker.hyperkit[74256]: [ 1283.577014]  [<ffffffff9b13c252>] ? on_each_cpu+0x16/0x40
2019-01-31 15:16:56.661328+0000  localhost com.docker.hyperkit[74256]: [ 1283.577755]  [<ffffffff9b12c392>] ? clock_was_set+0x18/0x1d
2019-01-31 15:16:56.662139+0000  localhost com.docker.hyperkit[74256]: [ 1283.578518]  [<ffffffff9b130d3a>] ? do_settimeofday64+0xe6/0xf2
2019-01-31 15:16:56.662992+0000  localhost com.docker.hyperkit[74256]: [ 1283.579328]  [<ffffffff9b1294f6>] ? do_sys_settimeofday64+0x98/0xf1
2019-01-31 15:16:56.663788+0000  localhost com.docker.hyperkit[74256]: [ 1283.580182]  [<ffffffff9b129607>] ? SyS_settimeofday+0xb8/0xda
2019-01-31 15:16:56.664549+0000  localhost com.docker.hyperkit[74256]: [ 1283.580977]  [<ffffffff9b0033f4>] ? do_syscall_64+0x6f/0x7f
2019-01-31 15:16:56.665496+0000  localhost com.docker.hyperkit[74256]: [ 1283.581740]  [<ffffffff9b7e74ce>] ? entry_SYSCALL_64_after_swapgs+0x58/0xc6
2019-01-31 15:16:56.669393+0000  localhost com.docker.hyperkit[74256]: [ 1283.582684] Code: 48 89 de 89 c7 e8 12 f9 ff ff 3b 05 77 96 c0 00 7d 1d 48 63 c8 48 8b 55 00 48 03 14 cd e0 33 a4 9b 8b 4a 18 80 e1 01 74 04 f3 90 <eb> f4 eb d1 48 83 c4 10 5b 5d 41 5c 41 5d 41 5e 41 5f c3 0f 1f

Steps to reproduce the behavior

  1. Run Docker for anything from 10 minutes to 24h on my Mac ;-)
@stephenc
Copy link
Author

@stephenc stephenc commented Jan 31, 2019

FYI Was also happening on stable and I upgraded to edge to see if if made a difference... (Ron Howard voice: "It didn't make a difference")

@EduardoLeonMiranda
Copy link

@EduardoLeonMiranda EduardoLeonMiranda commented Jan 31, 2019

SAME PROBLEM HERE!!!!

@mlouage
Copy link

@mlouage mlouage commented Feb 5, 2019

Same problem here. Tried solving it with solutions mentioned in #1759 like decreasing the CPU count and increasing but that didn't help.

@jammi
Copy link

@jammi jammi commented Feb 6, 2019

Same, also #1759, which this is probably a duplicate of.

@stephenc
Copy link
Author

@stephenc stephenc commented Feb 6, 2019

@jammi so I had been experiencing #1759 but that seemed to go away around 18.06

This issue only appeared since the new year. And the symptoms sound different. CPU usage is fine until 💥 and then the Docker VM is unresponsive to any control. I need to force kill all the Docker processes.

Another strange datapoint. In an effort to see what might be going wrong, I kept a window open on the Docker VM’s TTY and had that running top and as long as the window is open, no reproduction (“Heisenbug!”)

@jammi
Copy link

@jammi jammi commented Feb 6, 2019

@stephenc Ok, this sounds like the issues I've been having since Docker Desktop 2.0; November-December. I can just leave it idle and it'll still go crazy high on CPU and not respond to anything. Killing and restarting it does not help, it goes right back up. "Reset to factory defaults" helps for an hour to a day or so, and then it goes on again. It's a huge PITA and made Docker Desktop essentially useless, so I've resorted to running VirtualBox for any local Docker and Kubernetes operations, which is far from ideal and seriously hurts productivity.

@waeljammal
Copy link

@waeljammal waeljammal commented Feb 9, 2019

I'm having a similar issue as well. I've had to resort to running all my services natively on a mac mini instead of docker, I can't even run kube because idle without anything running it consumes like 50+% on all my cores making my laptop really sluggish. Now I need to buy a Linux box to run kube on so I can test stuff :( spinning it up frequently just for tests and having to shut it down after is becoming tedious.

@luismayta
Copy link

@luismayta luismayta commented Feb 10, 2019

SAME PROBLEM HERE!!!!

@asnov
Copy link

@asnov asnov commented Feb 12, 2019

The same issue with 2.0.0.2 on Mac-mini (macOS Mojave 10.14.3).

@kazak1377
Copy link

@kazak1377 kazak1377 commented Feb 15, 2019

Same here Docker desktop Version 2.0.0.3 (31259)
Engine: 18.09.2
Compose: 1.23.2
Machine: 0.16.1

@ryantuck
Copy link

@ryantuck ryantuck commented Feb 28, 2019

What is the workaround for running docker on a mac until this issue gets ack'd or addressed?

@luluzhao
Copy link

@luluzhao luluzhao commented Mar 6, 2019

Same problem here. Is there any workaround to solve this issue? Thanks.

@kazak1377
Copy link

@kazak1377 kazak1377 commented Mar 7, 2019

Upper in this topic somebody suggested to use docker-sync on macos. For me this worked. But it have some bugs, so i'd like to see native solution from docker team

@jammi
Copy link

@jammi jammi commented Mar 7, 2019

I'm basically back to Virtualbox and docker-machine configurations on it. Since it's not exactly a lightweight configuration either, I'll probably have to invest in some portable Linux cluster to develop locally on.

@ahmad-sa3d
Copy link

@ahmad-sa3d ahmad-sa3d commented Mar 17, 2019

The same Here Using Docker 2.0.0.3 Mac OS 10.14.3

@ibash
Copy link

@ibash ibash commented Mar 23, 2019

I think we all know that docker is the real cause of global warming. 😛

@fzamperin
Copy link

@fzamperin fzamperin commented Mar 25, 2019

Same problem here using Docker 2.0.0.3 Mac OS 10.14.3

@PaulForgey
Copy link

@PaulForgey PaulForgey commented Mar 27, 2019

Same issue.

Mac OS 10.13.6 Docker Desktop 2.0.0.3.

Eats 100% CPU with no containers running, and after quitting Docker Desktop com.desktop.hyperkit must be force quit. Did reset to factory defaults.

@larryboymi
Copy link

@larryboymi larryboymi commented Apr 3, 2019

Same issue here

@stephenc
Copy link
Author

@stephenc stephenc commented Apr 3, 2019

Still happening for me... though it hasn't struck for a while, its back with vengeance today!

(Mostly hasn't struck in a while because I haven't been starting, running and stopping containers)

@nicodev3
Copy link

@nicodev3 nicodev3 commented Apr 5, 2019

Same issue...

@miralize
Copy link

@miralize miralize commented Apr 5, 2019

Happening on 10.14.4 too.

Docker Desktop 2.0.0.3

@ysavary
Copy link

@ysavary ysavary commented Apr 7, 2019

Same issue: i tried to reset to factory defaults and reset the disk image. It does not help. CPU of com.docker.hyperkit goes to 200% even before i started any containers. Restarting the computer temporary fix the issue!

macOS 10.14.14
Filesystem: APFS (Encrypted)
Docker desktop: 2.0.0.3 (31259)

@andreyleskov
Copy link

@andreyleskov andreyleskov commented Apr 8, 2019

The same issue on Edge version
Os: Mojave 10.14.4
Filesystem: APFS (UnEncrypted)
Docker: 2.0.3.0 (31778) Edge

Docker Desktop is almost unusable now 8(

@Mouflin-Guillaume
Copy link

@Mouflin-Guillaume Mouflin-Guillaume commented Apr 9, 2019

Same issue, do you have a solution?

@brian-yu
Copy link

@brian-yu brian-yu commented Apr 9, 2019

Running into this as well
Mojave 10.14.13
APFS (Unencrypted)
Docker 2.0.0.3 (31259)

@larryboymi
Copy link

@larryboymi larryboymi commented Apr 10, 2019

In my case I was doing a useradd... found adding -l solved my issue by way of reading through this issue

@svanscho
Copy link

@svanscho svanscho commented Apr 12, 2019

Same here - any update?

@gwagner
Copy link

@gwagner gwagner commented Apr 12, 2019

EDIT: Below did not actually resolve the issue. After about 1 hour, CPU started to spike again

I had the same issue which now seems to be resolved:

I first tried the maxfiles fix noted here: #1759
That had no change on my system.

I then adjusted my memory to 6G and my swap down to 512MB and the issue is gone.

MBP i7 OSX 10.14.3 Docker Desktop 2.0.0.3 Engine 18.09.2

@FlorinAndrei
Copy link

@FlorinAndrei FlorinAndrei commented Oct 1, 2020

the main problems are upstream so out of our control

Which project is that? I'll be more than happy to open a ticket with them.

@dyriavin
Copy link

@dyriavin dyriavin commented Oct 1, 2020

As far as I can see - still more than 100% with running containers :c ( Docker 2.3.4 stable )

@stephenc
Copy link
Author

@stephenc stephenc commented Oct 1, 2020

@AlexanderDyriavin if you have running containers please find a different bug. This is issue (in order to assist the Docker people to fix it) is specifically about having high CPU usage with no containers running and with Kubernetes not enabled.

I will close this issue if 2.4.1 doesn't spin up the CPUs on me during the next two weeks as that seems long enough to prove the absence of the issue that caused me to raise the bug in the first place

@stephen-turner
Copy link
Contributor

@stephen-turner stephen-turner commented Oct 2, 2020

the main problems are upstream so out of our control

Which project is that? I'll be more than happy to open a ticket with them.

It would be on kubernetes/kubernetes. I suggest you read the whole of kubernetes/minikube#3207 first, where the minikube team are fighting with the same issue. kubernetes/kubernetes#89936 is one ticket they mentioned, but I'm not sure if that's the whole problem.

@stephen-turner
Copy link
Contributor

@stephen-turner stephen-turner commented Oct 2, 2020

@AlexanderDyriavin Please upgrade to 2.4, we have made a lot of improvements.

@stephenc
Copy link
Author

@stephenc stephenc commented Oct 2, 2020

Ok, I had to do some stuff on an older service module in our code base. Previously thig bug would hit about every 3-4 times you fired up the suite of services... Nothing so far.

I'll be doing more testing next week, but from what I can see, the issue that caused my original bug report appears to be gone now...

@stephenc
Copy link
Author

@stephenc stephenc commented Oct 2, 2020

Screenshot 2020-10-02 at 21 04 57

This is the version I am currently on.

Now there are likely other bugs related to when you have actual workloads running. But firing up and tearing down again the suite of services that I have would trigger the CPU spike after tearing down quite easily.

@FernandoMiguel
Copy link

@FernandoMiguel FernandoMiguel commented Oct 3, 2020

I'm on the latest edge and it's been super smooth for me who only runs a couple containers a few times a week.
I haven't seen loads of cpu when in idle as I used to..
Haven't had to close docker desktop in weeks.. I believe the original issue has been greatly improved, if not entirely fixed

@Tatsh
Copy link

@Tatsh Tatsh commented Oct 3, 2020

I'm on the latest edge and it's been super smooth for me who only runs a couple containers a few times a week.
I haven't seen loads of cpu when in idle as I used to..
Haven't had to close docker desktop in weeks.. I believe the original issue has been greatly improved, if not entirely fixed

Same.

@WimCools
Copy link

@WimCools WimCools commented Oct 3, 2020

I have installed 2.4.0.0.
I see the same problems as before. My Macbook Pro got very hot. The CPU is very high with NO containers running.
Most of the CPU is spend on :
/usr/sbin/mDNSResponder
/Applications/Docker.app/Contents/MacOS/com.docker.supervisor -watchdog

@stephen-turner
Copy link
Contributor

@stephen-turner stephen-turner commented Oct 5, 2020

@WimCools Please upload diagnostics. We can't do anything without diagnostics. Thanks.

@WimCools
Copy link

@WimCools WimCools commented Oct 5, 2020

Here the output of the diagnostics run :
20201005082249.zip

@kimwilson
Copy link

@kimwilson kimwilson commented Oct 7, 2020

Same issue with 2.4.0.0
Diagnostic ID 8EB4E050-9350-4B02-8B61-29CEC3E555A9/20201007112157

@ebriney
Copy link
Member

@ebriney ebriney commented Oct 7, 2020

Let me take a look @kimwilson
Thanks to your report, I did a fix for the dns query in a loop @WimCools

@FlorinAndrei
Copy link

@FlorinAndrei FlorinAndrei commented Oct 7, 2020

9FB8F573-ADD1-44BA-8718-0C7AFD708805/20201007181433

2.4.0.0

com.docker.hyperkit uses CPU with no actual task being run by me

@stephenc
Copy link
Author

@stephenc stephenc commented Oct 7, 2020

I am now happy after one week of heavy soak testing to consider my original issue resolved.

I am closing this issue as FIXED.

I encourage others to open new issues for their remaining issues, my problem with the space-heater is resolved. 😹

@stephenc stephenc closed this Oct 7, 2020
@gnapse
Copy link

@gnapse gnapse commented Oct 8, 2020

I commendted above a few weeks ago and was requested to provide a diagnostic id when the issue appeared again. It did today. Here;s the diagnostic ID: 769AE5DE-61B6-4080-B4A5-91BA29EC209A/20201008014258

You can see below how serious the situation was at the moment:

CleanShot 2020-10-07 at 22 43 24@2x

@nebuk89
Copy link

@nebuk89 nebuk89 commented Oct 8, 2020

Hey all,

We have now shipped the changes from our investigation over the last 3 months as part of the 2.4 Desktop release.
This does not mean we have got all of the bugs potentially causing this (we fixed a new one yesterday! ) but it is the point where we are no longer going to be driving a significant investigation into multiple potential root causes to this. (which was tracked under docker/roadmap#12)

We will do a blog post in a few weeks detailing the things we found/changes we made to give you some insight into what we did and why.

If you are still having issues, I would ask that you create new tickets on for-mac rather than comment on old tickets as we are going to close these to keep our backlog a bit tidier and not mix up the messages (and it is easier for us to get signal on the scale of issues this way).

Thanks again for your patience and an even bigger thank you to all of you who took the time to test builds & upload diagnostics!

@zwass
Copy link

@zwass zwass commented Oct 8, 2020

I encountered a new related issue that seems possibly to have emerged in 2.4.0.0: #4981

@justice47
Copy link

@justice47 justice47 commented Oct 13, 2020

@stephen-turner update after a week+ - the problem seems to be resolved, com.docker.hyperkit is not wasting more than 50% CPU

@stephen-turner
Copy link
Contributor

@stephen-turner stephen-turner commented Oct 13, 2020

Great, thanks for the update. Current status is that most people seem to be saying that it's fixed. There are one or two rarer CPU bugs in other tickets that we're still tracking down.

@infolock
Copy link

@infolock infolock commented Oct 15, 2020

This is most def not fixed. It ranges anywhere from 100% to 600% at times for me - which is freaking crazy.

This is the 4th time that it has forced my machine's battery to 0% WHILE PLUGGED IN!

I dunno what this process is doing, but it ain't good.

@stephen-turner
Copy link
Contributor

@stephen-turner stephen-turner commented Oct 15, 2020

@infolock Please open a new ticket with a diagnostics id. Thank you.

@WimCools
Copy link

@WimCools WimCools commented Oct 16, 2020

I have installed 2.4.1.0 (48583) I don't see any improvements.
/usr/sbin/mDNSResponder is using too much CPU resources.

@WimCools
Copy link

@WimCools WimCools commented Oct 16, 2020

With version 2.4.1.0 my container does not build anymore :

[17/28] RUN cp /download/ravdev_hosts /etc/hosts:
#21 20.23 cp: cannot create regular file ‘/etc/hosts’: Read-only file system


failed to solve with frontend dockerfile.v0: failed to build LLB: executor failed running [/bin/sh -c cp /download/ravdev_hosts /etc/hosts]: runc did not terminate sucessfully

@stephen-turner
Copy link
Contributor

@stephen-turner stephen-turner commented Oct 16, 2020

I'm going to lock this issue now as the biggest causes of this symptom have been fixed. If you are still having CPU problems, please open a new ticket with a diagnostics id so that we can investigate it. Thank you.

@docker docker locked and limited conversation to collaborators Oct 16, 2020
@docker-desktop-robot
Copy link
Collaborator

@docker-desktop-robot docker-desktop-robot commented Nov 15, 2020

Closed issues are locked after 30 days of inactivity.
This helps our team focus on active issues.

If you have found a problem that seems similar to this, please open a new issue.

Send feedback to Docker Community Slack channels #docker-for-mac or #docker-for-windows.
/lifecycle locked

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet