Mailman 3 January 2018 - Twisted

[Twisted-Python] Twisted.logger on windows max recursion depth exceeded
by John Aherne 07 Jan '18

07 Jan '18

I've started to look at Python3 and klein I am using python3.6.3 32bit and twisted 17.9.0 on windows10 klein is downloaded from pypi. I got to the point of needing to do some logging and thought I now should use the new logger system. Below I have posted the python code I am using and the traceback for when it crashes. The last part is the log output for when the program works as expected. *First Setup* With the first setup all seems to work as expected. I can log to stdio and to a FileLogObserver without error. This works with or without the print statements enabled in the event formatter (jahlog) *Second Setup* The second setup causes python to crash with the print statements enabled in the event formatter. With the for loop print enabled the system will crash. With just printing the keys from the event dict it will produce the recursion depth error but won't crash python. If I comment out the print statements all seems to work correctly. I assume I am doing something wrong or something I should not be trying to do. But I can't work out what causes the 2 setups to behave so differently. The traceback I have posted below shows the result when using the for loop to print out the items in the event dict. As you can see there are a whole lot of empty items it iterates over. The last section below shows the log output when all is working as expected. Here we see the expected result from iterating the event dict. About 8 items to print. The question is What am I doing wrong if at all. Or why is there such a difference between the 2 setups. Any pointers gratefully accepted. import os import sys import traceback from klein import Klein from twisted.web import static #from twisted.internet import reactor from twisted.web.resource import NoResource from twisted.internet.defer import succeed #from twisted.python import log from twisted.logger import Logger, formatEvent, formatTime from twisted.logger import FileLogObserver, globalLogPublisher, globalLogBeginner from twisted.python.logfile import DailyLogFile from pprint import pprint def jahlog(event): #print('EVENT DIR', event.keys()) for item in event: print('ITEM', event[item]) my_tb = '' eventText = 'NONE' if 'log_failure' in event: print('TRACEBACVK22 failure', event['log_failure']) my_tb = event['log_failure'] event['log_format'] = str(event['log_format']) eventText = formatEvent(event) time = formatTime(event["log_time"]) my_space = event["log_namespace"] my_level = event["log_level"] my_logger = event["log_logger"] if 'log_logger' in event else 'JAHlog' system_log = event["log_system"] if 'log_system' in event else '-' eventString = "{[time]} {[namespace]} {[loglevel]} {[my_logger]} {[system_log]} {[text]}\r\n {[my_tb]}".format(dict(time=time), dict(namespace=my_space), dict(loglevel=my_level), dict(my_logger=my_logger), dict(system_log=system_log), dict(text=eventText), dict(my_tb=my_tb) ) return eventString log = Logger(namespace="jah_test5") globalLogPublisher.addObserver(FileLogObserver(DailyLogFile.fromFullPath('c:\\logs\\my_log9.log'), jahlog)) #Replace the above 2 lines with the following 2 lines and all is well #f = FileLogObserver(DailyLogFile.fromFullPath('c:\\logs\\my_log6.log'), jahlog) #log = Logger(observer=f, namespace="klein_test") app = Klein() @app.route('/') def jah(request): logdata = 'some log data' print('DO JAH', logdata) log.debug('DO JAH LOGGGGG {data!r}\r\n', data=logdata) return b"GOT RESULT" #my_html app.run('localhost', 9000) Do run with following logger log = Logger(namespace="jah_test5") globalLogPublisher.addObserver(FileLogObserver(DailyLogFile.fromFullPath('c:\\logs\\my_log9.log'), jahlog)) Total Inability To Support Usual Programming PS C:\jahtest> ./klein_static_test5.py 2018-01-06 11:48:37+0000 [-] ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM ITEM - 2018-01-06 11:48:37+0000 [-] Temporarily disabling observer <twisted.logger._file.FileLogObserver object at 0x00000287D6E597B8> due to exception: [Failure instance: Traceback: <class 'RecursionError'>: maximum recursion depth exceeded C:\Program Files\Python36\lib\site-packages\twisted\logger\_file.py:50:__call__ C:\jahtest\klein_static_test5.py:18:jahlog C:\Program Files\Python36\lib\site-packages\twisted\logger\_io.py:170:write C:\Program Files\Python36\lib\site-packages\twisted\logger\_logger.py:135:emit --- <exception caught here> --- C:\Program Files\Python36\lib\site-packages\twisted\logger\_observer.py:131:__call__ C:\Program Files\Python36\lib\site-packages\twisted\logger\_file.py:50:__call__ C:\jahtest\klein_static_test5.py:18:jahlog C:\Program Files\Python36\lib\site-packages\twisted\logger\_io.py:170:write C:\Program Files\Python36\lib\site-packages\twisted\logger\_logger.py:117:emit C:\Program Files\Python36\lib\site-packages\constantly\_constants.py:273:iterconstants ] Traceback (most recent call last): File "C:\Program Files\Python36\lib\site-packages\twisted\logger\_file.py", line 50, in __call__ text = self.formatEvent(event) File "C:\jahtest\klein_static_test5.py", line 18, in jahlog print('ITEM', event[item]) File "C:\Program Files\Python36\lib\site-packages\twisted\logger\_io.py", line 170, in write self.log.emit(self.level, format=u"{log_io}", log_io=line) File "C:\Program Files\Python36\lib\site-packages\twisted\logger\_logger.py", line 135, in emit self.observer(event) --- <exception caught here> --- File "C:\Program Files\Python36\lib\site-packages\twisted\logger\_observer.py", line 131, in __call__ observer(event) File "C:\Program Files\Python36\lib\site-packages\twisted\logger\_file.py", line 50, in __call__ text = self.formatEvent(event) File "C:\jahtest\klein_static_test5.py", line 18, in jahlog print('ITEM', event[item]) File "C:\Program Files\Python36\lib\site-packages\twisted\logger\_io.py", line 170, in write self.log.emit(self.level, format=u"{log_io}", log_io=line) File "C:\Program Files\Python36\lib\site-packages\twisted\logger\_logger.py", line 117, in emit if level not in LogLevel.iterconstants(): File "C:\Program Files\Python36\lib\site-packages\constantly\_constants.py", line 273, in iterconstants sorted(constants, key=lambda descriptor: descriptor._index)) builtins.RecursionError: maximum recursion depth exceeded Fatal Python error: Cannot recover from stack overflow. Do run with following logger f = FileLogObserver(DailyLogFile.fromFullPath('c:\\logs\\my_log6.log'), jahlog) log = Logger(observer=f, namespace="klein_test") PS C:\jahtest> ^C PS C:\jahtest> ^C PS C:\jahtest> ./klein_static_test5.py 2018-01-06 11:54:29+0000 [-] Log opened. 2018-01-06 11:54:29+0000 [-] Site starting on 9000 2018-01-06 11:54:29+0000 [-] Starting factory <twisted.web.server.Site object at 0x000001A886F11588> 2018-01-06 11:54:40+0000 [-] DO JAH some log data 2018-01-06 11:54:40+0000 [-] ITEM some log data 2018-01-06 11:54:40+0000 [-] ITEM <Logger 'klein_test'> 2018-01-06 11:54:40+0000 [-] ITEM <LogLevel=debug> 2018-01-06 11:54:40+0000 [-] ITEM klein_test 2018-01-06 11:54:40+0000 [-] ITEM None 2018-01-06 11:54:40+0000 [-] ITEM DO JAH LOGGGGG {data!r} 2018-01-06 11:54:40+0000 [-] 2018-01-06 11:54:40+0000 [-] ITEM 1515239680.6134038 2018-01-06 11:54:40+0000 [-] "127.0.0.1" - - [06/Jan/2018:11:54:40 +0000] "GET / HTTP/1.1" 200 10 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.84 Safari/537.36" 2018-01-06 11:54:46+0000 [-] DO JAH some log data 2018-01-06 11:54:46+0000 [-] ITEM some log data 2018-01-06 11:54:46+0000 [-] ITEM <Logger 'klein_test'> 2018-01-06 11:54:46+0000 [-] ITEM <LogLevel=debug> 2018-01-06 11:54:46+0000 [-] ITEM klein_test 2018-01-06 11:54:46+0000 [-] ITEM None 2018-01-06 11:54:46+0000 [-] ITEM DO JAH LOGGGGG {data!r} 2018-01-06 11:54:46+0000 [-] 2018-01-06 11:54:46+0000 [-] ITEM 1515239686.295032 2018-01-06 11:54:46+0000 [-] "127.0.0.1" - - [06/Jan/2018:11:54:45 +0000] "GET / HTTP/1.1" 200 10 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.84 Safari/537.36" -- *John Aherne* *www.rocs.co.uk <http://www.rocs.co.uk>* 020 7223 7567

2 2

[Twisted-Python] Weekly Bug Summary
by trac＠twistedmatrix.com 07 Jan '18

07 Jan '18

1 0

[Twisted-Python] buildbot.twistedmatrix.com is down?
by Craig Rodrigues 06 Jan '18

06 Jan '18

Hi, It looks like buildbot.twistedmatrix.com is down. Does anyone know how to bring it back? -- Craig

2 5

[Twisted-Python] logObservers and syslog proposal
by Svein Seldal 05 Jan '18

05 Jan '18

Hi I'm currently working on understanding the twister.logger scheme with the purpose of getting proper logging in my end-user application. https://gist.github.com/sveinse/041c69b6bbdde83cf5b00fecae3dcd50 It took me a while to get my head around the difference in using twisted.logger.globalLogBeginner.beginLoggingTo() vs using twisted.logger.globalLogPublisher.addObserver(). Neither of the methods behave precisely as I'd like them to. See https://gist.github.com/sveinse/041c69b6bbdde83cf5b00fecae3dcd50#file-log-p… 1) What are the intended difference between these two ways of installing a logobserver? 2) I'd like to contribute a SyslogObserver for the new twister.logger scheme. See the _syslog.py file in the gist. It has been ported from the old logging scheme. Would this be useful to Twisted? I was uncertain what to do with log_failures in the observer. I see that dumping of log_failures has been removed from t.l.FileLogObserver(). What is the appropriate way to deal with log_failures? In the proposal of SyslogObserver I addded a dumpTraceback option to the constructor to select if the tb should go to the syslog or not. (My application shall have tb to syslog.) Best regards, Svein

2 1

[Twisted-Python] failUnlessFailure vs assertFailure
by Adi Roiban 04 Jan '18

04 Jan '18

Hi, Do you know why we still have failUnlessFailure is an alias to assertFailure? [1] It looks like pydoctor does not include aliases as I don't see failUnlessFailure in the HTML rendering http://twistedmatrix.com/documents/current/api/twisted.trial.unittest.TestC… Looking at the current code, I see that it is used only in a single place in Twisted https://github.com/twisted/twisted/search?utf8=%E2%9C%93&q=failUnlessFailur… I see that in the past assertFailure was an alias for failUnlessFailure [2] Is the plan to continue to have the alias? Maybe we can have a comment before the alias. Can we deprecate it? Should pydoctor be updated to also show aliases of public methods? Regards, [1] https://github.com/twisted/twisted/blob/e38cc25a67747899c6984d6ebaa8d3d1347… [2] https://github.com/twisted/twisted/commit/ce0b00de026a896b731d8794de2fd61b5… -- Adi Roiban

3 2

[Twisted-Python] Drop support for Python 3.3
by Craig Rodrigues 03 Jan '18

03 Jan '18

I submitted this patch to drop support for Python 3.3: https://github.com/twisted/twisted/pull/943 1. Python 3.3 was declared EOL on Sep. 29, 2017 2. In terms of major Linux distributions, Python 3.4 came with Python 3.4 is in Debian 8, Ubuntu 14.04, Fedora 21 So after this patch, Twisted would run on: Python 2.7 and Python 3.4+ Thoughts? -- Craig

2 2