search

containers / buildah

A tool that facilitates building OCI images.
https://buildah.io
Apache License 2.0
7.31k stars 770 forks source link

excessive time to extract an image #1212

Closed bparees closed 5 years ago

bparees commented 5 years ago

i'm seeing 8 minutes to extract layers for an image:

2018-12-01T00:20:33.829189125Z Storing signatures
2018-12-01T00:20:33.83564504Z time="2018-12-01T00:20:33Z" level=debug msg="Applying tar in /var/lib/containers/storage/overlay/43e653f84b79ba52711b0f726ff5a7fd1162ae9df4be76ca1de8370b8bbf9bb0/diff"
2018-12-01T00:23:27.636624993Z time="2018-12-01T00:23:27Z" level=debug msg="Applying tar in /var/lib/containers/storage/overlay/6df79b1583a08ac99149863f20cd6501d54d4aa23a0cc715e6f8feecf1ba1192/diff"
2018-12-01T00:23:50.534784378Z time="2018-12-01T00:23:50Z" level=debug msg="Applying tar in /var/lib/containers/storage/overlay/ee75a9465db51da55c4e2053de527176dc1aba996ab4f7b5261e75535fafb028/diff"
2018-12-01T00:23:53.050243349Z time="2018-12-01T00:23:53Z" level=debug msg="Applying tar in /var/lib/containers/storage/overlay/75570abb35deb82793b3a787c49d4e67ecb4f3a447553f7c84748b769d40c33b/diff"
2018-12-01T00:23:55.944472286Z time="2018-12-01T00:23:55Z" level=debug msg="Applying tar in /var/lib/containers/storage/overlay/58671557a5584907e7f01fa146dc8ec9df03860b15abf8318c3bce125a89788c/diff"
2018-12-01T00:27:36.642161832Z time="2018-12-01T00:27:36Z" level=debug msg="Applying tar in /var/lib/containers/storage/overlay/ab55a737cc6366f71d91c1b9e96e486abbe3e58e3b96a93ba5c5bfcc365ae715/diff"
2018-12-01T00:28:17.328078033Z time="2018-12-01T00:28:17Z" level=debug msg="Applying tar in /var/lib/containers/storage/overlay/01cbf83bf219bf39ea77589c74103bd6524c7eb52ffd00a0767e1c5629d8571c/diff"
2018-12-01T00:28:19.830563355Z time="2018-12-01T00:28:19Z" level=debug msg="Applying tar in /var/lib/containers/storage/overlay/6a03e28c27e3a139f2f63944bd4e922ebf472250b88564261dbf06660245147f/diff"
2018-12-01T00:28:21.944994502Z time="2018-12-01T00:28:21Z" level=debug msg="Applying tar in /var/lib/containers/storage/overlay/4b6375a1fe85dc9b174f97ba846f9a6307c202e6e92b2193d57c5d72148a8963/diff"
2018-12-01T00:28:24.93967535Z time="2018-12-01T00:28:24Z" level=debug msg="setting image creation date to 2018-06-01 11:50:43.892304076 +0000 UTC"
2018-12-01T00:28:24.947880404Z time="2018-12-01T00:28:24Z" level=debug msg="created new image ID \"e42d0dccf073123561d83ea8bbc9f0cc5e491cfd07130a464a416cdb99ced387\""

There is nothing special about the image that i know of, the image in question is docker.io/centos/ruby-22-centos7

you can see the full buildah logs here: https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/21556/pull-ci-openshift-origin-master-e2e-gcp-builds/200

/cc @smarterclayton

rhatdan commented 5 years ago

I just did a buildah pull of this image locally and time shows.

real 0m52.165s user 0m30.642s sys 0m5.124s

Docker took real 0m45.643s user 0m0.188s sys 0m0.147s

ALthough I am not sure I compared apples to apples.

rhatdan commented 5 years ago

@mtrmac Any ideas?

mtrmac commented 5 years ago

Not at all; vaguely guessing about something I don’t understand: cloud CPU/IO throttling?

smarterclayton commented 5 years ago

How many IOps does buildah do vs docker in your local tests? On a local disk / SSD you might not notice the difference between the two if one does a substantially higher number of IO operations (smaller writes) but on a cloud you're going to be heavily punished if you do.

smarterclayton commented 5 years ago

(i.e. if we're not using buffered writers to disk in buildah you would see this much more)

rhatdan commented 5 years ago

@nalind PTAL

TomSweeneyRedHat commented 5 years ago

@vrothberg me thinks that a by product of your #1244 is addressing this issue too. Could you verify please?

mtrmac commented 5 years ago

I don‘t think so; the logs shows processing in storageImageDestination.Commit after all the copies and possible caching has happened; it is extracting on-disk tar files to on-disk image storage.

mrunalp commented 5 years ago

@sjug is looking into iops comparison with docker.

sjug commented 5 years ago

Built buildah master (non-parallel) and compared it to docker disk usage. (Google Doc)

Very unusual findings as the write speed is quite high for docker but the IOPS are very low, perhaps the io write size is larger for docker?

edit: This was on EC2 gp2 disks

rhatdan commented 5 years ago

@nalind @mtrmac WDYT?

rhatdan commented 5 years ago

@bparees @nalind @mtrmac Any progress on this?

bparees commented 5 years ago

i haven't touched it but @mffiedler recently opened a bug about slow build performance in 4.x, it would be nice to know if this is part of that and whether it can be improved in the 4.0 timeframe.

rhatdan commented 5 years ago

Well we did put a bunch of improvements into buildah 1.7 which is not vendored into OpenShift yet. But we are working on other improvements as well. We should be able to get these into 4.X

bparees commented 5 years ago

Well we did put a bunch of improvements into buildah 1.7 which is not vendored into OpenShift yet.

Any reason for us not to go ahead and pull buildah 1.7 in now?

/cc @nalind @adambkaplan

rhatdan commented 5 years ago

Nope, I would advise it, but I do not know the procedure.

bparees commented 5 years ago

Nope, I would advise it, but I do not know the procedure.

sounds good, we'll take care of it.

rhatdan commented 5 years ago

Closing this issue.