yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1999800] [NEW] tempest.api.image.v2.test_images.ImageLocationsTest.test_set_location intermittently fails with The Store URI was malformed

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Balazs Gibizer <1999800@xxxxxxxxxxxxxxxxxx>
Date: Thu, 15 Dec 2022 15:27:46 -0000
Reply-to: Bug 1999800 <1999800@xxxxxxxxxxxxxxxxxx>
Sender: noreply@xxxxxxxxxxxxx
Public bug reported:

Example run with failure:
https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_67c/854119/12/gate/nova-ceph-multistore/67cb433/testr_results.html

Traceback (most recent call last):
  File "/opt/stack/tempest/tempest/api/image/v2/test_images.py", line 844, in test_set_location
    self._check_set_location()
  File "/opt/stack/tempest/tempest/api/image/v2/test_images.py", line 820, in _check_set_location
    self.client.update_image(image['id'], [
  File "/opt/stack/tempest/tempest/lib/services/image/v2/images_client.py", line 40, in update_image
    resp, body = self.patch('images/%s' % image_id, data, headers)
  File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 346, in patch
    return self.request('PATCH', url, extra_headers, headers, body)
  File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 720, in request
    self._error_checker(resp, resp_body)
  File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 831, in _error_checker
    raise exceptions.BadRequest(resp_body, resp=resp)
tempest.lib.exceptions.BadRequest: Bad request
Details: b'400 Bad Request\n\nThe Store URI was malformed.\n\n   '

Dec 15 12:37:12.908234 ubuntu-focal-ovh-bhs1-0032504354 glance-
api[109302]: DEBUG oslo_policy.policy [None
req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
ImageLocationsTest-114614806 tempest-
ImageLocationsTest-114614806-project] enforce: rule="context_is_admin"
creds={"domain_id": null, "is_admin_project": true, "project_domain_id":
"default", "project_id": "858e3d7134924eab94d5ed2b2be4e845", "roles":
["member", "reader"], "service_project_domain_id": null,
"service_project_id": null, "service_roles": [],
"service_user_domain_id": null, "service_user_id": null, "system_scope":
null, "user_domain_id": "default", "user_id":
"e5f710a5113b4259b676fe1d7a4d88c0"} target={"auth_token": "***",
"domain": null, "global_request_id": null, "is_admin": false,
"is_admin_project": true, "project": "858e3d7134924eab94d5ed2b2be4e845",
"project_domain": "default", "project_id":
"858e3d7134924eab94d5ed2b2be4e845", "read_only": false, "request_id":
"req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff", "resource_uuid": null,
"roles": ["member", "reader"], "service_catalog": [{"endpoints":
[{"publicURL":
"https://158.69.74.2/volume/v3/858e3d7134924eab94d5ed2b2be4e845";,
"region": "RegionOne"}], "name": "cinder", "type": "block-storage"},
{"endpoints": [{"publicURL": "https://158.69.74.2/image";, "region":
"RegionOne"}], "name": "glance", "type": "image"}, {"endpoints":
[{"publicURL":
"https://158.69.74.2/volume/v3/858e3d7134924eab94d5ed2b2be4e845";,
"region": "RegionOne"}], "name": "cinderv3", "type": "volumev3"},
{"endpoints": [{"publicURL": "https://158.69.74.2:9696/networking";,
"region": "RegionOne"}], "name": "neutron", "type": "network"},
{"endpoints": [{"publicURL":
"https://158.69.74.2/compute/v2/858e3d7134924eab94d5ed2b2be4e845";,
"region": "RegionOne"}], "name": "nova_legacy", "type":
"compute_legacy"}, {"endpoints": [{"publicURL":
"https://158.69.74.2/identity";, "region": "RegionOne"}], "name":
"keystone", "type": "identity"}, {"endpoints": [{"publicURL":
"https://158.69.74.2/compute/v2.1";, "region": "RegionOne"}], "name":
"nova", "type": "compute"}, {"endpoints": [{"publicURL":
"https://158.69.74.2/placement";, "region": "RegionOne"}], "name":
"placement", "type": "placement"}], "show_deleted": false,
"system_scope": null, "user": "e5f710a5113b4259b676fe1d7a4d88c0",
"user_domain": "default", "user_identity":
"e5f710a5113b4259b676fe1d7a4d88c0 858e3d7134924eab94d5ed2b2be4e845 -
default default"} {{(pid=109302) enforce /usr/local/lib/python3.8/dist-
packages/oslo_policy/policy.py:1036}}

Dec 15 12:37:12.937378 ubuntu-focal-ovh-bhs1-0032504354 glance-
api[109302]: DEBUG oslo_policy.policy [None
req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
ImageLocationsTest-114614806 tempest-
ImageLocationsTest-114614806-project] enforce: rule="set_image_location"
creds={"domain_id": null, "is_admin_project": true, "project_domain_id":
"default", "project_id": "858e3d7134924eab94d5ed2b2be4e845", "roles":
["member", "reader"], "service_project_domain_id": null,
"service_project_id": null, "service_roles": [],
"service_user_domain_id": null, "service_user_id": null, "system_scope":
null, "user_domain_id": "default", "user_id":
"e5f710a5113b4259b676fe1d7a4d88c0"} target={"checksum": null,
"container_format": "bare", "created_at": "2022-12-15T12:37:13.000000",
"disk_format": "raw", "extra_properties": {}, "image_id":
"67fb8cb9-03be-4974-aeef-08e12bbe3001", "member": null, "min_disk": 0,
"min_ram": 0, "name": null, "os_hash_algo": null, "os_hash_value": null,
"os_hidden": false, "owner": "858e3d7134924eab94d5ed2b2be4e845",
"project_id": "858e3d7134924eab94d5ed2b2be4e845", "protected": false,
"size": null, "status": "queued", "tags": [], "updated_at":
"2022-12-15T12:37:13.000000", "virtual_size": null, "visibility":
"shared"} {{(pid=109302) enforce /usr/local/lib/python3.8/dist-
packages/oslo_policy/policy.py:1036}}

Dec 15 12:37:12.968329 ubuntu-focal-ovh-bhs1-0032504354 glance-
api[109302]: INFO glance_store._drivers.http [None
req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
ImageLocationsTest-114614806 tempest-
ImageLocationsTest-114614806-project] The HTTP URL is invalid:
('Connection aborted.', RemoteDisconnected('Remote end closed connection
without response'))

Dec 15 12:37:12.970706 ubuntu-focal-ovh-bhs1-0032504354 glance-
api[109302]: INFO eventlet.wsgi.server [None
req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
ImageLocationsTest-114614806 tempest-
ImageLocationsTest-114614806-project]
158.69.74.2,158.69.74.2,158.69.74.2 - - [15/Dec/2022 12:37:12] "PATCH
/v2/images/67fb8cb9-03be-4974-aeef-08e12bbe3001 HTTP/1.1" 400 266
0.065326

Dec 15 12:37:12.986970 ubuntu-focal-ovh-bhs1-0032504354 glance-
api[109302]: DEBUG glance.api.middleware.version_negotiation [None
req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
ImageLocationsTest-114614806 tempest-
ImageLocationsTest-114614806-project] Determining version of request:
POST /v2/images Accept: application/json {{(pid=109302) process_request
/opt/stack/glance/glance/api/middleware/version_negotiation.py:44}}

Dec 15 12:37:12.987276 ubuntu-focal-ovh-bhs1-0032504354 glance-
api[109302]: DEBUG glance.api.middleware.version_negotiation [None
req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
ImageLocationsTest-114614806 tempest-
ImageLocationsTest-114614806-project] Using url versioning
{{(pid=109302) process_request
/opt/stack/glance/glance/api/middleware/version_negotiation.py:57}}

Dec 15 12:37:12.987536 ubuntu-focal-ovh-bhs1-0032504354 glance-
api[109302]: DEBUG glance.api.middleware.version_negotiation [None
req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
ImageLocationsTest-114614806 tempest-
ImageLocationsTest-114614806-project] Matched version: v2 {{(pid=109302)
process_request
/opt/stack/glance/glance/api/middleware/version_negotiation.py:69}}

Dec 15 12:37:12.987728 ubuntu-focal-ovh-bhs1-0032504354 glance-
api[109302]: DEBUG glance.api.middleware.version_negotiation [None
req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
ImageLocationsTest-114614806 tempest-
ImageLocationsTest-114614806-project] new path /v2/images {{(pid=109302)
process_request
/opt/stack/glance/glance/api/middleware/version_negotiation.py:70}}


The only difference between a failed and a successful run is that this single log only appears in the failed run:

Dec 15 12:37:12.968329 ubuntu-focal-ovh-bhs1-0032504354 glance-
api[109302]: INFO glance_store._drivers.http [None
req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
ImageLocationsTest-114614806 tempest-
ImageLocationsTest-114614806-project] The HTTP URL is invalid:
('Connection aborted.', RemoteDisconnected('Remote end closed connection
without response'))


It is not super frequent but it happens time to time:

$ logsearch log --job-group nova-devstack --result FAILURE 'The Store URI was malformed.' --days 40
[snip]
Builds with matching logs 7/589:
+----------------------------------+---------------------+--------------------+----------+-----------------------------------+--------+----------------------+
| uuid                             | finished            | project            | pipeline | review                            | branch | job                  |
+----------------------------------+---------------------+--------------------+----------+-----------------------------------+--------+----------------------+
| 67cb43320f4240c4829b50dbfb4ebb60 | 2022-12-15T12:55:27 | openstack/nova     | gate     | https://review.opendev.org/854119 | master | nova-ceph-multistore |
| faba1d60b734486aa477df42e1303aaa | 2022-12-13T16:57:20 | openstack/nova     | gate     | https://review.opendev.org/854118 | master | nova-ceph-multistore |
| 922b9ef8b32e41c998cb03400bb454e4 | 2022-12-13T11:02:34 | openstack/devstack | gate     | https://review.opendev.org/865544 | master | nova-ceph-multistore |
| 99b8e1ddaa014eccba173420f5d90711 | 2022-12-12T13:39:08 | openstack/devstack | check    | https://review.opendev.org/867215 | master | nova-ceph-multistore |
| 1a6de03afd39494cb7a88f39b07da236 | 2022-12-03T04:10:23 | openstack/nova     | gate     | https://review.opendev.org/852171 | master | nova-ceph-multistore |
| ae4a8cc0d3394f5d840013c8ce657bfc | 2022-12-02T06:14:19 | openstack/nova     | gate     | https://review.opendev.org/852171 | master | nova-ceph-multistore |
| d1e7510e804448c2b68f588d68093220 | 2022-11-29T14:41:39 | openstack/devstack | check    | https://review.opendev.org/865014 | master | nova-ceph-multistore |
+----------------------------------+---------------------+--------------------+----------+-----------------------------------+--------+----------------------+

** Affects: glance
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to Glance.
https://bugs.launchpad.net/bugs/1999800

Title:
  tempest.api.image.v2.test_images.ImageLocationsTest.test_set_location
  intermittently fails with The Store URI was malformed

Status in Glance:
  New

Bug description:
  Example run with failure:
  https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_67c/854119/12/gate/nova-ceph-multistore/67cb433/testr_results.html

  Traceback (most recent call last):
    File "/opt/stack/tempest/tempest/api/image/v2/test_images.py", line 844, in test_set_location
      self._check_set_location()
    File "/opt/stack/tempest/tempest/api/image/v2/test_images.py", line 820, in _check_set_location
      self.client.update_image(image['id'], [
    File "/opt/stack/tempest/tempest/lib/services/image/v2/images_client.py", line 40, in update_image
      resp, body = self.patch('images/%s' % image_id, data, headers)
    File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 346, in patch
      return self.request('PATCH', url, extra_headers, headers, body)
    File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 720, in request
      self._error_checker(resp, resp_body)
    File "/opt/stack/tempest/tempest/lib/common/rest_client.py", line 831, in _error_checker
      raise exceptions.BadRequest(resp_body, resp=resp)
  tempest.lib.exceptions.BadRequest: Bad request
  Details: b'400 Bad Request\n\nThe Store URI was malformed.\n\n   '

  Dec 15 12:37:12.908234 ubuntu-focal-ovh-bhs1-0032504354 glance-
  api[109302]: DEBUG oslo_policy.policy [None
  req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
  ImageLocationsTest-114614806 tempest-
  ImageLocationsTest-114614806-project] enforce: rule="context_is_admin"
  creds={"domain_id": null, "is_admin_project": true,
  "project_domain_id": "default", "project_id":
  "858e3d7134924eab94d5ed2b2be4e845", "roles": ["member", "reader"],
  "service_project_domain_id": null, "service_project_id": null,
  "service_roles": [], "service_user_domain_id": null,
  "service_user_id": null, "system_scope": null, "user_domain_id":
  "default", "user_id": "e5f710a5113b4259b676fe1d7a4d88c0"}
  target={"auth_token": "***", "domain": null, "global_request_id":
  null, "is_admin": false, "is_admin_project": true, "project":
  "858e3d7134924eab94d5ed2b2be4e845", "project_domain": "default",
  "project_id": "858e3d7134924eab94d5ed2b2be4e845", "read_only": false,
  "request_id": "req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff",
  "resource_uuid": null, "roles": ["member", "reader"],
  "service_catalog": [{"endpoints": [{"publicURL":
  "https://158.69.74.2/volume/v3/858e3d7134924eab94d5ed2b2be4e845";,
  "region": "RegionOne"}], "name": "cinder", "type": "block-storage"},
  {"endpoints": [{"publicURL": "https://158.69.74.2/image";, "region":
  "RegionOne"}], "name": "glance", "type": "image"}, {"endpoints":
  [{"publicURL":
  "https://158.69.74.2/volume/v3/858e3d7134924eab94d5ed2b2be4e845";,
  "region": "RegionOne"}], "name": "cinderv3", "type": "volumev3"},
  {"endpoints": [{"publicURL": "https://158.69.74.2:9696/networking";,
  "region": "RegionOne"}], "name": "neutron", "type": "network"},
  {"endpoints": [{"publicURL":
  "https://158.69.74.2/compute/v2/858e3d7134924eab94d5ed2b2be4e845";,
  "region": "RegionOne"}], "name": "nova_legacy", "type":
  "compute_legacy"}, {"endpoints": [{"publicURL":
  "https://158.69.74.2/identity";, "region": "RegionOne"}], "name":
  "keystone", "type": "identity"}, {"endpoints": [{"publicURL":
  "https://158.69.74.2/compute/v2.1";, "region": "RegionOne"}], "name":
  "nova", "type": "compute"}, {"endpoints": [{"publicURL":
  "https://158.69.74.2/placement";, "region": "RegionOne"}], "name":
  "placement", "type": "placement"}], "show_deleted": false,
  "system_scope": null, "user": "e5f710a5113b4259b676fe1d7a4d88c0",
  "user_domain": "default", "user_identity":
  "e5f710a5113b4259b676fe1d7a4d88c0 858e3d7134924eab94d5ed2b2be4e845 -
  default default"} {{(pid=109302) enforce
  /usr/local/lib/python3.8/dist-packages/oslo_policy/policy.py:1036}}

  Dec 15 12:37:12.937378 ubuntu-focal-ovh-bhs1-0032504354 glance-
  api[109302]: DEBUG oslo_policy.policy [None
  req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
  ImageLocationsTest-114614806 tempest-
  ImageLocationsTest-114614806-project] enforce:
  rule="set_image_location" creds={"domain_id": null,
  "is_admin_project": true, "project_domain_id": "default",
  "project_id": "858e3d7134924eab94d5ed2b2be4e845", "roles": ["member",
  "reader"], "service_project_domain_id": null, "service_project_id":
  null, "service_roles": [], "service_user_domain_id": null,
  "service_user_id": null, "system_scope": null, "user_domain_id":
  "default", "user_id": "e5f710a5113b4259b676fe1d7a4d88c0"}
  target={"checksum": null, "container_format": "bare", "created_at":
  "2022-12-15T12:37:13.000000", "disk_format": "raw",
  "extra_properties": {}, "image_id":
  "67fb8cb9-03be-4974-aeef-08e12bbe3001", "member": null, "min_disk": 0,
  "min_ram": 0, "name": null, "os_hash_algo": null, "os_hash_value":
  null, "os_hidden": false, "owner": "858e3d7134924eab94d5ed2b2be4e845",
  "project_id": "858e3d7134924eab94d5ed2b2be4e845", "protected": false,
  "size": null, "status": "queued", "tags": [], "updated_at":
  "2022-12-15T12:37:13.000000", "virtual_size": null, "visibility":
  "shared"} {{(pid=109302) enforce /usr/local/lib/python3.8/dist-
  packages/oslo_policy/policy.py:1036}}

  Dec 15 12:37:12.968329 ubuntu-focal-ovh-bhs1-0032504354 glance-
  api[109302]: INFO glance_store._drivers.http [None
  req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
  ImageLocationsTest-114614806 tempest-
  ImageLocationsTest-114614806-project] The HTTP URL is invalid:
  ('Connection aborted.', RemoteDisconnected('Remote end closed
  connection without response'))

  Dec 15 12:37:12.970706 ubuntu-focal-ovh-bhs1-0032504354 glance-
  api[109302]: INFO eventlet.wsgi.server [None
  req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
  ImageLocationsTest-114614806 tempest-
  ImageLocationsTest-114614806-project]
  158.69.74.2,158.69.74.2,158.69.74.2 - - [15/Dec/2022 12:37:12] "PATCH
  /v2/images/67fb8cb9-03be-4974-aeef-08e12bbe3001 HTTP/1.1" 400 266
  0.065326

  Dec 15 12:37:12.986970 ubuntu-focal-ovh-bhs1-0032504354 glance-
  api[109302]: DEBUG glance.api.middleware.version_negotiation [None
  req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
  ImageLocationsTest-114614806 tempest-
  ImageLocationsTest-114614806-project] Determining version of request:
  POST /v2/images Accept: application/json {{(pid=109302)
  process_request
  /opt/stack/glance/glance/api/middleware/version_negotiation.py:44}}

  Dec 15 12:37:12.987276 ubuntu-focal-ovh-bhs1-0032504354 glance-
  api[109302]: DEBUG glance.api.middleware.version_negotiation [None
  req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
  ImageLocationsTest-114614806 tempest-
  ImageLocationsTest-114614806-project] Using url versioning
  {{(pid=109302) process_request
  /opt/stack/glance/glance/api/middleware/version_negotiation.py:57}}

  Dec 15 12:37:12.987536 ubuntu-focal-ovh-bhs1-0032504354 glance-
  api[109302]: DEBUG glance.api.middleware.version_negotiation [None
  req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
  ImageLocationsTest-114614806 tempest-
  ImageLocationsTest-114614806-project] Matched version: v2
  {{(pid=109302) process_request
  /opt/stack/glance/glance/api/middleware/version_negotiation.py:69}}

  Dec 15 12:37:12.987728 ubuntu-focal-ovh-bhs1-0032504354 glance-
  api[109302]: DEBUG glance.api.middleware.version_negotiation [None
  req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
  ImageLocationsTest-114614806 tempest-
  ImageLocationsTest-114614806-project] new path /v2/images
  {{(pid=109302) process_request
  /opt/stack/glance/glance/api/middleware/version_negotiation.py:70}}

  
  The only difference between a failed and a successful run is that this single log only appears in the failed run:

  Dec 15 12:37:12.968329 ubuntu-focal-ovh-bhs1-0032504354 glance-
  api[109302]: INFO glance_store._drivers.http [None
  req-10d1acb6-05d9-4b82-9f8b-15e91d78d7ff tempest-
  ImageLocationsTest-114614806 tempest-
  ImageLocationsTest-114614806-project] The HTTP URL is invalid:
  ('Connection aborted.', RemoteDisconnected('Remote end closed
  connection without response'))

  
  It is not super frequent but it happens time to time:

  $ logsearch log --job-group nova-devstack --result FAILURE 'The Store URI was malformed.' --days 40
  [snip]
  Builds with matching logs 7/589:
  +----------------------------------+---------------------+--------------------+----------+-----------------------------------+--------+----------------------+
  | uuid                             | finished            | project            | pipeline | review                            | branch | job                  |
  +----------------------------------+---------------------+--------------------+----------+-----------------------------------+--------+----------------------+
  | 67cb43320f4240c4829b50dbfb4ebb60 | 2022-12-15T12:55:27 | openstack/nova     | gate     | https://review.opendev.org/854119 | master | nova-ceph-multistore |
  | faba1d60b734486aa477df42e1303aaa | 2022-12-13T16:57:20 | openstack/nova     | gate     | https://review.opendev.org/854118 | master | nova-ceph-multistore |
  | 922b9ef8b32e41c998cb03400bb454e4 | 2022-12-13T11:02:34 | openstack/devstack | gate     | https://review.opendev.org/865544 | master | nova-ceph-multistore |
  | 99b8e1ddaa014eccba173420f5d90711 | 2022-12-12T13:39:08 | openstack/devstack | check    | https://review.opendev.org/867215 | master | nova-ceph-multistore |
  | 1a6de03afd39494cb7a88f39b07da236 | 2022-12-03T04:10:23 | openstack/nova     | gate     | https://review.opendev.org/852171 | master | nova-ceph-multistore |
  | ae4a8cc0d3394f5d840013c8ce657bfc | 2022-12-02T06:14:19 | openstack/nova     | gate     | https://review.opendev.org/852171 | master | nova-ceph-multistore |
  | d1e7510e804448c2b68f588d68093220 | 2022-11-29T14:41:39 | openstack/devstack | check    | https://review.opendev.org/865014 | master | nova-ceph-multistore |
  +----------------------------------+---------------------+--------------------+----------+-----------------------------------+--------+----------------------+

To manage notifications about this bug go to:
https://bugs.launchpad.net/glance/+bug/1999800/+subscriptions