# HG changeset patch
# User Denis Laxalde <denis.laxalde@logilab.fr>
# Date 1374487717 -7200
# Node ID 13ed6de4177473b3ef8a99a1b94873729eaa8a1c
# Parent  570208f74a840d4b4df382dca660268b9ba62046
[querier] Add timings to debug prints (DBG_RQL)

this may ease to spot some problematic queries

diff -r 570208f74a84 -r 13ed6de41774 server/sources/__init__.py
--- a/server/sources/__init__.py	Wed Jul 24 08:43:16 2013 +0200
+++ b/server/sources/__init__.py	Mon Jul 22 12:08:37 2013 +0200
@@ -21,6 +21,7 @@
 
 import itertools
 from os.path import join, splitext
+from time import time
 from datetime import datetime, timedelta
 from logging import getLogger
 
@@ -37,7 +38,9 @@
 
 def dbg_st_search(uri, union, varmap, args, cachekey=None, prefix='rql for'):
     if server.DEBUG & server.DBG_RQL:
+        global t
         print '  %s %s source: %s' % (prefix, uri, repr(union.as_string()))
+        t = time()
         if varmap:
             print '    using varmap', varmap
         if server.DEBUG & server.DBG_MORE:
@@ -51,9 +54,10 @@
 def dbg_results(results):
     if server.DEBUG & server.DBG_RQL:
         if len(results) > 10:
-            print '  -->', results[:10], '...', len(results)
+            print '  -->', results[:10], '...', len(results),
         else:
-            print '  -->', results
+            print '  -->', results,
+        print 'time: ', time() - t
     # return true so it can be used as assertion (and so be killed by python -O)
     return True