Re: [scala-internals] Typing timings

[Francois]

Le 16/01/2013 01:03, Grzegorz Kossakowski a écrit :

Hi,

Iulian's response in the other thread prompted me to spend a little bit more time on my little AspectJ experiment. Here's the result: https://github.com/gkossakowski/scalac-aspects#typing-timings-typingtimingsaj

I also created a tool for outputting the raw data in HTML: https://gist.github.com/4543164

The good news is that it's already usable. If you are curious whether you have pathological code snippets that take exceptionally long to compile you can run this tool to collect some useful data. Once you get results you can sort them by second column to see what takes the longest time.

The tool turned out to be already usable enough that I managed to find a problem in our own code base, see: https://issues.scala-lang.org/browse/SI-6979

Wow, that seems very interesting.
I have a non trivial project, build with Maven (yes...), that is pathologically long to compile. The per-file timing would be very helpful as a starting point, to try to see where the lowest fruits are. Do you know about a way to hook your tool in a maven build ?

Or perhaps the simplest is to just use an ad-hoc build command for the timing (there is certainly a way to ask Maven to output what scalac command it execute) ?

-- 
Francois ARMAND
http://fanf42.blogspot.com
http://www.normation.com

[David Bernard]

Hi,

You can try "mvn compile -DdisplayCmd=true"
The plugin will print the command used to run scalac (a big part of
the command is to stored in a file). I think you can reuse those info
to create a script to call scalac-aspects.

scalac-aspects require asjectj and other stuff (script, .aj) to run.
Currently, I don't think it's a good idea to include it in the
scala-maven-plugin, but it can provide usefull info.

Any info, idea are welcome. Tell me how to integrate them.

[Francois Armand]

On Wednesday, 16 January 2013 11:32:13 UTC+1, David Bernard wrote:

Hi,

You can try "mvn compile -DdisplayCmd=true"
The plugin will print the command used to run scalac (a big part of
the command is to stored in a file). I think you can reuse those info
to create a script to call scalac-aspects.

Thanks, that helped !
 

scalac-aspects require asjectj and other stuff (script, .aj) to run.
Currently, I don't think it's a good idea to include it in the
scala-maven-plugin, but it can provide usefull info.

Any info, idea are welcome. Tell me how to integrate them.

All I need is to be able to pass the following option to scalac:

* -J-javaagent:/some/path/to/aspectjweaver.jar
* -nobootcp
* -toolcp /some/path/to/aspects.jar

The first two are OK, with arg and jvmArg, but when I try to pass -toolcp, I get a "scalac error: bad option: '-toolcp /home/fanf/java/workspaces/rudder-project/scalac-aspects/aspects.jar'

I tried to set it with:
<configuration>
          <args>
            <arg>-nobootcp</arg>
            <arg>-toolcp /home/fanf/java/workspaces/rudder-project/scalac-aspects/aspects.jar</arg>
          </args>
          ....
 

[David Bernard]

try with

<configuration>
<args>
<arg>-nobootcp</arg>

<arg>-toolcp</arg>
<arg>/home/fanf/java/workspaces/rudder-project/scalac-aspects/aspects.jar</arg>
</args>

> --
>
>
>

[Francois]

Le 27/01/2013 19:01, David Bernard a écrit :

try with

<configuration>
          <args>
            <arg>-nobootcp</arg>
            <arg>-toolcp</arg>
            <arg>/DIR/workspaces/rudder-project/scalac-aspects/aspects.jar</arg>
          </args>

OK, so now I don't have an error anymore, the cmds arguments seems ok, but the timing are not displayed.


More preciselly, if I compile from command line, I get the timing.
But with maven, nothing is displayed, even if the given parameters seems ok (see at the end for all the details).

Parhaps someone has an idea about what could be wrong ? Is there a way to log more info about aspectj, to see if it  is correctly loaded ?

The timing are displayed with "sysout.println", I don't know if it's relevant.

Thanks for any idea !

Details of the two compilation done:

Command line:

scalac -J-javaagent:/DIR/aspectj/lib/aspectjweaver.jar -toolcp /DIR/workspaces/rudder-project/scalac-aspects/aspects.jar -nobootcp -d /DIR/workspaces/rudder-project/scala-ldap/target/classes -classpath /M2/com/unboundid/unboundid-ldapsdk/2.3.1/unboundid-ldapsdk-2.3.1.jar:/M2/com/normation/utils/2.6.0-scala_2.10-SNAPSHOT/utils-2.6.0-scala_2.10-SNAPSHOT.jar:/M2/commons-io/commons-io/2.4/commons-io-2.4.jar:/M2/org/scala-lang/scala-library/2.10.0/scala-library-2.10.0.jar:/M2/joda-time/joda-time/2.1/joda-time-2.1.jar:/M2/org/joda/joda-convert/1.2/joda-convert-1.2.jar:/M2/net/liftweb/lift-common_2.10/2.5-M4/lift-common_2.10-2.5-M4.jar:/M2/org/slf4j/slf4j-api/1.6.6/slf4j-api-1.6.6.jar:/M2/ch/qos/logback/logback-core/1.0.7/logback-core-1.0.7.jar:/M2/ch/qos/logback/logback-classic/1.0.7/logback-classic-1.0.7.jar:/DIR/workspaces/rudder-project/scala-ldap/target/classes $(echo **/*.scala)

==> timing displayed

Maven:

cmd: 

java -classpath /M2/org/scala-lang/scala-reflect/2.10.0/scala-reflect-2.10.0.jar:/M2/org/scala-lang/scala-compiler/2.10.0/scala-compiler-2.10.0.jar:/M2/org/scala-lang/scala-library/2.10.0/scala-library-2.10.0.jar:/M2/net/alchim31/maven/scala-maven-plugin/3.1.0/scala-maven-plugin-3.1.0.jar -Xbootclasspath/a:/M2/org/scala-lang/scala-reflect/2.10.0/scala-reflect-2.10.0.jar:/M2/org/scala-lang/scala-compiler/2.10.0/scala-compiler-2.10.0.jar:/M2/org/scala-lang/scala-library/2.10.0/scala-library-2.10.0.jar -javaagent:/DIR/aspectj/lib/aspectjweaver.jar scala_maven_executions.MainWithArgsInFile scala.tools.nsc.Main /tmp/scala-maven-7752166555154956917.args

/tmp/scala-maven-7752166555154956917.args :

-target:jvm-1.6
-nobootcp
-toolcp
/DIR/workspaces/rudder-project/scalac-aspects/aspects.jar
-classpath
/M2/com/unboundid/unboundid-ldapsdk/2.3.1/unboundid -ldapsdk-2.3.1.jar:/M2/com/normation/utils/2.6.0-scala_2.10-SNAPSHOT/utils-2.6.0-scala_2.10-SNAPSHOT.jar:/M2/commons-io/commons-io/2.4/commons-io-2.4.jar:/M2/org/scala-lang/scala-library/2.10.0/scala-library-2.10.0.jar:/M2/joda-time/joda-time/2.1/joda-time-2.1.jar:/M2/org/joda/joda-convert/1.2/joda-convert-1.2.jar:/M2/net/liftweb/lift-common_2.10/2.5-M4/lift-common_2.10-2.5-M4.jar:/M2/org/slf4j/slf4j-api/1.6.6/slf4j-api-1.6.6.jar:/M2/ch/qos/logback/logback-core/1.0.7/logback-core-1.0.7.jar:/M2/ch/qos/logback/logback-classic/1.0.7/logback-classic-1.0.7.jar:/DIR/workspaces/rudder-project/scala-ldap/target/classes
-d
/DIR/workspaces/rudder-project/scala-ldap/target/classes
(list of classes here)


==> no timing displayed

[David Bernard]

It's a bug in the maven-plugin : it doesn't take care of -nobootcp so
the scala-library is part of -Xbootclasspath/a.
I'll be mainly offline this week, I'll see if I can publish a snapshot
this morning with a fix.

[David Bernard]

You can tried with scala-maven-plugin 3.1.3-SNAPSHOT (repo :
https://oss.sonatype.org/content/repositories/snapshots)

/davidB

[Francois]

Le 28/01/2013 12:02, David Bernard a écrit :

You can tried with scala-maven-plugin 3.1.3-SNAPSHOT (repo :
https://oss.sonatype.org/content/repositories/snapshots)

Thanks for that...

Tested, and it doesn't work. But now, I opened my eyes a little better, and I see why.

When running from the comand line, the corresponding Java command is executed, I see that:

java  -javaagent:/home/fanf/java/aspectj/lib/aspectjweaver.jar -classpath /home/fanf/java/scala-2.10.0/lib/akka-actors.jar:/home/fanf/java/scala-2.10.0/lib/jline.jar:/home/fanf/java/scala-2.10.0/lib/scala-actors.jar:/home/fanf/java/scala-2.10.0/lib/scala-actors-migration.jar:/home/fanf/java/scala-2.10.0/lib/scala-compiler.jar:/home/fanf/java/scala-2.10.0/lib/scala-library.jar:/home/fanf/java/scala-2.10.0/lib/scala-partest.jar:/home/fanf/java/scala-2.10.0/lib/scalap.jar:/home/fanf/java/scala-2.10.0/lib/scala-reflect.jar:/home/fanf/java/scala-2.10.0/lib/scala-swing.jar:/home/fanf/java/scala-2.10.0/lib/typesafe-config.jar:/home/fanf/java/workspaces/rudder-project/scalac-aspects/aspects.jar OTHERSTUFF

And from Scala maven plugin, I get that:

java -classpath /home/fanf/.m2/repository/org/scala-lang/scala-compiler/2.10.0/scala-compiler-2.10.0.jar:/home/fanf/.m2/repository/org/scala-lang/scala-reflect/2.10.0/scala-reflect-2.10.0.jar:/home/fanf/.m2/repository/org/scala-lang/scala-library/2.10.0/scala-library-2.10.0.jar:/home/fanf/.m2/repository/net/alchim31/maven/scala-maven-plugin/3.1.3-SNAPSHOT/scala-maven-plugin-3.1.3-SNAPSHOT.jar -javaagent:/home/fanf/java/aspectj/lib/aspectjweaver.jar OTHERSTUFF

And in the arg file, I have:
-toolcp
/home/fanf/java/workspaces/rudder-project/scalac-aspects/aspects.jar

So, I think the -toolcp argument is not understood by scala-maven-plugin. But what I really want is not to have that option, but just to have my aspects.jar in the java classpath.
I see that the <dependencies> tag under <plugin> should allow to do that, but it does not seem to be read by scalac. Well, I don't understand Maven-plugin magic, and I don't know where the tag is supposed to be parsed, but even with:

<plugin>
        <groupId>net.alchim31.maven</groupId>
        <artifactId>scala-maven-plugin</artifactId>
        <version>3.1.3-SNAPSHOT</version>
        <dependencies>
          <dependency>
            <groupId>scalac-aspects</groupId>
            <artifactId>per-unit-timing</artifactId>
            <version>1.0-SNAPSHOT</version>
          </dependency>
        </dependencies>
        <executions>

"dependencies" is null in ScalaMojoSupport#getToolClasspath()

(adding hardcoded "addToClasspath("scalac-aspects", "per-unit-timing", "1.0-SNAPSHOT", classpath);" in getToolClasspath actually allows to have the aspect executed :)

Should I open a bug for the dependency part ?

Thanks again for youe help and responsivness !

[David Bernard]

Nice you find a workaround.
Yes, please open a ticket, then i'll not forgot. I'll try to provide support for toolcp with dedicated config (next week).

If you have time, open an other ticket with info to integrate this metric in the plugin, or write a wiki page with instructions and your feedback for other users.

Thanks

[Francois]

Le 28/01/2013 19:46, David Bernard a écrit :

Nice you find a workaround.

Well, forking scala-maven-plugin and hardcoding my dependencies barelly qualify as a workaround :)

Yes, please open a ticket, then i'll not forgot. I'll try to provide support for toolcp with dedicated config (next week).

In fact there is no bug on the plugin, I misplaced the dependency tag... And now everything is working !
So basically, just adding the timing aspect and a couple of configuration parameters works :) Of course, it should be possible to use any aspect, that great !

If you have time, open an other ticket with info to integrate this metric in the plugin, or write a wiki page with instructions and your feedback for other users.

Yes, I'm going to write a blog post on that, and try to add documentation on the wiki :)

Thanks again for the help !

[Francois]

Le 28/01/2013 19:46, David Bernard a écrit :
>

> Nice you find a workaround.
> Yes, please open a ticket, then i'll not forgot. I'll try to provide
> support for toolcp with dedicated config (next week).
>
> If you have time, open an other ticket with info to integrate this
> metric in the plugin, or write a wiki page with instructions and your
> feedback for other users.
>
>

So, thanks to your help and responsivness of David, it all works nicely:
http://blog.normation.com/en/2013/01/29/per-file-compilation-time-in-a-scala-maven-project/

David, I'll try to update the wiki soon.

Thanks again,