profiling line by line
Hi, I am using the prun feature of Ipython which is very helpful. I was wondering though if theres anything for Python that would allow line-by-line profiling (ie a time for each line of code) like the MATLAB profiler? Cheers Robin
On Mon, Sep 15, 2008 at 05:27, Robin <robince@gmail.com> wrote:
Hi,
I am using the prun feature of Ipython which is very helpful.
I was wondering though if theres anything for Python that would allow line-by-line profiling (ie a time for each line of code) like the MATLAB profiler?
I don't think there is anything out there at the moment. Python does have a hook for line-by-line tracing, and one can make a line-by-line profiler from it. To do it with the least overhead, you need to use the C API for it and a C callback. I do have some Cython code that does this. It needs a little bit more work, though. I'll try to push it out soonish. -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
On Mon, Sep 15, 2008 at 5:18 PM, Robert Kern <robert.kern@gmail.com> wrote:
I do have some Cython code that does this. It needs a little bit more work, though. I'll try to push it out soonish.
That would make me an extremely happy user, I've been looking for this for years! I can't imagine I'm the only one who profiles some hundred lines of code and ends up with 90% of total time in the dot-function Arnar
On Mon, Sep 15, 2008 at 5:13 PM, Arnar Flatberg <arnar.flatberg@gmail.com> wrote:
On Mon, Sep 15, 2008 at 5:18 PM, Robert Kern <robert.kern@gmail.com> wrote:
I do have some Cython code that does this. It needs a little bit more work, though. I'll try to push it out soonish.
That would make me an extremely happy user, I've been looking for this for years! I can't imagine I'm the only one who profiles some hundred lines of code and ends up with 90% of total time in the dot-function
Yes, that would be terrific - the profiler is about the only thing I miss from Matlab... Especially after an afternoon of refactoring everything into tiny functions to get anything useful out of the normal profiler and see where the bottleneck in my code was. Robin
On Mon, Sep 15, 2008 at 11:13, Arnar Flatberg <arnar.flatberg@gmail.com> wrote:
That would make me an extremely happy user, I've been looking for this for years! I can't imagine I'm the only one who profiles some hundred lines of code and ends up with 90% of total time in the dot-function
For the time being, you can grab it here: http://www.enthought.com/~rkern/cgi-bin/hgwebdir.cgi/line_profiler/ It requires Cython and a C compiler to build. I'm still debating myself about the desired workflow for using it, but for now, it only profiles functions which you have registered with it. I have made the profiler work as a decorator to make this easy. E.g., from line_profiler import LineProfiler profile = LineProfiler() @profile def my_slow_func(): ... profile.dump_stats('my_slow_func.lprof') This is kind of inconvenient, so I have a little script that handles everything except for the @profile itself. It started as a script to run cProfile nicely, so it actually does that by default. I took pystone.py from the Python source and added a couple of @profile decorators to demonstrate: [line_profiler]$ ./kernprof.py --help Usage: ./kernprof.py [-s setupfile] [-o output_file_path] scriptfile [arg] ... Options: -h, --help show this help message and exit -l, --line-by-line Use the line-by-line profiler from the line_profiler module instead of cProfile. Implies --builtin. -b, --builtin Put 'profile' in the builtins. Use 'profile.enable()' and 'profile.disable()' in your code to turn it on and off, or '@profile' to decorate a single function, or 'with profile:' to profile a single section of code. -o OUTFILE, --outfile=OUTFILE Save stats to <outfile> -s SETUP, --setup=SETUP Code to execute before the code to profile [line_profiler]$ ./kernprof.py -l pystone.py Pystone(1.1) time for 50000 passes = 11.34 This machine benchmarks at 4409.17 pystones/second Wrote profile results to pystone.py.lprof [line_profiler]$ ./view_line_prof.py pystone.py.lprof Timer unit: 1e-06 s File: pystone.py Function: Proc0 at line 79 Total time: 8.46516 s Line # Hits Time % Time Line Contents ===================================================== 79 @profile 80 def Proc0(loops=LOOPS): 81 global IntGlob 82 global BoolGlob 83 global Char1Glob 84 global Char2Glob 85 global Array1Glob 86 global Array2Glob 87 global PtrGlb 88 global PtrGlbNext 89 90 1 11 0.0 starttime = clock() 91 50001 128471 1.5 for i in range(loops): 92 50000 125580 1.5 pass 93 1 28 0.0 nulltime = clock() - starttime 94 95 1 21 0.0 PtrGlbNext = Record() 96 1 8 0.0 PtrGlb = Record() 97 1 2 0.0 PtrGlb.PtrComp = PtrGlbNext 98 1 2 0.0 PtrGlb.Discr = Ident1 99 1 2 0.0 PtrGlb.EnumComp = Ident3 100 1 3 0.0 PtrGlb.IntComp = 40 101 1 3 0.0 PtrGlb.StringComp = "DHRYSTONE PROGRAM, SOME STRING" 102 1 2 0.0 String1Loc = "DHRYSTONE PROGRAM, 1'ST STRING" 103 1 5 0.0 Array2Glob[8][7] = 10 104 105 1 6 0.0 starttime = clock() 106 107 50001 123728 1.5 for i in range(loops): 108 50000 220345 2.6 Proc5() 109 50000 238459 2.8 Proc4() 110 50000 119789 1.4 IntLoc1 = 2 111 50000 123639 1.5 IntLoc2 = 3 112 50000 116081 1.4 String2Loc = "DHRYSTONE PROGRAM, 2'ND STRING" 113 50000 119487 1.4 EnumLoc = Ident2 114 50000 653711 7.7 BoolGlob = not Func2(String1Loc, String2Loc) 115 50000 130518 1.5 while IntLoc1 < IntLoc2: 116 50000 132916 1.6 IntLoc3 = 5 * IntLoc1 - IntLoc2 117 50000 235608 2.8 IntLoc3 = Proc7(IntLoc1, IntLoc2) 118 50000 147952 1.7 IntLoc1 = IntLoc1 + 1 119 50000 664949 7.9 Proc8(Array1Glob, Array2Glob, IntLoc1, IntLoc3) 120 50000 1710897 20.2 PtrGlb = Proc1(PtrGlb) 121 50000 130536 1.5 CharIndex = 'A' 122 50000 130006 1.5 while CharIndex <= Char2Glob: 123 100000 546206 6.5 if EnumLoc == Func1(CharIndex, 'C'): 124 EnumLoc = Proc6(Ident1) 125 100000 353517 4.2 CharIndex = chr(ord(CharIndex)+1) 126 50000 133892 1.6 IntLoc3 = IntLoc2 * IntLoc1 127 50000 126802 1.5 IntLoc2 = IntLoc3 / IntLoc1 128 50000 139932 1.7 IntLoc2 = 7 * (IntLoc3 - IntLoc2) - IntLoc1 129 50000 1912016 22.6 IntLoc1 = Proc2(IntLoc1) 130 131 1 12 0.0 benchtime = clock() - starttime - nulltime 132 1 18 0.0 return benchtime, (loops / benchtime) File: pystone.py Function: Proc2 at line 150 Total time: 0.612312 s Line # Hits Time % Time Line Contents ===================================================== 150 @profile 151 def Proc2(IntParIO): 152 50000 75147 12.3 IntLoc = IntParIO + 10 153 50000 64428 10.5 while 1: 154 50000 70023 11.4 if Char1Glob == 'A': 155 50000 69017 11.3 IntLoc = IntLoc - 1 156 50000 70189 11.5 IntParIO = IntLoc - IntGlob 157 50000 65503 10.7 EnumLoc = Ident1 158 50000 68191 11.1 if EnumLoc == Ident1: 159 50000 66168 10.8 break 160 50000 63646 10.4 return IntParIO I used to call kernprof.py lsprof.py, but then I realized that's what cProfile used to be named when it was outside of the stdlib. So I'm just going to call it kernprof until a better name comes along. So, I could use some comments on the workflow. Does this look sensible to everyone? How else would you like to use it? -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
On Wed, Sep 17, 2008 at 3:56 AM, Robert Kern <robert.kern@gmail.com> wrote:
So, I could use some comments on the workflow. Does this look sensible to everyone? How else would you like to use it?
Works for me. I would love to use it as a part of an ipython session. Initially, I sprinkled som $profile in a library of my own, then I thought I would use the -s (SETUP) option to initialize some data to pass into the $profiled functions. However, I have probably misunderstood the meaning of the -s option. Could you give an example of its use? I ended in doing a %edit in ipython to write a small test script with testdata and library imports, used kernprof.py and view_line_prof.py from ipython and captured the output from view_line_prof into ipython. Pheew .... now, there's perhaps an easier way? BTW, in the requirements you may want to mention argparse (view_line_prof.py) Thanks for sharing ! Arnar
On Wed, Sep 17, 2008 at 07:12, Arnar Flatberg <arnar.flatberg@gmail.com> wrote:
On Wed, Sep 17, 2008 at 3:56 AM, Robert Kern <robert.kern@gmail.com> wrote:
So, I could use some comments on the workflow. Does this look sensible to everyone? How else would you like to use it?
Works for me. I would love to use it as a part of an ipython session. Initially, I sprinkled som $profile in a library of my own, then I thought I would use the -s (SETUP) option to initialize some data to pass into the $profiled functions. However, I have probably misunderstood the meaning of the -s option. Could you give an example of its use?
It's mostly for using cProfile on a whole script. Since line_profiler is already only active for certain functions, it's probably not all that useful. At the time I added the feature, I was trying to profile (part of) a GUI program using wx and VTK, both of which take a long time to load and taking up a good chunk of my profile time. If I had a script, load_wx_vtk.py: import wx from enthought.tvtk import tvtk Then I could just do: $ kernprof.py -s load_wx_vtk.py my_script.py The script at the end still needs to be the main thing that executes.
I ended in doing a %edit in ipython to write a small test script with testdata and library imports, used kernprof.py and view_line_prof.py from ipython and captured the output from view_line_prof into ipython. Pheew .... now, there's perhaps an easier way?
It should be straightforward to make an ipython %magic, yes. There are some questions as to how that would work, though. Do you want the top-level code in the file to be profiled? Or do you just want functions defined inside to be profiled? Do you want to be able to specify functions defined outside of the code to be profiled?
BTW, in the requirements you may want to mention argparse (view_line_prof.py)
Oops! Yes. -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
On Wed, Sep 17, 2008 at 10:33 PM, Robert Kern <robert.kern@gmail.com> wrote:
On Wed, Sep 17, 2008 at 07:12, Arnar Flatberg <arnar.flatberg@gmail.com> wrote:
On Wed, Sep 17, 2008 at 3:56 AM, Robert Kern <robert.kern@gmail.com>
wrote:
It should be straightforward to make an ipython %magic, yes. There are some questions as to how that would work, though. Do you want the top-level code in the file to be profiled?
I dont think that will be my primary use.
Or do you just want functions defined inside to be profiled?
That was my initial thought, yes
Do you want to be able to specify functions defined outside of the code to be profiled?
Sounds complicated, but that would be nice. I'll play around with ipythons %magic to see if I can get a workflow Im comfortable with. I was thinking something in the line of ipython's %prun for a quick looksy, and the possibility to easily write small scripts to test different inputs (small/large arrays etc.) to a specific function. Any recommendations are very welcome. I do not have much experience in profiling code. Arnar
On Wed, Sep 17, 2008 at 07:12, Arnar Flatberg <arnar.flatberg@gmail.com> wrote:
On Wed, Sep 17, 2008 at 3:56 AM, Robert Kern <robert.kern@gmail.com> wrote:
So, I could use some comments on the workflow. Does this look sensible to everyone? How else would you like to use it?
Works for me. I would love to use it as a part of an ipython session. Initially, I sprinkled som $profile in a library of my own, then I thought I would use the -s (SETUP) option to initialize some data to pass into the $profiled functions. However, I have probably misunderstood the meaning of the -s option. Could you give an example of its use? I ended in doing a %edit in ipython to write a small test script with testdata and library imports, used kernprof.py and view_line_prof.py from ipython and captured the output from view_line_prof into ipython. Pheew .... now, there's perhaps an easier way?
There is now! Add import line_profiler ip.expose_magic('lprun', line_profiler.magic_lprun) to your ipy_user_conf.py . In [1]: %lprun? Type: Magic function Base Class: <type 'instancemethod'> Namespace: IPython internal File: /Users/rkern/hg/line_profiler/line_profiler.py Definition: %lprun(self, parameter_s='') Docstring: Execute a statement under the line-by-line profiler from the line_profiler module. Usage: %lprun -f func1 -f func2 <statement> The given statement (which doesn't require quote marks) is run via the LineProfiler. Profiling is enabled for the functions specified by the -f options. The statistics will be shown side-by-side with the code through the pager once the statement has completed. Options: -f <function>: LineProfiler only profiles functions and methods it is told to profile. This option tells the profiler about these functions. Multiple -f options may be used. The argument may be any expression that gives a Python function or method object. However, one must be careful to avoid spaces that may confuse the option parser. Additionally, functions defined in the interpreter at the In[] prompt or via %run currently cannot be displayed. Write these functions out to a separate file and import them. One or more -f options are required to get any useful results. -D <filename>: dump the raw statistics out to a marshal file on disk. The usual extension for this is ".lprof". These statistics may be viewed later by running line_profiler.py as a script. -T <filename>: dump the text-formatted statistics with the code side-by-side out to a text file. -r: return the LineProfiler object after it has completed profiling.
BTW, in the requirements you may want to mention argparse (view_line_prof.py)
'tis gone now. The script and the requirement for argparse. Now you just use line_profiler.py as a script. -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
Hey, On Fri, Sep 26, 2008 at 5:36 PM, Robert Kern <robert.kern@gmail.com> wrote:
There is now! Add
import line_profiler ip.expose_magic('lprun', line_profiler.magic_lprun)
to your ipy_user_conf.py .
Mmh, should we ship this out of the box in ipython? The C dependency is the only thing that gives me a bit of pause. There goes our pure C, easy to build binaries for... On the other hand, me wants :) What's your take on that? f
On Sat, Sep 27, 2008 at 00:50, Fernando Perez <fperez.net@gmail.com> wrote:
Hey,
On Fri, Sep 26, 2008 at 5:36 PM, Robert Kern <robert.kern@gmail.com> wrote:
There is now! Add
import line_profiler ip.expose_magic('lprun', line_profiler.magic_lprun)
to your ipy_user_conf.py .
Mmh, should we ship this out of the box in ipython? The C dependency is the only thing that gives me a bit of pause. There goes our pure C, easy to build binaries for... On the other hand, me wants :)
What's your take on that?
I'd prefer not to. The exclusion of C modules is an eminently reasonable one. You would inevitably make it optional, and my opinion is that optional functionality is best handled by separate packages. Feel free to add it as "highly recommended" in the IPython installation instructions, though. :-) -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
On Sat, Sep 27, 2008 at 1:31 AM, Robert Kern <robert.kern@gmail.com> wrote:
Mmh, should we ship this out of the box in ipython? The C dependency is the only thing that gives me a bit of pause. There goes our pure C, easy to build binaries for... On the other hand, me wants :)
s/pure C/pure Python/ grr...
What's your take on that?
I'd prefer not to. The exclusion of C modules is an eminently reasonable one. You would inevitably make it optional, and my opinion is that optional functionality is best handled by separate packages.
Agreed. Not having C dependencies simplifies lots of things for us. If we ever gain an unavoidable one, we can then revisit this.
Feel free to add it as "highly recommended" in the IPython installation instructions, though. :-)
Most certainly will. It would be better to have a more stable release/download link than your hg repo. Do you have a page or a Pypi link for it yet? A little readme? Cheers, f
On Sat, Sep 27, 2008 at 2:36 AM, Robert Kern <robert.kern@gmail.com> wrote:
On Wed, Sep 17, 2008 at 07:12, Arnar Flatberg <arnar.flatberg@gmail.com> wrote:
On Wed, Sep 17, 2008 at 3:56 AM, Robert Kern <robert.kern@gmail.com>
wrote:
There is now!
Excellent work! I've had no problem with using the ipython-support (lprun), and it works for all my usecases, so far.
Feel free to add it as "highly recommended" in the IPython installation instructions, though. :-)
Most certainly will. It would be better to have a more stable release/download link than your hg repo. Do you have a page or a Pypi link for it yet? A little readme?
I thought the hg-repos distribution was painless. The doc string says it all for usage, however a note on the ipy_user_conf setup should probably be documented some other place than just this thread. Thanks, Arnar
On Wed, Sep 17, 2008 at 3:56 AM, Robert Kern <robert.kern@gmail.com> wrote:
On Mon, Sep 15, 2008 at 11:13, Arnar Flatberg <arnar.flatberg@gmail.com> wrote:
That would make me an extremely happy user, I've been looking for this for years! I can't imagine I'm the only one who profiles some hundred lines of code and ends up with 90% of total time in the dot-function
For the time being, you can grab it here:
http://www.enthought.com/~rkern/cgi-bin/hgwebdir.cgi/line_profiler/
It requires Cython and a C compiler to build. I'm still debating myself about the desired workflow for using it, but for now, it only profiles functions which you have registered with it. I have made the profiler work as a decorator to make this easy. E.g.,
from line_profiler import LineProfiler
profile = LineProfiler()
@profile def my_slow_func(): ...
profile.dump_stats('my_slow_func.lprof')
This is kind of inconvenient, so I have a little script that handles everything except for the @profile itself. It started as a script to run cProfile nicely, so it actually does that by default.
I took pystone.py from the Python source and added a couple of @profile decorators to demonstrate:
[line_profiler]$ ./kernprof.py --help Usage: ./kernprof.py [-s setupfile] [-o output_file_path] scriptfile [arg] ...
Options: -h, --help show this help message and exit -l, --line-by-line Use the line-by-line profiler from the line_profiler module instead of cProfile. Implies --builtin. -b, --builtin Put 'profile' in the builtins. Use 'profile.enable()' and 'profile.disable()' in your code to turn it on and off, or '@profile' to decorate a single function, or 'with profile:' to profile a single section of code. -o OUTFILE, --outfile=OUTFILE Save stats to <outfile> -s SETUP, --setup=SETUP Code to execute before the code to profile
[line_profiler]$ ./kernprof.py -l pystone.py Pystone(1.1) time for 50000 passes = 11.34 This machine benchmarks at 4409.17 pystones/second Wrote profile results to pystone.py.lprof
[line_profiler]$ ./view_line_prof.py pystone.py.lprof Timer unit: 1e-06 s
File: pystone.py Function: Proc0 at line 79 Total time: 8.46516 s [...]
This is what I am getting: $ ./kernprof.py -l pystone.py Wrote profile results to pystone.py.lprof $ ./view_line_prof.py pystone.py.lprof Timer unit: 1e-06 s $ So I think you meant: $ ./kernprof.py -l mystone.py 20628 Wrote profile results to mystone.py.lprof $ ./view_line_prof.py mystone.py.lprof Timer unit: 1e-06 s File: pystone.py Function: Proc0 at line 79 Total time: 13.0803 s [...] Now it works. This is an excellent piece of software! Nice job. Just today I needed such a thing! How do you easily install it? I usually do "python setup.py install --home=~/lib" and I have the PYTHONPATH + PATH setup in my .bashrc, but I then need to manually remove the stuff from my ~/lib if I want to uninstall, which sucks. So this time I just did "python setup.py build" and moved the .so file manually to the current dir. But there must be a better way. What is your workflow? Anyway, so I used it on my code and here is what I got: File: hermes1d/mesh.py Function: integrate_function at line 119 Total time: 0.647412 s Line # Hits Time % Time Line Contents ===================================================== 119 @profile 120 def integrate_function(self, f): 121 """ 122 Integrate the function "f" on the element. 123 """ 124 96 1091 0.2 from numpy import array 125 96 461070 71.2 from scipy.integrate import quadrature 126 96 496 0.1 a, b = self.nodes[0].x, self.nodes[1].x 127 96 418 0.1 def func(x): 128 #print x 129 #print array([f.f(y) for y in x]) 130 return array([f.f(y) for y in x]) 131 96 183903 28.4 val, err = quadrature(func, a, b) 132 #print val, a, b 133 #stop 134 96 434 0.1 return val This is interesting, because 70% of time is spent on "from scipy.integrate import quadrature". So this is not good. So I moved it out and voila! My code is 3.4x faster. I really didn't know that importing (scipy.integrate) is *so* slow. File: hermes1d/mesh.py Function: integrate_function at line 121 Total time: 0.189429 s Line # Hits Time % Time Line Contents ===================================================== 121 @profile 122 def integrate_function(self, f): 123 """ 124 Integrate the function "f" on the element. 125 """ 126 96 1080 0.6 from numpy import array 127 96 499 0.3 a, b = self.nodes[0].x, self.nodes[1].x 128 96 408 0.2 def func(x): 129 #print x 130 #print array([f.f(y) for y in x]) 131 return array([f.f(y) for y in x]) 132 96 187020 98.7 val, err = quadrature(func, a, b) 133 #print val, a, b 134 #stop 135 96 422 0.2 return val Btw, after profiling quadrature in scipy: 110 384 1241 0.1 err = 100.0 111 384 1184 0.1 val = err 112 384 1167 0.1 n = 1 113 384 4086 0.5 vfunc = vectorize1(func, args, vec_func=vec_func) 114 1152 4509 0.5 while (err > tol) and (n < maxiter): 115 768 879911 97.4 newval = fixed_quad(vfunc, a, b, (), n)[0] 116 768 4072 0.5 err = abs(newval-val) 117 768 2470 0.3 val = newval 118 768 2513 0.3 n = n + 1 119 384 1381 0.2 if n == maxiter: 120 print "maxiter (%d) exceeded. Latest difference = %e" % (n,err) 121 384 1225 0.1 return val, err And fixed_quad: 46 768 630714 74.4 [x,w] = p_roots(n) 47 768 8757 1.0 x = real(x) 48 768 13312 1.6 ainf, binf = map(isinf,(a,b)) 49 768 2912 0.3 if ainf or binf: 50 raise ValueError, "Gaussian quadrature is only available for " \ 51 "finite limits." 52 768 22106 2.6 y = (b-a)*(x+1)/2.0 + a 53 768 170229 20.1 return (b-a)/2.0*sum(w*func(y,*args),0), None it gives interesting results. For example in my case, where I need to call this often, I should cache the p_roots results. Anyways, this profiler is exciting, it makes things easy to profile. Ondrej
On Wed, Sep 17, 2008 at 18:09, Ondrej Certik <ondrej@certik.cz> wrote:
On Wed, Sep 17, 2008 at 3:56 AM, Robert Kern <robert.kern@gmail.com> wrote:
On Mon, Sep 15, 2008 at 11:13, Arnar Flatberg <arnar.flatberg@gmail.com> wrote:
That would make me an extremely happy user, I've been looking for this for years! I can't imagine I'm the only one who profiles some hundred lines of code and ends up with 90% of total time in the dot-function
For the time being, you can grab it here:
http://www.enthought.com/~rkern/cgi-bin/hgwebdir.cgi/line_profiler/
It requires Cython and a C compiler to build. I'm still debating myself about the desired workflow for using it, but for now, it only profiles functions which you have registered with it. I have made the profiler work as a decorator to make this easy. E.g.,
from line_profiler import LineProfiler
profile = LineProfiler()
@profile def my_slow_func(): ...
profile.dump_stats('my_slow_func.lprof')
This is kind of inconvenient, so I have a little script that handles everything except for the @profile itself. It started as a script to run cProfile nicely, so it actually does that by default.
I took pystone.py from the Python source and added a couple of @profile decorators to demonstrate:
[line_profiler]$ ./kernprof.py --help Usage: ./kernprof.py [-s setupfile] [-o output_file_path] scriptfile [arg] ...
Options: -h, --help show this help message and exit -l, --line-by-line Use the line-by-line profiler from the line_profiler module instead of cProfile. Implies --builtin. -b, --builtin Put 'profile' in the builtins. Use 'profile.enable()' and 'profile.disable()' in your code to turn it on and off, or '@profile' to decorate a single function, or 'with profile:' to profile a single section of code. -o OUTFILE, --outfile=OUTFILE Save stats to <outfile> -s SETUP, --setup=SETUP Code to execute before the code to profile
[line_profiler]$ ./kernprof.py -l pystone.py Pystone(1.1) time for 50000 passes = 11.34 This machine benchmarks at 4409.17 pystones/second Wrote profile results to pystone.py.lprof
[line_profiler]$ ./view_line_prof.py pystone.py.lprof Timer unit: 1e-06 s
File: pystone.py Function: Proc0 at line 79 Total time: 8.46516 s [...]
This is what I am getting:
$ ./kernprof.py -l pystone.py Wrote profile results to pystone.py.lprof $ ./view_line_prof.py pystone.py.lprof Timer unit: 1e-06 s
$
So I think you meant:
$ ./kernprof.py -l mystone.py 20628 Wrote profile results to mystone.py.lprof $ ./view_line_prof.py mystone.py.lprof Timer unit: 1e-06 s
File: pystone.py Function: Proc0 at line 79 Total time: 13.0803 s [...]
Now it works.
No, I meant pystone.py. My script-finding code may have (incorrectly) found a different, uninstrumented pystone.py file somewhere else, though. Try with "./pystone.py".
This is an excellent piece of software! Nice job. Just today I needed such a thing!
How do you easily install it?
"python setup.py install" should have installed the module. I haven't done anything with the scripts, yet.
I usually do "python setup.py install --home=~/lib" and I have the PYTHONPATH + PATH setup in my .bashrc, but I then need to manually remove the stuff from my ~/lib if I want to uninstall, which sucks. So this time I just did "python setup.py build" and moved the .so file manually to the current dir. But there must be a better way. What is your workflow?
For things I am developing on, I build them in-place, using the setuptools "develop" command to add the appropriate path to the easy-install.pth file. To remove, I would just edit that file. For thing I'm not developing on, I usually build and install an egg if at all possible. But then, I'm typically on a single-user box where I'm root, so I sometimes do nasty and unsanitary things like chown -R rkern:rkern /usr/local/.
Anyway, so I used it on my code and here is what I got:
File: hermes1d/mesh.py Function: integrate_function at line 119 Total time: 0.647412 s
Line # Hits Time % Time Line Contents ===================================================== 119 @profile 120 def integrate_function(self, f): 121 """ 122 Integrate the function "f" on the element. 123 """ 124 96 1091 0.2 from numpy import array 125 96 461070 71.2 from scipy.integrate import quadrature 126 96 496 0.1 a, b = self.nodes[0].x, self.nodes[1].x 127 96 418 0.1 def func(x): 128 #print x 129 #print array([f.f(y) for y in x]) 130 return array([f.f(y) for y in x]) 131 96 183903 28.4 val, err = quadrature(func, a, b) 132 #print val, a, b 133 #stop 134 96 434 0.1 return val
This is interesting, because 70% of time is spent on "from scipy.integrate import quadrature". So this is not good.
So I moved it out and voila! My code is 3.4x faster. I really didn't know that importing (scipy.integrate) is *so* slow.
It should only be slow the first time. If it's not, then there's a problem somewhere (and I wouldn't put it past being in the profiler; it might screw up something in the import mechanism). Can you do the import both outside the function *and* inside to see if that changes the result? -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
On Thu, Sep 18, 2008 at 1:29 AM, Robert Kern <robert.kern@gmail.com> wrote:
On Wed, Sep 17, 2008 at 18:09, Ondrej Certik <ondrej@certik.cz> wrote:
On Wed, Sep 17, 2008 at 3:56 AM, Robert Kern <robert.kern@gmail.com> wrote:
On Mon, Sep 15, 2008 at 11:13, Arnar Flatberg <arnar.flatberg@gmail.com> wrote:
That would make me an extremely happy user, I've been looking for this for years! I can't imagine I'm the only one who profiles some hundred lines of code and ends up with 90% of total time in the dot-function
For the time being, you can grab it here:
http://www.enthought.com/~rkern/cgi-bin/hgwebdir.cgi/line_profiler/
It requires Cython and a C compiler to build. I'm still debating myself about the desired workflow for using it, but for now, it only profiles functions which you have registered with it. I have made the profiler work as a decorator to make this easy. E.g.,
from line_profiler import LineProfiler
profile = LineProfiler()
@profile def my_slow_func(): ...
profile.dump_stats('my_slow_func.lprof')
This is kind of inconvenient, so I have a little script that handles everything except for the @profile itself. It started as a script to run cProfile nicely, so it actually does that by default.
I took pystone.py from the Python source and added a couple of @profile decorators to demonstrate:
[line_profiler]$ ./kernprof.py --help Usage: ./kernprof.py [-s setupfile] [-o output_file_path] scriptfile [arg] ...
Options: -h, --help show this help message and exit -l, --line-by-line Use the line-by-line profiler from the line_profiler module instead of cProfile. Implies --builtin. -b, --builtin Put 'profile' in the builtins. Use 'profile.enable()' and 'profile.disable()' in your code to turn it on and off, or '@profile' to decorate a single function, or 'with profile:' to profile a single section of code. -o OUTFILE, --outfile=OUTFILE Save stats to <outfile> -s SETUP, --setup=SETUP Code to execute before the code to profile
[line_profiler]$ ./kernprof.py -l pystone.py Pystone(1.1) time for 50000 passes = 11.34 This machine benchmarks at 4409.17 pystones/second Wrote profile results to pystone.py.lprof
[line_profiler]$ ./view_line_prof.py pystone.py.lprof Timer unit: 1e-06 s
File: pystone.py Function: Proc0 at line 79 Total time: 8.46516 s [...]
This is what I am getting:
$ ./kernprof.py -l pystone.py Wrote profile results to pystone.py.lprof $ ./view_line_prof.py pystone.py.lprof Timer unit: 1e-06 s
$
So I think you meant:
$ ./kernprof.py -l mystone.py 20628 Wrote profile results to mystone.py.lprof $ ./view_line_prof.py mystone.py.lprof Timer unit: 1e-06 s
File: pystone.py Function: Proc0 at line 79 Total time: 13.0803 s [...]
Now it works.
No, I meant pystone.py. My script-finding code may have (incorrectly) found a different, uninstrumented pystone.py file somewhere else, though. Try with "./pystone.py".
This is an excellent piece of software! Nice job. Just today I needed such a thing!
How do you easily install it?
"python setup.py install" should have installed the module. I haven't done anything with the scripts, yet.
I usually do "python setup.py install --home=~/lib" and I have the PYTHONPATH + PATH setup in my .bashrc, but I then need to manually remove the stuff from my ~/lib if I want to uninstall, which sucks. So this time I just did "python setup.py build" and moved the .so file manually to the current dir. But there must be a better way. What is your workflow?
For things I am developing on, I build them in-place, using the setuptools "develop" command to add the appropriate path to the easy-install.pth file. To remove, I would just edit that file.
For thing I'm not developing on, I usually build and install an egg if at all possible.
But then, I'm typically on a single-user box where I'm root, so I sometimes do nasty and unsanitary things like chown -R rkern:rkern /usr/local/.
Anyway, so I used it on my code and here is what I got:
File: hermes1d/mesh.py Function: integrate_function at line 119 Total time: 0.647412 s
Line # Hits Time % Time Line Contents ===================================================== 119 @profile 120 def integrate_function(self, f): 121 """ 122 Integrate the function "f" on the element. 123 """ 124 96 1091 0.2 from numpy import array 125 96 461070 71.2 from scipy.integrate import quadrature 126 96 496 0.1 a, b = self.nodes[0].x, self.nodes[1].x 127 96 418 0.1 def func(x): 128 #print x 129 #print array([f.f(y) for y in x]) 130 return array([f.f(y) for y in x]) 131 96 183903 28.4 val, err = quadrature(func, a, b) 132 #print val, a, b 133 #stop 134 96 434 0.1 return val
This is interesting, because 70% of time is spent on "from scipy.integrate import quadrature". So this is not good.
So I moved it out and voila! My code is 3.4x faster. I really didn't know that importing (scipy.integrate) is *so* slow.
It should only be slow the first time. If it's not, then there's a problem somewhere (and I wouldn't put it past being in the profiler; it might screw up something in the import mechanism). Can you do the import both outside the function *and* inside to see if that changes the result?
Sure. "b.py": from scipy.integrate import quadrature --------------- def a(): b = 1 for x in range(1000000): a() --------------- "a.py": --------------- def a(): from scipy.integrate import quadrature b = 1 for x in range(1000000): a() --------------- and: ondra@pc232:~/repos/hermes1d$ time python a.py real 0m2.655s user 0m2.612s sys 0m0.044s ondra@pc232:~/repos/hermes1d$ time python b.py real 0m0.620s user 0m0.540s sys 0m0.080s So I guess that speaks for itself. Don't have time to dig more, but I think it's this line in scipy/integrate/__init__: __all__ = filter(lambda s:not s.startswith('_'),dir()) But maybe also something else, I don't know. Ondrej Ondrej
On Thu, Sep 18, 2008 at 05:46, Ondrej Certik <ondrej@certik.cz> wrote:
On Thu, Sep 18, 2008 at 1:29 AM, Robert Kern <robert.kern@gmail.com> wrote:
On Wed, Sep 17, 2008 at 18:09, Ondrej Certik <ondrej@certik.cz> wrote:
Anyway, so I used it on my code and here is what I got:
File: hermes1d/mesh.py Function: integrate_function at line 119 Total time: 0.647412 s
Line # Hits Time % Time Line Contents ===================================================== 119 @profile 120 def integrate_function(self, f): 121 """ 122 Integrate the function "f" on the element. 123 """ 124 96 1091 0.2 from numpy import array 125 96 461070 71.2 from scipy.integrate import quadrature 126 96 496 0.1 a, b = self.nodes[0].x, self.nodes[1].x 127 96 418 0.1 def func(x): 128 #print x 129 #print array([f.f(y) for y in x]) 130 return array([f.f(y) for y in x]) 131 96 183903 28.4 val, err = quadrature(func, a, b) 132 #print val, a, b 133 #stop 134 96 434 0.1 return val
This is interesting, because 70% of time is spent on "from scipy.integrate import quadrature". So this is not good.
So I moved it out and voila! My code is 3.4x faster. I really didn't know that importing (scipy.integrate) is *so* slow.
It should only be slow the first time. If it's not, then there's a problem somewhere (and I wouldn't put it past being in the profiler; it might screw up something in the import mechanism). Can you do the import both outside the function *and* inside to see if that changes the result?
Sure. "b.py":
from scipy.integrate import quadrature
--------------- def a(): b = 1
for x in range(1000000): a() ---------------
"a.py":
--------------- def a(): from scipy.integrate import quadrature b = 1
for x in range(1000000): a() ---------------
and:
ondra@pc232:~/repos/hermes1d$ time python a.py
real 0m2.655s user 0m2.612s sys 0m0.044s
ondra@pc232:~/repos/hermes1d$ time python b.py
real 0m0.620s user 0m0.540s sys 0m0.080s
So I guess that speaks for itself. Don't have time to dig more, but I think it's this line in scipy/integrate/__init__:
__all__ = filter(lambda s:not s.startswith('_'),dir())
I don't see how. I can verify that it only gets executed once. import sys print 'scipy.integrate.__init__' __all__ = filter(lambda s:sys.stdout.write('.') or not s.startswith('_'),dir()) $ time python a.py scipy.integrate.__init__ .............................python a.py 2.26s user 0.72s system 98% cpu 3.009 total Anyways, a million repetitions adds about 2s to your time (oh, you may also want to do this a couple of times and wait for the times to settle down in order get the same effect from the disk caches). That's about 2 microseconds per import. The cost you are seeing in your profile is much, much greater than 2 us * 96, so I think it really is the first import that makes up the bulk of it. -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
On Wed, Sep 17, 2008 at 18:29, Robert Kern <robert.kern@gmail.com> wrote:
On Wed, Sep 17, 2008 at 18:09, Ondrej Certik <ondrej@certik.cz> wrote:
This is what I am getting:
$ ./kernprof.py -l pystone.py Wrote profile results to pystone.py.lprof $ ./view_line_prof.py pystone.py.lprof Timer unit: 1e-06 s
$
So I think you meant:
$ ./kernprof.py -l mystone.py 20628 Wrote profile results to mystone.py.lprof $ ./view_line_prof.py mystone.py.lprof Timer unit: 1e-06 s
File: pystone.py Function: Proc0 at line 79 Total time: 13.0803 s [...]
Now it works.
No, I meant pystone.py. My script-finding code may have (incorrectly) found a different, uninstrumented pystone.py file somewhere else, though. Try with "./pystone.py".
There was a bug in how I was constructing the munged namespaces. Fixed now. -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
Hi Robert, Robert Kern wrote:
On Mon, Sep 15, 2008 at 11:13, Arnar Flatberg <arnar.flatberg@gmail.com> wrote:
That would make me an extremely happy user, I've been looking for this for years! I can't imagine I'm the only one who profiles some hundred lines of code and ends up with 90% of total time in the dot-function
For the time being, you can grab it here:
http://www.enthought.com/~rkern/cgi-bin/hgwebdir.cgi/line_profiler/
It requires Cython and a C compiler to build. I'm still debating myself about the desired workflow for using it, but for now, it only profiles functions which you have registered with it. I have made the profiler work as a decorator to make this easy. E.g.,
many thanks for this! I have wanted to try out the profiler but failed to build it (changeset 6 0de294aa75bf): $ python setup.py install --root=/home/share/software/ running install running build running build_py creating build creating build/lib.linux-i686-2.4 copying line_profiler.py -> build/lib.linux-i686-2.4 running build_ext cythoning _line_profiler.pyx to _line_profiler.c building '_line_profiler' extension creating build/temp.linux-i686-2.4 i486-pc-linux-gnu-gcc -pthread -fno-strict-aliasing -DNDEBUG -fPIC -I/usr/include/python2.4 -c -I/usr/include/python2.4 -c _line_profiler.c -o build/temp.linux-i686-2.4/_line_profiler.o _line_profiler.c:1614: error: 'T_LONGLONG' undeclared here (not in a function) error: command 'i486-pc-linux-gnu-gcc' failed with exit status 1 I have cython-0.9.8.1 and GCC 4.1.2, 32-bit machine. r.
On Thu, Sep 18, 2008 at 1:01 PM, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
Hi Robert,
Robert Kern wrote:
On Mon, Sep 15, 2008 at 11:13, Arnar Flatberg <arnar.flatberg@gmail.com> wrote:
That would make me an extremely happy user, I've been looking for this for years! I can't imagine I'm the only one who profiles some hundred lines of code and ends up with 90% of total time in the dot-function
For the time being, you can grab it here:
http://www.enthought.com/~rkern/cgi-bin/hgwebdir.cgi/line_profiler/
It requires Cython and a C compiler to build. I'm still debating myself about the desired workflow for using it, but for now, it only profiles functions which you have registered with it. I have made the profiler work as a decorator to make this easy. E.g.,
many thanks for this! I have wanted to try out the profiler but failed to build it (changeset 6 0de294aa75bf):
$ python setup.py install --root=/home/share/software/ running install running build running build_py creating build creating build/lib.linux-i686-2.4 copying line_profiler.py -> build/lib.linux-i686-2.4 running build_ext cythoning _line_profiler.pyx to _line_profiler.c building '_line_profiler' extension creating build/temp.linux-i686-2.4 i486-pc-linux-gnu-gcc -pthread -fno-strict-aliasing -DNDEBUG -fPIC -I/usr/include/python2.4 -c -I/usr/include/python2.4 -c _line_profiler.c -o build/temp.linux-i686-2.4/_line_profiler.o _line_profiler.c:1614: error: 'T_LONGLONG' undeclared here (not in a function) error: command 'i486-pc-linux-gnu-gcc' failed with exit status 1
I have cython-0.9.8.1 and GCC 4.1.2, 32-bit machine.
I am telling you all the time Robert to use Debian that it just works and you say, no no, gentoo is the best. :) Ondrej
Ondrej Certik wrote:
On Thu, Sep 18, 2008 at 1:01 PM, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
It requires Cython and a C compiler to build. I'm still debating myself about the desired workflow for using it, but for now, it only profiles functions which you have registered with it. I have made the profiler work as a decorator to make this easy. E.g.,
many thanks for this! I have wanted to try out the profiler but failed to build it (changeset 6 0de294aa75bf):
$ python setup.py install --root=/home/share/software/ running install running build running build_py creating build creating build/lib.linux-i686-2.4 copying line_profiler.py -> build/lib.linux-i686-2.4 running build_ext cythoning _line_profiler.pyx to _line_profiler.c building '_line_profiler' extension creating build/temp.linux-i686-2.4 i486-pc-linux-gnu-gcc -pthread -fno-strict-aliasing -DNDEBUG -fPIC -I/usr/include/python2.4 -c -I/usr/include/python2.4 -c _line_profiler.c -o build/temp.linux-i686-2.4/_line_profiler.o _line_profiler.c:1614: error: 'T_LONGLONG' undeclared here (not in a function) error: command 'i486-pc-linux-gnu-gcc' failed with exit status 1
I have cython-0.9.8.1 and GCC 4.1.2, 32-bit machine.
I am telling you all the time Robert to use Debian that it just works and you say, no no, gentoo is the best. :)
And what's wrong with that? :) Once you get over the learning curve, Gentoo works just fine. Must be Robert K.'s fault. :) Ryan -- Ryan May Graduate Research Assistant School of Meteorology University of Oklahoma
On Thu, Sep 18, 2008 at 4:12 PM, Ryan May <rmay31@gmail.com> wrote:
Ondrej Certik wrote:
On Thu, Sep 18, 2008 at 1:01 PM, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
It requires Cython and a C compiler to build. I'm still debating myself about the desired workflow for using it, but for now, it only profiles functions which you have registered with it. I have made the profiler work as a decorator to make this easy. E.g.,
many thanks for this! I have wanted to try out the profiler but failed to build it (changeset 6 0de294aa75bf):
$ python setup.py install --root=/home/share/software/ running install running build running build_py creating build creating build/lib.linux-i686-2.4 copying line_profiler.py -> build/lib.linux-i686-2.4 running build_ext cythoning _line_profiler.pyx to _line_profiler.c building '_line_profiler' extension creating build/temp.linux-i686-2.4 i486-pc-linux-gnu-gcc -pthread -fno-strict-aliasing -DNDEBUG -fPIC -I/usr/include/python2.4 -c -I/usr/include/python2.4 -c _line_profiler.c -o build/temp.linux-i686-2.4/_line_profiler.o _line_profiler.c:1614: error: 'T_LONGLONG' undeclared here (not in a function) error: command 'i486-pc-linux-gnu-gcc' failed with exit status 1
I have cython-0.9.8.1 and GCC 4.1.2, 32-bit machine.
I am telling you all the time Robert to use Debian that it just works and you say, no no, gentoo is the best. :)
And what's wrong with that? :) Once you get over the learning curve, Gentoo works just fine. Must be Robert K.'s fault. :)
Well, I think if Robert C. hasn't yet get over the learning curve after so many years of hard work, maybe the learning curve is too steep. :) Anyway, back to work: Robert K., I noticed that if I profile some function, I get results like this for example: ---- 40 3072 46952 6.6 [x,w] = p_roots(n) 41 3072 24192 3.4 x = real(x) 42 3072 34470 4.8 ainf, binf = map(isinf,(a,b)) 43 3072 6565 0.9 if ainf or binf: 44 raise ValueError, "Gaussian quadrature is only available for " \ 45 "finite limits." 46 3072 5093 0.7 if not reference: 47 x = (b-a)*(x+1)/2.0 + a 48 3072 594190 83.5 return (b-a)/2.0*sum(w*func(x,*args),0) --- Then if I turn profiling of the func() method, I get this: -------------------- 40 3072 46999 4.6 [x,w] = p_roots(n) 41 3072 24313 2.4 x = real(x) 42 3072 34327 3.4 ainf, binf = map(isinf,(a,b)) 43 3072 6190 0.6 if ainf or binf: 44 raise ValueError, "Gaussian quadrature is only available for " \ 45 "finite limits." 46 3072 4918 0.5 if not reference: 47 x = (b-a)*(x+1)/2.0 + a 48 3072 906876 88.6 return (b-a)/2.0*sum(w*func(x,*args),0) ----------- So the timing raises a lot. For obvious reasons, that's the overhead of the profiler. But the problem is that then the timings just don't fit, e.g. if I sum the total time spent in subfunctions, it doesn't account for all the time printed on the respective line in the parent function. I don't know if there is any way to fix it, or even worth fixing. So I guess one should just use the profiling info to determine which line to fix. Do you think it's worthy to implement line profiling for all lines and then make sure that all timings match? What is your experience. Ondrej
So the timing raises a lot. For obvious reasons, that's the overhead of the profiler. But the problem is that then the timings just don't fit, e.g. if I sum the total time spent in subfunctions, it doesn't account for all the time printed on the respective line in the parent function.
I don't know if there is any way to fix it, or even worth fixing. So I guess one should just use the profiling info to determine which line to fix.
Do you think it's worthy to implement line profiling for all lines and then make sure that all timings match? What is your experience.
The reason I want this is so that I can determine just by looking at the timing how much time is spent at the line and how much time is spent at the functions that are being called at the line. I think it is doable, what do you think? One would trace how much time was wasted in python_trace_callback and then just substract this time from all parent function's lines timings. Btw Robin, how is Matlab doing it? Ondrej
On Thu, Sep 18, 2008 at 10:03, Ondrej Certik <ondrej@certik.cz> wrote:
Anyway, back to work: Robert K., I noticed that if I profile some function, I get results like this for example:
---- 40 3072 46952 6.6 [x,w] = p_roots(n) 41 3072 24192 3.4 x = real(x) 42 3072 34470 4.8 ainf, binf = map(isinf,(a,b)) 43 3072 6565 0.9 if ainf or binf: 44 raise ValueError, "Gaussian quadrature is only available for " \ 45 "finite limits." 46 3072 5093 0.7 if not reference: 47 x = (b-a)*(x+1)/2.0 + a 48 3072 594190 83.5 return (b-a)/2.0*sum(w*func(x,*args),0) ---
Then if I turn profiling of the func() method, I get this:
-------------------- 40 3072 46999 4.6 [x,w] = p_roots(n) 41 3072 24313 2.4 x = real(x) 42 3072 34327 3.4 ainf, binf = map(isinf,(a,b)) 43 3072 6190 0.6 if ainf or binf: 44 raise ValueError, "Gaussian quadrature is only available for " \ 45 "finite limits." 46 3072 4918 0.5 if not reference: 47 x = (b-a)*(x+1)/2.0 + a 48 3072 906876 88.6 return (b-a)/2.0*sum(w*func(x,*args),0) -----------
So the timing raises a lot. For obvious reasons, that's the overhead of the profiler. But the problem is that then the timings just don't fit, e.g. if I sum the total time spent in subfunctions, it doesn't account for all the time printed on the respective line in the parent function.
I don't know if there is any way to fix it, or even worth fixing. So I guess one should just use the profiling info to determine which line to fix.
So here's what going on: I'm being clever (and possibly too clever). When tracing is enabled, Python will call my tracing function just before each new line gets executed. If tracing isn't enabled for this function, I return. Otherwise, I grab the current time. Then, I look for the last line and time I recorded for this function. I look up the accumulator for the (code, old line) pair and record the time delta. Then I grab the current time *again*, and store the current line and this new time for the next go 'round. This way, I exclude most of the time spent inside the profiler itself and just record the time being spent in the code. The total time reported is just a sum of the recorded times, not the sum of wall-clock times spent in the function. Now, this does break down in your use case where you are profiling both the caller and callee and trying to determine how much of a line's time is being spent just by calling the function. I could record wall-clock times between the start and end of a function call, but I think that's fragile. For example, suppose you are profiling A() and B() but not C(), and both A() and C() call B(). Using the wall-clock time spent in B() will tell you that you spent more time in B() than the appropriate line (or lines!) that called it in A(). I think the most robust way to figure this out is to rewrite your code to pull out such calls onto their own lines. This is like breaking up your functions into tiny little one-liners in order to use cProfile only it doesn't suck *nearly* as much. -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
Ondrej Certik wrote:
On Thu, Sep 18, 2008 at 4:12 PM, Ryan May <rmay31@gmail.com> wrote:
Ondrej Certik wrote:
On Thu, Sep 18, 2008 at 1:01 PM, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
It requires Cython and a C compiler to build. I'm still debating myself about the desired workflow for using it, but for now, it only profiles functions which you have registered with it. I have made the profiler work as a decorator to make this easy. E.g., many thanks for this! I have wanted to try out the profiler but failed to build it (changeset 6 0de294aa75bf):
$ python setup.py install --root=/home/share/software/ running install running build running build_py creating build creating build/lib.linux-i686-2.4 copying line_profiler.py -> build/lib.linux-i686-2.4 running build_ext cythoning _line_profiler.pyx to _line_profiler.c building '_line_profiler' extension creating build/temp.linux-i686-2.4 i486-pc-linux-gnu-gcc -pthread -fno-strict-aliasing -DNDEBUG -fPIC -I/usr/include/python2.4 -c -I/usr/include/python2.4 -c _line_profiler.c -o build/temp.linux-i686-2.4/_line_profiler.o _line_profiler.c:1614: error: 'T_LONGLONG' undeclared here (not in a function) error: command 'i486-pc-linux-gnu-gcc' failed with exit status 1
I have cython-0.9.8.1 and GCC 4.1.2, 32-bit machine. I am telling you all the time Robert to use Debian that it just works and you say, no no, gentoo is the best. :) And what's wrong with that? :) Once you get over the learning curve, Gentoo works just fine. Must be Robert K.'s fault. :)
Well, I think if Robert C. hasn't yet get over the learning curve after so many years of hard work, maybe the learning curve is too steep. :)
This is most probably not related to Gentoo at all and certainly not related to me knowing Gentoo or not :) (and no, learning Gentoo is not that hard.) r.
On Fri, Sep 19, 2008 at 10:37 AM, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
Ondrej Certik wrote:
On Thu, Sep 18, 2008 at 4:12 PM, Ryan May <rmay31@gmail.com> wrote:
Ondrej Certik wrote:
On Thu, Sep 18, 2008 at 1:01 PM, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
It requires Cython and a C compiler to build. I'm still debating myself about the desired workflow for using it, but for now, it only profiles functions which you have registered with it. I have made the profiler work as a decorator to make this easy. E.g., many thanks for this! I have wanted to try out the profiler but failed to build it (changeset 6 0de294aa75bf):
$ python setup.py install --root=/home/share/software/ running install running build running build_py creating build creating build/lib.linux-i686-2.4 copying line_profiler.py -> build/lib.linux-i686-2.4 running build_ext cythoning _line_profiler.pyx to _line_profiler.c building '_line_profiler' extension creating build/temp.linux-i686-2.4 i486-pc-linux-gnu-gcc -pthread -fno-strict-aliasing -DNDEBUG -fPIC -I/usr/include/python2.4 -c -I/usr/include/python2.4 -c _line_profiler.c -o build/temp.linux-i686-2.4/_line_profiler.o _line_profiler.c:1614: error: 'T_LONGLONG' undeclared here (not in a function) error: command 'i486-pc-linux-gnu-gcc' failed with exit status 1
I have cython-0.9.8.1 and GCC 4.1.2, 32-bit machine. I am telling you all the time Robert to use Debian that it just works and you say, no no, gentoo is the best. :) And what's wrong with that? :) Once you get over the learning curve, Gentoo works just fine. Must be Robert K.'s fault. :)
Well, I think if Robert C. hasn't yet get over the learning curve after so many years of hard work, maybe the learning curve is too steep. :)
This is most probably not related to Gentoo at all and certainly not related to me knowing Gentoo or not :) (and no, learning Gentoo is not that hard.)
Let us know where the problem was. :) I am just using common sense, if something works on Debian and macosx and doesn't work on gentoo, I thought it was safe to say it was gentoo related, but I may well be wrong. :)) Ondrej
On Thu, Sep 18, 2008 at 06:01, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
Hi Robert,
Robert Kern wrote:
On Mon, Sep 15, 2008 at 11:13, Arnar Flatberg <arnar.flatberg@gmail.com> wrote:
That would make me an extremely happy user, I've been looking for this for years! I can't imagine I'm the only one who profiles some hundred lines of code and ends up with 90% of total time in the dot-function
For the time being, you can grab it here:
http://www.enthought.com/~rkern/cgi-bin/hgwebdir.cgi/line_profiler/
It requires Cython and a C compiler to build. I'm still debating myself about the desired workflow for using it, but for now, it only profiles functions which you have registered with it. I have made the profiler work as a decorator to make this easy. E.g.,
many thanks for this! I have wanted to try out the profiler but failed to build it (changeset 6 0de294aa75bf):
$ python setup.py install --root=/home/share/software/ running install running build running build_py creating build creating build/lib.linux-i686-2.4 copying line_profiler.py -> build/lib.linux-i686-2.4 running build_ext cythoning _line_profiler.pyx to _line_profiler.c building '_line_profiler' extension creating build/temp.linux-i686-2.4 i486-pc-linux-gnu-gcc -pthread -fno-strict-aliasing -DNDEBUG -fPIC -I/usr/include/python2.4 -c -I/usr/include/python2.4 -c _line_profiler.c -o build/temp.linux-i686-2.4/_line_profiler.o _line_profiler.c:1614: error: 'T_LONGLONG' undeclared here (not in a function) error: command 'i486-pc-linux-gnu-gcc' failed with exit status 1
I have cython-0.9.8.1 and GCC 4.1.2, 32-bit machine.
It uses the #define'd macro PY_LONG_LONG. Go through your Python headers to see what this gets expanded to. -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
Robert Kern wrote:
On Thu, Sep 18, 2008 at 06:01, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
Hi Robert,
Robert Kern wrote:
On Mon, Sep 15, 2008 at 11:13, Arnar Flatberg <arnar.flatberg@gmail.com> wrote:
That would make me an extremely happy user, I've been looking for this for years! I can't imagine I'm the only one who profiles some hundred lines of code and ends up with 90% of total time in the dot-function For the time being, you can grab it here:
http://www.enthought.com/~rkern/cgi-bin/hgwebdir.cgi/line_profiler/
It requires Cython and a C compiler to build. I'm still debating myself about the desired workflow for using it, but for now, it only profiles functions which you have registered with it. I have made the profiler work as a decorator to make this easy. E.g., many thanks for this! I have wanted to try out the profiler but failed to build it (changeset 6 0de294aa75bf):
$ python setup.py install --root=/home/share/software/ running install running build running build_py creating build creating build/lib.linux-i686-2.4 copying line_profiler.py -> build/lib.linux-i686-2.4 running build_ext cythoning _line_profiler.pyx to _line_profiler.c building '_line_profiler' extension creating build/temp.linux-i686-2.4 i486-pc-linux-gnu-gcc -pthread -fno-strict-aliasing -DNDEBUG -fPIC -I/usr/include/python2.4 -c -I/usr/include/python2.4 -c _line_profiler.c -o build/temp.linux-i686-2.4/_line_profiler.o _line_profiler.c:1614: error: 'T_LONGLONG' undeclared here (not in a function) error: command 'i486-pc-linux-gnu-gcc' failed with exit status 1
I have cython-0.9.8.1 and GCC 4.1.2, 32-bit machine.
It uses the #define'd macro PY_LONG_LONG. Go through your Python headers to see what this gets expanded to.
I have Python 2.4.4 in "pyconfig.h" #define HAVE_LONG_LONG 1 in "pyport.h": #ifdef HAVE_LONG_LONG #ifndef PY_LONG_LONG #define PY_LONG_LONG long long #endif #endif /* HAVE_LONG_LONG */ so it seems compatible with 'ctypedef long long PY_LONG_LONG' r.
On Fri, Sep 19, 2008 at 03:33, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
I have Python 2.4.4
in "pyconfig.h"
#define HAVE_LONG_LONG 1
in "pyport.h":
#ifdef HAVE_LONG_LONG #ifndef PY_LONG_LONG #define PY_LONG_LONG long long #endif #endif /* HAVE_LONG_LONG */
so it seems compatible with 'ctypedef long long PY_LONG_LONG'
Ah, found it. T_LONGLONG is a #define from structmember.h which is used to describe the types of attributes. Apparently, this was not added until Python 2.5. That particular member didn't actually need to be long long, so I've fixed that. -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
Robert Kern wrote:
Ah, found it. T_LONGLONG is a #define from structmember.h which is used to describe the types of attributes. Apparently, this was not added until Python 2.5. That particular member didn't actually need to be long long, so I've fixed that.
Great, I will try it after it appears on the web page. Thank you, r.
On Fri, Sep 19, 2008 at 07:00, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
Robert Kern wrote:
Ah, found it. T_LONGLONG is a #define from structmember.h which is used to describe the types of attributes. Apparently, this was not added until Python 2.5. That particular member didn't actually need to be long long, so I've fixed that.
Great, I will try it after it appears on the web page.
Oops! It's now pushed. -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
Robert Kern wrote:
On Fri, Sep 19, 2008 at 07:00, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
Robert Kern wrote:
Ah, found it. T_LONGLONG is a #define from structmember.h which is used to describe the types of attributes. Apparently, this was not added until Python 2.5. That particular member didn't actually need to be long long, so I've fixed that. Great, I will try it after it appears on the web page.
Oops! It's now pushed.
Thanks, it builds ok now! But then cProfile is also new in 2.5. - I should probably upgrade and stop bothering you :-) r.
On Sun, Sep 21, 2008 at 02:09, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
Robert Kern wrote:
On Fri, Sep 19, 2008 at 07:00, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
Robert Kern wrote:
Ah, found it. T_LONGLONG is a #define from structmember.h which is used to describe the types of attributes. Apparently, this was not added until Python 2.5. That particular member didn't actually need to be long long, so I've fixed that. Great, I will try it after it appears on the web page.
Oops! It's now pushed.
Thanks, it builds ok now! But then cProfile is also new in 2.5. - I should probably upgrade and stop bothering you :-)
Actually, if you pull again, I've just pushed my changes to remove the hard dependency on cProfile. -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
Robert Kern wrote:
On Sun, Sep 21, 2008 at 02:09, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
Robert Kern wrote:
On Fri, Sep 19, 2008 at 07:00, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
Robert Kern wrote:
Ah, found it. T_LONGLONG is a #define from structmember.h which is used to describe the types of attributes. Apparently, this was not added until Python 2.5. That particular member didn't actually need to be long long, so I've fixed that. Great, I will try it after it appears on the web page. Oops! It's now pushed. Thanks, it builds ok now! But then cProfile is also new in 2.5. - I should probably upgrade and stop bothering you :-)
Actually, if you pull again, I've just pushed my changes to remove the hard dependency on cProfile.
Cool, then I have another one: $ ./kernprof.py -l pystone.py Traceback (most recent call last): File "./kernprof.py", line 173, in ? sys.exit(main(sys.argv)) File "./kernprof.py", line 138, in main import line_profiler File "/home/share/software/packages/line_profiler-2ea515d0cbc1/line_profiler.py", line 9, in ? from _line_profiler import LineProfiler as CLineProfiler File "_line_profiler.pyx", line 3, in _line_profiler (_line_profiler.c:2246) from cProfile import label ImportError: No module named cProfile Or do I call the profiler in a wrong way? r.
On Sun, Sep 21, 2008 at 02:26, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
Cool, then I have another one:
$ ./kernprof.py -l pystone.py Traceback (most recent call last): File "./kernprof.py", line 173, in ? sys.exit(main(sys.argv)) File "./kernprof.py", line 138, in main import line_profiler File "/home/share/software/packages/line_profiler-2ea515d0cbc1/line_profiler.py", line 9, in ? from _line_profiler import LineProfiler as CLineProfiler File "_line_profiler.pyx", line 3, in _line_profiler (_line_profiler.c:2246) from cProfile import label ImportError: No module named cProfile
Or do I call the profiler in a wrong way?
Nope, I just had a brainfart and put the implementation of label() in the wrong file. Pull again. -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
Robert Kern wrote:
On Sun, Sep 21, 2008 at 02:26, Robert Cimrman <cimrman3@ntc.zcu.cz> wrote:
Cool, then I have another one:
$ ./kernprof.py -l pystone.py Traceback (most recent call last): File "./kernprof.py", line 173, in ? sys.exit(main(sys.argv)) File "./kernprof.py", line 138, in main import line_profiler File "/home/share/software/packages/line_profiler-2ea515d0cbc1/line_profiler.py", line 9, in ? from _line_profiler import LineProfiler as CLineProfiler File "_line_profiler.pyx", line 3, in _line_profiler (_line_profiler.c:2246) from cProfile import label ImportError: No module named cProfile
Or do I call the profiler in a wrong way?
Nope, I just had a brainfart and put the implementation of label() in the wrong file. Pull again.
:-) The example works now in Python 2.4. r.
The hotshot profiler used to do this, but I don't think it is really supported anymore... I have not used it in a while, but agree that a line-by-line profiler can be very nice. Michael. On Sep 15, 2008, at 6:27 AM, Robin wrote:
Hi,
I am using the prun feature of Ipython which is very helpful.
I was wondering though if theres anything for Python that would allow line-by-line profiling (ie a time for each line of code) like the MATLAB profiler?
Cheers
Robin _______________________________________________ Numpy-discussion mailing list Numpy-discussion@scipy.org http://projects.scipy.org/mailman/listinfo/numpy-discussion
Michael McNeil Forbes wrote:
The hotshot profiler used to do this, but I don't think it is really supported anymore... I have not used it in a while, but agree that a line-by-line profiler can be very nice.
You can do it with kcachegrind, which is arguably more powerful, but it is a bit a pain to set up. http://jcalderone.livejournal.com/21124.html cheers, David
On Mon, Sep 15, 2008 at 21:43, David Cournapeau <david@ar.media.kyoto-u.ac.jp> wrote:
Michael McNeil Forbes wrote:
The hotshot profiler used to do this, but I don't think it is really supported anymore... I have not used it in a while, but agree that a line-by-line profiler can be very nice.
You can do it with kcachegrind, which is arguably more powerful, but it is a bit a pain to set up.
No, that's with cProfile, which doesn't support line-by-line profiling. -- Robert Kern "I have come to believe that the whole world is an enigma, a harmless enigma that is made terrible by our own mad attempt to interpret it as though it had an underlying truth." -- Umberto Eco
Robert Kern wrote:
On Mon, Sep 15, 2008 at 21:43, David Cournapeau <david@ar.media.kyoto-u.ac.jp> wrote:
You can do it with kcachegrind, which is arguably more powerful, but it is a bit a pain to set up.
No, that's with cProfile, which doesn't support line-by-line profiling.
You're right, I did it with hotshot, I did not paste the right link, sorry. The right one should be: http://ddaa.net/blog/python/lsprof-calltree Both profiles (cProfile and hotshot) formats are usable with kcachegrind, but you have to convert first the profiles, so it is not as integrated as if everything was in python. It does give you information similar as matlab, which is one thing I missed from matlab too when I started using python. cheers, David
participants (10)
-
Arnar Flatberg -
David Cournapeau -
Fernando Perez -
Gael Varoquaux -
Michael McNeil Forbes -
Ondrej Certik -
Robert Cimrman -
Robert Kern -
Robin -
Ryan May