<div dir="ltr"><font face="monospace, monospace">Hi, guys,<br><br>TL;DR<br>After implementation of the blueprint[1], now we use olso.log module in Mistral, just as the same with other projects. However, we still use mistral.utils.wf_trace module to make some info insertion into log messages(we want to log execution id or task id during workflow running), which is a little bit ugly, considering it could be replaced using oslo.log features itself.</font><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace"><div class="gmail_default" style="font-size:small;display:inline">​So, I ​submit the proposal here to bring more people to have an open discussion, to make sure wo make consensus about that before I start to do code work.</div><br><br>Below is the long version in rst format:<br><br>Problem Description<br>===================<br>Currently, we have mistral.utils.wf_trace module to get execution-id and task-id during mistral workflow execution, then insert them to the log, so there are plenty of <a href="http://wf_trace.info">wf_trace.info</a> invokings all around our code repo, which is much more likely a hacking to log module funtionality, and it's not consistent with most of the log behavior in code writing.<br><br>Proposed Change<br>===============<br>Instead of adding an extra wf_trace module, we make use of the capability provided by oslo.log. Take an example, we have code as below::<br><br>    wf_ex = task_ex.workflow_execution<br>    <a href="http://wf_trace.info">wf_trace.info</a>(task_ex, "Task '%s' [%s -> %s]" % (<a href="http://task_ex.name">task_ex.name</a>, task_ex.state, state))<br><br>then, you will see from the log with content below:<br><br>``2015-06-26 04:09:50.326 19492 mistral.engine.default_engine INFO Task 'my_task' [WAITING -> RUNNING] (execution_id=c79b656f-f57f-4761-a270-138ee2417e54 task_id=a8935974-5468-de89-b785-138ee241qefd)``<br><br>the execution_id and task_i<div class="gmail_default" style="font-size:small;display:inline">​​</div>d are automatically inserted in wf_trace module. With oslo.log, we could change the log behavior::<br><br>    wf_ex = task_ex.workflow_execution<br>    LOG.info("Task '%s' [%s -> %s]" % (<a href="http://task_ex.name">task_ex.name</a>, task_ex.state, state), resource={'type': 'workflow', 'id': <a href="http://wf_ex.id">wf_ex.id</a>})<br><br>and don't forget config *logging_default_format_string* value in *mistral.conf* to: <br><br>``%(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s [-] %(resource)s%(message)s``<div class="gmail_default" style="font-size:small;display:inline">​​</div><br><br>so, the log content would be like this:<br><br>``2015-06-26 04:09:50.326 19492 mistral.engine.default_engine INFO [workflow-c79b656f-f57f-4761-a270-138ee2417e54] Task 'my_task' [WAITING -> RUNNING]``<br><br>As you could noticed, the task_id is lost, yes, actually, for the time being, oslo.log don't provide the capability such as recording various resources at the same time in one line, which I have send an email to openstack-dev mailing list to ask what oslo team suggest for this issue. <br><br>However, IMO, we have enough information for the operators to debug, we have execution-id, task name, etc, and most importnantly it's a more general way for logging.<br><br>But, if you really don't tolerate this change, we have workaround here before the oslo.log has a final solution(maybe that will never happen). We change the code as below::<br><br>    wf_ex = task_ex.workflow_execution<br>    LOG.info("Task '%s'(%s) [%s -> %s]" % (<a href="http://task_ex.name">task_ex.name</a>, <a href="http://task_ex.id">task_ex.id</a>, task_ex.state, state), resource={'type': 'workflow', 'id': <a href="http://wf_ex.id">wf_ex.id</a>})<br><br>so, the log content would be like this:<br><br>``2015-06-26 04:09:50.326 19492 mistral.engine.default_engine INFO [workflow-c79b656f-f57f-4761-a270-138ee2417e54] Task 'my_task'(a8935974-5468-de89-b785-138ee241qefd) [WAITING -> RUNNING]``<br><br>Finally, we get rid of the redundant wf_trace module from Mistral, which is really important for an engineer with OCD :-)<br><br>REST API Impact<br>---------------<br>No, it's just an improvement internally<br><br>Security Impact<br>---------------<br>No<br><br>Other End User Impact<br>---------------------<br>No<br><br>Performance Impact<br>------------------<br>Absolutely no.<br><br>Other Deployer Impact<br>---------------------<br>No<br><br>Developer Impact<br>----------------<br>Yes, it will change how the developers want to log something related to executions or tasks.<br><br>Alternatives<br>------------<br>Anyway, we could keep the wf_trace module as it is, but it's a very ugly way.<br><br>References<br>==========<br><a href="https://blueprints.launchpad.net/oslo.log/+spec/app-agnostic-logging-parameters">https://blueprints.launchpad.net/oslo.log/+spec/app-agnostic-logging-parameters</a><br><br>[1]: <a href="https://blueprints.launchpad.net/mistral/+spec/mistral-log-enhancement">https://blueprints.launchpad.net/mistral/+spec/mistral-log-enhancement</a><br>-- <br>Regards!<br>-----------------------------------<br>Lingxian Kong</font></div></div>