Maoni's WebLog

The Defrag Tools Channel9 series on managed memory diagnostics

2013-04-06T00:54:56Z

Recently I did a few videos for the popular "Defrag Tools" series on Channel9. They are just talking about pretty basic things about doing managed memory investigations so I'd imagine for most of you it's something you already know. However, you can feel free to suggest things you'd like to see in the comments of these videos (or on this blog for that matter :-)). 2 have aired:

http://channel9.msdn.com/Shows/Defrag-Tools/Defrag-Tools-33-CLR-GC-Part-1

http://channel9.msdn.com/Shows/Defrag-Tools/Defrag-Tools-34-CLR-GC-Part-2

What's new in GC in CLR 4.5 from our team blog

2012-07-24T01:27:12Z

This is now live from CLR's team blog. This paints a more complete picture than what I talked about in my "What's new in 4.5 GC" Channel 9 interview which mostly focused on Server Background GC.

http://blogs.msdn.com/b/dotnet/archive/2012/07/20/the-net-framework-4-5-includes-new-garbage-collector-enhancements-for-client-and-server-apps.aspx

Enjoy!

So, what's new in the CLR 4.5 GC?

2011-09-22T00:49:19Z

Last time I posted a "So, what's new" entry was when we release 4.0 ~3 years ago (can't believe it's already been that long..). Now I get to talk about what's new in the 4.5 GC. Actually I just talked about this with Channel 9 and here's the link to the video: http://channel9.msdn.com/posts/Maoni-Stephens-CLR-45-Server-Background-GC

Enjoy!

Finalization Uncovered

2010-11-15T23:38:00Z

I’ve talked about finalization before but based on seeing questions related to it it appears that it deserves some clarification.

First of all, finalization is a mechanism we provide in the CLR wheras Dispose is a programming pattern. See Clearing up some confusion over finalization and other areas in GC for an explanation why we provide finalization. Inside of the GC, it’s completely not aware of Dispose. People often call GC.SuppressFinalize in their Dispose implementation but that’s just a choice they make when they write code. I will explain exactly what GC.SuppressFinalize does in a bit. Oh and I am not the owner of the “Dispose pattern” J

So what happens when you allocate an object with a finalizer? GC’s allocator will get called and it’s told this object is finalizable. So if GC can successfully allocate this object it will then record that this is a finalizable object. GC maintains a list to record finalizable objects so a new object will be in the gen0 part of that list. Recording just means writing the object address X to an entry in the gen0 part.

When GC promotes a finalizable object to another generation, it’ll move its address to the part of the list for that generation. Of course when the object is compacted we also need to update the entry in the finalize list with the new address.

When GC finishes marking objects, ie, it has determined which ones should be live, it will look at the list for the generation it’s collecting see if those objects are dead. For the dead ones it will then promote that object and move the address to the part of the list that’s for “ready for finalization” objects. If any of such objects are found, GC will signal to the finalizer thread that there’s work to do.

When the managed threads are restarted after GC is done, since the finalizer thread is also a managed thread, it also gets restarted and starts to do its work – running finalizers. It does this by asking for the entries in the “ready for finalization” part of the list. Those entries are removed from the list as the objects’ finalizers are run.

If you do a !finalizequeue you will see output like this:

0:015> !finalizequeue

SyncBlocks to be cleaned up: 0

MTA Interfaces to be released: 0

STA Interfaces to be released: 0

----------------------------------

------------------------------

Heap 0

generation 0 has 971 finalizable objects (000000000e31b958->000000000e31d7b0)

generation 1 has 346 finalizable objects (000000000e31ae88->000000000e31b958)

generation 2 has 139 finalizable objects (000000000e31aa30->000000000e31ae88)

Ready for finalization 0 objects (000000000e31d7b0->000000000e31d7b0)

------------------------------

Heap 1

generation 0 has 2686 finalizable objects (000000000d41aa10->000000000d41fe00)

generation 1 has 473 finalizable objects (000000000d419b48->000000000d41aa10)

generation 2 has 129 finalizable objects (000000000d419740->000000000d419b48)

Ready for finalization 0 objects (000000000d41fe00->000000000d41fe00)

------------------------------

Heap 2

generation 0 has 319 finalizable objects (000000000d298298->000000000d298c90)

generation 1 has 302 finalizable objects (000000000d297928->000000000d298298)

generation 2 has 241 finalizable objects (000000000d2971a0->000000000d297928)

Ready for finalization 0 objects (000000000d298c90->000000000d298c90)

------------------------------

Heap 3

generation 0 has 147 finalizable objects (000000000c982998->000000000c982e30)

generation 1 has 432 finalizable objects (000000000c981c18->000000000c982998)

generation 2 has 147 finalizable objects (000000000c981780->000000000c981c18)

Ready for finalization 0 objects (000000000c982e30->000000000c982e30)

As you can see, there are “Finalizable” objects and “Ready for finalization” objects, as we talked about above.

It’s very common to see 0 “Ready for finalization” objects. Why? Because the finalizer thread runs at THREAD_PRIORITY_HIGHEST. As soon as managed threads are resumed it’s the first to run unless you have other threads of the same or higher priority. Finalizers usually do very little work so it shouldn’t be long before the finalizers are run. If there’s another GC happening (other threads can still run and allocate if you have more than 1 CPU), if there are still “Ready for finalization” entries, we need to make sure those objects are promoted.

So what happens when you call GC.SuppressFinalize on an object? It just sets a bit for this object that tells the GC to not do the operations it would do for a finalizable object it finds dead, in other words, when GC scans the finalizable objects when it sees that bit is set, it will treat it as if it was not a finalizable object (so the object will be considered completely dead at this point and we will no longer remember it in our “Finalizable” portion of the list).

When you call GC.ReRegisterForFinalize we will check to see if that bit is set, if it’s we simply clear it. Otherwise we will ask GC to insert it in the “Finalizable” portion of the list.

Debugging with the Right Tools

2010-04-24T03:01:00Z

Wow, it’s been almost a year since I last blogged J We just shipped CLR V4.0. Yay!

An internal email thread prompted me to write this blog entry – one very powerful tool I wanted to point out when you need to debug/investigate issues is your debugger (if your debugger is also windbg/cdb that is J since that’s what I use and that’s what I will talk about in this article).

For those of you who are interested in investigating memory related issues at all, whether it’s because you don’t like your current app’s memory usage or you simply want to improve, learning to use the debugger is invaluable. If you haven’t started using windbg/cdb, I would strongly encourage you to – I promise you won’t regret it.

I’ve talked about using SoS before. We’ve added some more SoS commands in V4.0 and some of those are related to GC like !AnalyzeOOM, !GCWhere and !FindRoots. You can read about them on the MSDN page. But I wanted to talk about some techniques that may not be obvious from reading reference material.

What do you want to know about GC when your program is? 2 of the most common things are

1) Why are GCs being triggered?

2) Why do GCs take this much time?

And the answers are, respectively:

1) The difference of the heap before and after a GC

2) The survivors from that GC

Let me explain those in detail. Each generation has its own allocation budget which I explained here. It’s a value that we set and when exceeded we’d want to trigger a GC. If we do a collection and discovered that there’s a lot of memory survived we would set this allocation budget very big which means you’d need to allocate more into that generation for us to want to trigger a GC. The rationale is that then we’d have a chance to reclaim some sizeable space back next time we do a GC. Otherwise we’d do all this work for a GC and not be able to find much dead memory.

So if you do a !dumpheap right before a GC you see what objects you have; then you do a !dumpheap right after that GC you see some of those objects disappeared. It’s those objects that triggered this GC. Why? ‘cause if we didn’t have any objects disappearing, we wouldn’t be doing GC (‘cause we’d get no dead space back). When you hear people say “you are doing gen2 GCs because you are churning gen2” this is preciously the explanation for that.

As of now, the CLR GC doesn’t compact the LOH. So if you want to look at the LOH you can see exactly which parts of the memory disappeared. Here’s a sample output of a heap range before and after a gen2 GC. Before the gen2 GC (I formatted the !dumpheap with the methodtable pointer replaced with their readable names):

Address MethodTable Size

--------------------------------------------------

00000007f7ffe1e0 System.Byte[] 2,080,000

00000007f81f9ee0 System.String 100,000

00000007f8212580 System.Byte[] 140,000

After this gen2 GC for the same heap range:

Address MethodTable Size

--------------------------------------------------

00000007f7ffe1e0 Free 2,320,000

So those 3 objects were collected. As the application author those objects may very well ring a bell for you why they were allocated so you can go from there see if/how you can do some optimizations.

The survivors from the collection are what you see in the output of !dumpheap at the end of that GC.

In this MSDN article I talked about how to set a breakpoint at the end of a gen2 GC. To set a bp at the beginning of a gen2 GC simply replace RestartEE with SuspendEE. If you want to do this for gen0 GCs, replace 2 with 0. Note that this applies to only non concurrent/background GCs though since concurrent/background GCs would not have the EE suspended for the most part.

Often I see people quickly go search for some other tools when they really could whip out the debugger and set a few breakpoints to see what things look like. Of course there are many useful tools out there – and they tend to aggregate info for you so you don’t have to do that yourself – but sometimes it’s so convenient to just use the most direct and handy tool which is your debugger.

Another classic example is when people ask me for help with debugging memory leaks and the easiest and quickest solution is to set a conditional bp on kernel32!VirtualAlloc for native memory leaks. I’ve seen this over and over again and this is how the conversation would usually go:

someone, “Maoni, I have a managed app that’s leaking memory. Can you help me with it?”

me, “Is it a managed memory leak?”

someone, “I don’t know.”

me, “How big is your managed heap? Can you do the SoS !dumpheap command?”

someone, “it’s only X MBs” [but his whole process uses much more than that]

me, “Does it grow? If you run your app for a while does the managed heap size change?”

someone, “No” (or “Not much, not nearly as much as the whole memory usage increases”)

me, “Can you take a look at your virtual memory address space by doing !address?” [!address gives you info on each virutal memory chunk. It’s also a windbg/cdb debugger extension but it’s in ext.dll which comes with the debugger package.]

someone, “It looks like there’re a lot of chunks of size S…”

me, “Can you set a conditional bp on kernel32!VirtualAlloc when the allocate size is S?” [Which means: bp kernel32!virtualalloc ".if (@edx==S) {kp} .else {g}"]

[some time elapses]

someone, “It looks like they all have the same callstack!!!”

At this point it’s clear what causes their memory leak.

If you need to see continuous output of some commands without disturbing the process too much you can always log it to a file (.logopen c:\mydebugsession.txt) and analysis the log after the process runs for a while.

As I mentioned there are tools that will aggregate this info for you (eg, the DebugDiag tool you can find on microsoft.com which shows you the aggregated callstack from all the VirtualAlloc calls) but if you’ve never used those tools it may take a while to set them up and learn how to use them. The debugger is something you have right there and use all the time so it’s something you can fairly conveniently solve with a debugger I tend to use that.

Channel9 Video on Background GC

2009-05-27T01:16:00Z

A couple of weeks back my PM and I did a channel9 video on Background GC. Take a look:

http://channel9.msdn.com/shows/Going+Deep/Maoni-Stephens-and-Andrew-Pardoe-CLR-4-Inside-Background-GC/

So, what’s new in the CLR 4.0 GC?

2008-11-20T04:02:00Z

PDC 2008 happened not long ago so I get to write another “what’s new in GC” blog entry. For quite a while now I’ve been working on a new concurrent GC that replaces the existing one. And this new concurrent GC is called “background GC”.

First of all let me apologize for having not written anything for so long. It’s been quite busy working on the new GC and other things.

Let me refresh your memory on concurrent GC. Concurrent GC has existed since CLR V1.0. For a blocking GC, ie, a non concurrent GC we always suspend managed threads, do the GC work then resume managed threads. Concurrent GC, on the other hand, runs concurrently with the managed threads to the following extend:

§ It allows you to allocate while a concurrent GC is in progress.

However you can only allocate so much – for small objects you can allocate at most up to end of the ephemeral segment. Remember if we don’t do an ephemeral GC, the total space occupied by ephemeral generations can be as big as a full segment allows so as soon as you reached the end of the segment you will need to wait for the concurrent GC to finish so managed threads that need to make small object allocations are suspended.

§ It still needs to stop managed threads a couple of times during a concurrent GC.

During a concurrent GC we need to suspend managed threads twice to do some phases of the GC. These phases could possibly take a while to finish.

We only do concurrent GCs for full GCs. A full GC can be either a concurrent GC or a blocking GC. Ephemeral GCs (ie, gen0 or gen1 GCs) are always blocking.

Concurrent GC is only available for workstation GC. In server GC we always do blocking GCs for any GCs.

Concurrent GC is done on a dedicated GC thread. This thread times out if no concurrent GC has happened for a while and gets recreated next time we need to do concurrent GC.

When the program activity (including making allocations and modifying references) is not really high and the heap is not very large concurrent GC works well – the latency caused by the GC is reasonable. But as people start writing larger applications with larger heaps that handle more stressful situations, the latency can be unacceptable.

Background GC is an evolution to concurrent GC. The significance of background GC is we can do ephemeral GCs while a background GC is in progress if needed. As with concurrent GC, background GC is also only applicable to full GCs and ephemeral GCs are always done as blocking GCs, and a background GC is also done on its dediated GC thread. The ephemeral GCs done while a background GC is in progress are called foreground GCs.

So when a background GC is in progress and you’ve allocated enough in gen0, we will trigger a gen0 GC (which may stay as a gen0 GC or get elevated as a gen1 GC depending on GC’s internal tuning). The background GC thread will check at frequent safe points (ie, when we can allow a foreground GC to happen) and see if there’s a request for a foreground GC. If so it will suspend itself and a foreground GC can happen. After this foreground GC is finished, the background GC thread and the user threads can resume their work.

Not only does this allow us to get rid of dead objects in young generations, it also lifts the restriction of having to stay in the ephemeral segment – if we need to expand the heap while a background GC is going on, we can do so in a gen1 GC.

We also made some performance improvement in background GC which does better at doing more things concurrently so the time we need to suspend managed threads is also shorter.

We are not offering background GC for server GC in V4.0. It’s under consideration – we recognize how important it is for server applications (which usually have much larger heaps than client apps) to benefit from smaller latency but the work did not fit in our V4.0 timeframe. For now for server applications, I would recommend you to look at the full GC notification feature we added in .NET 3.5 SP1. It’s explained here: http://msdn.microsoft.com/en-us/library/cc713687.aspx. Basically you register to get notified when a full GC is approaching and when it’s finished. This allows you to do software load balancing between different server instances – when a full GC is about to happen in one of the server instances, you can redirect new requests to other instances.

64-bit vs 32-bit

2007-05-15T16:40:00Z

As 64-bit machines become more common, the problems we need to solve also evolve. In this post I’d like to talk about what it means for the GC and the applications’ memory usage when we move from 32-bit to 64-bit.

One big limitation of 32-bit is the virtual memory address space - as a user mode process you get 2GB, and if you use large address aware you get 3GB. A few years these seemed like giant numbers but I've seen as more and more people start using .NET framework, the sizes of the managed heap go up at a quite high rate. I remember when I first started working on GC (which was late 2004 I think) we were talking about hundreds of MBs of heaps - 300MB seemed like a lot. Today I am seeing managed heaps easily of GBs in size - and yes, some of them (and more and more of them) are on 64-bit - 2 or 3GB is just not enough anymore.

And along with this, we are shifting to solving a different set of problems. In CLR 2.0 we concentrated heavily on using the VM space efficiently. We tried very hard to reduce the fragmentation on the managed heap so when you get a hold of a chunk of virtual memory you can make very efficient use of it. So people don't see problems like they have N managed heap segments, are running out of VM, yet many of these segments are quite empty (meaning having a lot of free space on them).

Then you switch to 64-bit. Now suddenly you don't need to worry about VM anymore - you get plenty there. Practically unlimited for many applications (of course it’s still limited – for example if you are running out physical memory to even allocate the datastructures for virtual pages then you still can’t reserve those pages). What kind of differences will you see in your managed memory usage?

First of all, your process consumes more memory - I am sure all of you are already aware of this - the pointer size is bigger - it's doubled on 64-bit so if you don't change anything at all, now your managed heap (which undoubtly contains references) is bigger. Of course being able to manipulate memory in QWORDs instead of DWORDs can also be beneficial –our measurements show that the raw allocation speed is slightly higher on 64-bit than on 32-bit that can be attributed to this.

There are other factors that could make your process consume more memory - for example the module size is bigger (mscorwks.dll is about 5MB on x86, 10MB on x64 and 20MB on ia64), instructions are bigger on 64-bit and what have you.

Another thing you may notice - if you have looked at the performance counters under .NET CLR Memory - is that you are now doing a lot fewer GCs on 64-bit than what you used to see on 32-bit.

The curious minds might have already noticed one thing - the managed heap segments are much bigger in size on 64-bit. If you do !SOS.eeheap -gc you will now see way bigger segments.

Why did we make the segment size so much bigger on 64-bit? Well, remember we talked about in Using GC Efficiently Part 2 how we have a budget for gen0 and when you've allocated more than this budget a GC will be triggered. When you have a bigger budget it means you’ll need to do fewer GCs which means your code will get more chance to run. From this perspective you should get a performance gain when you move to 64-bit - I want to emphasize the “this perspective” part because in general things tend to run slower on 64-bit. The perf benefit you get because of GC may very well be obscured by other perf degrades. In reality many people are not expecting perf gain when they move to 64-bit but rather they are happy with being able to use more memory to handle more work load.

Of course we also don’t want to wait for too long before we collect – we strive for the right balance between memory (how much memory your app consumes) and CPU (how often user threads run).

He’s live… he’s live not… he’s live…

2007-03-21T08:17:00Z

I was making some code changes today and thought this was interesting to share. As you know, the WeakReference class has a getter and a setter method to get and set the Target which is what the weakref points to. See Using GC Efficiently – Part 3 for more details on WeakReference.

Note that the code below is only for illustration purposes – it is not necessarily what’s in the production code.

So let’s say the code used to look like this in the WeakReference class:

internal IntPtr m_handle;

public Object Target

{

get

{

IntPtr h = m_handle;

if (IntPtr.Zero == h)

return false;

Object o = GCHandle.InternalGet(h);

h = Thread.VolatileRead(ref m_handle);

GC.KeepAlive (this);

return (h == IntPtr.Zero) ? null : o;

}

...

}

m_handle is the weak GCHandle that we create to implemente the weakref funtionality. It’s a weak handle that points to the object that you want your weakref object to point to.

The problem is Thread.VolatileRead kind of a heavy weight thing - not very performant (there was a reason why we used this API in the first place…not necessarily a good one but it’s what we ended up with).

First of all let’s take a look at the old code. Notice that we have a GC.KeepAlive in there. Why would we do that? I mean if during the call of Thread.VolatileRead, the weakref object is dead and its finalizer sets m_handle to 0, we’d just read 0. That’s fine right?

But imagine this code:

Object o = new Object();

while (true)

{

WeakReference wr = new WeakReference (o);

if (wr.Target == null)

{

...

}

o.GetHashCode();

We know that o is live during the while loop which means it would be really nice if wr.Target is null (some would consider it a bug if wr.Target was ever null in this case). If we didn’t have the KeepAlive, object wr could be considered dead as soon as its address is passed in to the Thread.VolatileRead call as the argument. So then h could be 0 and we’d return null. So we want to make sure that if the object the weakref points to is guaranteed to be live during the getter call, you will always get back that object instead of null.

Wouldn’t that achieve the same effect since m_handle is an instance data member and if it’s used, the *this* object should be kept alive where the last statement is?

Well, actually since m_handle is not a volatile, jit could generate some code that stores the value of m_handle in a register so it will not need to read the value of m_handle again when it’s at that last statement.

Another interesting thing about this code is that it does the IntPtr.Zero check after it first read the value of m_handle. But how can m_handle be 0? m_handle is only set to 0 in the WeakReference class’s finalizer code. If we are already KeepAlive-ing the weakref object, it means the object should be live therefore by definition the finalizer should have not been run, right?

Well, unfortunately there is a case where m_handle can be 0 while we are in the getter which is when the getter is called in an object’s finalizer. Imagine you have this object hireachy:

public class ObjectA

{

WeakReference wr;

public ObjectA(WeakReference wr0)

{

...

wr = wr0;

}

...

public ~ObjectA()

{

...

if (wr.Target == null)

{

...

}

...

}

ObjectA a = new ObjectA();

When a is not used anymore, at some point both a’s and wr0’s finalizer (assuming a is the only object that contains a reference to wr0) will be put on the finalize queue.

Now if a’s finalizer gets to run first, we are fine ‘cause when we are in wr0’s getter, m_handle is still valid. But if wr0’s finalizer gets to run first, then when a’s finalizer is run, m_handle is already set to 0. Of course as we’ve been saying that a finalizer should do no more than releasing native resources, this shouldn’t be a common scenario.

So, the idea is to change m_handle to volatile and eliminate the need for calling Thread.VolatileRead. The resulting code looks like this:

internal volatile IntPtr m_handle;

public Object Target

{

get

{

IntPtr h = m_handle;

if (IntPtr.Zero == h)

return null;

Object o = GCHandle.InternalGet(h);

return (m_handle == IntPtr.Zero) ? null : o;

}

...

}

Notice that KeepAlive is gone because we are reading a volatile value which means the weakref object will be kept alive though out the getter. We still need to check if h is IntPtr.Zero at the beginning because we are still subject to be called from another object’s finalizer.

Some people don’t use volatile’s in fear of losing performance ‘cause volatile’s can’t be optimzed by the compiler. In reality though, if you read the volatile into a local when you need to access it frequently and that you are fine with the cached value, no reason to be afraid of using volatile’s.

Difference Between Perf Data Reported by Different Tools – 4

2007-01-12T08:03:00Z

.NET CLR Memory\% Time in GC counter and !runaway on thread(s) doing GC.

The 2 common ways people use to look at the time spent in GC are the % Time in GC performance counter under .NET CLR Memory, and the CPU time displayed by the !runaway debugger command in cdb/windbg. What do they mean exactly? % Time in GC is calculated like this:

When the n^thGC starts (ie, after the managed threads are suspended and before the GC work starts), we record the timestamp at that time. Let’s call this TA(n);

When n^thGC ends (ie, after the GC work is done and before we resume the managed threads), we record another timestamp. Let’s call this TB(n);

So Time spent in this GC is TB(n) – TA(n). And the time since the last GC ended is TB(n) – TB(n-1). So % Time in GC is (TB(n) – TA(n)) / (TB(n) – TB(n-1)).

Since we only record the timestamps we don’t actually discount the time when the thread was switched out – for example, if you are on a single proc machine and another process has a thread of the same priority (as the thread that’s doing GC) that’s also ready to run it may take away some time from the thread that’s doing the GC. None the less it’s a good approximation.

One common scenario where it’s not a good approximation is when paging occurs. In this case you will see a very high % Time in GC but really the time that’s actually spent doing GC work is low ‘cause most of the time is spent doing IO. To verify if you hit this case you can look at the Memory\Pages/sec to see how much it’s paging.

!runaway is more accurate in the sense that it does record the actual time spent on the threads. However I did observe 2 common mistakes when using !runaway to look at time spent in GC.

1) mistake “time spent on the GC thread(s)” as “time spent in GC”.

Let’s take Server GC as an example. When a GC is needed the GC threads first perform the suspension work. Obviously this takes time. Sometimes it can take quite a bit time if you have many threads or some threads get stuck and it takes a long time to suspend them.

2) using the current !runaway output to judge how much time GC has taken without taking into count that some user threads have died. Besides looking at the User/Kernel Mode time you may want to also look at Elapsed Time. The following output is from one of the issues I looked at:

Elapsed Time

Thread Time

0:2094 0 days 11:57:10.406

1:2098 0 days 11:57:10.152

2:2044 0 days 11:57:09.898

3:27cc 0 days 11:57:09.882

4:20c0 0 days 11:57:09.597

13:810 0 days 11:57:09.565

12:21d4 0 days 11:57:09.565

11:2308 0 days 11:57:09.565

10:1d24 0 days 11:57:09.565

9:23e0 0 days 11:57:09.565

8:24d0 0 days 11:57:09.565

7:2168 0 days 11:57:09.565

6:2134 0 days 11:57:09.565

5:2124 0 days 11:57:09.565

14:570 0 days 11:57:08.582

15:10fc 0 days 11:57:00.000

16:1ac4 0 days 11:56:58.256

17:1900 0 days 11:56:58.176

18:1624 0 days 11:56:57.494

19:11f8 0 days 10:35:01.881

21:1620 0 days 0:41:45.017

22:1cc8 0 days 0:37:30.496

23:2de0 0 days 0:29:01.820

24:2e10 0 days 0:29:01.711

25:2d88 0 days 0:22:26.988

26:1668 0 days 0:19:26.175

27:2cb0 0 days 0:16:16.814

29:2d1c 0 days 0:11:53.779

28:1de8 0 days 0:11:53.779

30:2ed4 0 days 0:11:35.466

32:2030 0 days 0:11:22.544

31:2084 0 days 0:11:22.544

33:12b0 0 days 0:07:53.510

35:28e4 0 days 0:03:13.801

34:2654 0 days 0:03:13.801

36:2d68 0 days 0:02:31.988

The orange lines are GC threads. They were created about 12 hours ago. The green lines are user threads and they were created 2 mins to 40mins ago. So naturally at the current state these user threads couldn’t’ve spent much time.