Bug 1339674 - image pruning errors with "malformed HTTP response"
Summary: image pruning errors with "malformed HTTP response"
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: Image Registry
Version: 3.2.0
Hardware: Unspecified
OS: Unspecified
low
low
Target Milestone: ---
: ---
Assignee: Maciej Szulik
QA Contact: zhou ying
URL:
Whiteboard:
Depends On:
Blocks: OSOPS_V3
TreeView+ depends on / blocked
 
Reported: 2016-05-25 14:52 UTC by Joel Diaz
Modified: 2017-03-08 18:26 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: No Doc Update
Doc Text:
We've updated doc after working this bug. It was a configuration problem.
Clone Of:
Environment:
Last Closed: 2016-11-22 23:01:19 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
oadm prune output with loglevel=8 (1.87 MB, application/x-xz)
2016-05-25 14:52 UTC, Joel Diaz
no flags Details
registry logs during image pruning (1.43 MB, application/x-xz)
2016-08-22 16:55 UTC, Joel Diaz
no flags Details

Description Joel Diaz 2016-05-25 14:52:45 UTC
Created attachment 1161477 [details]
oadm prune output with loglevel=8

Description of problem:
Running an 'oadm prune images' command will result in numerous errors with messages like:

sha256:49638d540b2b62f3b01c388e9d8134c55493b1fa659ed84e97cb59b87a6b8e6c
error deleting blob sha256:49638d540b2b62f3b01c388e9d8134c55493b1fa659ed84e97cb59b87a6b8e6c from the registry: error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"

Version-Release number of selected component (if applicable):
atomic-openshift-3.2.0.44-1.git.4.f626ed7.el7.x86_64
tuned-profiles-atomic-openshift-node-3.2.0.44-1.git.4.f626ed7.el7.x86_64
atomic-openshift-node-3.2.0.44-1.git.4.f626ed7.el7.x86_64
atomic-openshift-clients-3.2.0.44-1.git.4.f626ed7.el7.x86_64
atomic-openshift-sdn-ovs-3.2.0.44-1.git.4.f626ed7.el7.x86_64
atomic-openshift-master-3.2.0.44-1.git.4.f626ed7.el7.x86_64

How reproducible:
Every time.

Steps to Reproduce:
1. run 'oadm prune images --keep-younger-than 24h --keep-tag-revisions 5 --token <pruning service account token> --confirm'
2.
3.

Actual results:
Many errors of the kind:
Deleting registry layer blobs ...
BLOB
sha256:49638d540b2b62f3b01c388e9d8134c55493b1fa659ed84e97cb59b87a6b8e6c
error deleting blob sha256:49638d540b2b62f3b01c388e9d8134c55493b1fa659ed84e97cb59b87a6b8e6c from the registry: error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"
sha256:fb72156091f3363a1ba34b4df9ebcce23ea158da4bd34e76aeac6ec8b4eaa541
error deleting blob sha256:fb72156091f3363a1ba34b4df9ebcce23ea158da4bd34e76aeac6ec8b4eaa541 from the registry: error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"
sha256:bf41fbde20a7771c89cfd9645e44f0680657f5babf8aac694fc7e98d6cb3b780
error deleting blob sha256:bf41fbde20a7771c89cfd9645e44f0680657f5babf8aac694fc7e98d6cb3b780 from the registry: error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"


Expected results:
Images to be successfully pruned.

Additional info:

Comment 1 Maciej Szulik 2016-07-25 14:38:29 UTC
The errors

error sending request: malformed HTTP response "\x15\x03\x01\x00\x02\x02"

are there because they inform that http request did not succeeded. We try both https and http when talking registry. Above means your registry is https and when trying http you're getting this error which informs the registry is https actually. If you carefully look through the logs you'll see those two actions being invoked. This is not a bug, but expected behavior.

What is worrying me though is this log:

Error with https for 172.30.10.62:5000/admin/blobs/sha256:f853ea70165e83b075d8bb401cd1106cd73fb0c6df524398c740cd9e657f4ed3: 500 Internal Server Error

Which means that actual delete operation on a registry didn't work. Do you have accompanying registry logs from that moment in time?

Comment 2 Joel Diaz 2016-08-22 16:55:56 UTC
Created attachment 1193020 [details]
registry logs during image pruning

Attaching registry logs emitted during the image pruning attempt.

Comment 3 Maciej Szulik 2016-09-08 08:11:18 UTC
Joel which storage driver you're using, I found in the logs following error:

error deleting blob \"sha256:679e94e097b72da814aaff05a8e04aa96ece4bad34dc60f487984e52062f5dc2\": operation unsupported

Which looks like it's related to a particular storage driver, but I don't want to go through them all.

Comment 4 Andy Grimm 2016-09-08 11:38:07 UTC
We are using S3

Comment 5 Maciej Szulik 2016-09-12 10:13:41 UTC
I've grepped through the logs and I see that ALL delete operation failed with this error. Can you verify that you have storage:delete:enabled: set to true [1]. The default config OpenShift provides ,has that turned on, but if you're modifying it you need to enable it explicitly.

[1] https://github.com/docker/distribution/blob/5e8d18f615031aeb79f3bdedcc954b08f86e9719/docs/configuration.md#delete

Comment 6 Joel Diaz 2016-09-15 15:28:55 UTC
(In reply to Maciej Szulik from comment #5)
> I've grepped through the logs and I see that ALL delete operation failed
> with this error. Can you verify that you have storage:delete:enabled: set to
> true [1]. The default config OpenShift provides ,has that turned on, but if
> you're modifying it you need to enable it explicitly.
> 
> [1]
> https://github.com/docker/distribution/blob/
> 5e8d18f615031aeb79f3bdedcc954b08f86e9719/docs/configuration.md#delete

That was the culprit. The 'delete: enabled' was not present in the registry config. My guess is that the cluster was provisioned with on old registry config template that didn't include this.

Image pruning now runs successfully after adding the necessary bits to the registry config.

Comment 7 Maciej Szulik 2016-09-16 09:33:35 UTC
I've added notes in the docs for future generations ;) 

https://github.com/openshift/openshift-docs/pull/2855


Note You need to log in before you can comment on or make changes to this bug.