|
David Sfiligoi
webmaster at world-vr.com
Tue Mar 31 21:26:09 EDT 2009
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)
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
|