Opened 7 years ago

Closed 4 years ago

#17105 closed defect (fixed)

[regression] build takes much longer

Reported by: xMartin Owned by: Rawld Gill
Priority: blocker Milestone: 1.11
Component: BuildSystem Version: 1.9.0
Keywords: Cc:
Blocked By: Blocking:

Description

Upgraded from 1.8.3 to 1.9.0 and my build takes 100 seconds now compared to 22 seconds before.

Spends a long time when it says in the console: "waiting for the optimizer runner to finish..." and in Terminal.app the window title contains "java".

NodeJS installed. MacBook? Air latest.

Change History (10)

comment:1 Changed 7 years ago by xMartin

Profile settings:

layerOptimize: 'closure',
stripConsole: 'all',
cssOptimize: 'comments',

comment:2 Changed 7 years ago by zzebastien

I've got the same behaviour, my build take much more longer with Dojo 1.9 than Dojo 1.8.3

In the console, it says 'starting writing resources...' and stuck here for at least 2 minutes. In terminal, title contains "java"

action: 'release', layerOptimize: 'closure', stripConsole: 'all',

I also use NodeJS version 0.8.16

I hesitate to move to 1.9 just because of it.

comment:3 Changed 7 years ago by lramos85

Aside from taking longer, I also have an issue in this version (1.9) where the stripConsole is ignored and do not get stripped out.

comment:4 Changed 6 years ago by xMartin

No comment on that? 1.9.1 seems to be ready...

comment:5 Changed 5 years ago by gitgrimbo

I am also seeing slower builds when using a Node-initiated build from a Git Bash shell in Windows 7.

I have put some indicative timings here - https://gist.github.com/gitgrimbo/6948910#file-dojo-build-results-md.

From initial investigation the java.exe processes that are spun up by the build (for closure optimisation in my case) take a certain amount of time to do the actual optimisation, but then take an unusually long time to exit. The rest of the build process seems to block because of this.

As an aside, the 'pure' java builds don't seem to suffer from this, and the speed of the pure java builds seems to be very good (relatively) when using later versions of JDK 8.

comment:6 Changed 5 years ago by dylan

Milestone: tbd1.11
Priority: undecidedblocker

comment:7 Changed 4 years ago by gitgrimbo

I think I've found a possible reason for the 60 second delay at the end of closure builds (when invoked from a build run by Node).

The closure compiler can use an ExecutorService to manage the compilation (https://github.com/google/closure-compiler/blob/v20130227/src/com/google/javascript/jscomp/Compiler.java#L194):

  private static final ExecutorService compilerExecutor =
      Executors.newCachedThreadPool(new ThreadFactory() {
    @Override public Thread newThread(Runnable r) {
      return new Thread(null, r, "jscompiler", COMPILER_STACK_SIZE);
    }
  });

The jdk1.6.0_45 version of this code looks like the following (the jdk1.8.0_45 code is the same). Note the 60 second timeout.

    public static ExecutorService newCachedThreadPool(ThreadFactory threadFactory) {
        return new ThreadPoolExecutor(0, Integer.MAX_VALUE,
                                      60L, TimeUnit.SECONDS,
                                      new SynchronousQueue<Runnable>(),
                                      threadFactory);
    }

This 60 seconds seems to be the compilerExecutor compiler waiting for new tasks. The closure process only terminates when the compilerExecutor times out.

I've tried debugging a simple Java app calling the closure compiler, and I can see this Thread waiting:

Thread [jscompiler] (Suspended)	
	Unsafe.park(boolean, long) line: not available [native method]	
	LockSupport.parkNanos(Object, long) line: 196	
	SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue$TransferStack$SNode, boolean, long) line: 424	
	SynchronousQueue$TransferStack.transfer(Object, boolean, long) line: 323	
	SynchronousQueue<E>.poll(long, TimeUnit) line: 874	
	ThreadPoolExecutor.getTask() line: 955	
	ThreadPoolExecutor$Worker.run() line: 917	
	Thread.run() line: 662	

You seem to be able to turn off Threads by using the useThreads property of the Compiler:

https://github.com/google/closure-compiler/blob/v20130227/src/com/google/javascript/jsc

comment:8 Changed 4 years ago by dylan

Thanks, we'll look into this prior to the 1.11 release!

comment:9 Changed 4 years ago by gitgrimbo

More info

This closure commit introduced the ExecutorService to Compiler (27 Jul 2012):

https://github.com/google/closure-compiler/commit/ed1e171c2007b96afc2f99cab97aed0b211e57a3

This dojo/util commit introduced a new version of closure (19 Mar 2013):

https://github.com/dojo/util/commit/91b3f04fa3d73cd116ad91145662113be3fe0a34

The above commit was only applied to Dojo 1.9 and above, leading to the 60 seconds delay being seen in Dojo 1.9 or later (when using closure compiler in a build run with Node).

Why is this only seen in Node builds? Probably because sendJob waits for spawned java.exe process to complete (60 seconds) but a Java build can ignore the compiler Thread and exit the JVM more forcefully (see build/rhino/process.js and exit() method).

comment:10 Changed 4 years ago by Bill Keese <bill@…>

Resolution: fixed
Status: newclosed

In 7085ef15f71a4dbd7b8662044d7155f185dc60c9/util:

Error: Processor CommitTicketReference failed
Unsupported version control system "git": Can't find an appropriate component, maybe the corresponding plugin was not enabled? 
Note: See TracTickets for help on using tickets.