metricd stops renewing/refreshing token with swift backend

Bug #1589926 reported by Yurii Prokulevych
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Gnocchi
Fix Released
Medium
Julien Danjou
2.1
Fix Released
Medium
Julien Danjou
python-swiftclient
Fix Released
Undecided
Unassigned

Bug Description

Gnocchi is configured to use swift backend. Also gnocchi's api is running under mod_wsgi.

After some time, gnocchi-metricd starts error'ing with next message:
...
2016-06-07 11:06:01.077 16999 DEBUG gnocchi.storage [-] Expunging deleted metrics process_background_tasks /usr/lib/python2.7/site-packages/gnocchi/storage/__init__.py:191
2016-06-07 11:06:06.060 16999 DEBUG gnocchi.storage [-] Processing new and to delete measures process_background_tasks /usr/lib/python2.7/site-packages/gnocchi/storage/__init__.py:183
2016-06-07 11:06:06.079 16999 INFO swiftclient [-] REQ: curl -i http://192.0.2.15:8080/v1/AUTH_a2a8b54f11bf47d7a5b8ac9be9acf5c9/measure?format=json&limit=16&delimiter=/ -X GET -H "X-Auth-Token: 4dd3cd7c8930434f..."
2016-06-07 11:06:06.079 16999 INFO swiftclient [-] RESP STATUS: 401 Unauthorized
2016-06-07 11:06:06.080 16999 INFO swiftclient [-] RESP HEADERS: {u'Date': u'Tue, 07 Jun 2016 11:06:06 GMT', u'Content-Length': u'131', u'Content-Type': u'text/html; charset=UTF-8', u'Www-Authenticate': u'Swift realm="AUTH_a2a8b54f11bf47d7a5b8ac9be9acf5c9", Keystone uri=\'http://192.0.2.15:5000/v2.0\'', u'X-Trans-Id': u'tx52d6876089464082a5389-005756aa9e'}
2016-06-07 11:06:06.080 16999 INFO swiftclient [-] RESP BODY: <html><h1>Unauthorized</h1><p>This server could not verify that you are authorized to access the document you requested.</p></html>
2016-06-07 11:06:06.080 16999 ERROR swiftclient [-] Container GET failed: http://192.0.2.15:8080/v1/AUTH_a2a8b54f11bf47d7a5b8ac9be9acf5c9/measure?format=json&limit=16&delimiter=/ 401 Unauthorized [first 60 chars of response] <html><h1>Unauthorized</h1><p>This server could not verify t
2016-06-07 11:06:06.080 16999 ERROR swiftclient Traceback (most recent call last):
2016-06-07 11:06:06.080 16999 ERROR swiftclient File "/usr/lib/python2.7/site-packages/swiftclient/client.py", line 1565, in _retry
2016-06-07 11:06:06.080 16999 ERROR swiftclient service_token=self.service_token, **kwargs)
2016-06-07 11:06:06.080 16999 ERROR swiftclient File "/usr/lib/python2.7/site-packages/swiftclient/client.py", line 884, in get_container
2016-06-07 11:06:06.080 16999 ERROR swiftclient http_response_content=body)
2016-06-07 11:06:06.080 16999 ERROR swiftclient ClientException: Container GET failed: http://192.0.2.15:8080/v1/AUTH_a2a8b54f11bf47d7a5b8ac9be9acf5c9/measure?format=json&limit=16&delimiter=/ 401 Unauthorized [first 60 chars of response] <html><h1>Unauthorized</h1><p>This server could not verify t
2016-06-07 11:06:06.080 16999 ERROR swiftclient
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage [-] Unexpected error during measures processing
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage Traceback (most recent call last):
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage File "/usr/lib/python2.7/site-packages/gnocchi/storage/__init__.py", line 185, in process_background_tasks
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage self.process_measures(index, block_size, sync)
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage File "/usr/lib/python2.7/site-packages/gnocchi/storage/_carbonara.py", line 346, in process_measures
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage block_size, full=sync)
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage File "/usr/lib/python2.7/site-packages/gnocchi/storage/swift.py", line 138, in _list_metric_with_measures_to_process
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage limit=limit)
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage File "/usr/lib/python2.7/site-packages/swiftclient/client.py", line 1638, in get_container
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage full_listing=full_listing, headers=headers)
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage File "/usr/lib/python2.7/site-packages/swiftclient/client.py", line 1565, in _retry
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage service_token=self.service_token, **kwargs)
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage File "/usr/lib/python2.7/site-packages/swiftclient/client.py", line 884, in get_container
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage http_response_content=body)
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage ClientException: Container GET failed: http://192.0.2.15:8080/v1/AUTH_a2a8b54f11bf47d7a5b8ac9be9acf5c9/measure?format=json&limit=16&delimiter=/ 401 Unauthorized [first 60 chars of response] <html><h1>Unauthorized</h1><p>This server could not verify t
2016-06-07 11:06:06.080 16999 ERROR gnocchi.storage
2016-06-07 11:06:06.081 16999 DEBUG gnocchi.storage [-] Expunging deleted metrics process_background_tasks /usr/lib/python2.7/site-packages/gnocchi/storage/__init__.py:191
...

And gnocchi_wsgi_error.log reports next:

[Tue Jun 07 11:06:31.662229 2016] [:error] [pid 32764] [remote 192.0.2.21:44] mod_wsgi (pid=32764): Exception occurred processing WSGI script '/var/www/cgi-bin/gnocchi/app'.
[Tue Jun 07 11:06:31.662262 2016] [:error] [pid 32764] [remote 192.0.2.21:44] Traceback (most recent call last):
[Tue Jun 07 11:06:31.662276 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/paste/urlmap.py", line 203, in __call__
[Tue Jun 07 11:06:31.662295 2016] [:error] [pid 32764] [remote 192.0.2.21:44] return app(environ, start_response)
[Tue Jun 07 11:06:31.662314 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/webob/dec.py", line 130, in __call__
[Tue Jun 07 11:06:31.662331 2016] [:error] [pid 32764] [remote 192.0.2.21:44] resp = self.call_func(req, *args, **self.kwargs)
[Tue Jun 07 11:06:31.662340 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/webob/dec.py", line 195, in call_func
[Tue Jun 07 11:06:31.662352 2016] [:error] [pid 32764] [remote 192.0.2.21:44] return self.func(req, *args, **kwargs)
[Tue Jun 07 11:06:31.662361 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py", line 467, in __call__
[Tue Jun 07 11:06:31.662375 2016] [:error] [pid 32764] [remote 192.0.2.21:44] response = req.get_response(self._app)
[Tue Jun 07 11:06:31.662384 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/webob/request.py", line 1317, in send
[Tue Jun 07 11:06:31.662396 2016] [:error] [pid 32764] [remote 192.0.2.21:44] application, catch_exc_info=False)
[Tue Jun 07 11:06:31.662405 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/webob/request.py", line 1281, in call_application
[Tue Jun 07 11:06:31.662417 2016] [:error] [pid 32764] [remote 192.0.2.21:44] app_iter = application(self.environ, start_response)
[Tue Jun 07 11:06:31.662425 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/webob/exc.py", line 1117, in __call__
[Tue Jun 07 11:06:31.662437 2016] [:error] [pid 32764] [remote 192.0.2.21:44] return self.application(environ, start_response)
[Tue Jun 07 11:06:31.662446 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/gnocchi/rest/app.py", line 68, in __call__
[Tue Jun 07 11:06:31.662460 2016] [:error] [pid 32764] [remote 192.0.2.21:44] return self.app(environ, start_response)
[Tue Jun 07 11:06:31.662480 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/pecan/middleware/recursive.py", line 56, in __call__
[Tue Jun 07 11:06:31.662525 2016] [:error] [pid 32764] [remote 192.0.2.21:44] return self.application(environ, start_response)
[Tue Jun 07 11:06:31.662538 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/pecan/core.py", line 829, in __call__
[Tue Jun 07 11:06:31.662552 2016] [:error] [pid 32764] [remote 192.0.2.21:44] return super(Pecan, self).__call__(environ, start_response)
[Tue Jun 07 11:06:31.662561 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/pecan/core.py", line 678, in __call__
[Tue Jun 07 11:06:31.662573 2016] [:error] [pid 32764] [remote 192.0.2.21:44] self.invoke_controller(controller, args, kwargs, state)
[Tue Jun 07 11:06:31.662582 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/pecan/core.py", line 572, in invoke_controller
[Tue Jun 07 11:06:31.662593 2016] [:error] [pid 32764] [remote 192.0.2.21:44] result = controller(*args, **kwargs)
[Tue Jun 07 11:06:31.662608 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/gnocchi/rest/__init__.py", line 513, in post_measures
[Tue Jun 07 11:06:31.662622 2016] [:error] [pid 32764] [remote 192.0.2.21:44] self.metric, six.moves.map(MeasureSchema, params))
[Tue Jun 07 11:06:31.662631 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/gnocchi/storage/_carbonara.py", line 248, in add_measures
[Tue Jun 07 11:06:31.662645 2016] [:error] [pid 32764] [remote 192.0.2.21:44] list(map(tuple, measures))))
[Tue Jun 07 11:06:31.662654 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/gnocchi/storage/swift.py", line 114, in _store_measures
[Tue Jun 07 11:06:31.662667 2016] [:error] [pid 32764] [remote 192.0.2.21:44] data)
[Tue Jun 07 11:06:31.662675 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/swiftclient/client.py", line 1709, in put_object
[Tue Jun 07 11:06:31.662687 2016] [:error] [pid 32764] [remote 192.0.2.21:44] response_dict=response_dict)
[Tue Jun 07 11:06:31.662696 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/swiftclient/client.py", line 1565, in _retry
[Tue Jun 07 11:06:31.662707 2016] [:error] [pid 32764] [remote 192.0.2.21:44] service_token=self.service_token, **kwargs)
[Tue Jun 07 11:06:31.662715 2016] [:error] [pid 32764] [remote 192.0.2.21:44] File "/usr/lib/python2.7/site-packages/swiftclient/client.py", line 1281, in put_object
[Tue Jun 07 11:06:31.662726 2016] [:error] [pid 32764] [remote 192.0.2.21:44] http_response_content=body)
[Tue Jun 07 11:06:31.662755 2016] [:error] [pid 32764] [remote 192.0.2.21:44] ClientException: Object PUT failed: http://192.0.2.15:8080/v1/AUTH_a2a8b54f11bf47d7a5b8ac9be9acf5c9/measure/466e5c18-6bf3-4559-97d0-b66d30827f9e/813633d6-d30f-477e-8ffb-9d48ffad111f_20160607_11%3A06%3A31 401 Unauthorized [first 60 chars of response] <html><h1>Unauthorized</h1><p>This server could not verify t

Packages:
python-gnocchiclient-2.2.0-1.el7ost.noarch
openstack-gnocchi-common-2.1.1-1.el7ost.noarch
openstack-gnocchi-statsd-2.1.1-1.el7ost.noarch
python-gnocchi-2.1.1-1.el7ost.noarch
openstack-gnocchi-metricd-2.1.1-1.el7ost.noarch
openstack-gnocchi-indexer-sqlalchemy-2.1.1-1.el7ost.noarch
openstack-gnocchi-api-2.1.1-1.el7ost.noarch
openstack-gnocchi-carbonara-2.1.1-1.el7ost.noarch

python-swiftclient-3.0.0-1.el7ost.noarch

Regards,
Yurii

Julien Danjou (jdanjou)
Changed in gnocchi:
status: New → Triaged
Revision history for this message
Julien Danjou (jdanjou) wrote :

The problem is that if you set retries=0 in the Swift client object, then it does not retry, even on 401, to renew the token.

Changed in gnocchi:
importance: Undecided → Medium
assignee: nobody → Julien Danjou (jdanjou)
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to gnocchi (master)

Fix proposed to branch: master
Review: https://review.openstack.org/326454

Changed in gnocchi:
status: Triaged → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to gnocchi (master)

Reviewed: https://review.openstack.org/326454
Committed: https://git.openstack.org/cgit/openstack/gnocchi/commit/?id=0bbf0799768b28df156f7871125d1f8120723132
Submitter: Jenkins
Branch: master

commit 0bbf0799768b28df156f7871125d1f8120723132
Author: Julien Danjou <email address hidden>
Date: Tue Jun 7 15:11:10 2016 +0200

    swift: force retry to 1

    Change I4320fb3e8bb30603bd70f8159fbcf855fc4a2880 set the retries to 0 to
    minimize the delay. Unfortunately, swiftclient makes no difference between the
    errors, so it won't renew the token on 401 and retry.

    Set retry to 1 so we have a chance to renew the token.

    Closes-Bug: #1589926

    Change-Id: I44428dd4b23d2c8c12852ebf87bd7b60e2f85e3b

Changed in gnocchi:
status: In Progress → Fix Committed
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to gnocchi (stable/2.1)

Fix proposed to branch: stable/2.1
Review: https://review.openstack.org/327293

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to gnocchi (stable/2.1)

Reviewed: https://review.openstack.org/327293
Committed: https://git.openstack.org/cgit/openstack/gnocchi/commit/?id=a247c52ba6fc5fc8f69ab068065cb0514a7760a9
Submitter: Jenkins
Branch: stable/2.1

commit a247c52ba6fc5fc8f69ab068065cb0514a7760a9
Author: Julien Danjou <email address hidden>
Date: Tue Jun 7 15:11:10 2016 +0200

    swift: force retry to 1

    Change I4320fb3e8bb30603bd70f8159fbcf855fc4a2880 set the retries to 0 to
    minimize the delay. Unfortunately, swiftclient makes no difference between the
    errors, so it won't renew the token on 401 and retry.

    Set retry to 1 so we have a chance to renew the token.

    Closes-Bug: #1589926

    Change-Id: I44428dd4b23d2c8c12852ebf87bd7b60e2f85e3b
    (cherry picked from commit 0bbf0799768b28df156f7871125d1f8120723132)

Revision history for this message
Doug Hellmann (doug-hellmann) wrote : Fix included in openstack/gnocchi 2.2.0

This issue was fixed in the openstack/gnocchi 2.2.0 release.

Julien Danjou (jdanjou)
Changed in gnocchi:
status: Fix Committed → Fix Released
milestone: none → 2.2.0
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to python-swiftclient (master)

Reviewed: https://review.openstack.org/326475
Committed: https://git.openstack.org/cgit/openstack/python-swiftclient/commit/?id=a62b7ee06c1a300c73d9a01b2c9bc05028f1fabd
Submitter: Jenkins
Branch: master

commit a62b7ee06c1a300c73d9a01b2c9bc05028f1fabd
Author: Julien Danjou <email address hidden>
Date: Tue Jun 7 15:49:32 2016 +0200

    client: renew token on 401 even if retries is 0

    Gnocchi uses a client with retries=0 to maximize throughtput and not retry N
    times on e.g. 404 when checking existence of an object. However, this as the
    side effect of never renewing the token since there' no retry on 401 either.

    This patches change the behavior so that 401 errors are always retried,
    whatever the retries value is.

    Closes-Bug: #1589926
    Change-Id: Ie06adf4cf17ea4592b5bbd7bbde9828e5e134e3e

Changed in python-swiftclient:
status: New → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/python-swiftclient 3.1.0

This issue was fixed in the openstack/python-swiftclient 3.1.0 release.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix proposed to gnocchi (master)

Related fix proposed to branch: master
Review: https://review.openstack.org/367436

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix merged to gnocchi (master)

Reviewed: https://review.openstack.org/367436
Committed: https://git.openstack.org/cgit/openstack/gnocchi/commit/?id=d3276209545e755d9db0067c837ddcf4e63add70
Submitter: Jenkins
Branch: master

commit d3276209545e755d9db0067c837ddcf4e63add70
Author: Julien Danjou <email address hidden>
Date: Thu Sep 8 17:05:13 2016 +0200

    swift: bump swiftclient dependency to 3.1.0 and set retries=0

    Now that swiftclient has a fix for Keystone authentication, this reverts
    back to retries=0 on the client and depends on the more recent version
    of swiftclient.

    Change-Id: Iae144426701a4cfe8937a811e761d9c8cb6d86db
    Related-Bug: #1589926

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/python-swiftclient 3.1.0

This issue was fixed in the openstack/python-swiftclient 3.1.0 release.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.