[CalendarServer-changes] [15145] twext/trunk/twext/enterprise

[source_changes at macosforge.org]

Revision: 15145
          http://trac.calendarserver.org//changeset/15145
Author:   cdaboo at apple.com
Date:     2015-09-22 11:16:52 -0700 (Tue, 22 Sep 2015)
Log Message:
-----------
Additional logging.

Modified Paths:
--------------
    twext/trunk/twext/enterprise/dal/record.py
    twext/trunk/twext/enterprise/jobs/queue.py

Modified: twext/trunk/twext/enterprise/dal/record.py
===================================================================
--- twext/trunk/twext/enterprise/dal/record.py	2015-09-22 18:03:08 UTC (rev 15144)
+++ twext/trunk/twext/enterprise/dal/record.py	2015-09-22 18:16:52 UTC (rev 15145)
@@ -35,8 +35,9 @@
     Count, ALL_COLUMNS)
 from twext.enterprise.ienterprise import ORACLE_DIALECT
 from twext.enterprise.util import parseSQLTimestamp
-# from twext.enterprise.dal.syntax import ExpressionSyntax
+from twext.python.log import Logger
 
+log = Logger()
 
 
 class ReadOnly(AttributeError):
@@ -444,6 +445,10 @@
                 NoWait=True,
             ).on(self.transaction)
         except:
+            log.debug("trylock failed: {item} {where}".format(
+                name=repr(self),
+                where=str(where),
+            ))
             yield savepoint.rollback(self.transaction)
             returnValue(False)
         else:

Modified: twext/trunk/twext/enterprise/jobs/queue.py
===================================================================
--- twext/trunk/twext/enterprise/jobs/queue.py	2015-09-22 18:03:08 UTC (rev 15144)
+++ twext/trunk/twext/enterprise/jobs/queue.py	2015-09-22 18:16:52 UTC (rev 15145)
@@ -582,13 +582,14 @@
                     break
 
                 # Always assign as a new job even when it is an orphan
+                log.debug("workCheck: assigned job: {jobID}".format(jobID=nextJob.jobID))
                 yield nextJob.assign(nowTime, self.queueOverdueTimeout)
                 self._timeOfLastWork = time.time()
                 loopCounter += 1
 
             except Exception as e:
                 log.error(
-                    "Failed to pick a new job: {jobID}, {exc}",
+                    "workCheck: Failed to pick a new job: {jobID}, {exc}",
                     jobID=nextJob.jobID if nextJob else "?",
                     exc=e,
                 )
@@ -609,7 +610,7 @@
                     except Exception as e:
                         # Could not mark as failed - break out of the next job loop
                         log.error(
-                            "Failed to mark failed new job:{}, {exc}",
+                            "workCheck: Failed to mark failed new job:{}, {exc}",
                             jobID=nextJob.jobID,
                             exc=e,
                         )
@@ -619,13 +620,13 @@
                         break
                     else:
                         # Marked the problem one as failed, so keep going and get the next job
-                        log.error("Marked failed new job: {jobID}", jobID=nextJob.jobID)
+                        log.error("workCheck: Marked failed new job: {jobID}", jobID=nextJob.jobID)
                         yield txn.commit()
                         txn = None
                         nextJob = None
                 else:
                     # Cannot mark anything as failed - break out of next job loop
-                    log.error("Cannot mark failed new job")
+                    log.error("workCheck: Cannot mark failed new job")
                     break
             finally:
                 if txn is not None:
@@ -640,7 +641,7 @@
                     # we can do stuff in parallel
                     worker.performJob(nextJob.descriptor())
                 except Exception as e:
-                    log.error("Failed to perform job for jobid={jobid}, {exc}", jobid=nextJob.jobID, exc=e)
+                    log.error("workCheck: Failed to perform job for jobid={jobid}, {exc}", jobid=nextJob.jobID, exc=e)
 
         if loopCounter:
             log.debug("workCheck: processed {ctr} jobs in one loop", ctr=loopCounter)
@@ -677,7 +678,7 @@
                 interval = poll
                 break
         if self._actualPollInterval != interval:
-            log.debug("workCheckLoop: interval set to {interval}s", interval=interval)
+            log.debug("_workCheckLoop: interval set to {interval}s", interval=interval)
         self._actualPollInterval = interval
         self._workCheckCall = self.reactor.callLater(
             self._actualPollInterval, self._workCheckLoop
@@ -731,7 +732,7 @@
 
             except Exception as e:
                 log.error(
-                    "Failed to process overdue job: {jobID}, {exc}",
+                    "overdueCheck: Failed to process overdue job: {jobID}, {exc}",
                     jobID=overdueJob.jobID if overdueJob else "?",
                     exc=e,
                 )
@@ -752,7 +753,7 @@
                     except Exception as e:
                         # Could not mark as failed - break out of the overdue job loop
                         log.error(
-                            "Failed to mark failed overdue job:{}, {exc}",
+                            "overdueCheck: Failed to mark failed overdue job:{}, {exc}",
                             jobID=overdueJob.jobID,
                             exc=e,
                         )
@@ -762,13 +763,13 @@
                         break
                     else:
                         # Marked the problem one as failed, so keep going and get the next overdue job
-                        log.error("Marked failed overdue job: {jobID}", jobID=overdueJob.jobID)
+                        log.error("overdueCheck: Marked failed overdue job: {jobID}", jobID=overdueJob.jobID)
                         yield txn.commit()
                         txn = None
                         overdueJob = None
                 else:
                     # Cannot mark anything as failed - break out of overdue job loop
-                    log.error("Cannot mark failed overdue job")
+                    log.error("overdueCheck: Cannot mark failed overdue job")
                     break
             finally:
                 if txn is not None:
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.macosforge.org/pipermail/calendarserver-changes/attachments/20150922/e4d9cd55/attachment-0001.html>