20 |
20 |
21 import contextlib |
21 import contextlib |
22 import http.client as http_client |
22 import http.client as http_client |
23 import json |
23 import json |
24 import sys |
24 import sys |
25 from time import clock, time |
25 from time import process_time, time |
26 from contextlib import contextmanager |
26 from contextlib import contextmanager |
27 |
27 |
28 from rql import BadRQLQuery |
28 from rql import BadRQLQuery |
29 |
29 |
30 from cubicweb import set_log_methods |
30 from cubicweb import set_log_methods |
203 |
203 |
204 def wrap_execute(cnx): |
204 def wrap_execute(cnx): |
205 orig_execute = cnx.execute |
205 orig_execute = cnx.execute |
206 |
206 |
207 def execute(rql, kwargs=None, build_descr=True): |
207 def execute(rql, kwargs=None, build_descr=True): |
208 tstart, cstart = time(), clock() |
208 tstart, cstart = time(), process_time() |
209 rset = orig_execute(rql, kwargs, build_descr=build_descr) |
209 rset = orig_execute(rql, kwargs, build_descr=build_descr) |
210 cnx.executed_queries.append((rql, kwargs, time() - tstart, clock() - cstart)) |
210 cnx.executed_queries.append((rql, kwargs, time() - tstart, |
|
211 process_time() - cstart)) |
211 return rset |
212 return rset |
212 |
213 |
213 return execute |
214 return execute |
214 |
215 |
215 def set_cnx(cnx): |
216 def set_cnx(cnx): |
218 cnx.executed_queries = [] |
219 cnx.executed_queries = [] |
219 |
220 |
220 return set_cnx |
221 return set_cnx |
221 |
222 |
222 req.set_cnx = wrap_set_cnx(req.set_cnx) |
223 req.set_cnx = wrap_set_cnx(req.set_cnx) |
223 tstart, cstart = time(), clock() |
224 tstart, cstart = time(), process_time() |
224 try: |
225 try: |
225 return self.main_handle_request(req) |
226 return self.main_handle_request(req) |
226 finally: |
227 finally: |
227 cnx = req.cnx |
228 cnx = req.cnx |
228 if cnx and cnx.executed_queries: |
229 if cnx and cnx.executed_queries: |
229 with self._logfile_lock: |
230 with self._logfile_lock: |
230 tend, cend = time(), clock() |
231 tend, cend = time(), process_time() |
231 try: |
232 try: |
232 result = ['\n' + '*' * 80] |
233 result = ['\n' + '*' * 80] |
233 result.append('%s -- (%.3f sec, %.3f CPU sec)' % ( |
234 result.append('%s -- (%.3f sec, %.3f CPU sec)' % ( |
234 req.url(), tend - tstart, cend - cstart)) |
235 req.url(), tend - tstart, cend - cstart)) |
235 result += ['%s %s -- (%.3f sec, %.3f CPU sec)' % q |
236 result += ['%s %s -- (%.3f sec, %.3f CPU sec)' % q |
333 # don't log form values they may contains sensitive information |
334 # don't log form values they may contains sensitive information |
334 self.debug('publish "%s" (%s, form params: %s)', path, |
335 self.debug('publish "%s" (%s, form params: %s)', path, |
335 req.session.sessionid, list(req.form)) |
336 req.session.sessionid, list(req.form)) |
336 # remove user callbacks on a new request (except for json controllers |
337 # remove user callbacks on a new request (except for json controllers |
337 # to avoid callbacks being unregistered before they could be called) |
338 # to avoid callbacks being unregistered before they could be called) |
338 tstart = clock() |
339 tstart = process_time() |
339 commited = False |
340 commited = False |
340 try: |
341 try: |
341 # standard processing of the request |
342 # standard processing of the request |
342 try: |
343 try: |
343 # apply CORS sanity checks |
344 # apply CORS sanity checks |
402 try: |
403 try: |
403 req.cnx.rollback() |
404 req.cnx.rollback() |
404 except Exception: |
405 except Exception: |
405 pass # ignore rollback error at this point |
406 pass # ignore rollback error at this point |
406 self.add_undo_link_to_msg(req) |
407 self.add_undo_link_to_msg(req) |
407 self.debug('query %s executed in %s sec', path, clock() - tstart) |
408 self.debug('query %s executed in %s sec', path, process_time() - tstart) |
408 return result |
409 return result |
409 |
410 |
410 # Error handlers |
411 # Error handlers |
411 |
412 |
412 def redirect_handler(self, req, ex): |
413 def redirect_handler(self, req, ex): |