q icon indicating copy to clipboard operation
q copied to clipboard

Add timing information on traced function

Open mistotebe opened this issue 10 years ago • 5 comments

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.

mistotebe avatar Oct 14 '15 10:10 mistotebe

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

mithro avatar Oct 14 '15 10:10 mithro

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

mistotebe avatar Oct 14 '15 13:10 mistotebe

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

mithro avatar Oct 14 '15 23:10 mithro

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 avatar Oct 15 '15 14:10 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()

mistotebe avatar Oct 20 '15 10:10 mistotebe