Open Stack

Henry -


On Mon, Jul 7, 2014 at 7:17 AM, Henry Nash <henryn at linux.vnet.ibm.com>
wrote:

> Hi
>
> Our debug log file size is getting pretty huge....a typical py26 jenkins
> run produces a whisker under 50Mb of log - which is problematic for at
> least the reason that our current jenkins setup consider the test run a
> failure if the log file is > 50 Mb.  (see
> http://logs.openstack.org/14/74214/40/check/gate-keystone-python26/1714702/subunit_log.txt.gz
> as an example for a recent patch I am working on).  Obviously we could just
> raise the limit, but we should probably also look at how effective our
> logging is.  Reviewing of the log file listed above shows:
>
> 1) Some odd corruption.  I think this is related to the subunit
> concatenation of output files, but haven't been able to find the exact
> cause (looking a local subunit file shows some weird characters, but not as
> bad as when as part of jenkins).  It may be that this corruption is dumping
> more data than we need into the log file.
>
> 2) There are some spectacularly uninteresting log entries, e.g. 25 lines
> of :
>
> Initialized with method overriding = True, and path info altering = True
>
> as part of each unit test call that uses routes! (This is generated as
> part of the routes.middleware init)
>
> 3) Some seemingly over zealous logging, e.g. the following happens
> multiple times per call:
>
> Parsed 2014-07-06T14:47:46.850145Z into {'tz_sign': None,
> 'second_fraction': '850145', 'hour': '14', 'daydash': '06', 'tz_hour':
> None, 'month': None, 'timezone': 'Z', 'second': '46', 'tz_minute': None,
> 'year': '2014', 'separator': 'T', 'monthdash': '07', 'day': None, 'minute':
> '47'} with default timezone <iso8601.iso8601.Utc object at 0x1a02fd0>
>
> Got '2014' for 'year' with default None
>
> Got '07' for 'monthdash' with default 1
>
> Got 7 for 'month' with default 7
>
> Got '06' for 'daydash' with default 1
>
> Got 6 for 'day' with default 6
>
> Got '14' for 'hour' with default None
>
> Got '47' for 'minute' with default None
>
>
The default log levels for the server are set in oslo-incubator's log
module[1]. This is where it sets iso8601=WARN which should get rid of #3.

In addition to these defaults, when the server starts it calls
config.set_default_for_default_log_levels()[2] which sets the routes logger
to INFO, which should take care of #2. The unit tests could do something
similar.

Maybe the tests can setup logging the same way.

[1]
http://git.openstack.org/cgit/openstack/keystone/tree/keystone/openstack/common/log.py?id=26364496ca292db25c2e923321d2366e9c4bedc3#n158
[2]
http://git.openstack.org/cgit/openstack/keystone/tree/bin/keystone-all#n116


> 3) LDAP is VERY verbose, e.g. 30-50 lines of debug per call to the driver.
>
>
> I'm happy to work to trim back some of worst excesses....but open to ideas
> as to whether we need a more formal approach to this...perhaps a good topic
> for our hackathon this week?
>
> Henry
>
> _______________________________________________
> OpenStack-dev mailing list
> OpenStack-dev at lists.openstack.org
> http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openstack.org/pipermail/openstack-dev/attachments/20140707/2e8e3c87/attachment.html>