Quantcast

profiling a Scala program

classic Classic list List threaded Threaded
18 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

profiling a Scala program

Russ Paielli-5
I am trying to figure out how to profile my Scala program. I found something called Java Visual VM (jvisualvm), and I am trying to use it. If there is a better alternative, please let me know.

I am referring to the online instructions, but as usual I am confused and spinning my wheels. I am using Scala 2.8 on Red Hat Linux. The instructions for jvisualvm say I should see an item under "Applications/Local" for my local application. As I am running my Scala program currently, it takes about something like 20-30 seconds to run. When I run it, I don't see it under "Applications/Local".

However, I see an item called "scala.tools.nsc.MainGenericRunner", which has an uptime of 671 hours and counting. I'm guessing this might be the JVM that my program is running on. It has Overview and Monitor tabs, but I don't see a Profiler tab (as I see with another application under Local). I saved several snapshots using the "Applications/Application Snapshot" pulldown menu item, but I have no idea what to do with them.

Can someone give me a clue or two about how to profile my program? It's running much slower than I had expected (no faster than the Python version that I converted to Scala), and I'd like to know why. Thanks.

Russ P.

--
http://RussP.us
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

Erik Engbrecht
I've profiled Scala using NetBeans (which I believe just embeds VisualVM in NetBeans), but it's tricky.

If you're just starting out, I'd suggest just using the -Xprof option.  That just prints statistics when the program exits.  Of course if you are launching your program using "scala MyProgram" then you need to set -Xprof via the JAVA_OPTS environment variable because you can't pass it on the command line...in which case you may need to set other options as well such as stack and heap sizes, because I think if JAVA_OPTS is set the scala script doesn't bother setting those options itself.

So:
export JAVA_OPTS="-Xmx256M -Xms32M -Xprof"
scala MyProgram

On Tue, Oct 19, 2010 at 8:33 PM, Russ Paielli <[hidden email]> wrote:
I am trying to figure out how to profile my Scala program. I found something called Java Visual VM (jvisualvm), and I am trying to use it. If there is a better alternative, please let me know.

I am referring to the online instructions, but as usual I am confused and spinning my wheels. I am using Scala 2.8 on Red Hat Linux. The instructions for jvisualvm say I should see an item under "Applications/Local" for my local application. As I am running my Scala program currently, it takes about something like 20-30 seconds to run. When I run it, I don't see it under "Applications/Local".

However, I see an item called "scala.tools.nsc.MainGenericRunner", which has an uptime of 671 hours and counting. I'm guessing this might be the JVM that my program is running on. It has Overview and Monitor tabs, but I don't see a Profiler tab (as I see with another application under Local). I saved several snapshots using the "Applications/Application Snapshot" pulldown menu item, but I have no idea what to do with them.

Can someone give me a clue or two about how to profile my program? It's running much slower than I had expected (no faster than the Python version that I converted to Scala), and I'd like to know why. Thanks.

Russ P.

--
http://RussP.us



--
http://erikengbrecht.blogspot.com/
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

Stephen Tu
I recommend yourkit: http://www.yourkit.com/

its quite an extensive profiler and gives you good visual representation of what's going on
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

Randall R Schulz-2
On Tuesday October 19 2010, Stephen Tu wrote:
> I recommend yourkit: http://www.yourkit.com/
>
> its quite an extensive profiler and gives you good visual
> representation of what's going on

I use it, too, and like it. But it is not inexpensive. If you can wait
(indefinitely), you can monitor their site for their occassional
specials. If I recall, when I bought it, it was far cheaper than the
usual list price, though it's too long ago for me to remember precisely
how much it cost me.


Randall Schulz
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

Rex Kerr-2
In reply to this post by Russ Paielli-5
Even though I write lots of code that has to perform well, I almost never bother with a full-fledged profiler.  I suggest that the following is likely to have the lowest entry barrier:

If it's run from the command line, start it up and hit Ctrl-\ a few times while it's running.  Optionally, write a short script to throw away all the useless stuff, or you can just snip it out by hand.  You're left with a handful of relevant stack traces; whatever comes up all the time is, naturally enough, what's taking most of your time.

If it's graphical and just sitting there waiting for input, it's easy enough to attach a graphical tool to it (jvisualvm or the NetBeans debugger) before launching something intensive.

For something that is _way_ slower than you expect, these should work fine.  When it's working pretty well and you want to tune it up to working really well is when you need a heavier-duty profiler.

Or calculate your own timings:

  def ptime[F](f: => F) = {
    var t0 = System.nanoTime
    val ans = f
    printf("Elapsed: %.3f s\n",1e-9*(System.nanoTime-t0))
    ans
  }

(overhead is ~2 ms/call on my system, mostly due to IO, so only use it to time nontrivial subsets of the problem).

  --Rex


On Tue, Oct 19, 2010 at 8:33 PM, Russ Paielli <[hidden email]> wrote:
I am trying to figure out how to profile my Scala program. I found something called Java Visual VM (jvisualvm), and I am trying to use it. If there is a better alternative, please let me know.

I am referring to the online instructions, but as usual I am confused and spinning my wheels. I am using Scala 2.8 on Red Hat Linux. The instructions for jvisualvm say I should see an item under "Applications/Local" for my local application. As I am running my Scala program currently, it takes about something like 20-30 seconds to run. When I run it, I don't see it under "Applications/Local".

However, I see an item called "scala.tools.nsc.MainGenericRunner", which has an uptime of 671 hours and counting. I'm guessing this might be the JVM that my program is running on. It has Overview and Monitor tabs, but I don't see a Profiler tab (as I see with another application under Local). I saved several snapshots using the "Applications/Application Snapshot" pulldown menu item, but I have no idea what to do with them.

Can someone give me a clue or two about how to profile my program? It's running much slower than I had expected (no faster than the Python version that I converted to Scala), and I'd like to know why. Thanks.

Russ P.

--
http://RussP.us

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

Russ Paielli-5
In reply to this post by Erik Engbrecht
On Tue, Oct 19, 2010 at 5:53 PM, Erik Engbrecht <[hidden email]> wrote:
I've profiled Scala using NetBeans (which I believe just embeds VisualVM in NetBeans), but it's tricky.

If you're just starting out, I'd suggest just using the -Xprof option.  That just prints statistics when the program exits.  Of course if you are launching your program using "scala MyProgram" then you need to set -Xprof via the JAVA_OPTS environment variable because you can't pass it on the command line...in which case you may need to set other options as well such as stack and heap sizes, because I think if JAVA_OPTS is set the scala script doesn't bother setting those options itself.

So:
export JAVA_OPTS="-Xmx256M -Xms32M -Xprof"
scala MyProgram


Thanks. I tried it with just "-Xprof", and it led me quickly to a 2x speedup. Now the program runs about twice as fast as the original Python version. That's not bad, but I was expecting a much larger speedup than that. I'm still getting this output from the profiler:

     Compiled + native   Method
 44.6%   995  +     0    scala.collection.LinearSeqOptimized$class.apply
 18.9%   422  +     0    ExceptionBlob

Can anyone give me a clue what that means? Thanks.

Russ P.


--
http://RussP.us
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

Stephen Tu
russ,

are you letting the JVM run a little bit before timing your executions? JIT compliation has from my experience a non-trivial impact on performance metrics
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

Erik Engbrecht
In reply to this post by Russ Paielli-5
The time spent unwinding the stack for exceptions shows up as ExceptionBlob when you use -Xprof.  There are parts of the Scala library that use exceptions for flow control.  I think Scala also implements non-local returns by throwing exceptions.  Unwinding the stack by throwing an exception is much, much more expensive than using a regular return.

LinearSeqOptimized.apply is called when you access an element of a LinearSeq (or certain types of LinearSeq) using an index.  LinearSeqs are linked structures, so accessing elements using indices is expensive.  You may want to use a IndexSeq instead, or change your access pattern.

On Tue, Oct 19, 2010 at 10:16 PM, Russ Paielli <[hidden email]> wrote:
On Tue, Oct 19, 2010 at 5:53 PM, Erik Engbrecht <[hidden email]> wrote:
I've profiled Scala using NetBeans (which I believe just embeds VisualVM in NetBeans), but it's tricky.

If you're just starting out, I'd suggest just using the -Xprof option.  That just prints statistics when the program exits.  Of course if you are launching your program using "scala MyProgram" then you need to set -Xprof via the JAVA_OPTS environment variable because you can't pass it on the command line...in which case you may need to set other options as well such as stack and heap sizes, because I think if JAVA_OPTS is set the scala script doesn't bother setting those options itself.

So:
export JAVA_OPTS="-Xmx256M -Xms32M -Xprof"
scala MyProgram


Thanks. I tried it with just "-Xprof", and it led me quickly to a 2x speedup. Now the program runs about twice as fast as the original Python version. That's not bad, but I was expecting a much larger speedup than that. I'm still getting this output from the profiler:

     Compiled + native   Method
 44.6%   995  +     0    scala.collection.LinearSeqOptimized$class.apply
 18.9%   422  +     0    ExceptionBlob

Can anyone give me a clue what that means? Thanks.

Russ P.


--
http://RussP.us



--
http://erikengbrecht.blogspot.com/
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

Russ Paielli-5
Thanks again, Erik. Apparently I must be indexing into (long) Lists too much. I'll have to start keeping an eye out for that.

Are early return statements inefficient?

Russ P.


On Tue, Oct 19, 2010 at 7:41 PM, Erik Engbrecht <[hidden email]> wrote:
The time spent unwinding the stack for exceptions shows up as ExceptionBlob when you use -Xprof.  There are parts of the Scala library that use exceptions for flow control.  I think Scala also implements non-local returns by throwing exceptions.  Unwinding the stack by throwing an exception is much, much more expensive than using a regular return.

LinearSeqOptimized.apply is called when you access an element of a LinearSeq (or certain types of LinearSeq) using an index.  LinearSeqs are linked structures, so accessing elements using indices is expensive.  You may want to use a IndexSeq instead, or change your access pattern.


--
http://RussP.us
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

William Uther

> On Tue, Oct 19, 2010 at 7:41 PM, Erik Engbrecht <[hidden email]> wrote:
>
> LinearSeqOptimized.apply is called when you access an element of a LinearSeq (or certain types of LinearSeq) using an index.  LinearSeqs are linked structures, so accessing elements using indices is expensive.  You may want to use a IndexSeq instead, or change your access pattern.
>

It would seem that a skip list <http://en.wikipedia.org/wiki/Skip_list#Indexable_skiplist> would work nicely as an immutable data structure for an IndexSeq.  I wonder how it would compare to the current Array implementation?

(Also does anyone know of a nice scala Splay Tree implementation of Map?)

Cheers,

Will       :-}

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

HamsterofDeath
In reply to this post by Russ Paielli-5
 i use the yourkit profiler, always worked fine and it's pretty powerful
- and easy. there's a 15 days trial -> yourkit.com

Am 20.10.2010 02:33, schrieb Russ Paielli:

> I am trying to figure out how to profile my Scala program. I found
> something called Java Visual VM (jvisualvm), and I am trying to use
> it. If there is a better alternative, please let me know.
>
> I am referring to the online instructions, but as usual I am confused
> and spinning my wheels. I am using Scala 2.8 on Red Hat Linux. The
> instructions for jvisualvm say I should see an item under
> "Applications/Local" for my local application. As I am running my
> Scala program currently, it takes about something like 20-30 seconds
> to run. When I run it, I don't see it under "Applications/Local".
>
> However, I see an item called "scala.tools.nsc.MainGenericRunner",
> which has an uptime of 671 hours and counting. I'm guessing this might
> be the JVM that my program is running on. It has Overview and Monitor
> tabs, but I don't see a Profiler tab (as I see with another
> application under Local). I saved several snapshots using the
> "Applications/Application Snapshot" pulldown menu item, but I have no
> idea what to do with them.
>
> Can someone give me a clue or two about how to profile my program?
> It's running much slower than I had expected (no faster than the
> Python version that I converted to Scala), and I'd like to know why.
> Thanks.
>
> Russ P.
>
> --
> http://RussP.us

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

Daniel Lichtenberger
In reply to this post by Randall R Schulz-2
On 10/20/2010 03:26 AM, Randall R Schulz wrote:

> On Tuesday October 19 2010, Stephen Tu wrote:
>    
>> I recommend yourkit: http://www.yourkit.com/
>>
>> its quite an extensive profiler and gives you good visual
>> representation of what's going on
>>      
> I use it, too, and like it. But it is not inexpensive. If you can wait
> (indefinitely), you can monitor their site for their occassional
> specials. If I recall, when I bought it, it was far cheaper than the
> usual list price, though it's too long ago for me to remember precisely
> how much it cost me.
>    

There are free EAP (Early Access) releases that usually work fairly well:
http://www.yourkit.com/eap/index.jsp

Daniel
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

HamsterofDeath
In reply to this post by Randall R Schulz-2
 i asked for a personal license (which was no longer for sale on their
site) and got a 40 or 60% discount, i forgot.
the other way is to jump from eap to eap to eap to release to eap and so
on, each one comes with another free 15 days.

Am 20.10.2010 03:26, schrieb Randall R Schulz:

> On Tuesday October 19 2010, Stephen Tu wrote:
>> I recommend yourkit: http://www.yourkit.com/
>>
>> its quite an extensive profiler and gives you good visual
>> representation of what's going on
> I use it, too, and like it. But it is not inexpensive. If you can wait
> (indefinitely), you can monitor their site for their occassional
> specials. If I recall, when I bought it, it was far cheaper than the
> usual list price, though it's too long ago for me to remember precisely
> how much it cost me.
>
>
> Randall Schulz
>

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

Erik Engbrecht
In reply to this post by Russ Paielli-5
Yes.  Early return statements, at least when they are inside a closure, throw exceptions.  It's been a while since I benchmarked it, but if HotSpot can apply optimizations a exception costs 3-10x more than a regular return.  If something prevents these optimizations I believe it's worse.

Here's some bytecode from an early return within a for loop.  Notice the NonLocalReturnControl and the athrow.  Scala basically boxes the result, puts it in an exception, throws it, then catches it and unboxes it in the outer function.

public void apply$mcVI$sp(int);
  Code:
   0: aload_0
   1: getfield #27; //Field i$1:I
   4: iconst_5
   5: if_icmpne 25
   8: new #29; //class scala/runtime/NonLocalReturnControl
   11: dup
   12: aload_0
   13: getfield #31; //Field nonLocalReturnKey1$1:Ljava/lang/Object;
   16: ldc #32; //int 6
   18: invokestatic #38; //Method scala/runtime/BoxesRunTime.boxToInteger:(I)Ljava/lang/Integer;
   21: invokespecial #42; //Method scala/runtime/NonLocalReturnControl."<init>":(Ljava/lang/Object;Ljava/lang/Object;)V
   24: athrow
   25: return


On Wed, Oct 20, 2010 at 12:17 AM, Russ Paielli <[hidden email]> wrote:
Thanks again, Erik. Apparently I must be indexing into (long) Lists too much. I'll have to start keeping an eye out for that.

Are early return statements inefficient?

Russ P.



On Tue, Oct 19, 2010 at 7:41 PM, Erik Engbrecht <[hidden email]> wrote:
The time spent unwinding the stack for exceptions shows up as ExceptionBlob when you use -Xprof.  There are parts of the Scala library that use exceptions for flow control.  I think Scala also implements non-local returns by throwing exceptions.  Unwinding the stack by throwing an exception is much, much more expensive than using a regular return.

LinearSeqOptimized.apply is called when you access an element of a LinearSeq (or certain types of LinearSeq) using an index.  LinearSeqs are linked structures, so accessing elements using indices is expensive.  You may want to use a IndexSeq instead, or change your access pattern.


--
http://RussP.us



--
http://erikengbrecht.blogspot.com/
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

Daniel Sobral
In reply to this post by William Uther
There's a nice immutable data structure already as default IndexedSeq, the Vector. And, then, there was a ticket with an alternate implementation. The discussion that followed was very interesting: http://lampsvn.epfl.ch/trac/scala/ticket/3724

On Wed, Oct 20, 2010 at 02:12, William Uther <[hidden email]> wrote:

> On Tue, Oct 19, 2010 at 7:41 PM, Erik Engbrecht <[hidden email]> wrote:
>
> LinearSeqOptimized.apply is called when you access an element of a LinearSeq (or certain types of LinearSeq) using an index.  LinearSeqs are linked structures, so accessing elements using indices is expensive.  You may want to use a IndexSeq instead, or change your access pattern.
>

It would seem that a skip list <http://en.wikipedia.org/wiki/Skip_list#Indexable_skiplist> would work nicely as an immutable data structure for an IndexSeq.  I wonder how it would compare to the current Array implementation?

(Also does anyone know of a nice scala Splay Tree implementation of Map?)

Cheers,

Will       :-}




--
Daniel C. Sobral

I travel to the future all the time.
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

Russ Paielli-5
In reply to this post by Russ Paielli-5
On Tue, Oct 19, 2010 at 9:17 PM, Russ Paielli <[hidden email]> wrote:
Thanks again, Erik. Apparently I must be indexing into (long) Lists too much. I'll have to start keeping an eye out for that.


And using "last" on a long list is probably not a good idea either! I was doing some of that. I guess I should replace the List with a Vector.

Russ P.
 
--
http://RussP.us
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

Naftoli Gugenheim
In reply to this post by Erik Engbrecht
Don't scala's control flow exceptions override the method that fills the stack trace to do nothing?


On Tue, Oct 19, 2010 at 10:41 PM, Erik Engbrecht <[hidden email]> wrote:
The time spent unwinding the stack for exceptions shows up as ExceptionBlob when you use -Xprof.  There are parts of the Scala library that use exceptions for flow control.  I think Scala also implements non-local returns by throwing exceptions.  Unwinding the stack by throwing an exception is much, much more expensive than using a regular return.

LinearSeqOptimized.apply is called when you access an element of a LinearSeq (or certain types of LinearSeq) using an index.  LinearSeqs are linked structures, so accessing elements using indices is expensive.  You may want to use a IndexSeq instead, or change your access pattern.


On Tue, Oct 19, 2010 at 10:16 PM, Russ Paielli <[hidden email]> wrote:
On Tue, Oct 19, 2010 at 5:53 PM, Erik Engbrecht <[hidden email]> wrote:
I've profiled Scala using NetBeans (which I believe just embeds VisualVM in NetBeans), but it's tricky.

If you're just starting out, I'd suggest just using the -Xprof option.  That just prints statistics when the program exits.  Of course if you are launching your program using "scala MyProgram" then you need to set -Xprof via the JAVA_OPTS environment variable because you can't pass it on the command line...in which case you may need to set other options as well such as stack and heap sizes, because I think if JAVA_OPTS is set the scala script doesn't bother setting those options itself.

So:
export JAVA_OPTS="-Xmx256M -Xms32M -Xprof"
scala MyProgram


Thanks. I tried it with just "-Xprof", and it led me quickly to a 2x speedup. Now the program runs about twice as fast as the original Python version. That's not bad, but I was expecting a much larger speedup than that. I'm still getting this output from the profiler:

     Compiled + native   Method
 44.6%   995  +     0    scala.collection.LinearSeqOptimized$class.apply
 18.9%   422  +     0    ExceptionBlob

Can anyone give me a clue what that means? Thanks.

Russ P.


--
http://RussP.us



--
http://erikengbrecht.blogspot.com/

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: profiling a Scala program

Erik Engbrecht
Sure.  If they didn't Russ would have seen a huge "fillInStackTrace" item on his profiling results.  But even with overriding the method, and even with exception caching (which non-local returns can't use, because they need to create an exception to hold the boxed return value), it's still a much slower path than normal returns.  Last I heard the best case was 3x slower than normal returns, and it doesn't take much to drift away from the best case.  The optimization of throws down to long jumps requires a lot to get inlined in order to happen, and it's easy to throw that off.  I've found very small code changes can make a big difference in the performance of code using exceptions for control flow.

On Wed, Oct 20, 2010 at 7:22 PM, Naftoli Gugenheim <[hidden email]> wrote:
Don't scala's control flow exceptions override the method that fills the stack trace to do nothing?


On Tue, Oct 19, 2010 at 10:41 PM, Erik Engbrecht <[hidden email]> wrote:
The time spent unwinding the stack for exceptions shows up as ExceptionBlob when you use -Xprof.  There are parts of the Scala library that use exceptions for flow control.  I think Scala also implements non-local returns by throwing exceptions.  Unwinding the stack by throwing an exception is much, much more expensive than using a regular return.

LinearSeqOptimized.apply is called when you access an element of a LinearSeq (or certain types of LinearSeq) using an index.  LinearSeqs are linked structures, so accessing elements using indices is expensive.  You may want to use a IndexSeq instead, or change your access pattern.


On Tue, Oct 19, 2010 at 10:16 PM, Russ Paielli <[hidden email]> wrote:
On Tue, Oct 19, 2010 at 5:53 PM, Erik Engbrecht <[hidden email]> wrote:
I've profiled Scala using NetBeans (which I believe just embeds VisualVM in NetBeans), but it's tricky.

If you're just starting out, I'd suggest just using the -Xprof option.  That just prints statistics when the program exits.  Of course if you are launching your program using "scala MyProgram" then you need to set -Xprof via the JAVA_OPTS environment variable because you can't pass it on the command line...in which case you may need to set other options as well such as stack and heap sizes, because I think if JAVA_OPTS is set the scala script doesn't bother setting those options itself.

So:
export JAVA_OPTS="-Xmx256M -Xms32M -Xprof"
scala MyProgram


Thanks. I tried it with just "-Xprof", and it led me quickly to a 2x speedup. Now the program runs about twice as fast as the original Python version. That's not bad, but I was expecting a much larger speedup than that. I'm still getting this output from the profiler:

     Compiled + native   Method
 44.6%   995  +     0    scala.collection.LinearSeqOptimized$class.apply
 18.9%   422  +     0    ExceptionBlob

Can anyone give me a clue what that means? Thanks.

Russ P.


--
http://RussP.us



--
http://erikengbrecht.blogspot.com/




--
http://erikengbrecht.blogspot.com/
Loading...