[Libreoffice] Assertions and Logging

[Michael Stahl]

On 18/11/11 15:25, Stephan Bergmann wrote:
> The downside of that mixture is that the useful debugging technique of 
> aborting upon detection of a violated invariant is not available.---If 
> you make OSL_ASSERT (and OSL_ENSURE, OSL_FAIL, etc.) abort, it will 
> abort far too often for mundane warnings for it to be useful.

indeed, the current state of tens of thousands of assertions firing on a
subsequentcheck run is pretty awful, this needs to be sorted out to have
the really bad assertions actually demand developer attention by calling
abort.

[...]

> 3  Furthermore, there is sometimes demand for additional, debug-only 
> code.  In general, that would be safety-check additions that are 
> considered too expensive to be included in production builds (e.g., code 
> that iterates over a data structure to check invariants, or additional, 
> redundant fields within data structures).  Enabling such additional code 
> potentially affects compatibility.
> 
> Such additional code is currently controlled via OSL_DEBUG_LEVEL et al. 
>   OSL_DEBUG_LEVEL==1 is generally used for additions that do not affect 
> compatibility (as it is enabled by both --enable-debug and 
> --enable-dbgutil).  OSL_DEBUG_LEVEL==2, DBG_UTIL (defined upon 
> --enable-dbguitl) and privately invented defines in certain parts of the 
> code (to be set manually by knowledgeable developers) are used for 
> additions that affect compatibility or that are considered too specific 
> for general inclusion.  Either because they are too expensive even for 
> every --enable-dbgutil build, or because they produce excessive log 
> information (for which case the below new log functionality offers a 
> better solution).

one requirement i would have on conditional compilation is that, whether
--disable-dbgutil or --enable-dbgutil, objects built with debug=t
(resulting in OSL_DEBUG_LEVEL being set to non-zero) should always be
binary compatible with objects built without debug=t.

this makes e.g. tracking down bugs introduced by mis-optimisation much
easier; i think we are in agreement on this point.

> This can probably be reduced to three cases:
> 
> #if OSL_DEBUG_LEVEL != 0  for additional code that does not cause 
> incompatibilities (if there is still demand for such code; the new log 
> functionality will remove the need for such code in many cases).  This 
> effectively reduces OSL_DEBUG_LEVEL to a binary switch (so the make 
> dbglevel=x feature can be removed; and OSL_DEBUG_LEVEL could potentially 
> be renamed---but that would probably not be worth it).
> 
> #if defined DBG_UTIL  for additional code that causes incompatibilities.

i think i've seen members of SwDoc being added with:
 #if OSL_DEBUG_LEVEL > 1
 #if OSL_DEBUG_LEVEL > 0
this kind of thing always struck me as wrong: it should be DBG_UTIL,
will try to clean that up a bit...

> #if defined MY_SPECIAL_DEBUG  (replaced with actual defines, varying 
> across the different code modules) for those special cases where always 
> enabling the additional code is deemed to expensive in general. 
> (However, for those special cases where the additional code produces 
> excess log information, see below.)

in these cases it is expected that the macro only affects a single
module, and the author knows what he/she is doing, so no guarantees on
binary compatibility required.

>>     Whether these macros generate any log output is controlled in a two-stage
>>     process.
>>
>>     First, at compile time the macro SAL_LOG_LEVEL controls whether these macros
>>     expand to actual code, or to no-ops.  SAL_LOG_LEVEL must expand to an
>>     integral value 0, 1, or 2.
>>
>>     If SAL_LOG_LEVEL is 0, neither the INFO nor the WARN macros produce code.
>>     If SAL_LOG_LEVEL is 1, only the WARN macros produce code.  If SAL_LOG_LEVEL
>>     is 2, both the INFO and the WARN macros produce code.

hmmm... i wonder if it makes sense to not distinguish between warnings
and info at compile-time (given that it is only active on debug builds
anyway), so it is not required to recompile a module to get full debug
output...

>>     Second, at runtime the environment variable SAL_LOG further limits which
>>     macro calls actually generate log output.  The environment varialbe SAL_LOG
>>     must either be unset or must match the regular expression

>>     If the environment variable is unset, "+WARN" is used instead (which results
>>     in all warnings being output but no infos).  If the given value does not
>>     match the regular expression, "+INFO+WARN" is used instead (which in turn
>>     results in everything being output).

... with the runtime default being to output only warnings, as above.

>>     A given macro call's level (INFO or WARN) and area is matched against the
>>     given switches as follows:  Only those switches for which the level matches
>>     the given level and for which the area is a prefix (including both empty and
>>     full prefixes) of the given area are considered.  Log output is generated if
>>     and only if among the longest such switches (if any), there is at least one
>>     that has a sense of "+".  (That is, if both +WARN.foo and -WARN.foo are
>>     present, +WARN.foo wins.)
>>
>>     For example, if SAL_LOG is "+INFO-INFO.foo+INFO.foo.bar", then calls like
>>     SAL_INFO("foo.bar", ...), SAL_INFO("foo.bar.baz", ...), or
>>     SAL_INFO("other", ...) generate output, while calls like
>>     SAL_INFO("foo", ...) or SAL_INFO("foo.barzzz", ...) do not.

(de-)activating by module is very useful, as everybody who has been
overwhelmed by the full debug output from e.g. sal would probably agree...

in summary, sounds like a good plan :)