<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40">
<head>
<meta http-equiv="Content-Type" content="text/html; charset=us-ascii">
<meta name="Generator" content="Microsoft Word 14 (filtered medium)">
<style><!--
/* Font Definitions */
@font-face
        {font-family:SimSun;
        panose-1:2 1 6 0 3 1 1 1 1 1;}
@font-face
        {font-family:SimSun;
        panose-1:2 1 6 0 3 1 1 1 1 1;}
@font-face
        {font-family:Calibri;
        panose-1:2 15 5 2 2 2 4 3 2 4;}
@font-face
        {font-family:Tahoma;
        panose-1:2 11 6 4 3 5 4 4 2 4;}
@font-face
        {font-family:"\@SimSun";
        panose-1:2 1 6 0 3 1 1 1 1 1;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
        {margin:0in;
        margin-bottom:.0001pt;
        font-size:11.0pt;
        font-family:"Calibri","sans-serif";}
a:link, span.MsoHyperlink
        {mso-style-priority:99;
        color:blue;
        text-decoration:underline;}
a:visited, span.MsoHyperlinkFollowed
        {mso-style-priority:99;
        color:purple;
        text-decoration:underline;}
span.EmailStyle17
        {mso-style-type:personal;
        font-family:"Calibri","sans-serif";
        color:windowtext;}
span.EmailStyle18
        {mso-style-type:personal-reply;
        font-family:"Calibri","sans-serif";
        color:#1F497D;}
.MsoChpDefault
        {mso-style-type:export-only;
        font-size:10.0pt;}
@page WordSection1
        {size:8.5in 11.0in;
        margin:1.0in 1.0in 1.0in 1.0in;}
div.WordSection1
        {page:WordSection1;}
--></style><!--[if gte mso 9]><xml>
<o:shapedefaults v:ext="edit" spidmax="1026" />
</xml><![endif]--><!--[if gte mso 9]><xml>
<o:shapelayout v:ext="edit">
<o:idmap v:ext="edit" data="1" />
</o:shapelayout></xml><![endif]-->
</head>
<body lang="EN-US" link="blue" vlink="purple">
<div class="WordSection1">
<p class="MsoNormal"><span style="color:#1F497D">I find the reason. <o:p></o:p></span></p>
<p class="MsoNormal"><span style="color:#1F497D"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="color:#1F497D">When devstack install sahara, “logging_context_format_string” would be configured by default to:<o:p></o:p></span></p>
<p class="MsoNormal"><span style="color:#1F497D">        logging_context_format_string = %(asctime)s.%(msecs)03d %(color)s%(levelname)s %(name)s [^[[01;36m%(request_id)s ^[[00;36m%(</span><b><span style="color:red">user_name</span></b><span style="color:#1F497D">)s
 %(project_name)s%(color)s] ^[[01;35m%(instance)s%(color)s%(message)s^[[00m<o:p></o:p></span></p>
<p class="MsoNormal"><span style="color:#1F497D"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="color:#1F497D">But we don’t have user_name, we’re using username:
<a href="https://github.com/openstack/sahara/blob/master/sahara/context.py#L40">https://github.com/openstack/sahara/blob/master/sahara/context.py#L40</a><o:p></o:p></span></p>
<p class="MsoNormal"><span style="color:#1F497D"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="color:#1F497D">The error do not happen until we merged
<a href="https://review.openstack.org/#/c/172426/">https://review.openstack.org/#/c/172426/</a>.<o:p></o:p></span></p>
<p class="MsoNormal"><span style="color:#1F497D">When we do LOG.debug with a Context instance.<o:p></o:p></span></p>
<p class="MsoNormal"><span style="color:#1F497D"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="color:#1F497D">Summited a fix already : <a href="https://review.openstack.org/#/c/180051/">
https://review.openstack.org/#/c/180051/</a><o:p></o:p></span></p>
<p class="MsoNormal"><span style="color:#1F497D"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="color:#1F497D">Thanks.<o:p></o:p></span></p>
<p class="MsoNormal"><span style="color:#1F497D">-chen<o:p></o:p></span></p>
<p class="MsoNormal"><span style="color:#1F497D"><o:p> </o:p></span></p>
<div>
<div style="border:none;border-top:solid #B5C4DF 1.0pt;padding:3.0pt 0in 0in 0in">
<p class="MsoNormal"><b><span style="font-size:10.0pt;font-family:"Tahoma","sans-serif"">From:</span></b><span style="font-size:10.0pt;font-family:"Tahoma","sans-serif""> Li, Chen
<br>
<b>Sent:</b> Tuesday, May 05, 2015 10:43 AM<br>
<b>To:</b> OpenStack Development Mailing List (not for usage questions) (openstack-dev@lists.openstack.org)<br>
<b>Subject:</b> [Sahara][oslo]Error in Log.debug<o:p></o:p></span></p>
</div>
</div>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">Hi all,<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">I just upgrade my devstack and re-installed.<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">My sahara keep reporting errors:<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">2015-05-05 10:42:00.453 DEBUG sahara.openstack.common.loopingcall [-] Dynamic looping call <bound method SaharaPeriodicTasks.run_periodic_tasks of <sahara.service.periodic.SaharaPeriodicTasks object at 0x7f2ccef987d0>> sleeping for 35.91
 seconds from (pid=5361) _inner /opt/stack/sahara/sahara/openstack/common/loopingcall.py:132<o:p></o:p></p>
<p class="MsoNormal">2015-05-05 10:42:36.397 DEBUG sahara.openstack.common.periodic_task [-] Running periodic task SaharaPeriodicTasks.terminate_unneeded_transient_clusters from (pid=5361) run_periodic_tasks /opt/stack/sahara/sahara/openstack/common/periodic_task.py:219<o:p></o:p></p>
<p class="MsoNormal">Traceback (most recent call last):<o:p></o:p></p>
<p class="MsoNormal">  File "/usr/lib/python2.7/logging/__init__.py", line 851, in emit<o:p></o:p></p>
<p class="MsoNormal">    msg = self.format(record)<o:p></o:p></p>
<p class="MsoNormal">  File "/usr/local/lib/python2.7/dist-packages/oslo_log/handlers.py", line 69, in format<o:p></o:p></p>
<p class="MsoNormal">    return logging.StreamHandler.format(self, record)<o:p></o:p></p>
<p class="MsoNormal">  File "/usr/lib/python2.7/logging/__init__.py", line 724, in format<o:p></o:p></p>
<p class="MsoNormal">    return fmt.format(record)<o:p></o:p></p>
<p class="MsoNormal">  File "/usr/local/lib/python2.7/dist-packages/oslo_log/formatters.py", line 235, in format<o:p></o:p></p>
<p class="MsoNormal">    return logging.Formatter.format(self, record)<o:p></o:p></p>
<p class="MsoNormal">  File "/usr/lib/python2.7/logging/__init__.py", line 467, in format<o:p></o:p></p>
<p class="MsoNormal">    s = self._fmt % record.__dict__<o:p></o:p></p>
<p class="MsoNormal">KeyError: 'user_name'<o:p></o:p></p>
<p class="MsoNormal">Logged from file periodic.py, line 137<o:p></o:p></p>
<p class="MsoNormal">2015-05-05 10:42:36.434 DEBUG sahara.openstack.common.loopingcall [-] Dynamic looping call <bound method SaharaPeriodicTasks.run_periodic_tasks of <sahara.service.periodic.SaharaPeriodicTasks object at 0x7f2ccef987d0>> sleeping for 9.96
 seconds from (pid=5361) _inner /opt/stack/sahara/sahara/openstack/common/loopingcall.py:132<o:p></o:p></p>
<p class="MsoNormal">2015-05-05 10:42:46.408 DEBUG sahara.openstack.common.periodic_task [-] Running periodic task SaharaPeriodicTasks.update_job_statuses from (pid=5361) run_periodic_tasks /opt/stack/sahara/sahara/openstack/common/periodic_task.py:219<o:p></o:p></p>
<p class="MsoNormal">Traceback (most recent call last):<o:p></o:p></p>
<p class="MsoNormal">  File "/usr/lib/python2.7/logging/__init__.py", line 851, in emit<o:p></o:p></p>
<p class="MsoNormal">    msg = self.format(record)<o:p></o:p></p>
<p class="MsoNormal">  File "/usr/local/lib/python2.7/dist-packages/oslo_log/handlers.py", line 69, in format<o:p></o:p></p>
<p class="MsoNormal">    return logging.StreamHandler.format(self, record)<o:p></o:p></p>
<p class="MsoNormal">  File "/usr/lib/python2.7/logging/__init__.py", line 724, in format<o:p></o:p></p>
<p class="MsoNormal">    return fmt.format(record)<o:p></o:p></p>
<p class="MsoNormal">  File "/usr/local/lib/python2.7/dist-packages/oslo_log/formatters.py", line 235, in format<o:p></o:p></p>
<p class="MsoNormal">    return logging.Formatter.format(self, record)<o:p></o:p></p>
<p class="MsoNormal">  File "/usr/lib/python2.7/logging/__init__.py", line 467, in format<o:p></o:p></p>
<p class="MsoNormal">    s = self._fmt % record.__dict__<o:p></o:p></p>
<p class="MsoNormal">KeyError: 'user_name'<o:p></o:p></p>
<p class="MsoNormal">Logged from file periodic.py, line 131<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">Anyone know why this happens ???<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">Thanks.<o:p></o:p></p>
<p class="MsoNormal">-chen<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
</body>
</html>