Development and Pipeline - Group home

How to start IDz client faster?

  

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/OS (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

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.


Common problems and solutions


Slow startup phase Possible solution
Before the splash screen
  • Check your real-time virus scanner configuration and exclude jar files.
    Antivirus exclusion
  • Add Java option -Xshareclasses:cacheDir= to your eclipse.ini to target a persistent and well performing network drive for the JVM class cache. Default is in the user home directory, something like C:\Users\MYUSER\AppData\Local\javasharedresources
Before workspace selection Eclipse OSGI is probably running an 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 VDI 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 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 eclipse.ini is protected and readonly?


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

"C:\Program Files\IBM\IDZ15\eclipse.exe" --launcher.ini I:/idz-start/eclipse.ini


Antivirus exclusion


When IDz is slow to show the splash screen or to run even though it does not seem to consume any CPU then a possible cause is that IDz is waiting on the antivirus to finish scanning jar files or configuration files from the workspace.

Depending on how the anti-virus works, the problem can be random like being slow on startup but only after a reboot of the machine or an operation/menu being slow only the first time,...

The problem can usually be solved by adding exclusion to the antivirus scanner.

The following directories are known for causing performance degradation if they are scanned:

  • IDz installation directories like for example c:\Program Files\IBM and c:\Program Files\IBMShared where most of the jar files are located. Check with Inst/allation Manager for the exact location of your shared and installation directories.
  • user workspace like c:\workspaces\wrk1
  • user home directory for the Eclipse OSGI configuration if the user is not administrator of his machine, like C:\Users\JohnDoe\.eclipse\org.eclipse.platform_4.6.3_1991667125_win32_win32_x86_64\configuration. When the user is administrator, IDz uses the configuration folder under [installation dir]\configuration. But when a user is not administrator or has no write permission on the default configuration directory then Eclipse will create a new configuration under his home directory.You will have to check with your operating system provider where the home directory is located.


To finalize this list, you need to take into consideration:

  • how the anti-virus works: what is scanned and when and how to exclude directories (you may need to contact your anti-virus provider on that)
  • the operating system, regional language settings, hypervisor environment, ... which can for example change the location of the user home directory
  • where IDz has been installed
  • if you accept to not scan these directories (you may need to discuss it with your security team)




How to troubleshoot slow startup


The steps are:

Enable Eclipse debug traces

 

Create a file named .options (in c:\temp for example) 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 JVM traces in eclipse.ini:

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

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" -debug c:\temp\.options -consoleLog > c:\temp\startup.log 2>&1

 
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,…).

I often hear “IDz startup is slow” just because the IDz icon is being clicked on but actually it starts every products installed “shell shared” with IDz like Enterprise Workflow Management, eGit, 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

What you do not want to find are traces like “[reconciler] Performing reconciliation.”

Under normal circumstances, you want to see reconciliation happening during:
  • First time the user launches Eclipse
  • When new plugins have been installed or upgraded

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

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
start = System.currentTimeMillis();
Debug.println("Starting " + bundle);
Debug.println("End starting " + bundle + " " + (System.currentTimeMillis() - start));

Indicate the plugin started in 118962 milliseconds

Entry Starting application: 354211
Explanation Created by org/eclipse/core/runtime/internal/adaptor/EclipseAppLauncher.runApplication()
and indicates the elapse time between start and current in milliseconds.
String timeString = equinoxConfig.getConfiguration("eclipse.startTime");
long time = timeString == null ? 0L : Long.parseLong(timeString);
Debug.println("Starting application: " + (System.currentTimeMillis() - time));

Workspace selection should happen shortly after this entry.


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


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.

Explanation
Created by org.eclipse.equinox.internal.p2.reconciler.dropins.ProfileSynchronizer.isUpToDate()

P2 has started

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.