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 > > >
|