Quickly Analysing A Heap Memory Leak by Jack Shirazi

oh we're starting excellent okay so this screen is what you want to take a picture of if you're gonna take any pictures and it's covering pretty much everything that we're gonna do so if you know all this you can leave the room now because it's pretty crowded we have four questions that we want to answer that's the one at the top the methodology and it's a methodology it's a generic methodology for any memory leak I'm going to be looking at heat memory leaks but that methodology stands for any memory leak if you answer those questions you've solved a leak and the tools I'm going to be looking at there sits that list of them I'm going to use GC viewer to look at the GC logs I'm gonna do some heap dumping some histogram and I'm gonna use eclipse mat and then I'll use visual VM as my profiler and I'll explain what I'm doing with each of those and over there in the right hand corner is Who I am so familiar with it you're welcome to leave the room there's lots of other interesting when not familiar with it then hopefully this is worthwhile these pictures are from the hotels for comments Instagram account they're all competition winners of a hotel's calm this is Vietnam if you want to go there beautiful okay so the four questions that we're gonna answer don't have a leak what is leaking what's keeping them alive where is it leaking from so let's start with and that's that's a logging before and after Java nine you should have juicy logging turned on for your application there is almost no overhead nobody does not recommend it to boot it accurately everybody recommends that you have it on so make sure that you do have juicy logging on okay so what I'm going to do first of all is I'm going to show you a particular juicy logs viewer we go over here and I'll kick it off I've got a GC so I'm using GC viewer which there's lots of them most of them are free lots of them there's quite a few of them most of them are free there's one called sensin which isn't free but gives you some very good information so it can be worth paying for it if you don't know what you're doing so this is GC viewer I will let me just load something and then I'll magnify it so you can see what I'm looking at so this is a GC log I don't know why it's okay let me make that a bit bigger so what what I have here is this tool I'll make it even bigger kind of make it bigger yes I can so I've loaded in loaded in a log you can you could any GC log that your JVM produces you can load it into here and you can actually load it in while it's live while it's generating data there's a button up here which is the refresh button and there's one that which will automatically refresh it every few seconds so you can see it happening at live so what I've loaded in is a juicy log now G sees garbage collections I'm talking about if you don't know what Juicy's are they're garbage collections they're they have two interesting parameters one is how long they take and the other is how much of the heap is being used up there's not the garbage creation about how much the heap is being yeah how much memory is being used so that's why down left here is an axis with two different numbers the one on the right here is seconds or yeah is seconds there 0.011 seconds in this case and the one on the left is megabytes 110 megabytes so those there's a dual scale on the left and there's a view option up here where you can turn on and off colors for various things that you want to measure so here I've turned on a few of them I've turned on these green lines they're a garbage collection and the height of that corresponds to the time it took the red and the blue on the other hand are how much heap has been used in your memory the red is the overall memory that's available to application the blue is how much has been used and because this is garbage collections let me just magnify it a bit so you understand what you're looking at these are garbage collection so it's going up and down because the young generation gets full and then there's a garbage collection it empties out as much as it can and then that's this up sawtooth pattern okay so this is called GC viewer it's my preferred viewer of garbage collections but as I said there are others if you go to faster J com there is a menu option with a list of all the garbage collectors that are available so I am going to open the reason why you want to look at garbage collectors and let me just magnify out so this is what a garbage collection log looks like when you have a memory leak okay and it's this is this is the most obvious kind there are other kinds you sometimes you get spikes where it blows out and doesn't have memory error and sometimes you get cash is being emptied after a while and so it goes back down and goes up but ultimately the point of having an out of memory error is that your heap got too full and it can't produce anymore memories so it runs out of memory and you will see that first happening in your juicy log so if you're monitoring it's it's an excellent way and certainly if there's any kind of leak gradually you can see it in the juicy log way before you get your ass of memory error so this is a great way of doing it now what you're looking for very specific things when you've got a memory leak your heap is getting gradually fuller it will try and free up memory that's the job of the garbage collector and each time it frees up memory it will drop how much is available and you'll get a with a memory that your guy you're guaranteed to get full GCS that's the that's the there's garbage collection to the young generation there's garbage collection to the old generation you'll guarantee that the old generation is going to get full up and it will have to do a full GC so what you're looking for specifically is amount of heap used after the full GCS so on this one I've got full GCS turned on as the big black lines here let me just focus in on that so you can see what I'm talking about up here on the top in the thick full juicy lines are black big black lines there it's not my choice of colors that's the colors that are there so each time I get one of these vertical black lines it was a full GC and what I'm looking at is the heap after the four GC so this the bottom of the blue after one of these black lines so is there there's one there's another there's another and the point is that after for each one of these it's going up now if there's no memory leak it would be flat it could be any level it depends on how many live objects you have for your standard application but it would be roughly flat it might go up and down and check a little bit but it'll be flat but with a memory leak it's guaranteed to go up because your memory is getting more and more full of these objects that are leaking there you can't get rid of and that's why this is very very simple to see and then you get to this state where lots and lots of full GCS happen all together and your application slows to a crawl because actually it's not really doing your application it's just doing garbage collection and you've built an application that does garbage collection a lot which is not the ideal situation and this is the point where everything slowed down and every Sun starts screaming and they've actually noticed there's a problem but you could have noticed this problem way way before so this is fairly standard and very straightforward turn on duty logging user do see viewer to view it or use any GC viewer to hear it and there we are that was tool number one so that's really simple really straightforward just look at the heap after each whole generation or four GC or majors you see whichever one you want to call it the next tool I'm going to look at our histograms so we answer the question the first question do I have a leak in that case the GC viewer showed you very straightforward second question is what is it that's leaking so let me see I have an application that clearly it will leak let me just kick it off this is an eclipse ide I know most of you use IntelliJ I use Eclipse because well I'll tell you later so why am I looking at I am looking at that so let's go and do JPS which is in your bin directory and it's the same as PS but defines the Java programs so there's the fastly application that I kicked off that's the process ID and in your again in your bin directory you have this tool called J map can you see it at the bottom let me let me just ctrl C and bump it up a bit okay so there is a J map in your bin directory that's a very useful tool and I am going to get a histogram from it and I'll show you what the history um looks like so I need to just tell you on it here so live I want that's the live means I want it to actually do a little GC before it gives me the the numbers because we've got a memory leak so I don't any dead objects that haven't been collected I want the dead objects that have been that have the dead objects that are releasing rather than the random dead objects that are dead but I haven't reached haven't been collected because of a garbage collection I'm not happening yet so that's J map let me just dump it into a file I'll call it t 160 so that's the thing I executed now let's have a look at that file and it's pretty straightforward okay so you get the first column which is just a numbering each of the rows for no particular reason and then there's the number of instances the number of bytes used by all of those instances and then the class name and the class name is fairly straightforward if it's just instances of a class instances of field it's a little bit more complicated if it's a an array so these are instances of hashmap dollar note which are the elements inside a hash map and this is an array of hash map dollar notes so there are 14 arrays of hash hash map dollar knows presumably 14 hashmaps there you can see the 14 there so that's an array that's standard puts the square bracket error and a semicolon at the end and then you've got also the the primitives that's a char that's a byte that's an int and these saying it's an array of char that's a char array and intr a byte array this is fairly straightforward quite easy to see and immediately I can see if I knew my application intimately and I wasn't expecting 108 thousand 208 something else's then I would say whoa that looks like a leak to me so with almost no effort using your histogram I can pretty much find a leak but let's say it's a little bit more complicated and I'm not sure what object is I've waited a little while I'll take a second histogram and then I'll go into bash because I write a Perl script but I don't know I only have part in Unix so all this is doing is merging those two files team into TT CSV so it's just a little policy I won't even bother telling you because it's just it's taking exactly you know it's using the class name as a key and it's just putting this in column 1 column 2 and then the for the next file and column 3 and column 4 so it's really straightforward you'll see when I open it there's nothing complex about it oh let me exit and make it bigger so you can see that just as I said the class is the key and then it's the the number of instances the number of bytes for the first sample and then the second sample let me just do a sort because we want to saw on I guess the number of instances is a good idea so that's sort on a number of instances up there okay so it's e actually well before I do that I'm gonna actually do a column where I'd if the number of instances because that's gonna be even easier so let me do that - that so here we have a column which is just the differences of the number instances and I'll swing that down to the bottom keep going there we go okay go back and it's all on the F column don't want a header was it my hate does not have editors and column F and I want the largest at the top so it's the other way around okay and that's our look what we've got so hey presto we have actually four objects that have increased which so if you think about it your standard application it's not leaking it's gonna have a set of objects and you do a garbage collection it's only the live objects and that set should be remain approximately the same because you'll create some objects but they'll get garbage collected anything that isn't leaking stays roughly the same anything that's leaking is going to increase in a number of instances that are there and the longer you you have a gap between these two histograms the longer the time is this is really straightforward and very simple that's gonna sometimes Excel is too clever for its own good so so what I'm seeing is that I've got something else is some char arrays and strings and some a shot notes so I have answered that question hang on I've answer that question what is leaking which classes I've actually got four classes that I know are leaking and they're obviously linked in some way I mean it's not it's not it's good not going to be surprising then obviously there's something else is the leaking but what can you expect from a quick example like this so that was that now the question the next question I'm asking is that we answered do I have a leak yes what is the key I found the class is very straight forward through the histograms what is keeping them alive okay so I have a leak but something must be keeping them alive it's not just a there's objects and they stay alive something is keeping the Nile what is it that's keeping them live nothing so far has told me that what I need for this is a heap dump so I have done a heap dump I used a map again it's less she does do a heap dump but there's other mechanisms to do heap thumps if you ping me if you look me up online and I'll send you all the slides so or you can look at recording all of these are available so I use eclipse mat so it clips mat is this is available as a standalone application but I I always used to use a clip so I just carry on using Eclipse because it's quite convenient because you can use it as a plug-in to your Eclipse of use it as an IDE which is why I've tended to stay with Eclipse anyway but you can use it completely as a standalone application you don't have to use the IDE so that's not a problem I will switch over to that and I will just switch to the Eclipse map view and I'm gonna load in a heap dump that I took earlier because it takes a little bit of time so I didn't want to wait around for it and this is a pretty quick talk so there's my leak and doing stuff this is the third tool were using we use GC viewer we used usage a map for the histogram and for dumping a leak and now we're using the Eclipse mat to analyze the heap so you get this when you load in the heap you get this dialog it says do you want to know that a leak suspects report it's very nice it actually says hang on I might be able to work out what the suspects are so let me do that and then I'll give you a report and there it is it takes a little while to come and you can see that okay so it's saying ah there's a problem suspect if I go back to the overview which is just in this other tab here then it's actually showing that me that most of the objects it partitions your application into roots from the roots and actually most of them are coming from one root but it's even clever and it's telling you exactly what it thinks so 80% of the time if you have a heap if you have a heap leak a leak in the heap this will tell you the right thing there are quite a lot of edge classes of leaks like for example if you've got a an ID and it's being duplicated at some low level so you get duplicate IDs of everything then you won't necessarily see that because all of the ideas are correct and they're all being held by something that's way down in the stack and the correct ones are held with you with the duplicated ones so you'll still see a leak but you won't necessarily see a root that says these are all the leaks because a lot of the time you go in there and if you start looking at the actual IDs they all look correct to you they don't really understand what it is so there's these edge cases where it can't identify and it they're really hard to identify anyway you can still use the tool but they're hard to identify both of them I'd say 80% of leaks this tells you straight away what the problem is so it's telling me it's a problem suspect number one it's saying oh I've got a class called fast leak and it's being held on by the the application class loader it's got to be held on by something in the JVM right and it's saying okay let me have a look at the details here so it's saying that I have my class here I launch a helper it's holding on to the class itself fast leak let me magnify this so you can see it so it's saying this is my JVM Clark JVM that's holding on to it this is my fast eat class and it has an instance variable called a cache and that a cache has a table and that's got a load of nodes and it's telling me over here on the right hand side just how much is retained how much of the heap is used so that's like that's most of the heat as 100 and I think the heap itself if I switch back to the other one it was around makes so the vast majority of the meat of the leek is held off this so straightaway I've answered my question there are if if it doesn't give you that really quickly I recommend looking at videos and how to use eclipse map there's a lot of other capabilities there's histograms like we don't have got in the last one there's a Dominator tree there's all sorts of things and you can you can go into there and start drilling down as far as you can but this was really straightforward and for the most part you can use eclipse mats or any memory analyzer to find what is holding on so that answered that third question what is it that's keeping my objects alive so I've established got a leak got something else and a few other things leaking and it's my this clasp which is holding on to the leak and then the last question is assuming it's not a simple little example like this where in my huge application of a hundred thousand lines of code because I could find I could start investigating all the code where is it is there a quick way of doing it yes there is a quick way of finding where the leak is did I start my I did so let me just kick off now any profiler that has a generational a tab that shows generations will work for this aspect here so let me go I'm going to attach fast leak and this is the fourth tool I'm looking at I'm using a profiler which has a generations it shows you the generations of the objects that are being monitored so most most standard profiles will do this I'm using visual VM so I want to with visual VM I just need to go over to the memory settings and I want to record allocation stack traces and let me kick that off so if you look at the the the tabs here focus in so you can see I've got the objects tracking them live tells you is it got this graphical view of how many bytes they're using so you can see what's taking up it's got a number it's got the live live objects account so very much that's the same numbers from the histogram we looked at earlier but then it's also got this column here which is called generations so this is not the age of the objects this is how many different aged objects there are it's a little subtle don't worry about it you don't actually need to know why you just need to know that it has to be a generations column that you can sort on that's all that's needed from the profiler because that will tell you exactly where it's sorted from so remember we've got a memory leak this is tracking all objects if I just sorted now I'll get all sorts of different objects in here but a memory leak only this is this is tracking objects that are dead but having been garbage collected yet so I just need to get rid of those ones so I'll go over to I think it's the monitor here and I'll execute a GC to get rid of any dead ones that can be collected because I want the live one the ones that I that are live I don't want to be live but our live that's where leak is and then I'll head back to the profiler and I'll look at the generations sort on them and there's three there at the top now if you remember from the go back to it sorry it's difficult to do this in if you remember from the spreadsheet we actually had four leaks and there's something else in these JVM classes the visual VM is only showing three of them that's because I've only tracked every tenth allocation not every allocation and also this is for free tool right so you get what you pay for but it's you know it's not too bad so I'll just say okay well this through these strings are leaking let me have a look at them so I'll take a snapshot and I'll show the allocation traces because remember we want to find where in the code we're leaking that's the that's the thing we're looking for here so it doesn't matter that I didn't get to something else as I can just focus on string and over here it's saying look at the big red bar there most of them are leaking from this plate so I'll expand that most of them are leaking from here most of them are leaking from here most of them are looking from here which is in the something reset method so of and then that's calling do something and that's also according something in it so their creators so I found a nasty suspect here which is something got reset where most of my stuff are leaking from and it's not a JVM class it's one of my classes so that makes it much more suspicious because it's typically not a JVM class that sneaking is it it's almost always my class yeah well I can't help it I don't write that great code so okay so what I've got over here I've got some things I can see these are the things that are leaking but if you go back to here there aren't any some things that are leaking there but there are something else's that are leaking so I've got something else down here and I've done the cardinal sin of making my hash code immutable it's dependent on something that can change and the reset changes it and so consequently when it tries to find it in the hash map to remove it it can't find it because it's got a different hash code so since I mean this is this is actually the single most common leak in all applications the vast majority of applications have the sneak for the most part you don't notice it because there aren't that many objects that are leaking but it's very very common it doesn't matter if you if you have a leak that doesn't matter it doesn't matter right but in this case it was it was fairly straightforward so Whistlestop this is uh I could go through this we've got three minutes no okay so that's it those are the tools let me just go through the but there that's that's it we've just got time for a question if anybody has one you shouldn't because it was such a brilliant presentation and clear as crystal [Music]

Channel: Devoxx

Views: 11,286

Rating: 4.8928571 out of 5

Keywords: DevoxxUK, DevoxxUK2019

Id: JoQN4xoXY5Y

Length: 28min 34sec (1714 seconds)

Published: Thu May 16 2019