[10/10] git commit: [#6388] start capturing verbose logging in perf script

[br...@apache.org]

[#6388] start capturing verbose logging in perf script


Project: http://git-wip-us.apache.org/repos/asf/incubator-allura/repo
Commit: http://git-wip-us.apache.org/repos/asf/incubator-allura/commit/5d062a62
Tree: http://git-wip-us.apache.org/repos/asf/incubator-allura/tree/5d062a62
Diff: http://git-wip-us.apache.org/repos/asf/incubator-allura/diff/5d062a62

Branch: refs/heads/db/6388
Commit: 5d062a62928a2f21abb476946c3d036454d1ab82
Parents: 436a7ae
Author: Dave Brondsema <db...@slashdotmedia.com>
Authored: Wed Dec 18 22:39:51 2013 +0000
Committer: Dave Brondsema <db...@slashdotmedia.com>
Committed: Wed Dec 18 22:39:51 2013 +0000

----------------------------------------------------------------------
 scripts/perf/call_count.py | 29 +++++++++++++++++++++--------
 1 file changed, 21 insertions(+), 8 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/incubator-allura/blob/5d062a62/scripts/perf/call_count.py
----------------------------------------------------------------------
diff --git a/scripts/perf/call_count.py b/scripts/perf/call_count.py
index 2b8e15c..234f097 100755
--- a/scripts/perf/call_count.py
+++ b/scripts/perf/call_count.py
@@ -18,10 +18,12 @@
 #       under the License.
 
 import json
-from pprint import pprint
+import logging
 
 from pylons import tmpl_context as c
 from testfixtures import LogCapture
+from mock import patch
+import timermiddleware
 
 from allura import model as M
 from allura.lib.helpers import push_config
@@ -36,16 +38,23 @@ def main():
     setup(test)
     url = generate_wiki_thread(test)
     load_page(test, url)
-    load_page(test, url)
-    load_page(test, url)
+    #load_page(test, url)
+    #load_page(test, url)
     test.tearDown()
 
 
 def setup(test):
     # includes setting up mim
-    with patch_middleware_config({'stats.sample_rate': 1}):
-       test.setUp()
+    with patch_middleware_config({'stats.sample_rate': 1,
+                                  'stats.debug_line_length': 1000,
+                                  }), \
+         patch('timermiddleware.log.isEnabledFor', return_value=True):  # can't set this via logging configuration since setUp() will load a logging config and then start using it before we have a good place to tweak it
+        # TODO: disable logging to test.log
+        test.setUp()
 
+    tmw_log = logging.getLogger('timermiddleware')
+    tmw_log.disabled = 0  # gets disabled when .ini file is loaded; dumb.
+    tmw_log.setLevel(logging.DEBUG)
 
 def generate_wiki_thread(test):
     # automagically instantiate the app
@@ -70,11 +79,15 @@ def generate_wiki_thread(test):
 
 
 def load_page(test, url):
-    with LogCapture('stats') as l:
+
+    with LogCapture('stats') as stats, LogCapture('timermiddleware') as calls:
         print url, test.app.get(url, extra_environ=dict(username='*anonymous')).status
-    for r in l.records:
-        timings = json.loads(r.message)
+
+    for r in stats.records:
+        timings = json.loads(r.getMessage())
         print json.dumps(timings['call_counts'])
+    for r in calls.records:
+        print r.getMessage()
 
 if __name__ == '__main__':
     main()