<div dir="ltr"><div class="gmail_extra"><br><div class="gmail_quote">On Mon, Jul 7, 2014 at 8:34 AM, Brant Knudson <span dir="ltr"><<a href="mailto:blk@acm.org" target="_blank">blk@acm.org</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
<div dir="ltr"><div><br></div>Henry -<br><div class="gmail_extra"><br><br><div class="gmail_quote"><div class="">On Mon, Jul 7, 2014 at 7:17 AM, Henry Nash <span dir="ltr"><<a href="mailto:henryn@linux.vnet.ibm.com" target="_blank">henryn@linux.vnet.ibm.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-style:solid;border-left-color:rgb(204,204,204);padding-left:1ex"><div style="word-wrap:break-word">Hi<div><br></div><div>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 <a href="http://logs.openstack.org/14/74214/40/check/gate-keystone-python26/1714702/subunit_log.txt.gz" target="_blank">http://logs.openstack.org/14/74214/40/check/gate-keystone-python26/1714702/subunit_log.txt.gz</a> 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:</div>
<div><br></div><div>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.</div>
<div><br></div></div></blockquote></div></div></div></div></blockquote><div><br></div><div>Bug report!<br></div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
<div dir="ltr"><div class="gmail_extra"><div class="gmail_quote"><div class=""><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-style:solid;border-left-color:rgb(204,204,204);padding-left:1ex">
<div style="word-wrap:break-word"><div></div><div>2) There are some spectacularly uninteresting log entries, e.g. 25 lines of :</div><div><br></div><div><span style="font-family:monospace;font-size:inherit;white-space:pre-wrap">Initialized with method overriding = True, and path info altering = True</span></div>
<div><span style="font-family:monospace;font-size:inherit;white-space:pre-wrap"><br></span></div><div>as part of each unit test call that uses routes! (This is generated as part of the routes.middleware init)</div><div><br>
</div><div>3) Some seemingly over zealous logging, e.g. the following happens multiple times per call:</div><div><br></div><div><div><font style="font-size:10px" face="Menlo">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></font></div>
<font style="font-size:10px" face="Menlo"><br></font><div><font style="font-size:10px" face="Menlo">Got '2014' for 'year' with default None</font></div><font style="font-size:10px" face="Menlo"><br></font><div>
<font style="font-size:10px" face="Menlo">Got '07' for 'monthdash' with default 1</font></div><font style="font-size:10px" face="Menlo"><br></font><div><font style="font-size:10px" face="Menlo">Got 7 for 'month' with default 7</font></div>
<font style="font-size:10px" face="Menlo"><br></font><div><font style="font-size:10px" face="Menlo">Got '06' for 'daydash' with default 1</font></div><font style="font-size:10px" face="Menlo"><br></font><div>
<font style="font-size:10px" face="Menlo">Got 6 for 'day' with default 6</font></div><font style="font-size:10px" face="Menlo"><br></font><div><font style="font-size:10px" face="Menlo">Got '14' for 'hour' with default None</font></div>
<font style="font-size:10px" face="Menlo"><br>Got '47' for 'minute' with default None</font></div><div><br></div></div></blockquote><div><br></div></div><div>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.<br>
<br>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.<br>
<br></div><div>Maybe the tests can setup logging the same way.</div><div><br>[1]
<a href="http://git.openstack.org/cgit/openstack/keystone/tree/keystone/openstack/common/log.py?id=26364496ca292db25c2e923321d2366e9c4bedc3#n158" target="_blank">http://git.openstack.org/cgit/openstack/keystone/tree/keystone/openstack/common/log.py?id=26364496ca292db25c2e923321d2366e9c4bedc3#n158</a><br>
[2] <a href="http://git.openstack.org/cgit/openstack/keystone/tree/bin/keystone-all#n116" target="_blank">http://git.openstack.org/cgit/openstack/keystone/tree/bin/keystone-all#n116</a><br> <br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-style:solid;border-left-color:rgb(204,204,204);padding-left:1ex">
<div class="">
<div style="word-wrap:break-word"><div></div><div>3) LDAP is VERY verbose, e.g. 30-50 lines of debug per call to the driver. </div><div><br></div><div>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?</div>
<span><font color="#888888"><div><br></div></font></span></div></div></blockquote></div></div></div></blockquote><div><br></div><div><div>This would be a great topic, but given that this is a community-wide issue, we already have some community-wide direction:</div>
<div><br></div><div><a href="https://wiki.openstack.org/wiki/Security/Guidelines/logging_guidelines#Log_Level_Usage_Recommendations">https://wiki.openstack.org/wiki/Security/Guidelines/logging_guidelines#Log_Level_Usage_Recommendations</a></div>
<div><a href="https://wiki.openstack.org/wiki/LoggingStandards">https://wiki.openstack.org/wiki/LoggingStandards</a><br></div><div><br></div><div>We certainly have room to better adhere to these expectations (I also think these two pages should be consolidated).</div>
</div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><div dir="ltr"><div class="gmail_extra">
<div class="gmail_quote"><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-style:solid;border-left-color:rgb(204,204,204);padding-left:1ex"><div class=""><div style="word-wrap:break-word">
<span><font color="#888888"><div></div><div>Henry</div></font></span></div><br></div>_______________________________________________<br>
OpenStack-dev mailing list<br>
<a href="mailto:OpenStack-dev@lists.openstack.org" target="_blank">OpenStack-dev@lists.openstack.org</a><br>
<a href="http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev" target="_blank">http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev</a><br>
<br></blockquote></div><br></div></div>
<br>_______________________________________________<br>
OpenStack-dev mailing list<br>
<a href="mailto:OpenStack-dev@lists.openstack.org">OpenStack-dev@lists.openstack.org</a><br>
<a href="http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev" target="_blank">http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev</a><br>
<br></blockquote></div><br></div></div>