Add timing information on traced function
q is very helpful when zeroing in on performance/timeout issues as well, make it even better by explicitly logging the time spent in the function.
Hi @mistotebe
Thanks for your patch! It looks like it currently isn't pep8 clean, can you please fix that?
=== Running pep8 on files
pep8 q.py setup.py test/test_basic.py
q.py:287:80: E501 line too long (96 > 79 characters)
q.py:305:80: E501 line too long (92 > 79 characters)
make: *** [pep8] Error 1
You should be able to run a make pep8 in the q directory (or even better yet a make all which will run the tests and build too!).
Hi @mithro, I've pushed an updated version. I ran make test, did not notice there being a pep8 target. Should be clean now.
Generally looks good. Can you think of any way to add a decent test for this functionality?
It shows you the timing so probably not, I could try adding a sleep() to it and check that it shows at least as much. Not sure.
There is an alternative approach to the logging that might actually be even more useful (potentially even replacing the "insert a blank line if we had more than 5 s between messages" bit):
- for each message, log time since last message e.g.: 2.3s(+0.9s)
- upon leaving the trace(), log time spent in that function e.g.: 2.3s(+0.9s) --> 1.2s my_function()