<div dir="ltr"><br><div class="gmail_extra"><br><div class="gmail_quote">2014-12-27 18:36 GMT+01:00 Christophe de Vienne <span dir="ltr"><<a href="mailto:christophe@unlish.com" target="_blank">christophe@unlish.com</a>></span>:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">Hi everyone,<br>
<br></blockquote><div><br></div><div>Hi Christophe,</div><div> </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
We are running into a behavior that feels wrong to me, while using the<br>
worker cube.<br>
<br>
The worker cube uses the task workflow to make sure only one worker gets<br>
to execute it. Hence, to acquire a task before executing it, it simply<br>
attempt to change its state.<br>
<br>
Doing so, it actually write a new entry in the database: a relation<br>
between the task and the 'executing' state. If the task is already being<br>
executed, ie if its state it already 'executing', the update fails with<br>
a duplicate key violation, and the worker simply pass to the next task.<br>
<br>
So far so good.<br>
<br>
The problem is that when the duplicate key violation occur, which is<br>
expected to happen sometimes with several workers, here is what we get<br>
in the logs:<br>
<br>
cubicweb.sources.system 2014-12-27 16:57:07,780 CRITICAL sql many:<br>
'INSERT INTO in_state_relation ( eid_from, eid_to ) VALUES (<br>
%(eid_from)s, %(eid_to)s )'<br>
 args: [{'eid_to': 2240, 'eid_from': 1250592}]<br>
dbms message: 'duplicate key value violates unique constraint<br>
"in_state_relation_p_key"\nDETAIL:  Key (eid_from, eid_to)=(1250592,<br>
2240) already exists.\n'<br>
cubicweb.sources.system 2014-12-27 16:57:10,072 CRITICAL transaction has<br>
been rolled back<br>
<br>
<br>
I consider this a problem because it is in no way a critical error: it<br>
is expected to happen sometimes, and if it does it is perfectly fine. It<br>
should not even be a warning.<br>
<br>
<br>
Digging a little in the source and looking for the 'transaction has been<br>
rolled back', I found the NativeSQLSource.doexec function, which is<br>
basically:<br>
<br>
    def doexec(self, cnx, query, args=None, rollback=True):<br>
        cursor = cnx.blablabla<br>
        try:<br>
            cursor.execute()<br>
        except Exception as ex:<br>
            self.critical('sql: xxx' % ex.xxx)<br>
            if rollback:<br>
                cnx.rollback()<br>
                self.critical('transaction has been rolled back')<br>
            # some clever code to translate the exception in a CW one<br>
            # if possible<br>
<br>
Several things are bothering me:<br>
<br>
- The 'rollback' feature, if anyhow useful (I do not think it is),<br>
  should not have such a default: doexec is, in my understanding, a low<br>
  level function. And rolling back a transaction is a high-level<br>
  decision. But since the doexec function is called by many intermediate<br>
  functions without passing any 'rollback' parameter, we end up with a<br>
  high-level decision made in a low-level function.<br></blockquote><div><br></div><div>At this point in the flow, the low-level transaction has been rolled back,</div><div>and we cannot defer for too long emitting a rollback event at the cw "cnx" level.</div><div> </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<br>
- If an error occur at the sql level, it will be transmitted or<br>
  translated to a CW error, which is fine. But if the exception is<br>
  raised and handled in a higher level function, why do we make it a<br>
  critical error?<br>
<br>
- Admitting that rolling-back automatically on errors is wanted in some<br>
  cases, how can it be considered 'critical'? The caller will receive<br>
  the original exception anyway, it is its job to decide if it is<br>
  critical or not.<br></blockquote><div><br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<br>
So basically, I would like to propose 2 things:<br>
<br>
- Remove the 'critical' logs, and change them into into 'debug', or<br>
  'info'.<br></blockquote><div><br></div><div>+1</div><div> </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<br>
- Remove the 'rollback' option, or at least change its default value.<br>
  I really thing this feature has nothing to do in this place.<br></blockquote><div><br></div><div>Should this be moved up to the Connection object ?</div><div> </div><div><a href="https://lists.cubicweb.org/mailman/listinfo/cubicweb" target="_blank"></a>Regards,</div><div>Aurélien.<br>
<br></div></div><br></div></div>