[Piglit] [PATCH 4/5] framework: refactor the log module

[Ilia Mirkin]

I didn't notice any other issues.

An alternative would be to drop the lock from _print entirely and just
assert that it's locked, since all the call sites already lock
beforehand. (Unless I missed something, in which case nevermind.)

Either way, you can add Reviewed-by: Ilia Mirkin <imirkin at alum.mit.edu>


On Wed, Aug 27, 2014 at 8:08 PM, Dylan Baker <baker.dylan.c at gmail.com> wrote:
> Just to be clear, with that one instance of pad= inside the lock you're
> good to see this land? And did you want to put acked, reviewed, etc on
> it?
>
> - Dylan
>
> On Tuesday, August 26, 2014 10:07:18 PM Ilia Mirkin wrote:
>> On Tue, Aug 26, 2014 at 8:44 PM, Dylan Baker <baker.dylan.c at gmail.com> wrote:
>> > Sorry it's taken me so long to get back to this (again), work has
>> > dictated slightly different priorities lately.
>> >
>> > On Tuesday, August 19, 2014 05:45:43 PM Ilia Mirkin wrote:
>> > [snip]
>> >>
>> >> No problem. Locking is probably one of the most complicated subjects
>> >> out there :) I'm again looking at the final output in your
>> >> log-refactor branch, not this patch specifically, although it should
>> >> be ~the same.
>> >>
>> >>     def _print(self, out):
>> >>         """ Shared print method that ensures any bad lines are overwritten """
>> >>         # If the new line is shorter than the old one add trailing
>> >>         # whitespace
>> >>         pad = self._state['lastlength'] - len(out)
>> >>
>> >>         with self._LOCK:
>> >> ... use pad ...
>> >>
>> >> So let's say you have (hopefully the ascii art works out... my
>> >> make-fonts-not-retarded-in-gmail plugin appears to have stopped
>> >> working for email composition)
>> >>
>> >> thread 1        thread 2
>> >> _print
>> >>                     _print
>> >> pad = ...
>> >>                     acquire lock
>> >>                     pad = ...
>> >>                     use pad
>> >>                     self._state['lastlength'] = ...
>> >>                     release lock
>> >> acquire lock
>> >> use pad
>> >>
>> >> Then that would be unfortunate, right? I think that the retrieval of
>> >> self._state['lastlength'] needs to move inside of the lock. That said,
>> >> it appears that _print is only ever called with the lock already
>> >> taken, in which case it shouldn't bother with the lock at all. In
>> >> general, having recursive locks is a sign of laziness, but I think it
>> >> can be forgiven here. But for _print, perhaps you can just assert that
>> >> the lock has already been taken.
>> >
>> > Right, that makes sense. I'll change that.
>> >
>> >>
>> >> Otherwise this (series) LGTM. Perhaps a little over-locked, but... not
>> >> unreasonably so.
>> >>
>> >> Out of curiousity, what is the dry-run time with this patch on
>> >> tests/gpu.py (for example)? That should give a good idea as to the
>> >> overhead of the locking... perhaps compare it to using
>> >> dummy_threading.RLock.
>> >
>> > When I run 'piglit run quick -c -d foo > /dev/null' (I don't want to
>> > measure the difference in console spewing after all), I see about .3
>> > seconds difference (~4.6 seconds vs ~4.3 seconds) between
>> > threading.RLock and dummy_threading.RLock.
>> >
>> > Does that seem reasonable to you?
>>
>> That seems very reasonable to me. I just wanted to make sure it wasn't
>> like... a minute :)
>>
>>   -ilia