[Twisted-Python] Re: supressess warnings

Andrew Dalke dalke at dalkescientific.com
Tue Apr 1 16:48:01 EST 2003


Itamar Shtull-Trauring:
 > Fixed in CVS - warnings will be logged to stderr if no log file
 > was specified.

Mmm, okay, I see the patch you did in CVS.

One thing I don't like about the log system is that it goes
into place on import, rather than after some explicit request
to actually use the log.  It isn't obvious anywhere that that
import will make a system level change.
   - what if I've changed warnings.showwarning in my own
        code (or in some other 3rd party package).  Where's the
        documentation which states that there will be a problem?

   - It's pervasive.  That is, if I import twisted.lore (perhaps
       because I want it to use it for my own documentation
       system) it's still the case that warnings.showwarning
       gets replaced.  There should be no reason for that.

Are there any other system-level functions or settings which
get tweaked by Twisted?

 > > It looks like Log.synchronized is old code that can be removed.   
Yes?

 > Probably not

Ahh, I see.  It's emulating the Java keyword.  Hmm, I probably
would have had a Log implementation which changed depending
on of this was threaded or not, and have threaded calls forward
the write/writeline via a Queue.

There are only 4 places which use that, outside of some of the
test code.  Is it really that useful given how non-obvious it is?

Also, I see that the other places which use a class with the
synchronized attribute (like web/static.py) also call  
threadable.synchronize
on the class, as in

python/logfile.py:threadable.synchronize(LogFile)
test/test_threadpool.py:threadable.synchronize(Counter)
test/test_threads.py:threadable.synchronize(Counter)
web/static.py:threadable.synchronize(FileTransfer)

Notice that log.py's Log class, which has a 'synchronized'
attribute, is not so initialized.  This suggests there's either a bug
(this class needs to be synchronized) or that that attribute is
unneeded.

Christopher Armstrong:
 > The bit that initializes the default logfile to NullFile is
 > something moshez and glyph wanted

Actually, I don't care where the default logfile goes, I just
care where my system warnings go.  But as you pointed out
in a later email, it's now sent to 'STDIO'.

I still don't like that it goes into effect without me doing
anything other than an import.

 > > Running Command: './admin/../bin/mktap mail --domain foo.bar=dump
 > > --user postmaster=postmaster  --pop 18110'
 > > option --pop not a unique prefix

 > I have no idea what this error means.

Looking only at the error message, it means that:
   - the option parsing code does automatic prefix expansion, so
        that if the option is '--pop3' and the argument is '--pop' and no
        other option starts with '--pop' then it's elided to '--pop3'.   
This
        was what DEC machines did for VMS commands (as I recall)
        and it was annoying because if a new option is added (like
        '--popcorn') then scripts which assumed that '--pop' would
        always be unique, broke.

   - and a new option was added which started with the '--pop'
        prefix, breaking the code.

   - and no one has run those tests in a while, probably not since
      10-Feb-03 when moshez added the following option.

        ["pop3s", "S", 0, "Port to start the POP3-over-SSL server on (0  
to disable)."],


 > This happened because you didn't use the `-P' option to cvs
 > update/checkout. Please put this in your ~/.cvsrc:

Ummmm, okay, done, and those errors go away.  The page at
   http://twistedmatrix.com/developers/cvs
should be updated to mention this.

 > I have no idea what the rest of the problems were about, though.

Here's the full set of tracebacks

======================================================================== 
=======
FAILURE: testReadLimit (twisted.test.test_policies.ThrottlingTestCase)
------------------------------------------------------------------------ 
-------
Traceback (most recent call last):
    File "/Users/dalke/cvses/Twisted/twisted/test/test_policies.py",  
line 193, in testReadLimit
     self.assertEquals(tServer.readThisSecond, 0)
  FailTest: 20 != 0

No clue.  A timing issue?

======================================================================== 
=======
FAILURE: testWriteLimit (twisted.test.test_policies.ThrottlingTestCase)
------------------------------------------------------------------------ 
-------
Traceback (most recent call last):
    File "/Users/dalke/cvses/Twisted/twisted/test/test_policies.py",  
line 152, in testWriteLimit
     self.assert_(abs(p.wrappedProtocol.paused - now - 1.0) < 0.1)
  FailTest

Related to the previous case?

======================================================================== 
=======
FAILURE: testFailing (twisted.test.test_tcp.LoopbackTestCase)
------------------------------------------------------------------------ 
-------
Traceback (most recent call last):
    File "/Users/dalke/cvses/Twisted/twisted/test/test_tcp.py", line  
171, in testFailing
     self.assert_(time.time() - start < 0.1)
  FailTest

Looks like it takes more than 0.1 seconds for me to fail that test.
On this box (OS X), a connect looks like it starts off with an IPv6  
request
then tries 127.0.0.1 then tries ... an IP address I got a few weeks ago.
Strange.  That's on another network, which is firewalled from here.
So that's probably where the delay comes in.

[Andrew-Dalkes-Computer:~/cvses/Twisted] dalke% time telnet localhost 69
Trying ::1...
telnet: connect to address ::1: Connection refused
Trying 127.0.0.1...
telnet: connect to address 127.0.0.1: Connection refused
Trying 207.225.60.130...
telnet: connect to address 207.225.60.130: Connection refused
telnet: Unable to connect to remote host
0.000u 0.020s 0:00.46 4.3%      0+0k 0+0io 0pf+0w


======================================================================== 
=======
ERROR: testEcho (twisted.test.test_process.ProcessTestCase)
------------------------------------------------------------------------ 
-------
Traceback (most recent call last):
    File "/Users/dalke/cvses/Twisted/twisted/trial/unittest.py", line  
165, in runOneTest
     method(testCase)
    File "/Users/dalke/cvses/Twisted/twisted/test/test_process.py", line  
140, in testEcho
     self.assertEquals(len(p.buffer), len(p.s * 10))
  AttributeError: EchoProtocol instance has no attribute 'buffer'

Trying to track that down, I see that
   twisted/internet/interfaces.py
has mention of
           @see: C{twisted.protocols.protocol.ProcessProtocol}
but twisted/protocols/protocol.py says
"""Deprecated - use twisted.internet.protocol instead.

Anyway, the only reason I can see this error happened is if
EchoProtocol's connectionMade wasn't called.  I simply
don't understand the code well enough to debug it right now.

======================================================================== 
=======
ERROR: testEcho (twisted.test.test_process.ProcessTestCase)
------------------------------------------------------------------------ 
-------
Traceback! exceptions.OSError, [Errno 35] Resource temporarily  
unavailable
./twisted/internet/process.py:281:__init__
./twisted/internet/protocol.py:290:makeConnection
/Users/dalke/cvses/Twisted/twisted/test/ 
test_process.py:82:connectionMade
./twisted/internet/process.py:358:write
./twisted/internet/process.py:126:write
./twisted/internet/abstract.py:145:write
./twisted/internet/process.py:111:writeSomeData
======================================================================== 
=======
ERROR: testEcho (twisted.test.test_process.ProcessTestCase)
------------------------------------------------------------------------ 
-------
Traceback! exceptions.AttributeError, EchoProtocol instance has no  
attribute 'buffer'
./twisted/internet/default.py:467:doSelect
./twisted/internet/process.py:345:doRead
./twisted/internet/fdesc.py:58:readFromFD
/Users/dalke/cvses/Twisted/twisted/test/test_process.py:86:outReceived
======================================================================== 
=======
ERROR: testUnicodeTolerance (twisted.test.test_xml.MicroDOMTest)
------------------------------------------------------------------------ 
-------
Traceback (most recent call last):
    File "/Users/dalke/cvses/Twisted/twisted/trial/unittest.py", line  
165, in runOneTest
     method(testCase)
    File "/Users/dalke/cvses/Twisted/twisted/test/test_xml.py", line  
326, in testUnicodeTolerance
     ud = microdom.parseString(s.encode('UTF-16'))
    File "/Users/dalke/cvses/Twisted/twisted/web/microdom.py", line 648,  
in parseString
     return parse(StringIO(st), *args, **kw)
    File "/Users/dalke/cvses/Twisted/twisted/web/microdom.py", line 613,  
in parse
     mdp.dataReceived(readable.getvalue())
    File "./twisted/protocols/sux.py", line 155, in dataReceived
    File "./twisted/protocols/sux.py", line 176, in do_begin
    File "./twisted/protocols/sux.py", line 108, in _parseError
  ParseError: <xmlfile />:1:1: First char of document ['\xfe'] wasn't <

\xfe is the byte order marker.  This test started with

s = "<foo><bar><baz /></bar></foo>"
then encoded it as UTF-16, which puts the BOM at the front.
So of course the string doesn't start with a '<'.

 > The *reason*, IIRC, was that "you shouldn't spam unwanted stuff
 > to STDIO"

Again, I realize this has been changed.  Just wanted to note
that system warnings about API differences are wanted, as well
as warnings about deprecations, etc.

 > > Why's the Log pickleable? What happens if a cStringIO is passed
 > > in instead of a file?  Or an outgoing network socket?  Or a
 > > os.popen("lp")?

 > Well, it should probably be pickleable only when it _can_ be. :) i.e.,

That didn't answer my question of why it needs to be pickled.
I suppose it's part of the App, which saves complete state via
a pickle?  Err, it can't, because that's a module variable.

In any case, the cleaner way to fix it is to have a specialized
replacement called instead of the native open call, and
have it store the arguments so that the unpickling gets the
correct calls, and allow backwards compatibility with
   if isinstance(logfile, file):
     logfile = PickleableFile(logfile)

 > Well, no, usually people use twistd. Which you should, if you're
 > writing a server.

I'm just working my way through the example, and it doesn't
use twistd, so I didn't.

As mentioned, I don't like how system settings are changed
on an import, much less without documentation which says
this will happen.

If everything server related should be done in the context
of twistd, then that warnings.showwarning replacement
should only be done when twistd is used, which is why
the patch I sent only made the switch when startLogging
was called.

The solution I see now, which is that showwarnings calls
the errlog instead of the msg log, still isn't the right
behaviour, IMO, if only because you are changing the
format of the error messages.  At the very least you should
call warnings.formatwarning instead of building your own
warning message.

Oh, and the code should be that if file is not None, to
use the file handle passed in to showwarnings, and not
the error log, that is, replace twisted/python/log.py from

def showwarning(message, category, filename, lineno, file=None):
     err('''\
WARNING: %s::
%s
file: %s; line: %s
''' % (category, indent(message), filename, lineno))

to

def showwarning(message, category, filename, lineno, file=None):
     m = warnings.formatwarning(message, category, filename, lineno)
     if file is None:
       err(m)
     else:
       file.write(m)

Finally, I noticed that other part of my patch were not accepted.
For example, the use of os.linesep is incorrect.  The log file is
opened in text mode, so "\n" will be converted to the appropriate
byte representation for the given platform.  In other words,

         logerr.write(str(stuff)+os.linesep)
should be
         logerr.write(str(stuff)+"\n")

I also did some things to clean up the code, like getting
rid of unneeded module imports (like string) and replacing

import cStringIO
  ...
StringIO = cStringIO
del cStringIO

with

import cStringIO as StringIO

I noticed none of these were accepted.

What should I do to make these sorts of changes more acceptable?
After all, the point of a good unit test suite is to make it easy for
people to refactor and clean up existing code.  All the tests passed
identically before and after my changes.

I could, for instance, have split up the patch into several parts.
However, part of what I did was to replace the warnings.showwarning
code only once, which required a test against a reload (as is
done in two other parts for the code) so I moved those into a
single change and fixed the comments for why it was done.

					Andrew
					dalke at dalkescientific.com





More information about the Twisted-Python mailing list