Thread Dump Analysis Generation Techniques - Part 2

hi everyone my name is Pierre Charbonneau welcome to the jvm trader manassas garrison techniques for two so what is the agenda for today so essentially we're going this is a continuing session from the port one so today we're going to learn how to generate read them using Apache Tomcat 9 right which is very well most or the top most popular Java container on the servlet container side and we're going to learn also as the second subject to do a generic consecutive tread of snapshots in order to break down the response time of slow request sure start to shoot this technique as well as the port 2 of decision today which is very useful for production support role again on the technology stack we have similar setup as the last video essentially Java hotspot 1.8 64-bit of course Apache Tomcat 9 which is the m4 built and the abun 2 15.0 4 still in our lab environment the tsardom generation tools are going to use today or again the u.s. native command kill - treat the GDK j stack utility and java show vm so those are the tools that were going to use also to explain that technique of charting contiguous nap shots in order to identify the root cause of slowness here's our lab setup so as you can see we did install the apache tomcat 9 so what you see here is the actual the manager console right off tom cat so i'm not going to spend a course on tomcat today but essentially that's the default console that we use for tomcat and what we did was created a very simple program essentially it's a JSP file from the example web app after on cat 9 and the only thing that we did was to create initiate a bit of a sleeping of the tread right to simulate a request or a JSP execution time taking 60 seconds this very simple program will be very useful to demonstrate the tread dam generation techniques and the consecutive approach as well ok so this is the program as you can see essentially just questing the tread to sleep for 20 seconds and we're doing that three times in a row just to generate a different line number which will be easier to track from a tread stack trace or note read them so back in the console right so of course when you're running Tomcat on Linux not to get at read them you need the P idea of the process right so here as you can see this is a default installation at the Tomcat 9 Tomcat it was already started just to save us some time so first thing I do is extract the PID of the Tomcat process 3 3 6 1 in this case okay so that's you're getting from the actual console of Linux now I also have Java visual vm open so as you can see Java VM was able to detect our Tomcat process with paid 3 3 6 1 which is the same one here of course from the console so now I'm going to demonstrate the technique to generate at read them as we saw painting there are three techniques that you can use the first one which is the native one is to use kill - tree so where's that tread imprinted right where they came on is tree well you need to go under the default install a tomcat as you see there's the katana at out log file the tread dam always can print it out in a standard output file as we saw in the earlier session or Oracle WebLogic I'm going to generate at Red Dog chemistry using the period Tomcat that's it you won't see anything in the screen the trailer won't get printed out as you can see in the log file so if you do a quick more on the cattle in a log file you can see that trading was generated just now and of course it contains the detail of all the shreds at the time of course there's no requests being executed right now so there won't be any data to analyze for us ok so that just to shoot the technique so kill - tree for Tomcat typically we will end up with a cat Helena that out file which is standard output cost depends of reconfiguration of Tomcat might have a couple of option but that's the default location where you will see the actual shred them file the second technique is to use a G stack as we saw earlier that one is also quite good instead of again a native it will just print at read them in the screen tray stack with the pit and you get this time it shred them from the actual console directly that was also very useful when you do profiling type of analysis using tread them and finally Java of M itself so here as you can see the process is attached joy humans might think the tread so from Giorgio's vm directly can monitor the Tomcat hell and of course you can generate read them here which similar to what we saw in the Catalina and J stack you will get the native information about treads so now back to the program so we as I said we created a simple program to show you the tread in action so I'm going to do a nice executed actual JSP so I'm going to generate a few requests you see I'm executing that JSP I called slow tread GSP which will sleep 60 seconds and now going to start let's start with a visual VM first so if you look on a tread mentoring sections you will see some of the tread in Tomcat are now sleeping now if you get it shred them here we will locate that shreds from Tomcat so Tomcat typically we'll be using that training con named in convention HTTP non-blocking i/o right and then the port the listen port of the Tomcat process and then the tradition and if you look at a stack trace this is precisely our JSP right since I we initiate a JSP file you can see that that red line 1 1 6 which are generated servlet from the JSP is actually sleeping and if we scroll down and read a few requests against there's another shred shred 36 doing the same but this time at line 1 1 7 right as I want to generate because we have 3 calls of the treadle sleeps you will see a different line number and depending where the tread is sleeping so as you can see from Java room it's fairly easy to isolate the actual trail itself now let's redo the same tried a few more requests this time we're going back to the G stack so I'm going to generate G stack and then of course you can locate the actual tread and you can see the data the tree is actually sleeping at line 1 1 6 if you get another one now you will see that shred is sleeping as line 1 1 7 which is that typically the goal of geez I can't read multiple snapshots and the same can be achieved also let's say we get a few more requests will do a kill - tree again process ID right then we'll look again at the Catalina that out then can search for actual sleep sleep and then you will see the actual tread 38 sleeping at line 1 1 8 there's another one 37 right and it's fairly easy to search with a log file is not too big you can look for your application or the pattern of slowness so it's fairly straightforward but of course J stack is very convenient since it's printing the data directly from the so it's very useful so those are the techniques right for Tomcats very straightforward Tomcat is very lightweight so fairly easy to monitor now I'm going to show you next what I meant in the beginning by consecutive technique so if we go back at the program you can see right that shred is sleeping every 20 seconds at this line then after that we'll sleep again and sleep again so three times this will generate a different line number so when you have a problem let's introduction let's you have a high response time of let's see 15-20 seconds a very powerful technique is to generate do some tread um sampling it's called kind of tread I'm sampling so in this case you will generate read them every three to five seconds and then you'll look at the tread stack trace and see where the trail is stuck or what the tread is doing where is this waiting from a database from our animation web service call or maybe is there a lock contention they could be also a deadlock situation even though it's rare it's impossible so that technique will essentially break down the response time in silos and by reeving the stack trade you will to see what the trade is doing in this case what we want to demonstrate is a line number change in this example right since you see a line transitioning from one one six one one seven one one eight okay that's what when I demonstrate to do these techniques are going to you J stack and generate multiple snapshot of J stacked like this okay so okay that we're saying the logs directory the techniques ug stack the process ID and then we will create an output file and we'll call it thread on one trade on to to run for etc every five seconds on a single request we're going to do okay so let's start we're going to initiate another request now let's see this request live we see thread 36 is sleeping right now so we're going to get right our first snapshot shred dumb one right as you will see it created a single file which Adam one and we're going to the same thing after five seconds thread them to when the technique is very useful because you can as I said bending of the of their response time especially if you're getting like 10 15 20 seconds of delays Kandarian multiple snapshot about 3 5 seconds in between and anyone analyze the transition of the trade execution pattern right in between the snapshot and eventually you will know exactly you know what where the problem is so in this case we have quite a few snaps already the tread is still spinning as you can see so we'll probably get a last snapshot and then we'll start to do the analysis so the request is completed as you can see our thread 36 which is the same thread 36 azusa now let's look at the first thread dump one as you will see if we search for slow which is our JSP name the actual trail is sleeping at line 1 1 6 this is from our first snapshot now let's see snapshot tree actually sleeping in line 1 1 7 so this is actually the same tread the same request right but of course since we simulated kind of as soon as that's why we said transition right because the first sleep called is complete then this is our second sleep call and eventually we'll see our last one line 1 1 8 which is our third sleep call to the tread so that's why I wanted to demonstrate because that technique is very powerful bribe because depending what the trail is doing you able to compare between the tread um snapshots like we did with J stack where the trail is doing so you will be able to do as I call it a transaction or response time breakdown analysis you you'll basically break down the slowness and in bucket and then you may determine that yeah I had one database call that took 2 seconds o add this web service call that took 15 seconds and maybe in-memory processing took less than one second right so with this analysis you will be able to identify the top two or three contributors of your performance slowness now this is not going to replace a full profiling activity but in production it's very powerful especially if you don't use advanced EPM technologies tools like you know Donna trace or dynamic so even you were like this technique is very powerful to to break down response time and show you potential problem I hope that you enjoyed this video now this will complete the trade em generation techniques as we saw and then of course the next video on the treadle will be focusing on the tread demand Alice's patterns which I will show you multiple type of problems that we will simulate in our lab and then I'll show you how to analyze that and we're going to use that across multiple containers worker WebLogic batch tomcat and also ABM WebSphere ok so thanks for watching

Channel: Pierre-Hugues Charbonneau

Views: 9,253

Keywords: Java, Java Virtual Machine, Thread Dump, JVM, Apache Tomcat, Ubuntu, Linux Kernel, Java VisualVM

Id: sdDooupSVT8

Length: 11min 1sec (661 seconds)

Published: Sat Mar 26 2016