[Numpy-discussion] profiling line by line
Ondrej Certik
ondrej@certik...
Wed Sep 17 18:09:39 CDT 2008
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
More information about the Numpy-discussion
mailing list