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

[Ilia Mirkin]

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