Re: [PATCH] debugs-refactor, v1

From: Alex Rousskov <rousskov_at_measurement-factory.com>
Date: Mon, 17 Feb 2014 16:44:10 -0700

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.

> 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.

The biggest problems with this patch are at the end of this email (sorry
-- moving quoted stuff is difficult).

> -#if defined(LOCKCOUNT_DEBUG)
> - old_debug(0,1)("Incrementing this %p from count %u\n",this,count_);
> +#if LOCKCOUNT_DEBUG
> + debugs(0, 8, "Incrementing this " << reinterpret_cast<const void *>(this) << "from count " <<

Missing space before "from".

> +/**
> + * Write out the SSL session details.
> + */
> +static std::string
> +debugDisplaySslContext(SSL *ssl)

Avoid the overhead of creating std::string if possible. const char * may
work better.

> + debugs(83, 4, debugDisplaySslContext(ssl) << "");

What is the purpose of logging ""?

> /* for shutting_down flag in xassert() */
> #include "globals.h"
>
> +
> char *Debug::debugOptions = NULL;
> int Debug::override_X = 0;

Please avoid non-changes.

> +static Mutex printlock;

Please avoid using phreads if Squid does not need them.

> +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.

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.

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:

>> - the new debugs() call is reentrant and threadsafe on all platforms,
>> not just windows

Thread safety is great, but we should not penalize 99% of Squid
installations (those that do not use threads). AFAICT, your
implementation applies that penalty to all installations.

> +std::string
> +LogLinePreamble()
> +{
> + std::string rv(debugLogTime());
> + rv.append(debugLogKid());
> + rv.append("| ");
> + return rv;
> +}

If the above code stays, please reserve string space before appending
stuff to it. I do not think it should stay though:

To avoid adding performance overheads of allocating strings, appending
to them, and copying them on return (when std::string does not CoW), you
should not log the result of LogLinePreamble() but log a LinePreamble
manipulator or object instead. A LinePreamble manipulator/object can
write each preamble item directly into the debugging stream, without any
overheads.

See Raw class as an example, but since yours will not need any class
members, you probably do not need a class object. Your LinePreamble can
be a stream manipulator like std::endl.

> - 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.

> 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?

Thank you,

Alex.
Received on Mon Feb 17 2014 - 23:44:22 MST

This archive was generated by hypermail 2.2.0 : Tue Feb 18 2014 - 12:00:13 MST