<!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>[15102] CalendarServer/branches/release/CalendarServer-5.4-dev</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/15102">15102</a></dd>
<dt>Author</dt> <dd>cdaboo@apple.com</dd>
<dt>Date</dt> <dd>2015-09-03 14:05:31 -0700 (Thu, 03 Sep 2015)</dd>
</dl>
<h3>Log Message</h3>
<pre>Add warning log messages when a txn stalls due to DB pool being fully utilized. Add warning for lost work check.</pre>
<h3>Modified Paths</h3>
<ul>
<li><a href="#CalendarServerbranchesreleaseCalendarServer54devcalendarserverpushapplepushpy">CalendarServer/branches/release/CalendarServer-5.4-dev/calendarserver/push/applepush.py</a></li>
<li><a href="#CalendarServerbranchesreleaseCalendarServer54devtwextenterpriseadbapi2py">CalendarServer/branches/release/CalendarServer-5.4-dev/twext/enterprise/adbapi2.py</a></li>
<li><a href="#CalendarServerbranchesreleaseCalendarServer54devtwextenterprisequeuepy">CalendarServer/branches/release/CalendarServer-5.4-dev/twext/enterprise/queue.py</a></li>
<li><a href="#CalendarServerbranchesreleaseCalendarServer54devtwextenterprisetesttest_queuepy">CalendarServer/branches/release/CalendarServer-5.4-dev/twext/enterprise/test/test_queue.py</a></li>
<li><a href="#CalendarServerbranchesreleaseCalendarServer54devtwistedcaldavdirectorydirectorypy">CalendarServer/branches/release/CalendarServer-5.4-dev/twistedcaldav/directory/directory.py</a></li>
<li><a href="#CalendarServerbranchesreleaseCalendarServer54devtxdavcaldavdatastoreschedulingimipinboundpy">CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/caldav/datastore/scheduling/imip/inbound.py</a></li>
<li><a href="#CalendarServerbranchesreleaseCalendarServer54devtxdavcaldavdatastoreschedulingimipmailgatewaypy">CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/caldav/datastore/scheduling/imip/mailgateway.py</a></li>
<li><a href="#CalendarServerbranchesreleaseCalendarServer54devtxdavcommondatastoresqlpy">CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/sql.py</a></li>
<li><a href="#CalendarServerbranchesreleaseCalendarServer54devtxdavcommondatastoresql_legacypy">CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/sql_legacy.py</a></li>
<li><a href="#CalendarServerbranchesreleaseCalendarServer54devtxdavcommondatastoreupgrademigratepy">CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/upgrade/migrate.py</a></li>
<li><a href="#CalendarServerbranchesreleaseCalendarServer54devtxdavcommondatastoreupgradesqlupgradepy">CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/upgrade/sql/upgrade.py</a></li>
</ul>
</div>
<div id="patch">
<h3>Diff</h3>
<a id="CalendarServerbranchesreleaseCalendarServer54devcalendarserverpushapplepushpy"></a>
<div class="modfile"><h4>Modified: CalendarServer/branches/release/CalendarServer-5.4-dev/calendarserver/push/applepush.py (15101 => 15102)</h4>
<pre class="diff"><span>
<span class="info">--- CalendarServer/branches/release/CalendarServer-5.4-dev/calendarserver/push/applepush.py 2015-09-03 21:00:43 UTC (rev 15101)
+++ CalendarServer/branches/release/CalendarServer-5.4-dev/calendarserver/push/applepush.py 2015-09-03 21:05:31 UTC (rev 15102)
</span><span class="lines">@@ -182,7 +182,7 @@
</span><span class="cx"> @type purgeSeconds: C{int}
</span><span class="cx"> """
</span><span class="cx"> self.log.debug("ApplePushNotifierService purgeOldSubscriptions")
</span><del>- txn = self.store.newTransaction()
</del><ins>+ txn = self.store.newTransaction(label="ApplePushNotifierService.purgeOldSubscriptions")
</ins><span class="cx"> yield txn.purgeOldAPNSubscriptions(int(time.time()) - purgeSeconds)
</span><span class="cx"> yield txn.commit()
</span><span class="cx">
</span><span class="lines">@@ -720,7 +720,7 @@
</span><span class="cx">
</span><span class="cx"> self.log.debug("FeedbackProtocol processFeedback time=%d token=%s" %
</span><span class="cx"> (timestamp, token))
</span><del>- txn = self.factory.store.newTransaction()
</del><ins>+ txn = self.factory.store.newTransaction(label="APNFeedbackProtocol.processFeedback")
</ins><span class="cx"> subscriptions = (yield txn.apnSubscriptionsByToken(token))
</span><span class="cx">
</span><span class="cx"> for key, modified, _ignore_uid in subscriptions:
</span><span class="lines">@@ -943,7 +943,7 @@
</span><span class="cx"> @type key: C{str}
</span><span class="cx"> """
</span><span class="cx"> now = int(time.time()) # epoch seconds
</span><del>- txn = self.store.newTransaction()
</del><ins>+ txn = self.store.newTransaction(label="APNSubscriptionResource.addSubscription")
</ins><span class="cx"> yield txn.addAPNSubscription(token, key, now, uid, userAgent, host)
</span><span class="cx"> yield txn.commit()
</span><span class="cx">
</span></span></pre></div>
<a id="CalendarServerbranchesreleaseCalendarServer54devtwextenterpriseadbapi2py"></a>
<div class="modfile"><h4>Modified: CalendarServer/branches/release/CalendarServer-5.4-dev/twext/enterprise/adbapi2.py (15101 => 15102)</h4>
<pre class="diff"><span>
<span class="info">--- CalendarServer/branches/release/CalendarServer-5.4-dev/twext/enterprise/adbapi2.py 2015-09-03 21:00:43 UTC (rev 15101)
+++ CalendarServer/branches/release/CalendarServer-5.4-dev/twext/enterprise/adbapi2.py 2015-09-03 21:05:31 UTC (rev 15102)
</span><span class="lines">@@ -31,6 +31,7 @@
</span><span class="cx">
</span><span class="cx"> import sys
</span><span class="cx"> import weakref
</span><ins>+import time
</ins><span class="cx">
</span><span class="cx"> from cStringIO import StringIO
</span><span class="cx"> from cPickle import dumps, loads
</span><span class="lines">@@ -47,7 +48,6 @@
</span><span class="cx"> from twisted.protocols.amp import Argument, String, Command, AMP, Integer
</span><span class="cx"> from twisted.internet import reactor as _reactor
</span><span class="cx"> from twisted.application.service import Service
</span><del>-from twisted.python import log
</del><span class="cx"> from twisted.internet.defer import maybeDeferred
</span><span class="cx"> from twisted.python.components import proxyForInterface
</span><span class="cx">
</span><span class="lines">@@ -63,6 +63,8 @@
</span><span class="cx"> AlreadyFinishedError, IAsyncTransaction, POSTGRES_DIALECT, ICommandBlock
</span><span class="cx"> )
</span><span class="cx">
</span><ins>+from twext.python.log import Logger
+log = Logger()
</ins><span class="cx">
</span><span class="cx"> # FIXME: there should be no defaults for connection metadata, it should be
</span><span class="cx"> # discovered dynamically everywhere. Right now it's specified as an explicit
</span><span class="lines">@@ -246,11 +248,11 @@
</span><span class="cx"> # Report the error before doing anything else, since doing
</span><span class="cx"> # other things may cause the traceback stack to be eliminated
</span><span class="cx"> # if they raise exceptions (even internally).
</span><del>- log.err(
- Failure(),
</del><ins>+ log.failure(
</ins><span class="cx"> "Exception from execute() on first statement in "
</span><span class="cx"> "transaction. Possibly caused by a database server "
</span><del>- "restart. Automatically reconnecting now."
</del><ins>+ "restart. Automatically reconnecting now.",
+ failure=Failure(),
</ins><span class="cx"> )
</span><span class="cx"> try:
</span><span class="cx"> self._connection.close()
</span><span class="lines">@@ -267,10 +269,10 @@
</span><span class="cx"> # making debugging surprising error conditions very
</span><span class="cx"> # difficult, so let's make sure that the error is logged
</span><span class="cx"> # just in case.
</span><del>- log.err(
- Failure(),
</del><ins>+ log.failure(
</ins><span class="cx"> "Exception from close() while automatically "
</span><del>- "reconnecting. (Probably not serious.)"
</del><ins>+ "reconnecting. (Probably not serious.)",
+ failure=Failure(),
</ins><span class="cx"> )
</span><span class="cx">
</span><span class="cx"> # Now, if either of *these* things fail, there's an error here
</span><span class="lines">@@ -354,7 +356,9 @@
</span><span class="cx">
</span><span class="cx">
</span><span class="cx"> def abort(self):
</span><del>- return self._end(self._connection.rollback).addErrback(log.err)
</del><ins>+ def _report(f):
+ log.failure("txn abort", failure=f)
+ return self._end(self._connection.rollback).addErrback(_report)
</ins><span class="cx">
</span><span class="cx">
</span><span class="cx"> def reset(self):
</span><span class="lines">@@ -1043,12 +1047,32 @@
</span><span class="cx"> basetxn = self._free.pop(0)
</span><span class="cx"> self._busy.append(basetxn)
</span><span class="cx"> txn = _SingleTxn(self, basetxn)
</span><ins>+ log.debug(
+ "ConnectionPool: txn busy '{label}': free={free}, busy={busy}, waiting={waiting}",
+ label=label,
+ free=len(self._free),
+ busy=len(self._busy) + len(self._finishing),
+ waiting=len(self._waiting),
+ )
</ins><span class="cx"> else:
</span><span class="cx"> txn = _SingleTxn(self, _WaitingTxn(self))
</span><span class="cx"> self._waiting.append(txn)
</span><ins>+ blocked = self._activeConnectionCount() >= self.maxConnections
+ if blocked:
+ txn._blocked_waiting_time = time.time()
+ txn._blocked_label = label
+ log.warn("ConnectionPool: txn blocked '{label}'", label=label)
+ log.debug(
+ "ConnectionPool: txn waiting add '{label}': free={free}, busy={busy}, waiting={waiting} {blocked}",
+ label=label,
+ free=len(self._free),
+ busy=len(self._busy) + len(self._finishing),
+ waiting=len(self._waiting),
+ blocked="blocked" if blocked else "",
+ )
</ins><span class="cx"> # FIXME/TESTME: should be len(self._busy) + len(self._finishing)
</span><span class="cx"> # (free doesn't need to be considered, as it's tested above)
</span><del>- if self._activeConnectionCount() < self.maxConnections:
</del><ins>+ if not blocked:
</ins><span class="cx"> self._startOneMore()
</span><span class="cx"> return txn
</span><span class="cx">
</span><span class="lines">@@ -1087,7 +1111,7 @@
</span><span class="cx"> self._busy.remove(txn)
</span><span class="cx"> self._repoolNow(baseTxn)
</span><span class="cx"> def maybeTryAgain(f):
</span><del>- log.err(f, "Re-trying connection due to connection failure")
</del><ins>+ log.failure("Re-trying connection due to connection failure", failure=f)
</ins><span class="cx"> txn._retry = self.reactor.callLater(self.RETRY_TIMEOUT, resubmit)
</span><span class="cx"> def resubmit():
</span><span class="cx"> d = holder.submit(initCursor)
</span><span class="lines">@@ -1124,8 +1148,26 @@
</span><span class="cx"> waiting = self._waiting.pop(0)
</span><span class="cx"> self._busy.append(txn)
</span><span class="cx"> waiting._unspoolOnto(txn)
</span><ins>+ if hasattr(waiting, "_blocked_waiting_time"):
+ log.warn(
+ "ConnectionPool: txn unblocked '{label}': delay {delay:.1f}ms",
+ label=waiting._blocked_label,
+ delay=1000 * (time.time() - waiting._blocked_waiting_time),
+ )
+ log.debug(
+ "ConnectionPool: txn waiting remove: free={free}, busy={busy}, waiting={waiting}",
+ free=len(self._free),
+ busy=len(self._busy) + len(self._finishing),
+ waiting=len(self._waiting),
+ )
</ins><span class="cx"> else:
</span><span class="cx"> self._free.append(txn)
</span><ins>+ log.debug(
+ "ConnectionPool: txn free: free={free}, busy={busy}, waiting={waiting}",
+ free=len(self._free),
+ busy=len(self._busy) + len(self._finishing),
+ waiting=len(self._waiting),
+ )
</ins><span class="cx">
</span><span class="cx">
</span><span class="cx">
</span><span class="lines">@@ -1213,7 +1255,7 @@
</span><span class="cx"> if f.type in command.errors:
</span><span class="cx"> returnValue(f)
</span><span class="cx"> else:
</span><del>- log.err(Failure(), "shared database connection pool error")
</del><ins>+ log.failure("shared database connection pool error", failure=f)
</ins><span class="cx"> raise FailsafeException()
</span><span class="cx"> else:
</span><span class="cx"> returnValue(val)
</span><span class="lines">@@ -1324,7 +1366,7 @@
</span><span class="cx">
</span><span class="cx">
</span><span class="cx"> def stopReceivingBoxes(self, why):
</span><del>- log.msg("(S) Stopped receiving boxes: " + why.getTraceback())
</del><ins>+ log.info("(S) Stopped receiving boxes: {tb}", tb=why.getTraceback())
</ins><span class="cx">
</span><span class="cx">
</span><span class="cx"> def unhandledError(self, failure):
</span><span class="lines">@@ -1332,7 +1374,7 @@
</span><span class="cx"> An unhandled error has occurred. Since we can't really classify errors
</span><span class="cx"> well on this protocol, log it and forget it.
</span><span class="cx"> """
</span><del>- log.err(failure, "Shared connection pool server encountered an error.")
</del><ins>+ log.failure("Shared connection pool server encountered an error.", failure=failure)
</ins><span class="cx">
</span><span class="cx">
</span><span class="cx"> @failsafeResponder(StartTxn)
</span><span class="lines">@@ -1438,11 +1480,11 @@
</span><span class="cx"> An unhandled error has occurred. Since we can't really classify errors
</span><span class="cx"> well on this protocol, log it and forget it.
</span><span class="cx"> """
</span><del>- log.err(failure, "Shared connection pool client encountered an error.")
</del><ins>+ log.failure("Shared connection pool client encountered an error.", failure=failure)
</ins><span class="cx">
</span><span class="cx">
</span><span class="cx"> def stopReceivingBoxes(self, why):
</span><del>- log.msg("(C) Stopped receiving boxes: " + why.getTraceback())
</del><ins>+ log.info("(C) Stopped receiving boxes: {tb}", tb=why.getTraceback())
</ins><span class="cx">
</span><span class="cx">
</span><span class="cx"> def newTransaction(self):
</span></span></pre></div>
<a id="CalendarServerbranchesreleaseCalendarServer54devtwextenterprisequeuepy"></a>
<div class="modfile"><h4>Modified: CalendarServer/branches/release/CalendarServer-5.4-dev/twext/enterprise/queue.py (15101 => 15102)</h4>
<pre class="diff"><span>
<span class="info">--- CalendarServer/branches/release/CalendarServer-5.4-dev/twext/enterprise/queue.py 2015-09-03 21:00:43 UTC (rev 15101)
+++ CalendarServer/branches/release/CalendarServer-5.4-dev/twext/enterprise/queue.py 2015-09-03 21:05:31 UTC (rev 15102)
</span><span class="lines">@@ -92,7 +92,6 @@
</span><span class="cx"> from twisted.internet.endpoints import TCP4ClientEndpoint
</span><span class="cx"> from twisted.protocols.amp import AMP, Command, Integer, Argument, String
</span><span class="cx"> from twisted.python.reflect import qual
</span><del>-from twisted.python import log
</del><span class="cx">
</span><span class="cx"> from twext.enterprise.dal.syntax import SchemaSyntax, Lock, NamedValue
</span><span class="cx">
</span><span class="lines">@@ -106,7 +105,10 @@
</span><span class="cx"> from zope.interface.interface import Interface
</span><span class="cx"> from twext.enterprise.locking import NamedLock
</span><span class="cx">
</span><ins>+from twext.python.log import Logger
+log = Logger()
</ins><span class="cx">
</span><ins>+
</ins><span class="cx"> class _IWorkPerformer(Interface):
</span><span class="cx"> """
</span><span class="cx"> An object that can perform work.
</span><span class="lines">@@ -165,7 +167,7 @@
</span><span class="cx">
</span><span class="cx">
</span><span class="cx"> @inlineCallbacks
</span><del>-def inTransaction(transactionCreator, operation):
</del><ins>+def inTransaction(transactionCreator, operation, label="<unlabeled>"):
</ins><span class="cx"> """
</span><span class="cx"> Perform the given operation in a transaction, committing or aborting as
</span><span class="cx"> required.
</span><span class="lines">@@ -180,7 +182,7 @@
</span><span class="cx"> its error, unless there is an error creating, aborting or committing
</span><span class="cx"> the transaction.
</span><span class="cx"> """
</span><del>- txn = transactionCreator()
</del><ins>+ txn = transactionCreator(label=label)
</ins><span class="cx"> try:
</span><span class="cx"> result = yield operation(txn)
</span><span class="cx"> except:
</span><span class="lines">@@ -839,7 +841,7 @@
</span><span class="cx"> except NoSuchRecord:
</span><span class="cx"> # The record has already been removed
</span><span class="cx"> pass
</span><del>- return inTransaction(txnFactory, work)
</del><ins>+ return inTransaction(txnFactory, work, label="ultimatelyPerform: {} {}".format(table.model.name, workID))
</ins><span class="cx">
</span><span class="cx">
</span><span class="cx">
</span><span class="lines">@@ -1278,11 +1280,17 @@
</span><span class="cx"> overdueItems = (yield itemType.query(
</span><span class="cx"> txn, (itemType.notBefore < tooLate))
</span><span class="cx"> )
</span><ins>+ if overdueItems:
+ log.warn(
+ "periodicLostWorkCheck: executing {count} items of {workType}",
+ count=len(overdueItems),
+ workType=itemType.table.model.name,
+ )
</ins><span class="cx"> for overdueItem in overdueItems:
</span><span class="cx"> peer = self.choosePerformer()
</span><span class="cx"> yield peer.performWork(overdueItem.table,
</span><span class="cx"> overdueItem.workID)
</span><del>- return inTransaction(self.transactionFactory, workCheck)
</del><ins>+ return inTransaction(self.transactionFactory, workCheck, label="_periodicLostWorkCheck")
</ins><span class="cx">
</span><span class="cx"> _currentWorkDeferred = None
</span><span class="cx"> _lostWorkCheckCall = None
</span><span class="lines">@@ -1294,7 +1302,9 @@
</span><span class="cx"> those checks in time based on the size of the cluster.
</span><span class="cx"> """
</span><span class="cx"> self._lostWorkCheckCall = None
</span><del>- @passthru(self._periodicLostWorkCheck().addErrback(log.err)
</del><ins>+ def _result(f):
+ log.failure("periodicLostWorkCheck failed", failure=f)
+ @passthru(self._periodicLostWorkCheck().addErrback(_result)
</ins><span class="cx"> .addCallback)
</span><span class="cx"> def scheduleNext(result):
</span><span class="cx"> self._currentWorkDeferred = None
</span><span class="lines">@@ -1343,7 +1353,7 @@
</span><span class="cx"> for node in nodes:
</span><span class="cx"> self._startConnectingTo(node)
</span><span class="cx">
</span><del>- self._startingUp = inTransaction(self.transactionFactory, startup)
</del><ins>+ self._startingUp = inTransaction(self.transactionFactory, startup, label="PeerConnectionPool.startService")
</ins><span class="cx"> @self._startingUp.addBoth
</span><span class="cx"> def done(result):
</span><span class="cx"> self._startingUp = None
</span><span class="lines">@@ -1405,8 +1415,10 @@
</span><span class="cx"> noted, "identify"
</span><span class="cx"> )
</span><span class="cx"> def noted(err, x="connect"):
</span><del>- log.msg("Could not {0} to cluster peer {1} because {2}"
- .format(x, node, str(err.value)))
</del><ins>+ log.info(
+ "Could not {action} to cluster peer {node} because {err}",
+ action=x, node=node, err=str(err.value),
+ )
</ins><span class="cx"> connected.addCallbacks(whenConnected, noted)
</span><span class="cx">
</span><span class="cx">
</span></span></pre></div>
<a id="CalendarServerbranchesreleaseCalendarServer54devtwextenterprisetesttest_queuepy"></a>
<div class="modfile"><h4>Modified: CalendarServer/branches/release/CalendarServer-5.4-dev/twext/enterprise/test/test_queue.py (15101 => 15102)</h4>
<pre class="diff"><span>
<span class="info">--- CalendarServer/branches/release/CalendarServer-5.4-dev/twext/enterprise/test/test_queue.py 2015-09-03 21:00:43 UTC (rev 15101)
+++ CalendarServer/branches/release/CalendarServer-5.4-dev/twext/enterprise/test/test_queue.py 2015-09-03 21:05:31 UTC (rev 15102)
</span><span class="lines">@@ -130,7 +130,7 @@
</span><span class="cx"> return self.aborts[-1]
</span><span class="cx">
</span><span class="cx"> createdTxns = []
</span><del>- def createTxn():
</del><ins>+ def createTxn(**kwargs):
</ins><span class="cx"> createdTxns.append(faketxn())
</span><span class="cx"> return createdTxns[-1]
</span><span class="cx"> dfrs = []
</span><span class="lines">@@ -728,20 +728,21 @@
</span><span class="cx"> self.store = yield buildStore(self, None)
</span><span class="cx"> def doit(txn):
</span><span class="cx"> return txn.execSQL(schemaText)
</span><del>- yield inTransaction(lambda: self.store.newTransaction("bonus schema"),
- doit)
- def indirectedTransactionFactory(*a):
</del><ins>+ yield inTransaction(self.store.newTransaction,
+ doit,
+ label="bonus schema")
+ def indirectedTransactionFactory(*a, **k):
</ins><span class="cx"> """
</span><span class="cx"> Allow tests to replace 'self.store.newTransaction' to provide
</span><span class="cx"> fixtures with extra methods on a test-by-test basis.
</span><span class="cx"> """
</span><del>- return self.store.newTransaction(*a)
</del><ins>+ return self.store.newTransaction(*a, **k)
</ins><span class="cx"> def deschema():
</span><span class="cx"> @inlineCallbacks
</span><span class="cx"> def deletestuff(txn):
</span><span class="cx"> for stmt in dropSQL:
</span><span class="cx"> yield txn.execSQL(stmt)
</span><del>- return inTransaction(lambda *a: self.store.newTransaction(*a),
</del><ins>+ return inTransaction(self.store.newTransaction,
</ins><span class="cx"> deletestuff)
</span><span class="cx"> self.addCleanup(deschema)
</span><span class="cx">
</span></span></pre></div>
<a id="CalendarServerbranchesreleaseCalendarServer54devtwistedcaldavdirectorydirectorypy"></a>
<div class="modfile"><h4>Modified: CalendarServer/branches/release/CalendarServer-5.4-dev/twistedcaldav/directory/directory.py (15101 => 15102)</h4>
<pre class="diff"><span>
<span class="info">--- CalendarServer/branches/release/CalendarServer-5.4-dev/twistedcaldav/directory/directory.py 2015-09-03 21:00:43 UTC (rev 15101)
+++ CalendarServer/branches/release/CalendarServer-5.4-dev/twistedcaldav/directory/directory.py 2015-09-03 21:05:31 UTC (rev 15102)
</span><span class="lines">@@ -1082,7 +1082,7 @@
</span><span class="cx">
</span><span class="cx"> @inlineCallbacks
</span><span class="cx"> def scheduleNextGroupCachingUpdate(store, seconds):
</span><del>- txn = store.newTransaction()
</del><ins>+ txn = store.newTransaction(label="scheduleNextGroupCachingUpdate")
</ins><span class="cx"> notBefore = datetime.datetime.utcnow() + datetime.timedelta(seconds=seconds)
</span><span class="cx"> log.debug("Scheduling next group cacher update: %s" % (notBefore,))
</span><span class="cx"> wp = (yield txn.enqueue(GroupCacherPollingWork, notBefore=notBefore))
</span></span></pre></div>
<a id="CalendarServerbranchesreleaseCalendarServer54devtxdavcaldavdatastoreschedulingimipinboundpy"></a>
<div class="modfile"><h4>Modified: CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/caldav/datastore/scheduling/imip/inbound.py (15101 => 15102)</h4>
<pre class="diff"><span>
<span class="info">--- CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/caldav/datastore/scheduling/imip/inbound.py 2015-09-03 21:00:43 UTC (rev 15101)
+++ CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/caldav/datastore/scheduling/imip/inbound.py 2015-09-03 21:05:31 UTC (rev 15102)
</span><span class="lines">@@ -168,7 +168,7 @@
</span><span class="cx">
</span><span class="cx"> @inlineCallbacks
</span><span class="cx"> def scheduleNextMailPoll(store, seconds):
</span><del>- txn = store.newTransaction()
</del><ins>+ txn = store.newTransaction(label="iMIP:scheduleNextMailPoll")
</ins><span class="cx"> notBefore = datetime.datetime.utcnow() + datetime.timedelta(seconds=seconds)
</span><span class="cx"> log.debug("Scheduling next mail poll: %s" % (notBefore,))
</span><span class="cx"> yield txn.enqueue(IMIPPollingWork, notBefore=notBefore)
</span><span class="lines">@@ -251,7 +251,7 @@
</span><span class="cx"> log.error("Mail gateway can't find token in DSN %s" % (msgId,))
</span><span class="cx"> return
</span><span class="cx">
</span><del>- txn = self.store.newTransaction()
</del><ins>+ txn = self.store.newTransaction(label="iMIP:processDSN")
</ins><span class="cx"> result = (yield txn.imipLookupByToken(token))
</span><span class="cx"> yield txn.commit()
</span><span class="cx"> try:
</span><span class="lines">@@ -277,7 +277,7 @@
</span><span class="cx"> pass
</span><span class="cx">
</span><span class="cx"> log.warn("Mail gateway processing DSN %s" % (msgId,))
</span><del>- txn = self.store.newTransaction()
</del><ins>+ txn = self.store.newTransaction(label="iMIP:enqueue IMIPReplyWork")
</ins><span class="cx"> yield txn.enqueue(IMIPReplyWork, organizer=organizer, attendee=attendee,
</span><span class="cx"> icalendarText=str(calendar))
</span><span class="cx"> yield txn.commit()
</span><span class="lines">@@ -300,7 +300,7 @@
</span><span class="cx"> "message %s" % (msg['To'], msg['Message-ID']))
</span><span class="cx"> returnValue(self.MALFORMED_TO_ADDRESS)
</span><span class="cx">
</span><del>- txn = self.store.newTransaction()
</del><ins>+ txn = self.store.newTransaction(label="iMIP:processReply")
</ins><span class="cx"> result = (yield txn.imipLookupByToken(token))
</span><span class="cx"> yield txn.commit()
</span><span class="cx"> try:
</span><span class="lines">@@ -383,7 +383,7 @@
</span><span class="cx"> # the appropriate ATTENDEE. This will require a new localizable
</span><span class="cx"> # email template for the message.
</span><span class="cx">
</span><del>- txn = self.store.newTransaction()
</del><ins>+ txn = self.store.newTransaction(label="iMIP:enqueue IMIPReplyWork")
</ins><span class="cx"> yield txn.enqueue(IMIPReplyWork, organizer=organizer, attendee=attendee,
</span><span class="cx"> icalendarText=str(calendar))
</span><span class="cx"> yield txn.commit()
</span></span></pre></div>
<a id="CalendarServerbranchesreleaseCalendarServer54devtxdavcaldavdatastoreschedulingimipmailgatewaypy"></a>
<div class="modfile"><h4>Modified: CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/caldav/datastore/scheduling/imip/mailgateway.py (15101 => 15102)</h4>
<pre class="diff"><span>
<span class="info">--- CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/caldav/datastore/scheduling/imip/mailgateway.py 2015-09-03 21:00:43 UTC (rev 15101)
+++ CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/caldav/datastore/scheduling/imip/mailgateway.py 2015-09-03 21:05:31 UTC (rev 15102)
</span><span class="lines">@@ -229,7 +229,7 @@
</span><span class="cx"> @type store: L{CommonDataStore}
</span><span class="cx"> """
</span><span class="cx"> oldDB = MailGatewayTokensDatabase(path)
</span><del>- txn = store.newTransaction()
</del><ins>+ txn = store.newTransaction(label="iMIP:migrateTokensToStore")
</ins><span class="cx"> for token, organizer, attendee, icaluid in oldDB.getAllTokens():
</span><span class="cx"> yield txn.imipCreateToken(organizer, attendee, icaluid, token=token)
</span><span class="cx"> yield txn.commit()
</span></span></pre></div>
<a id="CalendarServerbranchesreleaseCalendarServer54devtxdavcommondatastoresqlpy"></a>
<div class="modfile"><h4>Modified: CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/sql.py (15101 => 15102)</h4>
<pre class="diff"><span>
<span class="info">--- CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/sql.py 2015-09-03 21:00:43 UTC (rev 15101)
+++ CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/sql.py 2015-09-03 21:05:31 UTC (rev 15102)
</span><span class="lines">@@ -210,7 +210,7 @@
</span><span class="cx"> Implementation of L{ICalendarStore.withEachCalendarHomeDo} and
</span><span class="cx"> L{IAddressbookStore.withEachAddressbookHomeDo}.
</span><span class="cx"> """
</span><del>- txn = yield self.newTransaction()
</del><ins>+ txn = yield self.newTransaction(label="_withEachHomeDo")
</ins><span class="cx"> try:
</span><span class="cx"> allUIDs = yield (Select([homeTable.OWNER_UID], From=homeTable)
</span><span class="cx"> .on(txn))
</span><span class="lines">@@ -252,7 +252,7 @@
</span><span class="cx"> """
</span><span class="cx"> txn = CommonStoreTransaction(
</span><span class="cx"> self,
</span><del>- self.sqlTxnFactory(),
</del><ins>+ self.sqlTxnFactory(label=label),
</ins><span class="cx"> self.enableCalendars,
</span><span class="cx"> self.enableAddressBooks,
</span><span class="cx"> self._notifierFactories if self._enableNotifications else {},
</span><span class="lines">@@ -5855,7 +5855,7 @@
</span><span class="cx"> Fix all UUIDs in the given SQL store to be in a canonical form;
</span><span class="cx"> 00000000-0000-0000-0000-000000000000 format and upper-case.
</span><span class="cx"> """
</span><del>- t = store.newTransaction(disableCache=True)
</del><ins>+ t = store.newTransaction(label="fixUUIDNormalization", disableCache=True)
</ins><span class="cx">
</span><span class="cx"> # First, let's see if there are any calendar, addressbook, or notification
</span><span class="cx"> # homes that have a de-normalized OWNER_UID. If there are none, then we can
</span></span></pre></div>
<a id="CalendarServerbranchesreleaseCalendarServer54devtxdavcommondatastoresql_legacypy"></a>
<div class="modfile"><h4>Modified: CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/sql_legacy.py (15101 => 15102)</h4>
<pre class="diff"><span>
<span class="info">--- CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/sql_legacy.py 2015-09-03 21:00:43 UTC (rev 15101)
+++ CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/sql_legacy.py 2015-09-03 21:05:31 UTC (rev 15102)
</span><span class="lines">@@ -485,7 +485,7 @@
</span><span class="cx"> # Use a new transaction to do this update quickly without locking the row for too long. However, the original
</span><span class="cx"> # transaction may have the row locked, so use wait=False and if that fails, fall back to using the original txn.
</span><span class="cx">
</span><del>- newTxn = obj.transaction().store().newTransaction()
</del><ins>+ newTxn = obj.transaction().store().newTransaction(label="reExpandResource")
</ins><span class="cx"> try:
</span><span class="cx"> yield obj.lock(wait=False, txn=newTxn)
</span><span class="cx"> except NoSuchObjectResourceError:
</span></span></pre></div>
<a id="CalendarServerbranchesreleaseCalendarServer54devtxdavcommondatastoreupgrademigratepy"></a>
<div class="modfile"><h4>Modified: CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/upgrade/migrate.py (15101 => 15102)</h4>
<pre class="diff"><span>
<span class="info">--- CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/upgrade/migrate.py 2015-09-03 21:00:43 UTC (rev 15101)
+++ CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/upgrade/migrate.py 2015-09-03 21:05:31 UTC (rev 15102)
</span><span class="lines">@@ -217,7 +217,7 @@
</span><span class="cx"> Upgrade one calendar home.
</span><span class="cx"> """
</span><span class="cx"> _ignore_migrateFunc, destFunc = homeTypeLookup[homeType]
</span><del>- fileTxn = self.upgrader.fileStore.newTransaction()
</del><ins>+ fileTxn = self.upgrader.fileStore.newTransaction(label="UpgradeHelperProcess:oneUpgrade")
</ins><span class="cx"> return (
</span><span class="cx"> maybeDeferred(destFunc(fileTxn), uid)
</span><span class="cx"> .addCallback(
</span><span class="lines">@@ -315,7 +315,7 @@
</span><span class="cx"> uid = normalizeUUIDOrNot(fileHome.uid())
</span><span class="cx"> self.log.warn("Starting migration transaction %s UID %r" %
</span><span class="cx"> (homeType, uid))
</span><del>- sqlTxn = self.sqlStore.newTransaction()
</del><ins>+ sqlTxn = self.sqlStore.newTransaction(label="UpgradeToDatabaseStep.migrateOneHome")
</ins><span class="cx"> homeGetter = destFunc(sqlTxn)
</span><span class="cx"> sqlHome = yield homeGetter(uid, create=False)
</span><span class="cx"> if sqlHome is not None and not self.merge:
</span><span class="lines">@@ -409,7 +409,7 @@
</span><span class="cx">
</span><span class="cx"> # First force each home to v1 data format so the upgrades will be triggered
</span><span class="cx"> self.log.warn("Migration extra steps.")
</span><del>- txn = self.sqlStore.newTransaction()
</del><ins>+ txn = self.sqlStore.newTransaction(label="UpgradeToDatabaseStep.doDataUpgradeSteps")
</ins><span class="cx"> for storeType in (ECALENDARTYPE, EADDRESSBOOKTYPE):
</span><span class="cx"> schema = txn._homeClass[storeType]._homeSchema
</span><span class="cx"> yield Update(
</span></span></pre></div>
<a id="CalendarServerbranchesreleaseCalendarServer54devtxdavcommondatastoreupgradesqlupgradepy"></a>
<div class="modfile"><h4>Modified: CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/upgrade/sql/upgrade.py (15101 => 15102)</h4>
<pre class="diff"><span>
<span class="info">--- CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/upgrade/sql/upgrade.py 2015-09-03 21:00:43 UTC (rev 15101)
+++ CalendarServer/branches/release/CalendarServer-5.4-dev/txdav/common/datastore/upgrade/sql/upgrade.py 2015-09-03 21:05:31 UTC (rev 15102)
</span><span class="lines">@@ -48,7 +48,7 @@
</span><span class="cx">
</span><span class="cx"> @inlineCallbacks
</span><span class="cx"> def stepWithResult(self, result):
</span><del>- sqlTxn = self.sqlStore.newTransaction()
</del><ins>+ sqlTxn = self.sqlStore.newTransaction(label="UpgradeAcquireLockStep")
</ins><span class="cx"> yield sqlTxn.acquireUpgradeLock()
</span><span class="cx"> yield sqlTxn.commit()
</span><span class="cx">
</span><span class="lines">@@ -69,7 +69,7 @@
</span><span class="cx">
</span><span class="cx"> @inlineCallbacks
</span><span class="cx"> def stepWithResult(self, result):
</span><del>- sqlTxn = self.sqlStore.newTransaction()
</del><ins>+ sqlTxn = self.sqlStore.newTransaction(label="UpgradeReleaseLockStep")
</ins><span class="cx"> yield sqlTxn.releaseUpgradeLock()
</span><span class="cx"> yield sqlTxn.commit()
</span><span class="cx">
</span><span class="lines">@@ -170,7 +170,7 @@
</span><span class="cx"> self.log.warn("Required database key %s: %s." % (self.versionKey, required_version,))
</span><span class="cx">
</span><span class="cx"> # Get the schema version in the current database
</span><del>- sqlTxn = self.sqlStore.newTransaction()
</del><ins>+ sqlTxn = self.sqlStore.newTransaction(label="UpgradeDatabaseCoreStep.getVersions")
</ins><span class="cx"> dialect = sqlTxn.dialect
</span><span class="cx"> try:
</span><span class="cx"> actual_version = yield sqlTxn.calendarserverValue(self.versionKey)
</span><span class="lines">@@ -313,7 +313,7 @@
</span><span class="cx"> Apply the schema upgrade .sql file to the database.
</span><span class="cx"> """
</span><span class="cx"> self.log.warn("Applying schema upgrade: %s" % (fp.basename(),))
</span><del>- sqlTxn = self.sqlStore.newTransaction()
</del><ins>+ sqlTxn = self.sqlStore.newTransaction(label="UpgradeDatabaseSchemaStep.applyUpgrade")
</ins><span class="cx"> try:
</span><span class="cx"> sql = fp.getContent()
</span><span class="cx"> yield sqlTxn.execSQLBlock(sql)
</span></span></pre>
</div>
</div>
</body>
</html>