<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.1//EN"
"http://www.w3.org/TR/xhtml11/DTD/xhtml11.dtd">
<html xmlns="http://www.w3.org/1999/xhtml">
<head><meta http-equiv="content-type" content="text/html; charset=utf-8" />
<title>[13687] twext/trunk/twext/enterprise</title>
</head>
<body>
<style type="text/css"><!--
#msg dl.meta { border: 1px #006 solid; background: #369; padding: 6px; color: #fff; }
#msg dl.meta dt { float: left; width: 6em; font-weight: bold; }
#msg dt:after { content:':';}
#msg dl, #msg dt, #msg ul, #msg li, #header, #footer, #logmsg { font-family: verdana,arial,helvetica,sans-serif; font-size: 10pt; }
#msg dl a { font-weight: bold}
#msg dl a:link { color:#fc3; }
#msg dl a:active { color:#ff0; }
#msg dl a:visited { color:#cc6; }
h3 { font-family: verdana,arial,helvetica,sans-serif; font-size: 10pt; font-weight: bold; }
#msg pre { overflow: auto; background: #ffc; border: 1px #fa0 solid; padding: 6px; }
#logmsg { background: #ffc; border: 1px #fa0 solid; padding: 1em 1em 0 1em; }
#logmsg p, #logmsg pre, #logmsg blockquote { margin: 0 0 1em 0; }
#logmsg p, #logmsg li, #logmsg dt, #logmsg dd { line-height: 14pt; }
#logmsg h1, #logmsg h2, #logmsg h3, #logmsg h4, #logmsg h5, #logmsg h6 { margin: .5em 0; }
#logmsg h1:first-child, #logmsg h2:first-child, #logmsg h3:first-child, #logmsg h4:first-child, #logmsg h5:first-child, #logmsg h6:first-child { margin-top: 0; }
#logmsg ul, #logmsg ol { padding: 0; list-style-position: inside; margin: 0 0 0 1em; }
#logmsg ul { text-indent: -1em; padding-left: 1em; }#logmsg ol { text-indent: -1.5em; padding-left: 1.5em; }
#logmsg > ul, #logmsg > ol { margin: 0 0 1em 0; }
#logmsg pre { background: #eee; padding: 1em; }
#logmsg blockquote { border: 1px solid #fa0; border-left-width: 10px; padding: 1em 1em 0 1em; background: white;}
#logmsg dl { margin: 0; }
#logmsg dt { font-weight: bold; }
#logmsg dd { margin: 0; padding: 0 0 0.5em 0; }
#logmsg dd:before { content:'\00bb';}
#logmsg table { border-spacing: 0px; border-collapse: collapse; border-top: 4px solid #fa0; border-bottom: 1px solid #fa0; background: #fff; }
#logmsg table th { text-align: left; font-weight: normal; padding: 0.2em 0.5em; border-top: 1px dotted #fa0; }
#logmsg table td { text-align: right; border-top: 1px dotted #fa0; padding: 0.2em 0.5em; }
#logmsg table thead th { text-align: center; border-bottom: 1px solid #fa0; }
#logmsg table th.Corner { text-align: left; }
#logmsg hr { border: none 0; border-top: 2px dashed #fa0; height: 1px; }
#header, #footer { color: #fff; background: #636; border: 1px #300 solid; padding: 6px; }
#patch { width: 100%; }
#patch h4 {font-family: verdana,arial,helvetica,sans-serif;font-size:10pt;padding:8px;background:#369;color:#fff;margin:0;}
#patch .propset h4, #patch .binary h4 {margin:0;}
#patch pre {padding:0;line-height:1.2em;margin:0;}
#patch .diff {width:100%;background:#eee;padding: 0 0 10px 0;overflow:auto;}
#patch .propset .diff, #patch .binary .diff {padding:10px 0;}
#patch span {display:block;padding:0 10px;}
#patch .modfile, #patch .addfile, #patch .delfile, #patch .propset, #patch .binary, #patch .copfile {border:1px solid #ccc;margin:10px 0;}
#patch ins {background:#dfd;text-decoration:none;display:block;padding:0 10px;}
#patch del {background:#fdd;text-decoration:none;display:block;padding:0 10px;}
#patch .lines, .info {color:#888;background:#fff;}
--></style>
<div id="msg">
<dl class="meta">
<dt>Revision</dt> <dd><a href="http://trac.calendarserver.org//changeset/13687">13687</a></dd>
<dt>Author</dt> <dd>cdaboo@apple.com</dd>
<dt>Date</dt> <dd>2014-06-25 11:38:55 -0700 (Wed, 25 Jun 2014)</dd>
</dl>
<h3>Log Message</h3>
<pre>Add staggering and separate reschedule time for locked jobs. Fix logging error.</pre>
<h3>Modified Paths</h3>
<ul>
<li><a href="#twexttrunktwextenterprisejobqueuepy">twext/trunk/twext/enterprise/jobqueue.py</a></li>
<li><a href="#twexttrunktwextenterprisetesttest_jobqueuepy">twext/trunk/twext/enterprise/test/test_jobqueue.py</a></li>
</ul>
</div>
<div id="patch">
<h3>Diff</h3>
<a id="twexttrunktwextenterprisejobqueuepy"></a>
<div class="modfile"><h4>Modified: twext/trunk/twext/enterprise/jobqueue.py (13686 => 13687)</h4>
<pre class="diff"><span>
<span class="info">--- twext/trunk/twext/enterprise/jobqueue.py 2014-06-25 18:31:40 UTC (rev 13686)
+++ twext/trunk/twext/enterprise/jobqueue.py 2014-06-25 18:38:55 UTC (rev 13687)
</span><span class="lines">@@ -354,8 +354,8 @@
</span><span class="cx"> _workTypes = None
</span><span class="cx"> _workTypeMap = None
</span><span class="cx">
</span><ins>+ lockRescheduleInterval = 60 # When a job can't run because of a lock, reschedule it this number of seconds in the future
</ins><span class="cx"> failureRescheduleInterval = 60 # When a job fails, reschedule it this number of seconds in the future
</span><del>- lockRescheduleInterval = 5 # When a job is locked, reschedule it this number of seconds in the future
</del><span class="cx">
</span><span class="cx"> def descriptor(self):
</span><span class="cx"> return JobDescriptor(self.jobID, self.weight, self.workType)
</span><span class="lines">@@ -385,21 +385,29 @@
</span><span class="cx"> return self.update(overdue=self.overdue + timedelta(seconds=bump))
</span><span class="cx">
</span><span class="cx">
</span><del>- def failedToRun(self, delay=None):
</del><ins>+ def failedToRun(self, locked=False, delay=None):
</ins><span class="cx"> """
</span><span class="cx"> The attempt to run the job failed. Leave it in the queue, but mark it
</span><span class="cx"> as unassigned, bump the failure count and set to run at some point in
</span><span class="cx"> the future.
</span><span class="cx">
</span><del>- @param delay: the number of seconds in the future at which to reschedule the
- next execution of the job. If L{None} use the default class property value.
</del><ins>+ @param lock: indicates if the failure was due to a lock timeout.
+ @type lock: L{bool}
+ @param delay: how long before the job is run again, or C{None} for a default
+ staggered delay behavior.
</ins><span class="cx"> @type delay: L{int}
</span><span class="cx"> """
</span><ins>+
+ # notBefore is set to the chosen interval multiplied by the failure count, which
+ # results in an incremental backoff for failures
+ if delay is None:
+ delay = self.lockRescheduleInterval if locked else self.failureRescheduleInterval
+ delay *= (self.failed + 1)
</ins><span class="cx"> return self.update(
</span><span class="cx"> assigned=None,
</span><span class="cx"> overdue=None,
</span><del>- failed=self.failed + 1,
- notBefore=datetime.utcnow() + timedelta(seconds=self.failureRescheduleInterval if delay is None else delay)
</del><ins>+ failed=self.failed + (0 if locked else 1),
+ notBefore=datetime.utcnow() + timedelta(seconds=delay)
</ins><span class="cx"> )
</span><span class="cx">
</span><span class="cx">
</span><span class="lines">@@ -452,18 +460,25 @@
</span><span class="cx">
</span><span class="cx"> except (JobFailedError, JobRunningError) as e:
</span><span class="cx"> # Job failed: abort with cleanup, but pretend this method succeeded
</span><del>- delay = job.lockRescheduleInterval if isinstance(e, JobRunningError) else job.failureRescheduleInterval
</del><span class="cx"> def _cleanUp():
</span><span class="cx"> @inlineCallbacks
</span><span class="cx"> def _cleanUp2(txn2):
</span><del>- job = yield cls.load(txn2, jobID)
- log.debug(
- "JobItem: {jobid} marking as failed {count} t={tm}",
- jobid=jobID,
- count=job.failed + 1,
- tm=_tm(),
- )
- yield job.failedToRun(delay=delay)
</del><ins>+ try:
+ job = yield cls.load(txn2, jobID)
+ except NoSuchRecord:
+ log.debug(
+ "JobItem: {jobid} disappeared t={tm}",
+ jobid=jobID,
+ tm=_tm(),
+ )
+ else:
+ log.debug(
+ "JobItem: {jobid} marking as failed {count} t={tm}",
+ jobid=jobID,
+ count=job.failed + 1,
+ tm=_tm(),
+ )
+ yield job.failedToRun(locked=isinstance(e, JobRunningError))
</ins><span class="cx"> return inTransaction(txnFactory, _cleanUp2, "ultimatelyPerform._cleanUp")
</span><span class="cx"> log.debug(
</span><span class="cx"> "JobItem: {jobid} {desc} {work} t={tm}",
</span><span class="lines">@@ -662,7 +677,7 @@
</span><span class="cx">
</span><span class="cx"> cls._workTypeMap = {}
</span><span class="cx"> for subcls in cls._workTypes:
</span><del>- cls._workTypeMap[subcls.table.model.name] = subcls
</del><ins>+ cls._workTypeMap[subcls.workType()] = subcls
</ins><span class="cx">
</span><span class="cx"> return cls._workTypes
</span><span class="cx">
</span><span class="lines">@@ -702,7 +717,7 @@
</span><span class="cx"> results = {}
</span><span class="cx"> now = datetime.utcnow()
</span><span class="cx"> for workItemType in cls.workTypes():
</span><del>- workType = workItemType.table.model.name
</del><ins>+ workType = workItemType.workType()
</ins><span class="cx"> results.setdefault(workType, {
</span><span class="cx"> "queued": 0,
</span><span class="cx"> "assigned": 0,
</span><span class="lines">@@ -860,6 +875,11 @@
</span><span class="cx"> _tableNameMap = {}
</span><span class="cx">
</span><span class="cx"> @classmethod
</span><ins>+ def workType(cls):
+ return cls.table.model.name
+
+
+ @classmethod
</ins><span class="cx"> @inlineCallbacks
</span><span class="cx"> def makeJob(cls, transaction, **kwargs):
</span><span class="cx"> """
</span><span class="lines">@@ -871,7 +891,7 @@
</span><span class="cx"> """
</span><span class="cx">
</span><span class="cx"> jobargs = {
</span><del>- "workType": cls.table.model.name
</del><ins>+ "workType": cls.workType()
</ins><span class="cx"> }
</span><span class="cx">
</span><span class="cx"> def _transferArg(name):
</span><span class="lines">@@ -1965,7 +1985,7 @@
</span><span class="cx"> return
</span><span class="cx">
</span><span class="cx"> @passthru(
</span><del>- self._workCheck().addErrback(log.error).addCallback
</del><ins>+ self._workCheck().addErrback(lambda result: log.error("_workCheckLoop: {exc}", exc=result)).addCallback
</ins><span class="cx"> )
</span><span class="cx"> def scheduleNext(result):
</span><span class="cx"> # TODO: if multiple nodes are present, see if we can
</span></span></pre></div>
<a id="twexttrunktwextenterprisetesttest_jobqueuepy"></a>
<div class="modfile"><h4>Modified: twext/trunk/twext/enterprise/test/test_jobqueue.py (13686 => 13687)</h4>
<pre class="diff"><span>
<span class="info">--- twext/trunk/twext/enterprise/test/test_jobqueue.py 2014-06-25 18:31:40 UTC (rev 13686)
+++ twext/trunk/twext/enterprise/test/test_jobqueue.py 2014-06-25 18:38:55 UTC (rev 13687)
</span><span class="lines">@@ -1364,13 +1364,12 @@
</span><span class="cx"> L{JobItem.run} fails an aggregated work item and then ignores it.
</span><span class="cx"> """
</span><span class="cx">
</span><del>- # Patch JobItem.assign and JobItem.bumpOverdue to track how many times
- # they are called.
</del><ins>+ # Patch JobItem.failedToRun to track how many times it is called.
</ins><span class="cx"> failed = [0]
</span><span class="cx"> _oldFailed = JobItem.failedToRun
</span><del>- def _newFailed(self, delay):
</del><ins>+ def _newFailed(self, locked=False, delay=None):
</ins><span class="cx"> failed[0] += 1
</span><del>- return _oldFailed(self, delay)
</del><ins>+ return _oldFailed(self, locked, 5)
</ins><span class="cx"> self.patch(JobItem, "failedToRun", _newFailed)
</span><span class="cx">
</span><span class="cx"> @transactionally(self.store.newTransaction)
</span><span class="lines">@@ -1378,13 +1377,14 @@
</span><span class="cx"> return txn.enqueue(
</span><span class="cx"> AggregatorWorkItem, a=1, b=1, workID=1
</span><span class="cx"> )
</span><del>- yield _enqueue1
</del><span class="cx">
</span><span class="cx"> @transactionally(self.store.newTransaction)
</span><span class="cx"> def _enqueue2(txn):
</span><span class="cx"> return txn.enqueue(
</span><span class="cx"> AggregatorWorkItem, a=1, b=2, workID=2
</span><span class="cx"> )
</span><ins>+
+ yield _enqueue1
</ins><span class="cx"> yield _enqueue2
</span><span class="cx">
</span><span class="cx"> # Make sure we have one JOB and one DUMMY_WORK_ITEM
</span><span class="lines">@@ -1411,9 +1411,9 @@
</span><span class="cx"> # they are called.
</span><span class="cx"> failed = [0]
</span><span class="cx"> _oldFailed = JobItem.failedToRun
</span><del>- def _newFailed(self, delay):
</del><ins>+ def _newFailed(self, locked=False, delay=None):
</ins><span class="cx"> failed[0] += 1
</span><del>- return _oldFailed(self, delay)
</del><ins>+ return _oldFailed(self, locked, 5)
</ins><span class="cx"> self.patch(JobItem, "failedToRun", _newFailed)
</span><span class="cx">
</span><span class="cx"> @transactionally(self.store.newTransaction)
</span><span class="lines">@@ -1421,13 +1421,14 @@
</span><span class="cx"> return txn.enqueue(
</span><span class="cx"> AggregatorWorkItem, a=1, b=1, workID=1
</span><span class="cx"> )
</span><del>- yield _enqueue1
</del><span class="cx">
</span><span class="cx"> @transactionally(self.store.newTransaction)
</span><span class="cx"> def _enqueue2(txn):
</span><span class="cx"> return txn.enqueue(
</span><span class="cx"> AggregatorWorkItem, a=1, b=1, workID=2
</span><span class="cx"> )
</span><ins>+
+ yield _enqueue1
</ins><span class="cx"> yield _enqueue2
</span><span class="cx">
</span><span class="cx"> # Make sure we have one JOB and one DUMMY_WORK_ITEM
</span></span></pre>
</div>
</div>
</body>
</html>