Martijn Faassen wrote:

Stefan Behnel wrote:

...

since we often have requests regarding better error reporting in lxml, I implemented a little error log. lxml now keeps a bounded list of output messages from libxml2/xslt (that normally appear on stdout) and provides access to the log entries through its exceptions.

LxmlException objects now have an additional attribute "error_log" that contain the last log entries (up to 20 by default). So, if an exception is raised, whoever catches it can print out the error messages from libxml2/xslt to see where things went wrong.

This behaviour can be switched on or off at compile time and defaults to off. If off, the attribute simply stores an empty tuple.

What's the motivation for defaulting this to 'off'?

I consider this more of a debug helper than something you'd use in production. It doesn't really help you in /handling/ errors as all you get is non computer readable strings with error messages. It /does/ help you when you read through them to see where the bugs in your applications are. It does not help your /program/ to handle errors.

Since the log had to be copied at the moment of exception raising, I first thought that exception creation becomes somewhat faster if it's switched off. I changed the error_log attribute to a property now that accesses the *current* log. This means that it does no longer guarantee to conserve the exact state of the error log at exception creation time (which should not be a problem if you do not make any libxml calls before catching it), but it also means that there is no longer any performance penalty for creating exceptions. So now, I would also prefer the default to be "on".

How precise is this information? Do we see the last 5 lines for an XML parsing error that occured earlier in a later XSLT reception?

Well, you see the last 20 lines - if you explicitly print them. They are not (currently) shown in the exception message or the traceback. The code cannot really try to find the line that triggered the error, so it's really just 20 lines of messages.

You /could/ extend this to incorporate more of the information provided by the libxml2/xslt error calls (like error types, etc.). On XML errors, for example, libxml2 gives you this:

int domain : What part of the library raised this er int code : The error code, e.g. an xmlParserError char * message : human-readable informative error messag xmlErrorLevel level : how consequent is the error char * file : the filename int line : the line number if available char * str1 : extra string information char * str2 : extra string information char * str3 : extra string information int int1 : extra number information int int2 : column number of the error or 0 if N/A void * ctxt : the parser context if available void * node : the node in the tree

The problem is: the more information you put into the log, the slower the application becomes. Providing the element that triggered the error, for example, would rather be out of scope. Note that you have to convert this information to Python representations in order to store it in the log.

We also have the case for RelaxNG/Schema reporting where no exception is raised if the XML is not valid according to the schema.

I added error_log properties to the RelaxNG and XMLSchema classes. That should solve that problem.

Stefan

Martijn Faassen wrote:

Another question: How does error logging work in combination with threads? I noticed that the code in lxml that turned off the talkativeness of libxml2 actually only worked for the main thread, and that new threads that use lxml do become talkative again.

According to the libxml2 docs, that's intentional. Each thread has to configure that for itself. Currently, there isn't that much in lxml anyway that takes care of threads. Everything that's module level will interfere.

A way to get around this would be to set an error log in each sensible function. Hmm, I actually think that would be the right way. I'll code this up and see how it turns out.

...

libxml2 gives you this:

int    domain    : What part of the library raised this er
int    code    : The error code, e.g. an xmlParserError
char *    message    : human-readable informative error messag
xmlErrorLevel    level    : how consequent is the error
char *    file    : the filename
int    line    : the line number if available
char *    str1    : extra string information
char *    str2    : extra string information
char *    str3    : extra string information
int    int1    : extra number information
int    int2    : column number of the error or 0 if N/A
void *    ctxt    : the parser context if available
void *    node    : the node in the tree

The problem is: the more information you put into the log, the slower the application becomes. Providing the element that triggered the error, for example, would rather be out of scope. Note that you have to convert this information to Python representations in order to store it in the log.

I'm not too concerned that slowing down exceptions somewhat is going to impact things that badly - these exceptions are typically not occuring very often. Since it's lxml's mission to make libxml2 usable by mortal python programmers with a nice API, I consider it part of our mission to make the error API as nice as possible too, providing as much information as we can, in an easy to understand way.

That's all future music though. I think this is already a great step forward, I'm just pointing where I'd like to go.

I also thought a bit more about this. It would be better to store more information and then allow filtering based on domain and error codes. RNG classes should only return RNG errors, for example (although earlier failures may have contributed to the current error...).

Maybe use a dedicated log entry class rather than plain strings?

...

...

We also have the case for RelaxNG/Schema reporting where no exception is raised if the XML is not valid according to the schema.

I added error_log properties to the RelaxNG and XMLSchema classes. That should solve that problem.

Another way that might be more consistent is to add new methods that either silently validate or, in case of validation errors, raise an exception.

Hmmm, I don't know. If that's only for retrieving more precise error information... Maybe a method like "assert" could be meaningful here.

Stefan

Martijn Faassen wrote:

Stefan Behnel wrote:

...

A way to get around this would be to set an error log in each sensible function. Hmm, I actually think that would be the right way. I'll code this up and see how it turns out.

Great! It'd be nice if threads worked with lxml, of course. One would like to have it work in a web server...

There is now a branch called error-reporting that implements this. It is partially untested, but at least the global logging and exception handling seems to work. It should potentially also work at a thread level, although the global logging may be broken there.

My SVN log entry:

large rewrite of the error handling API - use named class attributes for error domain, type and level - _LogEntry class represents xmlError structure - _ErrorLog collects error entries - global log collects all errors, rotates at 100 entries - API functions can be wrapped in log.connect() and log.disconnect() to provide a local error log (exemplified in XMLSchema and RelaxNG - untested)

The last line refers to a local log that can be created at object instantiation time (i.e. at the end of RelaxNG.__init__() etc.).

Stefan