719261 - Add more logging to AggregatingScheduler

Status: RESOLVED FIXED

(Release Engineering :: General, defect, P2)

Description

[Rail Aliiev [:rail]]

It would be great to print some information about scheduled builders, initialization, etc.

Comment 1

[Rail Aliiev [:rail]]

Attachment: moar logging

Comment 2

[Rail Aliiev [:rail]]

Attachment: moar logging

* print schedulerid to simplify debugging
* use self.working flag for transactions! :D Hopefully fixes bug 719260
* reset the state to its initial state after creating a buildset
* worked as expected in staging

Comment 3

[Chris AtLee [:catlee]]

Comment on attachment 589969 [details] [diff] [review]
moar logging

Review of attachment 589969 [details] [diff] [review]:
-----------------------------------------------------------------

::: scheduler.py
@@ +383,5 @@
>          for b in self.upstreamBuilders:
>              if b not in state['remainingBuilders']:
>                  state['remainingBuilders'].append(b)
> +        log.msg('%s <id=%s>: reloaded' % (self.__class__.__name__,
> +                                          self.schedulerid))

I think you should use id(self) here instead of self.schedulerid. Or perhaps log both? The thing we want to know is if two instances of the scheduler are running at the same time. The schedulerid's should be the same, because the schedulers will have the same name.

@@ +404,5 @@
>          self.set_state(t, state)
>  
>      def run(self):
>          d = self.parent.db.runInteraction(self._run)
>          return d

would it make sense to move the 'if self.working' logic into the run() method instead of _run()?

Also, I think adding a callback to d to reset self.working to False is better than setting it at the end of _run(), since exceptions may be raised inside _run() that would prevent self.working to be reset to False.

Comment 4

[Rail Aliiev [:rail]]

(In reply to Chris AtLee [:catlee] from comment #3)
> I think you should use id(self) here instead of self.schedulerid. Or perhaps
> log both? The thing we want to know is if two instances of the scheduler are
> running at the same time. The schedulerid's should be the same, because the
> schedulers will have the same name.

OK.
 
> @@ +404,5 @@
> >          self.set_state(t, state)
> >  
> >      def run(self):
> >          d = self.parent.db.runInteraction(self._run)
> >          return d
> 
> would it make sense to move the 'if self.working' logic into the run()
> method instead of _run()?

I thought about that, but run() just adds deferred to to the pool and actual execution happens in _run().
 
> Also, I think adding a callback to d to reset self.working to False is
> better than setting it at the end of _run(), since exceptions may be raised
> inside _run() that would prevent self.working to be reset to False.

Good point. I should reset the state in any case.

Comment 5

[Rail Aliiev [:rail]]

Attachment: moar logging 2

* use id(self)
* reset self.working in any case

intediff: https://gist.github.com/1647790

Comment 6

[Rail Aliiev [:rail]]

Comment on attachment 590191 [details] [diff] [review]
moar logging 2

http://hg.mozilla.org/build/buildbotcustom/rev/53cb872ea338

Comment 7

[[e-mail] (:bhearsum)]

Merged to production.