How to speed up model generation?

[Torsten Juergeleit]

Generating a small domain model from scratch via "mvn clean compile" takes on my machine (windoze xp) "literally" ages:

[INFO] --- fornax-oaw-m2-plugin:3.2.3:run-workflow (default) @ domain ---
[INFO] Fornax Model Workflow Maven2 Plugin V3.2.3
[INFO]  o.e.emf.mwe.utils.StandaloneSetup - Registering platform uri 'C:\DriveD\vk\relaunch-domain\base'
[INFO]  o.e.emf.mwe.utils.StandaloneSetup - Adding generated EPackage 'org.fornax.cartridges.sculptor.dsl.sculptordsl.SculptordslPackage'
[INFO]  o.e.emf.mwe.utils.StandaloneSetup - Adding generated EPackage 'sculptormetamodel.SculptormetamodelPackage'
[INFO]  org.eclipse.xpand2.Generator - Written 79 files to outlet [default](src/generated/java)
[INFO]  org.eclipse.xpand2.Generator - Written 18 files to outlet TO_SRC(src/main/java)
[INFO]  org.eclipse.xpand2.Generator - Written 2 files to outlet TO_SRC_TEST(src/test/java)
[INFO]  org.eclipse.xpand2.Generator - Skipped writing of 1 files to outlet TO_SRC_TEST(src/test/java)
[INFO]  org.eclipse.xpand2.Generator - Written 3 files to outlet TO_GEN_SRC_TEST(src/test/generated/java)
[INFO]  org.eclipse.xpand2.Generator - Written 3 files to outlet TO_RESOURCES(src/main/resources)
[INFO]  org.eclipse.xpand2.Generator - Written 4 files to outlet TO_RESOURCES_TEST(src/test/resources)
[INFO]  org.eclipse.xpand2.Generator - Skipped writing of 2 files to outlet TO_RESOURCES_TEST(src/test/resources)
[INFO]  org.eclipse.xpand2.Generator - Written 16 files to outlet TO_GEN_RESOURCES(src/generated/resources)
[INFO]  org.eclipse.xpand2.Generator - Written 3 files to outlet TO_GEN_RESOURCES_TEST(src/test/generated/resources)
[INFO]  o.e.e.mwe2.runtime.workflow.Workflow - Done.
[INFO] Workflow 'file://c:\DriveD\vk\relaunch-domain\base\domain/src/main/resources/generator/Workflow.mwe2' finished.
[INFO] Adding c:\DriveD\vk\relaunch-domain\base\domain\src\generated\resources to the list of current resources.
[INFO] Adding c:\DriveD\vk\relaunch-domain\base\domain\src\main\resources to the list of current resources.
[INFO] Adding c:\DriveD\vk\relaunch-domain\base\domain\src\test\generated\resources to the list of current resources.
[INFO] Adding c:\DriveD\vk\relaunch-domain\base\domain\src\test\generated\java to the list of current resources.
[INFO]
[INFO] --- fornax-checksum-m2-plugin:1.0.0:run (after generate) @ domain ---
[INFO] Ignoring directories: [.svn]
[INFO] ChecksumValidator: GENERATE CHECKSUMS
[INFO]
[INFO] --- fornax-graphviz-m2-plugin:1.0.0:run (default) @ domain ---
[INFO]
[INFO] --- maven-resources-plugin:2.4.3:resources (default-resources) @ domain ---
[INFO] Using 'ISO-8859-1' encoding to copy filtered resources.
[INFO] Copying 11 resources
[INFO] Copying 22 resources
[INFO] Copying 11 resources
[INFO]
[INFO] --- maven-compiler-plugin:2.3.2:compile (default-compile) @ domain ---
[INFO] Compiling 99 source files to c:\DriveD\vk\relaunch-domain\base\domain\target\classes
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 58.766s
[INFO] Finished at: Wed Jul 13 19:46:03 CEST 2011
[INFO] Final Memory: 12M/123M
[INFO] ------------------------------------------------------------------------


Up to the point where the text "Adding generated EPackage 'sculptormetamodel.SculptormetamodelPackage'" is logged the maven build is fast. Then the build goes to sleep and with the first logged message from "org.eclipse.xpand2.Generator" the build is fast again.

Most (95%) of the time is spent in "org.fornax.toolsupport.maven2.MojoWorkflowRunner.run()" waiting for a Ant build (running in a separate JVM) finishing it's stuff.

Is it possible to tweak this process to get a better performance? Maybe by skipping of generating the documentation (*.dot, *.html).

/Torsten

[Patrik Nordwall]

This is what I use when doing small changes

mvn -o -npu generate-sources

Make sure maven is given much memory, assuming you have free memory in your box.

set MAVEN_OPTS=-Xms256m -Xmx1024m

We have done an effort to do partial generate of the changed modules as described here: http://fornax.itemis.de/confluence/display/fornax/3.+Advanced+Tutorial+%28CSC%29#3.AdvancedTutorial%28CSC%29-Dividemodelintoseveralfiles

If this doesn't help my only advice is to buy a new MacBook Pro ;-)

/Patrik

[agt14]

unfortunatly i have the same problem. i try to descibe my environment
and tests maybe somebody can help.

- if i run "mvn -o -npu generate-sources" the generation will be block
and i get the following times:
[INFO] Parent project for ebl-parent ..................... SUCCESS
[0.157s]
[INFO] Business tier project for ebl ..................... SUCCESS
[2:48.546s]
[INFO] Web project for ebl-web ........................... SUCCESS
[15.469s]

- i get almost the same performance with mvn clean install

- it is strange that the generation in the ebl project is blocked but
in ebl-parent is not blocked

- if i run the mwe2 workflow in eclipse with Run as->MWE2 Workflow
then the generation in finished in a few seconds (~10 sec)


My environment:
Sculptor 2.0
5 Entities with 5 attributes each

U:\>mvn -version
Apache Maven 3.0.3 (r1075438; 2011-02-28 18:31:09+0100)
Maven home: C:\Programme\apache-maven-3.0.3\bin\..
Java version: 1.6.0_25, vendor: Sun Microsystems Inc.
Java home: C:\Programme\Java\jdk1.6.0_25\jre
Default locale: en_US, platform encoding: Cp1252
OS name: "windows xp", version: "5.1", arch: "x86", family: "windows"

eclipse plugin versions
org.eclipse.emf.mwe2.language.ui_1.0.2.v201102151014.jar
org.eclipse.emf.mwe2.language_1.0.2.v201102151014.jar
org.eclipse.emf.mwe2.launch_1.0.2.v201102151014.jar
org.eclipse.emf.mwe2.runtime_1.0.2.v201102150556.jar

[Patrik Nordwall]

What memory settings (-Xms -Xmx) have you given mvn?

/Patrik

[agt14]

i tryed the settings you have suggested
set MAVEN_OPTS=-Xms256m -Xmx1024m

on my computer this setting doesn't change the performance. i can see
in the task manager that the maven uses more memory but it takes the
same time. (the same with set MAVEN_OPTS=-Xms1024m -Xmx1024m)
it is strange that at the step "[INFO]

o.e.emf.mwe.utils.StandaloneSetup - Adding generated EPackage

'sculptormetamodel.SculptormetamodelPackage'" the processing is block
and there is no cpu activity or hard disk usage.

i also tryed with maven 2.2.1 but the same result.

[Torsten Juergeleit]

The fornax-oaw-m2-plugin is internally forking a JVM. This JVM gets it memory settings via Maven plugin properties as described in [1].

/Torsten

[1] http://fornax.itemis.de/confluence/display/fornax/7.+Developer%27s+Guide+%28CSC%29#7.Developer%27sGuide%28CSC%29-PerformanceTuningofGenerator

On Saturday, August 6, 2011 4:11:12 PM UTC+2, agt14 wrote:

i tryed the settings you have suggested
set MAVEN_OPTS=-Xms256m -Xmx1024m

on my computer this setting doesn't change the performance. i can see
in the task manager that the maven uses more memory but it takes the
same time. (the same with set MAVEN_OPTS=-Xms1024m -Xmx1024m)
it is strange that at the step "[INFO]
o.e.emf.mwe.utils.StandaloneSetup - Adding generated EPackage
'sculptormetamodel.SculptormetamodelPackage'" the processing is block
and there is no cpu activity or hard disk usage.

i also tryed with maven 2.2.1 but the same result.

[Patrik Nordwall]

Thanks Torsten. Can you try if that helps?

I thought the default came from the parent mvn process, if not defined as properties. If that is not the case it is very important to set those propeeties and we should revise the archetypes.

/Patrik

[agt14]

unfortunatly this setting did not chnage the performance.
i wounder what is the reson for the performance difference between the
ebl and ebl-web project. both of them call the fornax-oaw-m2-plugin in
the same way.

On Aug 6, 5:57 pm, Patrik Nordwall <patrik.nordw...@gmail.com> wrote:
> Thanks Torsten. Can you try if that helps?
>
> I thought the default came from the parent mvn process, if not defined as properties. If that is not the case it is very important to set those propeeties and we should revise the archetypes.
>
> /Patrik
>

> 6 aug 2011 kl. 16:52 skrev Torsten Juergeleit <torsten.juergel...@gmail.com>:
>
>
>
>
>
>
>
> > The fornax-oaw-m2-plugin is internally forking a JVM. This JVM gets it memory settings via Maven plugin properties as described in [1].
>
> > /Torsten
>

> > [1]http://fornax.itemis.de/confluence/display/fornax/7.+Developer%27s+Gu...

[Patrik Nordwall]

Ok, Very strange, 3 minutes is incredibly long, especially since you say that the same thing takes 10 sec when running from Eclipse. Hard for me to know what can be wrong.

/Patrik

[agt14]

i would like to try to debug this problem if possible. do you have any
idea where i find some documentation describing how to debug this?
thank you

[Pavel Tavoda]

Can you please run jstack <PID> (pid you can find with jps) at time
when this generation 'freeze'? Please send us result.

Regards

Pavel

[Patrik Nordwall]

Great idea. You can also attatch jvisualvm to the process and look at memory and cpu graphs to see if something actually is going on.

/Patrik

[Torsten Juergeleit]

From [1] and looking through the source code of "org.eclipse.emf.mwe2.runtime.workflow.Workflow" (mentioned in [1]) I assume that using "Run as -> MWE2 Workflow" is so fast because it runs the MWE2 workflow within the Eclipse runtime.

In comparison the fornax-oaw-m2-plugin has to do heavy lifting: Forking a separate JVM via the Java Ant task and starting a EMF runtime with all its dependant Eclipse plugins from scratch. This normally takes a while :-(

/Torsten

[1] http://dev.eclipse.org/viewcvs/viewvc.cgi/org.eclipse.tmf/org.eclipse.xtext/plugins/org.eclipse.xtext.doc/help/MWE2.html?root=Modeling_Project&view=co

[Torsten Juergeleit]

If available, YourKit [1] is very helpful here. They're offering an evaluation license for 15 days.

YourKit can easily be activated in your Maven build by adding YourKits java agent to the list of JVM arguments of the M2 plugin, e.g.

                <plugin>
                    <groupId>org.fornax.toolsupport</groupId>
                    <artifactId>fornax-oaw-m2-plugin</artifactId>
                    <version>${fornax-oaw-m2.version}</version>
                    <configuration>
                        <workflowEngine>mwe2</workflowEngine>
                        <workflowDescriptor>file://${basedir}/src/main/resources/generator/Workflow.mwe2</workflowDescriptor>
                        <checkFilesets>
                            <checkFileset>
                                <directory>${basedir}</directory>
                                <includes>
                                    <include>src/main/resources/*.btdesign</include>
                                </includes>
                            </checkFileset>
                        </checkFilesets>
                        <properties>
                            <modelFile>src/main/resources/model.btdesign</modelFile>
                            <appProject>${project.artifactId}</appProject>
                        </properties>
                        <jvmSettings>
                            <jvmArgs>
                                <jvmArg>-agentpath:"C:/Programme/YourKit Java Profiler 9.5.6/bin/win32/yjpagent.dll=dir=c:/yourkit/,tracing"</jvmArg>
                                <jvmArg>-client</jvmArg>
                                <jvmArg>-Xms100m</jvmArg>
                                <jvmArg>-Xmx500m</jvmArg>
                            </jvmArgs>
                        </jvmSettings>
                    </configuration>
                </plugin>

/Torsten

[1] http://yourkit.com/

[Torsten Juergeleit]

I took a brief look in a YourKit sample of a complete run of the fornax-oaw-m2-plugin.

Environment:

- Windows XP SP 3
- Maven 3.0.3
- Sculptor 2.0.0
- Java HotSpot(TM) Client VM; 1.6.0_26; 20.1-b02; mixed mode


Here are some findings:

- Heap usage: allocated 96MB, used 53MB
- Non heap: allocated 28MB , used 28MB (20MB permgen)
- Classses loaded: 4321 (no class unloading)
- single thread "main"
- 99% of execution time is spent in "org.eclipse.emf.mwe2.launch.runtime.Mwe2Launcher.main(String[])" -> forked by Maven plugin
- hot spots (methods with biggest CPU consumption):

* org.antlr.runtime.Lexer.nextToken()     10%
* org.antlr.runtime.CommonTokenStream.LT(int)    5%
* org.antlr.runtime.ANTLRStringStream.LA(int)   4%     -> invocation count: 3,8 million
* java.lang.ClassLoader.loadClass(String)  4%
* de.hunsicker.jalopy.language.JavaRecognizer$1.nextToken()   3%

- exceptions:

* 175 MissingResourceException in "org.fornax.cartridges.sculptor.generator.util.GeneratorProperties.getProperty(String)"


- samples: 472 in ~6 minutes

* 194 samples within "org.hybridlabs.source.formatter.JavaImportBeautifier.beforeWriteAndClose(FileHandle)"



Hhm, there's plenty of Antlr parsing going on by mwe, xtext, xtend, xpand and the Java beautifier.
It seems that JavaImportBeautifier is burning plenty of CPU.

I'm not sure if this Java beautifying approach is scaling. If more Java code is generated (bigger domain model) more time is spent beautifying the generated code.

So how about an option to skip the expensive beautification of generated Java code? In our case the already beautified (one-shot generated) code will be beautified by the developer within Eclipse again :-)

/Torsten

[Torsten Juergeleit]

By removing the postprocessor "org.hybridlabs.source.formatter.JavaImportBeautifier" from the code generation step within Sculptors MWE2 workflow we got our generation time improved greatly (up to 4 times):

    // Code generation
    component = org.eclipse.xpand2.Generator {
        metaModel = org.eclipse.xtend.typesystem.emf.EmfRegistryMetaModel {
            useSingleGlobalResourceSet = true
        }
        fileEncoding = "iso-8859-1"
        outlet = {                               path = outlet.src.dir                             }//postprocessor = org.hybridlabs.source.formatter.JavaImportBeautifier {}}
        outlet = {name = "TO_SRC"                path = outlet.src.once.dir      overwrite = false }//postprocessor = org.hybridlabs.source.formatter.JavaImportBeautifier {}}
        outlet = {name = "TO_SRC_TEST"           path = outlet.src.test.once.dir overwrite = false }//postprocessor = org.hybridlabs.source.formatter.JavaImportBeautifier {}}
        outlet = {name = "TO_GEN_SRC_TEST"       path = outlet.src.test.dir      overwrite = true  }//postprocessor = org.hybridlabs.source.formatter.JavaImportBeautifier {}}
        outlet = {name = "TO_RESOURCES"          path = outlet.res.once.dir      overwrite = false postprocessor = XmlFormatter {}}


Is there any chance to achieve this via SpecialCases without copying and tweaking the complete workflow from "workflow::Sculptorworkflow.mwe2"?

/Torsten

[Torsten Juergeleit]

As a workaround one can classpath-shadow the class "org.hybridlabs.source.formatter.JavaImportBeautifier" with an empty PostProcessor implementation:

package org.hybridlabs.source.formatter;

import org.eclipse.xpand2.output.FileHandle;
import org.eclipse.xpand2.output.PostProcessor;

public class JavaImportBeautifier implements PostProcessor {

    @Override
    public void afterClose(FileHandle arg0) {
        // Do nothing
    }

    @Override
    public void beforeWriteAndClose(FileHandle arg0) {
        // Do nothing
    }

}


Putting this class in a jar in front of "fornax-cartridges-sculptor-generator-2.0.0.jar" (and in front of its transitive dependency "hybridlabs-beautifier-m2t-xpand-2.1.1.jar") does the trick.


Ok, the generated Java code looks ugly, but the build is a lot faster :-)

/Torsten

[Patrik Nordwall]

Thanks for looking into how to speed up generation. I also think it is important. I spent some time on it a while ago to try to do more partial generation, based on what was changed in the model. Xtext has some support for that, but I didn't manage to get it working good enough (immature, complicated), so I placed that idea on the shelf. The best I could do at that point was the partial module generation, as described in docs.

Regarding scalable, it is not intended to be used in one big monolithic model. I think we all do better design than that.

Regarding beautifier, interesting conclusion. I must see that for my self. Then we have an area to improve.

However, I would never recommend to remove the beatifier. Generated code should be as readable as hand written. 

/Patrik

[Torsten Juergeleit]

> However, I would never recommend to remove the beatifier. Generated code should be as readable as hand written.

You're right, at least for the one-shot generated Java code is getting rid of the fully-qualified type names needed.


So how about  an option to turning off beautifying of the java code in the "/generated/" folders? This code is normally only shown to the compiler and not to the developer (maybe for debugging purposes).


And how is xpand2s built-in java beautifier "org.eclipse.xpand2.output.JavaBeautifier" handling fully-qualified type names? Eclipse code formatter / organize imports isn't capable of removing fully-qualified type names.

/Torsten

[Torsten Juergeleit]

Or maybe providing an option for turning of code formatting via "JavaImportBeautifier.setFormat(false)" may speed up code generation a bit.

Or how about providing an extension point where one can provide its own implementation of "org.eclipse.xpand2.output.PostProcessor"?

/Torsten

Am Montag, 8. August 2011 19:59:00 UTC+2 schrieb Torsten Juergeleit:

> However, I would never recommend to remove the beatifier. Generated code should be as readable as hand written.

You're right, at least for the one-shot generated Java code is getting rid of the fully-qualified type names needed.


So how about  an option to turning off beautifying of the java code in the "/generated/" folders? This code is normally only shown to the compiler and not to the developer (maybe for debugging purposes).


And how is xpand2s built-in java beautifier "org.eclipse.xpand2.output.JavaBeautifier" handling fully-qualified type names? Eclipse code formatter / organize imports isn't capable of removing fully-qualified type names.

/Torsten

Am Montag, 8. August 2011 18:09:37 UTC+2 schrieb Patrik Nordwall:

Thanks for looking into how to speed up generation. I also think it is important. I spent some time on it a while ago to try to do more partial generation, based on what was changed in the model. Xtext has some support for that, but I didn't manage to get it working good enough (immature, complicated), so I placed that idea on the shelf. The best I could do at that point was the partial module generation, as described in docs.

Regarding scalable, it is not intended to be used in one big monolithic model. I think we all do better design than that.

Regarding beautifier, interesting conclusion. I must see that for my self. Then we have an area to improve.

However, I would never recommend to remove the beatifier. Generated code should be as readable as hand written. 

/Patrik

[Patrik Nordwall]

I tried with one of my real world projects. It consists of:

110 model elements (Entity, ValueObject, Service, Repository, enum, etc...)

335 generated files

Timing reported by maven (Total time:)

mvn clean generate-sources: 45 s

Removed fornax-checksum-m2-plugin from pom.xml

mvn clean generate-sources: 12.6 s

I also tried to manually remove all files and then generate without checksum plugin. Same result.

Removed JavaImportBeautifier postprocessor from Sculptorworkflow.mwe2

mvn clean generate-sources: 9.5 sec

Do you see the same kind of result when removing fornax-checksum-m2-plugin?

/Patrik

[Torsten Juergeleit]

>Do you see the same kind of result when removing fornax-checksum-m2-plugin?

No, removing fornax-checksum-m2-plugin doesn't give us this kind of remarkable performance boost.

/Torsten

[Torsten Juergeleit]

So we ended up with the following approach:

We're using a patched version of the default Sculptorworkflow with a no-formatting JavaImportBeautifier (format = false) for the one-shot generated java code and disabled JavaImportBeautifier for the always regenerated java code.

outlet = {                             

  path = outlet.src.dir                             /*postprocessor = org.hybridlabs.source.formatter.JavaImportBeautifier {}*/}

outlet = {name = "TO_SRC"                path = outlet.src.once.dir      overwrite = false postprocessor = org.hybridlabs.source.formatter.JavaImportBeautifier { format = false }}

outlet = {name = "TO_SRC_TEST"           path = outlet.src.test.once.dir overwrite = false postprocessor = org.hybridlabs.source.formatter.JavaImportBeautifier { format = false }}

outlet = {name = "TO_GEN_SRC_TEST"       path = outlet.src.test.dir      overwrite = true  /*postprocessor = org.hybridlabs.source.formatter.JavaImportBeautifier {}*/}


The performance gain is not optimal but we definitely need to get rid of the fully-qualified type names in the one-shot generated java code.

/Torsten

Am Montag, 8. August 2011 19:59:00 UTC+2 schrieb Torsten Juergeleit:

> However, I would never recommend to remove the beatifier. Generated code should be as readable as hand written.

You're right, at least for the one-shot generated Java code is getting rid of the fully-qualified type names needed.


So how about  an option to turning off beautifying of the java code in the "/generated/" folders? This code is normally only shown to the compiler and not to the developer (maybe for debugging purposes).


And how is xpand2s built-in java beautifier "org.eclipse.xpand2.output.JavaBeautifier" handling fully-qualified type names? Eclipse code formatter / organize imports isn't capable of removing fully-qualified type names.

/Torsten

Am Montag, 8. August 2011 18:09:37 UTC+2 schrieb Patrik Nordwall:

Thanks for looking into how to speed up generation. I also think it is important. I spent some time on it a while ago to try to do more partial generation, based on what was changed in the model. Xtext has some support for that, but I didn't manage to get it working good enough (immature, complicated), so I placed that idea on the shelf. The best I could do at that point was the partial module generation, as described in docs.

Regarding scalable, it is not intended to be used in one big monolithic model. I think we all do better design than that.

Regarding beautifier, interesting conclusion. I must see that for my self. Then we have an area to improve.

However, I would never recommend to remove the beatifier. Generated code should be as readable as hand written. 

/Patrik

[Patrik Nordwall]

I found the reason for the "45 s vs 13 s mystery". fornax-checksum-m2-plugin removes logback.xml when it is not changed, as it should, and that means that default debug log level triggers a lot of (invisible) debug log calls inside  JavaImportBeautifierImpl.

This must be fixed somehow. We can't ship projects from archetypes with this silent problem. It goes away as soon as logback.xml has been touched, but the initial experience is bad. I don't think we even generate logback.xml for all project types.

How do you think we should fix it?

@agt14: Have you tried to remove fornax-checksum-m2-plugin, or do some modifications in logback.xml?

/Patrik

[Torsten Juergeleit]

>How do you think we should fix it?

IMHO the requirement of the sculptor generator (which internally uses a forked JVM) to have a logback.xml on the maven projects classpath is not a good idea.

How about shipping the sculptor generator jar with its own logback.xml? This way it's made sure that the generator always runs with appropriate log settings.

Btw. why is the sculptor generator jar a dependency of the maven project instead a dependency of the fornax-oaw-m2-plugin?

/Torsten

[agt14]

using Java VisualVM i have found out that 99% of the time is spend in
ch.qos.logback.core.joran.spi.ConsoleTarget$1.write(ConsoleTarget.java:
36). this was called from JavaImportBeautifierImpl.traverseAst() using
Logger.debug(). it seems that somewhere in my classpath there is a
configuration defining the log level debug. to avoid this i renamed
the \src\main\resources\logback.xml in \src\main\resources\logback-
test.xml. because of the higher priority of logback-test.xml i get a
much better perormance

with logback-test.xml

[INFO] Parent project for ebl-parent ..................... SUCCESS

[0.282s]

[INFO] Business tier project for ebl ..................... SUCCESS

[12.781s]

[INFO] Web project for ebl-web ........................... SUCCESS

[39.750s]

without logback-test.xml

[INFO] Parent project for ebl-parent ..................... SUCCESS

[0.282s]

[INFO] Business tier project for ebl ..................... SUCCESS

[1:39.812s]

[INFO] Web project for ebl-web ........................... SUCCESS

[34.469s]

On Aug 9, 9:53 pm, Torsten Juergeleit <torsten.juergel...@gmail.com>
wrote:

> >>>   path = outlet.src.dir                **             /*postprocessor =
> >>> org.hybridlabs.source.**formatter.JavaImportBeautifier {}*/}

>
> >> outlet = {name = "TO_SRC"                path = outlet.src.once.dir      
> >> overwrite = false postprocessor =
> >> org.hybridlabs.source.formatter.JavaImportBeautifier { format = false }}
>
> >> outlet = {name = "TO_SRC_TEST"           path = outlet.src.test.once.dir
> >> overwrite = false postprocessor =
> >> org.hybridlabs.source.formatter.JavaImportBeautifier { format = false }}
>
> >> outlet = {name = "TO_GEN_SRC_TEST"       path = outlet.src.test.dir      
> >> overwrite = true  /*postprocessor =
> >> org.hybridlabs.source.formatter.JavaImportBeautifier {}*/}
>
> >> The performance gain is not optimal but we definitely need to get rid of
> >> the fully-qualified type names in the one-shot generated java code.
>
> >> /Torsten
>
> >> Am Montag, 8. August 2011 19:59:00 UTC+2 schrieb Torsten Juergeleit:
>
> >>> > However, I would never recommend to remove the beatifier. Generated
> >>> code should be as readable as hand written.
>
> >>> You're right, at least for the one-shot generated Java code is getting
> >>> rid of the fully-qualified type names needed.
>
> >>> So how about  an option to turning off beautifying of the java code in
> >>> the "/generated/" folders? This code is normally only shown to the compiler
> >>> and not to the developer (maybe for debugging purposes).
>

> >>> And how is xpand2s built-in java beautifier "org.eclipse.xpand2.output.*
> >>> *JavaBeautifier" handling fully-qualified type names? Eclipse code

> >>> formatter / organize imports isn't capable of removing fully-qualified type
> >>> names.
>
> >>> /Torsten
>
> >>> Am Montag, 8. August 2011 18:09:37 UTC+2 schrieb Patrik Nordwall:
>
> >>>> Thanks for looking into how to speed up generation. I also think it is
> >>>> important. I spent some time on it a while ago to try to do more partial
> >>>> generation, based on what was changed in the model. Xtext has some support
> >>>> for that, but I didn't manage to get it working good enough (immature,
> >>>> complicated), so I placed that idea on the shelf. The best I could do at
> >>>> that point was the partial module generation, as described in docs.
>
> >>>> Regarding scalable, it is not intended to be used in one big monolithic
> >>>> model. I think we all do better design than that.
>
> >>>> Regarding beautifier, interesting conclusion. I must see that for my
> >>>> self. Then we have an area to improve.
>
> >>>> However, I would never recommend to remove the beatifier. Generated code
> >>>> should be as readable as hand written.
>
> >>>> /Patrik
>
> >>>> 8 aug 2011 kl. 17:49 skrev Torsten Juergeleit <tors...@gmail.com>:
>
> >>>> As a workaround one can classpath-shadow the class

> >>>> "org.hybridlabs.source.**formatter.**JavaImportBeautifier" with an
> >>>> empty PostProcessor implementation:
>
> >>>> package org.hybridlabs.source.**formatter;
>
> >>>> import org.eclipse.xpand2.output.**FileHandle;
> >>>> import org.eclipse.xpand2.output.**PostProcessor;

>
> >>>> public class JavaImportBeautifier implements PostProcessor {
>
> >>>>     @Override
> >>>>     public void afterClose(FileHandle arg0) {
> >>>>         // Do nothing
> >>>>     }
>
> >>>>     @Override
> >>>>     public void beforeWriteAndClose(FileHandle arg0) {
> >>>>         // Do nothing
> >>>>     }
>
> >>>> }
>

> >>>> Putting this class in a jar in front of "fornax-cartridges-sculptor-**generator-2.0.0.jar"
> >>>> (and in front of its transitive dependency "hybridlabs-beautifier-m2t-*
> >>>> *xpand-2.1.1.jar") does the trick.

>
> >>>> Ok, the generated Java code looks ugly, but the build is a lot faster
> >>>> :-)
>
> >>>> /Torsten
>
> >>>> Am Montag, 8. August 2011 16:20:31 UTC+2 schrieb Torsten Juergeleit:
>

> >>>>> By removing the postprocessor "org.hybridlabs.source.**formatter.**JavaImportBeautifier"

> >>>>> from the code generation step within Sculptors MWE2 workflow we got our
> >>>>> generation time improved greatly (up to 4 times):
>
> >>>>>     // Code generation
> >>>>>     component = org.eclipse.xpand2.Generator {

> >>>>>         metaModel = org.eclipse.xtend.typesystem.**emf.EmfRegistryMetaModel

> >>>>> {
> >>>>>             useSingleGlobalResourceSet = true
> >>>>>         }
> >>>>>         fileEncoding = "iso-8859-1"

> >>>>>         outlet = {                             **  path =
> >>>>> outlet.src.dir                **             }//postprocessor =
> >>>>> org.hybridlabs.source.**formatter.JavaImportBeautifier {}}

> >>>>>         outlet = {name = "TO_SRC"                path =
> >>>>> outlet.src.once.dir      overwrite = false }//postprocessor =

> >>>>> org.hybridlabs.source.**formatter.JavaImportBeautifier {}}

> >>>>>         outlet = {name = "TO_SRC_TEST"           path =
> >>>>> outlet.src.test.once.dir overwrite = false }//postprocessor =

> >>>>> org.hybridlabs.source.**formatter.JavaImportBeautifier {}}

> >>>>>         outlet = {name = "TO_GEN_SRC_TEST"       path =
> >>>>> outlet.src.test.dir      overwrite = true  }//postprocessor =

> >>>>> org.hybridlabs.source.**formatter.JavaImportBeautifier {}}

> >>>>>         outlet = {name = "TO_RESOURCES"          path =
> >>>>> outlet.res.once.dir      overwrite = false postprocessor = XmlFormatter {}}
>
> >>>>> Is there any chance to achieve this via SpecialCases without copying

> >>>>> and tweaking the complete workflow from "workflow::Sculptorworkflow.**

> >>>>> mwe2"?
>
> >>>>> /Torsten
>
> >>>>> Am Montag, 8. August 2011 15:52:43 UTC+2 schrieb Torsten Juergeleit:
>
> >>>>>> I took a brief look in a YourKit sample of a complete run of the
> >>>>>> fornax-oaw-m2-plugin.
>
> >>>>>> Environment:
>
> >>>>>> - Windows XP SP 3
> >>>>>> - Maven 3.0.3
> >>>>>> - Sculptor 2.0.0
> >>>>>> - Java HotSpot(TM) Client VM; 1.6.0_26; 20.1-b02; mixed mode
>
> >>>>>> Here are some findings:
>
> >>>>>> - Heap usage: allocated 96MB, used 53MB
> >>>>>> - Non heap: allocated 28MB , used 28MB (20MB permgen)
> >>>>>> - Classses loaded: 4321 (no class unloading)
> >>>>>> - single thread "main"

> >>>>>> - 99% of execution time is spent in "org.eclipse.emf.mwe2.launch.**
> >>>>>> runtime.Mwe2Launcher.main(**String[])" -> forked by Maven plugin

> >>>>>> - hot spots (methods with biggest CPU consumption):
>

> >>>>>> * org.antlr.runtime.Lexer.**nextToken()     10%
> >>>>>> * org.antlr.runtime.**CommonTokenStream.LT<http://org.antlr.runtime.CommonTokenStream.LT>(int)    
> >>>>>> 5%
> >>>>>> * org.antlr.runtime.**ANTLRStringStream.LA<http://org.antlr.runtime.ANTLRStringStream.LA>(int)  

> >>>>>> 4%     -> invocation count: 3,8 million

> >>>>>> * java.lang.ClassLoader.**loadClass(String)  4%
> >>>>>> * de.hunsicker.jalopy.language.**JavaRecognizer$1.nextToken()   3%
>
> >>>>>> - exceptions:
>
> >>>>>> * 175 MissingResourceException in "org.fornax.cartridges.**
> >>>>>> sculptor.generator.util.**GeneratorProperties.**getProperty(String)"

>
> >>>>>> - samples: 472 in ~6 minutes
>

> >>>>>> * 194 samples within "org.hybridlabs.source.**formatter.**
> >>>>>> JavaImportBeautifier.**beforeWriteAndClose(**FileHandle)"

>
> >>>>>> Hhm, there's plenty of Antlr parsing going on by mwe, xtext, xtend,
> >>>>>> xpand and the Java beautifier.
> >>>>>> It seems that JavaImportBeautifier is burning plenty of CPU.
>
> >>>>>> I'm not sure if this Java beautifying approach is scaling. If more
> >>>>>> Java code is generated (bigger domain model) more time is spent beautifying
> >>>>>> the generated code.
>
> >>>>>> So how about an option to skip the expensive beautification of
> >>>>>> generated Java code? In our case the already beautified (one-shot generated)
> >>>>>> code will be beautified by the developer within Eclipse again :-)
>
> >>>>>> /Torsten
>
> >>>>>> Am Sonntag, 7. August 2011 20:17:23 UTC+2 schrieb Pavel Tavoda:
>
> >>>>>>> Can you please run jstack <PID> (pid you can find with jps) at time
> >>>>>>> when this generation 'freeze'? Please send us result.
>
> >>>>>>> Regards
>
> >>>>>>> Pavel
>
> >>>>>>> On Aug 7, 2:17 pm, agt14 <kr...@agentes.de> wrote:
> >>>>>>> > i would like to try to debug this problem if possible. do you have
> >>>>>>> any
> >>>>>>> > idea where i find some documentation describing how to debug this?
> >>>>>>> > thank you
>

> ...
>
> read more »

[Patrik Nordwall]

Great! Then you had the same problem as I found.

I have fixed it in trunk, see http://fornax.itemis.de/jira/browse/CSC-651

You can fix it in 2.0.0 project by adding the same kind of settings to fornax-oaw-m2-plugin as described in CSC-651

Copy the following logback-sculptor.xml file to your src/main/resources/generator directory:

http://fornax.svn.sourceforge.net/viewvc/fornax/trunk/cartridges/sculptor/fornax-cartridges-sculptor-generator/src/main/resources/generator/logback-sculptor.xml?revision=7651&content-type=text%2Fplain

/Patrik

[Patrik Nordwall]

On Tue, Aug 9, 2011 at 9:53 PM, Torsten Juergeleit <torsten.j...@gmail.com> wrote:

>How do you think we should fix it?

IMHO the requirement of the sculptor generator (which internally uses a forked JVM) to have a logback.xml on the maven projects classpath is not a good idea.

How about shipping the sculptor generator jar with its own logback.xml? This way it's made sure that the generator always runs with appropriate log settings.

Good idea. That is pretty much what I did to solve CSC-651. I will not include default logback.xml in any jar file, due to the risk of having that jar in the runtime classpath.

 

Btw. why is the sculptor generator jar a dependency of the maven project instead a dependency of the fornax-oaw-m2-plugin?

Yes, that would be much better. We have had problems with that and therefore had to include it in project dependencies instead. I don't remember what the problem was. Maybe it was the the fork in fornax-oaw-m2-plugin or maybe it was that then it will not be included in project libs when using eclipse:eclipse, and then not possible to run generation from eclipse "Run as > MWE2 Workflow".

/Torsten

[Pavel Tavoda]

I don't know how is it with .xxx files in archetype but we can ship
initial .ignore-checksum.txt in archetype. With content like:
src/main/resources/logback.xml
src/main/resources/generator

Pavel

On Aug 9, 8:18 pm, Patrik Nordwall <patrik.nordw...@gmail.com> wrote:
> I found the reason for the "45 s vs 13 s mystery". fornax-checksum-m2-plugin
> removes logback.xml when it is not changed, as it should, and that means
> that default debug log level triggers a lot of (invisible) debug log calls
> inside  JavaImportBeautifierImpl.
>
> This must be fixed somehow. We can't ship projects from archetypes with this
> silent problem. It goes away as soon as logback.xml has been touched, but
> the initial experience is bad. I don't think we even generate logback.xml
> for all project types.
>
> How do you think we should fix it?
>
> @agt14: Have you tried to remove fornax-checksum-m2-plugin, or do some
> modifications in logback.xml?
>
> /Patrik
>
> On Tue, Aug 9, 2011 at 5:14 PM, Torsten Juergeleit <
>
>
>
>
>
>
>
> torsten.juergel...@gmail.com> wrote:
> > So we ended up with the following approach:
>
> > We're using a patched version of the default Sculptorworkflow with a
> > no-formatting JavaImportBeautifier (format = false) for the one-shot
> > generated java code and disabled JavaImportBeautifier for the always
> > regenerated java code.
>
> > outlet = {
>

> >>   path = outlet.src.dir                **             /*postprocessor =
> >> org.hybridlabs.source.**formatter.JavaImportBeautifier {}*/}

>
> > outlet = {name = "TO_SRC"                path = outlet.src.once.dir
> > overwrite = false postprocessor =
> > org.hybridlabs.source.formatter.JavaImportBeautifier { format = false }}
>
> > outlet = {name = "TO_SRC_TEST"           path = outlet.src.test.once.dir
> > overwrite = false postprocessor =
> > org.hybridlabs.source.formatter.JavaImportBeautifier { format = false }}
>
> > outlet = {name = "TO_GEN_SRC_TEST"       path = outlet.src.test.dir
> > overwrite = true  /*postprocessor =
> > org.hybridlabs.source.formatter.JavaImportBeautifier {}*/}
>
> > The performance gain is not optimal but we definitely need to get rid of
> > the fully-qualified type names in the one-shot generated java code.
>
> > /Torsten
>
> > Am Montag, 8. August 2011 19:59:00 UTC+2 schrieb Torsten Juergeleit:
>
> >> > However, I would never recommend to remove the beatifier. Generated code
> >> should be as readable as hand written.
>
> >> You're right, at least for the one-shot generated Java code is getting rid
> >> of the fully-qualified type names needed.
>
> >> So how about  an option to turning off beautifying of the java code in the
> >> "/generated/" folders? This code is normally only shown to the compiler and
> >> not to the developer (maybe for debugging purposes).
>

> >> And how is xpand2s built-in java beautifier "org.eclipse.xpand2.output.**JavaBeautifier"

> >> handling fully-qualified type names? Eclipse code formatter / organize
> >> imports isn't capable of removing fully-qualified type names.
>
> >> /Torsten
>
> >> Am Montag, 8. August 2011 18:09:37 UTC+2 schrieb Patrik Nordwall:
>
> >>> Thanks for looking into how to speed up generation. I also think it is
> >>> important. I spent some time on it a while ago to try to do more partial
> >>> generation, based on what was changed in the model. Xtext has some support
> >>> for that, but I didn't manage to get it working good enough (immature,
> >>> complicated), so I placed that idea on the shelf. The best I could do at
> >>> that point was the partial module generation, as described in docs.
>
> >>> Regarding scalable, it is not intended to be used in one big monolithic
> >>> model. I think we all do better design than that.
>
> >>> Regarding beautifier, interesting conclusion. I must see that for my
> >>> self. Then we have an area to improve.
>
> >>> However, I would never recommend to remove the beatifier. Generated code
> >>> should be as readable as hand written.
>
> >>> /Patrik
>
> >>> 8 aug 2011 kl. 17:49 skrev Torsten Juergeleit <torste...@gmail.com>:
>
> >>> As a workaround one can classpath-shadow the class

> >>> "org.hybridlabs.source.**formatter.**JavaImportBeautifier" with an empty
> >>> PostProcessor implementation:
>

> >>> package org.hybridlabs.source.**formatter;
>
> >>> import org.eclipse.xpand2.output.**FileHandle;
> >>> import org.eclipse.xpand2.output.**PostProcessor;
>

> >>> public class JavaImportBeautifier implements PostProcessor {
>
> >>>     @Override
> >>>     public void afterClose(FileHandle arg0) {
> >>>         // Do nothing
> >>>     }
>
> >>>     @Override
> >>>     public void beforeWriteAndClose(FileHandle arg0) {
> >>>         // Do nothing
> >>>     }
>
> >>> }
>

> >>> Putting this class in a jar in front of "fornax-cartridges-sculptor-**generator-2.0.0.jar"
> >>> (and in front of its transitive dependency "hybridlabs-beautifier-m2t-**xpand-2.1.1.jar")

> >>> does the trick.
>
> >>> Ok, the generated Java code looks ugly, but the build is a lot faster :-)
>
> >>> /Torsten
>
> >>> Am Montag, 8. August 2011 16:20:31 UTC+2 schrieb Torsten Juergeleit:
>

> >>>> By removing the postprocessor "org.hybridlabs.source.**formatter.**JavaImportBeautifier"

> >>>> from the code generation step within Sculptors MWE2 workflow we got our
> >>>> generation time improved greatly (up to 4 times):
>
> >>>>     // Code generation
> >>>>     component = org.eclipse.xpand2.Generator {

> >>>>         metaModel = org.eclipse.xtend.typesystem.**emf.EmfRegistryMetaModel

> >>>> {
> >>>>             useSingleGlobalResourceSet = true
> >>>>         }
> >>>>         fileEncoding = "iso-8859-1"

> >>>>         outlet = {                             **  path =
> >>>> outlet.src.dir                **             }//postprocessor =
> >>>> org.hybridlabs.source.**formatter.JavaImportBeautifier {}}

> >>>>         outlet = {name = "TO_SRC"                path =
> >>>> outlet.src.once.dir      overwrite = false }//postprocessor =

> >>>> org.hybridlabs.source.**formatter.JavaImportBeautifier {}}

> >>>>         outlet = {name = "TO_SRC_TEST"           path =
> >>>> outlet.src.test.once.dir overwrite = false }//postprocessor =

> >>>> org.hybridlabs.source.**formatter.JavaImportBeautifier {}}

> >>>>         outlet = {name = "TO_GEN_SRC_TEST"       path =
> >>>> outlet.src.test.dir      overwrite = true  }//postprocessor =

> >>>> org.hybridlabs.source.**formatter.JavaImportBeautifier {}}

> >>>>         outlet = {name = "TO_RESOURCES"          path =
> >>>> outlet.res.once.dir      overwrite = false postprocessor = XmlFormatter {}}
>
> >>>> Is there any chance to achieve this via SpecialCases without copying and

> >>>> tweaking the complete workflow from "workflow::Sculptorworkflow.**

> >>>> mwe2"?
>
> >>>> /Torsten
>
> >>>> Am Montag, 8. August 2011 15:52:43 UTC+2 schrieb Torsten Juergeleit:
>
> >>>>> I took a brief look in a YourKit sample of a complete run of the
> >>>>> fornax-oaw-m2-plugin.
>
> >>>>> Environment:
>
> >>>>> - Windows XP SP 3
> >>>>> - Maven 3.0.3
> >>>>> - Sculptor 2.0.0
> >>>>> - Java HotSpot(TM) Client VM; 1.6.0_26; 20.1-b02; mixed mode
>
> >>>>> Here are some findings:
>
> >>>>> - Heap usage: allocated 96MB, used 53MB
> >>>>> - Non heap: allocated 28MB , used 28MB (20MB permgen)
> >>>>> - Classses loaded: 4321 (no class unloading)
> >>>>> - single thread "main"

> >>>>> - 99% of execution time is spent in "org.eclipse.emf.mwe2.launch.**
> >>>>> runtime.Mwe2Launcher.main(**String[])" -> forked by Maven plugin

> >>>>> - hot spots (methods with biggest CPU consumption):
>

> >>>>> * org.antlr.runtime.Lexer.**nextToken()     10%
> >>>>> * org.antlr.runtime.**CommonTokenStream.LT<http://org.antlr.runtime.CommonTokenStream.LT>(int)
> >>>>> 5%
> >>>>> * org.antlr.runtime.**ANTLRStringStream.LA<http://org.antlr.runtime.ANTLRStringStream.LA>(int)

> >>>>> 4%     -> invocation count: 3,8 million

> >>>>> * java.lang.ClassLoader.**loadClass(String)  4%
> >>>>> * de.hunsicker.jalopy.language.**JavaRecognizer$1.nextToken()   3%
>
> >>>>> - exceptions:
>
> >>>>> * 175 MissingResourceException in "org.fornax.cartridges.**
> >>>>> sculptor.generator.util.**GeneratorProperties.**getProperty(String)"

>
> >>>>> - samples: 472 in ~6 minutes
>

> >>>>> * 194 samples within "org.hybridlabs.source.**formatter.**
> >>>>> JavaImportBeautifier.**beforeWriteAndClose(**FileHandle)"

> ...
>
> read more »

[Patrik Nordwall]

Yes, that would be good, but not necessary, since I now use different log conf for generator, which is a good thing anyway. Logging for generation is very different from runtime.

/Patrik

[Torsten Juergeleit]

Using logbacks system property to point to a sculptor-specific logback configuration is a very clever solution. Thanks Patrik.

This solved our performance issues as well. So we could activate the java code beautifier again.

But keep in mind to exclude this logback config file from being picked up by the jar plugin (adding "**/generator/logback-sculptor.xml" to the jar plugins exclusion list). Otherwise one will end up with logback complaining:

[INFO] 10:29:13,431 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [generator/logback-sculptor.xml] at [file:/C:/DriveD/vk/relaunch_content/service/vertrieb/src/main/resources/generator/logback-sculptor.xml]
[INFO] 10:29:13,431 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [generator/logback-sculptor.xml] occurs multiple times on the classpath.
[INFO] 10:29:13,431 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [generator/logback-sculptor.xml] occurs at [file:/C:/DriveD/vk/relaunch_content/service/vertrieb/src/main/resources/generator/logback-sculptor.xml]
[INFO] 10:29:13,431 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [generator/logback-sculptor.xml] occurs at [jar:file:/C:/DriveD/vk/relaunch_content/service/produkt/target/produkt-11.3.0-SNAPSHOT.jar!/generator/logback-sculptor.xml]

/Torsten

/Patrik

On Aug 9, 9:53 pm, Torsten Juergeleit <torsten.j...@gmail.com>
wrote:

> >How do you think we should fix it?
>
> IMHO the requirement of the sculptor generator (which internally uses a
> forked JVM) to have a logback.xml on the maven projects classpath is not a
> good idea.
> How about shipping the sculptor generator jar with its own logback.xml? This
> way it's made sure that the generator always runs with appropriate log
> settings.
>
> Btw. why is the sculptor generator jar a dependency of the maven project
> instead a dependency of the fornax-oaw-m2-plugin?
>
> /Torsten
>
> Am Dienstag, 9. August 2011 20:18:16 UTC+2 schrieb Patrik Nordwall:
>
>
>
>
>
>
>
>
>
> > I found the reason for the "45 s vs 13 s mystery". fornax-checksum-m2-plugin
> > removes logback.xml when it is not changed, as it should, and that means
> > that default debug log level triggers a lot of (invisible) debug log calls
> > inside  JavaImportBeautifierImpl.
>
> > This must be fixed somehow. We can't ship projects from archetypes with
> > this silent problem. It goes away as soon as logback.xml has been touched,
> > but the initial experience is bad. I don't think we even generate
> > logback.xml for all project types.
>
> > How do you think we should fix it?
>
> > @agt14: Have you tried to remove fornax-checksum-m2-plugin, or do some
> > modifications in logback.xml?
>
> > /Patrik
>

> > On Tue, Aug 9, 2011 at 5:14 PM, Torsten Juergeleit <torste...@gmail.com

[Torsten Juergeleit]

> We have had problems with that and therefore had to include it in project dependencies instead. I don't remember what the problem was. Maybe it was the the fork in 

fornax-oaw-m2-plugin or maybe it was that then it will not be included in project libs when using eclipse:eclipse, and then not possible to run generation from eclipse "Run as > MWE2 Workflow".

Good point. If only the Sculptor maven plugin would know about the generator dependencies then these dependencies would not appear on Eclipses classpath and using "Run as > MWE2 Workflow" would fail.

This issue could be solved via a sculptor-specific M2E extension (as mentioned in https://groups.google.com/d/topic/fornax-platform/hlWQmqYRXkI/discussion ) which would put all the required dependendecies onto the classpath of a M2E Eclipse project during project initialization.

/Torsten