Launchpad itself

Merge lp:~mwhudson/launchpad/log-noop-puller-runs into lp:launchpad

  1. log-noop-puller-runs
  2. Merge into devel
Proposed by Michael Hudson-Doyle
Status: Merged
Approved by: Michael Hudson-Doyle
Approved revision: not available
Merged at revision: not available
Proposed branch: lp:~mwhudson/launchpad/log-noop-puller-runs
Merge into: lp:launchpad
Diff against target: 185 lines (+36/-26)
4 files modified
lib/lp/codehosting/puller/scheduler.py (+11/-7)
lib/lp/codehosting/puller/tests/test_scheduler.py (+11/-10)
lib/lp/codehosting/puller/tests/test_worker.py (+3/-3)
lib/lp/codehosting/puller/worker.py (+11/-6)
To merge this branch: bzr merge lp:~mwhudson/launchpad/log-noop-puller-runs
Reviewer Review Type Date Requested Status
Jonathan Lange (community) Approve
Review via email: mp+16460@code.launchpad.net

Commit message

Log when the puller runs but does not transfer any revisions

To post a comment you must log in.
Revision history for this message
Michael Hudson-Doyle (mwhudson) wrote :

Hi there,

It is a fact that roughly half of the runs of the branch puller are from import branches. It is a fairly confident supposition of mine that most of these pulls do not actually move any revisions around and that we should stop the import system requesting mirrors when no revisions were imported. However, as Aaron pointed out this morning, it's pretty easy to log whether a run of the puller transferred any revisions so we can upgrade this supposition to a fact and that's what this branch does.

The net effect of the changes are that the "successfully mirrored" lines in the log now look like this:

2009-12-22 00:34:07 INFO Successfully mirrored HOSTED branch 77 lp-hosted:///~mark/gnome-terminal/trunk to lp-mirrored:///~mark/gnome-terminal/trunk to from rev null: to <email address hidden> (non-trivial)

Or this:

2009-12-22 00:34:28 INFO Successfully mirrored HOSTED branch 77 lp-hosted:///~mark/gnome-terminal/trunk to lp-mirrored:///~mark/gnome-terminal/trunk to from rev <email address hidden> to <email address hidden> (noop)

I think this will allow simple but sufficient grep based analysis of the puller log files.

Cheers,
mwh

Revision history for this message
Jonathan Lange (jml) wrote :

Looks very straightforward.

review: Approve

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
=== modified file 'lib/lp/codehosting/puller/scheduler.py'
--- lib/lp/codehosting/puller/scheduler.py 2009-11-21 01:47:27 +0000
+++ lib/lp/codehosting/puller/scheduler.py 2009-12-22 00:41:17 +0000
@@ -236,10 +236,10 @@
236 def do_mirrorDeferred(self):236 def do_mirrorDeferred(self):
237 self.reported_mirror_finished = True237 self.reported_mirror_finished = True
238238
239 def do_mirrorSucceeded(self, latest_revision):239 def do_mirrorSucceeded(self, revid_before, revid_after):
240 def mirrorSucceeded():240 def mirrorSucceeded():
241 d = defer.maybeDeferred(241 d = defer.maybeDeferred(
242 self.listener.mirrorSucceeded, latest_revision)242 self.listener.mirrorSucceeded, revid_before, revid_after)
243 d.addCallback(self.reportMirrorFinished)243 d.addCallback(self.reportMirrorFinished)
244 return d244 return d
245 self.runNotification(mirrorSucceeded)245 self.runNotification(mirrorSucceeded)
@@ -374,13 +374,17 @@
374 return self.branch_puller_endpoint.callRemote(374 return self.branch_puller_endpoint.callRemote(
375 'mirrorFailed', self.branch_id, reason)375 'mirrorFailed', self.branch_id, reason)
376376
377 def mirrorSucceeded(self, revision_id):377 def mirrorSucceeded(self, revid_before, revid_after):
378 if revid_before == revid_after:
379 was_noop = 'noop'
380 else:
381 was_noop = 'non-trivial'
378 self.logger.info(382 self.logger.info(
379 'Successfully mirrored branch %d %s to %s to rev %s',383 'Successfully mirrored %s branch %d %s to %s to from rev %s to %s'
380 self.branch_id, self.source_url, self.destination_url,384 ' (%s)', self.branch_type_name, self.branch_id, self.source_url,
381 revision_id)385 self.destination_url, revid_before, revid_after, was_noop)
382 return self.branch_puller_endpoint.callRemote(386 return self.branch_puller_endpoint.callRemote(
383 'mirrorComplete', self.branch_id, revision_id)387 'mirrorComplete', self.branch_id, revid_after)
384388
385 def log(self, message):389 def log(self, message):
386 self.logger.info('From worker: %s', message)390 self.logger.info('From worker: %s', message)
387391
=== modified file 'lib/lp/codehosting/puller/tests/test_scheduler.py'
--- lib/lp/codehosting/puller/tests/test_scheduler.py 2009-11-22 20:29:33 +0000
+++ lib/lp/codehosting/puller/tests/test_scheduler.py 2009-12-22 00:41:17 +0000
@@ -224,8 +224,8 @@
224 def startMirroring(self):224 def startMirroring(self):
225 self.calls.append('startMirroring')225 self.calls.append('startMirroring')
226226
227 def mirrorSucceeded(self, last_revision):227 def mirrorSucceeded(self, revid_before, revid_after):
228 self.calls.append(('mirrorSucceeded', last_revision))228 self.calls.append(('mirrorSucceeded', revid_before, revid_after))
229229
230 def mirrorFailed(self, message, oops):230 def mirrorFailed(self, message, oops):
231 self.calls.append(('mirrorFailed', message, oops))231 self.calls.append(('mirrorFailed', message, oops))
@@ -262,8 +262,9 @@
262 """Receiving a mirrorSucceeded message notifies the listener."""262 """Receiving a mirrorSucceeded message notifies the listener."""
263 self.protocol.do_startMirroring()263 self.protocol.do_startMirroring()
264 self.listener.calls = []264 self.listener.calls = []
265 self.protocol.do_mirrorSucceeded('1234')265 self.protocol.do_mirrorSucceeded('rev1', 'rev2')
266 self.assertEqual([('mirrorSucceeded', '1234')], self.listener.calls)266 self.assertEqual(
267 [('mirrorSucceeded', 'rev1', 'rev2')], self.listener.calls)
267 self.assertProtocolSuccess()268 self.assertProtocolSuccess()
268269
269 def test_mirrorDeferred(self):270 def test_mirrorDeferred(self):
@@ -320,7 +321,7 @@
320 """321 """
321 self.protocol.do_startMirroring()322 self.protocol.do_startMirroring()
322 self.clock.advance(config.supermirror.worker_timeout - 1)323 self.clock.advance(config.supermirror.worker_timeout - 1)
323 self.protocol.do_mirrorSucceeded('rev1')324 self.protocol.do_mirrorSucceeded('rev1', 'rev2')
324 self.clock.advance(2)325 self.clock.advance(2)
325 return self.assertFailure(326 return self.assertFailure(
326 self.termination_deferred, error.TimeoutError)327 self.termination_deferred, error.TimeoutError)
@@ -476,18 +477,18 @@
476 return deferred.addCallback(checkSetStackedOn)477 return deferred.addCallback(checkSetStackedOn)
477478
478 def test_mirrorComplete(self):479 def test_mirrorComplete(self):
479 arbitrary_revision_id = 'rev1'480 arbitrary_revision_ids = ('rev1', 'rev2')
480 deferred = defer.maybeDeferred(self.eventHandler.startMirroring)481 deferred = defer.maybeDeferred(self.eventHandler.startMirroring)
481482
482 def mirrorSucceeded(ignored):483 def mirrorSucceeded(*ignored):
483 self.status_client.calls = []484 self.status_client.calls = []
484 return self.eventHandler.mirrorSucceeded(arbitrary_revision_id)485 return self.eventHandler.mirrorSucceeded(*arbitrary_revision_ids)
485 deferred.addCallback(mirrorSucceeded)486 deferred.addCallback(mirrorSucceeded)
486487
487 def checkMirrorCompleted(ignored):488 def checkMirrorCompleted(ignored):
488 self.assertEqual(489 self.assertEqual(
489 [('mirrorComplete', self.arbitrary_branch_id,490 [('mirrorComplete', self.arbitrary_branch_id,
490 arbitrary_revision_id)],491 arbitrary_revision_ids[1])],
491 self.status_client.calls)492 self.status_client.calls)
492 return deferred.addCallback(checkMirrorCompleted)493 return deferred.addCallback(checkMirrorCompleted)
493494
@@ -797,7 +798,7 @@
797798
798 check_lock_id_script = """799 check_lock_id_script = """
799 branch.lock_write()800 branch.lock_write()
800 protocol.mirrorSucceeded('b')801 protocol.mirrorSucceeded('a', 'b')
801 protocol.sendEvent(802 protocol.sendEvent(
802 'lock_id', branch.control_files._lock.peek()['user'])803 'lock_id', branch.control_files._lock.peek()['user'])
803 sys.stdout.flush()804 sys.stdout.flush()
804805
=== modified file 'lib/lp/codehosting/puller/tests/test_worker.py'
--- lib/lp/codehosting/puller/tests/test_worker.py 2009-11-21 00:28:10 +0000
+++ lib/lp/codehosting/puller/tests/test_worker.py 2009-12-22 00:41:17 +0000
@@ -681,11 +681,11 @@
681 self.assertSentNetstrings(['startMirroring', '0'])681 self.assertSentNetstrings(['startMirroring', '0'])
682682
683 def test_mirrorSucceeded(self):683 def test_mirrorSucceeded(self):
684 # Calling 'mirrorSucceeded' sends the revno and 'mirrorSucceeded'.684 # Calling 'mirrorSucceeded' sends the revids and 'mirrorSucceeded'.
685 self.protocol.startMirroring()685 self.protocol.startMirroring()
686 self.resetBuffers()686 self.resetBuffers()
687 self.protocol.mirrorSucceeded(1234)687 self.protocol.mirrorSucceeded('rev1', 'rev2')
688 self.assertSentNetstrings(['mirrorSucceeded', '1', '1234'])688 self.assertSentNetstrings(['mirrorSucceeded', '2', 'rev1', 'rev2'])
689689
690 def test_mirrorFailed(self):690 def test_mirrorFailed(self):
691 # Calling 'mirrorFailed' sends the error message.691 # Calling 'mirrorFailed' sends the error message.
692692
=== modified file 'lib/lp/codehosting/puller/worker.py'
--- lib/lp/codehosting/puller/worker.py 2009-09-18 00:08:40 +0000
+++ lib/lp/codehosting/puller/worker.py 2009-12-22 00:41:17 +0000
@@ -105,8 +105,8 @@
105 # success or failure.105 # success or failure.
106 self.sendEvent('mirrorDeferred')106 self.sendEvent('mirrorDeferred')
107107
108 def mirrorSucceeded(self, last_revision):108 def mirrorSucceeded(self, revid_before, revid_after):
109 self.sendEvent('mirrorSucceeded', last_revision)109 self.sendEvent('mirrorSucceeded', revid_before, revid_after)
110110
111 def mirrorFailed(self, message, oops_id):111 def mirrorFailed(self, message, oops_id):
112 self.sendEvent('mirrorFailed', message, oops_id)112 self.sendEvent('mirrorFailed', message, oops_id)
@@ -322,10 +322,11 @@
322 # over from previous puller worker runs. We will block on other322 # over from previous puller worker runs. We will block on other
323 # locks and fail if they are not broken before the timeout expires323 # locks and fail if they are not broken before the timeout expires
324 # (currently 5 minutes).324 # (currently 5 minutes).
325 revid_before = branch.last_revision()
325 if branch.get_physical_lock_status():326 if branch.get_physical_lock_status():
326 branch.break_lock()327 branch.break_lock()
327 self.updateBranch(source_branch, branch)328 self.updateBranch(source_branch, branch)
328 return branch329 return branch, revid_before
329330
330331
331class PullerWorker:332class PullerWorker:
@@ -411,6 +412,10 @@
411 reporting protocol -- a "naked mirror", if you will. This is412 reporting protocol -- a "naked mirror", if you will. This is
412 particularly useful for tests that want to mirror a branch and be413 particularly useful for tests that want to mirror a branch and be
413 informed immediately of any errors.414 informed immediately of any errors.
415
416 :return: ``(branch, revid_before)``, where ``branch`` is the
417 destination branch and ``revid_before`` was the tip revision
418 *before* the mirroring process ran.
414 """419 """
415 # Avoid circular import420 # Avoid circular import
416 from lp.codehosting.vfs import get_puller_server421 from lp.codehosting.vfs import get_puller_server
@@ -429,7 +434,7 @@
429 """434 """
430 self.protocol.startMirroring()435 self.protocol.startMirroring()
431 try:436 try:
432 dest_branch = self.mirrorWithoutChecks()437 dest_branch, revid_before = self.mirrorWithoutChecks()
433 # add further encountered errors from the production runs here438 # add further encountered errors from the production runs here
434 # ------ HERE ---------439 # ------ HERE ---------
435 #440 #
@@ -500,8 +505,8 @@
500 raise505 raise
501506
502 else:507 else:
503 last_rev = dest_branch.last_revision()508 revid_after = dest_branch.last_revision()
504 self.protocol.mirrorSucceeded(last_rev)509 self.protocol.mirrorSucceeded(revid_before, revid_after)
505510
506 def __eq__(self, other):511 def __eq__(self, other):
507 return self.source == other.source and self.dest == other.dest512 return self.source == other.source and self.dest == other.dest