Re: [PATCH] debugs-refactor, v1

On Tue, Feb 18, 2014 at 5:58 PM, Alex Rousskov
<rousskov_at_measurement-factory.com> wrote:
> On 02/17/2014 11:16 PM, Francesco wrote:
>>
>> On 18 Feb 2014, at 00:44, Alex Rousskov <rousskov_at_measurement-factory.com> wrote:
>>
>>> On 02/17/2014 02:46 PM, Kinkie wrote:
>>>
>>>> the attached patch aims at simplifying debug, making it also more effective.
>>>
>>> It would be better to finish the discussion regarding the future of
>>> debugging before making debugging-focused changes IMO.
>
>> This effort is only about making the existing debugging interface
>> more consistent (its refactoring was apparently stopped midway
>> through), and removing some unused code.
>
> IMO, it would be better to change existing debugging interface
> (including stuff you call "API cruft" and API stuff you consider
> "unused") after we finish the discussion regarding the future of
> debugging, but it is obviously too late for that. Let's try to finish
> this project since you started (and invested a lot in) it already.

Abandoning it is not a problem, if the effort to finish is more than
what I already spent (a few hours).

>>>> It:
>>>> - removes some of the API cruft (ctx_enter, ctx_exit, BuildPrefixInit)
>>>> - shuffles the remaining public functions to static members of Debug
>>>> - fixes clients still relying on old_debug (thanks to Amos)
>>>> - implements a compatibility wrapper for std::mutex (not all compilers
>>>> we care about implement it yet) relying on pthread mutexes if needed.
>>>> - increases the efficiency of debugs() message creation by reducing
>>>> the number of data copies
>>>> - the new debugs() call is reentrant and threadsafe on all platforms,
>>>> not just windows
>>>
>>>> It's been build- and run- tested on ubuntu raring; it's being tested
>>>> in the build farm as we speak; it's possible that as results from that
>>>> come in some small changes will be needed, but the API is hopefully
>>>> fixed.
>>>>
>>>> Feature branch at lp:~squid/squid/debugs-refactor.
>>>
>>> Have you verified your performance improvements claims? The patch may
>>> remove some copying, but it also adds mutex overheads (one of two very
>>> different kinds, depending on ./configure outcome?). It would be
>>> interesting to see which overheads are heavier. If you have not verified
>>> those claims, perhaps it would be prudent to at least augment those
>>> claims as unverified and far from obvious.
>
>> You are right. It _does_ eliminate some copying. It is not something on the critical path - unless running at ALL,9 the fast path is the one where output is not even accumulated - that one critical part of the original API was carefully kept.
>
> In this context, it is not important whether the patch eliminates some
> copying. It is important whether the patch eliminates more than it adds.
> We have had several discussions about this in the past but keep coming
> back to this issue for some reason: It is the net effect that counts; if
> the net effect is unknown or unclear, we have to disclose that and
> indicate both intended improvements and regressions. You are not [just]
> advertising a patch -- you are making a full disclosure.

current code: each call to finishDebug will cause 4 user-level copies:
one for the str() call out of the streambuf, and one for each _db_*
call to honor the %s format.
proposed code: 1 for the str() call, and 1 for syslog

>>>> +static Mutex printlock;
>>>
>>> Please avoid using phreads if Squid does not need them.
>>
>> This raises an interesting question: how do I detect if these are needed?
>
> If you want to invest a lot of cycles in it, then adjust the code that
> uses threads to enable thread-safe debugging (and associated overheads).
>
> If you do not want to invest a lot of cycles, then remove any mention of
> pthreads from your patch. Let the folks who care about threads work on
> making debugging thread-safe, driving those changes from their unique
> perspective.

If we want to serialize debugs, there is going to be a synchronization
primitive. Caring for that in client code seems overkill..

>>>> +static Mutex printlock;
>>> ...
>>>> +Debug::Print(const std::string & logline)
>>>> {
>>> ...
>>>> + printlock.lock();
>>> ...
>>>> + printlock.unlock();
>>>> +}
>>>
>>> AFAICT, your implementation will freeze Squid forever when debugs() is
>>> called recursively. If true, this would be a major regression not worth
>>> any of the claimed improvements.
>
>> It shouldn't, because the Print method (as only used by debugs() is
>> serialized
>
> If Print() calls are serialized, we do not need mutex locks to protect
> them. I now begin to understand that your code does not match your
> description -- you are making Print() thread-safe, not debugs() as
> claimed. debugs() is [still] unsafe. This understanding will help in
> reviewing your patch.
>
> The mutex will not cause locking problems in most cases indeed. However,
> it is not needed in most cases either. Enable it conditionally on
> Windows, just like the old code did (that still leaves you liable for
> Windows changes, but at least those who are not interested in Windows
> would not have to pay close attention to them).

Ok. But can we rely on std::mutex on windows? I suspect not, and the
windows API as currently used are terrible.

>>> We need debugs() not to crash when used reentrantly, but we do not
>>> really want to pay much for "great" reentrant support because reentrant
>>> calls are rare and one can usually figure out what happened anyway even
>>> if the resulting debugging strings are messy. Strict locking (with
>>> waiting) is the wrong solution here.
>
>> The locking is only used when outputting, to avoid races mixing
>> output lines. Is it worth it? I can't be sure: the current code has a
>> platform-specific mutex in place on windows only and that's where I
>> took the need from. Advice is welcome.
>
> My advice is to let the Windows and threads folks improve
> thread/Windows-safety *if* they think those aspects need to be improved
> to match their actual needs. Do not force everybody else to proactively
> spend their cycles on avoiding races that do not exist for 99% of Squid
> installations. We can come back to that topic when/if Windows/threads
> folks want to revisit it, of course, but let _them_ drive that effort
> because they have the use cases and can shape, test, and advocate for
> the improvements correctly.
>
>
>>> Perhaps I am missing some global dependency/context here, but if you
>>> want to improve the common-case debugging efficiency and simplify
>>> things, please do not force all debugging through mutexes, especially
>>> through pthread mutexes. Something went wrong here. Perhaps you are
>>> correctly solving the wrong problem, not sure:
>
>> Well, the current code uses a very verbose mutex, but on windows only
>> for some reason (see above)
>
> FWIW, unless noted otherwise, I will be ignoring Windows-only changes in
> my review. I am not qualified or interested enough in that area.
>
> Please note that non-threaded code does not need mutexes. I hope we do
> not need to discuss/change threaded code now, for the reasons stated a
> bit earlier.

Ok.

>>>> - std::ostream &_dbo=Debug::getDebugOut(); \
>>>> + std::ostringstream dbss; \
>>>
>>> To minimize overheads, it would be great to have a reusable debugging
>>> stream with large pre-allocated storage backing except for rare
>>> reentrant/recursive calls that will trigger creation of "back up"
>>> dynamic streams. The old interface/approach would facilitate that kind
>>> of optimization. I do not recommend removing it.
>>
>> .. does it? Maybe it facilitates but it doesn't really seem to be used.
>
> The get/put debugging stream interface allows the implementation to
> allocate and delete streams as needed, which can be used to preserve and
> reuse an allocated stream (the common case). The current code does not
> contain that optimization but the API allows for it. By removing that
> API, you are making that optimization a lot more difficult. Please
> reinstate that API or explain why it should be removed.
>
> Also, I suspect removing that API breaks eCAP as discussed further below.
>
>
>> (also, remember performance here is not critical as the string stream
>> only gets created on the non-common case).
>
> If I read the patch correctly, the dbss object cited in the above code
> snippet is created and destroyed on every debugs() call that results in
> output, right? That is the performance sensitive path as far as
> debugging is concerned (not important when debugging is at ALL,1, of
> course, but we all know that sometimes the problem cannot be reproduced
> with debugging on because Squid becomes too slow so I do consider
> debugging performance important).
>
> In other words, for the purpose of this discussion about debugging,
> "ALL,9" is a common/interesting case.
>
>
>>>> void
>>>> Adaptation::Ecap::Host::closeDebug(std::ostream *debug)
>>>> {
>>>> - if (debug)
>>>> - Debug::finishDebug();
>>>> }
>>>
>>> Can you explain what happened here? Is eCAP adapter debugging not
>>> supported any more?
>>
>> The debugging happens via debugs() which each does the equivalent of finishDebug().
>
> eCAP does not use debugs() API. It uses Debug::getDebugOut() and
> Debug::finishDebug(). Please see Adaptation::Ecap::Host::openDebug().
> Please make sure that method and Adaptation::Ecap::Host::closeDebug()
> still work after your changes.

Ok, this is a killer.
I'm being convinced that it's not worth going through the effort.
Maybe something can be salvaged, e.g. finishing to shuffle the _db_*
methods in to the Debug class, or the compat/mutex.h layer.

But I'm not convinced anymore it's worth investing any more effort, at
least not now.

Thanks for investing the time to review this.

  Kinkie
Received on Tue Feb 18 2014 - 17:45:25 MST