Comment 0 for bug 1583276

Revision history for this message
Andreas Hasenack (ahasenack) wrote :

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.

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.

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