Bug 1322587

Summary: Image pruning fails with a secured registry.
Product: OpenShift Container Platform Reporter: Wesley Hearn <whearn>
Component: Image RegistryAssignee: Maciej Szulik <maszulik>
Status: CLOSED ERRATA QA Contact: Wei Sun <wsun>
Severity: medium Docs Contact:
Priority: high    
Version: 3.2.0CC: aos-bugs, mfojtik, pweil, tdawson, whearn, yinzhou
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: No Doc Update
Doc Text:
We've only added more logging around this bug to debug the root cause. Unfortunately since then we haven't seen this bug. This doesn't deserve any documentation, imho.
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-09-27 09:37:14 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1303130    

Description Wesley Hearn 2016-03-30 19:52:26 UTC
Description of problem:
When doing oadm prune images it errors with
"error deleting blob sha256:31a9a4e57bfbdd427185e1e72e1d51264c832da2cd91e7b3bf5fa1cb64e5b309 from the registry: error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02""

Version-Release number of selected component (if applicable):
3.2.0.8

How reproducible:
Always

Steps to Reproduce:
1. Install 3.2.0.8 and secure the registry
2. Create a service account and give it access to prune images
3. Run oadm prune images --keep-younger-than=24h --keep-tag-revisions=5 --confirm

Actual results:
I0330 14:26:10.980731  107288 imagepruner.go:430] Unable to find image "sha256:e3dfc88bbfbb3ecff135cdd995eca3541a8738e5393e7af6161f58612b68ffc9" in the graph
I0330 14:26:10.980865  107288 imagepruner.go:430] Unable to find image "sha256:65f5cb8b8ba2fecacf6f7421462f0167234619baeb9d54638d6c60e52e1908a5" in the graph
I0330 14:26:10.980909  107288 imagepruner.go:430] Unable to find image "sha256:65f5cb8b8ba2fecacf6f7421462f0167234619baeb9d54638d6c60e52e1908a5" in the graph
I0330 14:26:10.980928  107288 imagepruner.go:430] Unable to find image "sha256:65f5cb8b8ba2fecacf6f7421462f0167234619baeb9d54638d6c60e52e1908a5" in the graph
I0330 14:26:10.980982  107288 imagepruner.go:430] Unable to find image "sha256:a6af9edbf6fe3c948f8e4bbad3bd7d9e9cf894aa44d607430c54e728d1e3be0a" in the graph
I0330 14:26:10.981035  107288 imagepruner.go:430] Unable to find image "sha256:92f3da2bbed0d01cc66c52245b7bf307cbec8a55987708c3400c3c6ad8678aaa" in the graph
I0330 14:26:10.981132  107288 imagepruner.go:430] Unable to find image "sha256:36da9985a8d7a7e5d36d2195e8e5f6b6056a803df635012fc809f44e0da1caf3" in the graph
I0330 14:26:10.981165  107288 imagepruner.go:430] Unable to find image "sha256:36da9985a8d7a7e5d36d2195e8e5f6b6056a803df635012fc809f44e0da1caf3" in the graph
I0330 14:26:10.981193  107288 imagepruner.go:430] Unable to find image "sha256:36da9985a8d7a7e5d36d2195e8e5f6b6056a803df635012fc809f44e0da1caf3" in the graph
I0330 14:26:10.981237  107288 imagepruner.go:430] Unable to find image "sha256:9a47aac69af68fffe7f44caa4875620f0eb19aec7fb5d893ce4ee64a48c0f6a4" in the graph
I0330 14:26:10.984167  107288 imagepruner.go:430] Unable to find image "sha256:e3dfc88bbfbb3ecff135cdd995eca3541a8738e5393e7af6161f58612b68ffc9" in the graph
I0330 14:26:10.984206  107288 imagepruner.go:430] Unable to find image "sha256:65f5cb8b8ba2fecacf6f7421462f0167234619baeb9d54638d6c60e52e1908a5" in the graph
I0330 14:26:10.984257  107288 imagepruner.go:430] Unable to find image "sha256:a6af9edbf6fe3c948f8e4bbad3bd7d9e9cf894aa44d607430c54e728d1e3be0a" in the graph
I0330 14:26:10.984286  107288 imagepruner.go:430] Unable to find image "sha256:92f3da2bbed0d01cc66c52245b7bf307cbec8a55987708c3400c3c6ad8678aaa" in the graph
I0330 14:26:10.984349  107288 imagepruner.go:430] Unable to find image "sha256:8a35f204224d6360acd778667ffecf657b7dcde7648771e9a84e0bbe1f43b05f" in the graph
I0330 14:26:10.984384  107288 imagepruner.go:430] Unable to find image "sha256:babce715fe339c729221b4635f3cec323b8801514f7992fb5ed89d46d1b1bc98" in the graph
I0330 14:26:10.984415  107288 imagepruner.go:430] Unable to find image "sha256:9d7cc3bcfa5392bb39f56527b4b00c0e4921fcab4669519bc760c05977a6b46b" in the graph
I0330 14:26:10.984442  107288 imagepruner.go:430] Unable to find image "sha256:4b2a128c6fa8da61e8bc1a0f66da0508ce6af2bb1e70e2d3cd06b2b039746174" in the graph
I0330 14:26:10.984468  107288 imagepruner.go:430] Unable to find image "sha256:c6bf898b7abf47198f4247901856252533c2a6a5705161e0b296e020a902fce3" in the graph
I0330 14:26:10.984514  107288 imagepruner.go:430] Unable to find image "sha256:36da9985a8d7a7e5d36d2195e8e5f6b6056a803df635012fc809f44e0da1caf3" in the graph
I0330 14:26:10.984547  107288 imagepruner.go:430] Unable to find image "sha256:9a47aac69af68fffe7f44caa4875620f0eb19aec7fb5d893ce4ee64a48c0f6a4" in the graph
I0330 14:26:10.984821  107288 imagepruner.go:430] Unable to find image "sha256:e3dfc88bbfbb3ecff135cdd995eca3541a8738e5393e7af6161f58612b68ffc9" in the graph
I0330 14:26:10.984860  107288 imagepruner.go:430] Unable to find image "sha256:65f5cb8b8ba2fecacf6f7421462f0167234619baeb9d54638d6c60e52e1908a5" in the graph
I0330 14:26:10.984909  107288 imagepruner.go:430] Unable to find image "sha256:a6af9edbf6fe3c948f8e4bbad3bd7d9e9cf894aa44d607430c54e728d1e3be0a" in the graph
I0330 14:26:10.984938  107288 imagepruner.go:430] Unable to find image "sha256:92f3da2bbed0d01cc66c52245b7bf307cbec8a55987708c3400c3c6ad8678aaa" in the graph
I0330 14:26:10.984973  107288 imagepruner.go:430] Unable to find image "sha256:36da9985a8d7a7e5d36d2195e8e5f6b6056a803df635012fc809f44e0da1caf3" in the graph
I0330 14:26:10.984997  107288 imagepruner.go:430] Unable to find image "sha256:9a47aac69af68fffe7f44caa4875620f0eb19aec7fb5d893ce4ee64a48c0f6a4" in the graph

Deleting registry layer blobs ...
BLOB
sha256:31a9a4e57bfbdd427185e1e72e1d51264c832da2cd91e7b3bf5fa1cb64e5b309
error deleting blob sha256:31a9a4e57bfbdd427185e1e72e1d51264c832da2cd91e7b3bf5fa1cb64e5b309 from the registry: error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"
sha256:f075d88cadb6e82d374f1dd04ca9e6e44a24bbb524cf5b235e92bffca89c04fa
error deleting blob sha256:f075d88cadb6e82d374f1dd04ca9e6e44a24bbb524cf5b235e92bffca89c04fa from the registry: error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"
sha256:fad853d9f249b03efa811eb9d4d900d1738e52986fcbb87ee78c4c2dad63cf0c
error deleting blob sha256:fad853d9f249b03efa811eb9d4d900d1738e52986fcbb87ee78c4c2dad63cf0c from the registry: error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"
sha256:a60f2e72863992c975bdfe9e7e2a4eb26e3b680ec96c6a25dea3ed61c4a4e6dc
error deleting blob sha256:a60f2e72863992c975bdfe9e7e2a4eb26e3b680ec96c6a25dea3ed61c4a4e6dc from the registry: error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"
sha256:91e0c708a9ac2bcc19644f4ef69528671f04cb5cc48b36c555a326e8e12fd12c
error deleting blob sha256:91e0c708a9ac2bcc19644f4ef69528671f04cb5cc48b36c555a326e8e12fd12c from the registry: error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"
error pruning blob "sha256:31a9a4e57bfbdd427185e1e72e1d51264c832da2cd91e7b3bf5fa1cb64e5b309": error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"
error pruning blob "sha256:f075d88cadb6e82d374f1dd04ca9e6e44a24bbb524cf5b235e92bffca89c04fa": error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"
error pruning blob "sha256:fad853d9f249b03efa811eb9d4d900d1738e52986fcbb87ee78c4c2dad63cf0c": error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"
error pruning blob "sha256:a60f2e72863992c975bdfe9e7e2a4eb26e3b680ec96c6a25dea3ed61c4a4e6dc": error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"
error pruning blob "sha256:91e0c708a9ac2bcc19644f4ef69528671f04cb5cc48b36c555a326e8e12fd12c": error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"

Expected results:
It to delete old images.

Additional info:

Comment 1 Paul Weil 2016-03-30 21:46:13 UTC
Maciej,

It appears that this can be caused by a 404 returning on the https call to delete the blob on the secure registry which then causes an http call to be issued which receives the malformed response error since the registry does not support http. (deleteFromRegistry function).

I seemed to be able to reproduce this 2 ways.  First was bouncing docker for some reason.  I was not clear why that was producing 404s.  The other way was to manually curl a DELETE to one of the SHAs like the pruner would do before running pruning.  

Here is what the logs look like: https://gist.github.com/pweil-/008198f231f0057b40294426915e69bc

Comment 2 Paul Weil 2016-03-30 22:35:51 UTC
Update:  it appears that the container was using an old config that did not have delete: enabled.  This appears to have fixed the problem for online but since I was able to reproduce this sporadically in vagrant I think this still needs a second look

Comment 3 Maciej Szulik 2016-03-31 08:22:34 UTC
This looks to be regression after fixing bug 1310062, apparently we might get 404 for certain layers, which should be just ignored. It might be that the layer got removed with some previous delete action, but I'm not sure about that. I'll confirm that with Michal Minar, since he's a registry expert and I'll prepare a fix for it.

Comment 4 Maciej Szulik 2016-03-31 14:11:20 UTC
I've created https://github.com/openshift/origin/pull/8318 which logs the error and continues pruning. @Wesley what I'd like to get from you is the reproducer which will allow me to investigate more what is the root cause of this problem, why we're trying to delete those layers in the first place. I'll lower the prio of this bug once this PR merges, but I'll leave it open until the root cause is identified and nailed down.

Comment 5 openshift-github-bot 2016-03-31 21:40:36 UTC
Commits pushed to master at https://github.com/openshift/origin

https://github.com/openshift/origin/commit/16375903659e3b820233ffe16e1528a27a31b0a6
Bug 1322587 - NotFound error (404) when deleting layers is logged but
we'll be continuing the execution.

https://github.com/openshift/origin/commit/9b043534a0baa15b051811bc32f9fed5891601c7
Merge pull request #8318 from soltysh/bug1322587

Merged by openshift-bot

Comment 6 Maciej Szulik 2016-04-01 21:49:42 UTC
Since the fix landed I'm lowering the priority, as discussed. But I'll keep the bug open until the root cause is nailed down and fixed.

Comment 7 Maciej Szulik 2016-06-28 09:37:28 UTC
Any information about the bug Wesley?

Comment 8 Michal Fojtik 2016-07-20 11:14:19 UTC
Wesley bump.

Comment 9 Wesley Hearn 2016-07-20 14:58:55 UTC
I am not sure how to make a reproducer. I have checked a few logs for our clusters and I have not seen it erroring any more.

Comment 10 Maciej Szulik 2016-07-20 15:36:41 UTC
Based on the last comment I'll move this bug to ON_QA, maybe they will be able to find something. If not it'll get closed.

Comment 11 zhou ying 2016-07-22 08:33:01 UTC
Confirmed with ose3.2.1.10, the issue has fixed:
openshift version
openshift v3.2.1.10-1-g668ed0a
kubernetes v1.2.0-36-g4a3f9c5
etcd 2.2.5


oadm prune images --keep-younger-than=0 --keep-tag-revisions=1
Dry run enabled - no modifications will be made. Add --confirm to remove images

Deleting registry layer blobs ...
BLOB
sha256:5a3e2c75e860737f0df84c92839626de8eebcaf510bdf3140cb3d033bd9befaf
sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4
sha256:0653bff3c5cf23727e0ebceae7a28f7534ab64ed13966e080e4c9b035176c401
sha256:39a454e5d9a158bcd4954e06d9f022823f10396e9fdd85a28a3fcc42d75a7ce7
sha256:4aff2ecfba9fc0ee02a77211fb0f54299839271120aa3066bffb511e26c27a70
sha256:33077750a5c8d59f9f7bed1abf9e156fc8975edc69f837d77aa4e68844a42567
sha256:05a0da00a5f4b0fa32b64da2a3ee17a112532d283f74aa2b8d5aff3e97eac9e4
sha256:bc16d5c17c382cc12d7c428de7766d1b49c8eb6b45f7986282cb2cdf39f1eae6
sha256:ab185f66a5e98f07be14592bc801b64ede8e23eb7edcf1c131e4a33a7a06995b
sha256:d409edbefba76d54916d1e2244246d979242be6e5c1e798634617c7951561319

Deleting images from server ...
IMAGE
sha256:b9fbd3ee64ef0a893d3281fc1ddb211d31e6643ebf660d3aa81118f83b693c03
[root@ip-172-18-1-224 ~]# oadm prune images --keep-younger-than=0 --keep-tag-revisions=1 --confirm

Deleting registry layer blobs ...
BLOB
sha256:bc16d5c17c382cc12d7c428de7766d1b49c8eb6b45f7986282cb2cdf39f1eae6
sha256:05a0da00a5f4b0fa32b64da2a3ee17a112532d283f74aa2b8d5aff3e97eac9e4
sha256:d409edbefba76d54916d1e2244246d979242be6e5c1e798634617c7951561319
sha256:0653bff3c5cf23727e0ebceae7a28f7534ab64ed13966e080e4c9b035176c401
sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4
sha256:ab185f66a5e98f07be14592bc801b64ede8e23eb7edcf1c131e4a33a7a06995b
sha256:39a454e5d9a158bcd4954e06d9f022823f10396e9fdd85a28a3fcc42d75a7ce7
sha256:5a3e2c75e860737f0df84c92839626de8eebcaf510bdf3140cb3d033bd9befaf
sha256:33077750a5c8d59f9f7bed1abf9e156fc8975edc69f837d77aa4e68844a42567
sha256:4aff2ecfba9fc0ee02a77211fb0f54299839271120aa3066bffb511e26c27a70

Deleting images from server ...
IMAGE
sha256:b9fbd3ee64ef0a893d3281fc1ddb211d31e6643ebf660d3aa81118f83b693c03
[root@ip-172-18-1-224 ~]# oadm prune images --keep-younger-than=0 --keep-tag-revisions=1

Comment 13 errata-xmlrpc 2016-09-27 09:37:14 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2016:1933