pythonpython-3.xtwistedrpy2twisted.web

Python Twisted rpy module called multiple times - why?

I am programming Python the first day today. I am running Twisted webserver like this

/usr/bin/python3 -m twisted web --http=80 --path=/website

I wanted to add a scripted page using an .rpy file at /test.rpy

This is the code in the test.rpy file

from twisted.web.resource import Resource
from twisted.python import log

import subprocess

class MyResource(Resource):
    def render_GET(self, request):
        log.startLogging(open('/root/test.log', 'a'))
        log.msg('test')
        request.setHeader(b"content-type", b"text/html")
        return b'abc'

resource = MyResource()

when i navigate to the location on the web browser, it shows "abc" as I would expect. But what I did not expect was in the test.log file (ip replaced with x.x.x.x)... as you can see, everytime i press Refresh on web browser it looks like the module is called multiple times -- first one time, next 2 times, next 3 times... can someone explain it to me?

# tail -f test.log 
2023-03-24 14:08:49+0000 [-] Warning: primary log target selected twice at </usr/lib/python3/dist-packages/twisted/python/log.py:208> - previously selected at </usr/lib/python3/dist-packages/twisted/application/runner/_runner.py:140>.  Remove one of the calls to beginLoggingTo.
2023-03-24 14:08:49+0000 [_GenericHTTPChannelProtocol (TLSMemoryBIOProtocol),0,x.x.x.x] Log opened.
2023-03-24 14:08:49+0000 [_GenericHTTPChannelProtocol (TLSMemoryBIOProtocol),0,x.x.x.x] test

2023-03-24 14:08:58+0000 [-] Warning: primary log target selected twice at </usr/lib/python3/dist-packages/twisted/python/log.py:208> - previously selected at </usr/lib/python3/dist-packages/twisted/python/log.py:208>.  Remove one of the calls to beginLoggingTo.
2023-03-24 14:08:58+0000 [-] Warning: primary log target selected twice at </usr/lib/python3/dist-packages/twisted/python/log.py:208> - previously selected at </usr/lib/python3/dist-packages/twisted/python/log.py:208>.  Remove one of the calls to beginLoggingTo.
2023-03-24 14:08:58+0000 [_GenericHTTPChannelProtocol (TLSMemoryBIOProtocol),0,x.x.x.x] Log opened.
2023-03-24 14:08:58+0000 [_GenericHTTPChannelProtocol (TLSMemoryBIOProtocol),0,x.x.x.x] Log opened.
2023-03-24 14:08:58+0000 [_GenericHTTPChannelProtocol (TLSMemoryBIOProtocol),0,x.x.x.x] test
2023-03-24 14:08:58+0000 [_GenericHTTPChannelProtocol (TLSMemoryBIOProtocol),0,x.x.x.x] test

2023-03-24 14:09:01+0000 [-] Warning: primary log target selected twice at </usr/lib/python3/dist-packages/twisted/python/log.py:208> - previously selected at </usr/lib/python3/dist-packages/twisted/python/log.py:208>.  Remove one of the calls to beginLoggingTo.
2023-03-24 14:09:01+0000 [-] Warning: primary log target selected twice at </usr/lib/python3/dist-packages/twisted/python/log.py:208> - previously selected at </usr/lib/python3/dist-packages/twisted/python/log.py:208>.  Remove one of the calls to beginLoggingTo.
2023-03-24 14:09:01+0000 [-] Warning: primary log target selected twice at </usr/lib/python3/dist-packages/twisted/python/log.py:208> - previously selected at </usr/lib/python3/dist-packages/twisted/python/log.py:208>.  Remove one of the calls to beginLoggingTo.
2023-03-24 14:09:01+0000 [_GenericHTTPChannelProtocol (TLSMemoryBIOProtocol),0,x.x.x.x] Log opened.
2023-03-24 14:09:01+0000 [_GenericHTTPChannelProtocol (TLSMemoryBIOProtocol),0,x.x.x.x] Log opened.
2023-03-24 14:09:01+0000 [_GenericHTTPChannelProtocol (TLSMemoryBIOProtocol),0,x.x.x.x] Log opened.
2023-03-24 14:09:01+0000 [_GenericHTTPChannelProtocol (TLSMemoryBIOProtocol),0,x.x.x.x] test
2023-03-24 14:09:01+0000 [_GenericHTTPChannelProtocol (TLSMemoryBIOProtocol),0,x.x.x.x] test
2023-03-24 14:09:01+0000 [_GenericHTTPChannelProtocol (TLSMemoryBIOProtocol),0,x.x.x.x] test

I expected the module to be called exactly one time, every time the page was loaded, not many times.

Solution 
  • from twisted.web.resource import Resource

from twisted.python import log

import subprocess

class MyResource(Resource):
    def render_GET(self, request):
        log.startLogging(open('/root/test.log', 'a'))

...

    I expected the module to be called exactly one time, every time the page was loaded, not many times.

    In your request handler, you add a new log observer that appends to /root/test.log. After the first request is handled, there is one log observer. After the second request is handled, there are two log observers. And so on.

    You aren't seeing your request handler get called multiple times for each request. You're seeing each log event get reported multiple times.