Updates:
Summary: Tests using suds fail if log level is below info
Status: WontFix
Comment #1 on issue 1100 by pekka.klarck: Tests using suds fail if log
level is below info
http://code.google.com/p/robotframework/issues/detail?id=1100
This problem is caused by a bug in suds. I have already investigated the
same problem for one of my clients, but that information is not publicly
available. Because someone else may encounter this bug again, I write a bit
more detailed explanation here for future reference. At the end there are
also possible workarounds that you may consider.
The bug
=======
There is following code in suds/sax/document.py file:
class Document(Element):
# snip
def root(self):
if len(self.children):
return self.children[0]
else:
return None
def str(self):
s = []
s.append(self.DECL)
s.append('\n')
s.append(self.root().str()) # BUG!! self.root() may return None
return ''.join(s)
# snip
def __unicode__(self):
return self.str()
In practice this bug means that if you try to create a string
representation of an empty Document instance, you will get an
`AttributeError: 'NoneType' object has no attribute 'str'`. And yes, that
is exactly the same error as in the original description.
Notice that this bug is already fixed in suds version control.
Unfortunately the fix is not included in 0.4 or 0.4.1 beta that are the
latest releases at the time of writing this comment.
Why it does not occur normally?
===============================
It seems that suds does not create string representation of Document
instances too often so the bug does not manifest itself normally. One place
where these string representations are needed, though, is logging: suds
uses Python's logging module and logs messages containing the possibly
crashing string representation on debug level.
Starting from RF 2.6 (issue 455) Robot has listened messages logged using
the logging module and thus logging bugs like this affect it. When you run
Robot normally, it configures the logging module so that only messages on
info level and above are emitted, and as a result the crashing debug
message is never processed. When using debug or trace levels with Robot,
the buggy debug message by suds is actually logged and you get a failure.
Notice that prior to RF 2.7, the logging module was configured so that it
always emitted all messages (issue 998). In practice that meant that you
got always got this failure regardless the logging level you used with
Robot.
Possible workarounds
====================
1) Install latest suds version directly from its version control. As
discussed above, the underlying logging bug is fixed there, but it may
obviously contain some new bugs (or features).
2) Fix the logging problem locally on your machine. You may also create a
custom installation package with only this fix for wider audience.
3) Add the following code to your library to configure the logging module
not to emit messages below INFO regardless Robot's logging level. If you
have this code in your library, it will be executed after Robot's logging
configuration and thus has precedence.
import logging
logging.getLogger().setLevel(logging.INFO)
A drawback of this approach is that you do not get debug messages logged by
suds (or any other tool using the logging module) into Robot's log file.
4) Simply do not use debug or trace levels with Robot. If you need them,
try to ignore the failures caused by this bug.
5) Try to convince suds developers to make a new official release. 0.4.1
release seems to be over year late so that may not be too easy.
Conclusion
==========
I close this issue as WontFix because I do not believe we should do
anything for this in Robot side. We probably could ignore logging errors
like this, but that could make debugging other problems involving similar
errors much harder. Adding a possibly very harmful workaround for Robot to
avoid a clear bug in a third party tool is not a good idea. I hope some of
the proposed workaround work for you.
