group.of.nepali.translators team mailing list archive

Thread
Date
[Bug 1583276] Re: glance restarted during image upload, image stuck in "saving" state

To: group.of.nepali.translators@xxxxxxxxxxxxxxxxxxx
From: Rafael David Tinoco <rafaeldtinoco@xxxxxxxxxxxxxx>
Date: Fri, 20 Sep 2019 09:35:42 -0000
Reply-to: Bug 1583276 <1583276@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Description changed:

+ [Impact]
+ 
  CI run: https://ci.lscape.net/job/landscape-system-tests/2451/
  
  gs3 log attached. Below some excerpts:
  
  It looks like the problem started when it uploaded the first image (14.04) to glance. That failed:
  WARNING   * 05-18 13:36:48 [PID:10259] * root * No rabbitmq connection available for msg{'status': 'Syncing', 'message': 'ubuntu-trusty-14.04-amd64-server-20160516 99%\n
  DEBUG     * 05-18 13:36:50 [PID:10259] * glanceclient.common.http * curl -i -X POST -H 'x-image-meta-property-source_content_id: com.ubuntu.cloud:released:download' -H 'INFO      * 05-18 13:37:01 [PID:10364] * root * glance-simplestreams-sync started.
  INFO      * 05-18 13:37:01 [PID:10364] * root * /var/run/glance-simplestreams-sync.pid is locked, exiting
  ERROR     * 05-18 13:37:07 [PID:10259] * root * Glance Client exception during do_sync:
  Error communicating with http://10.96.10.146:9292 [Errno 32] Broken pipe
  Will continue polling.
  Traceback (most recent call last):
-   File "/usr/share/glance-simplestreams-sync/glance-simplestreams-sync.py", line 444, in main
-     do_sync(charm_conf, status_exchange)
-   File "/usr/share/glance-simplestreams-sync/glance-simplestreams-sync.py", line 215, in do_sync
-     tmirror.sync(smirror, path=initial_path)
-   File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 91, in sync
-     return self.sync_index(reader, path, data, content)
-   File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 254, in sync_index
-     self.sync(reader, path=epath)
-   File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 89, in sync
-     return self.sync_products(reader, path, data, content)
-   File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 341, in sync_products
-     self.insert_item(item, src, target, pgree, ipath_cs)
-   File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/glance.py", line 303, in insert_item
-     ret = self.gclient.images.create(**create_kwargs)
-   File "/usr/lib/python2.7/dist-packages/glanceclient/v1/images.py", line 253, in create
-     'POST', '/v1/images', headers=hdrs, body=image_data)
-   File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 289, in raw_request
-     return self._http_request(url, method, **kwargs)
-   File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 235, in _http_request
-     raise exc.CommunicationError(message=message)
+   File "/usr/share/glance-simplestreams-sync/glance-simplestreams-sync.py", line 444, in main
+     do_sync(charm_conf, status_exchange)
+   File "/usr/share/glance-simplestreams-sync/glance-simplestreams-sync.py", line 215, in do_sync
+     tmirror.sync(smirror, path=initial_path)
+   File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 91, in sync
+     return self.sync_index(reader, path, data, content)
+   File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 254, in sync_index
+     self.sync(reader, path=epath)
+   File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 89, in sync
+     return self.sync_products(reader, path, data, content)
+   File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 341, in sync_products
+     self.insert_item(item, src, target, pgree, ipath_cs)
+   File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/glance.py", line 303, in insert_item
+     ret = self.gclient.images.create(**create_kwargs)
+   File "/usr/lib/python2.7/dist-packages/glanceclient/v1/images.py", line 253, in create
+     'POST', '/v1/images', headers=hdrs, body=image_data)
+   File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 289, in raw_request
+     return self._http_request(url, method, **kwargs)
+   File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 235, in _http_request
+     raise exc.CommunicationError(message=message)
  CommunicationError: Error communicating with http://10.96.10.146:9292 [Errno 32] Broken pipe
  INFO      * 05-18 13:37:07 [PID:10259] * root * sync done.
  INFO      * 05-18 13:38:01 [PID:10372] * root * glance-simplestreams-sync started.
+ 
+ [Test Case]
  
  Found evidence in the juju logs for glance/0 that it restarted right at 13:37:07:
  2016-05-18 13:37:07 INFO ceph-relation-changed ^MReading state information... 0%^MReading state information... 0%^MReading state information... Done
  2016-05-18 13:37:07 INFO juju-log ceph:50: Loaded template from templates/ceph.conf
  2016-05-18 13:37:07 INFO juju-log ceph:50: Rendering from template: ceph.conf
  2016-05-18 13:37:07 INFO juju-log ceph:50: Wrote template /var/lib/charm/glance/ceph.conf.
  2016-05-18 13:37:07 INFO ceph-relation-changed glance-api stop/waiting
  2016-05-18 13:37:07 INFO ceph-relation-changed glance-api start/running, process 62839
  
  glance/1 had its last restart later:
  2016-05-18 13:32:01 INFO ceph-relation-changed glance-api start/running, process 31045
  
  glance/2 at that time too:
  2016-05-18 13:32:00 INFO ceph-relation-changed glance-api start/running, process 30584
  
  In gs3, a few log entries later, we can see that 14.04 is in state "saving" in glance:
  (...)
  {"images": [{"status": "saving", "deleted_at": null, "name": "auto-sync/ubuntu-trusty-14.04-amd64-server-20160516-disk1.img", "deleted": false, "container_format": "bare
  (...)
  
  It remains in this state throughout the logs.
  
  gs3 then proceeds to download 16.04, upload it to glance, and then
  finally publishes the streams. It's unknown if 14.04 is part of this
  publication or not.
  
+ [Regression Potential]
+ 
+ This part was added specifically for the Xenial backport, including:
+ 
+ - 433-glance-ignore-inactive-images.patch (LP: #1583276)
+ 
+ And chances of regression are small based on the MR feedback from SEG
+ and this particular bug already stating the issue was fixed.
+ 
+ [Other Info]
+ 
  Landscape however fails, because it doesn't find enough "active" images:
  May 18 14:33:29 job-handler-1 INFO  RetryingCall for '_wait_for_active_image' failed, will try again.
  May 18 14:33:29 job-handler-1 INFO  Traceback: <class 'canonical.landscape.model.openstack.jobs.errors.NoActiveImageAvailable'>: #012/usr/lib/python2.7/dist-packages/twisted/internet/defer.py:393:callback#012/usr/lib/python2.7/dist-packages/twisted/internet/defer.py:501:_startRunCallbacks#012/usr/lib/python2.7/dist-packages/twisted/internet/defer.py:588:_runCallbacks#012/usr/lib/python2.7/dist-packages/twisted/internet/defer.py:1184:gotResult#012--- <exception caught here> ---#012/usr/lib/python2.7/dist-packages/twisted/internet/defer.py:1128:_inlineCallbacks#012/opt/canonical/landscape/canonical/landscape/model/openstack/jobs/images.py:48:_wait_for_active_image

** Also affects: simplestreams (Ubuntu)
   Importance: Undecided
       Status: New

** Also affects: simplestreams (Ubuntu Bionic)
   Importance: Undecided
       Status: New

** Also affects: simplestreams (Ubuntu Disco)
   Importance: Undecided
       Status: New

** Also affects: simplestreams (Ubuntu Xenial)
   Importance: Undecided
       Status: New

** Changed in: simplestreams (Ubuntu)
       Status: New => Fix Released

** Changed in: simplestreams (Ubuntu Disco)
       Status: New => Fix Released

** Changed in: simplestreams (Ubuntu Bionic)
       Status: New => Fix Released

** Changed in: simplestreams (Ubuntu Xenial)
       Status: New => In Progress

** Changed in: simplestreams (Ubuntu Xenial)
     Assignee: (unassigned) => Rafael David Tinoco (rafaeldtinoco)

-- 
You received this bug notification because you are a member of नेपाली
भाषा समायोजकहरुको समूह, which is subscribed to Xenial.
Matching subscriptions: Ubuntu 16.04 Bugs
https://bugs.launchpad.net/bugs/1583276

Title:
  glance restarted during image upload, image stuck in "saving" state

Status in Glance - Simplestreams Sync Charm:
  Invalid
Status in Landscape Server:
  Fix Committed
Status in Landscape Server 16.06 series:
  Fix Released
Status in simplestreams:
  Fix Released
Status in simplestreams package in Ubuntu:
  Fix Released
Status in simplestreams source package in Xenial:
  In Progress
Status in simplestreams source package in Bionic:
  Fix Released
Status in simplestreams source package in Disco:
  Fix Released

Bug description:
  [Impact]

  CI run: https://ci.lscape.net/job/landscape-system-tests/2451/

  gs3 log attached. Below some excerpts:

  It looks like the problem started when it uploaded the first image (14.04) to glance. That failed:
  WARNING   * 05-18 13:36:48 [PID:10259] * root * No rabbitmq connection available for msg{'status': 'Syncing', 'message': 'ubuntu-trusty-14.04-amd64-server-20160516 99%\n
  DEBUG     * 05-18 13:36:50 [PID:10259] * glanceclient.common.http * curl -i -X POST -H 'x-image-meta-property-source_content_id: com.ubuntu.cloud:released:download' -H 'INFO      * 05-18 13:37:01 [PID:10364] * root * glance-simplestreams-sync started.
  INFO      * 05-18 13:37:01 [PID:10364] * root * /var/run/glance-simplestreams-sync.pid is locked, exiting
  ERROR     * 05-18 13:37:07 [PID:10259] * root * Glance Client exception during do_sync:
  Error communicating with http://10.96.10.146:9292 [Errno 32] Broken pipe
  Will continue polling.
  Traceback (most recent call last):
    File "/usr/share/glance-simplestreams-sync/glance-simplestreams-sync.py", line 444, in main
      do_sync(charm_conf, status_exchange)
    File "/usr/share/glance-simplestreams-sync/glance-simplestreams-sync.py", line 215, in do_sync
      tmirror.sync(smirror, path=initial_path)
    File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 91, in sync
      return self.sync_index(reader, path, data, content)
    File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 254, in sync_index
      self.sync(reader, path=epath)
    File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 89, in sync
      return self.sync_products(reader, path, data, content)
    File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/__init__.py", line 341, in sync_products
      self.insert_item(item, src, target, pgree, ipath_cs)
    File "/usr/lib/python2.7/dist-packages/simplestreams/mirrors/glance.py", line 303, in insert_item
      ret = self.gclient.images.create(**create_kwargs)
    File "/usr/lib/python2.7/dist-packages/glanceclient/v1/images.py", line 253, in create
      'POST', '/v1/images', headers=hdrs, body=image_data)
    File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 289, in raw_request
      return self._http_request(url, method, **kwargs)
    File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 235, in _http_request
      raise exc.CommunicationError(message=message)
  CommunicationError: Error communicating with http://10.96.10.146:9292 [Errno 32] Broken pipe
  INFO      * 05-18 13:37:07 [PID:10259] * root * sync done.
  INFO      * 05-18 13:38:01 [PID:10372] * root * glance-simplestreams-sync started.

  [Test Case]

  Found evidence in the juju logs for glance/0 that it restarted right at 13:37:07:
  2016-05-18 13:37:07 INFO ceph-relation-changed ^MReading state information... 0%^MReading state information... 0%^MReading state information... Done
  2016-05-18 13:37:07 INFO juju-log ceph:50: Loaded template from templates/ceph.conf
  2016-05-18 13:37:07 INFO juju-log ceph:50: Rendering from template: ceph.conf
  2016-05-18 13:37:07 INFO juju-log ceph:50: Wrote template /var/lib/charm/glance/ceph.conf.
  2016-05-18 13:37:07 INFO ceph-relation-changed glance-api stop/waiting
  2016-05-18 13:37:07 INFO ceph-relation-changed glance-api start/running, process 62839

  glance/1 had its last restart later:
  2016-05-18 13:32:01 INFO ceph-relation-changed glance-api start/running, process 31045

  glance/2 at that time too:
  2016-05-18 13:32:00 INFO ceph-relation-changed glance-api start/running, process 30584

  In gs3, a few log entries later, we can see that 14.04 is in state "saving" in glance:
  (...)
  {"images": [{"status": "saving", "deleted_at": null, "name": "auto-sync/ubuntu-trusty-14.04-amd64-server-20160516-disk1.img", "deleted": false, "container_format": "bare
  (...)

  It remains in this state throughout the logs.

  gs3 then proceeds to download 16.04, upload it to glance, and then
  finally publishes the streams. It's unknown if 14.04 is part of this
  publication or not.

  [Regression Potential]

  This part was added specifically for the Xenial backport, including:

  - 433-glance-ignore-inactive-images.patch (LP: #1583276)

  And chances of regression are small based on the MR feedback from SEG
  and this particular bug already stating the issue was fixed.

  [Other Info]

  Landscape however fails, because it doesn't find enough "active" images:
  May 18 14:33:29 job-handler-1 INFO  RetryingCall for '_wait_for_active_image' failed, will try again.
  May 18 14:33:29 job-handler-1 INFO  Traceback: <class 'canonical.landscape.model.openstack.jobs.errors.NoActiveImageAvailable'>: #012/usr/lib/python2.7/dist-packages/twisted/internet/defer.py:393:callback#012/usr/lib/python2.7/dist-packages/twisted/internet/defer.py:501:_startRunCallbacks#012/usr/lib/python2.7/dist-packages/twisted/internet/defer.py:588:_runCallbacks#012/usr/lib/python2.7/dist-packages/twisted/internet/defer.py:1184:gotResult#012--- <exception caught here> ---#012/usr/lib/python2.7/dist-packages/twisted/internet/defer.py:1128:_inlineCallbacks#012/opt/canonical/landscape/canonical/landscape/model/openstack/jobs/images.py:48:_wait_for_active_image

To manage notifications about this bug go to:
https://bugs.launchpad.net/glance-simplestreams-sync-charm/+bug/1583276/+subscriptions