More and more companies are adopting cloud solutions and virtual desktop infrastructure (VDI) which can lead to startup time issues with Eclipse based applications like IBM Developer for z Systems (IDz).

I will try to list here some common issues and solutions as well as tips to troubleshoot the problem.

The 3 main phases


There are 3 main phases during Eclipse “startup” which usually have quite different reasons for being slow:

  1. Startup of java.exe and before splash screen
  2. Between splash screen and workspace selection
  3. After workspace selection until workbench is usable
1 2 3

By default many IBM Eclipse products use javaw.exe instead of java.exe so you don’t see the first command window. You just see that it takes a long time before the splash screen appears. You will see below how to make it visible by using java.exe instead of javaw.exe.

 

The difficult part now is to identify where your startup is slow.

Common problems and solutions



Slow startup phase Possible solutions
Before the splash screen
  • Check your real-time virus scanner configuration and exclude jar files.
    See Antivirus exclusion for more details on how to resolve this problem.
  • Add Java option -Xshareclasses:cacheDir= to your eclipse.ini to target a persistent and well performing network drive for the JVM class cache. By default this is the user home directory, something like C:\Users\MYUSER\AppData\Local\javasharedresources
Before workspace selection Eclipse OSGI is probably running unexpected reconciliation.

  • Use -configuration option to target a persistent and well performing network drive. By default Eclipse build the OSGI configuration (list of plugins to load) under the user home directory, something like C:\Users\IBM_ADMIN\.eclipse\org.eclipse.platform_4.4.2_2138503820_win32_win32_x86_64. On VDI, the user home might not be persistent and new reconciliation will happen after each logoff/logon
  • Use -Declipse.home.location to indicate the Eclipse installation path. If for example the installation was made under “Program Files” but when packaged for VDI it appears as being under something like

    "C:/Users/johndoe/AppData/Local/.../pkgid1234/.../ProgramFilesX64/IBM/SDP" . Eclipse OSGI will then perceive it as a mismatch and will start a reconciliation.

  • Do not use -clean option (often found on the command line options) which also forces a reconciliation
After workspace selection Use -data option to target a persistent and well performing network drive.

See Eclipse runtime options for more information.

Your eclipse.ini will then looks like:

...
-install 
C:/Program Files/IBM/SDP 
-configuration I:/rdz-start/ 
-vmargs 
-Xquickstart 
... 
-Xshareclasses:name=IBMSDP_%u,cacheDir=I:/javashrcls 
... 
-Declipse.home.location="C:/Users/johndoe/AppData/Local/.../pkgid1234/.../ProgramFilesX64/IBM/SDP" 

What if I cannot modify eclipse.ini?


If you have no permission to modify eclipse.ini, you can still indicate another one on the command line by using parameter –launcher.ini, for example:

"C:\Program Files\IBM\SDP14\eclipse.exe" -product com.ibm.rational.developer.systemz.product.ide --launcher.ini I:/idz-start/eclipse.ini

How to troubleshoot slow startup


The steps are:

Enable Eclipse debug traces

 

Create a file named .options (in c:\temp for example which you will reference when starting Eclipse in debug mode, see below) with the following content:

# Prints out start level service debug information
org.eclipse.osgi/debug/startlevel=true
# Prints out timing information for bundle activation
org.eclipse.osgi/debug/bundleTime=true
# Debug the loading of message bundles
org.eclipse.osgi/debug/messageBundles=true
# monitor bundle activation
org.eclipse.osgi/monitor/activation=true
org.eclipse.equinox.p2.core/debug=true
org.eclipse.equinox.p2.core/reconciler=true
org.eclipse.equinox.p2.core/publisher=true

Enable Java traces:

Unfortunately, the OSGI trace entries do not have a timestamp… so it can be useful to add the -Xtrace option in bold below to your eclipse.ini and use java.exe instead of javaw.exe

 

-vm
jdk/jre/bin/java.exe
-startup
plugins/org.eclipse.equinox.launcher_1.3.0.v20140415-2008.jar
–launcher.library
plugins/org.eclipse.equinox.launcher.win32.win32.x86_64_1.1.200.v20150204-1316
-install
C:/Program Files/IBM/SDP14
-vmargs
-Xquickstart
-Xms100m
-Xmx1024m
-Xmnx64m
-Xgcpolicy:gencon
-Xscmx96m
-Xshareclasses:name=IBMSDP14_%u
-XX:MaxPermSize=512M
-Xnolinenumbers
-Xcompressedrefs
-Xtrace:none,maximal=mt,output=c:\temp\jvmtrc.log,trigger={method{org/eclipse/core/runtime/internal/adaptor/EclipseAppLauncher.runApplication,jstacktrace},method{org/eclipse/equinox/internal/p2/reconciler/dropins/Activator.start,jstacktrace},method{org/eclipse/equinox/launcher/Main.main,jstacktrace},method{org/eclipse/ui/internal/ide/application/IDEApplication.promptForWorkspace,jstacktrace}},stackdepth=1

 

Traces are created in output=c:\temp\jvmtrc.log

Start Eclipse in debug mode

From a command prompt, you will need to start eclipseC.exe instead of eclipse.exe with option -debug and -consoleLog

For example:


"C:\Program Files\IBM\SDP14\eclipsec.exe" -product com.ibm.rational.developer.systemz.product.ide -debug c:\temp\.options -consoleLog > c:\temp\startup.log 2>&1

 

The -product parameter depends on the product you use: IDz, RTC, DataStudio,…
The correct value can be found on the properties of the startup icon.

 

You can copy paste the complete target field and then change

  • eclipse.exe into eclipsec.exe
  • then add -debug <your .options file>
  • add -consoleLog
  • and a redirection of the output “> c:\temp\startup.log 2>&1”

Know what products/plugins are installed and being started

When you start an Eclipse “product” like IDz, it does not mean that you start “only” IDz.
You start everything that is installed on this same workbench/shell but under the branding of product IDz (meaning splash screen, default perspective,…).

Double clicking on IDz icon will actually start every products installed “shell shared” with IDz like Rational Team Concert, Data Studio, CICS Explorer, and any other third party products, debugger,…

To know what you have really started, go to menu Help > about > Installation Details and click on tab Configuration.
You will then see most of the paths being used (OSGI, user home,…) and all the plugins/features loaded:

  • org.eclipse.* will be Eclipse plugins
  • com.ibm.* will be IBM plugins
  • other packages will be third party plugins

Examples of IBM products/plugins:

com.ibm.datastudio.consolidated.licensing (1.0.400.v20150716_0751) "IBM Data Studio" [Starting] com.ibm.pdtools.common.component.core (14.0.17.v20170515-1506) "Problem Determination Tools for z/OS" [Active] com.ibm.rational.developer.systemz.product (14.0.1015.v20170624_0301) "IBM Developer for z Systems" [Active] com.ibm.team.concert (3.1.1200.v20151110_0208) "Rational Team Concert" [Active]

 

Analyze the logs


OSGI traces

Below are some key entries to look for in the OSGI trace file (c:\temp\startup.log in this example):

  • Before workspace selection

 

Entry
Starting org.eclipse.equinox.simpleconfigurator_1.1.0.v20131217-1203 [3]
End starting org.eclipse.equinox.simpleconfigurator_1.1.0.v20131217-1203 [3] 118962
			
Explanation
Created by org.eclipse.osgi.internal.framework.BundleContextImpl

The log data “End starting org.eclipse….-1203 [3]” indicates that the plugin started in 118962 milliseconds

 

Entry
[p2] Tue May 30 03:14:19 PDT 2017 - [Start Level: Equinox Container: 80b1686c-2045-0017-177b-d1f592d8e972] [reconciler] Cached timestamp file empty.
[p2] Tue May 30 03:14:19 PDT 2017 - [Start Level: Equinox Container: 80b1686c-2045-0017-177b-d1f592d8e972] [reconciler] Performing reconciliation.
End starting org.eclipse.equinox.p2.reconciler.dropins_1.1.200.v20131119-0908 [2887] 631703
Explanation
Created by org.eclipse.equinox.internal.p2.reconciler.dropins.ProfileSynchronizer.isUpToDate()

P2 reconciliation has started and took 631703 milliseconds

 

Usually P2 reconciliation will take a lot of time so what you do not want to find are traces like “[reconciler] Performing reconciliation.”.
Instead you will prefer to see traces like “[reconciler] Reconciliation skipped.”

Under normal circumstances, you want to see reconciliation happening during:

  • First time the user launches Eclipse
  • When new plugins have been installed or upgraded

 

Entry
StartLevel: changing bundle
StartLevel: resuming bundle;
Explanation
Created by org.eclipse.osgi.container.ModuleContainer

“changing bundle” happens during -clean or when starting Eclipse the first time and OSGI config is being built/rebuilt

 

  • After workspace selection

 

Entry
Starting application: 354211
Application Started: 869955
Explanation
Created by org/eclipse/core/runtime/internal/adaptor/EclipseAppLauncher.runApplication() 

It shows the elapse time between start and current in milliseconds.
Workspace selection happens shortly after “Starting application”.
Workbench UI is available shortly after “Application Started”.
In this example, startup already took 354211 milliseconds before workspace selection and UI was available after 869955 milliseconds.

 

JVM Traces

The JVM trace file can be formatted using command:

"C:\Program Files\IBM\SDP14\jdk\jre\bin\java.exe" com.ibm.jvm.TraceFormat C:\temp\jvmtrc.log C:\temp\jvmtrc.formatted.log

and the output looks like:

Trace file header:
        JVM start time: 13:36:14.200000000


               Trace Formatted Data

Time (UTC)          Thread ID          Tracepoint ID       Type        Tracepoint Data
13:36:14.758548889 *0x0000000002330500 mt.3                Entry      >org/eclipse/equinox/launcher/Main.main([Ljava/lang/String;)V bytecode static method
13:36:14.758554407  0x0000000002330500 j9trc_aux.0         Event       jstacktrace:
13:36:14.758566210  0x0000000002330500 j9trc_aux.1         Event       [1] org.eclipse.equinox.launcher.Main.main (Bytecode PC: 0)
13:36:21.533760790 *0x000000000263a600 mt.0                Entry      >org/eclipse/equinox/internal/p2/reconciler/dropins/Activator.start(Lorg/osgi/framework/BundleContext;)V bytecode method, this = 0xfccead60
13:36:21.533770149  0x000000000263a600 j9trc_aux.0         Event       jstacktrace:
13:36:21.533782162  0x000000000263a600 j9trc_aux.1         Event       [1] org.eclipse.equinox.internal.p2.reconciler.dropins.Activator.start (Bytecode PC: 0)
13:36:21.549168878  0x000000000263a600 mt.6                Exit       <org/eclipse/equinox/internal/p2/reconciler/dropins/Activator.start(Lorg/osgi/framework/BundleContext;)V bytecode method
13:36:21.651251152 *0x0000000002330500 mt.0                Entry      >org/eclipse/core/runtime/internal/adaptor/EclipseAppLauncher.runApplication(Ljava/lang/Object;)Ljava/lang/Object; bytecode method, this = 0xfcf20ba8
13:36:21.651262676  0x0000000002330500 j9trc_aux.0         Event       jstacktrace:
13:36:21.651271476  0x0000000002330500 j9trc_aux.1         Event       [1] org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication (Bytecode PC: 0)
13:36:22.141296968  0x0000000002330500 mt.0                Entry      >org/eclipse/ui/internal/ide/application/IDEApplication.promptForWorkspace(Lorg/eclipse/swt/widgets/Shell;Lorg/eclipse/ui/internal/ide/ChooseWorkspaceData;Z)Ljava/net/URL; bytecode method, this = 0xfd4a4d68
13:36:22.141318759  0x0000000002330500 j9trc_aux.0         Event       jstacktrace:
13:36:22.141328048  0x0000000002330500 j9trc_aux.1         Event       [1] org.eclipse.ui.internal.ide.application.IDEApplication.promptForWorkspace (Bytecode PC: 0)
13:36:24.108059854  0x0000000002330500 mt.6                Exit       <org/eclipse/ui/internal/ide/application/IDEApplication.promptForWorkspace(Lorg/eclipse/swt/widgets/Shell;Lorg/eclipse/ui/internal/ide/ChooseWorkspaceData;Z)Ljava/net/URL; bytecode method
13:36:24.723034921  0x0000000002330500 mt.6                Exit       <org/eclipse/core/runtime/internal/adaptor/EclipseAppLauncher.runApplication(Ljava/lang/Object;)Ljava/lang/Object; bytecode method
13:36:26.088397751 *0x000000000263a600 dg.262              Debug       ***** Thread termination - trace purged *****

 

Entries to look for are the reconcilier startup and workspace prompt.

Join The Discussion

Your email address will not be published. Required fields are marked *