subject:"\[Libreoffice\] Assertions and Logging"


On 11/23/2011 10:05 AM, Miklos Vajna wrote:

Then forget the patch, all we need is to update
http://wiki.documentfoundation.org/Development/How_to_debug#Useful_macros
to reflect that now SAL_LOG controls OSL_TRACE messages, not dbglevel
1.


Thanks for the pointer.  I will update that wiki page.

Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

On 11/22/2011 10:50 AM, Stephan Bergmann wrote:

I pushed the proposed changes as
http://cgit.freedesktop.org/libreoffice/core/commit/?id=70a6b9ffbd676a1384433a86205d2cd4f2d4f4b1
and
http://cgit.freedesktop.org/libreoffice/binfilter/commit/?id=d45d5ee81e3d3f1779774af3f400ce3f1aa6697d.
Any further refinements (where to send the log output, performance
considerations) can carry on from there.

Based on Lubos's comments, I changed this once again, incompatibly:

* sal/log.h is now sal/log.hxx, and can thus only be used from C++ code.
If we need it in a file that is still C, change that file to C++
first. (I see almost no need for any pure C files in LO at all. That
many implementation files in, e.g., sal are written in C is a historic
relic that can and should be fixed; I already did that recently for
sal/source/rtl. The stable C header files in the URE interface are a
different thing, of course.)

* The _S suffix is dropped from the logging macros using streaming, and
the format-string variants are gone. A compile time check ensures the
common case of streaming just a plain C-style string literal still
produces reasonably compact call-site code.

* The format-string variants are still available in sal/detail/log.h,
but only to be used in obsolete osl/diagnose.h etc., and going to be
removed again eventually.

I noticed this change will break non-clean builds in odk, cd odk rm
-rf ${INPATH?} should help.

Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging


On 11/22/2011 06:53 PM, Lubos Lunak wrote:

On Tuesday 22 of November 2011, Stephan Bergmann wrote:

On 11/22/2011 05:17 PM, Lubos Lunak wrote:

   Does it really matter, when it is used only in debug builds anyway?
Debug builds are slower already anyway, and if the cost of generating the
output is considered expensive, what about the cost of wherever the
output will end up?


While the macros are currently only enabled in debug builds, I see no
reason that should always be so.  A production build from which one can
extract such logging information would be quite useful, I think.  So I
designed the macros with that in mind.


  I still don't think that changes much. If the output is already generated, it
will end up somewhere, and that's either /dev/null, in which case the
generation should not be enabled at all, or it's some terminal, where the
cost of scrolling, displaying, etc. is much higher than just some string
creation, or it's some log file, which involves system buffers, writing to
disk, etc. and that is again more expensive. We could probably make each of
the output calls solve a random sudoku just for the fun of it and it wouldn't
make a noticeable difference :). This usage would need at least the part for
deciding whether to generate any output to be cheap though.


I was more concerned about call-site code size than run time.  Should 
have made that more clear.



The only problem with the S variants is the call-site bloat of creating
a std::ostringstream and piping into it, etc.  I don't see how that can
elegantly be avoided, though.


  If the std::stream stuff is really that heavy, then we don't necessarily need
to use it (although I admit that this may not fit the above requirement if
doing the work of using something else is considered not elegant). The stream
  foo style does not mandate using std::stream, e.g. QDebug [*] uses this
style too. And this could be done later, if it actually is needed. I think
it's better to start with good API and possibly fix the performance later
rather than start with good performance and fix the API later.


Yes, replacing std::ostringstream with something else would remain an 
option if need be.



  As for the plain string case being fast, maybe that could be achieved using
an overload (or template) with std::stream and const char*.


I achieved it with some compile-time template programming now, see my 
other mail.


Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging


On 11/22/2011 06:01 PM, Norbert Thiebaud wrote:

Well,
first I do like the ability to use these kind of infrastructures even
on release code...


...which I was careful to keep in mind while designing the interface. 
But for the implementation, I kept it as simple as possible for now.



you'd need more level, but having a INFO or VERBOSE mode that survive


Not sure whether we really need more levels.  (I note that all the 
elaborate logging facilities do have lots of levels, but that somehow 
leaves me unconvinced.)  Lets see.



Second, static data is a problem, as is initialize-once data in a
multi-threaded world.


humm ?? initialize _before_ getting to the multithreaded part.


which a *library* like sal cannot do


I'm not arguing against the format of the configuration, but against
the delayed-parsing repeated for each and every log message.
(which is pointless since you use an env-variable so it is an
execution-invariant -- unless you are thinking about adding a
uno-service to change it on the fly ;-) )


Honestly, I am not worried about the performance of the current 
implementation at all.  If it should ever become a bottleneck (esp. if 
we ever decide to enable logs in production builds), we could rather 
easily improve it (though by adding complexity), without (that's my hope 
having designed it that way) having to modify the interface.


Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-23 Thread Norbert Thiebaud

On Wed, Nov 23, 2011 at 9:24 AM, Stephan Bergmann sberg...@redhat.com wrote:
 Second, static data is a problem, as is initialize-once data in a
 multi-threaded world.

 humm ?? initialize _before_ getting to the multithreaded part.

 which a *library* like sal cannot do

who said that sal has to auto-initialized the service.

main() explicitly call sal_init_trace_services(char*
log_env_descrition) (or whatever) and store the resulting array of
logging context in a globally visible variable that the tracing macro
can use.


 I'm not arguing against the format of the configuration, but against
 the delayed-parsing repeated for each and every log message.
 (which is pointless since you use an env-variable so it is an
 execution-invariant -- unless you are thinking about adding a
 uno-service to change it on the fly ;-) )

 Honestly, I am not worried about the performance of the current
 implementation at all.  If it should ever become a bottleneck (esp. if we
 ever decide to enable logs in production builds), we could rather easily
 improve it (though by adding complexity), without (that's my hope having
 designed it that way) having to modify the interface.

If you use a string as a trace-selector you will never get something
with performance good-enough for release code.
you need a numeric level and a numeric module/feature selector.

You need a system so that when the trace are not wanted a trace-point
cost a couple of integer testing at worse. you can't take a call, you
cant' have to construct arguments for the call,
you certainly can't have c++ object instantiation/clone/copy etc...

Norbert
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging


On 11/23/2011 05:04 PM, Norbert Thiebaud wrote:

On Wed, Nov 23, 2011 at 9:24 AM, Stephan Bergmannsberg...@redhat.com  wrote:
who said that sal has to auto-initialized the service.

main() explicitly call sal_init_trace_services(char*
log_env_descrition) (or whatever) and store the resulting array of
logging context in a globally visible variable that the tracing macro
can use.


sure; see my though by adding complexity parenthetical remark below


Honestly, I am not worried about the performance of the current
implementation at all.  If it should ever become a bottleneck (esp. if we
ever decide to enable logs in production builds), we could rather easily
improve it (though by adding complexity), without (that's my hope having
designed it that way) having to modify the interface.


If you use a string as a trace-selector you will never get something
with performance good-enough for release code.
you need a numeric level and a numeric module/feature selector.

You need a system so that when the trace are not wanted a trace-point
cost a couple of integer testing at worse. you can't take a call, you
cant' have to construct arguments for the call,
you certainly can't have c++ object instantiation/clone/copy etc...


numbers, please  :)

Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-23 Thread Norbert Thiebaud

On Wed, Nov 23, 2011 at 10:12 AM, Stephan Bergmann sberg...@redhat.com wrote:

 If you use a string as a trace-selector you will never get something
 with performance good-enough for release code.
 you need a numeric level and a numeric module/feature selector.

 You need a system so that when the trace are not wanted a trace-point
 cost a couple of integer testing at worse. you can't take a call, you
 cant' have to construct arguments for the call,
 you certainly can't have c++ object instantiation/clone/copy etc...

 numbers, please  :)

Seriously ? you need 'numbers' to be convinced that

b == 10

is more performant than (excerpt, not taking into account a couple of
epilogue/prologue among other things...)

for (char const * p = env;;) {
Sense sense;
switch (*p++) {
case '\0':
return senseLen[POSITIVE] = senseLen[NEGATIVE];
// if a specific item is both postiive and negative
// (senseLen[POSITIVE] == senseLen[NEGATIVE]), default to
// positive
case '+':
sense = POSITIVE;
break;
case '-':
sense = NEGATIVE;
break;
default:
return true; // upon an illegal SAL_LOG value, enable everything
}
char const * p1 = p;
while (*p1 != '.'  *p1 != '+'  *p1 != '-'  *p1 != '\0') {
++p1;
}
bool match;
if (equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM(INFO))) {
match = level == SAL_DETAIL_LOG_LEVEL_INFO;
} else if (equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM(WARN)))
{
match = level == SAL_DETAIL_LOG_LEVEL_WARN;
} else {
return true;
// upon an illegal SAL_LOG value, everything is considered
// positive
}
char const * p2 = p1;
while (*p2 != '+'  *p2 != '-'  *p2 != '\0') {
++p2;
}
if (match) {
if (*p1 == '.') {
++p1;
std::size_t n = p2 - p1;
if ((n == areaLen  equalStrings(p1, n, area, areaLen))
|| (n  areaLen  area[n] == '.'
 equalStrings(p1, n, area, n)))
{
senseLen[sense] = p2 - p;
}
} else {
senseLen[sense] = p1 - p;
}
}
p = p2;
}

at the very least: restrict the 'area' variable (the one that limit
base on module/feature) in the use-call to be something that could be
part of a variable/constant name
and use the #foo preprocesor to keep it string for now.

#define log(level, area, xxx...)  _log(level, #area, xxx...)

that way at least we will be able to use a numeric value on day,
without having to change every use point
something like
#define log(level, area, xxx...) _log(level, SAL_AREA_ID ## area, xxx)

Norbert
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging


On 11/23/2011 05:36 PM, Norbert Thiebaud wrote:

Seriously ? you need 'numbers' to be convinced that

b == 10

is more performant than (excerpt, not taking into account a couple of
epilogue/prologue among other things...)

[...]

Yes, I need numbers to be convinced that the difference is of practical 
relevance.



at the very least: restrict the 'area' variable (the one that limit
base on module/feature) in the use-call to be something that could be
part of a variable/constant name
and use the #foo preprocesor to keep it string for now.

#define log(level, area, xxx...)  _log(level, #area, xxx...)

that way at least we will be able to use a numeric value on day,
without having to change every use point
something like
#define log(level, area, xxx...) _log(level, SAL_AREA_ID ## area, xxx)


While a central registry of such defines could be useful also for 
consistency and to avoid typos, it is the very central registry aspect 
that makes it look unattractive to me.


Also, how bad will the current scheme necessarily be in practice? 
Whether to enable any output at all from any SAL_INFO or SAL_WARN, 
resp., can be decided cheaply.  Only if you enable output from, say, 
SAL_INFO and want to further restrict it on area, *each* call to 
SAL_INFO will incur an overhead.  But what are the use cases?  For 
developers' debug builds, all of this will be rather irrelevant.  For 
production builds, my assumption is they would routinely log either 
nothing at all or *all* SAL_WARNs.  So only if a user would explicitly 
enable certain area-restricted SAL_INFOs (to find out more about a 
reproducible problem he experiences) would the decision to represent 
areas as strings necessarily have negative consequences (which IMO would 
again be tolerable in that special scenario).


Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-23 Thread Norbert Thiebaud

While a central registry of such defines could be useful also for consistency 
and to avoid typos, it is the very central registry aspect that makes it 
look unattractive to me.

Sure, but at least the technic I mentionned would allow for us to
_choose_ one way or another
If you stick with string as the area argument, the barrier to change
to a central repository will be so high as to insure that it will
indeed never happen.



  For production builds, my assumption is they would
 routinely log either nothing at all or *all* SAL_WARNs.  So only if a user
 would explicitly enable certain area-restricted SAL_INFOs (to find out more
 about a reproducible problem he experiences) would the decision to represent
 areas as strings necessarily have negative consequences (which IMO would
 again be tolerable in that special scenario).

This is a self fulling prophecy. beside in order to exclude them all
you still need to parse your env variable no?
so sure the parsing will be (relatively) fast... but you still get a
couple of prologue, epilogue, a couple of variable initialization, a
get_env
so a no-op operation is still 100x more instructions than necessary.

actually reading the code if env = NULL you force it to +WARN and then
go ahead an parse it...:-(


Note that this discussion is orthogonal to whether to use fprintf or
something more c++ friendly. I don;t care too much about that since
once the decision is made to actually do the trace I don't care as
much about performance... it is going to be slow either way...
What I care about is that we can use that facility quite liberaly with
the knowledge that as long as you are not actually taking the trace
the cost is minimal.

To that extend, pushing as much or the complexity to the init function
and make the wrapper that trigger the trace as lightweight as possible
is desirable.

Note that I'm arguing from a position where I'd like to have such
facility cheap and usable in release build.. this is above and beyond
what we currently have.

Norbert





 ___
 LibreOffice mailing list
 LibreOffice@lists.freedesktop.org
 http://lists.freedesktop.org/mailman/listinfo/libreoffice

___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

I pushed the proposed changes as 
http://cgit.freedesktop.org/libreoffice/core/commit/?id=70a6b9ffbd676a1384433a86205d2cd4f2d4f4b1 
and 
http://cgit.freedesktop.org/libreoffice/binfilter/commit/?id=d45d5ee81e3d3f1779774af3f400ce3f1aa6697d. 
 Any further refinements (where to send the log output, performance 
considerations) can carry on from there.


I added a short summary as 
https://wiki.documentfoundation.org/Development#Assertions_and_Logging; feel 
free to expand.  I also filed easy hack 
https://bugs.freedesktop.org/show_bug.cgi?id=43157 Clean up 
OSL_ASSERT, DBG_ASSERT, etc.  As already discussed, if any uses of the 
obsolete functionality still remains after a while, I would initiate a 
mass-conversion OSL_ASSERT-SAL_WARN, OSL_TRACE-SAL_INFO, etc.


I made a few further changes to the proposed patches when I pushed them:

- DBG_ASSERT etc. from tools/debug.hxx still are only enabled depending 
on DBG_UTIL.  Trying an --enable-debug --disable-dbgutil build, it broke 
at many places that #ifdef DBG_UTIL some code that is later used within 
a DBG_ASSERT (e.g., an additional variable capturing some old value, 
modified later and checked afterwards, or a function parameter name that 
is only used within a DBG_ASSERT).  This is a lot of work to clean up 
(see the easy hack above).


- I replaced the single SAL_LOG_LEVEL (with values 0, 1, 2) with 
individual defines SAL_LOG_INFO and SAL_LOG_WARN.  This makes it easier 
to replace the code mentioned above, going from


  #ifdef DBG_UTIL
int old = x;
  #endif
... // modify x
DBG_ASSERT(x  old);

to

  #if defined SAL_LOG_WARN // instead of: SAL_LOG_LEVEL = 1
int old = x;
  #endif
.. // modify x
SAL_WARN_IF(x = old, ...);

(Where for such a cheap initialization like int old = x; it would also 
work to have that variable included unconditionally, followed by a 
(void) old; // avoid warnings; but there are also cases of more 
expensive initialization, that you would likely want to keep excluded 
from production builds.)


- The SAL_INFO/WARN messages are now defined to be always UTF-8, and 
rtl/oustringostreaminserter.hxx always converts to UTF-8.  That 
minimizes information loss and would potentially enable use of 
SAL_STREAM for construction of UNO exception messages, see the recent 
thread about that.  However, I do not bother to convert the data output 
to stderr from UTF-8 to any other encoding.


Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-22 Thread Bjoern Michaelsen

Hi,

On Fri, Nov 18, 2011 at 03:25:16PM +0100, Stephan Bergmann wrote:
 For one, there are two sets of functionality that cater for the same
 needs.  One is osl/diagnose.h, the other is tools/debug.hxx.

There is also 3/4 of a log4j reimplementation in extensions/source/logging.
Just saying ...

Best,

Bjoern
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-22 Thread 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

Re: [Libreoffice] Assertions and Logging

2011-11-22 Thread Bjoern Michaelsen

Hi Michael, Stephan, all,

On Tue, Nov 22, 2011 at 12:46:52PM +0100, Michael Stahl wrote:
 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.

Full agreement here.

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

A bit of digging in gits history shows that to be a blunt removal commit of
DBG_UTIL in sw in 2010. I cant make any sense of it, as it completly broke non
DBG_UTIL debug builds for no gain. Can anyone enlighten me on this?

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

Agree. The only valid reason for not having all debug tools compiled in is
runtime performance and binary size. Once you are debugging those are mostly
irrelevant.

 in summary, sounds like a good plan :)

yep.

Best,

Bjoern
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging


On 11/22/2011 11:55 AM, Bjoern Michaelsen wrote:

There is also 3/4 of a log4j reimplementation in extensions/source/logging.
Just saying ...


Yes, based on com.sun.star.logging UNO interfaces and 
comphelper/logging.hxx wrapper.  Apparently only sparingly used, in 
connectivity and package/source/xstor.  Needs revisiting, whether its 
few uses should be changed to use sal/log.h instead, or whether there is 
indeed demand for some higher-level logging facilities (being based on 
UNO makes it unsuitable for many places in the code base).


Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-22 Thread Tor Lillqvist

 Agree. The only valid reason for not having all debug tools compiled in is
 runtime performance and binary size.

Which brings up the question: Should my attempts to use the MSVC
debugging runtime (and debug code in its headers, i.e. -D_DEBUG) when
using --enable-dbgutil be reverted? It currently is not possible to
build that way anyway, you get compilation errors. I spent some weeks,
on and off, trying to get rid of those, but finally gave up. Or does
somebody else feel like continuing?

--tml
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-22 Thread Bjoern Michaelsen

On Tue, Nov 22, 2011 at 01:50:24PM +0100, Stephan Bergmann wrote:
 Yes, based on com.sun.star.logging UNO interfaces and
 comphelper/logging.hxx wrapper.  Apparently only sparingly used, in
 connectivity and package/source/xstor.
... and the now dormant Usage Tracking.

 Needs revisiting, whether its few uses should be changed to use sal/log.h
 instead, or whether there is indeed demand for some higher-level logging
 facilities (being based on UNO makes it unsuitable for many places in the
 code base).

Right. Killing it off if it can be merged should be considered, which is why I
brought it up.

Best,

Bjoern
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-22 Thread Caolán McNamara

On Mon, 2011-11-21 at 17:53 +0100, Stephan Bergmann wrote:
 So, from a practical standpoint, failing smoketest on failed SAL_WARNs
 would be right.  On the other hand, there might be SAL_WARNs that
 legitimately fire during smoketest (a trivial example would be if we
 purposefully tested illegal input during smoketest),

Given the pain of getting the smoketest warning free, We could policy
that smoketest is warning free, while unit tests are ok to have
warnings, they should be encouraged to explore the edge-space where
warnings can be expected.

Only thing left unresolved from my perspective is whether warnings on
windows works.

C.

___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging


On 11/22/2011 03:05 PM, Caolán McNamara wrote:

Only thing left unresolved from my perspective is whether warnings on
windows works.


Maybe somebody using a Windows build could give input here, whether the 
current state works well enough?  (At least for a MinGW based one; given 
that configure currently rejects --enable-dbgutil for an MSVC based one 
I guess nobody cares for debug output for that configuration at the 
moment, anyway?)


Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-22 Thread Noel Grandin



Stephan Bergmann wrote:
 based one; given that configure currently rejects --enable-dbgutil for an 
 MSVC based one I guess nobody cares for
 debug output for that configuration at the moment, anyway?)

I think it's more a case of the Windows users struggling to get a basic build 
going reliably. Once that works we can
start adding the nice-to-haves :-)


Disclaimer: http://www.peralex.com/disclaimer.html


___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-22 Thread Michael Stahl

On 22/11/11 13:54, Tor Lillqvist wrote:
 Agree. The only valid reason for not having all debug tools compiled in is
 runtime performance and binary size.
 
 Which brings up the question: Should my attempts to use the MSVC
 debugging runtime (and debug code in its headers, i.e. -D_DEBUG) when
 using --enable-dbgutil be reverted? It currently is not possible to
 build that way anyway, you get compilation errors. I spent some weeks,
 on and off, trying to get rid of those, but finally gave up. Or does
 somebody else feel like continuing?

ah, you have disabled --enable-dbgutil altogether for MSVC?
that seems like throwing out the proverbial baby with the bathwater.

if the MSVC debug stuff is indeed too difficult, then just comment it
out, put in a comment that says FIXME, and re-enable the
--enable-dbgutil stuff, that way windows devs at last get some
assertions and internal consistency checks.

regards,
 michael

___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-22 Thread Tor Lillqvist

 if the MSVC debug stuff is indeed too difficult, then just comment it
 out, put in a comment that says FIXME, and re-enable the
 --enable-dbgutil stuff, that way windows devs at last get some
 assertions and internal consistency checks.

But you can't build it with --enable-dbgutil ... configure.in says:

# Compiling with MSVC using --enable-dbgutil (i.e. using the
# debugging runtime, and defining _DEBUG when compiling) just
# causes too many compilation errors. After having spent some
# months slowly fixing them one by one, having reached sw, I give
# up. Feel free to try again.

--tml
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-22 Thread Lubos Lunak


 First of all: I see this has been already committed, after giving people only 
slightly more than the weekend and the day after it to react, which I 
consider too short for something with as large scope as this. Some of us 
don't work on the weekends and have a backlog when they come back on Monday.

On Friday 18 of November 2011, Stephan Bergmann wrote:
...
 - The implementation is somewhat careful to produce as little code as
 possible at the call-site of the new macros, and to keep the code path
 for suppressed logs as short as possible.  However, the C++-stream-style
 macros will potentially always be more expensive than the
 C-printf-format-style ones.

 Does it really matter, when it is used only in debug builds anyway? Debug 
builds are slower already anyway, and if the cost of generating the output is 
considered expensive, what about the cost of wherever the output will end up?

 One open question is which set of macros (the C-printf-format-style ones
 or the C++-stream-style ones) to give the natural names without
 additional suffix.

 IMO that is a rather simpler decision: The natural names should be used by 
the only set that exists, for a number of reasons:
- the C variants don't work with C++ strings (or other non-trivial data), 
which makes them next to useless
- this is debug code, so the slight performance cost is negligible
- where do we have non-C++ code that has actually needs to use this 
functionality and cannot just have the filename extension changed?
- people will mix the two sets randomly, with all the consequences (mess, 
wondering when to use which one)
- the _S suffix is ugly and it is the variant that'll eventually be used more
- if there are any (real) problems with the C++ variant, perhaps they should 
be simply rather fixed/improved
- WTH should we intentionally have two sets of one functionality again?

-- 
 Lubos Lunak
 l.lu...@suse.cz
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-22 Thread Norbert Thiebaud

On Tue, Nov 22, 2011 at 1:41 AM, Stephan Bergmann sberg...@redhat.com wrote:
 On 11/22/2011 06:35 AM, Norbert Thiebaud wrote:

 The run tine flexibility is a great feature, but the proposed
 implementation is scary perf-wise

 I kept the implementation simplistic on purpose.  First, remember that
 logging (at least for now) is only enabled in debug/dbgutil builds, and that
 the SAL_LOG environment variable will have a rather short value most of the
 time (the default is just +WARN).  Beware premature optimization.

Well,
first I do like the ability to use these kind of infrastructures even
on release code...
you'd need more level, but having a INFO or VERBOSE mode that survive
in release code can be quite
useful. You could imagine having the ability to collect trace, on the
user machine, about what dll got dlopen, when and from where,
about access to the user profile, which Registry was access what was
the value, etc...

But that can't be even considered if the system does not have a cost
~0 when the traces are inactive.

second: even parsing +WARN is a couple of order of magnitude (at
least) more expensive than 'if (lvl = integer_constant)'
especially since, in order to get the parsing done, you need to have
all the argument of the log function evaluated and the call made.
in C++ that can easily mean, depending on the argument passed, object
creation + copy, etc...



 Second, static data is a problem, as is initialize-once data in a
 multi-threaded world.

humm ?? initialize _before_ getting to the multithreaded part.
Initialization only require getenv and parsing a string... it surely
does not require a large infrastructure, so you do that
as the first thing of main(), before anything get spinned out.
Beside the state-array is a compile-time constant size (depending only
on the defines that assign module_id. all you need is a MAX_MODULE_ID
and that
array is pre-initialized with 0 content. which happen to mean no-log.

  To properly initialize it you need synchronization
 mechanisms, which are either platform specific or need to use osl/mutex.h,
 which in turn is undesirable.  Avoid the use of other sal code in this file
 as much as possible, so that this code can be called from other sal code
 without causing endless recursion.  I already felt uneasy enough adding
 OSL_DETAIL_GETPID.

if you test up front, for log message, in a macro, before getting in
the formatting and all, you do not have any recursion.
If you call too early (before the setup is done/finished) these log
message are just not triggered.


 Third, free-form string area codes are indeed not optimal.  But I fear typos
 here more than I fear performance problems.  And their advantage is that
 they need zero centralized configuration.

I'm not arguing against the format of the configuration, but against
the delayed-parsing repeated for each and every log message.
(which is pointless since you use an env-variable so it is an
execution-invariant -- unless you are thinking about adding a
uno-service to change it on the fly ;-) )


Norbert
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging


On 11/22/2011 05:17 PM, Lubos Lunak wrote:

  First of all: I see this has been already committed, after giving people only
slightly more than the weekend and the day after it to react, which I
consider too short for something with as large scope as this. Some of us
don't work on the weekends and have a backlog when they come back on Monday.


I did not commit it in order to stop any discussion.  Sorry if it looked 
that way.  Rather, as I did not get any totally disagreeing reactions, I 
thought it would be easier to polish this further if the code is 
actually in.  (And I think it was a good decision to commit it early; 
naturally, the various tinderboxes pointed me to some flaws that were 
still in.)



On Friday 18 of November 2011, Stephan Bergmann wrote:
...

- The implementation is somewhat careful to produce as little code as
possible at the call-site of the new macros, and to keep the code path
for suppressed logs as short as possible.  However, the C++-stream-style
macros will potentially always be more expensive than the
C-printf-format-style ones.


  Does it really matter, when it is used only in debug builds anyway? Debug
builds are slower already anyway, and if the cost of generating the output is
considered expensive, what about the cost of wherever the output will end up?


While the macros are currently only enabled in debug builds, I see no 
reason that should always be so.  A production build from which one can 
extract such logging information would be quite useful, I think.  So I 
designed the macros with that in mind.



One open question is which set of macros (the C-printf-format-style ones
or the C++-stream-style ones) to give the natural names without
additional suffix.


  IMO that is a rather simpler decision: The natural names should be used by
the only set that exists, for a number of reasons:
- the C variants don't work with C++ strings (or other non-trivial data),
which makes them next to useless
- this is debug code, so the slight performance cost is negligible


See above.  I think its important to keep the most common case (the log 
message can be expressed as a static C literal) cheap.



- where do we have non-C++ code that has actually needs to use this
functionality and cannot just have the filename extension changed?


Of course, if works in C were the only reason for the non-S variant, 
we could change existing C files into C++ ones as a prerequisite for 
adapting them to sal/log.h.  (And changing them is a useful exercise 
regardless, anyway.)


Maybe it would make sense to simplify the non-S variants so that they 
only work with a plain string, removing the printf-style format feature. 
 But that would mean some work, adapting the existing uses of OSL_TRACE 
that depend on that feature.



- people will mix the two sets randomly, with all the consequences (mess,
wondering when to use which one)
- the _S suffix is ugly and it is the variant that'll eventually be used more
- if there are any (real) problems with the C++ variant, perhaps they should
be simply rather fixed/improved


The only problem with the S variants is the call-site bloat of creating 
a std::ostringstream and piping into it, etc.  I don't see how that can 
elegantly be avoided, though.



- WTH should we intentionally have two sets of one functionality again?


Yeah, I get your point.

Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-22 Thread Lubos Lunak

On Tuesday 22 of November 2011, Stephan Bergmann wrote:
 On 11/22/2011 05:17 PM, Lubos Lunak wrote:
...
 I did not commit it in order to stop any discussion.  Sorry if it looked
 that way.  Rather, as I did not get any totally disagreeing reactions, I
 thought it would be easier to polish this further if the code is
 actually in.  (And I think it was a good decision to commit it early;
 naturally, the various tinderboxes pointed me to some flaws that were
 still in.)

 Well, ok, what I had in mind was you having to rework what has been already 
committed in a case somebody points out something that requires extensive 
changes (or the possibility of it's already in being used as an argument 
against the changes), but if you see it this way, fair enough.

Does it really matter, when it is used only in debug builds anyway?
  Debug builds are slower already anyway, and if the cost of generating the
  output is considered expensive, what about the cost of wherever the
  output will end up?

 While the macros are currently only enabled in debug builds, I see no
 reason that should always be so.  A production build from which one can
 extract such logging information would be quite useful, I think.  So I
 designed the macros with that in mind.

 I still don't think that changes much. If the output is already generated, it 
will end up somewhere, and that's either /dev/null, in which case the 
generation should not be enabled at all, or it's some terminal, where the 
cost of scrolling, displaying, etc. is much higher than just some string 
creation, or it's some log file, which involves system buffers, writing to 
disk, etc. and that is again more expensive. We could probably make each of 
the output calls solve a random sudoku just for the fun of it and it wouldn't 
make a noticeable difference :). This usage would need at least the part for 
deciding whether to generate any output to be cheap though.

 Maybe it would make sense to simplify the non-S variants so that they
 only work with a plain string, removing the printf-style format feature.
   But that would mean some work, adapting the existing uses of OSL_TRACE
 that depend on that feature.

 That looks like a good reason to keep the printf variant, but not as the 
primary one.

 The only problem with the S variants is the call-site bloat of creating
 a std::ostringstream and piping into it, etc.  I don't see how that can
 elegantly be avoided, though.

 If the std::stream stuff is really that heavy, then we don't necessarily need 
to use it (although I admit that this may not fit the above requirement if 
doing the work of using something else is considered not elegant). The stream 
 foo style does not mandate using std::stream, e.g. QDebug [*] uses this 
style too. And this could be done later, if it actually is needed. I think 
it's better to start with good API and possibly fix the performance later 
rather than start with good performance and fix the API later.

 As for the plain string case being fast, maybe that could be achieved using 
an overload (or template) with std::stream and const char*.


[*] http://doc.qt.nokia.com/4.7/qdebug.html
-- 
 Lubos Lunak
 l.lu...@suse.cz
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-22 Thread Miklos Vajna

On Fri, Nov 18, 2011 at 03:25:16PM +0100, Stephan Bergmann 
sberg...@redhat.com wrote:
  #define OSL_DEBUG_ONLY(s)   _OSL_DEBUG_ONLY(s)
 -#define OSL_TRACE   _OSL_TRACE
 -#define OSL_ASSERT(c)   _OSL_ENSURE(c, OSL_THIS_FILE, __LINE__, 0)
 -#define OSL_ENSURE(c, m)   _OSL_ENSURE(c, OSL_THIS_FILE, __LINE__, m)
 -#define OSL_FAIL(m)_OSL_ENSURE(0, OSL_THIS_FILE, __LINE__, m)
 +#define OSL_TRACE(...) SAL_INFO(legacy.osl, __VA_ARGS__)
 +#define OSL_ASSERT(c) SAL_WARN_IF(!(c), legacy.osl, OSL_ASSERT)
 +#define OSL_ENSURE(c, m) SAL_WARN_IF(!(c), legacy.osl, %s, m)
 +#define OSL_FAIL(m) SAL_WARN_IF(sal_True, legacy.osl, %s, m)

Hi Stephan,

These changes cause that without an

export SAL_LOG=+INFO

former OSL_TRACE() messages do not show up on the console, even with
dbglevel=2.

I like that SAL_LOG can now filter SAL_INFO messages, but are you sure
it's a good idea to disable them all by default with dbglevel=2, instead
of enabling them by default (when SAL_LOG is not set), like it was
before?

IOW, is the attached patch OK?

Thanks.
diff --git a/sal/osl/all/log.cxx b/sal/osl/all/log.cxx
index be45cf6..9493715 100644
--- a/sal/osl/all/log.cxx
+++ b/sal/osl/all/log.cxx
@@ -84,7 +84,11 @@ bool report(sal_detail_LogLevel level, char const * area) {
 assert(area != 0);
 char const * env = std::getenv(SAL_LOG);
 if (env == 0) {
+#if OSL_DEBUG_LEVEL  1
+env = +INFO+WARN;
+#else
 env = +WARN;
+#endif
 }
 std::size_t areaLen = std::strlen(area);
 enum Sense { POSITIVE = 0, NEGATIVE = 1 };


pgpRbocu96Tmn.pgp
Description: PGP signature
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging


On 11/22/2011 11:50 PM, Miklos Vajna wrote:

These changes cause that without an

export SAL_LOG=+INFO

former OSL_TRACE() messages do not show up on the console, even with
dbglevel=2.

I like that SAL_LOG can now filter SAL_INFO messages, but are you sure
it's a good idea to disable them all by default with dbglevel=2, instead
of enabling them by default (when SAL_LOG is not set), like it was
before?

IOW, is the attached patch OK?


My understanding is as follows:

- There is a large number of OSL_TRACE calls all over the code base, 
producing large amounts of output at runtime.


- Nobody wants to see all that output at once.  People are generally 
only interested in the OSL_TRACE output from some specific module etc.


- For that, in the past it was necessary to recompile the relevant code 
with dbglevel=2.  Now, no recompilation is necessary any longer, you 
just need to add +INFO.area to SAL_LOG at runtime.


Your patch would imply that you either (a) routinely build the whole 
code base with dbglevel=2 (do you really do that? does the amount of 
resulting output not intimidate you?), or (b) need to recompile just sal 
with dbglevel=2 before automatically (without setting SAL_LOG) seeing 
any (but again, also all) OSL_TRACE output.


Is that really your use case?

Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-21 Thread Caolán McNamara

On Fri, 2011-11-18 at 15:25 +0100, Stephan Bergmann wrote:

Alright, so we end up with
use assert if you want an assert
SAL_WARN if you want to warn about something odd, but which isn't
necessarily definitely wrong
SAL_INFO for verbose logging

Practical question though, is on windows where does the output go ?

Should we write off all the DBG_ASSERTs as hopeless to unwind and mass
convert them all to SAL_WARNs ?

How do we feel about code that does e.g.

assert(pFoo);
if (!pFoo)
throw catchAbleFoo(wtf);

i.e. do we have a philosophical problem with gracefully/semi-gracefully
handing should-be impossible cases ?

C.

___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging


On 11/21/2011 01:30 PM, Caolán McNamara wrote:

On Fri, 2011-11-18 at 15:25 +0100, Stephan Bergmann wrote:

Alright, so we end up with
use assert if you want an assert
SAL_WARN if you want to warn about something odd, but which isn't
necessarily definitely wrong
SAL_INFO for verbose logging

Practical question though, is on windows where does the output go ?


SAL_INFO/WARN just go to stderr for now.  What should work to see them 
even for a gui soffice.exe is to add something like 2log.txt to the 
command line.  Not sure if there is enough of a Windows developer base 
that demands a more sophisticated solution?  (One could extend the 
SAL_LOG environment variable, so that a trailing file part would 
append the data to a given file, for example.  Or see to hook up Window' 
OutputDebugString.)



Should we write off all the DBG_ASSERTs as hopeless to unwind and mass
convert them all to SAL_WARNs ?


I would initially file an easy hack to do the conversion.  If that does 
not lead to clean-up in a reasonable time-frame, I would suggest to 
mass-convert the remainder to SAL_WARN.



How do we feel about code that does e.g.

assert(pFoo);
if (!pFoo)
 throw catchAbleFoo(wtf);

i.e. do we have a philosophical problem with gracefully/semi-gracefully
handing should-be impossible cases ?


I think that's a perversion, and should be avoided.  It the author could 
not convince himself that !pFoo is not impossible (modulo bugs), then he 
should use OSL_WARN instead.  If however he *is* convinced that !pFoo is 
impossible absent any bugs, but argues that if there *are* bugs, the 
added if statement adds some sort of safety, I would counter-argue that 
this alleged safety net pointlessly increases complexity and is probably 
full of holes and inconsistencies anyway (as it is likely an extremely 
untested code path).


Such defensive programming IMO would need to be architected into the 
code from the beginning.  It makes little sense to add such things 
locally just here and there.  And I'm not even convinced LO is an 
application for which an elaborate defensive programming architecture 
would be justified.  If there is a bug, crash early.  (One thing we 
could IMO improve though, is to not rely on trying to save open 
documents from within a signal handler, but instead rely on frequent 
auto-save and roll back to the last saved version after a crash.)


Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-21 Thread Terrence Enger

On Mon, 2011-11-21 at 14:30 +0100, Stephan Bergmann wrote:
   (One thing we 
 could IMO improve though, is to not rely on trying to save open 
 documents from within a signal handler, but instead rely on frequent 
 auto-save and roll back to the last saved version after a crash.)

Not disagreeing, but this would increase the fraction of the
time during which Writer, at least, ignores keystrokes.  If
you are looking at the screen when this happens, you just
wait for the autosave to finish and then carry on; if you
are looking at something else, you are faced later--for some
walue of later--with the challenge of trying to
reconstruct what you were thinking.

Terry.


___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging


On 11/21/2011 04:14 PM, Terrence Enger wrote:

On Mon, 2011-11-21 at 14:30 +0100, Stephan Bergmann wrote:

   (One thing we
could IMO improve though, is to not rely on trying to save open
documents from within a signal handler, but instead rely on frequent
auto-save and roll back to the last saved version after a crash.)


Not disagreeing, but this would increase the fraction of the
time during which Writer, at least, ignores keystrokes.  If
you are looking at the screen when this happens, you just
wait for the autosave to finish and then carry on; if you
are looking at something else, you are faced later--for some
walue of later--with the challenge of trying to
reconstruct what you were thinking.


True.  So an improvement probably better left for the hypothetical 
future where we have really fast save and/or save in the background.


Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-21 Thread Caolán McNamara

On Mon, 2011-11-21 at 14:30 +0100, Stephan Bergmann wrote:
 On 11/21/2011 01:30 PM, Caolán McNamara wrote:
  Practical question though, is on windows where does the output go ?
 
 SAL_INFO/WARN just go to stderr for now.  What should work to see them 
 even for a gui soffice.exe is to add something like 2log.txt to the 
 command line.  

oh, does that work ? I was labouring under the misunderstanding that we
closed those streams under windows, or something of that nature. I'm a
complete windows weenie.

 
  assert(pFoo);
  if (!pFoo)
   throw catchAbleFoo(wtf);
 
  i.e. do we have a philosophical problem with gracefully/semi-gracefully
  handing should-be impossible cases ?
 
 I think that's a perversion, and should be avoided.  It the author could 
 not convince himself that !pFoo is not impossible (modulo bugs), then he 
 should use OSL_WARN instead.  If however he *is* convinced that !pFoo is 
 impossible absent any bugs, but argues that if there *are* bugs, the 
 added if statement adds some sort of safety,

I have no strong feelings either way, but might as well agree now while
we can. So the plan is that asserts are for 100% can never happen
things. So that would suggest that anything which might fail for
external reasons is not a candidate for assert.

oslModule hModule= osl_loadModule( foo );
assert(hModule)
if (!hModule)
throw bar;

is wrong, because foo might not exist if some member of the lunatic
fringe deleted some .sos out of his install. Or more fairly, his distro
tried to split up packages into subpackages and mis-categorized one of
them.

In which case, we should use SAL_WARN to indicate its an unlikely and
suspicious event. So do we then consider SAL_WARNs as failures from the
perspective of e.g. the smoketest where we can argue reasonably that
we're in a controlled environment and nothing unusual should occur ?

C.

___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-21 Thread Michael Meeks


On Mon, 2011-11-21 at 16:23 +0100, Stephan Bergmann wrote:
 True.  So an improvement probably better left for the hypothetical 
 future where we have really fast save and/or save in the background.

Of course; in a world of interactive co-editing; we should really
stream everything people edit to a journal file using that serialisation
 then replay it when we re-start ;-) [ and then kill autosave
altogether ].

But that of course requires rather more work.

 (One thing we could IMO improve though, is to not rely on trying to
 save open documents from within a signal handler, but instead rely on
 frequent auto-save and roll back to the last saved version after a
 crash.)

Until then, I think we need to stick with the signal handler, sadly, it
is truly ugly, and I assume it can deadlock too if the signal happens at
certain places wrt. holding mutex', remarkably few posix calls are
signal-safe.

HTH,

Michael.

-- 
michael.me...@suse.com  , Pseudo Engineer, itinerant idiot

___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging


On 11/21/2011 04:50 PM, Michael Meeks wrote:

Until then, I think we need to stick with the signal handler, sadly, it
is truly ugly, and I assume it can deadlock too if the signal happens at
certain places wrt. holding mutex', remarkably few posix calls are
signal-safe.


One indeed occasionally observes hanging crashes or crashes within 
crashes caused by the illegal activities we start off the signal handler.


Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging


On 11/21/2011 04:42 PM, Caolán McNamara wrote:

On Mon, 2011-11-21 at 14:30 +0100, Stephan Bergmann wrote:

On 11/21/2011 01:30 PM, Caolán McNamara wrote:

Practical question though, is on windows where does the output go ?


SAL_INFO/WARN just go to stderr for now.  What should work to see them
even for a gui soffice.exe is to add something like 2log.txt to the
command line.


oh, does that work ? I was labouring under the misunderstanding that we
closed those streams under windows, or something of that nature. I'm a
complete windows weenie.


I remember it at least used to work even with 4NT back in those days 
(the supported syntax there was the csh , IIRC).  No idea whether we 
started to close stderr for some reason since then, though.



assert(pFoo);
if (!pFoo)
  throw catchAbleFoo(wtf);

i.e. do we have a philosophical problem with gracefully/semi-gracefully
handing should-be impossible cases ?


I think that's a perversion, and should be avoided.  It the author could
not convince himself that !pFoo is not impossible (modulo bugs), then he
should use OSL_WARN instead.  If however he *is* convinced that !pFoo is
impossible absent any bugs, but argues that if there *are* bugs, the
added if statement adds some sort of safety,


I have no strong feelings either way, but might as well agree now while
we can. So the plan is that asserts are for 100% can never happen
things. So that would suggest that anything which might fail for
external reasons is not a candidate for assert.

oslModule hModule= osl_loadModule( foo );
assert(hModule)
if (!hModule)
 throw bar;

is wrong, because foo might not exist if some member of the lunatic
fringe deleted some .sos out of his install. Or more fairly, his distro
tried to split up packages into subpackages and mis-categorized one of
them.


Yes, that's my model, too.  Even if missing/corrupted files that belong 
to the installation are somewhat more on the scale towards cannot 
happen than, say, trying to read malformed .odt files, they still 
represent external errors, not logic programming errors.


It would be good if such impossible to proceed situations would lead 
to uncaught exceptions (which is IMO acceptable in case of a fucked up 
installation) or clear error messages from within LO (this 
functionality is unavailable (detailed error message: ...)), instead of 
LO silently doing nothing (as is so often the case today, e.g., when you 
choose a menu item that triggers functionality that requires Java, and 
you don't have a JVM).



In which case, we should use SAL_WARN to indicate its an unlikely and
suspicious event. So do we then consider SAL_WARNs as failures from the
perspective of e.g. the smoketest where we can argue reasonably that
we're in a controlled environment and nothing unusual should occur ?


I'm somewhat undecided here.  The smoketest used to fail on OSL_ASSERTs 
(at least partly motivated by the assumption that OSL_ASSERTs represent 
true assertions; even if that assumption was false, the OSL_ASSERTs that 
did fire during smoketest were generally either true assertions that got 
fixed, or of informative nature and degraded to OSL_TRACE, IIRC).  I 
think I effectively removed that with my patch (it still fails for true 
asserts that abort now, of course), but intended to revisit that.  On 
the one hand, your rationale is probably true that SAL_WARNs probably 
always indicate severe enough problems that they would not normally fire 
in the controlled environment of smoketest.  So, from a practical 
standpoint, failing smoketest on failed SAL_WARNs would be right.  On 
the other hand, there might be SAL_WARNs that legitimately fire during 
smoketest (a trivial example would be if we purposefully tested illegal 
input during smoketest), so from a theoretical standpoint failing 
smoketest on failed SAL_WARNs would be wrong.  But I think I'll stick 
with the practical standpoint for now (if only since its easier to 
eventually change from a failing smoketest to one that ignores SAL_WARNs 
than vice versa).


Stephan
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-21 Thread Kevin Hunter


At 11:53am -0500 Mon, 21 Nov 2011, Stephan Bergmann wrote:

It would be good if such impossible to proceed situations would
lead to uncaught exceptions [...] or clear error messages from within
LO (this functionality is unavailable (detailed error message:
...)), instead of LO silently doing nothing (as is so often the case
today, e.g., when you choose a menu item that triggers functionality
that requires Java, and you don't have a JVM).


I'm not sure if that was a conclusion to this thread, but are we 
documenting this kind of decision in a concise format (and hopefully 
single page) on the wiki?  After a few minutes of looking, all I see is 
this page:


http://wiki.documentfoundation.org/Development#General_Programming_Guidelines

For us non-core folks who aren't able to follow every message, and new 
devs in general, having a page of LO coding style and various examples 
of what (not) to do would, at least for me, be very helpful.


Kevin
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-21 Thread Eike Rathke

Hi Stephan,

On Monday, 2011-11-21 17:53:42 +0100, Stephan Bergmann wrote:
 On 11/21/2011 04:42 PM, Caolán McNamara wrote:
 On Mon, 2011-11-21 at 14:30 +0100, Stephan Bergmann wrote:
 SAL_INFO/WARN just go to stderr for now.  What should work to see them
 even for a gui soffice.exe is to add something like 2log.txt to the
 command line.
 
 oh, does that work ? I was labouring under the misunderstanding that we
 closed those streams under windows, or something of that nature. I'm a
 complete windows weenie.
 
 I remember it at least used to work even with 4NT back in those days
 (the supported syntax there was the csh , IIRC).  No idea whether
 we started to close stderr for some reason since then, though.

From what I vaguely remember it is Windows that closes those streams for
GUI executables, at least if they point to a terminal, it might work if
redirected, don't know. In Windows builds there used to be
a solver/$INPATH/bin/guistd.com or some such that if copied to the path
of soffice.exe and renamed to soffice.com and invoked instead preserved
stdout/stderr streams. Maybe it's still built.

  Eike

-- 
LibreOffice Calc developer. Number formatter stricken i18n transpositionizer.
GnuPG key 0x293C05FD : 997A 4C60 CE41 0149 0DB3  9E96 2F1A D073 293C 05FD


pgpTUocl4DpsU.pgp
Description: PGP signature
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-21 Thread Tor Lillqvist

 From what I vaguely remember it is Windows that closes those streams for
 GUI executables,

Something like that, yes, although they are not closed in the sense
that they would first be open (inherited in the Unix sense); they
are never open in the first place in GUI executables, unless
explicitly redirected when creating the process (which the shell,
cmd.exe, does when you redirect input/out from/to a file/pipe). (HEre
I talk about the underlying Win32 file handles; the C library's file
descriptors, and the corresponding C++ streams probably *are* open,
even if connected to invalid file handles.)

 In Windows builds there used to be
 a solver/$INPATH/bin/guistd.com or some such that if copied to the path
 of soffice.exe and renamed to soffice.com and invoked instead preserved
 stdout/stderr streams. Maybe it's still built.

Not for soffice, there we just have soffice.exe and soffice.bin. But
for unopkg we deliver three different exectuables: unopkg.com,
unopkg.exe and unopkg.bin, which start each others in that order, if I
understand correctly.

Now, if I understand the purpose of the outermost wrapper, the
guistdio == unopkg.com thing, that is probably not needed any more on
modern Windowses (XP or later) as it is possible for a process to
attach to the console (think controlling terminal in Unix terms) of
the parent process, and thus acquire the possibility to reopen its
stdin/out/err to the paren't process's console. Look for documentation
for AttachConsole(ATTACH_PARENT_PROCESS).

--tml
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-21 Thread Norbert Thiebaud

On Mon, Nov 21, 2011 at 6:30 AM, Caolán McNamara caol...@redhat.com wrote:
 On Fri, 2011-11-18 at 15:25 +0100, Stephan Bergmann wrote:


 Practical question though, is on windows where does the output go ?

Actually I have a similar scheme for my own stuff, and I send the
output to program_pid.log in the current working directory. if the
current working directory is not writable, I send it to that same file
but in $TMP. For libreoffice an alternative could be the ~/.lo
directory or whatever the equivalent is on windows...

Note that using stderr/stdout may be a problem as that could interfere
with other stuff. on windows there is not always a Console associated
with the execution... and our codebase is also used for other, more
batch oriented piece of code... messing with stderr/stdout may
actually be a pain.

I also have mechnism so that if no message is written, the log file is
actually cleaned-up on termination. iow some kind a mechanism to avoid
these log file to polute too much (maybe a kind of 'clean on startup'
to get rid of old lingering log files)

The biggest issue on windows, is 'flush' (well that is a problem in C
because windows does not do signal handling... but with exception on
C++ maybe there is a way around that)

Norbert
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging

2011-11-21 Thread Norbert Thiebaud

On Fri, Nov 18, 2011 at 8:25 AM, Stephan Bergmann sberg...@redhat.com wrote:

    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

The run tine flexibility is a great feature, but the proposed
implementation is scary perf-wise

you don't want to re-parse the log-config at every log message.

You need to parse it once and for all... and not use string but enum
to identify the module/category you want to trace.

as a one-time steup cost you parse you env variable and initialize a
static array, which for each module/category contain the max
acceptable level of log
(0 = no log, 1=error, 2=warn, 3=info (4=debug?)

the test of log-ability should  be a simple if( array[module] =
level) and the macro writtin so that the no-trace path is as cheap as
possible.

To illustrate (this is for pure C where each 'module' actually have a
init_module function to dynamically register themselves to the tracing
system... that may not work nicely in c++ (ironically), but the
general gist is the same:

(excerpt)

header:

#define _msgs_out(rc) { msgs_trace_intern(%s -- 0x%x, __func__, rc);};
#define _msgs_cond(lvl) if((lvl = MSGS_BUILD_TRACE_LEVEL)  (lvl =
MSGS_CONTEXT-level))

#define msgs_major _msgs_cond(LVL_MAJOR) msgs_trace_intern
#define msgs_normal_msgs_cond(LVL_NORMAL)msgs_trace_intern
#define msgs_minor _msgs_cond(LVL_MINOR) msgs_trace_intern
#define msgs_detail_msgs_cond(LVL_DETAIL)msgs_trace_intern
#define msgs_verbose   _msgs_cond(LVL_VERBOSE)   msgs_trace_intern
#define msgs_debug _msgs_cond(LVL_DEBUG) msgs_trace_intern
#define msgs_logorrhea _msgs_cond(LVL_LOGORRHEA) msgs_trace_intern
#define msgs_uncondmsgs_trace_intern


static inline void msgs_trace_intern(const char format[], ...)
{
va_list list;

va_start(list, format);
msgs_do_trace(MSGS_CONTEXT, format, list);
va_end(list);
}

here MSGS_CONTEXT could be g_aModules_Context[module_id] , modifying
the api above, adding a module_id parm (in my case the module_id is
implicit based on the location of the trace)

Note: the lvl = MSGS_BUILD_TRACE_LEVEL in _msgs_cond means that the
whole things is optimized out at compile if the test is false (both
part of the test are actually build time constant. the second part f
the test means thta the test cost just a couple of integer compare to
fail.

Note that I have an intermediary static inlinee msgs_trace_intern due
to the fact that I use a static variable MSGS_CONTEXT, static to each
'module'... in you case you do not need that, if you do a full
centralized pre-registration.

Note that you can use:

log(writer,)

 and in the define of the log macro use module ## _LOG_ID to refer to
the enum value, and #module to have a pretty sting to print, so that
your log still show a human readable module name

for example, I use something like :

/* We need two macro here, to have a proper expansion of the 'module'
parameter */
#define CORE_DECLARE_MODULE(module) CORE_DECLARE_MODULE2(module)

#define CORE_DECLARE_MODULE2(module) \
static struct msgs_module_context g_context = { module ##  _MODULE_ID
, -1, 0, 0, NULL,  #module}

to define my module_level context

Norbert
___
LibreOffice mailing list
LibreOffice@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/libreoffice

Re: [Libreoffice] Assertions and Logging