thread heap leak?

thread heap leak?

[David Muse]

Hello all,

I've been chasing a series of strange bugs for months now, and I hope someone can shed some light on it.

We have this little server program that listens for client connections on an inet socket.  When it receives a connection, it pthread_create()'s a detached thread to handle the request and the main thread waits for more client connections.

The child thread talks to the client, and usually forks off a new process to handle the client request.  It then relays data back and forth between the child process' stdin/stdout and the client.  Eventually the process exit()'s, and the thread pthread_exit()'s.

This program has run with no problems for like 6 years.  We recently started deploying it to Amazon AWS and ran into all kinds of trouble.


We originally encountered the fork+malloc error, and the program would crash 4 or 5 times per day.  We upgraded to glibc-2.28 to solve that.  By upgraded, I mean that we compiled glibc-2.28 and are running the program by manually invoking the dynamic loader like this:

/opt/glibc-2.29-runtime/lib/ld-2.28.so --library-path /opt/glibc-2.28-runtime/lib:/lib64:/usr/lib64 ./proxy -port 3490

This solved the fork+malloc error.

However, we then started noticing what appeared to be a memory leak.  Valgrind counldn't find anything though, and we eventually discovered that anyonymous heap segments were piling up.  For example:

/proc/943/maps:
...
ibc-2.29-runtime/lib/libc-2.29.so
2b933f891000-2b933fa91000 ---p 001e0000 103:01 487930                    /opt/glibc-2.29-runtime/lib/libc-2.29.so
2b933fa91000-2b933fa95000 r--p 001e0000 103:01 487930                    /opt/glibc-2.29-runtime/lib/libc-2.29.so
2b933fa95000-2b933fa97000 rw-p 001e4000 103:01 487930                    /opt/glibc-2.29-runtime/lib/libc-2.29.so
... these "anonymous" segments ...
2b933fa97000-2b933fa9b000 rw-p 00000000 00:00 0 
2b933fa9b000-2b933fa9c000 ---p 00000000 00:00 0 
2b933fa9c000-2b933fc9c000 rw-p 00000000 00:00 0 
2b933fc9c000-2b933fc9d000 ---p 00000000 00:00 0 
2b933fc9d000-2b933fe9d000 rw-p 00000000 00:00 0 
2b9340000000-2b934007f000 rw-p 00000000 00:00 0 
2b934007f000-2b9344000000 ---p 00000000 00:00 0 
2b9344000000-2b9344032000 rw-p 00000000 00:00 0 
2b9344032000-2b9348000000 ---p 00000000 00:00 0 
2b9348000000-2b9348001000 ---p 00000000 00:00 0 
2b9348001000-2b9348201000 rw-p 00000000 00:00 0 
2b9348201000-2b9348202000 ---p 00000000 00:00 0 
2b9348202000-2b9348402000 rw-p 00000000 00:00 0 
2b9348402000-2b9348403000 ---p 00000000 00:00 0 
2b9348403000-2b9348603000 rw-p 00000000 00:00 0 
2b9348603000-2b9348604000 ---p 00000000 00:00 0 
2b9348604000-2b9348804000 rw-p 00000000 00:00 0 
2b934c000000-2b934c023000 rw-p 00000000 00:00 0 
2b934c023000-2b9350000000 ---p 00000000 00:00 0 
2b9350000000-2b9350021000 rw-p 00000000 00:00 0 
2b9350021000-2b9354000000 ---p 00000000 00:00 0 
2b9354000000-2b9354084000 rw-p 00000000 00:00 0 
2b9354084000-2b9358000000 ---p 00000000 00:00 0 
2b9358000000-2b9358021000 rw-p 00000000 00:00 0 
2b9358021000-2b935c000000 ---p 00000000 00:00 0 
7fff8287e000-7fff8289f000 rw-p 00000000 00:00 0                          [stack]
7fff828f4000-7fff828f7000 r--p 00000000 00:00 0                          [vvar]
7fff828f7000-7fff828f9000 r-xp 00000000 00:00 0                          [vdso]
ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0                  [vsyscall]


After quite a bit of googling, I discovered the name of these segments: "anonymous" segments, and that they are used for various things, including mmapping chunks of files, and thread stacks.

Over time, we get more and more of them until top shows the app's VIRT to be around 4G (I think, maybe just 2G).  Then it crashes.  The RES is never more than a few MB.

Upgrading to glibc 2.29 dramatically reduced this behavior, but the heap still grows and every 4 or 5 days the app crashes.

Any ideas what might be going on?

Thanks!

David Muse
david.muse@firstworks.com

Re: thread heap leak?

[Carlos O'Donell]

On 3/22/19 10:53 AM, David Muse wrote:
> We have this little server program that listens for client
> connections on an inet socket.  When it receives a connection, it
> pthread_create()'s a detached thread to handle the request and the
> main thread waits for more client connections.

The stack for the detached thread is recoverable only if the thread
exits, at which point it calls 	__free_tcb () (only if detached,
because otherwise only pthread_join() does this recovery), enqueues
the stack onto the free list and leaves it there. Subsequent thread
creation attemps to reuse the stack, but must wait for the kernel
to clear the registered tid memory (CLONE_CHILD_CLEARTID) to mark
the stack reusable (FREE_P). The total size of the thread stack
cache should only be ~40MiB, and new stack creation triggers an
automatic check to trim this cache back down to 40MiB.

Have you been able to reduce this to a smaller test case?

The anonymous mappings might indeed be thread stacks, but you'd
have to verify that yourself, and you can do that by asking the
thread for the stack information and printing that.

Are you using Amazon Linux or a known distro upstream?

-- 
Cheers,
Carlos.

Re: thread heap leak?

[Florian Weimer]

* David Muse:

> Over time, we get more and more of them until top shows the app's VIRT
> to be around 4G (I think, maybe just 2G).  Then it crashes.  The RES
> is never more than a few MB.

Do you have backtraces from the crash?  How did you determine that the
crashes and the anonymous mappings are related?

How do you launch the detached threads?  Do you use any other thread
attributes?

Re: thread heap leak?

[David Muse]

On Fri, 22 Mar 2019 13:03:51 -0400
"Carlos O'Donell" <codonell@redhat.com> wrote:

> On 3/22/19 10:53 AM, David Muse wrote:
> > We have this little server program that listens for client
> > connections on an inet socket.  When it receives a connection, it
> > pthread_create()'s a detached thread to handle the request and the
> > main thread waits for more client connections.
> 
> The stack for the detached thread is recoverable only if the thread
> exits, at which point it calls 	__free_tcb () (only if detached,
> because otherwise only pthread_join() does this recovery), enqueues
> the stack onto the free list and leaves it there. Subsequent thread
> creation attemps to reuse the stack, but must wait for the kernel
> to clear the registered tid memory (CLONE_CHILD_CLEARTID) to mark
> the stack reusable (FREE_P). The total size of the thread stack
> cache should only be ~40MiB, and new stack creation triggers an
> automatic check to trim this cache back down to 40MiB.
> 
> Have you been able to reduce this to a smaller test case?
> 
> The anonymous mappings might indeed be thread stacks, but you'd
> have to verify that yourself, and you can do that by asking the
> thread for the stack information and printing that.
> 
> Are you using Amazon Linux or a known distro upstream?
> 
> -- 
> Cheers,
> Carlos.
> 

I did comment out lots of features in the program to narrow down the problem, but I haven't been able to reproduce the leak in a compact test case.  I've been working on that though.

How do I get the stack information from the thread?  I know that I can do pthread_attr_getstacksize for the size, but what else can I get?

We're using OpenSUSE Leap 42.3.  I've seen the problem directly there.  I've gotten reports that it also occurs on RHEL 7, but I can't confirm that.

Thanks,

David
david.muse@firstworks.com

Re: thread heap leak?

[Carlos O'Donell]

On 3/22/19 1:39 PM, David Muse wrote:
> On Fri, 22 Mar 2019 13:03:51 -0400 "Carlos O'Donell"
> <codonell@redhat.com> wrote:
> 
>> On 3/22/19 10:53 AM, David Muse wrote:
>>> We have this little server program that listens for client 
>>> connections on an inet socket.  When it receives a connection,
>>> it pthread_create()'s a detached thread to handle the request and
>>> the main thread waits for more client connections.
>> 
>> The stack for the detached thread is recoverable only if the
>> thread exits, at which point it calls 	__free_tcb () (only if
>> detached, because otherwise only pthread_join() does this
>> recovery), enqueues the stack onto the free list and leaves it
>> there. Subsequent thread creation attemps to reuse the stack, but
>> must wait for the kernel to clear the registered tid memory
>> (CLONE_CHILD_CLEARTID) to mark the stack reusable (FREE_P). The
>> total size of the thread stack cache should only be ~40MiB, and new
>> stack creation triggers an automatic check to trim this cache back
>> down to 40MiB.
>> 
>> Have you been able to reduce this to a smaller test case?
>> 
>> The anonymous mappings might indeed be thread stacks, but you'd 
>> have to verify that yourself, and you can do that by asking the 
>> thread for the stack information and printing that.
>> 
>> Are you using Amazon Linux or a known distro upstream?
> 
> I did comment out lots of features in the program to narrow down the
> problem, but I haven't been able to reproduce the leak in a compact
> test case.  I've been working on that though.

Good luck :-)

> How do I get the stack information from the thread?  I know that I
> can do pthread_attr_getstacksize for the size, but what else can I
> get?

You can use pthread_getattr_np() to take a snapshot of the thread's
attributes and look at those, that will get you the information about
stack address location and size.

You should try using something like systemtap to put tap points on
your program and observe the behaviour of the detached threads.


> We're using OpenSUSE Leap 42.3.  I've seen the problem directly
> there.  I've gotten reports that it also occurs on RHEL 7, but I
> can't confirm that.

Andreas,

Have you seen reports like this?

-- 
Cheers,
Carlos.

Re: thread heap leak?

[David Muse]

On Fri, 22 Mar 2019 18:31:01 +0100
Florian Weimer <fw@deneb.enyo.de> wrote:

> * David Muse:
> 
> > Over time, we get more and more of them until top shows the app's VIRT
> > to be around 4G (I think, maybe just 2G).  Then it crashes.  The RES
> > is never more than a few MB.
> 
> Do you have backtraces from the crash?  How did you determine that the
> crashes and the anonymous mappings are related?
> 
> How do you launch the detached threads?  Do you use any other thread
> attributes?
> 

I've struggled to get backtraces.  The app has a crash-handler that prints a backttrace to the log, but that also crashes inside of a malloc.  Getting a core on the production system has been a challenge too.  I'll see if I can get that.

I'm not 100% sure that they are related.

I have a monitor running that does a top every 30 seconds or so.  The pattern is always that the app's VIRT grows to about 2G and then it crashes.  We figured it was a memory leak, so we started running it through valgrind.  We'd see the same memory usage, but valgrind would report no leaks, and only a few K of "still reachable" memory.  This was the same whether the app crashed, or whether we just killed it after a few hours.  I eventually noticed the anonymous segments in /proc/<pid>/maps, did some math on them, and them + [stack] roughly added up to the VIRT size.  So, I figured they were responsible for the VIRT growth.

It's not clear why the app is crashing at about 2G.  I'd think that a 64-bit process ought to be able to address more than that.  But, since it always crashes at that size, it seems like it's related.

Code to launch detached threads:

... main ...

	cs->threadattr=new pthread_attr_t;
	pthread_attr_init(cs->threadattr);
	pthread_attr_setdetachstate(cs->threadattr,PTHREAD_CREATE_DETACHED);
	...
	cs->threadhandle=new pthread_t;
	if (pthread_create(cs->threadhandle,cs->threadattr,
				(void *(*)(void *))clientThread,
				(void *)cs)) {
		... error handling ...
	}


... inside of clientThread() ...

        pthread_attr_destroy(cs->threadattr);
	...
	pthread_exit(NULL);


No other attributes.

Thanks!

David
david.muse@firstworks.com

Re: thread heap leak?

[Carlos O'Donell]

On 3/22/19 1:53 PM, David Muse wrote:
> On Fri, 22 Mar 2019 18:31:01 +0100
> Florian Weimer <fw@deneb.enyo.de> wrote:
> 
>> * David Muse:
>>
>>> Over time, we get more and more of them until top shows the app's VIRT
>>> to be around 4G (I think, maybe just 2G).  Then it crashes.  The RES
>>> is never more than a few MB.
>>
>> Do you have backtraces from the crash?  How did you determine that the
>> crashes and the anonymous mappings are related?
>>
>> How do you launch the detached threads?  Do you use any other thread
>> attributes?
>>
> 
> I've struggled to get backtraces.  The app has a crash-handler that prints a backttrace to the log, but that also crashes inside of a malloc.  Getting a core on the production system has been a challenge too.  I'll see if I can get that.
> 
> I'm not 100% sure that they are related.
> 
> I have a monitor running that does a top every 30 seconds or so.  The pattern is always that the app's VIRT grows to about 2G and then it crashes.  We figured it was a memory leak, so we started running it through valgrind.  We'd see the same memory usage, but valgrind would report no leaks, and only a few K of "still reachable" memory.  This was the same whether the app crashed, or whether we just killed it after a few hours.  I eventually noticed the anonymous segments in /proc/<pid>/maps, did some math on them, and them + [stack] roughly added up to the VIRT size.  So, I figured they were responsible for the VIRT growth.
> 
> It's not clear why the app is crashing at about 2G.  I'd think that a 64-bit process ought to be able to address more than that.  But, since it always crashes at that size, it seems like it's related.
> 
> Code to launch detached threads:
> 
> ... main ...
> 
> 	cs->threadattr=new pthread_attr_t;
> 	pthread_attr_init(cs->threadattr);
> 	pthread_attr_setdetachstate(cs->threadattr,PTHREAD_CREATE_DETACHED);
> 	...
> 	cs->threadhandle=new pthread_t;
> 	if (pthread_create(cs->threadhandle,cs->threadattr,
> 				(void *(*)(void *))clientThread,
> 				(void *)cs)) {
> 		... error handling ...
> 	}
> 
> 
> ... inside of clientThread() ...
> 
>          pthread_attr_destroy(cs->threadattr);
> 	...
> 	pthread_exit(NULL);
> 
> 
> No other attributes.

If the detached thread exits the memory should get reaped
(eventually, the kernel is sometimes slow at reaping).

You really need to instrument the thread stack/size and
correlate the anonymous mappings to the threads, and figure
out why you crash.

When a thread exits we use madvise (MADV_DONTNEED) to mark
the pages of the stack (minus PTHREAD_STACK_MIN) as unused.
This means VmSIZE remains high, but VmRSS is reduced.
However, eventually when the stack cache exceeds 40MiB we
start unmapping the entire caches.

I wonder if your OS has a customization to increase the stack
cache size? Are you able to debug the value of 'stack_cache_maxsize'
that you see from nptl/allocatestack.c?

-- 
Cheers,
Carlos.

Re: thread heap leak?

[Florian Weimer]

* David Muse:

> I've struggled to get backtraces.  The app has a crash-handler that
> prints a backttrace to the log, but that also crashes inside of a
> malloc.

Please consider disabling the crash handler.  It typically interferes
with debugging, particularly if it tricks like fork.  (malloc in a
crash handler is certainly not a good sign.)

> Code to launch detached threads:
>
> ... main ...
>
> 	cs->threadattr=new pthread_attr_t;
> 	pthread_attr_init(cs->threadattr);
> 	pthread_attr_setdetachstate(cs->threadattr,PTHREAD_CREATE_DETACHED);
> 	...
> 	cs->threadhandle=new pthread_t;
> 	if (pthread_create(cs->threadhandle,cs->threadattr,
> 				(void *(*)(void *))clientThread,
> 				(void *)cs)) {
> 		... error handling ...
> 	}
>
>
> ... inside of clientThread() ...
>
>         pthread_attr_destroy(cs->threadattr);
> 	...
> 	pthread_exit(NULL);
>
>
> No other attributes.

Hmm.  Computing the sizes of mappings you quoted and the gaps between
them[1], I get this:

   0.016 2b933fa97000-2b933fa9b000 rw-p 00000000 00:00 0 
   0.004 2b933fa9b000-2b933fa9c000 ---p 00000000 00:00 0 
   2.000 2b933fa9c000-2b933fc9c000 rw-p 00000000 00:00 0 
   0.004 2b933fc9c000-2b933fc9d000 ---p 00000000 00:00 0 
   2.000 2b933fc9d000-2b933fe9d000 rw-p 00000000 00:00 0 
... 1.387 ...
   0.496 2b9340000000-2b934007f000 rw-p 00000000 00:00 0 
  63.504 2b934007f000-2b9344000000 ---p 00000000 00:00 0 
   0.195 2b9344000000-2b9344032000 rw-p 00000000 00:00 0 
  63.805 2b9344032000-2b9348000000 ---p 00000000 00:00 0 
   0.004 2b9348000000-2b9348001000 ---p 00000000 00:00 0 
   2.000 2b9348001000-2b9348201000 rw-p 00000000 00:00 0 
   0.004 2b9348201000-2b9348202000 ---p 00000000 00:00 0 
   2.000 2b9348202000-2b9348402000 rw-p 00000000 00:00 0 
   0.004 2b9348402000-2b9348403000 ---p 00000000 00:00 0 
   2.000 2b9348403000-2b9348603000 rw-p 00000000 00:00 0 
   0.004 2b9348603000-2b9348604000 ---p 00000000 00:00 0 
   2.000 2b9348604000-2b9348804000 rw-p 00000000 00:00 0 
... 55.984 ...
   0.137 2b934c000000-2b934c023000 rw-p 00000000 00:00 0 
  63.863 2b934c023000-2b9350000000 ---p 00000000 00:00 0 
   0.129 2b9350000000-2b9350021000 rw-p 00000000 00:00 0 
  63.871 2b9350021000-2b9354000000 ---p 00000000 00:00 0 
   0.516 2b9354000000-2b9354084000 rw-p 00000000 00:00 0 
  63.484 2b9354084000-2b9358000000 ---p 00000000 00:00 0 
   0.129 2b9358000000-2b9358021000 rw-p 00000000 00:00 0 
  63.871 2b9358021000-2b935c000000 ---p 00000000 00:00 0 

So these mappings are a mix of thread stacks, assuming that you set
the stack ulimit to 2 MiB (more usual would be 8 MiB).

There are also mostly-deallocated heaps (mapped with PROT_NONE,
probably due to vm.overcommit_memory=2 mode).  The reported gaps are
the result of malloc heap alignment.

So this doesn't look like anything unusual so far.  I guess the next
step would be to look at the full list of mappings and check if the
number of thread stacks is reasonable (there should be about 20 of
them at most, I think).

[1] Script used:

import sys
last_address = 0
for line in sys.stdin:
    line = line.strip()
    comps = line.split(' ')
    low, high = comps[0].split('-')
    low = int(low, 16)
    high = int(high, 16)
    size_mib = (high - low) / 2.**20
    if last_address > 0 and last_address != low:
        print("... {:.3f} ...".format((low - last_address) / 2.**20))
    last_address = high
    print("  {:>6.3f} {}".format(size_mib, line))

Re: thread heap leak?

[Andreas Schwab]

On Mär 22 2019, Carlos O'Donell <codonell@redhat.com> wrote:

> Have you seen reports like this?

I cannot remember having seen any bug reports about this.

Andreas.

-- 
Andreas Schwab, SUSE Labs, schwab@suse.de
GPG Key fingerprint = 0196 BAD8 1CE9 1970 F4BE  1748 E4D4 88E3 0EEA B9D7
"And now for something completely different."

Re: thread heap leak?

[David Muse]

On Fri, 22 Mar 2019 13:45:42 -0400
"Carlos O'Donell" <codonell@redhat.com> wrote:

> On 3/22/19 1:39 PM, David Muse wrote:
> > On Fri, 22 Mar 2019 13:03:51 -0400 "Carlos O'Donell"
> > <codonell@redhat.com> wrote:
> > 
> >> On 3/22/19 10:53 AM, David Muse wrote:
> >>> We have this little server program that listens for client 
> >>> connections on an inet socket.  When it receives a connection,
> >>> it pthread_create()'s a detached thread to handle the request and
> >>> the main thread waits for more client connections.
> >> 
> >> The stack for the detached thread is recoverable only if the
> >> thread exits, at which point it calls 	__free_tcb () (only if
> >> detached, because otherwise only pthread_join() does this
> >> recovery), enqueues the stack onto the free list and leaves it
> >> there. Subsequent thread creation attemps to reuse the stack, but
> >> must wait for the kernel to clear the registered tid memory
> >> (CLONE_CHILD_CLEARTID) to mark the stack reusable (FREE_P). The
> >> total size of the thread stack cache should only be ~40MiB, and new
> >> stack creation triggers an automatic check to trim this cache back
> >> down to 40MiB.
> >> 
> >> Have you been able to reduce this to a smaller test case?
> >> 
> >> The anonymous mappings might indeed be thread stacks, but you'd 
> >> have to verify that yourself, and you can do that by asking the 
> >> thread for the stack information and printing that.
> >> 
> >> Are you using Amazon Linux or a known distro upstream?
> > 
> > I did comment out lots of features in the program to narrow down the
> > problem, but I haven't been able to reproduce the leak in a compact
> > test case.  I've been working on that though.
> 
> Good luck :-)
> 
> > How do I get the stack information from the thread?  I know that I
> > can do pthread_attr_getstacksize for the size, but what else can I
> > get?
> 
> You can use pthread_getattr_np() to take a snapshot of the thread's
> attributes and look at those, that will get you the information about
> stack address location and size.
> 
> You should try using something like systemtap to put tap points on
> your program and observe the behaviour of the detached threads.
> 
> 
> > We're using OpenSUSE Leap 42.3.  I've seen the problem directly
> > there.  I've gotten reports that it also occurs on RHEL 7, but I
> > can't confirm that.
> 
> Andreas,
> 
> Have you seen reports like this?
> 
> -- 
> Cheers,
> Carlos.
> 

Thanks for the advice.  I'll try pthread_getattr_np() and systemtap and see what info I can get.

Thanks,

David
david.muse@firstworks.com

Re: thread heap leak?

[David Muse]

On Fri, 22 Mar 2019 14:01:14 -0400
"Carlos O'Donell" <codonell@redhat.com> wrote:

> On 3/22/19 1:53 PM, David Muse wrote:
> > On Fri, 22 Mar 2019 18:31:01 +0100
> > Florian Weimer <fw@deneb.enyo.de> wrote:
> > 
> >> * David Muse:
> >>
> >>> Over time, we get more and more of them until top shows the app's VIRT
> >>> to be around 4G (I think, maybe just 2G).  Then it crashes.  The RES
> >>> is never more than a few MB.
> >>
> >> Do you have backtraces from the crash?  How did you determine that the
> >> crashes and the anonymous mappings are related?
> >>
> >> How do you launch the detached threads?  Do you use any other thread
> >> attributes?
> >>
> > 
> > I've struggled to get backtraces.  The app has a crash-handler that prints a backttrace to the log, but that also crashes inside of a malloc.  Getting a core on the production system has been a challenge too.  I'll see if I can get that.
> > 
> > I'm not 100% sure that they are related.
> > 
> > I have a monitor running that does a top every 30 seconds or so.  The pattern is always that the app's VIRT grows to about 2G and then it crashes.  We figured it was a memory leak, so we started running it through valgrind.  We'd see the same memory usage, but valgrind would report no leaks, and only a few K of "still reachable" memory.  This was the same whether the app crashed, or whether we just killed it after a few hours.  I eventually noticed the anonymous segments in /proc/<pid>/maps, did some math on them, and them + [stack] roughly added up to the VIRT size.  So, I figured they were responsible for the VIRT growth.
> > 
> > It's not clear why the app is crashing at about 2G.  I'd think that a 64-bit process ought to be able to address more than that.  But, since it always crashes at that size, it seems like it's related.
> > 
> > Code to launch detached threads:
> > 
> > ... main ...
> > 
> > 	cs->threadattr=new pthread_attr_t;
> > 	pthread_attr_init(cs->threadattr);
> > 	pthread_attr_setdetachstate(cs->threadattr,PTHREAD_CREATE_DETACHED);
> > 	...
> > 	cs->threadhandle=new pthread_t;
> > 	if (pthread_create(cs->threadhandle,cs->threadattr,
> > 				(void *(*)(void *))clientThread,
> > 				(void *)cs)) {
> > 		... error handling ...
> > 	}
> > 
> > 
> > ... inside of clientThread() ...
> > 
> >          pthread_attr_destroy(cs->threadattr);
> > 	...
> > 	pthread_exit(NULL);
> > 
> > 
> > No other attributes.
> 
> If the detached thread exits the memory should get reaped
> (eventually, the kernel is sometimes slow at reaping).
> 
> You really need to instrument the thread stack/size and
> correlate the anonymous mappings to the threads, and figure
> out why you crash.
> 
> When a thread exits we use madvise (MADV_DONTNEED) to mark
> the pages of the stack (minus PTHREAD_STACK_MIN) as unused.
> This means VmSIZE remains high, but VmRSS is reduced.
> However, eventually when the stack cache exceeds 40MiB we
> start unmapping the entire caches.
> 
> I wonder if your OS has a customization to increase the stack
> cache size? Are you able to debug the value of 'stack_cache_maxsize'
> that you see from nptl/allocatestack.c?
> 
> -- 
> Cheers,
> Carlos.
> 

I probably can't check stack_cache_maxsize in production, but I can probably check it on a dev VM.  I'd expect it to be the same.  I'd think it would have to be really large to cause the problem I'm seeing, but I'll check.

David
david.muse@firstworks.com

Re: thread heap leak?

[David Muse]

On Fri, 22 Mar 2019 19:41:22 +0100
Florian Weimer <fw@deneb.enyo.de> wrote:

> * David Muse:
> 
> > I've struggled to get backtraces.  The app has a crash-handler that
> > prints a backttrace to the log, but that also crashes inside of a
> > malloc.
> 
> Please consider disabling the crash handler.  It typically interferes
> with debugging, particularly if it tricks like fork.  (malloc in a
> crash handler is certainly not a good sign.)
> 
> > Code to launch detached threads:
> >
> > ... main ...
> >
> > 	cs->threadattr=new pthread_attr_t;
> > 	pthread_attr_init(cs->threadattr);
> > 	pthread_attr_setdetachstate(cs->threadattr,PTHREAD_CREATE_DETACHED);
> > 	...
> > 	cs->threadhandle=new pthread_t;
> > 	if (pthread_create(cs->threadhandle,cs->threadattr,
> > 				(void *(*)(void *))clientThread,
> > 				(void *)cs)) {
> > 		... error handling ...
> > 	}
> >
> >
> > ... inside of clientThread() ...
> >
> >         pthread_attr_destroy(cs->threadattr);
> > 	...
> > 	pthread_exit(NULL);
> >
> >
> > No other attributes.
> 
> Hmm.  Computing the sizes of mappings you quoted and the gaps between
> them[1], I get this:
> 
>    0.016 2b933fa97000-2b933fa9b000 rw-p 00000000 00:00 0 
>    0.004 2b933fa9b000-2b933fa9c000 ---p 00000000 00:00 0 
>    2.000 2b933fa9c000-2b933fc9c000 rw-p 00000000 00:00 0 
>    0.004 2b933fc9c000-2b933fc9d000 ---p 00000000 00:00 0 
>    2.000 2b933fc9d000-2b933fe9d000 rw-p 00000000 00:00 0 
> ... 1.387 ...
>    0.496 2b9340000000-2b934007f000 rw-p 00000000 00:00 0 
>   63.504 2b934007f000-2b9344000000 ---p 00000000 00:00 0 
>    0.195 2b9344000000-2b9344032000 rw-p 00000000 00:00 0 
>   63.805 2b9344032000-2b9348000000 ---p 00000000 00:00 0 
>    0.004 2b9348000000-2b9348001000 ---p 00000000 00:00 0 
>    2.000 2b9348001000-2b9348201000 rw-p 00000000 00:00 0 
>    0.004 2b9348201000-2b9348202000 ---p 00000000 00:00 0 
>    2.000 2b9348202000-2b9348402000 rw-p 00000000 00:00 0 
>    0.004 2b9348402000-2b9348403000 ---p 00000000 00:00 0 
>    2.000 2b9348403000-2b9348603000 rw-p 00000000 00:00 0 
>    0.004 2b9348603000-2b9348604000 ---p 00000000 00:00 0 
>    2.000 2b9348604000-2b9348804000 rw-p 00000000 00:00 0 
> ... 55.984 ...
>    0.137 2b934c000000-2b934c023000 rw-p 00000000 00:00 0 
>   63.863 2b934c023000-2b9350000000 ---p 00000000 00:00 0 
>    0.129 2b9350000000-2b9350021000 rw-p 00000000 00:00 0 
>   63.871 2b9350021000-2b9354000000 ---p 00000000 00:00 0 
>    0.516 2b9354000000-2b9354084000 rw-p 00000000 00:00 0 
>   63.484 2b9354084000-2b9358000000 ---p 00000000 00:00 0 
>    0.129 2b9358000000-2b9358021000 rw-p 00000000 00:00 0 
>   63.871 2b9358021000-2b935c000000 ---p 00000000 00:00 0 
> 
> So these mappings are a mix of thread stacks, assuming that you set
> the stack ulimit to 2 MiB (more usual would be 8 MiB).
> 
> There are also mostly-deallocated heaps (mapped with PROT_NONE,
> probably due to vm.overcommit_memory=2 mode).  The reported gaps are
> the result of malloc heap alignment.
> 
> So this doesn't look like anything unusual so far.  I guess the next
> step would be to look at the full list of mappings and check if the
> number of thread stacks is reasonable (there should be about 20 of
> them at most, I think).
> 
> [1] Script used:
> 
> import sys
> last_address = 0
> for line in sys.stdin:
>     line = line.strip()
>     comps = line.split(' ')
>     low, high = comps[0].split('-')
>     low = int(low, 16)
>     high = int(high, 16)
>     size_mib = (high - low) / 2.**20
>     if last_address > 0 and last_address != low:
>         print("... {:.3f} ...".format((low - last_address) / 2.**20))
>     last_address = high
>     print("  {:>6.3f} {}".format(size_mib, line))
> 

Ok, I'll see what I can find on that front.

It looks like vm.overcommit_memory=0 on that system:

ec2-user@ip-172-31-25-149:~> cat /proc/sys/vm/overcommit_memory 
0

I'm not sure if that changes your analysis or not though.

Thanks,

David
david.muse@firstworks.com

Re: thread heap leak?

[David Muse]

On Mon, 25 Mar 2019 11:46:27 -0400
David Muse <david.muse@firstworks.com> wrote:

> On Fri, 22 Mar 2019 19:41:22 +0100
> Florian Weimer <fw@deneb.enyo.de> wrote:
> 
> > * David Muse:
> > 
> > > I've struggled to get backtraces.  The app has a crash-handler that
> > > prints a backttrace to the log, but that also crashes inside of a
> > > malloc.
> > 
> > Please consider disabling the crash handler.  It typically interferes
> > with debugging, particularly if it tricks like fork.  (malloc in a
> > crash handler is certainly not a good sign.)
> > 
> > > Code to launch detached threads:
> > >
> > > ... main ...
> > >
> > > 	cs->threadattr=new pthread_attr_t;
> > > 	pthread_attr_init(cs->threadattr);
> > > 	pthread_attr_setdetachstate(cs->threadattr,PTHREAD_CREATE_DETACHED);
> > > 	...
> > > 	cs->threadhandle=new pthread_t;
> > > 	if (pthread_create(cs->threadhandle,cs->threadattr,
> > > 				(void *(*)(void *))clientThread,
> > > 				(void *)cs)) {
> > > 		... error handling ...
> > > 	}
> > >
> > >
> > > ... inside of clientThread() ...
> > >
> > >         pthread_attr_destroy(cs->threadattr);
> > > 	...
> > > 	pthread_exit(NULL);
> > >
> > >
> > > No other attributes.
> > 
> > Hmm.  Computing the sizes of mappings you quoted and the gaps between
> > them[1], I get this:
> > 
> >    0.016 2b933fa97000-2b933fa9b000 rw-p 00000000 00:00 0 
> >    0.004 2b933fa9b000-2b933fa9c000 ---p 00000000 00:00 0 
> >    2.000 2b933fa9c000-2b933fc9c000 rw-p 00000000 00:00 0 
> >    0.004 2b933fc9c000-2b933fc9d000 ---p 00000000 00:00 0 
> >    2.000 2b933fc9d000-2b933fe9d000 rw-p 00000000 00:00 0 
> > ... 1.387 ...
> >    0.496 2b9340000000-2b934007f000 rw-p 00000000 00:00 0 
> >   63.504 2b934007f000-2b9344000000 ---p 00000000 00:00 0 
> >    0.195 2b9344000000-2b9344032000 rw-p 00000000 00:00 0 
> >   63.805 2b9344032000-2b9348000000 ---p 00000000 00:00 0 
> >    0.004 2b9348000000-2b9348001000 ---p 00000000 00:00 0 
> >    2.000 2b9348001000-2b9348201000 rw-p 00000000 00:00 0 
> >    0.004 2b9348201000-2b9348202000 ---p 00000000 00:00 0 
> >    2.000 2b9348202000-2b9348402000 rw-p 00000000 00:00 0 
> >    0.004 2b9348402000-2b9348403000 ---p 00000000 00:00 0 
> >    2.000 2b9348403000-2b9348603000 rw-p 00000000 00:00 0 
> >    0.004 2b9348603000-2b9348604000 ---p 00000000 00:00 0 
> >    2.000 2b9348604000-2b9348804000 rw-p 00000000 00:00 0 
> > ... 55.984 ...
> >    0.137 2b934c000000-2b934c023000 rw-p 00000000 00:00 0 
> >   63.863 2b934c023000-2b9350000000 ---p 00000000 00:00 0 
> >    0.129 2b9350000000-2b9350021000 rw-p 00000000 00:00 0 
> >   63.871 2b9350021000-2b9354000000 ---p 00000000 00:00 0 
> >    0.516 2b9354000000-2b9354084000 rw-p 00000000 00:00 0 
> >   63.484 2b9354084000-2b9358000000 ---p 00000000 00:00 0 
> >    0.129 2b9358000000-2b9358021000 rw-p 00000000 00:00 0 
> >   63.871 2b9358021000-2b935c000000 ---p 00000000 00:00 0 
> > 
> > So these mappings are a mix of thread stacks, assuming that you set
> > the stack ulimit to 2 MiB (more usual would be 8 MiB).
> > 
> > There are also mostly-deallocated heaps (mapped with PROT_NONE,
> > probably due to vm.overcommit_memory=2 mode).  The reported gaps are
> > the result of malloc heap alignment.
> > 
> > So this doesn't look like anything unusual so far.  I guess the next
> > step would be to look at the full list of mappings and check if the
> > number of thread stacks is reasonable (there should be about 20 of
> > them at most, I think).
> > 
> > [1] Script used:
> > 
> > import sys
> > last_address = 0
> > for line in sys.stdin:
> >     line = line.strip()
> >     comps = line.split(' ')
> >     low, high = comps[0].split('-')
> >     low = int(low, 16)
> >     high = int(high, 16)
> >     size_mib = (high - low) / 2.**20
> >     if last_address > 0 and last_address != low:
> >         print("... {:.3f} ...".format((low - last_address) / 2.**20))
> >     last_address = high
> >     print("  {:>6.3f} {}".format(size_mib, line))
> > 
> 
> Ok, I'll see what I can find on that front.
> 
> It looks like vm.overcommit_memory=0 on that system:
> 
> ec2-user@ip-172-31-25-149:~> cat /proc/sys/vm/overcommit_memory 
> 0
> 
> I'm not sure if that changes your analysis or not though.
> 
> Thanks,
> 
> David
> david.muse@firstworks.com

I just remembered something...

You mentioned 2mb or 8mb stack ulimits.  The default is 8mb, but we're using:
ulimit -s unlimited

on the production VM.  Could this be contributing to the problem?

David
david.muse@firstworks.com

Re: thread heap leak?

[Carlos O'Donell]

On 3/28/19 2:17 PM, David Muse wrote:
> I just remembered something...
> 
> You mentioned 2mb or 8mb stack ulimits.  The default is 8mb, but we're using:
> ulimit -s unlimited
> 
> on the production VM.  Could this be contributing to the problem?

No, that's not likely the problem.

Thread stacks are allocated with mmap, and in the presence of an unlimited
ulimit they fall back to the default size which is 2MiB.

nptl/nptl-init.c:

350   /* Determine the default allowed stack size.  This is the size used
351      in case the user does not specify one.  */
352   struct rlimit limit;
353   if (__getrlimit (RLIMIT_STACK, &limit) != 0
354       || limit.rlim_cur == RLIM_INFINITY)
355     /* The system limit is not usable.  Use an architecture-specific
356        default.  */
357     limit.rlim_cur = ARCH_STACK_DEFAULT_SIZE;
                          ^^^^^^^^^^^^^^^^^^^^^^^

358   else if (limit.rlim_cur < PTHREAD_STACK_MIN)
359     /* The system limit is unusably small.
360        Use the minimal size acceptable.  */
361     limit.rlim_cur = PTHREAD_STACK_MIN;

sysdeps/x86_64/nptl/pthreaddef.h

  19 /* Default stack size.  */
  20 #define ARCH_STACK_DEFAULT_SIZE (2 * 1024 * 1024)

-- 
Cheers,
Carlos.

Re: thread heap leak?

[David Muse]

On Mon, 25 Mar 2019 11:37:58 -0400
David Muse <david.muse@firstworks.com> wrote:

> On Fri, 22 Mar 2019 13:45:42 -0400
> "Carlos O'Donell" <codonell@redhat.com> wrote:
> 
> > On 3/22/19 1:39 PM, David Muse wrote:
> > > On Fri, 22 Mar 2019 13:03:51 -0400 "Carlos O'Donell"
> > > <codonell@redhat.com> wrote:
> > > 
> > >> On 3/22/19 10:53 AM, David Muse wrote:
> > >>> We have this little server program that listens for client 
> > >>> connections on an inet socket.  When it receives a connection,
> > >>> it pthread_create()'s a detached thread to handle the request and
> > >>> the main thread waits for more client connections.
> > >> 
> > >> The stack for the detached thread is recoverable only if the
> > >> thread exits, at which point it calls 	__free_tcb () (only if
> > >> detached, because otherwise only pthread_join() does this
> > >> recovery), enqueues the stack onto the free list and leaves it
> > >> there. Subsequent thread creation attemps to reuse the stack, but
> > >> must wait for the kernel to clear the registered tid memory
> > >> (CLONE_CHILD_CLEARTID) to mark the stack reusable (FREE_P). The
> > >> total size of the thread stack cache should only be ~40MiB, and new
> > >> stack creation triggers an automatic check to trim this cache back
> > >> down to 40MiB.
> > >> 
> > >> Have you been able to reduce this to a smaller test case?
> > >> 
> > >> The anonymous mappings might indeed be thread stacks, but you'd 
> > >> have to verify that yourself, and you can do that by asking the 
> > >> thread for the stack information and printing that.
> > >> 
> > >> Are you using Amazon Linux or a known distro upstream?
> > > 
> > > I did comment out lots of features in the program to narrow down the
> > > problem, but I haven't been able to reproduce the leak in a compact
> > > test case.  I've been working on that though.
> > 
> > Good luck :-)
> > 
> > > How do I get the stack information from the thread?  I know that I
> > > can do pthread_attr_getstacksize for the size, but what else can I
> > > get?
> > 
> > You can use pthread_getattr_np() to take a snapshot of the thread's
> > attributes and look at those, that will get you the information about
> > stack address location and size.
> > 
> > You should try using something like systemtap to put tap points on
> > your program and observe the behaviour of the detached threads.
> > 
> > 
> > > We're using OpenSUSE Leap 42.3.  I've seen the problem directly
> > > there.  I've gotten reports that it also occurs on RHEL 7, but I
> > > can't confirm that.
> > 
> > Andreas,
> > 
> > Have you seen reports like this?
> > 
> > -- 
> > Cheers,
> > Carlos.
> > 
> 
> Thanks for the advice.  I'll try pthread_getattr_np() and systemtap and see what info I can get.
> 
> Thanks,
> 
> David
> david.muse@firstworks.com

Ok, I added some thread-stack logging to my program and collected some data.  Here's what I have so far.

It looks like during this run, only 4 threads were forked, and 3 of them reused the same stack:

thread: addr: 0000000089a63000  end: 0000000089c63000 - stack 1
thread: addr: 0000000089e65000  end: 000000008a065000 - stack 2 
thread: addr: 0000000089e65000  end: 000000008a065000 - stack 2 (reused)
thread: addr: 0000000089e65000  end: 000000008a065000 - stack 2 (reused)

In /proc/<pid>/maps, I see the 2 stacks:

2aeb89a5e000-2aeb89a62000 rw-p 00000000 00:00 0
2aeb89a62000-2aeb89a63000 ---p 00000000 00:00 0
2aeb89a63000-2aeb89c63000 rw-p 00000000 00:00 0 - stack 1
2aeb89c63000-2aeb89c64000 ---p 00000000 00:00 0
2aeb89c64000-2aeb89e64000 rw-p 00000000 00:00 0
2aeb89e64000-2aeb89e65000 ---p 00000000 00:00 0
2aeb89e65000-2aeb8a065000 rw-p 00000000 00:00 0 - stack 2
2aeb8c000000-2aeb8c097000 rw-p 00000000 00:00 0
2aeb8c097000-2aeb90000000 ---p 00000000 00:00 0
2aeb90000000-2aeb90093000 rw-p 00000000 00:00 0
2aeb90093000-2aeb94000000 ---p 00000000 00:00 0
2aeb94000000-2aeb940a2000 rw-p 00000000 00:00 0
2aeb940a2000-2aeb98000000 ---p 00000000 00:00 0

But what are the rest of those anonymous segments?

This might not be a thread-stack leak, but some other kind of leak.  What else creates anonymous segments like that?

David
david.muse@firstworks.com

Re: thread heap leak?

[Carlos O'Donell]

On 3/30/19 1:06 PM, David Muse wrote:
> 2aeb89a5e000-2aeb89a62000 rw-p 00000000 00:00 0	[16KiB]

> 2aeb89a62000-2aeb89a63000 ---p 00000000 00:00 0	[stack guard]
> 2aeb89a63000-2aeb89c63000 rw-p 00000000 00:00 0 - stack 1

> 2aeb89c63000-2aeb89c64000 ---p 00000000 00:00 0	[stack guard]
> 2aeb89c64000-2aeb89e64000 rw-p 00000000 00:00 0	[2MiB thread stack]

> 2aeb89e64000-2aeb89e65000 ---p 00000000 00:00 0	[stack guard]
> 2aeb89e65000-2aeb8a065000 rw-p 00000000 00:00 0 - stack 2

> 2aeb8c000000-2aeb8c097000 rw-p 00000000 00:00 0	[618KiB - heap, 64MiB + aligned]
> 2aeb8c097000-2aeb90000000 ---p 00000000 00:00 0	[66MiB - MADV_DONTNEED]

> 2aeb90000000-2aeb90093000 rw-p 00000000 00:00 0	[602KiB - heap, 64MiB + aligned]
> 2aeb90093000-2aeb94000000 ---p 00000000 00:00 0	[66MiB - MADV_DONTNEED]

> 2aeb94000000-2aeb940a2000 rw-p 00000000 00:00 0	[663KiB - heap, 64MiB + aligned]
> 2aeb940a2000-2aeb98000000 ---p 00000000 00:00 0	[66MiB - MADV_DONTNEED]
> 
> But what are the rest of those anonymous segments?
> 
> This might not be a thread-stack leak, but some other kind of leak.
> What else creates anonymous segments like that?

Looks like 3 threads, and 3 heaps.

-- 
Cheers,
Carlos.

Re: thread heap leak?

[David Muse]

On Sat, 30 Mar 2019 23:59:45 -0400
"Carlos O'Donell" <codonell@redhat.com> wrote:

> On 3/30/19 1:06 PM, David Muse wrote:
> > 2aeb89a5e000-2aeb89a62000 rw-p 00000000 00:00 0	[16KiB]
> 
> > 2aeb89a62000-2aeb89a63000 ---p 00000000 00:00 0	[stack guard]
> > 2aeb89a63000-2aeb89c63000 rw-p 00000000 00:00 0 - stack 1
> 
> > 2aeb89c63000-2aeb89c64000 ---p 00000000 00:00 0	[stack guard]
> > 2aeb89c64000-2aeb89e64000 rw-p 00000000 00:00 0	[2MiB thread stack]
> 
> > 2aeb89e64000-2aeb89e65000 ---p 00000000 00:00 0	[stack guard]
> > 2aeb89e65000-2aeb8a065000 rw-p 00000000 00:00 0 - stack 2
> 
> > 2aeb8c000000-2aeb8c097000 rw-p 00000000 00:00 0	[618KiB - heap, 64MiB + aligned]
> > 2aeb8c097000-2aeb90000000 ---p 00000000 00:00 0	[66MiB - MADV_DONTNEED]
> 
> > 2aeb90000000-2aeb90093000 rw-p 00000000 00:00 0	[602KiB - heap, 64MiB + aligned]
> > 2aeb90093000-2aeb94000000 ---p 00000000 00:00 0	[66MiB - MADV_DONTNEED]
> 
> > 2aeb94000000-2aeb940a2000 rw-p 00000000 00:00 0	[663KiB - heap, 64MiB + aligned]
> > 2aeb940a2000-2aeb98000000 ---p 00000000 00:00 0	[66MiB - MADV_DONTNEED]
> > 
> > But what are the rest of those anonymous segments?
> > 
> > This might not be a thread-stack leak, but some other kind of leak.
> > What else creates anonymous segments like that?
> 
> Looks like 3 threads, and 3 heaps.
> 
> -- 
> Cheers,
> Carlos.
> 

Yeah, that is what it looks like, but where did the 3rd thread stack come from?  As far as I can tell, no thread created it.

I'll see if I can get the same kind of stats when it's about to crash and see if they look any different.

Dave
david.muse@firstworks.com

Re: thread heap leak?

[Andreas Schwab]

On Mär 31 2019, David Muse <david.muse@firstworks.com> wrote:

> Yeah, that is what it looks like, but where did the 3rd thread stack come from?  As far as I can tell, no thread created it.

Try using `strace -k -e mmap' to see where the mapping is created.

Andreas.

-- 
Andreas Schwab, SUSE Labs, schwab@suse.de
GPG Key fingerprint = 0196 BAD8 1CE9 1970 F4BE  1748 E4D4 88E3 0EEA B9D7
"And now for something completely different."

Re: thread heap leak?

[David Muse]

On Mon, 01 Apr 2019 10:19:53 +0200
Andreas Schwab <schwab@suse.de> wrote:

> On Mär 31 2019, David Muse <david.muse@firstworks.com> wrote:
> 
> > Yeah, that is what it looks like, but where did the 3rd thread stack come from?  As far as I can tell, no thread created it.
> 
> Try using `strace -k -e mmap' to see where the mapping is created.
> 
> Andreas.
> 
> -- 
> Andreas Schwab, SUSE Labs, schwab@suse.de
> GPG Key fingerprint = 0196 BAD8 1CE9 1970 F4BE  1748 E4D4 88E3 0EEA B9D7
> "And now for something completely different."
> 

Thanks for the strace tip Andreas.  I built strace-5.0 with --enable-stacktrace=yes --with-libunwind, and I get the following mmap calls when I use it:

(numbered by me)

1  - mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ac55d978000
2  - mmap(0x2ac55e050000, 13472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x2ac55e050000
3  - mmap(0x2ac55e25e000, 184832, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x2ac55e25e000
4  - mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ac55d97a000
5  - mmap(0x2ac55eadc000, 12320, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x2ac55eadc000
6  - mmap(0x2ac55f426000, 14336, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x2ac55f426000
7  - mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ac55d97c000
8  - mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ac55d97e000
9  - mmap(NULL, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ac55d980000
10 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac55f42a000
11 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac55f62b000
12 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac55f82c000
13 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac55fa2d000
14 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac55fc2e000
15 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac574000000
16 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac574201000
17 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac574402000
18 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac574603000
19 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac574804000
20 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac574a05000
21 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac574c06000
22 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac574e07000
23 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac575008000
24 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac575209000
25 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac57540a000
26 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac57560b000
27 - mmap(NULL, 2101248, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2ac57580c000

I can correlate call number 6 and calls numbered 10-27 with the process map.  Presumedly, 1-5 and 7-9 were unmapped.  10-27 appear to be thread stacks, considering their size, and that they were called with the MAP_STACK option :)

2ac55f426000-2ac55f42a000 rw-p 00000000 00:00 0 -  6
2ac55f42a000-2ac55f42b000 ---p 00000000 00:00 0  - 10
2ac55f42b000-2ac55f62b000 rw-p 00000000 00:00 0 
2ac55f62b000-2ac55f62c000 ---p 00000000 00:00 0  - 11
2ac55f62c000-2ac55f82c000 rw-p 00000000 00:00 0 
2ac55f82c000-2ac55f82d000 ---p 00000000 00:00 0  - 12
2ac55f82d000-2ac55fa2d000 rw-p 00000000 00:00 0
2ac55fa2d000-2ac55fa2e000 ---p 00000000 00:00 0  - 13
2ac55fa2e000-2ac55fc2e000 rw-p 00000000 00:00 0
2ac55fc2e000-2ac55fc2f000 ---p 00000000 00:00 0  - 14
2ac55fc2f000-2ac55fe2f000 rw-p 00000000 00:00 0 
2ac560000000-2ac56002b000 rw-p 00000000 00:00 0 
2ac56002b000-2ac564000000 ---p 00000000 00:00 0 
2ac564000000-2ac564021000 rw-p 00000000 00:00 0 
2ac564021000-2ac568000000 ---p 00000000 00:00 0 
2ac568000000-2ac56807f000 rw-p 00000000 00:00 0 
2ac56807f000-2ac56c000000 ---p 00000000 00:00 0 
2ac56c000000-2ac56c021000 rw-p 00000000 00:00 0 
2ac56c021000-2ac570000000 ---p 00000000 00:00 0 
2ac570000000-2ac570021000 rw-p 00000000 00:00 0 
2ac570021000-2ac574000000 ---p 00000000 00:00 0
2ac574000000-2ac574001000 ---p 00000000 00:00 0 - 15
2ac574001000-2ac574201000 rw-p 00000000 00:00 0
2ac574201000-2ac574202000 ---p 00000000 00:00 0 - 16
2ac574202000-2ac574402000 rw-p 00000000 00:00 0
2ac574402000-2ac574403000 ---p 00000000 00:00 0 - 17
2ac574403000-2ac574603000 rw-p 00000000 00:00 0
2ac574603000-2ac574604000 ---p 00000000 00:00 0 - 18
2ac574604000-2ac574804000 rw-p 00000000 00:00 0
2ac574804000-2ac574805000 ---p 00000000 00:00 0 - 19
2ac574805000-2ac574a05000 rw-p 00000000 00:00 0
2ac574a05000-2ac574a06000 ---p 00000000 00:00 0 - 20
2ac574a06000-2ac574c06000 rw-p 00000000 00:00 0
2ac574c06000-2ac574c07000 ---p 00000000 00:00 0 - 21
2ac574c07000-2ac574e07000 rw-p 00000000 00:00 0
2ac574e07000-2ac574e08000 ---p 00000000 00:00 0 - 22
2ac574e08000-2ac575008000 rw-p 00000000 00:00 0
2ac575008000-2ac575009000 ---p 00000000 00:00 0 - 23
2ac575009000-2ac575209000 rw-p 00000000 00:00 0
2ac575209000-2ac57520a000 ---p 00000000 00:00 0 - 24
2ac57520a000-2ac57540a000 rw-p 00000000 00:00 0
2ac57540a000-2ac57540b000 ---p 00000000 00:00 0 - 25
2ac57540b000-2ac57560b000 rw-p 00000000 00:00 0
2ac57560b000-2ac57560c000 ---p 00000000 00:00 0 - 26
2ac57560c000-2ac57580c000 rw-p 00000000 00:00 0
2ac57580c000-2ac57580d000 ---p 00000000 00:00 0 - 27
2ac57580d000-2ac575a0d000 rw-p 00000000 00:00 0 
2ac578000000-2ac5780a6000 rw-p 00000000 00:00 0 
2ac5780a6000-2ac57c000000 ---p 00000000 00:00 0 
2ac57c000000-2ac57c098000 rw-p 00000000 00:00 0 
2ac57c098000-2ac580000000 ---p 00000000 00:00 0 
2ac580000000-2ac5800a6000 rw-p 00000000 00:00 0 
2ac5800a6000-2ac584000000 ---p 00000000 00:00 0 
2ac584000000-2ac584037000 rw-p 00000000 00:00 0 
2ac584037000-2ac588000000 ---p 00000000 00:00 0 
2ac588000000-2ac58802a000 rw-p 00000000 00:00 0 
2ac58802a000-2ac58c000000 ---p 00000000 00:00 0 
2ac58c000000-2ac58c098000 rw-p 00000000 00:00 0 
2ac58c098000-2ac590000000 ---p 00000000 00:00 0 
2ac590000000-2ac5900e9000 rw-p 00000000 00:00 0 
2ac5900e9000-2ac594000000 ---p 00000000 00:00 0 
2ac594000000-2ac594084000 rw-p 00000000 00:00 0 
2ac594084000-2ac598000000 ---p 00000000 00:00 0 
2ac598000000-2ac598098000 rw-p 00000000 00:00 0 
2ac598098000-2ac59c000000 ---p 00000000 00:00 0 
2ac59c000000-2ac59c0a5000 rw-p 00000000 00:00 0 
2ac59c0a5000-2ac5a0000000 ---p 00000000 00:00 0 
2ac5a0000000-2ac5a0021000 rw-p 00000000 00:00 0 
2ac5a0021000-2ac5a4000000 ---p 00000000 00:00 0 
2ac5a4000000-2ac5a40a2000 rw-p 00000000 00:00 0 
2ac5a40a2000-2ac5a8000000 ---p 00000000 00:00 0 
2ac5a8000000-2ac5a8021000 rw-p 00000000 00:00 0 
2ac5a8021000-2ac5ac000000 ---p 00000000 00:00 0 

However, there are still quite a few anonymous segments in there, that don't correspond to an mmap call.  Is there something else that could have created them?

Thanks,

David
david.muse@firstworks.com

Re: thread heap leak?

[Florian Weimer]

* David Muse:

> I can correlate call number 6 and calls numbered 10-27 with the
> process map.  Presumedly, 1-5 and 7-9 were unmapped.  10-27 appear to
> be thread stacks, considering their size, and that they were called
> with the MAP_STACK option :)

The other regions appear to be 64 MiB heaps created by malloc, with
some regions not backed by storage.  There should be at least one such
heap for each thread.  They will be reused for new threads eventually.

Thanks,
Florian

Re: thread heap leak?

[David Muse]

On Sat, 27 Apr 2019 11:35:34 +0200
Florian Weimer <fw@deneb.enyo.de> wrote:

> * David Muse:
> 
> > I can correlate call number 6 and calls numbered 10-27 with the
> > process map.  Presumedly, 1-5 and 7-9 were unmapped.  10-27 appear to
> > be thread stacks, considering their size, and that they were called
> > with the MAP_STACK option :)
> 
> The other regions appear to be 64 MiB heaps created by malloc, with
> some regions not backed by storage.  There should be at least one such
> heap for each thread.  They will be reused for new threads eventually.
> 
> Thanks,
> Florian
> 

Is there a case where they wouldn't be reused, or where the VIRT might grow to 2G or more before they are?  I think that's what I'm seeing.  Those heaps pile up until the VIRT is about 2G, then the app crashes.

Thanks,

David
david.muse@firstworks.com

Re: thread heap leak?

[Florian Weimer]

* David Muse:

> Is there a case where they wouldn't be reused, or where the VIRT might
> grow to 2G or more before they are?  I think that's what I'm seeing.
> Those heaps pile up until the VIRT is about 2G, then the app crashes.

If you create 32 threads which make some long-term allocations and
then exit, without creating new threads, there will be 32 such heaps,
occupying 2 GiB of address space.  They will only get reused if you
create new threads.

Re: thread heap leak?

[David Muse]

On Mon, 29 Apr 2019 07:43:36 +0200
Florian Weimer <fw@deneb.enyo.de> wrote:

> * David Muse:
> 
> > Is there a case where they wouldn't be reused, or where the VIRT might
> > grow to 2G or more before they are?  I think that's what I'm seeing.
> > Those heaps pile up until the VIRT is about 2G, then the app crashes.
> 
> If you create 32 threads which make some long-term allocations and
> then exit, without creating new threads, there will be 32 such heaps,
> occupying 2 GiB of address space.  They will only get reused if you
> create new threads.
> 

Ahh, ok.  I have a couple of questions then...

Is the 64MB segment size a result of my app doing 64MB of allocations, or is that a default heap size?  Is that tuneable?

Is there a way to inspect the base address of a thread's heap from within the app?

If a thread exits, is its heap marked as available?  If so, is this visible to the app?

At what point do new threads recycle old heaps?  Eg. Does a newly created thread just grab a heap if an unused one is available, or is there a minimum number of old heaps that have to pile up before they will be recycled?  If there's a minimum number, is that tuneable?

In a 64-bit app (on suse linux running on AWS (Xen)), should a malloc() crash when the address space grows to 2G?  I ask because my app was originally compiled as a 32-bit app, and we noticed that a malloc() would crash when the address space grew to 2G.  This made sense, but we recompiled it as a 64-bit app and still see the same behavior.

Thanks!

David
david.muse@firstworks.com

Re: thread heap leak?

[DJ Delorie]

David Muse <david.muse@firstworks.com> writes:
> Ahh, ok.  I have a couple of questions then...

Some of the answers are in the wiki:
https://sourceware.org/glibc/wiki/MallocInternals

> Is the 64MB segment size a result of my app doing 64MB of allocations,
> or is that a default heap size?  Is that tuneable?

Tunables are documented in the manual, or in manual/tunables.texi in the
source tree.  No tunables control the heap sizes, which are defined by
the two constants HEAP_MIN_SIZE (32kb) and HEAP_MAX_SIZE (1Mb for 32-bit
or 64Mb for 64-bit, IIRC)

> Is there a way to inspect the base address of a thread's heap from
> within the app?

As per the wiki, the base address of the heap is just the pointer,
masked to the right number of bits.  All heaps begin at a power of two.

> If a thread exits, is its heap marked as available?  If so, is this
> visible to the app?

I don't think any heap-specific information is available to the app.

> At what point do new threads recycle old heaps?  Eg. Does a newly
> created thread just grab a heap if an unused one is available, or is
> there a minimum number of old heaps that have to pile up before they
> will be recycled?  If there's a minimum number, is that tuneable?

First off, don't confuse heaps with arenas.  There are a fixed max
number of arenas, but each arena can have more than one heap as more
memory is required.  Heaps may be returned to the kernel if all their
memory is free'd, arenas are put on a free list when they're not used.
New threads prefer to attach to an arena on the free list, else a new
one is created if the max isn't reached, else arenas are shared.

> In a 64-bit app (on suse linux running on AWS (Xen)), should a
> malloc() crash when the address space grows to 2G?

No.

(technicality: malloc() should never *crash* anyway, but it may return
NULL and cause your application to crash ;)

Re: thread heap leak?

[David Muse]

On Tue, 30 Apr 2019 19:55:54 -0400
"Carlos O'Donell" <codonell@redhat.com> wrote:

> On 4/30/19 5:48 PM, DJ Delorie wrote:
> > David Muse <david.muse@firstworks.com> writes:
> >> Ahh, ok.  I have a couple of questions then...
> > 
> > Some of the answers are in the wiki:
> > https://sourceware.org/glibc/wiki/MallocInternals
> > 
> >> Is the 64MB segment size a result of my app doing 64MB of allocations,
> >> or is that a default heap size?  Is that tuneable?
> 
> The first allocation of a new heap (attached to a given arena) creates
> the virtual-address reservation of a size that matches the default
> heap size, which is 64MiB for a 64-bit process.
> 
> This does not consume any memory though, it's just VA. RSS is used only
> when you start dirtying pages.
> 
> > Tunables are documented in the manual, or in manual/tunables.texi in the
> > source tree.  No tunables control the heap sizes, which are defined by
> > the two constants HEAP_MIN_SIZE (32kb) and HEAP_MAX_SIZE (1Mb for 32-bit
> > or 64Mb for 64-bit, IIRC)
> 
> And even if it was a tunable it would only change the increment of VA
> reservation, and not the RSS used by the application e.g. you would
> add X-sized heaps to the arena instead of Y-sized heaps.
>   
> >> Is there a way to inspect the base address of a thread's heap from
> >> within the app?
> > 
> > As per the wiki, the base address of the heap is just the pointer,
> > masked to the right number of bits.  All heaps begin at a power of two.
> 
> Also, there isn't anything to inspect, the heap is an internal detail
> of the implementation. You still haven't found the root cause of the
> failure you're seeing.
> 
> >> If a thread exits, is its heap marked as available?  If so, is this
> >> visible to the app?
> > 
> > I don't think any heap-specific information is available to the app.
> 
> Correct. The heaps are an implementation detail. We really really should
> have a heap dumper, a visualizer for the dump, and analysis tooling to
> allow developers to see how the heap is interacting with their allocation
> patterns... but we don't (yet).
> 
> >> At what point do new threads recycle old heaps?  Eg. Does a newly
> >> created thread just grab a heap if an unused one is available, or is
> >> there a minimum number of old heaps that have to pile up before they
> >> will be recycled?  If there's a minimum number, is that tuneable?
> > 
> > First off, don't confuse heaps with arenas.  There are a fixed max
> > number of arenas, but each arena can have more than one heap as more
> > memory is required.  Heaps may be returned to the kernel if all their
> > memory is free'd, arenas are put on a free list when they're not used.
> > New threads prefer to attach to an arena on the free list, else a new
> > one is created if the max isn't reached, else arenas are shared.
> 
> Yeah, there is a terminology issue here, most developers think of their
> application as having 2 things: a stack, and a heap. This isn't quite
> the truth in a modern OS and is perhaps an oversimplification.
> 
> >> In a 64-bit app (on suse linux running on AWS (Xen)), should a
> >> malloc() crash when the address space grows to 2G?
> > 
> > No.
> 
> Agreed. You need to do a root cause analysis of this failure, perhaps
> involving SUSE. However, Andreas (SUSE) commented upstream in this
> issue thathe hasn't seen anything like this.
>   
> > (technicality: malloc() should never *crash* anyway, but it may return
> > NULL and cause your application to crash ;)
> 
> David, I appreciate that you keep coming back to the list to discuss
> this issue, and I find it very interesting to watch your progress. I hope
> you get to the root cause!
> 
> -- 
> Cheers,
> Carlos.
> 

Thanks for all of the help and info guys.

I never got to the bottom of this problem, but it mysteriously just stopped happening, with no changes to the app, no system updates, and no changes to user behavior.  It was reliably happening 4 or 5 times a day, then just stopped happening, and hasn't happened in weeks.

The only thing I can imagine is that the VM host (Xen at AWS) was somehow causing 64-bit apps to crash, in the guest, when their VIRT hit 2Gb, and that was fixed behind-the-scenes.

I may have more questions if the problem crops up again, but for now, all is well.

Thanks again,

David Muse
david.muse@firstworks.com