Bug 560412 - EGit core activator doing too much
Summary: EGit core activator doing too much
Status: RESOLVED FIXED
Alias: None
Product: EGit
Classification: Technology
Component: Core (show other bugs)
Version: 5.7   Edit
Hardware: All All
: P3 normal (vote)
Target Milestone: 5.12   Edit
Assignee: Project Inbox CLA
QA Contact:
URL:
Whiteboard:
Keywords: performance
Depends on: 560527 560528
Blocks: 571430
  Show dependency tree
 
Reported: 2020-02-22 06:17 EST by Alex Blewitt CLA
Modified: 2021-03-13 12:17 EST (History)
8 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Alex Blewitt CLA 2020-02-22 06:17:58 EST
The EGit activator take about 1/2s on my (aging) laptop at start-up, which is directly on the startup path of Eclipse. If we can defer some of this to a background thread/job, then we would be able to shave some time off of startup.

https://github.com/eclipse/egit/blob/b99de6856fa9dc100d16d884b90249ffa7ea99ec/org.eclipse.egit.core/src/org/eclipse/egit/core/Activator.java#L222-L276
Comment 1 Alex Blewitt CLA 2020-02-22 06:20:40 EST
See https://alblue.bandlem.com/2020/02/bundles.svg and the write-up at https://alblue.bandlem.com/2020/02/jfr-bundle-listener.html for more information
Comment 2 Michael Keppler CLA 2020-02-23 09:05:33 EST
We investigated much of that in bug 540545 and did not find any way to improve it reasonably.
Comment 3 Alex Blewitt CLA 2020-02-23 15:50:54 EST
We found one fix in JGit already with bug 560414 and I'm fairly certain that other improvements could be made. The startup shows that the SSH part, while a bit of it, isn't the only delay (but the JGit class loading does take a non-trivial amount of time).

The longest pauses in the activator so far are:

* FS.setAsyncFileStoreAttributes(true); <- causes JGit classes to load, rather than being an expensive call
* setupHttp();
* SshPreferencesMirror.INSTANCE.start()
* setupSSH(context);
* repositoryCache = new RepositoryCache()
* indexDiffCache = new IndexDiffCache();
* registerAutoShareProjects()

Being able to move some of the creation of those to a background job would be beneficial.
Comment 4 Thomas Wolf CLA 2020-02-23 16:19:44 EST
(In reply to Alex Blewitt from comment #3)
> * FS.setAsyncFileStoreAttributes(true); <- causes JGit classes to load,
> rather than being an expensive call

Well, you can't expect anything in EGit to work if JGit isn't loaded.

> * setupHttp();

Would have to look; probably loads httpcomponents or core.net. 

> * SshPreferencesMirror.INSTANCE.start()

It's a preference access.

> * setupSSH(context);

We already looked at that in bug 540545, and moving this to a background job didn't really help but will complicate a lot of things.

> * repositoryCache = new RepositoryCache()
> * indexDiffCache = new IndexDiffCache();

Could perhaps be done on demand in the getters, at the cost of additional synchronization.

> * registerAutoShareProjects()

That should be super-cheap.

Note that if setupHttp() or setupSSH() are done asynchronously, one must ensure that all operations using http or ssh are delayed until this setup is done. Since these setups do set global factories, this might rather difficult to achieve.
Comment 5 Lars Vogel CLA 2020-02-24 04:06:13 EST
Using build in tracing of platform, I see that Egit is leading by far the list of the top ten of the longest running activators (using an SDK plus Egit).

Activator times
495 org.eclipse.egit.ui_5.7.0.202002232031
395 org.eclipse.egit.core_5.7.0.202002232031
348 org.eclipse.jdt.ui_3.21.0.v20200218-1551
202 org.eclipse.jdt.core_3.21.0.v20200223-1120
140 org.eclipse.ui.trace_1.1.800.v20200106-1301
138 org.eclipse.core.runtime_3.17.100.v20200203-0917
130 org.eclipse.core.resources_3.13.700.v20200209-1624
82 org.eclipse.core.contenttype_3.7.600.v20200124-1609
79 org.eclipse.ui.workbench_3.118.0.v20200222-0719
78 org.eclipse.equinox.registry_3.8.700.v20200121-1457
Comment 7 Andrey Loskutov CLA 2020-02-24 04:10:21 EST
(In reply to Lars Vogel from comment #5)
> Using build in tracing of platform, I see that Egit is leading by far the
> list of the top ten of the longest running activators (using an SDK plus
> Egit).
> 
> Activator times
> 495 org.eclipse.egit.ui_5.7.0.202002232031
> 395 org.eclipse.egit.core_5.7.0.202002232031
> 348 org.eclipse.jdt.ui_3.21.0.v20200218-1551
> 202 org.eclipse.jdt.core_3.21.0.v20200223-1120
> 140 org.eclipse.ui.trace_1.1.800.v20200106-1301
> 138 org.eclipse.core.runtime_3.17.100.v20200203-0917
> 130 org.eclipse.core.resources_3.13.700.v20200209-1624
> 82 org.eclipse.core.contenttype_3.7.600.v20200124-1609
> 79 org.eclipse.ui.workbench_3.118.0.v20200222-0719
> 78 org.eclipse.equinox.registry_3.8.700.v20200121-1457

As mentioned already, these times above are cumulative, means 495 ms for egit.ui contain already 395 ms for egit core that again contain runtime, contenttype etc.

So please either improve the calculation of such numbers or add a disclaimer that the numbers are cumulative and do not represent bundle own startup time.
Comment 8 Lars Vogel CLA 2020-02-24 04:37:59 EST
(In reply to Andrey Loskutov from comment #7)

> So please either improve the calculation of such numbers or add a disclaimer
> that the numbers are cumulative and do not represent bundle own startup time.

If A requires B to load, than this is currently included in the required startup time of A. IMHO that is correct, i.e.. if you trace the runtime of method you also include the runtime of called methods. 

If you see a way to improve that feel free to suggest to change to Equinox logging.
Comment 9 Matthias Sohn CLA 2020-02-24 04:54:08 EST
(In reply to Andrey Loskutov from comment #7)
> (In reply to Lars Vogel from comment #5)
> > Using build in tracing of platform, I see that Egit is leading by far the
> > list of the top ten of the longest running activators (using an SDK plus
> > Egit).
> > 
> > Activator times
> > 495 org.eclipse.egit.ui_5.7.0.202002232031
> > 395 org.eclipse.egit.core_5.7.0.202002232031
> > 348 org.eclipse.jdt.ui_3.21.0.v20200218-1551
> > 202 org.eclipse.jdt.core_3.21.0.v20200223-1120
> > 140 org.eclipse.ui.trace_1.1.800.v20200106-1301
> > 138 org.eclipse.core.runtime_3.17.100.v20200203-0917
> > 130 org.eclipse.core.resources_3.13.700.v20200209-1624
> > 82 org.eclipse.core.contenttype_3.7.600.v20200124-1609
> > 79 org.eclipse.ui.workbench_3.118.0.v20200222-0719
> > 78 org.eclipse.equinox.registry_3.8.700.v20200121-1457
> 
> As mentioned already, these times above are cumulative, means 495 ms for
> egit.ui contain already 395 ms for egit core that again contain runtime,
> contenttype etc.
> 
> So please either improve the calculation of such numbers or add a disclaimer
> that the numbers are cumulative and do not represent bundle own startup time.

ok, this gives the following times added by the respective Activators:

Activator own times
100 org.eclipse.egit.ui_5.7.0.202002232031
 47 org.eclipse.egit.core_5.7.0.202002232031
146 org.eclipse.jdt.ui_3.21.0.v20200218-1551
 62 org.eclipse.jdt.core_3.21.0.v20200223-1120
  2 org.eclipse.ui.trace_1.1.800.v20200106-1301
  8 org.eclipse.core.runtime_3.17.100.v20200203-0917
 48 org.eclipse.core.resources_3.13.700.v20200209-1624
  3 org.eclipse.core.contenttype_3.7.600.v20200124-1609
  1 org.eclipse.ui.workbench_3.118.0.v20200222-0719
 78 org.eclipse.equinox.registry_3.8.700.v20200121-1457

and this means in this installation jdt.ui is currently in the leader box, followed by egit.ui and equinox registry
Comment 10 Lars Vogel CLA 2020-02-24 05:59:02 EST
Matthias, how did you calculate these times? The reported activator time for A only includes other activator times if that activation is triggered by A.
Comment 11 Matthias Sohn CLA 2020-02-24 06:44:55 EST
(In reply to Lars Vogel from comment #10)
> Matthias, how did you calculate these times? The reported activator time for
> A only includes other activator times if that activation is triggered by A.

then I don't understand the numbers this trace is emitting
Comment 12 Lars Vogel CLA 2020-02-24 07:05:50 EST
(In reply to Matthias Sohn from comment #11)
> (In reply to Lars Vogel from comment #10)
> > Matthias, how did you calculate these times? The reported activator time for
> > A only includes other activator times if that activation is triggered by A.
> 
> then I don't understand the numbers this trace is emitting

Lets say bundle A does not depend on anything but calls some internal code-> activation time == time to load the required classes, call methods, etc.

If bundle A requires bundle B and that is not already activated -> activation time of A == time to load the required classes, activate bundle B, call methods, etc.

If bundle A requires bundle B and B  is already activated -> activation time of A == time to load the required classes, call methods, etc-> activation time of B is not added to it, as B is already activated

So a fast starting bundle triggers as little as possible other bundles code in its activator to avoid activating other bundles and therefore delaying the startup.
Comment 13 Matthias Sohn CLA 2020-02-24 08:23:44 EST
(In reply to Lars Vogel from comment #12)
> (In reply to Matthias Sohn from comment #11)
> > (In reply to Lars Vogel from comment #10)
> > > Matthias, how did you calculate these times? The reported activator time for
> > > A only includes other activator times if that activation is triggered by A.
> > 
> > then I don't understand the numbers this trace is emitting
> 
> Lets say bundle A does not depend on anything but calls some internal code->
> activation time == time to load the required classes, call methods, etc.
> 
> If bundle A requires bundle B and that is not already activated ->
> activation time of A == time to load the required classes, activate bundle
> B, call methods, etc.
> 
> If bundle A requires bundle B and B  is already activated -> activation time
> of A == time to load the required classes, call methods, etc-> activation
> time of B is not added to it, as B is already activated
> 
> So a fast starting bundle triggers as little as possible other bundles code
> in its activator to avoid activating other bundles and therefore delaying
> the startup.

This means if 20 other bundles also depend on bundle B being activated one of them gets all the blame of slowing down the startup and the others can happily enjoy piggy backing on the startup of B without getting blamed. This doesn't seem fair and makes comparing these numbers almost impossible.
Comment 14 Lars Vogel CLA 2020-02-24 08:33:41 EST
I think it is similar to calling a method which calls slow code. IMHO this must be part of the trace time of the method.
Comment 15 Lars Vogel CLA 2020-02-24 09:26:43 EST
(In reply to Matthias Sohn from comment #13)

> This means if 20 other bundles also depend on bundle B being activated one
> of them gets all the blame of slowing down the startup and the others can
> happily enjoy piggy backing on the startup of B without getting blamed. This
> doesn't seem fair and makes comparing these numbers almost impossible.

Important note here is that is it OK to dependent on a plug-in. This will not trigger activation. Only if you call its code from your activator you trigger the other activation code.

IMHO activators should be avoided and OSGi services (which are started lazy) should be preferred.
Comment 16 Alex Blewitt CLA 2020-02-24 14:03:38 EST
As per https://alblue.bandlem.com/2020/02/bundles.svg I highlighted that some of the cost of the EGit UI bundle is caused due to the EGit Core bundle, which in turn is caused by the Core Net bundle startup. So the total delay of the EGit UI bundle is not entirely down to the EGit UI bundle itself, but rather a combination of the other parts as well.

Note that the JGit bundle doesn't have an activator, but the EGit bundle causes the JGit classes to load, which is also part of the delay (and hence the fixed one). But the fact is that during start up (when the splash screen is loading) that EGit takes about 25% of the time of the main thread (with Mylyn taking 25% and JDT taking 25%). So there's opportunity to improve this here if we can.

Note that delays caused by loading classes in dependent bundles are part of the total cost, and there are fixes elsewhere we can do (e.g. the networking lookup in JGit).
Comment 17 Michael Keppler CLA 2020-02-24 14:43:57 EST
Honestly I trust my profiler more than those tracing numbers. And at least on my machine the order is mylyn, pde, jdt, egit, when looking at the CPU time needed by their activators including all transitive method calls. So please be a bit more careful making claims like "egit activator takes most time". That can vary wildly between different setup.

Also there are some costs, which are currently labeled to be caused by egit, but would still be caused _even without egit_. Example: I see timezone data related stuff in some date time formatter class initialization, which is _currently_ triggered by jgit. If jgit would avoid using that formatter class, chances are very high that many arbitrary other classes in the IDE cause that static initializer to run, and are then blamed for no good reason.

I see one more potential place for optimization, that was not mentioned before (as far as I can tell): GitProjectData.reconfigureWindowCache() consumes 1/3 of the egit.core activator runtime for me, where a lot of time seems to go into parsing the configs (which is generally slow on Windows). Can this reconfiguration be executed later? Especially if we assume that the values to be used (from the workspace preferences) are almost always the same and there is in fact no need for a reconfiguration all the time?
Comment 18 Alex Blewitt CLA 2020-02-24 16:14:11 EST
I'm sorry, I don't think anyone mentioned the word "most" other than in your comment. Do you have a reference to what you are referring to?

This is not about the specific ordering of 'which one is the most'; the point is that these are opportunities to make Eclipse launch faster, and it's going to be through a combination of improvements through a number of different places that in all probably do not need to be complete before the splash screen is dismissed.
Comment 19 Lars Vogel CLA 2020-02-24 16:22:43 EST
(In reply to Alex Blewitt from comment #18)
> I'm sorry, I don't think anyone mentioned the word "most" other than in your
> comment. Do you have a reference to what you are referring to?

I think it was my comment, as EGit is reported by the Equinox logging as longest. https://bugs.eclipse.org/bugs/show_bug.cgi?id=560412#c5 

> This is not about the specific ordering of 'which one is the most'; the
> point is that these are opportunities to make Eclipse launch faster, and
> it's going to be through a combination of improvements through a number of
> different places that in all probably do not need to be complete before the
> splash screen is dismissed.

+1

Thanks Mickael for using the profiler. 1/3 reduction sounds great.

Btw: I have not Mylyn installed as it slows down significant the startup so that is why it is not in my list. SonarLint used to be also on the top but they moved most of their activator code to a Job, see https://bugs.eclipse.org/bugs/show_bug.cgi?id=553535#c13.
Comment 20 Thomas Wolf CLA 2020-02-24 16:35:23 EST
(In reply to Michael Keppler from comment #17)
> GitProjectData.reconfigureWindowCache()

That could be safely done in the background I think.
Comment 21 Alex Blewitt CLA 2020-02-24 16:54:08 EST
So, the FS.setAsyncBackground call (on my system) triggers both a load of the remaining FS inner classes, and then the load of SLF4J. This is because the loading of the inner class FS.FileStoreAttributes seems to also load the FS.TemporaryBuffer, and then a nested set of classes from there. Together, this adds up to 200ms on my machine.

With this simple change in FS.FileStoreAttributes:

-               private static void setBackground(boolean async) {
+               public static void setBackground(boolean async) {
                        background.set(async);
                }

and this in the EGit activator:

-				FS.setAsyncFileStoreAttributes(true);
+				FS.FileStoreAttributes.setBackground(true);

the time goes down to 6ms.

Of course, there may be loads of other JGit classes down the line, but those can be inspected independently. Whether the above change is desirable from a coding perspective is open to the developers, but it would seem that this change would permit a way of evolving forwards compatibly while optimising this specific use case.

Alternatives investigated involve moving the FileStoreAttributes out of the inner class to an external one but that is more invasive and doesn't improve it significantly other than the above.

Since this is a combined change in both JGit and EGit, should I raise a new bug in JGit to make the accessor public, and then follow up with another EGit bug for this specific change? Happy to provide the gerrit patch if desired.
Comment 22 Thomas Wolf CLA 2020-02-25 02:09:25 EST
(In reply to Alex Blewitt from comment #21)
On OS X 10.14.6, Java 8, I don't see any significant difference neither for this FS call itself nor on the total time for startup.

Also, it may look good in isolation on your machine, but what's the net effect on the total time for Activator.start()? 

Another thing to consider with such micro-optimizations is that if a long time is observed due to loading other bundles in one step, then often optimizing that bit just delays the loading of said bundles to a later step inside Activator.start() and the overall time remains more or less the same.

Also note: timing on Windows may be very different from timing on OS X or Linux due to different filesystem characteristics. Michael already mentioned it: file access on Windows can be very expensive compared to other systems. Especially accessing file attributes (last modified time and such).
Comment 23 Alex Blewitt CLA 2020-02-25 15:03:05 EST
Thomas, how did you measure the difference?

This is the test I ran on my machine:

--- 8< ---
public class Testy {
		public static void main(String args[]) throws Exception {
				fs();
		}
		public static void fs() throws Exception {
				long start = System.currentTimeMillis();
				FS.FileStoreAttributes.setBackground(true);
				long end = System.currentTimeMillis();
				System.out.println("Time FS: " + (end - start) + "ms");
		}
}
--- 8< ---

This reports ~240ms on my machine without the change (but with the change Matthias merged to remove the DNS lookup), and ~15ms with the change. It is provably faster and this clearly comes from avoiding the classloading costs with SLF4J, caused by bringing in the TemporaryBuffer class. You can verify this yourself by running with -Xlog:class+info on Java 11, for example:

---8<--- Without the change
[0.111s][info][class,load] java.lang.Package source: jrt:/java.base
[0.111s][info][class,load] java.lang.Package$VersionInfo source: jrt:/java.base
[0.112s][info][class,load] org.eclipse.jgit.util.FS source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.112s][info][class,load] org.eclipse.jgit.util.TemporaryBuffer source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.113s][info][class,load] org.eclipse.jgit.util.TemporaryBuffer$LocalFile source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.113s][info][class,load] org.eclipse.jgit.util.TemporaryBuffer$Heap source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.114s][info][class,load] java.lang.AssertionError source: jrt:/java.base
[0.114s][info][class,load] java.io.IOException source: jrt:/java.base
[0.114s][info][class,load] java.lang.UnsupportedOperationException source: jrt:/java.base
[0.114s][info][class,load] java.lang.SecurityException source: jrt:/java.base
[0.114s][info][class,load] java.lang.InternalError source: jrt:/java.base
[0.114s][info][class,load] java.lang.InterruptedException source: jrt:/java.base
[0.114s][info][class,load] java.security.AccessControlException source: jrt:/java.base
[0.115s][info][class,load] org.eclipse.jgit.errors.CommandFailedException source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.115s][info][class,load] java.io.Reader source: jrt:/java.base
[0.115s][info][class,load] java.io.InputStreamReader source: jrt:/java.base
[0.116s][info][class,load] org.eclipse.jgit.api.errors.JGitInternalException source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.116s][info][class,load] java.nio.file.InvalidPathException source: jrt:/java.base
[0.117s][info][class,load] org.eclipse.jgit.lib.Config source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.117s][info][class,load] org.eclipse.jgit.lib.StoredConfig source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.118s][info][class,load] jdk.internal.loader.URLClassPath$JarLoader source: jrt:/java.base
[0.118s][info][class,load] java.util.zip.ZipConstants source: jrt:/java.base
[0.118s][info][class,load] java.util.zip.ZipFile source: jrt:/java.base
[0.118s][info][class,load] jdk.internal.misc.JavaUtilZipFileAccess source: jrt:/java.base
[0.118s][info][class,load] java.util.zip.ZipFile$1 source: jrt:/java.base
[0.119s][info][class,load] sun.net.www.protocol.jar.Handler source: jrt:/java.base
[0.119s][info][class,load] jdk.internal.loader.URLClassPath$JarLoader$1 source: jrt:/java.base
[0.119s][info][class,load] jdk.internal.loader.FileURLMapper source: jrt:/java.base
[0.120s][info][class,load] java.util.jar.JarFile source: jrt:/java.base
[0.120s][info][class,load] jdk.internal.misc.JavaUtilJarAccess source: jrt:/java.base
[0.120s][info][class,load] java.util.jar.JavaUtilJarAccessImpl source: jrt:/java.base
[0.120s][info][class,load] java.lang.Runtime$Version source: jrt:/java.base
[0.120s][info][class,load] java.nio.charset.StandardCharsets source: jrt:/java.base
[0.120s][info][class,load] sun.nio.cs.UTF_16BE source: jrt:/java.base
[0.121s][info][class,load] sun.nio.cs.UTF_16LE source: jrt:/java.base
[0.121s][info][class,load] sun.nio.cs.UTF_16 source: jrt:/java.base
[0.121s][info][class,load] java.util.zip.ZipCoder source: jrt:/java.base
[0.121s][info][class,load] java.util.zip.ZipCoder$UTF8 source: jrt:/java.base
[0.121s][info][class,load] java.util.zip.ZipFile$CleanableResource source: jrt:/java.base
[0.121s][info][class,load] java.util.zip.ZipFile$Source source: jrt:/java.base
[0.122s][info][class,load] java.util.zip.ZipFile$Source$Key source: jrt:/java.base
[0.122s][info][class,load] java.nio.file.FileSystems source: jrt:/java.base
[0.122s][info][class,load] java.nio.file.FileSystems$DefaultFileSystemHolder source: jrt:/java.base
[0.122s][info][class,load] java.nio.file.FileSystems$DefaultFileSystemHolder$1 source: jrt:/java.base
[0.122s][info][class,load] sun.nio.fs.DefaultFileSystemProvider source: jrt:/java.base
[0.123s][info][class,load] java.nio.file.spi.FileSystemProvider source: jrt:/java.base
[0.123s][info][class,load] sun.nio.fs.AbstractFileSystemProvider source: jrt:/java.base
[0.123s][info][class,load] sun.nio.fs.UnixFileSystemProvider source: jrt:/java.base
[0.123s][info][class,load] sun.nio.fs.BsdFileSystemProvider source: jrt:/java.base
[0.123s][info][class,load] sun.nio.fs.MacOSXFileSystemProvider source: jrt:/java.base
[0.123s][info][class,load] java.nio.file.OpenOption source: jrt:/java.base
[0.123s][info][class,load] java.nio.file.StandardOpenOption source: jrt:/java.base
[0.123s][info][class,load] java.nio.file.FileSystem source: jrt:/java.base
[0.123s][info][class,load] sun.nio.fs.UnixFileSystem source: jrt:/java.base
[0.123s][info][class,load] sun.nio.fs.BsdFileSystem source: jrt:/java.base
[0.123s][info][class,load] sun.nio.fs.MacOSXFileSystem source: jrt:/java.base
[0.124s][info][class,load] java.nio.file.Watchable source: jrt:/java.base
[0.124s][info][class,load] java.nio.file.Path source: jrt:/java.base
[0.124s][info][class,load] sun.nio.fs.UnixPath source: jrt:/java.base
[0.124s][info][class,load] sun.nio.fs.Util source: jrt:/java.base
[0.124s][info][class,load] sun.nio.fs.UnixNativeDispatcher source: jrt:/java.base
[0.125s][info][class,load] sun.nio.fs.UnixNativeDispatcher$1 source: jrt:/java.base
[0.125s][info][class,load] java.lang.ClassLoader$2 source: jrt:/java.base
[0.125s][info][class,load] java.lang.ClassLoader$NativeLibrary source: jrt:/java.base
[0.125s][info][class,load] java.util.ArrayDeque$DeqIterator source: jrt:/java.base
[0.127s][info][class,load] java.util.concurrent.ConcurrentHashMap$ValuesView source: jrt:/java.base
[0.127s][info][class,load] java.util.Enumeration source: jrt:/java.base
[0.127s][info][class,load] java.util.concurrent.ConcurrentHashMap$ValueIterator source: jrt:/java.base
[0.127s][info][class,load] java.nio.file.attribute.BasicFileAttributes source: jrt:/java.base
[0.127s][info][class,load] java.nio.file.attribute.PosixFileAttributes source: jrt:/java.base
[0.127s][info][class,load] sun.nio.fs.UnixFileAttributes source: jrt:/java.base
[0.127s][info][class,load] sun.nio.fs.UnixFileStoreAttributes source: jrt:/java.base
[0.127s][info][class,load] sun.nio.fs.UnixMountEntry source: jrt:/java.base
[0.128s][info][class,load] java.net.URI$Parser source: jrt:/java.base
[0.128s][info][class,load] java.nio.file.CopyOption source: jrt:/java.base
[0.128s][info][class,load] java.nio.file.LinkOption source: jrt:/java.base
[0.129s][info][class,load] java.nio.file.Files source: jrt:/java.base
[0.129s][info][class,load] java.nio.file.attribute.AttributeView source: jrt:/java.base
[0.129s][info][class,load] java.nio.file.attribute.FileAttributeView source: jrt:/java.base
[0.129s][info][class,load] java.nio.file.attribute.BasicFileAttributeView source: jrt:/java.base
[0.129s][info][class,load] sun.nio.fs.UnixFileAttributeViews source: jrt:/java.base
[0.129s][info][class,load] sun.nio.fs.DynamicFileAttributeView source: jrt:/java.base
[0.129s][info][class,load] sun.nio.fs.AbstractBasicFileAttributeView source: jrt:/java.base
[0.129s][info][class,load] sun.nio.fs.UnixFileAttributeViews$Basic source: jrt:/java.base
[0.129s][info][class,load] sun.nio.fs.NativeBuffers source: jrt:/java.base
[0.129s][info][class,load] sun.nio.fs.NativeBuffers$1 source: jrt:/java.base
[0.130s][info][class,load] jdk.internal.misc.TerminatingThreadLocal$1 source: jrt:/java.base
[0.130s][info][class,load] java.util.IdentityHashMap source: jrt:/java.base
[0.130s][info][class,load] java.util.IdentityHashMap$KeySet source: jrt:/java.base
[0.130s][info][class,load] sun.nio.fs.NativeBuffer source: jrt:/java.base
[0.130s][info][class,load] sun.nio.fs.NativeBuffer$Deallocator source: jrt:/java.base
[0.131s][info][class,load] sun.nio.fs.UnixFileAttributes$UnixAsBasicFileAttributes source: jrt:/java.base
[0.131s][info][class,load] java.util.concurrent.TimeUnit source: jrt:/java.base
[0.131s][info][class,load] java.nio.file.attribute.FileTime source: jrt:/java.base
[0.131s][info][class,load] java.io.DataOutput source: jrt:/java.base
[0.131s][info][class,load] java.io.DataInput source: jrt:/java.base
[0.131s][info][class,load] java.io.RandomAccessFile source: jrt:/java.base
[0.131s][info][class,load] jdk.internal.misc.JavaIORandomAccessFileAccess source: jrt:/java.base
[0.131s][info][class,load] java.io.RandomAccessFile$2 source: jrt:/java.base
[0.132s][info][class,load] java.util.concurrent.atomic.AtomicBoolean source: jrt:/java.base
[0.132s][info][class,load] java.lang.invoke.MethodHandles source: jrt:/java.base
[0.132s][info][class,load] java.lang.invoke.MemberName$Factory source: jrt:/java.base
[0.132s][info][class,load] java.lang.reflect.ReflectPermission source: jrt:/java.base
[0.133s][info][class,load] java.lang.invoke.MethodHandles$Lookup source: jrt:/java.base
[0.133s][info][class,load] sun.invoke.util.VerifyAccess source: jrt:/java.base
[0.133s][info][class,load] java.lang.NoSuchFieldException source: jrt:/java.base
[0.133s][info][class,load] java.lang.invoke.VarHandles source: jrt:/java.base
[0.134s][info][class,load] java.lang.invoke.VarHandleInts$FieldInstanceReadOnly source: jrt:/java.base
[0.134s][info][class,load] java.lang.invoke.VarHandleInts$FieldInstanceReadWrite source: jrt:/java.base
[0.134s][info][class,load] java.lang.invoke.VarHandle$1 source: jrt:/java.base
[0.134s][info][class,load] java.util.function.BiFunction source: jrt:/java.base
[0.134s][info][class,load] jdk.internal.util.Preconditions$1 source: jrt:/java.base
[0.134s][info][class,load] java.lang.invoke.VarHandleGuards source: jrt:/java.base
[0.135s][info][class,load] java.lang.invoke.VarForm source: jrt:/java.base
[0.135s][info][class,load] java.lang.invoke.VarHandle$AccessType source: jrt:/java.base
[0.135s][info][class,load] java.lang.invoke.VarHandle$AccessMode source: jrt:/java.base
[0.136s][info][class,load] java.lang.invoke.MethodType$ConcurrentWeakInternSet source: jrt:/java.base
[0.136s][info][class,load] java.lang.invoke.MethodType$ConcurrentWeakInternSet$WeakEntry source: jrt:/java.base
[0.136s][info][class,load] java.lang.invoke.MethodTypeForm source: jrt:/java.base
[0.136s][info][class,load] sun.invoke.util.Wrapper source: jrt:/java.base
[0.136s][info][class,load] sun.invoke.util.Wrapper$Format source: jrt:/java.base
[0.137s][info][class,load] java.util.zip.ZipFile$Source$End source: jrt:/java.base
[0.138s][info][class,load] java.util.zip.ZipUtils source: jrt:/java.base
[0.138s][info][class,load] jdk.internal.perf.PerfCounter source: jrt:/java.base
[0.139s][info][class,load] jdk.internal.perf.Perf$GetPerfAction source: jrt:/java.base
[0.139s][info][class,load] jdk.internal.perf.Perf source: jrt:/java.base
[0.139s][info][class,load] jdk.internal.perf.PerfCounter$CoreCounters source: jrt:/java.base
[0.139s][info][class,load] sun.nio.ch.DirectBuffer source: jrt:/java.base
[0.139s][info][class,load] java.nio.MappedByteBuffer source: jrt:/java.base
[0.139s][info][class,load] java.nio.DirectByteBuffer source: jrt:/java.base
[0.139s][info][class,load] java.nio.Bits source: jrt:/java.base
[0.140s][info][class,load] java.util.concurrent.atomic.AtomicLong source: jrt:/java.base
[0.140s][info][class,load] jdk.internal.misc.JavaNioAccess$BufferPool source: jrt:/java.base
[0.140s][info][class,load] java.nio.Bits$1 source: jrt:/java.base
[0.140s][info][class,load] java.nio.LongBuffer source: jrt:/java.base
[0.140s][info][class,load] java.nio.DirectLongBufferU source: jrt:/java.base
[0.140s][info][class,load] jdk.internal.util.jar.JarIndex source: jrt:/java.base
[0.141s][info][class,load] java.util.jar.JarFile$1 source: jrt:/java.base
[0.141s][info][class,load] java.util.zip.ZipEntry source: jrt:/java.base
[0.141s][info][class,load] java.util.jar.JarEntry source: jrt:/java.base
[0.141s][info][class,load] java.util.jar.JarFile$JarFileEntry source: jrt:/java.base
[0.141s][info][class,load] java.util.zip.ZipFile$ZipFileInputStream source: jrt:/java.base
[0.141s][info][class,load] java.util.zip.InflaterInputStream source: jrt:/java.base
[0.141s][info][class,load] java.util.zip.ZipFile$ZipFileInflaterInputStream source: jrt:/java.base
[0.141s][info][class,load] java.util.zip.Inflater source: jrt:/java.base
[0.143s][info][class,load] java.util.zip.Inflater$InflaterZStreamRef source: jrt:/java.base
[0.143s][info][class,load] java.util.zip.ZipFile$InflaterCleanupAction source: jrt:/java.base
[0.148s][info][class,load] java.util.jar.Attributes source: jrt:/java.base
[0.149s][info][class,load] java.util.jar.Manifest$FastInputStream source: jrt:/java.base
[0.149s][info][class,load] sun.util.PreHashedMap source: jrt:/java.base
[0.149s][info][class,load] sun.nio.cs.StandardCharsets$Aliases source: jrt:/java.base
[0.149s][info][class,load] sun.nio.cs.StandardCharsets$Cache source: jrt:/java.base
[0.150s][info][class,load] java.util.jar.Attributes$Name source: jrt:/java.base
[0.167s][info][class,load] jdk.internal.loader.URLClassPath$JarLoader$2 source: jrt:/java.base
[0.168s][info][class,load] java.util.jar.JarVerifier source: jrt:/java.base
[0.168s][info][class,load] java.security.CodeSigner source: jrt:/java.base
[0.168s][info][class,load] java.io.ByteArrayOutputStream source: jrt:/java.base
[0.169s][info][class,load] sun.security.util.ManifestEntryVerifier source: jrt:/java.base
[0.170s][info][class,load] sun.security.util.SignatureFileVerifier source: jrt:/java.base
[0.170s][info][class,load] sun.security.util.ManifestDigester source: jrt:/java.base
[0.170s][info][class,load] sun.security.util.ManifestDigester$Position source: jrt:/java.base
[0.170s][info][class,load] sun.security.util.ManifestDigester$Entry source: jrt:/java.base
[0.170s][info][class,load] sun.security.util.ManifestDigester$Section source: jrt:/java.base
[0.171s][info][class,load] java.lang.invoke.LambdaMetafactory source: jrt:/java.base
[0.171s][info][class,load] java.lang.invoke.LambdaForm$NamedFunction source: jrt:/java.base
[0.171s][info][class,load] java.lang.invoke.DirectMethodHandle$Holder source: jrt:/java.base
[0.172s][info][class,load] sun.invoke.util.ValueConversions source: jrt:/java.base
[0.173s][info][class,load] java.lang.invoke.MethodHandleImpl source: jrt:/java.base
[0.173s][info][class,load] java.lang.invoke.Invokers source: jrt:/java.base
[0.173s][info][class,load] java.lang.invoke.LambdaForm$Kind source: jrt:/java.base
[0.174s][info][class,load] java.lang.NoSuchMethodException source: jrt:/java.base
[0.174s][info][class,load] java.lang.invoke.LambdaForm$BasicType source: jrt:/java.base
[0.174s][info][class,load] java.lang.invoke.LambdaForm$Name source: jrt:/java.base
[0.175s][info][class,load] java.lang.invoke.LambdaForm$Holder source: jrt:/java.base
[0.175s][info][class,load] java.lang.invoke.MethodHandleImpl$Intrinsic source: jrt:/java.base
[0.175s][info][class,load] java.lang.invoke.InvokerBytecodeGenerator source: jrt:/java.base
[0.176s][info][class,load] java.lang.invoke.InvokerBytecodeGenerator$2 source: jrt:/java.base
[0.176s][info][class,load] java.lang.invoke.BootstrapMethodInvoker source: jrt:/java.base
[0.177s][info][class,load] java.lang.invoke.Invokers$Holder source: jrt:/java.base
[0.178s][info][class,load] jdk.internal.misc.JavaLangInvokeAccess source: jrt:/java.base
[0.178s][info][class,load] java.lang.invoke.MethodHandleImpl$1 source: jrt:/java.base
[0.178s][info][class,load] java.lang.invoke.AbstractValidatingLambdaMetafactory source: jrt:/java.base
[0.178s][info][class,load] java.lang.invoke.InnerClassLambdaMetafactory source: jrt:/java.base
[0.178s][info][class,load] jdk.internal.org.objectweb.asm.Type source: jrt:/java.base
[0.179s][info][class,load] java.lang.invoke.MethodHandleInfo source: jrt:/java.base
[0.179s][info][class,load] java.lang.invoke.InfoFromMemberName source: jrt:/java.base
[0.179s][info][class,load] sun.invoke.util.BytecodeDescriptor source: jrt:/java.base
[0.179s][info][class,load] jdk.internal.org.objectweb.asm.ClassVisitor source: jrt:/java.base
[0.179s][info][class,load] jdk.internal.org.objectweb.asm.ClassWriter source: jrt:/java.base
[0.180s][info][class,load] jdk.internal.org.objectweb.asm.ByteVector source: jrt:/java.base
[0.180s][info][class,load] jdk.internal.org.objectweb.asm.Item source: jrt:/java.base
[0.180s][info][class,load] jdk.internal.org.objectweb.asm.MethodVisitor source: jrt:/java.base
[0.181s][info][class,load] jdk.internal.org.objectweb.asm.MethodWriter source: jrt:/java.base
[0.181s][info][class,load] jdk.internal.org.objectweb.asm.Label source: jrt:/java.base
[0.181s][info][class,load] jdk.internal.org.objectweb.asm.Frame source: jrt:/java.base
[0.182s][info][class,load] jdk.internal.org.objectweb.asm.AnnotationVisitor source: jrt:/java.base
[0.182s][info][class,load] jdk.internal.org.objectweb.asm.AnnotationWriter source: jrt:/java.base
[0.182s][info][class,load] java.lang.invoke.TypeConvertingMethodAdapter source: jrt:/java.base
[0.182s][info][class,load] java.lang.invoke.InnerClassLambdaMetafactory$ForwardingMethodGenerator source: jrt:/java.base
[0.182s][info][class,load] sun.security.util.ManifestDigester$$Lambda$1/0x0000000800065840 source: sun.security.util.ManifestDigester
[0.182s][info][class,load] java.lang.invoke.InnerClassLambdaMetafactory$1 source: jrt:/java.base
[0.183s][info][class,load] java.lang.invoke.BoundMethodHandle source: jrt:/java.base
[0.183s][info][class,load] java.lang.invoke.ClassSpecializer source: jrt:/java.base
[0.183s][info][class,load] java.lang.invoke.BoundMethodHandle$Specializer source: jrt:/java.base
[0.183s][info][class,load] java.lang.invoke.ClassSpecializer$1 source: jrt:/java.base
[0.183s][info][class,load] java.lang.invoke.ClassSpecializer$SpeciesData source: jrt:/java.base
[0.183s][info][class,load] java.lang.invoke.BoundMethodHandle$SpeciesData source: jrt:/java.base
[0.184s][info][class,load] java.util.ImmutableCollections$SubList source: jrt:/java.base
[0.184s][info][class,load] java.lang.invoke.ClassSpecializer$Factory source: jrt:/java.base
[0.184s][info][class,load] java.lang.invoke.BoundMethodHandle$Specializer$Factory source: jrt:/java.base
[0.185s][info][class,load] java.lang.invoke.SimpleMethodHandle source: jrt:/java.base
[0.185s][info][class,load] java.lang.invoke.BoundMethodHandle$Species_L source: jrt:/java.base
[0.186s][info][class,load] sun.invoke.util.VerifyType source: jrt:/java.base
[0.186s][info][class,load] sun.invoke.empty.Empty source: jrt:/java.base
[0.186s][info][class,load] java.lang.invoke.DirectMethodHandle$1 source: jrt:/java.base
[0.186s][info][class,load] java.lang.invoke.DirectMethodHandle$Accessor source: jrt:/java.base
[0.186s][info][class,load] sun.invoke.util.Wrapper$1 source: jrt:/java.base
[0.187s][info][class,load] java.lang.invoke.DelegatingMethodHandle source: jrt:/java.base
[0.187s][info][class,load] java.lang.invoke.MethodHandleImpl$IntrinsicMethodHandle source: jrt:/java.base
[0.187s][info][class,load] java.lang.invoke.DelegatingMethodHandle$Holder source: jrt:/java.base
[0.188s][info][class,load] java.lang.invoke.LambdaFormEditor source: jrt:/java.base
[0.188s][info][class,load] java.lang.invoke.LambdaFormEditor$Transform source: jrt:/java.base
[0.189s][info][class,load] java.lang.invoke.LambdaFormBuffer source: jrt:/java.base
[0.189s][info][class,load] java.lang.invoke.InvokerBytecodeGenerator$CpPatch source: jrt:/java.base
[0.190s][info][class,load] java.lang.invoke.LambdaForm$MH/0x0000000800065c40 source: java.lang.invoke.LambdaForm
[0.191s][info][class,load] sun.security.jca.Providers source: jrt:/java.base
[0.191s][info][class,load] java.lang.InheritableThreadLocal source: jrt:/java.base
[0.191s][info][class,load] sun.security.jca.ProviderList source: jrt:/java.base
[0.191s][info][class,load] sun.security.jca.ProviderConfig source: jrt:/java.base
[0.191s][info][class,load] java.security.Provider source: jrt:/java.base
[0.192s][info][class,load] sun.security.jca.ProviderList$3 source: jrt:/java.base
[0.192s][info][class,load] sun.security.jca.ProviderList$1 source: jrt:/java.base
[0.192s][info][class,load] java.security.Provider$ServiceKey source: jrt:/java.base
[0.192s][info][class,load] java.security.Provider$EngineDescription source: jrt:/java.base
[0.193s][info][class,load] jdk.internal.math.FloatingDecimal source: jrt:/java.base
[0.193s][info][class,load] jdk.internal.math.FloatingDecimal$BinaryToASCIIConverter source: jrt:/java.base
[0.193s][info][class,load] jdk.internal.math.FloatingDecimal$ExceptionalBinaryToASCIIBuffer source: jrt:/java.base
[0.193s][info][class,load] jdk.internal.math.FloatingDecimal$BinaryToASCIIBuffer source: jrt:/java.base
[0.193s][info][class,load] jdk.internal.math.FloatingDecimal$1 source: jrt:/java.base
[0.193s][info][class,load] jdk.internal.math.FloatingDecimal$ASCIIToBinaryConverter source: jrt:/java.base
[0.193s][info][class,load] jdk.internal.math.FloatingDecimal$PreparedASCIIToBinaryBuffer source: jrt:/java.base
[0.193s][info][class,load] jdk.internal.math.FloatingDecimal$ASCIIToBinaryBuffer source: jrt:/java.base
[0.194s][info][class,load] sun.security.jca.ProviderList$2 source: jrt:/java.base
[0.194s][info][class,load] java.security.Security source: jrt:/java.base
[0.194s][info][class,load] java.security.Security$1 source: jrt:/java.base
[0.194s][info][class,load] java.util.Properties$LineReader source: jrt:/java.base
[0.195s][info][class,load] java.lang.StringUTF16 source: jrt:/java.base
[0.197s][info][class,load] sun.security.provider.Sun source: jrt:/java.base
[0.197s][info][class,load] sun.security.util.SecurityConstants source: jrt:/java.base
[0.197s][info][class,load] java.net.NetPermission source: jrt:/java.base
[0.197s][info][class,load] java.security.SecurityPermission source: jrt:/java.base
[0.198s][info][class,load] java.net.SocketPermission source: jrt:/java.base
[0.198s][info][class,load] sun.security.action.GetBooleanAction source: jrt:/java.base
[0.198s][info][class,load] sun.security.provider.SunEntries source: jrt:/java.base
[0.198s][info][class,load] sun.security.provider.SunEntries$1 source: jrt:/java.base
[0.198s][info][class,load] java.security.SecureRandomSpi source: jrt:/java.base
[0.198s][info][class,load] sun.security.provider.NativePRNG source: jrt:/java.base
[0.199s][info][class,load] sun.security.provider.NativePRNG$Variant source: jrt:/java.base
[0.199s][info][class,load] sun.security.provider.NativePRNG$1 source: jrt:/java.base
[0.199s][info][class,load] sun.security.provider.NativePRNG$2 source: jrt:/java.base
[0.199s][info][class,load] sun.security.provider.NativePRNG$RandomIO source: jrt:/java.base
[0.199s][info][class,load] sun.security.provider.FileInputStreamPool source: jrt:/java.base
[0.199s][info][class,load] sun.security.provider.FileInputStreamPool$UnclosableInputStream source: jrt:/java.base
[0.199s][info][class,load] sun.security.provider.FileInputStreamPool$StreamRef source: jrt:/java.base
[0.200s][info][class,load] sun.security.provider.NativePRNG$Blocking source: jrt:/java.base
[0.200s][info][class,load] sun.security.provider.NativePRNG$NonBlocking source: jrt:/java.base
[0.201s][info][class,load] sun.security.pkcs.PKCS7 source: jrt:/java.base
[0.201s][info][class,load] sun.security.util.DerInputStream source: jrt:/java.base
[0.202s][info][class,load] sun.security.util.DerIndefLenConverter source: jrt:/java.base
[0.202s][info][class,load] sun.security.util.DerInputBuffer source: jrt:/java.base
[0.202s][info][class,load] sun.security.pkcs.ContentInfo source: jrt:/java.base
[0.202s][info][class,load] sun.security.util.ObjectIdentifier source: jrt:/java.base
[0.202s][info][class,load] sun.security.util.DerValue source: jrt:/java.base
[0.203s][info][class,load] sun.security.util.IOUtils source: jrt:/java.base
[0.203s][info][class,load] sun.security.util.DerEncoder source: jrt:/java.base
[0.203s][info][class,load] sun.security.util.DerOutputStream source: jrt:/java.base
[0.203s][info][class,load] sun.security.util.ByteArrayLexOrder source: jrt:/java.base
[0.203s][info][class,load] sun.security.util.ByteArrayTagOrder source: jrt:/java.base
[0.203s][info][class,load] jdk.internal.util.ArraysSupport source: jrt:/java.base
[0.204s][info][class,load] java.math.BigInteger source: jrt:/java.base
[0.205s][info][class,load] sun.security.x509.AlgorithmId source: jrt:/java.base
[0.207s][info][class,load] java.security.cert.CertificateFactory source: jrt:/java.base
[0.207s][info][class,load] java.security.cert.CertificateFactorySpi source: jrt:/java.base
[0.207s][info][class,load] sun.security.jca.GetInstance source: jrt:/java.base
[0.207s][info][class,load] java.util.LinkedHashMap$LinkedEntrySet source: jrt:/java.base
[0.207s][info][class,load] java.util.LinkedHashMap$LinkedHashIterator source: jrt:/java.base
[0.207s][info][class,load] java.util.LinkedHashMap$LinkedEntryIterator source: jrt:/java.base
[0.208s][info][class,load] java.security.Provider$Service source: jrt:/java.base
[0.208s][info][class,load] java.security.Provider$UString source: jrt:/java.base
[0.210s][info][class,load] sun.security.provider.X509Factory source: jrt:/java.base
[0.210s][info][class,load] sun.security.util.Cache source: jrt:/java.base
[0.211s][info][class,load] sun.security.util.MemoryCache source: jrt:/java.base
[0.211s][info][class,load] sun.security.jca.GetInstance$Instance source: jrt:/java.base
[0.211s][info][class,load] java.security.cert.X509Extension source: jrt:/java.base
[0.211s][info][class,load] java.security.cert.X509Certificate source: jrt:/java.base
[0.211s][info][class,load] sun.security.util.Cache$EqualByteArray source: jrt:/java.base
[0.212s][info][class,load] sun.security.x509.X509CertImpl source: jrt:/java.base
[0.212s][info][class,load] sun.security.x509.CertAttrSet source: jrt:/java.base
[0.212s][info][class,load] sun.security.x509.X509CertInfo source: jrt:/java.base
[0.212s][info][class,load] sun.security.x509.CertificateVersion source: jrt:/java.base
[0.213s][info][class,load] sun.security.x509.CertificateSerialNumber source: jrt:/java.base
[0.213s][info][class,load] sun.security.x509.SerialNumber source: jrt:/java.base
[0.213s][info][class,load] sun.security.x509.CertificateAlgorithmId source: jrt:/java.base
[0.213s][info][class,load] sun.security.x509.GeneralNameInterface source: jrt:/java.base
[0.213s][info][class,load] sun.security.x509.X500Name source: jrt:/java.base
[0.214s][info][class,load] sun.security.x509.X500Name$1 source: jrt:/java.base
[0.214s][info][class,load] javax.security.auth.x500.X500Principal source: jrt:/java.base
[0.215s][info][class,load] sun.security.x509.RDN source: jrt:/java.base
[0.215s][info][class,load] sun.security.x509.AVA source: jrt:/java.base
[0.215s][info][class,load] sun.security.x509.CertificateValidity source: jrt:/java.base
[0.216s][info][class,load] sun.util.calendar.CalendarSystem source: jrt:/java.base
[0.216s][info][class,load] sun.util.calendar.AbstractCalendar source: jrt:/java.base
[0.216s][info][class,load] sun.util.calendar.BaseCalendar source: jrt:/java.base
[0.216s][info][class,load] sun.util.calendar.Gregorian source: jrt:/java.base
[0.216s][info][class,load] sun.util.calendar.CalendarDate source: jrt:/java.base
[0.216s][info][class,load] sun.util.calendar.BaseCalendar$Date source: jrt:/java.base
[0.216s][info][class,load] sun.util.calendar.Gregorian$Date source: jrt:/java.base
[0.216s][info][class,load] sun.util.calendar.CalendarUtils source: jrt:/java.base
[0.217s][info][class,load] java.util.Date source: jrt:/java.base
[0.217s][info][class,load] sun.security.x509.CertificateX509Key source: jrt:/java.base
[0.217s][info][class,load] java.security.Key source: jrt:/java.base
[0.217s][info][class,load] java.security.PublicKey source: jrt:/java.base
[0.217s][info][class,load] sun.security.x509.X509Key source: jrt:/java.base
[0.218s][info][class,load] sun.security.util.BitArray source: jrt:/java.base
[0.218s][info][class,load] java.security.spec.KeySpec source: jrt:/java.base
[0.218s][info][class,load] java.security.spec.EncodedKeySpec source: jrt:/java.base
[0.218s][info][class,load] java.security.spec.X509EncodedKeySpec source: jrt:/java.base
[0.218s][info][class,load] java.security.KeyFactory source: jrt:/java.base
[0.218s][info][class,load] sun.security.jca.ProviderList$ServiceList source: jrt:/java.base
[0.218s][info][class,load] sun.security.jca.ProviderList$ServiceList$1 source: jrt:/java.base
[0.218s][info][class,load] sun.security.rsa.SunRsaSign source: jrt:/java.base
[0.219s][info][class,load] sun.security.rsa.SunRsaSignEntries source: jrt:/java.base
[0.220s][info][class,load] java.security.KeyFactorySpi source: jrt:/java.base
[0.220s][info][class,load] sun.security.rsa.RSAKeyFactory source: jrt:/java.base
[0.220s][info][class,load] sun.security.rsa.RSAKeyFactory$Legacy source: jrt:/java.base
[0.220s][info][class,load] java.security.spec.RSAPublicKeySpec source: jrt:/java.base
[0.220s][info][class,load] java.security.spec.RSAPrivateKeySpec source: jrt:/java.base
[0.220s][info][class,load] java.security.spec.RSAPrivateCrtKeySpec source: jrt:/java.base
[0.220s][info][class,load] java.security.spec.PKCS8EncodedKeySpec source: jrt:/java.base
[0.221s][info][class,load] sun.security.rsa.RSAUtil$KeyType source: jrt:/java.base
[0.221s][info][class,load] java.security.interfaces.RSAKey source: jrt:/java.base
[0.221s][info][class,load] java.security.interfaces.RSAPublicKey source: jrt:/java.base
[0.221s][info][class,load] sun.security.rsa.RSAPublicKeyImpl source: jrt:/java.base
[0.221s][info][class,load] sun.security.rsa.RSAUtil source: jrt:/java.base
[0.221s][info][class,load] sun.security.x509.CertificateExtensions source: jrt:/java.base
[0.222s][info][class,load] java.util.SortedMap source: jrt:/java.base
[0.222s][info][class,load] java.util.NavigableMap source: jrt:/java.base
[0.222s][info][class,load] java.util.TreeMap source: jrt:/java.base
[0.222s][info][class,load] java.util.Collections$SynchronizedMap source: jrt:/java.base
[0.223s][info][class,load] java.security.cert.Extension source: jrt:/java.base
[0.223s][info][class,load] sun.security.x509.Extension source: jrt:/java.base
[0.223s][info][class,load] sun.security.x509.OIDMap source: jrt:/java.base
[0.223s][info][class,load] sun.security.x509.PKIXExtensions source: jrt:/java.base
[0.223s][info][class,load] sun.security.x509.OIDMap$OIDInfo source: jrt:/java.base
[0.224s][info][class,load] sun.security.x509.KeyUsageExtension source: jrt:/java.base
[0.224s][info][class,load] java.util.TreeMap$Entry source: jrt:/java.base
[0.224s][info][class,load] sun.security.x509.BasicConstraintsExtension source: jrt:/java.base
[0.224s][info][class,load] sun.security.x509.SubjectKeyIdentifierExtension source: jrt:/java.base
[0.224s][info][class,load] sun.security.x509.KeyIdentifier source: jrt:/java.base
[0.225s][info][class,load] sun.security.x509.AuthorityKeyIdentifierExtension source: jrt:/java.base
[0.225s][info][class,load] sun.security.x509.GeneralNames source: jrt:/java.base
[0.225s][info][class,load] sun.security.x509.X509AttributeName source: jrt:/java.base
[0.225s][info][class,load] sun.security.util.MemoryCache$CacheEntry source: jrt:/java.base
[0.225s][info][class,load] sun.security.util.MemoryCache$SoftCacheEntry source: jrt:/java.base
[0.225s][info][class,load] jdk.internal.event.Event source: jrt:/java.base
[0.225s][info][class,load] jdk.internal.event.X509CertificateEvent source: jrt:/java.base
[0.225s][info][class,load] jdk.internal.event.EventHelper source: jrt:/java.base
[0.226s][info][class,load] java.lang.System$Logger$Level source: jrt:/java.base
[0.226s][info][class,load] jdk.internal.logger.LazyLoggers source: jrt:/java.base
[0.226s][info][class,load] jdk.internal.logger.LazyLoggers$1 source: jrt:/java.base
[0.226s][info][class,load] jdk.internal.logger.LazyLoggers$LazyLoggerFactories source: jrt:/java.base
[0.226s][info][class,load] java.lang.System$LoggerFinder source: jrt:/java.base
[0.226s][info][class,load] jdk.internal.logger.DefaultLoggerFinder source: jrt:/java.base
[0.226s][info][class,load] jdk.internal.logger.DefaultLoggerFinder$1 source: jrt:/java.base
[0.226s][info][class,load] java.lang.System$Logger source: jrt:/java.base
[0.226s][info][class,load] sun.util.logging.PlatformLogger$Bridge source: jrt:/java.base
[0.226s][info][class,load] sun.util.logging.PlatformLogger$ConfigurableBridge source: jrt:/java.base
[0.226s][info][class,load] jdk.internal.logger.BootstrapLogger source: jrt:/java.base
[0.227s][info][class,load] jdk.internal.logger.BootstrapLogger$DetectBackend source: jrt:/java.base
[0.227s][info][class,load] jdk.internal.logger.BootstrapLogger$DetectBackend$1 source: jrt:/java.base
[0.227s][info][class,load] java.util.ServiceLoader source: jrt:/java.base
[0.227s][info][class,load] java.util.ServiceLoader$ModuleServicesLookupIterator source: jrt:/java.base
[0.227s][info][class,load] jdk.internal.loader.AbstractClassLoaderValue$Memoizer source: jrt:/java.base
[0.227s][info][class,load] java.util.Spliterators source: jrt:/java.base
[0.227s][info][class,load] java.util.Spliterator source: jrt:/java.base
[0.228s][info][class,load] java.util.Spliterators$EmptySpliterator source: jrt:/java.base
[0.228s][info][class,load] java.util.Spliterators$EmptySpliterator$OfRef source: jrt:/java.base
[0.228s][info][class,load] java.util.Spliterator$OfPrimitive source: jrt:/java.base
[0.228s][info][class,load] java.util.Spliterator$OfInt source: jrt:/java.base
[0.228s][info][class,load] java.util.Spliterators$EmptySpliterator$OfInt source: jrt:/java.base
[0.228s][info][class,load] java.util.Spliterator$OfLong source: jrt:/java.base
[0.228s][info][class,load] java.util.Spliterators$EmptySpliterator$OfLong source: jrt:/java.base
[0.228s][info][class,load] java.util.Spliterator$OfDouble source: jrt:/java.base
[0.228s][info][class,load] java.util.Spliterators$EmptySpliterator$OfDouble source: jrt:/java.base
[0.228s][info][class,load] java.util.Spliterators$ArraySpliterator source: jrt:/java.base
[0.228s][info][class,load] java.util.stream.StreamSupport source: jrt:/java.base
[0.229s][info][class,load] java.util.stream.BaseStream source: jrt:/java.base
[0.229s][info][class,load] java.util.stream.Stream source: jrt:/java.base
[0.229s][info][class,load] java.util.stream.PipelineHelper source: jrt:/java.base
[0.229s][info][class,load] java.util.stream.AbstractPipeline source: jrt:/java.base
[0.229s][info][class,load] java.util.stream.ReferencePipeline source: jrt:/java.base
[0.229s][info][class,load] java.util.stream.ReferencePipeline$Head source: jrt:/java.base
[0.229s][info][class,load] java.util.stream.StreamOpFlag source: jrt:/java.base
[0.230s][info][class,load] java.util.stream.StreamOpFlag$Type source: jrt:/java.base
[0.230s][info][class,load] java.util.stream.StreamOpFlag$MaskBuilder source: jrt:/java.base
[0.230s][info][class,load] java.util.EnumMap source: jrt:/java.base
[0.230s][info][class,load] java.util.EnumMap$1 source: jrt:/java.base
[0.230s][info][class,load] java.lang.Class$3 source: jrt:/java.base
[0.230s][info][class,load] sun.reflect.annotation.AnnotationParser source: jrt:/java.base
[0.231s][info][class,load] jdk.internal.reflect.NativeMethodAccessorImpl source: jrt:/java.base
[0.231s][info][class,load] jdk.internal.reflect.DelegatingMethodAccessorImpl source: jrt:/java.base
[0.231s][info][class,load] java.util.function.Consumer source: jrt:/java.base
[0.231s][info][class,load] java.util.Spliterators$1Adapter source: jrt:/java.base
[0.232s][info][class,load] java.lang.Module$ReflectionData source: jrt:/java.base
[0.232s][info][class,load] java.lang.WeakPairMap source: jrt:/java.base
[0.232s][info][class,load] java.lang.WeakPairMap$Pair source: jrt:/java.base
[0.232s][info][class,load] java.lang.WeakPairMap$Pair$Lookup source: jrt:/java.base
[0.232s][info][class,load] jdk.internal.org.objectweb.asm.FieldVisitor source: jrt:/java.base
[0.232s][info][class,load] jdk.internal.org.objectweb.asm.FieldWriter source: jrt:/java.base
[0.232s][info][class,load] java.lang.ModuleLayer$$Lambda$2/0x0000000800065040 source: java.lang.ModuleLayer
[0.233s][info][class,load] java.util.ServiceLoader$LazyClassPathLookupIterator source: jrt:/java.base
[0.233s][info][class,load] java.util.ServiceLoader$2 source: jrt:/java.base
[0.234s][info][class,load] java.util.ServiceLoader$3 source: jrt:/java.base
[0.234s][info][class,load] jdk.internal.module.Resources source: jrt:/java.base
[0.234s][info][class,load] jdk.internal.loader.BuiltinClassLoader$2 source: jrt:/java.base
[0.234s][info][class,load] jdk.internal.loader.BuiltinClassLoader$5 source: jrt:/java.base
[0.234s][info][class,load] java.lang.module.ModuleReader source: jrt:/java.base
[0.234s][info][class,load] jdk.internal.module.SystemModuleFinders$SystemModuleReader source: jrt:/java.base
[0.234s][info][class,load] jdk.internal.module.SystemModuleFinders$SystemImage source: jrt:/java.base
[0.234s][info][class,load] jdk.internal.jimage.ImageReaderFactory source: jrt:/java.base
[0.234s][info][class,load] java.nio.file.Paths source: jrt:/java.base
[0.234s][info][class,load] jdk.internal.jimage.ImageReaderFactory$1 source: jrt:/java.base
[0.235s][info][class,load] jdk.internal.jimage.ImageReader source: jrt:/java.base
[0.235s][info][class,load] jdk.internal.jimage.BasicImageReader source: jrt:/java.base
[0.235s][info][class,load] jdk.internal.jimage.ImageReader$SharedImageReader source: jrt:/java.base
[0.235s][info][class,load] jdk.internal.jimage.BasicImageReader$1 source: jrt:/java.base
[0.235s][info][class,load] jdk.internal.jimage.NativeImageBuffer source: jrt:/java.base
[0.235s][info][class,load] jdk.internal.jimage.NativeImageBuffer$1 source: jrt:/java.base
[0.236s][info][class,load] jdk.internal.jimage.ImageHeader source: jrt:/java.base
[0.237s][info][class,load] java.nio.IntBuffer source: jrt:/java.base
[0.237s][info][class,load] java.nio.DirectIntBufferU source: jrt:/java.base
[0.237s][info][class,load] java.nio.DirectByteBufferR source: jrt:/java.base
[0.237s][info][class,load] java.nio.DirectIntBufferRU source: jrt:/java.base
[0.237s][info][class,load] jdk.internal.jimage.ImageStrings source: jrt:/java.base
[0.237s][info][class,load] jdk.internal.jimage.ImageStringsReader source: jrt:/java.base
[0.238s][info][class,load] jdk.internal.jimage.decompressor.Decompressor source: jrt:/java.base
[0.238s][info][class,load] jdk.internal.jimage.ImageLocation source: jrt:/java.base
[0.239s][info][class,load] java.util.Collections$EmptyIterator source: jrt:/java.base
[0.239s][info][class,load] java.util.Collections$EmptyEnumeration source: jrt:/java.base
[0.239s][info][class,load] jdk.internal.loader.BuiltinClassLoader$1 source: jrt:/java.base
[0.240s][info][class,load] java.lang.CompoundEnumeration source: jrt:/java.base
[0.240s][info][class,load] jdk.internal.loader.URLClassPath$1 source: jrt:/java.base
[0.241s][info][class,load] java.util.concurrent.CopyOnWriteArrayList$COWIterator source: jrt:/java.base
[0.241s][info][class,load] sun.util.logging.internal.LoggingProviderImpl source: jrt:/java.logging
[0.241s][info][class,load] sun.util.logging.internal.LoggingProviderImpl$LogManagerAccess source: jrt:/java.logging
[0.241s][info][class,load] java.util.ServiceLoader$1 source: jrt:/java.base
[0.241s][info][class,load] java.util.ServiceLoader$Provider source: jrt:/java.base
[0.241s][info][class,load] java.util.ServiceLoader$ProviderImpl source: jrt:/java.base
[0.242s][info][class,load] jdk.internal.logger.BootstrapLogger$LoggingBackend source: jrt:/java.base
[0.242s][info][class,load] jdk.internal.logger.AbstractLoggerWrapper source: jrt:/java.base
[0.242s][info][class,load] jdk.internal.logger.LazyLoggers$LazyLoggerWrapper source: jrt:/java.base
[0.242s][info][class,load] jdk.internal.logger.LazyLoggers$JdkLazyLogger source: jrt:/java.base
[0.242s][info][class,load] jdk.internal.logger.LazyLoggers$LoggerAccessor source: jrt:/java.base
[0.242s][info][class,load] jdk.internal.logger.LazyLoggers$LazyLoggerAccessor source: jrt:/java.base
[0.242s][info][class,load] jdk.internal.logger.BootstrapLogger$RedirectedLoggers source: jrt:/java.base
[0.243s][info][class,load] sun.util.logging.PlatformLogger$ConfigurableBridge$LoggerConfiguration source: jrt:/java.base
[0.243s][info][class,load] jdk.internal.logger.SimpleConsoleLogger source: jrt:/java.base
[0.243s][info][class,load] jdk.internal.logger.SurrogateLogger source: jrt:/java.base
[0.243s][info][class,load] sun.util.logging.PlatformLogger source: jrt:/java.base
[0.243s][info][class,load] sun.util.logging.PlatformLogger$Level source: jrt:/java.base
[0.244s][info][class,load] sun.security.x509.ExtendedKeyUsageExtension source: jrt:/java.base
[0.245s][info][class,load] sun.security.x509.AuthorityInfoAccessExtension source: jrt:/java.base
[0.245s][info][class,load] sun.security.x509.AccessDescription source: jrt:/java.base
[0.245s][info][class,load] sun.security.x509.GeneralName source: jrt:/java.base
[0.245s][info][class,load] sun.security.x509.URIName source: jrt:/java.base
[0.245s][info][class,load] sun.security.x509.DNSName source: jrt:/java.base
[0.246s][info][class,load] sun.security.x509.CRLDistributionPointsExtension source: jrt:/java.base
[0.246s][info][class,load] sun.security.x509.DistributionPoint source: jrt:/java.base
[0.246s][info][class,load] sun.security.x509.CertificatePoliciesExtension source: jrt:/java.base
[0.246s][info][class,load] sun.security.x509.PolicyInformation source: jrt:/java.base
[0.246s][info][class,load] sun.security.x509.CertificatePolicyId source: jrt:/java.base
[0.247s][info][class,load] java.util.LinkedHashSet source: jrt:/java.base
[0.247s][info][class,load] java.security.cert.PolicyQualifierInfo source: jrt:/java.base
[0.249s][info][class,load] sun.security.pkcs.SignerInfo source: jrt:/java.base
[0.249s][info][class,load] java.security.CryptoPrimitive source: jrt:/java.base
[0.249s][info][class,load] java.util.EnumSet source: jrt:/java.base
[0.249s][info][class,load] java.util.RegularEnumSet source: jrt:/java.base
[0.250s][info][class,load] java.security.AlgorithmConstraints source: jrt:/java.base
[0.250s][info][class,load] sun.security.util.AbstractAlgorithmConstraints source: jrt:/java.base
[0.250s][info][class,load] sun.security.util.DisabledAlgorithmConstraints source: jrt:/java.base
[0.250s][info][class,load] sun.security.util.AlgorithmDecomposer source: jrt:/java.base
[0.250s][info][class,load] java.util.regex.Pattern source: jrt:/java.base
[0.251s][info][class,load] java.util.regex.Pattern$Node source: jrt:/java.base
[0.251s][info][class,load] java.util.regex.Pattern$1 source: jrt:/java.base
[0.251s][info][class,load] java.util.regex.Pattern$LastNode source: jrt:/java.base
[0.251s][info][class,load] java.util.regex.Pattern$GroupHead source: jrt:/java.base
[0.251s][info][class,load] java.util.regex.ASCII source: jrt:/java.base
[0.251s][info][class,load] java.util.regex.Pattern$SliceNode source: jrt:/java.base
[0.251s][info][class,load] java.util.regex.Pattern$SliceI source: jrt:/java.base
[0.251s][info][class,load] java.util.regex.Pattern$BranchConn source: jrt:/java.base
[0.251s][info][class,load] java.util.regex.Pattern$Branch source: jrt:/java.base
[0.251s][info][class,load] java.util.regex.Pattern$GroupTail source: jrt:/java.base
[0.251s][info][class,load] java.util.regex.Pattern$TreeInfo source: jrt:/java.base
[0.251s][info][class,load] java.util.regex.Pattern$NotBehind source: jrt:/java.base
[0.252s][info][class,load] java.util.regex.Pattern$Slice source: jrt:/java.base
[0.252s][info][class,load] java.util.regex.Pattern$Begin source: jrt:/java.base
[0.252s][info][class,load] java.util.regex.Pattern$First source: jrt:/java.base
[0.252s][info][class,load] java.util.regex.Pattern$Start source: jrt:/java.base
[0.252s][info][class,load] sun.security.util.AbstractAlgorithmConstraints$1 source: jrt:/java.base
[0.252s][info][class,load] java.util.ArrayList$SubList source: jrt:/java.base
[0.252s][info][class,load] sun.security.util.DisabledAlgorithmConstraints$Constraints source: jrt:/java.base
[0.253s][info][class,load] java.util.Arrays$ArrayList source: jrt:/java.base
[0.253s][info][class,load] java.util.Arrays$ArrayItr source: jrt:/java.base
[0.253s][info][class,load] sun.security.util.DisabledAlgorithmConstraints$Constraint source: jrt:/java.base
[0.253s][info][class,load] sun.security.util.DisabledAlgorithmConstraints$DisabledConstraint source: jrt:/java.base
[0.253s][info][class,load] java.util.StringTokenizer source: jrt:/java.base
[0.253s][info][class,load] sun.security.util.DisabledAlgorithmConstraints$KeySizeConstraint source: jrt:/java.base
[0.253s][info][class,load] sun.security.util.DisabledAlgorithmConstraints$Constraint$Operator source: jrt:/java.base
[0.253s][info][class,load] sun.security.util.DisabledAlgorithmConstraints$1 source: jrt:/java.base
[0.254s][info][class,load] sun.security.pkcs.PKCS9Attributes source: jrt:/java.base
[0.254s][info][class,load] sun.security.pkcs.PKCS9Attribute source: jrt:/java.base
[0.255s][info][class,load] java.lang.Byte$ByteCache source: jrt:/java.base
[0.257s][info][class,load] sun.security.x509.SubjectAlternativeNameExtension source: jrt:/java.base
[0.259s][info][class,load] sun.security.util.ConstraintsParameters source: jrt:/java.base
[0.260s][info][class,load] java.util.regex.MatchResult source: jrt:/java.base
[0.260s][info][class,load] java.util.regex.Matcher source: jrt:/java.base
[0.260s][info][class,load] java.util.regex.IntHashSet source: jrt:/java.base
[0.260s][info][class,load] java.security.MessageDigestSpi source: jrt:/java.base
[0.260s][info][class,load] java.security.MessageDigest source: jrt:/java.base
[0.261s][info][class,load] sun.security.provider.DigestBase source: jrt:/java.base
[0.261s][info][class,load] sun.security.provider.SHA2 source: jrt:/java.base
[0.261s][info][class,load] sun.security.provider.SHA2$SHA256 source: jrt:/java.base
[0.261s][info][class,load] sun.security.util.MessageDigestSpi2 source: jrt:/java.base
[0.261s][info][class,load] java.security.MessageDigest$Delegate source: jrt:/java.base
[0.261s][info][class,load] sun.security.provider.ByteArrayAccess source: jrt:/java.base
[0.262s][info][class,load] java.util.StringJoiner source: jrt:/java.base
[0.262s][info][class,load] sun.security.x509.AVAKeyword source: jrt:/java.base
[0.263s][info][class,load] java.text.Normalizer$Form source: jrt:/java.base
[0.263s][info][class,load] java.text.Normalizer source: jrt:/java.base
[0.263s][info][class,load] sun.text.normalizer.NormalizerBase source: jrt:/java.base
[0.263s][info][class,load] sun.text.normalizer.NormalizerBase$Mode source: jrt:/java.base
[0.263s][info][class,load] sun.text.normalizer.NormalizerBase$NONEMode source: jrt:/java.base
[0.263s][info][class,load] sun.text.normalizer.NormalizerBase$NFDMode source: jrt:/java.base
[0.263s][info][class,load] sun.text.normalizer.NormalizerBase$NFKDMode source: jrt:/java.base
[0.263s][info][class,load] sun.text.normalizer.NormalizerBase$NFCMode source: jrt:/java.base
[0.263s][info][class,load] sun.text.normalizer.NormalizerBase$NFKCMode source: jrt:/java.base
[0.263s][info][class,load] sun.text.normalizer.NormalizerBase$1 source: jrt:/java.base
[0.263s][info][class,load] sun.text.normalizer.NormalizerBase$NFKDModeImpl source: jrt:/java.base
[0.263s][info][class,load] sun.text.normalizer.NormalizerBase$ModeImpl source: jrt:/java.base
[0.263s][info][class,load] sun.text.normalizer.Normalizer2 source: jrt:/java.base
[0.264s][info][class,load] sun.text.normalizer.Norm2AllModes source: jrt:/java.base
[0.264s][info][class,load] sun.text.normalizer.Norm2AllModes$NoopNormalizer2 source: jrt:/java.base
[0.264s][info][class,load] sun.text.normalizer.Norm2AllModes$NFKCSingleton source: jrt:/java.base
[0.264s][info][class,load] sun.text.normalizer.Norm2AllModes$Norm2AllModesSingleton source: jrt:/java.base
[0.264s][info][class,load] sun.text.normalizer.NormalizerImpl source: jrt:/java.base
[0.264s][info][class,load] sun.text.normalizer.ICUBinary$Authenticate source: jrt:/java.base
[0.264s][info][class,load] sun.text.normalizer.NormalizerImpl$IsAcceptable source: jrt:/java.base
[0.264s][info][class,load] sun.text.normalizer.ICUBinary source: jrt:/java.base
[0.265s][info][class,load] sun.text.normalizer.ICUBinary$1 source: jrt:/java.base
[0.265s][info][class,load] jdk.internal.module.Checks source: jrt:/java.base
[0.265s][info][class,load] java.lang.invoke.DirectMethodHandle$Special source: jrt:/java.base
[0.266s][info][class,load] jdk.internal.module.SystemModuleFinders$SystemModuleReader$$Lambda$3/0x0000000800065440 source: jdk.internal.module.SystemModuleFinders$SystemModuleReader
[0.266s][info][class,load] java.io.DataInputStream source: jrt:/java.base
[0.266s][info][class,load] sun.text.normalizer.VersionInfo source: jrt:/java.base
[0.267s][info][class,load] sun.text.normalizer.Trie2 source: jrt:/java.base
[0.267s][info][class,load] sun.text.normalizer.Trie2_16 source: jrt:/java.base
[0.267s][info][class,load] sun.text.normalizer.Trie2$ValueMapper source: jrt:/java.base
[0.267s][info][class,load] sun.text.normalizer.Trie2$1 source: jrt:/java.base
[0.267s][info][class,load] sun.text.normalizer.Trie2$UTrie2Header source: jrt:/java.base
[0.271s][info][class,load] sun.text.normalizer.Norm2AllModes$Normalizer2WithImpl source: jrt:/java.base
[0.271s][info][class,load] sun.text.normalizer.Norm2AllModes$ComposeNormalizer2 source: jrt:/java.base
[0.271s][info][class,load] sun.text.normalizer.Norm2AllModes$DecomposeNormalizer2 source: jrt:/java.base
[0.271s][info][class,load] sun.security.util.KeyUtil source: jrt:/java.base
[0.271s][info][class,load] sun.security.util.Length source: jrt:/java.base
[0.271s][info][class,load] javax.security.auth.Destroyable source: jrt:/java.base
[0.272s][info][class,load] javax.crypto.SecretKey source: jrt:/java.base
[0.272s][info][class,load] java.security.SignatureSpi source: jrt:/java.base
[0.272s][info][class,load] java.security.Signature source: jrt:/java.base
[0.272s][info][class,load] jdk.internal.misc.JavaSecuritySignatureAccess source: jrt:/java.base
[0.272s][info][class,load] java.security.Signature$1 source: jrt:/java.base
[0.272s][info][class,load] sun.security.jca.ServiceId source: jrt:/java.base
[0.273s][info][class,load] java.security.Signature$Delegate source: jrt:/java.base
[0.273s][info][class,load] sun.security.util.SignatureUtil source: jrt:/java.base
[0.273s][info][class,load] java.security.PrivateKey source: jrt:/java.base
[0.273s][info][class,load] java.security.interfaces.RSAPrivateKey source: jrt:/java.base
[0.274s][info][class,load] sun.security.rsa.RSASignature source: jrt:/java.base
[0.274s][info][class,load] sun.security.rsa.RSASignature$SHA256withRSA source: jrt:/java.base
[0.274s][info][class,load] sun.security.pkcs.PKCS8Key source: jrt:/java.base
[0.274s][info][class,load] sun.security.rsa.RSAPrivateKeyImpl source: jrt:/java.base
[0.274s][info][class,load] java.security.interfaces.RSAPrivateCrtKey source: jrt:/java.base
[0.274s][info][class,load] sun.security.rsa.RSAPrivateCrtKeyImpl source: jrt:/java.base
[0.274s][info][class,load] sun.security.rsa.RSAUtil$1 source: jrt:/java.base
[0.274s][info][class,load] sun.security.rsa.RSACore source: jrt:/java.base
[0.275s][info][class,load] sun.security.rsa.RSAPadding source: jrt:/java.base
[0.275s][info][class,load] java.math.MutableBigInteger source: jrt:/java.base
[0.279s][info][class,load] java.security.GeneralSecurityException source: jrt:/java.base
[0.279s][info][class,load] javax.crypto.BadPaddingException source: jrt:/java.base
[0.280s][info][class,load] java.security.cert.CertPath source: jrt:/java.base
[0.281s][info][class,load] sun.security.provider.certpath.X509CertPath source: jrt:/java.base
[0.281s][info][class,load] java.util.Collections$UnmodifiableList source: jrt:/java.base
[0.281s][info][class,load] java.util.Collections$UnmodifiableRandomAccessList source: jrt:/java.base
[0.281s][info][class,load] sun.security.timestamp.TimestampToken source: jrt:/java.base
[0.281s][info][class,load] sun.security.provider.SHA source: jrt:/java.base
[0.282s][info][class,load] java.security.Timestamp source: jrt:/java.base
[0.286s][info][class,load] sun.security.util.SignatureFileVerifier$ConfigurationHolder source: jrt:/java.base
[0.288s][info][class,load] java.util.Base64 source: jrt:/java.base
[0.288s][info][class,load] java.util.Base64$Decoder source: jrt:/java.base
[0.288s][info][class,load] java.util.Base64$Encoder source: jrt:/java.base
[0.289s][info][class,load] java.util.jar.JarVerifier$VerifierStream source: jrt:/java.base
[0.289s][info][class,load] sun.security.util.ManifestEntryVerifier$SunProviderHolder source: jrt:/java.base
[0.294s][info][class,load] org.slf4j.LoggerFactory source: file:/Applications/Eclipse.app/Contents/Eclipse/plugins/org.slf4j.api_1.7.2.v20121108-1250.jar
[0.294s][info][class,load] java.lang.IncompatibleClassChangeError source: jrt:/java.base
[0.294s][info][class,load] java.lang.NoSuchMethodError source: jrt:/java.base
[0.295s][info][class,load] java.lang.IllegalStateException source: jrt:/java.base
[0.295s][info][class,load] java.lang.NoSuchFieldError source: jrt:/java.base
[0.296s][info][class,load] org.slf4j.ILoggerFactory source: file:/Applications/Eclipse.app/Contents/Eclipse/plugins/org.slf4j.api_1.7.2.v20121108-1250.jar
[0.296s][info][class,load] org.slf4j.helpers.SubstituteLoggerFactory source: file:/Applications/Eclipse.app/Contents/Eclipse/plugins/org.slf4j.api_1.7.2.v20121108-1250.jar
[0.297s][info][class,load] org.slf4j.Logger source: file:/Applications/Eclipse.app/Contents/Eclipse/plugins/org.slf4j.api_1.7.2.v20121108-1250.jar
[0.298s][info][class,load] org.slf4j.helpers.NOPLoggerFactory source: file:/Applications/Eclipse.app/Contents/Eclipse/plugins/org.slf4j.api_1.7.2.v20121108-1250.jar
[0.300s][info][class,load] org.slf4j.helpers.Util source: file:/Applications/Eclipse.app/Contents/Eclipse/plugins/org.slf4j.api_1.7.2.v20121108-1250.jar
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
[0.303s][info][class,load] org.slf4j.helpers.NamedLoggerBase source: file:/Applications/Eclipse.app/Contents/Eclipse/plugins/org.slf4j.api_1.7.2.v20121108-1250.jar
[0.303s][info][class,load] org.slf4j.helpers.MarkerIgnoringBase source: file:/Applications/Eclipse.app/Contents/Eclipse/plugins/org.slf4j.api_1.7.2.v20121108-1250.jar
[0.303s][info][class,load] org.slf4j.helpers.NOPLogger source: file:/Applications/Eclipse.app/Contents/Eclipse/plugins/org.slf4j.api_1.7.2.v20121108-1250.jar
[0.304s][info][class,load] org.eclipse.jgit.treewalk.WorkingTreeIterator$Entry source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.304s][info][class,load] org.eclipse.jgit.util.FS$FSFactory source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.305s][info][class,load] org.eclipse.jgit.util.FS_Win32 source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.305s][info][class,load] org.eclipse.jgit.util.FS_Win32_Cygwin source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.305s][info][class,load] org.eclipse.jgit.util.FS_POSIX source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.306s][info][class,load] org.eclipse.jgit.util.SystemReader source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.306s][info][class,load] org.eclipse.jgit.util.SystemReader$Default source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.307s][info][class,load] org.eclipse.jgit.storage.file.FileBasedConfig source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.307s][info][class,load] org.eclipse.jgit.util.time.MonotonicClock source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.307s][info][class,load] java.net.UnknownHostException source: jrt:/java.base
[0.308s][info][class,load] org.eclipse.jgit.util.SystemReader$Default$1 source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.308s][info][class,load] java.util.concurrent.atomic.AtomicReference source: jrt:/java.base
[0.308s][info][class,load] java.lang.invoke.VarHandleObjects$FieldInstanceReadOnly source: jrt:/java.base
[0.308s][info][class,load] java.lang.invoke.VarHandleObjects$FieldInstanceReadWrite source: jrt:/java.base
[0.309s][info][class,load] org.eclipse.jgit.lib.ObjectChecker source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.310s][info][class,load] org.eclipse.jgit.lib.AnyObjectId source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.310s][info][class,load] org.eclipse.jgit.lib.ObjectId source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.310s][info][class,load] org.eclipse.jgit.errors.CorruptObjectException source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.311s][info][class,load] org.eclipse.jgit.lib.Constants source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.312s][info][class,load] java.lang.IndexOutOfBoundsException source: jrt:/java.base
[0.312s][info][class,load] java.lang.ArrayIndexOutOfBoundsException source: jrt:/java.base
[0.312s][info][class,load] java.security.NoSuchAlgorithmException source: jrt:/java.base
[0.312s][info][class,load] org.eclipse.jgit.errors.InvalidObjectIdException source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.313s][info][class,load] org.eclipse.jgit.util.RawParseUtils source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.313s][info][class,load] java.nio.charset.CharacterCodingException source: jrt:/java.base
[0.313s][info][class,load] org.eclipse.jgit.errors.BinaryBlobException source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.314s][info][class,load] java.nio.charset.IllegalCharsetNameException source: jrt:/java.base
[0.314s][info][class,load] java.nio.charset.UnsupportedCharsetException source: jrt:/java.base
[0.314s][info][class,load] org.eclipse.jgit.lib.MutableObjectId source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.315s][info][class,load] org.eclipse.jgit.util.MutableInteger source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.315s][info][class,load] org.eclipse.jgit.lib.ObjectChecker$ErrorType source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.316s][info][class,load] org.eclipse.jgit.util.SystemReader$$Lambda$4/0x0000000800064840 source: org.eclipse.jgit.util.SystemReader
[0.317s][info][class,load] org.eclipse.jgit.errors.ConfigInvalidException source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.317s][info][class,load] java.nio.file.FileSystemException source: jrt:/java.base
[0.317s][info][class,load] java.nio.file.FileAlreadyExistsException source: jrt:/java.base
[0.318s][info][class,load] org.eclipse.jgit.util.FS_POSIX$AtomicFileCreation source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.318s][info][class,load] org.eclipse.jgit.util.FS$FileStoreAttributes source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.319s][info][class,load] java.nio.file.AccessDeniedException source: jrt:/java.base
[0.319s][info][class,load] java.time.temporal.TemporalAccessor source: jrt:/java.base
[0.319s][info][class,load] java.time.temporal.Temporal source: jrt:/java.base
[0.319s][info][class,load] org.eclipse.jgit.errors.LockFailedException source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.319s][info][class,load] java.util.concurrent.ExecutionException source: jrt:/java.base
[0.319s][info][class,load] java.util.concurrent.CancellationException source: jrt:/java.base
[0.320s][info][class,load] java.util.concurrent.TimeoutException source: jrt:/java.base
[0.320s][info][class,load] java.time.temporal.TemporalAmount source: jrt:/java.base
[0.320s][info][class,load] java.time.Duration source: jrt:/java.base
[0.321s][info][class,load] org.eclipse.jgit.util.SimpleLruCache source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.321s][info][class,load] java.util.concurrent.locks.AbstractQueuedSynchronizer source: jrt:/java.base
[0.321s][info][class,load] java.util.concurrent.locks.ReentrantLock$Sync source: jrt:/java.base
[0.321s][info][class,load] java.util.concurrent.locks.ReentrantLock$NonfairSync source: jrt:/java.base
[0.321s][info][class,load] java.util.concurrent.locks.AbstractQueuedSynchronizer$Node source: jrt:/java.base
Time FS: 211ms
---8<---

Here's what it looks like with the proposed change:

---8<---
[0.127s][info][class,load] java.lang.Package source: jrt:/java.base
[0.127s][info][class,load] java.lang.Package$VersionInfo source: jrt:/java.base
[0.128s][info][class,load] org.eclipse.jgit.util.FS$FileStoreAttributes source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.128s][info][class,load] java.lang.SecurityException source: jrt:/java.base
[0.129s][info][class,load] java.io.IOException source: jrt:/java.base
[0.129s][info][class,load] java.lang.InterruptedException source: jrt:/java.base
[0.129s][info][class,load] java.util.concurrent.ExecutionException source: jrt:/java.base
[0.129s][info][class,load] java.lang.IllegalStateException source: jrt:/java.base
[0.129s][info][class,load] java.util.concurrent.CancellationException source: jrt:/java.base
[0.129s][info][class,load] java.util.concurrent.TimeoutException source: jrt:/java.base
[0.129s][info][class,load] java.nio.file.FileSystemException source: jrt:/java.base
[0.129s][info][class,load] java.nio.file.AccessDeniedException source: jrt:/java.base
[0.129s][info][class,load] java.time.temporal.TemporalAccessor source: jrt:/java.base
[0.129s][info][class,load] java.time.temporal.Temporal source: jrt:/java.base
[0.130s][info][class,load] org.eclipse.jgit.errors.ConfigInvalidException source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.130s][info][class,load] org.eclipse.jgit.errors.LockFailedException source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.131s][info][class,load] java.time.temporal.TemporalAmount source: jrt:/java.base
[0.131s][info][class,load] java.time.Duration source: jrt:/java.base
[0.132s][info][class,load] java.math.BigInteger source: jrt:/java.base
[0.133s][info][class,load] org.eclipse.jgit.util.SimpleLruCache source: file:/Users/alex/Projects/jgit/org.eclipse.jgit/bin/
[0.134s][info][class,load] java.util.concurrent.locks.AbstractQueuedSynchronizer source: jrt:/java.base
[0.134s][info][class,load] java.util.concurrent.locks.ReentrantLock$Sync source: jrt:/java.base
[0.134s][info][class,load] java.util.concurrent.locks.ReentrantLock$NonfairSync source: jrt:/java.base
[0.135s][info][class,load] java.lang.invoke.MethodHandles source: jrt:/java.base
[0.135s][info][class,load] java.lang.invoke.MemberName$Factory source: jrt:/java.base
[0.135s][info][class,load] java.lang.reflect.ReflectPermission source: jrt:/java.base
[0.135s][info][class,load] java.lang.invoke.MethodHandles$Lookup source: jrt:/java.base
[0.136s][info][class,load] sun.invoke.util.VerifyAccess source: jrt:/java.base
[0.136s][info][class,load] java.lang.NoSuchFieldException source: jrt:/java.base
[0.136s][info][class,load] java.lang.invoke.VarHandles source: jrt:/java.base
[0.136s][info][class,load] java.lang.invoke.VarHandleInts$FieldInstanceReadOnly source: jrt:/java.base
[0.136s][info][class,load] java.lang.invoke.VarHandleInts$FieldInstanceReadWrite source: jrt:/java.base
[0.136s][info][class,load] java.lang.invoke.VarHandle$1 source: jrt:/java.base
[0.137s][info][class,load] java.util.function.BiFunction source: jrt:/java.base
[0.137s][info][class,load] jdk.internal.util.Preconditions$1 source: jrt:/java.base
[0.137s][info][class,load] java.lang.invoke.VarHandleGuards source: jrt:/java.base
[0.137s][info][class,load] java.lang.invoke.VarForm source: jrt:/java.base
[0.137s][info][class,load] java.lang.invoke.VarHandle$AccessType source: jrt:/java.base
[0.138s][info][class,load] java.lang.invoke.VarHandle$AccessMode source: jrt:/java.base
[0.138s][info][class,load] java.lang.invoke.MethodType$ConcurrentWeakInternSet source: jrt:/java.base
[0.138s][info][class,load] java.lang.invoke.MethodType$ConcurrentWeakInternSet$WeakEntry source: jrt:/java.base
[0.139s][info][class,load] java.lang.invoke.MethodTypeForm source: jrt:/java.base
[0.139s][info][class,load] sun.invoke.util.Wrapper source: jrt:/java.base
[0.139s][info][class,load] sun.invoke.util.Wrapper$Format source: jrt:/java.base
[0.140s][info][class,load] java.util.concurrent.locks.AbstractQueuedSynchronizer$Node source: jrt:/java.base
[0.140s][info][class,load] java.lang.invoke.VarHandleObjects$FieldInstanceReadOnly source: jrt:/java.base
[0.140s][info][class,load] java.lang.invoke.VarHandleObjects$FieldInstanceReadWrite source: jrt:/java.base
[0.141s][info][class,load] java.util.concurrent.atomic.AtomicBoolean source: jrt:/java.base
Time FS: 14ms
---8<---
Comment 24 Alex Blewitt CLA 2020-02-25 15:07:01 EST
> Another thing to consider with such micro-optimizations is that if a long time is observed due to loading other bundles in one step, then often optimizing that bit just delays the loading of said bundles to a later step inside Activator.start() and the overall time remains more or less the same.

Sorry, I forgot to reply to this. You are right; we are not avoiding the possibility of not doing this at all but rather doing it later; more specifically, off the main thread. Startup time is dominated by processing/loading on the main thread, not other threads. If we can move the slow parts to background threads, it also solves the issue at hand.

> Also note: timing on Windows may be very different from timing on OS X or Linux due to different filesystem characteristics. Michael already mentioned it: file access on Windows can be very expensive compared to other systems. Especially accessing file attributes (last modified time and such).

You're quite right; however, I tested on OS X. Not sure who mentioned Windows, but it wasn't me ... (macOS 10.11 on a 2011 macBookPro, which clearly shows where slow things are slow perhaps more clearly than a faster machine)
Comment 25 Lars Vogel CLA 2020-02-25 15:20:45 EST
Alex, please push Gerrits for this bug so that we can also easily test your changes.
Comment 26 Thomas Wolf CLA 2020-02-25 15:44:05 EST
(In reply to Alex Blewitt from comment #23)
> Thomas, how did you measure the difference?

Simply instrumented the Activator :-) But I ran it still with that DNS resolution in there, that seems to have swamped the rest. With the DNS resolution gone, there _is_ an effect also on my machine (from ~20ms down to ~3).
Comment 27 Lars Vogel CLA 2020-02-25 15:45:13 EST
(In reply to Thomas Wolf from comment #26)
> (In reply to Alex Blewitt from comment #23)
> > Thomas, how did you measure the difference?
> 
> Simply instrumented the Activator :-) But I ran it still with that DNS
> resolution in there, that seems to have swamped the rest. With the DNS
> resolution gone, there _is_ an effect also on my machine (from ~20ms down to
> ~3).

Hubbabubba, that is a big gain! Alex, lets see some Gerrits!
Comment 28 Lars Vogel CLA 2020-02-25 15:55:50 EST
(In reply to Lars Vogel from comment #27)
> (In reply to Thomas Wolf from comment #26)
from ~20ms down to ~3).
> 

Ups, I misread this as 200ms. Still would be good to see some Gerrits so that we all can use your profiles to measure.
Comment 29 Alex Blewitt CLA 2020-02-25 16:36:16 EST
I've raised bug 560527 against JGit to expose the public caller; not sure which it needs to be targeted to. Once that's in, we can update the EGit to use that instead.
Comment 30 Lars Vogel CLA 2020-02-25 17:21:31 EST Comment hidden (obsolete)
Comment 31 Eclipse Genie CLA 2020-02-25 17:25:02 EST
New Gerrit change created: https://git.eclipse.org/r/158363
Comment 32 Lars Vogel CLA 2020-02-25 17:26:17 EST
(In reply to Thomas Wolf from comment #20)
> (In reply to Michael Keppler from comment #17)
> > GitProjectData.reconfigureWindowCache()
> 
> That could be safely done in the background I think.

Putting GitProjectData.reconfigureWindowCache() into a job show the following for me:

Without change:

198 ms for total start time event STARTED - osgi.identity; osgi.identity="org.eclipse.egit.core"; type="osgi.bundle"; version:Version="5.7.0.qualifier"; singleton:="true" [id=124]
241 ms for total start time event STARTED - osgi.identity; osgi.identity="org.eclipse.egit.ui"; type="osgi.bundle"; version:Version="5.7.0.qualifier"; singleton:="true" [id=128]


With GitProjectData.reconfigureWindowCache(); in a job:

128 ms for total start time event STARTED - osgi.identity; osgi.identity="org.eclipse.egit.core"; type="osgi.bundle"; version:Version="5.7.0.qualifier"; singleton:="true" [id=124]
181 ms for total start time event STARTED - osgi.identity; osgi.identity="org.eclipse.egit.ui"; type="osgi.bundle"; version:Version="5.7.0.qualifier"; singleton:="true" [id=128]
Comment 33 Thomas Wolf CLA 2020-02-25 17:47:47 EST
If anybody sees opportunities for improving the Egit core activator by moving things into asynchronous threads or jobs or futures or whatever: by all means, experiment with it.

But I suggest we *don't* put such things in into 5.7.0. Such things are for early 5.8.0 after Simrel 2020-03. It's IMO too close to release already, and I consider such backgrounding too risky to include in 5.7.0.
Comment 34 Matthias Sohn CLA 2020-02-25 18:43:35 EST
(In reply to Thomas Wolf from comment #33)
> If anybody sees opportunities for improving the Egit core activator by
> moving things into asynchronous threads or jobs or futures or whatever: by
> all means, experiment with it.
> 
> But I suggest we *don't* put such things in into 5.7.0. Such things are for
> early 5.8.0 after Simrel 2020-03. It's IMO too close to release already, and
> I consider such backgrounding too risky to include in 5.7.0.

+1, yesterday I contributed the current state to 2020-03 M3 and next week we have RC1

I have a question for my education: what's the common understanding in which state a plugin should be after its Activator's start method is done ?
If we move a lot of initialisation/class loading etc which is currently done in the Main thread in the activator to another thread the Main thread will more quickly exit this start method but can we call the plugin already active at this point in time ?
Comment 35 Eclipse Genie CLA 2020-02-26 02:40:20 EST
New Gerrit change created: https://git.eclipse.org/r/158385
Comment 36 Andrey Loskutov CLA 2020-02-29 17:36:19 EST
(In reply to Matthias Sohn from comment #34)
> I have a question for my education: what's the common understanding in which
> state a plugin should be after its Activator's start method is done ?
> If we move a lot of initialisation/class loading etc which is currently done
> in the Main thread in the activator to another thread the Main thread will
> more quickly exit this start method but can we call the plugin already
> active at this point in time ?

From equinox point of view we are done with activation after leaving start(). What do we want to init afterwards is totally up to us. 

Lot of work inside start() is not only "bad" from UI point of view (*if* we are activated in UI thread at all, equinox sets a 30 sec timer here independently on the thread where we are), it is also a common root cause of deadlock cases because start() locks all the code accessing the bundle. On the one side, locked start() offers a good place to init all sensible "singletons" in the bundle, on the other side, if that code takes too long, and does too much, it can become a serious problem.
Comment 37 Eclipse Genie CLA 2020-03-06 18:21:31 EST
New Gerrit change created: https://git.eclipse.org/r/158972
Comment 38 Lars Vogel CLA 2020-03-16 12:30:20 EDT
(In reply to Lars Vogel from comment #5)
> Using build in tracing of platform, I see that Egit is leading by far the
> list of the top ten of the longest running activators (using an SDK plus
> Egit).
> 
> Activator times
> 495 org.eclipse.egit.ui_5.7.0.202002232031
> 395 org.eclipse.egit.core_5.7.0.202002232031
> 348 org.eclipse.jdt.ui_3.21.0.v20200218-1551
> 202 org.eclipse.jdt.core_3.21.0.v20200223-1120
> 140 org.eclipse.ui.trace_1.1.800.v20200106-1301
> 138 org.eclipse.core.runtime_3.17.100.v20200203-0917
> 130 org.eclipse.core.resources_3.13.700.v20200209-1624
> 82 org.eclipse.core.contenttype_3.7.600.v20200124-1609
> 79 org.eclipse.ui.workbench_3.118.0.v20200222-0719
> 78 org.eclipse.equinox.registry_3.8.700.v20200121-1457

With change from Egit night 0 which should include Bug 560527 and Bug 560528 and SDK Build id: I20200315-1800 I see the following startup times which looks already a lot better from the EGit perspective.

Activator times
425 org.eclipse.jdt.ui_3.21.100.v20200315-1658
402 org.eclipse.egit.ui_5.8.0.202003121753
335 org.eclipse.egit.core_5.8.0.202003121753
262 org.eclipse.jdt.core_3.21.100.v20200314-1817
160 org.eclipse.core.resources_3.13.700.v20200209-1624
146 org.eclipse.ui.trace_1.1.800.v20200106-1301
143 org.eclipse.core.runtime_3.17.200.v20200310-0218
90 org.eclipse.core.contenttype_3.7.700.v20200310-0218
85 org.eclipse.equinox.registry_3.8.700.v20200121-1457
76 org.eclipse.ui.workbench_3.118.100.v20200310-0123

Egit has still one of the most time consuming activators. Looking forward for the pending patches.
Comment 39 Sebastian Zarnekow CLA 2020-03-17 04:07:36 EDT
(In reply to Lars Vogel from comment #38)
> (In reply to Lars Vogel from comment #5)
> > Using build in tracing of platform, I see that Egit is leading by far the
> > list of the top ten of the longest running activators (using an SDK plus
> > Egit).
> > 
> > Activator times
> > 495 org.eclipse.egit.ui_5.7.0.202002232031
> > 395 org.eclipse.egit.core_5.7.0.202002232031
> > 348 org.eclipse.jdt.ui_3.21.0.v20200218-1551
> > 202 org.eclipse.jdt.core_3.21.0.v20200223-1120
> > 140 org.eclipse.ui.trace_1.1.800.v20200106-1301
> > 138 org.eclipse.core.runtime_3.17.100.v20200203-0917
> > 130 org.eclipse.core.resources_3.13.700.v20200209-1624
> > 82 org.eclipse.core.contenttype_3.7.600.v20200124-1609
> > 79 org.eclipse.ui.workbench_3.118.0.v20200222-0719
> > 78 org.eclipse.equinox.registry_3.8.700.v20200121-1457
> 
> With change from Egit night 0 which should include Bug 560527 and Bug 560528
> and SDK Build id: I20200315-1800 I see the following startup times which
> looks already a lot better from the EGit perspective.
> 
> Activator times
> 425 org.eclipse.jdt.ui_3.21.100.v20200315-1658
> 402 org.eclipse.egit.ui_5.8.0.202003121753
> 335 org.eclipse.egit.core_5.8.0.202003121753
> 262 org.eclipse.jdt.core_3.21.100.v20200314-1817
> 160 org.eclipse.core.resources_3.13.700.v20200209-1624
> 146 org.eclipse.ui.trace_1.1.800.v20200106-1301
> 143 org.eclipse.core.runtime_3.17.200.v20200310-0218
> 90 org.eclipse.core.contenttype_3.7.700.v20200310-0218
> 85 org.eclipse.equinox.registry_3.8.700.v20200121-1457
> 76 org.eclipse.ui.workbench_3.118.100.v20200310-0123
> 
> Egit has still one of the most time consuming activators. Looking forward
> for the pending patches.

I'm a bit confused here. The numbers add up to a longer starting time for the mentioned bundles then before (2087 vs 2124ms).
Comment 40 Andrey Loskutov CLA 2020-03-17 04:22:43 EDT
(In reply to Sebastian Zarnekow from comment #39)
> I'm a bit confused here. The numbers add up to a longer starting time for
> the mentioned bundles then before (2087 vs 2124ms).

Sebastian, the numbers you see in this ticket are coming from some random startup measurements, they aren't systematic in any way, so just don't take them seriously.

It is like measuring the temperature with a random tool at random location and random time once a day and say "global warming is there" if the number increases or "thanks to Greta, the temperature is going down" if it decreases.
Comment 41 Lars Vogel CLA 2020-03-17 05:37:55 EDT
(In reply to Andrey Loskutov from comment #40)
> (In reply to Sebastian Zarnekow from comment #39)
> > I'm a bit confused here. The numbers add up to a longer starting time for
> > the mentioned bundles then before (2087 vs 2124ms).
> 
> Sebastian, the numbers you see in this ticket are coming from some random
> startup measurements, they aren't systematic in any way, so just don't take
> them seriously.
> 
> It is like measuring the temperature with a random tool at random location
> and random time once a day and say "global warming is there" if the number
> increases or "thanks to Greta, the temperature is going down" if it
> decreases.

Andrey, feel free to provide more reliable numbers based on your own measurements. I have not seen that yet.
Comment 42 Andrey Loskutov CLA 2020-03-17 05:55:39 EDT
(In reply to Lars Vogel from comment #41)
> (In reply to Andrey Loskutov from comment #40)
> > (In reply to Sebastian Zarnekow from comment #39)
> > > I'm a bit confused here. The numbers add up to a longer starting time for
> > > the mentioned bundles then before (2087 vs 2124ms).
> > 
> > Sebastian, the numbers you see in this ticket are coming from some random
> > startup measurements, they aren't systematic in any way, so just don't take
> > them seriously.
> > 
> > It is like measuring the temperature with a random tool at random location
> > and random time once a day and say "global warming is there" if the number
> > increases or "thanks to Greta, the temperature is going down" if it
> > decreases.
> 
> Andrey, feel free to provide more reliable numbers based on your own
> measurements. I have not seen that yet.

Lars, the reason I don't provide the numbers is simple - I don't work on this topic, and do not plan to. As I've mentioned already on one of the "optimization" bugs, Eclipse start times are OK for me, I don't care if it will start in 2 or 3 seconds. If the times would be around 15 - 30 seconds, it will be interesting for me again, but I haven't seen such times for ages now.

However, If *I* would work on improving startup time, I would *first* create a reproducible test scenario that can be executed ~100 times by script automatically (so that everyone could reproduce that), considering things like file system cache / Eclipse bundle cache, warm or cold startup, local or NFS mounted file system, SSD vs HDD, Java version, OS version, installed bundles etc. Anything else is not serious (computer) science for me.
Comment 43 Lars Vogel CLA 2020-03-17 06:25:39 EDT
Andrey, we have an open bug for providing a realible way of measuring startup time but so far no one was able to provide a good way. You are more then welcome to implement nan approach.

If you do not work on a topic or do not plan to or do not care you should stop criticism other people for doing their best to work on a topic which they find important. Otherwise your behaviour is IMHO bad for the community and against the behaviour guidelines for Eclipse projects.
Comment 44 Sebastian Zarnekow CLA 2020-03-17 06:32:31 EDT
Andrey provided sufficient hints on how to tackle the problem repeatedly in other tickets, too. If these are ignored, criticism is certainly allowed to be expressed.

But before this discussion becomes off-topic, the point remains: If the current method to produce measurements is the best we have so far, Lars, please shed some light onto the fact that the last batch of numbers adds up to a longer startup time than with the previous batch of numbers.

Previous: 2087ms
Now:      2124ms

How do you plan to cope with that? Iff this is the only criteria, wouldn't that imply that the most recent changes should be reverted?
Comment 45 Lars Vogel CLA 2020-03-17 06:50:34 EDT
Sebastian, improvement suggestions are always welcome if delivered without insulting others.

The OSGi startup number measurements can vary a bit from measurement to measurement. So they are currently only indicators for the performance of the individual plug-in activators. Total startup time reported by OSGi was varies a bit. 

Alex and Michael used profilers for their patches.
Comment 46 Lars Vogel CLA 2020-03-17 06:57:44 EDT
Should have been: Without insulting other people work
Comment 47 Andrey Loskutov CLA 2020-03-17 09:11:45 EDT
(In reply to Lars Vogel from comment #43)
> Andrey, we have an open bug for providing a realible way of measuring
> startup time but so far no one was able to provide a good way. You are more
> then welcome to implement nan approach.

Thanks, but I leave this work for those who want work on startup performance. As already mentioned, it is not a topic of interest for me now.

> If you do not work on a topic or do not plan to or do not care you should
> stop criticism other people for doing their best to work on a topic which
> they find important. 

I believe you mix criticism with feedback and review work. Not all patches from "people doing their best" should be merged just because that will make them happy. Not all comments should be left unanswered just because it will make someone uncomfortable with the truth.

I reviewed (and also vetoed) many patches in this area because they affect not only startup performance but also stability and proper functionality of Eclipse and I plan to continue with that work, to prevent such things like this one: bug 551147 comment 48 (among many others). I also will continue to reply on comments that aren't based on hard facts and claim something that can't be reproduced by anyone else, like comment 38.

> Otherwise your behaviour is IMHO bad for the community
> and against the behaviour guidelines for Eclipse projects.

I believe bug 551147 is BAD. Many other bugs that were introduced during various "optimizations" are bad. I wonder which guideline says that fixing or preventing such bugs is also bad, but maybe I've missed something.
Comment 48 Lars Vogel CLA 2020-03-17 09:33:26 EDT
(In reply to Andrey Loskutov from comment #47)
> (In reply to Lars Vogel from comment #43)

> I believe you mix criticism with feedback and review work. Not all patches
> from "people doing their best" should be merged just because that will make
> them happy. Not all comments should be left unanswered just because it will
> make someone uncomfortable with the truth.

Andrey, you said: "Sebastian, the numbers you see in this ticket are coming from some random startup measurements, they aren't systematic in any way, so just don't take them seriously."

Alex, Michael, Thomas and others spend time on tracing the startup. So the above statement is insulting to their work. All the above people a highly skilled and spend most likely a significant amount of work.

> I reviewed (and also vetoed) many patches in this area because they affect
> not only startup performance but also stability and proper functionality of
> Eclipse and I plan to continue with that work

Your work is highly appreciated. I also personally think I know you well and I'm happy I convinced you a long time ago to join the platform team and helped to receiving you to get committer status. I also see that you improved already a lot in delivering feedback to others, thank your for that. But your "aren't systematic in any way" statement ff shows that you will could improve in delivering your feedback to others.

Alex already resigned once from contributing to the Eclipse IDE because of harsh feedback. Given Alex technical excellence and skills I would like to avoid this again. As I helped you to overcome your issues with contributing to platform, I try to do the same for Alex (and others). I see my most important work for platform in recruiting people for platform which are better programmers when me and will continue to fight technical or social issues which may prevent this.
Comment 49 Andrey Loskutov CLA 2020-03-17 10:22:34 EDT
(In reply to Lars Vogel from comment #48)
> (In reply to Andrey Loskutov from comment #47)
> > (In reply to Lars Vogel from comment #43)
> 
> > I believe you mix criticism with feedback and review work. Not all patches
> > from "people doing their best" should be merged just because that will make
> > them happy. Not all comments should be left unanswered just because it will
> > make someone uncomfortable with the truth.
> 
> Andrey, you said: "Sebastian, the numbers you see in this ticket are coming
> from some random startup measurements, they aren't systematic in any way, so
> just don't take them seriously."
> 
> Alex, Michael, Thomas and others spend time on tracing the startup. So the
> above statement is insulting to their work. All the above people a highly
> skilled and spend most likely a significant amount of work.

I must be coming from a parallel universe. I'm talking about facts & serious working approach, you about insulting. If facts or systematic working model are insulting, so sorry, wrong profession chosen...

The numbers in this ticket aren't reproducible for anyone else except the authors, and even the authors will not be able to reproduce them now. Making any conclusions out of such numbers is highly dangerous!

Comment 44 is the best example for that. If we would be serious and systematic in our working model, we would immediately revert the patches that were submitted before, because we see an obvious regression.

But no one reverts anything - this means, the numbers in this ticket are NOT perceived as serious or systematic, and this just confirms my conclusion in comment 40.

We don't revert patches even if we see a clear regression in numbers - why? We should at least try to explain why the higher overall startup time is coming from and why it should be better now as before, but even this doesn't happen, instead I'm accused to write insulting comments.

I would have no objections here if I would see numbers coming from *series* of measurements taken by automated script or test (that everyone could use to verify the measurements) and showing comparable median results for at least two different systems.
Comment 50 Lars Vogel CLA 2020-03-17 10:30:32 EDT
(In reply to Andrey Loskutov from comment #49)

> We don't revert patches even if we see a clear regression in numbers - why?
> We should at least try to explain why the higher overall startup time is
> coming from and why it should be better now as before, but even this doesn't
> happen, instead I'm accused to write insulting comments.

Please read again comment #45 for your content question. 

If you earlier tried  to say "the numbers provides by Lars from the OSGi startup reporting can sometimes vary and therefore the total status number reported is also not deterministic" than we can agree. And I believe this way to expression would be so much better to "the numbers you see in this ticket are coming from some random startup measurements, they aren't systematic in any way, so just don't take them seriously." as this includes also the trace numbers provided by others. For example, https://bugs.eclipse.org/bugs/show_bug.cgi?id=560412#c16
Comment 51 Lars Vogel CLA 2020-03-17 10:40:34 EDT
Andrey, I suggest to close our dispute here to avoid spamming the rest and either move to personal email if you still feel to discuss this with me. My understand: we both still agree that startup numbers provided by OSGi are not reliable and only an indicator, see Bug 550208 opened 2019-08-19 08 by me.
Comment 52 Lars Vogel CLA 2020-05-22 07:47:30 EDT
We have two wip Gerrits for this issue. Can they be finished?
Comment 53 Alex Blewitt CLA 2020-05-22 08:18:19 EDT
At least one of the WIP issues was looking at moving this to DS ... while the approach is sound, it needed some further investigation as to whether the services needed to be started immediately or not. I had planned to come back to this and replace it with a DS component but will see how much time I can get in before we hit a late RC stage; otherwise, it might be worth moving this to the next release.
Comment 54 Lars Vogel CLA 2020-05-22 08:57:03 EDT
(In reply to Alex Blewitt from comment #53)
> At least one of the WIP issues was looking at moving this to DS ... while
> the approach is sound, it needed some further investigation as to whether
> the services needed to be started immediately or not. I had planned to come
> back to this and replace it with a DS component but will see how much time I
> can get in before we hit a late RC stage; otherwise, it might be worth
> moving this to the next release.

Thanks Alex, looking forward to your update. I don't feel strongly about this or next release, with the 3 months release cycle everythings comes really fast to the end user.
Comment 55 Eclipse Genie CLA 2021-02-15 06:02:51 EST
New Gerrit change created: https://git.eclipse.org/r/c/egit/egit/+/176260
Comment 57 Thomas Wolf CLA 2021-03-13 12:17:16 EST
Closing this now. If there are any problems, please open separate new issues.