swiftclient logs all ClientException (404) at ERROR (with traceback)

[Dan Prince]

When using Glance Havana with the latest version of swiftclient I get the following stack trace in my Glance API server log on startup:

2013-08-16 15:46:25.279 28346 ERROR swiftclient [-] Container HEAD failed: http://nova1:8080/v1/AUTH_85e1d06769e4448a9a11d9924297a206/glance 404 Not Found
2013-08-16 15:46:25.279 28346 TRACE swiftclient Traceback (most recent call last):
2013-08-16 15:46:25.279 28346 TRACE swiftclient File "/usr/lib/python2.7/site-packages/swiftclient/client.py", line 1095, in _retry
2013-08-16 15:46:25.279 28346 TRACE swiftclient rv = func(self.url, self.token, *args, **kwargs)
2013-08-16 15:46:25.279 28346 TRACE swiftclient File "/usr/lib/python2.7/site-packages/swiftclient/client.py", line 566, in head_container
2013-08-16 15:46:25.279 28346 TRACE swiftclient http_response_content=body)
2013-08-16 15:46:25.279 28346 TRACE swiftclient ClientException: Container HEAD failed: http://nova1:8080/v1/AUTH_85e1d06769e4448a9a11d9924297a206/glance 404 Not Found
2013-08-16 15:46:25.279 28346 TRACE swiftclient

-----

I'm using swift_store_create_container_on_put = True and the issue seems get logged when the _create_container_if_missing function in the Glance swift backend checks for the swift container. The Glance code looks totally fine to me one of our logging configs seems to cause the swiftclient library to log this exception regardless.

We should not be logging an ERROR when creating the initial swift container...

[Matt Riedemann (mriedem)]

Hmm, that error is whitelisted now:

https://github.com/openstack/tempest/blob/master/etc/whitelist.yaml#L48

[Erno Kuvaja (jokke)]

Moved to glance-store. Needs to be re-evaluated if the issue is still valid.

[Darren Hoyland (autonomouse)]

We have several hits for this bug in OIL (The regex we used to find this bug was: "TRACE swiftclient ClientException. Container HEAD failed.{55,70}glance 404 Not Found" searching in files matching this glob pattern: "glance_*_var_log_glance_api.log")

[Kairat Kushaev (kkushaev)]

Need to remove 404 error traceback from log files.

[Kairat Kushaev (kkushaev)]

Ok, that's not glance_store error.
404 exception is logged in python-swiftclient: https://github.com/openstack/python-swiftclient/blob/master/swiftclient/client.py#1522.
So I am moving the bug to swiftclient. It should not show stack-trace when 404 has been raised.

[clayg (clay-gerrard)]

also reported on twitter [1]

Problem seems to be that we need some additional filtering in Connection._retry [2] to decide the appropriate logging (if any) for the exception.

More generally I would say if we're going to raise it bare it's not that useful to log it first (as opposed to logging the original socket error before translating to a ClientException) - let the caller do that if they want (e.g. swiftclient.service logs lots of *non*-404 ClientExceptions (again, sigh)).

At a minimum we should change it to use `logger.debug(err, exc_info=True)` instead of logger.exception for blanket ClientException handling.

1. https://twitter.com/wolever/status/697234620966895616
2. https://github.com/openstack/python-swiftclient/blob/d2ee01bfe4bc8ac864d8f10ef657e6ce45168d9c/swiftclient/client.py#L1532

[clayg (clay-gerrard)]

So I guess this is actually the "a little bit much with logging" reaction to lp bug #1202229 (see original change https://review.openstack.org/#/c/37336/)

[gordon chung (chungg)]

affects us in Gnocchi as well[1]. i'm curious what the motivation for logging stuff in the client is (especially as ERROR)? shouldn't this be logged in swift server and a simple status code returned. it should be up to the user to decide whether something is an error or not (from client pov).

to describe our use case in Gnocchi, we store metrics in an object in swift. as this happens hundreds/thousands times a second, we do not check if something exists first. in Gnocchi, we assume something exists and if doesn't, we create it. this allows us to avoid overhead of checking for existence hundreds/thousands times a second.

https://bugs.launchpad.net/gnocchi/+bug/1554759

[Bartek Żurawski (bartekzurawski1)]

IMHO this bug mostly affects users who use swiftclient/client.py, that's why I think that we can remove all loggers including logger definition from this file, and give callers opportunity to make theirs own logs as the want. What do you think about that kind of solution?

[clayg (clay-gerrard)]

Reported again on https://bugs.launchpad.net/swift/+bug/1621425

[OpenStack Infra (hudson-openstack)]

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

commit 481f74caf1ffc649128bb8db84ac9104304420a9
Author: Tim Burke <email address hidden>
Date: Fri Oct 28 12:19:35 2016 +0200

    Low-level API: Don't log just before raising an exception

    The only logging we should do is when we've encountered a problem *and
    we've dealt with it ourselves*. When we're raising an exception, it
    should be up to the caller to decide whether to log anything about it.

    Anything else is just rude.

    Change-Id: I1c96b76d90a78b7a10ffe63e4a7440c8f579147c
    Closes-Bug: 1213179
    Related-Bug: 1202229

[OpenStack Infra (hudson-openstack)]

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