[mod_python] multiple processing of the same python script by the handler

Graham Dumpleton graham.dumpleton at gmail.com
Tue Mar 31 20:44:58 EDT 2009


You have the registration of the logger inside a function which is
called multiple times. It needs to be a global scope in the module so
it is only done once. See below.

2009/4/1 David Sfiligoi <webmaster at world-vr.com>:
> Hi Graham,
>
> Thanks for the quick response.   I have implemented a module which I place
> in / (literally) for ensuring that the test works.   I then also wrote a
> small stress test app which would hit the script with a parameter which
> increments at each request to see so I can see if there is multiplicity of
> logging.   Unfortunately there was still multiple entries of the same log
> data.  I should  say that the data received by the server on the other end of
> the socket is now unique(seems to be so far anyway). So thank you for
> assisting :-)   The issue with the logging module still baffles me.  Perhaps
> somebody else on the list has input?
>
> def handler(req):
>    davelogger = apache.import_module("/davelogger.py")
>    request_data = util.FieldStorage(req)
>    clientip = req.get_remote_host(apache.REMOTE_NOLOOKUP)
>    geoip = 'NL'
>    str_req_data = str(clientip) + "| CC: " + str(geoip) + "| "
>    str_req_datadb = "ip: " + str(clientip) + "| CC: " + str(geoip) + "| "
>    for key in request_data:
>        str_req_datadb += "| " + str(key) + ": " + str(request_data[key])
>        str_req_data += str(key) + ": " + str(request_data[key]) + "| "
>
>    davelogger.logdata(str_req_data[:-2],str_req_datadb)
>    return apache.OK
>
> davelogger.py module:
>
> def logdata(data,datadb):
>    logger = logging.getLogger('mylogger.py')
>    logging_handler =
> logging.FileHandler('/usr/local/apache2/htdocs/mylog.log')
>    formatter = logging.Formatter('%(asctime)s %(levelname)s %(message)s')
>    logging_handler.setFormatter(formatter)
>    logger.addHandler(logging_handler)
>    logger.setLevel(logging.INFO)

Parts of above initialisation should be at global scope in module, not
inside function which is called multiple times.

Graham

>
>    curtime = datetime.now().isoformat(' ')
>    try:
>        s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
>        s.settimeout(0.5)
>        s.connect(('10.0.0.2', 8199))
>        message = "date: " + str(curtime[:-4] + "| " + datadb)
>        len_sent = s.send(message)
>        s.close()
>
>    except:
>        data += '| dbupdate: failed|'
>        pass
>    logger.info(data)
>
>
> log data from the logger module
> 2009-03-29 23:28:48,452 INFO 10.0.0.2| CC: NL| x: 195
> 2009-03-29 23:28:48,452 INFO 10.0.0.2| CC: NL| x: 195
> 2009-03-29 23:28:48,452 INFO 10.0.0.2| CC: NL| x: 195
> 2009-03-29 23:28:48,452 INFO 10.0.0.2| CC: NL| x: 195
> 2009-03-29 23:28:48,452 INFO 10.0.0.2| CC: NL| x: 195
> 2009-03-29 23:28:48,452 INFO 10.0.0.2| CC: NL| x: 195
> 2009-03-29 23:28:48,452 INFO 10.0.0.2| CC: NL| x: 195
> 2009-03-29 23:28:48,500 INFO 10.0.0.2| CC: NL| x: 196
> 2009-03-29 23:28:48,500 INFO 10.0.0.2| CC: NL| x: 196
> 2009-03-29 23:28:48,500 INFO 10.0.0.2| CC: NL| x: 196
> 2009-03-29 23:28:48,500 INFO 10.0.0.2| CC: NL| x: 196
> 2009-03-29 23:28:48,500 INFO 10.0.0.2| CC: NL| x: 196
> 2009-03-29 23:28:48,500 INFO 10.0.0.2| CC: NL| x: 196
>
> stdout from the socket server:
> {'date': '2009-03-29
> 23:28:48', 'ip': '10.0.0.2', 'CC': 'NL', 'eventid': '0de8b6b1b019d19bc3e7eb5ca986cdcade75e20587211569eebdfcc8', 'x': '194'}
> {'date': '2009-03-29
> 23:28:48', 'ip': '10.0.0.2', 'CC': 'NL', 'eventid': 'bc728c0113bb35d748bf2be0fae52a85242c87a0d41495aeee9d69c0', 'x': '195'}
> {'date': '2009-03-29
> 23:28:48', 'ip': '10.0.0.2', 'CC': 'NL', 'eventid': '9f946b3948d2f2b84b241e25f1a05f2260e53a98a7d1af5a61787f38', 'x': '196'}
>
>
> On Sunday 29 March 2009 09:33:46 pm you wrote:
>
>
>> 2009/3/30 David Sfiligoi <webmaster at world-vr.com>:
>> > Hi Graham,
>> >
>> > Yes I agree defining my logger outside the mod python handler was a bad
>> > idea. Using the req.log_error works of course.  Obviously if I wanted
>> > integrate this into all the other apps that revolve around those logs,
>> > i'd have to write a converter or change each apps which parses the log
>> > data.
>> >
>> > I'd like to understand this a bit better, perhaps I have the wrong basic
>> > idea on how the python handler works in overall, but if I install the log
>> > handler in the handler function and delete the log objects before ending,
>> > shouldn't that take care of the multiple logging issue?
>> >
>> > Or are you saying that each piece of code that should not produce
>> > multiple entries of the same thing should really be inside a module so I
>> > can let import_module() take care of it?
>>
>> Put logging initialisation in a completely separate module outside of
>> document tree and not inside of the handler code files. Setup
>> PythonPath if need be where that separate module is located,  and then
>> have handler code files import that module from that other location.
>>
>> This should ensure that the logging initialisation code is imported
>> and run only once per process. If you intentionally then change the
>> logging initialisation module code, you will need to restart Apache.
>>
>> > Im seeing the same 'multiplicity' issue when I open a socket while in
>> > handler function. This is really what trigger the question.
>>
>> That I can't explain at this point. I was assuming that your
>> duplicated logging may have been confusing the issue.
>>
>> > Thanks,
>> >
>> > David
>> >
>> > On Sunday 29 March 2009 05:45:01 am Graham Dumpleton wrote:
>> >> If you change a mod_python handler script, it will be automatically
>> >> reloaded. This would be a problem in your code as you installed a log
>> >> handler each time it is loaded into the same process. Having multiple
>> >> instances of the log handler installed would result in the same
>> >> information possibly being logged multiple times.
>> >>
>> >> I would suggest you add inside your handler script:
>> >>
>> >>   req.log_error("I have been called")
>> >>
>> >> If that appears twice in the Apache error log file then I would be
>> >> concerned, otherwise I would say the problem is with your use of the
>> >> logging module.
>> >>
>> >> Also read about import_module() in:
>> >>
>> >>   http://www.modpython.org/live/current/doc-html/pyapi-apmeth.html
>> >>
>> >> as it explains a bit about module reloading and the way to preserve
>> >> global data or avoid stuff which performs additive operations each
>> >> time it is loaded.
>> >>
>> >> Graham
>
>
>



More information about the Mod_python mailing list