[Red5] Red5 0.7 leaking memory per connection! (was: jmap -histo:live ... is that normal? :-o)
Daniel Rossi
spam at electroteque.org
Sat Apr 5 05:34:36 PST 2008
That will explain my out of memory issues with a huge heap space of
3.5GB. I'll monitor again and might need a reboot.
On 06/04/2008, at 12:20 AM, Steven Gong wrote:
> Hi Thomas,
> Thanks for reporting this. Can you create a JIRA issue, attach your
> test app and describe how to reproduce it? Thank you again!
>
> On Sat, Apr 5, 2008 at 9:09 PM, Thomas Auge <auge at virtues.net> wrote:
> Well, I started a fresh server process and hit it with simple rtmp
> connect/disconnect, never more than 1 concurrent connection. (Server
> Ver
> = yesterdays trunk)
>
> The application I used to test doesn't do anything that isn't
> specifically called by the client. So only the appJoin/appLeave stuff
> was executed, which only adds a logfile entry.
>
> After "a few" connections (to allow for buffer allocation and whatnot)
> memory usage looked like this:
>
> New Generation (Eden + 1 Survivor Space):
> capacity = 1966080 (1.875MB)
> used = 1213632 (1.15740966796875MB)
> free = 752448 (0.71759033203125MB)
> 61.728515625% used
> Eden Space:
> capacity = 1769472 (1.6875MB)
> used = 1017024 (0.96990966796875MB)
> free = 752448 (0.71759033203125MB)
> 57.47612847222222% used
> From Space:
> capacity = 196608 (0.1875MB)
> used = 196608 (0.1875MB)
> free = 0 (0.0MB)
> 100.0% used
> To Space:
> capacity = 196608 (0.1875MB)
> used = 0 (0.0MB)
> free = 196608 (0.1875MB)
> 0.0% used
> tenured generation:
> capacity = 4046848 (3.859375MB)
> used = 3863016 (3.6840591430664062MB)
> free = 183832 (0.17531585693359375MB)
> 95.4574028972672% used
> Perm Generation:
> capacity = 12582912 (12.0MB)
> used = 11693904 (11.152175903320312MB)
> free = 889008 (0.8478240966796875MB)
> 92.93479919433594% used
>
>
> After roughly 1000 connects/disconnects it looked like this:
>
> Heap Usage:
> New Generation (Eden + 1 Survivor Space):
> capacity = 7929856 (7.5625MB)
> used = 6670280 (6.361274719238281MB)
> free = 1259576 (1.2012252807617188MB)
> 84.11602934529958% used
> Eden Space:
> capacity = 7077888 (6.75MB)
> used = 5818312 (5.548774719238281MB)
> free = 1259576 (1.2012252807617188MB)
> 82.20406991464121% used
> From Space:
> capacity = 851968 (0.8125MB)
> used = 851968 (0.8125MB)
> free = 0 (0.0MB)
> 100.0% used
> To Space:
> capacity = 851968 (0.8125MB)
> used = 0 (0.0MB)
> free = 851968 (0.8125MB)
> 0.0% used
> tenured generation:
> capacity = 17100800 (16.30859375MB)
> used = 16006112 (15.264617919921875MB)
> free = 1094688 (1.043975830078125MB)
> 93.59861526946108% used
> Perm Generation:
> capacity = 12582912 (12.0MB)
> used = 12024400 (11.467361450195312MB)
> free = 558512 (0.5326385498046875MB)
> 95.56134541829427% used
>
>
> Each connection lasts a fraction of a second, so nothing should make
> it
> into the tenured generation. And there should be no reason for the new
> generation to grow either, because its only needed to handle one
> connection.
>
> To make sure it's not a problem with my app, I ran it on the test app
> that comes with red5 again. Same effect: New and tenured generation
> grew
> over time. When each of those generations reached 100%, garbage
> collection was run as expected. My VM is configured to increase heap
> size when usage after GC is at over 80%. With each garbage collection
> there was less than 20% free space and the total heap capacity was
> expanded.
>
> I repeated the test with 0.7.0 with the same effect. After 700 single
> non-concurrent connections to the test app, the tenured space has
> slowly
> grown from 2 allocated megabytes to 12mb. Same effect with VM
> default GC
> options. I don't think it's a java problem.
>
> On a more practical note, as mentioned before, my live application
> supports over 200 concurrent users with roughly 100 megabytes of
> allocated memory (right after startup). Nothing is stored in the
> app, it
> just passes data from client to client. A day later with roughly the
> same amount of clients, the allocated memory has grown to over 500mb
> of
> which 324 are used for the tenured generation.
> The part I don't get is, that Eden space has grown to 146 megs, too.
> For
> what? :-o
>
> Prove me wrong please, but I think something is leaking memory here. I
> had actually planned to add different server functionalities to the
> test, to find the culprit, but it seems just connecting to the server
> already wastes a good chunk of memory. (Somewhere around the
> 15kb/connection ballpark). The live server leaking memory had seen
> around 16k connections when it had 330mb in the tenured space.
> Compared
> to shorter runtime values I am sure up to 100meg of that is really
> needed, but if you assume 15k lost/connection, as the tests suggest,
> then you end up with 234MB leaked, which sounds about right.
>
> And here's the fun part: In 0.6.2 this problem does not exist. If I
> run
> the same test on 0.6.2 the tenured generation balances out at ~3.29mb
> and the eden generation collects nicely into a few kb after 100
> connections. (Hard to say how much exactly, but funny enough,
> somewhere
> in the 20kb ballpark. You know, we were losing 15kb at each connection
> in 0.7? Seems that's part of what red5 needs to support one
> connection ;)
> Even after 500 connections, the tenured generation is still at 3.5MB
> capacity and 3.42MB used. After roughly 600 connections the tenured
> space GCed nicely into 2.5MB.
>
> I am going got miss the multithreaded application adapater, but I'll
> drowngrade for now. ;)
>
>
> And just for shits and giggles, here is the memory usage of a live
> server (0.7) 5 minutes after startup while serving almost 300
> concurrent
> connections (half of it video, half of it heavy shared object
> shuffling
> ;), and having seen only around 1000 connections total. Red5 is NOT
> memory intensive. Only 0.7 is after prolonged use. :(
>
> Heap Usage:
> New Generation (Eden + 1 Survivor Space):
> capacity = 18808832 (17.9375MB)
> used = 9229976 (8.802391052246094MB)
> free = 9578856 (9.135108947753906MB)
> 49.07256335746951% used
> Eden Space:
> capacity = 16777216 (16.0MB)
> used = 8318504 (7.933143615722656MB)
> free = 8458712 (8.066856384277344MB)
> 49.5821475982666% used
> From Space:
> capacity = 2031616 (1.9375MB)
> used = 911472 (0.8692474365234375MB)
> free = 1120144 (1.0682525634765625MB)
> 44.86438382056452% used
> To Space:
> capacity = 2031616 (1.9375MB)
> used = 0 (0.0MB)
> free = 2031616 (1.9375MB)
> 0.0% used
> tenured generation:
> capacity = 40947712 (39.05078125MB)
> used = 40784192 (38.89483642578125MB)
> free = 163520 (0.15594482421875MB)
> 99.60066144843454% used
> Perm Generation:
> capacity = 12582912 (12.0MB)
> used = 12374056 (11.800819396972656MB)
> free = 208856 (0.19918060302734375MB)
> 98.3401616414388% used
>
>
>
> Happy bug hunting! I'd help, but java gives me the creeps. ;)
>
> Thomas
>
>
> P.S.: jmap -histo output looks just as broken as below on 0.7.0 on a
> different machine. So I guess this is "normal" in a way. It is just
> annoying, that most memory is used by:
> 1: 67210 4387760 [C
> 2: 8829 4033872 [B
> ... which does not really help much, does it? ;)
>
> In 0.6.2 the output has similar broken references, but the top memory
> usage are different whatevers ;). So [C and [B could be the problem.
> Whatever they are. ;) Maybe some debug information is missing? Does
> java
> even have or need debug references? ;-)
>
>
>
>
> Daniel Rossi wrote:
> > any ideas how to check this, i think the cpu thing is the gc going
> > crazy, does it ramp up and down ? We need to somehow come up with
> the
> > best java configure line to run red5 in I guess ?
> >
> >
> > On 05/04/2008, at 10:28 AM, Thomas Auge wrote:
> >
> >> Hi all,
> >>
> >> I am having some memory issues with red5. Basically over time it
> uses
> >> all available memory. Most of it ends up in the tenured generation.
> >> Funny enough, it's not related to clients. When the server starts
> >> up, it
> >> supports over 300 clients with only 100MB of ram. But it keeps
> >> growing.
> >> When it hits the limit of memory it's allowed to take, garbage
> >> collection runs wild, which is quite obvious from the CPU load.
> >>
> >> The funny thing is, when I check histo:live, I see this:
> >>
> >> num #instances #bytes class name
> >> ----------------------------------------------
> >> 1: 16876 8385376 [B
> >> 2: 157904 5052928
> >> java.util.concurrent.ConcurrentHashMap$Segment
> >> 3: 162252 3894048
> >> java.util.concurrent.locks.ReentrantLock$NonfairSync
> >> 4: 54184 3707544 [C
> >> 5: 26950 3079704 <constMethodKlass>
> >> 6: 157904 2601128
> >> [Ljava.util.concurrent.ConcurrentHashMap$HashEntry;
> >> 7: 9744 2473720 [I
> >> 8: 26950 2156728 <methodKlass>
> >> 9: 36112 1577920 <symbolKlass>
> >> 10: 18779 1550528 [Ljava.util.HashMap$Entry;
> >> 11: 2790 1416824 <constantPoolKlass>
> >> 12: 56729 1361496 java.lang.String
> >> 13: 2790 1182248 <instanceKlassKlass>
> >> 14: 38774 930576 java.util.HashMap$Entry
> >> 15: 2545 872656 <constantPoolCacheKlass>
> >> 16: 9869 789520
> >> [Ljava.util.concurrent.ConcurrentHashMap$Segment;
> >> 17: 16820 672800 java.util.HashMap
> >> 18: 1804 404096
> >> org.red5.server.net.rtmp.RTMPMinaConnection
> >> 19: 9869 394760
> >> java.util.concurrent.ConcurrentHashMap
> >> 20: 1804 375232
> >> org.apache.mina.transport.socket.nio.SocketSessionImpl
> >> 21: 11750 365752 [Ljava.lang.Object;
> >> 22: 10001 320032
> >> org.apache.commons.collections.map.AbstractLinkedMap$LinkEntry
> >> 23: 3085 296160 java.lang.Class
> >> 24: 3595 220616 [S
> >> 25: 1813 217560 java.net.SocksSocketImpl
> >> 26: 8540 204960 javax.management.ObjectName
> >> $Property
> >> 27: 1804 187616 sun.nio.ch.SocketChannelImpl
> >> 28: 4467 185000 [[I
> >> 29: 7223 173352 java.net.InetSocketAddress
> >> ...
> >>
> >>
> >> That looks unealthy in a way. Any ideas what could cause such a
> >> garbled
> >> output?
> >>
> >> Thanks,
> >>
> >> Thomas
> >>
> >> P.S.: I am using the latest trunk.
> >>
> >> _______________________________________________
> >> Red5 mailing list
> >> Red5 at osflash.org
> >> http://osflash.org/mailman/listinfo/red5_osflash.org
> >
> >
> > _______________________________________________
> > Red5 mailing list
> > Red5 at osflash.org
> > http://osflash.org/mailman/listinfo/red5_osflash.org
> >
>
>
> _______________________________________________
> Red5 mailing list
> Red5 at osflash.org
> http://osflash.org/mailman/listinfo/red5_osflash.org
>
>
>
> --
> Best Regards
> Steven Gong
>
> InfraRed5 Red5 Consultant: http://www.infrared5.com, steven at infrared5.com
>
> Red5 Developer: http://osflash.org/red5, http://jira.red5.org/confluence/display/
> ~steven/Home
>
> Javaflash Project Founder and Maintainer: http://osflash.org/javaflash
> _______________________________________________
> Red5 mailing list
> Red5 at osflash.org
> http://osflash.org/mailman/listinfo/red5_osflash.org
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://osflash.org/pipermail/red5_osflash.org/attachments/20080406/55873ec9/attachment-0001.html
More information about the Red5
mailing list