Add timing information on traced function

[mistotebe]

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.

[mithro]

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!).

[mistotebe]

Hi @mithro, I've pushed an updated version. I ran make test, did not notice there being a pep8 target. Should be clean now.

[mithro]

Generally looks good. Can you think of any way to add a decent test for this functionality?

[mistotebe]

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.

[mistotebe]

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()