{"id":2807,"date":"2022-04-29T12:10:44","date_gmt":"2022-04-29T03:10:44","guid":{"rendered":"https:\/\/jennifersoft.com\/en\/uncategorized\/%ec%8a%a4%ed%83%9d%ed%8a%b8%eb%a0%88%ec%9d%b4%ec%8a%a4-%ec%83%98%ed%94%8c%eb%a7%81%ec%9d%84-%ec%9d%b4%ec%9a%a9%ed%95%9c-%ec%84%b1%eb%8a%a5-%eb%b6%84%ec%84%9d-sfrstacktrace-flight-recorder\/"},"modified":"2022-05-10T10:00:05","modified_gmt":"2022-05-10T01:00:05","slug":"2022-05-10","status":"publish","type":"post","link":"https:\/\/jennifersoft.com\/en\/blog\/tech\/2022-05-10\/","title":{"rendered":"Stacktrace Sampling Based Performance Analysis \u2013 SFR (Stacktrace Flight Recorder)"},"content":{"rendered":"\n<figure class=\"wp-block-image\"><img decoding=\"async\" src=\"https:\/\/jennifersoft.com\/ko\/wp-content\/uploads\/sites\/2\/2022\/05\/\u1100\u116e\u11a8\u1106\u116e\u11ab_\u1107\u1173\u11af\u1105\u1169\u1100\u1173_\u1111\u1173\u11af\u1105\u1166\u110b\u1175\u11b7\u1109\u1173\u110f\u1169\u1111\u1173_\u110f\u1165\u1107\u1165_220501-1024x614.jpg\" alt=\"\" class=\"wp-image-10700\"\/><figcaption><br><\/figcaption><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">Since we improved the Java performance by using the\nstacktrace analysis function for individual transactions introduced in <a href=\"https:\/\/jennifersoft.com\/ko\/blog\/tech\/2021-10-18\/\" target=\"_blank\" rel=\"noreferrer noopener\">https:\/\/jennifersoft.com\/ko\/blog\/tech\/2021-10-18\/<\/a>&nbsp; last time, Jira has been still maintaining a\nhigh speed without a single restart (So, unfortunately, we don\u2019t have a chance\nto use the latest version of Jira.&nbsp;\nhahaha).<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Now, we are back with the function that can help our entire application performance analysis a little bit.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">A\nstory about developer Y starting his own hard struggle to resolve performance\nissues that cannot be done with individual transaction analysis.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Let\u2019s\nbegin now!<\/p>\n\n\n\n<h3 class=\"wp-block-heading\">Prologue<\/h3>\n\n\n\n<p class=\"wp-block-paragraph\">A\nvery peaceful day as usual. Developer Y was still working on APM collection\nserver stuff.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">But, he learned that similar types of issues are recently registered in Jira.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">The following stuff is displayed on the log of the collection server and the dashboard does not display any data.<\/p>\n\n\n\n<pre class=\"EnlighterJSRAW\" data-enlighter-language=\"generic\" data-enlighter-theme=\"atomic\" data-enlighter-highlight=\"\" data-enlighter-linenumbers=\"\" data-enlighter-lineoffset=\"\" data-enlighter-title=\"\" data-enlighter-group=\"\">server.data.2022-04-14.log:2022-04-14 15:33:04.833 KST [:ME:CommandFromViewServerProcessor] WARN  c.a.d.n.CommandFromViewServerHandler - Request from view takes much time to finish. request=CommandRequest(key=520:70,bodyLength=94), finish=350\/1000, wait=0, process=350&lt;br>\nserver.data.2022-04-14.log:2022-04-14 15:33:04.990 KST [:ME:CommandFromViewServerProcessor] WARN  c.a.d.n.CommandFromViewServerHandler - Request from view takes much time to finish. request=CommandRequest(key=520:70,bodyLength=94), finish=300\/1000, wait=0, process=300&lt;br>\nserver.data.2022-04-14.log:2022-04-14 15:33:08.186 KST [:ME:CommandFromViewServerProcessor] WARN  c.a.d.n.CommandFromViewServerHandler - Request from view takes much time to finish. request=CommandRequest(key=520:70,bodyLength=136), finish=401\/1000, wait=0, process=401&lt;br>\nserver.data.2022-04-14.log:2022-04-14 15:33:08.701 KST [:ME:CommandFromViewServerProcessor] WARN  c.a.d.n.CommandFromViewServerHandler - Request from view takes much time to finish. request=CommandRequest(key=520:70,bodyLength=136), finish=294\/1000, wait=0, process=294&lt;br>\nserver.data.2022-04-14.log:2022-04-14 16:28:02.497 KST [:ME:CommandFromViewServerProcessor] WARN  c.a.d.n.CommandFromViewServerHandler - Request from view takes much time to finish. request=CommandRequest(key=520:70,bodyLength=94), finish=300\/1000, wait=0, process=300<\/pre>\n\n\n\n<p class=\"wp-block-paragraph\">According\nto our simple analysis, each request is supposed to be processed within 1\nsecond, but it only takes from 0.2 to 0.4 seconds.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Wait\na minute.. Not even one second, but it finishes the performance improvement in\n0.x seconds. Is this possible?<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">He decided to use the function to analyze the stacktrace collected on the basis of transactions that we used last time.<\/p>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"779\" height=\"582\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_01-1.png\" alt=\"\" class=\"wp-image-2829\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_01-1.png 779w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_01-1-300x224.png 300w\" sizes=\"auto, (max-width: 779px) 100vw, 779px\" \/><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">Well, most of the transactions are processed in less than 1 second.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">He adjusted the Y-axis of X-view chart to a smaller scale and found out some transactions collected in the stacktrace.<\/p>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1024\" height=\"632\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_02-1024x632.png\" alt=\"\" class=\"wp-image-2830\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_02-1024x632.png 1024w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_02-300x185.png 300w\" sizes=\"auto, (max-width: 1024px) 100vw, 1024px\" \/><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">He\nchecked that since the collection server is processing TCP requests, not web\nrequests, individual transactions are finished in a very short time period.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">However,\njust with the stacktrace information collected for each transaction, he\ncouldn\u2019t even get a clue as to how performance can be improved, so He did not\nknow what to do.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">After some thoughts, he recalled that the previous developer inserted a function to call methods somewhere there, right? He quickly activated the option and checked the log.<\/p>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1016\" height=\"368\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_03.png\" alt=\"\" class=\"wp-image-2831\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_03.png 1016w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_03-300x109.png 300w\" sizes=\"auto, (max-width: 1016px) 100vw, 1016px\" \/><\/figure>\n\n\n\n<h3 class=\"wp-block-heading\">Preparation for the new stacktrace analysis function<\/h3>\n\n\n\n<p class=\"wp-block-paragraph\">Instead\nof individual transactions, we needed to view the sampling results throughout\nthe entire application, so unlike before, we had no entry point such as in\nX-view, so we needed a new analysis screen.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">The following goals are set for the analysis function to supplement the disadvantages of the sampling function displayed in the existing log.<\/p>\n\n\n\n<ul class=\"wp-block-list\"><li>Enabling speedy viewing  over a daily range (make it quick..)<\/li><li>Being able to use in an easy way without going through complicated settings (developer does not like tedious things..)<\/li><li>Minimizing the impacts on agents and collection servers (We shouldn\u2019t have trouble because we use it?)<\/li><li>Being able to intuitively assess the relations of method calls to look for (Time is money..)<\/li><\/ul>\n\n\n\n<p class=\"wp-block-paragraph\">The\ninitial two required components are selected as follows.<\/p>\n\n\n\n<ul class=\"wp-block-list\"><li>Statistics of methods being\n     called during the stacktrace method collection period (afterward, we call\n     this top method.)<\/li><li>FlameGraph based on the\n     stacktrace called from the viewing range<\/li><\/ul>\n\n\n\n<p class=\"wp-block-paragraph\">Ah.. Now, we thought there can be many stacktraces subject to analysis unlike before. In the past, it is the stacktrace information about a single transaction, but now it is the stacktrace information collected from everywhere, that is why.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">\u201cInstead of adjusting the minute- based viewing range that was no good, isn\u2019t there a better way?\u201d<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Developer\nY carefully browsed through the FlameGraph related articles, and found\nFlameScope(<a href=\"https:\/\/netflixtechblog.com\/netflix-flamescope-a57ca19d47bb\">https:\/\/netflixtechblog.com\/netflix-flamescope-a57ca19d47bb<\/a>).<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Well,\nit is about the visualization method developed by the developer of FlameGraph.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">To put is simply, it is a heatmap chart that displays the data collected in a small time scale by applying a different level of darkness of colors in proportion to the number of data sets. It differs from general heatmaps in that both X-axis and Y-axis represent time, so it is possible to express the varying pattern depending on time flows.<\/p>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"990\" height=\"840\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_04.png\" alt=\"\" class=\"wp-image-2832\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_04.png 990w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_04-300x255.png 300w\" sizes=\"auto, (max-width: 990px) 100vw, 990px\" \/><figcaption> These are the main patterns expressed with FlameScope. For more details, check <a href=\"https:\/\/www.brendangregg.com\/blog\/2018-11-08\/flamescope-pattern-recognition.html\">https:\/\/www.brendangregg.com\/blog\/2018-11-08\/flamescope-pattern-recognition.html<\/a>.\u00a0 <\/figcaption><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">Oh, yes. Now, we can use this to adjust the range when viewing large-size data. Maybe, we see that pattern, we can even assess the status of the application as well, right?<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Now,\nwe have selected 3 items for the new analysis screen.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Besides assessing the application status from the pattern, since it is a chart that shows the time flows, we can drag the range and set the viewing range of massive stacktrace information.<\/p>\n\n\n\n<ul class=\"wp-block-list\"><li>FlameScope<\/li><li>Top Method<\/li><li>FlameGraph<\/li><\/ul>\n\n\n\n<p class=\"wp-block-paragraph\">I\nwill introduce you to further details of each item once the analysis screen is\ncompleted.<\/p>\n\n\n\n<h3 class=\"wp-block-heading\">About after 3 months&#8230;<\/h3>\n\n\n\n<p class=\"wp-block-paragraph\">After heated debates among front-end developers,  and designers, now the new analysis function is completed.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">The name of the function was chosen through internal ballots finally as <strong>SFR <\/strong>(Stacktrace Flight Recorder). It means that the stacktrace information is gradually recorded without knowing as the application operates.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">I think stacktrace information recorded at all times can greatly help you in assessing the cause of unexpected troubles.<\/p>\n\n\n\n<h3 class=\"wp-block-heading\">Let me introduce you to <strong>SFR<\/strong>.<\/h3>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1024\" height=\"558\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_05-1024x558.png\" alt=\"\" class=\"wp-image-2833\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_05-1024x558.png 1024w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_05-300x164.png 300w\" sizes=\"auto, (max-width: 1024px) 100vw, 1024px\" \/><\/figure>\n\n\n\n<h4 class=\"wp-block-heading\">Intended use and purpose of a component<\/h4>\n\n\n\n<p class=\"wp-block-paragraph\">As\nshown in the above image attached, SFR is mainly composed of three components.<\/p>\n\n\n\n<ol class=\"wp-block-list\"><li>FlameScope<\/li><\/ol>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1024\" height=\"119\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_06-1024x119.png\" alt=\"\" class=\"wp-image-2834\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_06-1024x119.png 1024w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_06-300x35.png 300w\" sizes=\"auto, (max-width: 1024px) 100vw, 1024px\" \/><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">It\nis a chart with lots of squares in reddish color. Each square means a time\nduration of 1 minute and the more the collected stacktrace there is the more\nred color it gets.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">FlameScope mainly serves two purposes.<\/p>\n\n\n\n<ul class=\"wp-block-list\"><li><strong>TopMethod, FlameGraph viewing range selection<\/strong> <\/li><\/ul>\n\n\n\n<p class=\"wp-block-paragraph\">We wanted to see the changes when viewing it on a daily scale,\nso we set the max viewing period to 7 days, If we view all the data pertaining\nto this period, then we won\u2019t be able to satisfy users with slow viewing speed?\nThe more red color it gets the greater amount of stacktrace is collected due to\nsome reasons. Generally, this is where the user needs to check. Since\ncollection frequency in the unit of minute based on FlameScope is displayed, it\nis possible to reduce the time section required for a user\u2019s analysis (It is a\nsimilar relation to the X-view chart used to check the profile). <\/p>\n\n\n\n<ul class=\"wp-block-list\"><li><strong>Prediction of application characteristics and status based on the\n     pattern displayed on the heatmap chart<\/strong> <\/li><\/ul>\n\n\n\n<p class=\"wp-block-paragraph\">In the above, as we described in the FlameGraph selection process, we can show a certain status of an application. We can see some of the patterns running periodically with a time interval, where loads are concentrated in a specific time at the company.<\/p>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1024\" height=\"256\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_07-1024x256.png\" alt=\"\" class=\"wp-image-2835\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_07-1024x256.png 1024w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_07-300x75.png 300w\" sizes=\"auto, (max-width: 1024px) 100vw, 1024px\" \/><figcaption>An application running according to a specific period There are some white blanks in the middle, and they mean no data is collected, and the application is doing some processing periodically (** service background data processing server).<br><\/figcaption><\/figure>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1024\" height=\"123\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_08-1-1024x123.png\" alt=\"\" class=\"wp-image-2837\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_08-1-1024x123.png 1024w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_08-1-300x36.png 300w\" sizes=\"auto, (max-width: 1024px) 100vw, 1024px\" \/><figcaption>The very red area in the middle refers to 9 AM to 6 PM and during this time section, there are lots of requests made (Demo to process a virtual request from the internal demo system).<\/figcaption><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">2 TopMethod<\/p>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"508\" height=\"1024\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_09-508x1024.png\" alt=\"\" class=\"wp-image-2838\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_09-508x1024.png 508w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_09-149x300.png 149w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_09.png 651w\" sizes=\"auto, (max-width: 508px) 100vw, 508px\" \/><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">It\nrepresents the distribution of calls for the method running at the time of\nstacktrace collection.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">If there is a method created by the user at the top, then the method is likely to be in the bottleneck point. In the above screenshot, the FileDispatcherImpl.size0 method that measures the file size is most frequently called.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Using the method to cache the previously measure file size, you can reduce the frequency of method appearance and during that time, you can acquire time for running new methods. It can in turn lead to an improvement in the application performance.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">This is the most useful part when using the log-based method sampling analysis function in the past, and here we can repeatedly find the method call areas and make an improvement.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">But here is an issue. To look for the method appearing here, we had to spend lots of time  using IDE to look for called methods. But if the method is called at several other places, then it would be even more tedious, right? (It would have been impossible without IDE.)<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">3.FlameGraph<\/p>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1024\" height=\"540\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_10-1024x540.png\" alt=\"\" class=\"wp-image-2839\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_10-1024x540.png 1024w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_10-300x158.png 300w\" sizes=\"auto, (max-width: 1024px) 100vw, 1024px\" \/><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">It is the soul\nsavior who rescued me from the boring job of looking for method locations in\nTopMethod. &nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;Here, as opposed to the\nprevious case, we use an upside down FlameGraph.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Generally, it is called <strong>Inverted<\/strong> <strong>FlameGraph<\/strong> or <strong>Icicle Graph<\/strong>. The size shrinks from top to bottom, and it looks like an iceberg, so they named it that way. At the top of the graph, there is the start point of stacktrace and as you go down, the more recently executed method will be found.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Let\u2019s\nassume that the user who wants to express the original FlameGraph instead of\nthe above chart has a monitor with a low resolution. Maybe, it is highly likely\nthat only chopstick-like sections will be displayed. A user who sees it for the\nfirst time will be perplexed (Moreover, in this case, the method name is not\neven displayed).<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">We thought if we use <strong>Inverted<\/strong> <strong>FlameGraph<\/strong>, at least, the top area will be the start area of the call stack, so, it would be easier for users to recognize it. And the self method can be immediately checked in TopMethod on the left.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Since it is possible to click a line of <strong>TopMethod<\/strong> on the left or enter search keywords, we can emphasize the location of the method in FlameGraph, so we can easily check the frequently called method and its location.<\/p>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1024\" height=\"575\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_11-1024x575.png\" alt=\"\" class=\"wp-image-2840\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_11-1024x575.png 1024w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_11-300x168.png 300w\" sizes=\"auto, (max-width: 1024px) 100vw, 1024px\" \/><figcaption>Many improvements have been made to the existing FlameGraph. When filtering in the upper right corner, you can easily recognize the matching method, and by clicking each square, only the current call tree is shown, excluding other call trees. In addition, it also provides the ability to revert or reset these zoom-ins.<\/figcaption><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">Now, we have discussed the components of SFR.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Now,\nlet\u2019s use SFR on our own to improve the performance of the app with slow\nresponse time as developer Y did and see if it is really effective, shall we?<\/p>\n\n\n\n<h4 class=\"wp-block-heading\">What is the problem?<\/h4>\n\n\n\n<p class=\"wp-block-paragraph\">APM dashboard displays data that is saved every second for each type of chart and target of collection. Therefore, the more the monitoring targets are the slower the viewing speed gets.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Users\nare recommended to maintain a proper number of monitoring targets, but this\ncannot be forced upon them. <\/p>\n\n\n\n<p class=\"wp-block-paragraph\">No matter how fast individual viewing is, as it is directly related to the disk I\/O, parallel viewing attempts can force most of threats to go into processing at the same time, thus requests made afterward go into standby mode.<\/p>\n\n\n\n<pre class=\"EnlighterJSRAW\" data-enlighter-language=\"generic\" data-enlighter-theme=\"atomic\" data-enlighter-highlight=\"\" data-enlighter-linenumbers=\"\" data-enlighter-lineoffset=\"\" data-enlighter-title=\"\" data-enlighter-group=\"\">2022-03-30 00:00:03.979 [:ME:CommandFromViewServerProcessor] WARN  c.a.d.n.CommandFromViewServerHandler - Request from view takes much time to finish. request=CommandRequest(key=520:70,bodyLength=4258), finish=750\/1000, wait=717, process=32\n 2022-03-30 00:00:04.002 [:ME:CommandFromViewServerProcessor] WARN  c.a.d.n.CommandFromViewServerHandler - Request from view takes much time to finish. request=CommandRequest(key=520:70,bodyLength=2098), finish=783\/1000, wait=717, process=65<\/pre>\n\n\n\n<p class=\"wp-block-paragraph\">Although the processing time is low,\nwe can see that the waiting time is very long. If you want to reduce the\nwaiting time, then you can make the small task processing time even shorter.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Even\nof you don\u2019t comply with the recommendation, a certain degree of usability\nshall be guaranteed, thus let&#8217;s try to accurately assess the bottleneck point\nand improve the response time.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">First, we installed an APM agent on the collection server and viewed the data collected for the day.<\/p>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1024\" height=\"552\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_12-1024x552.png\" alt=\"\" class=\"wp-image-2841\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_12-1024x552.png 1024w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_12-300x162.png 300w\" sizes=\"auto, (max-width: 1024px) 100vw, 1024px\" \/><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">We dragged the red area of FlameScope, and found out that most of the processing time was spent reading RandomAccessFile based on the content displayed in TopMethod. The cause might be consistent attempts to read the file.<\/p>\n\n\n\n<h4 class=\"wp-block-heading\">Improvement attempts \u2013 1<\/h4>\n\n\n\n<p class=\"wp-block-paragraph\">Most of the time is spent reading the file, so how can we make it faster?<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">We\ncan also apply memory-mapped file implementation methods to Java to enable us\nto directly map a file to memory and read\/write, but there are some areas we\nshould be careful with, so let&#8217;s take a look at other aspects.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Here, the pink area is the widest area, and you will see the AbstractRecord.toObjectDB part in the middle that stands out.<\/p>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1024\" height=\"568\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_13-1024x568.png\" alt=\"\" class=\"wp-image-2842\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_13-1024x568.png 1024w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_13-300x166.png 300w\" sizes=\"auto, (max-width: 1024px) 100vw, 1024px\" \/><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">The lower-ranked methods use RealtimeObjectRecord.read to read in bytes from InputStream in the correct order to convert them to objects.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">This part accounts for a total of 19.05%, so, if we make this one go faster, then we might be able to improve the performance a little bit.<\/p>\n\n\n\n<pre class=\"EnlighterJSRAW\" data-enlighter-language=\"generic\" data-enlighter-theme=\"atomic\" data-enlighter-highlight=\"\" data-enlighter-linenumbers=\"\" data-enlighter-lineoffset=\"\" data-enlighter-title=\"\" data-enlighter-group=\"\">protected IRecord read(InputStream in, boolean db) {\n    if (!db) {\n        this.time = TcpUtil.getlong(in);\n    }\n\n    this.otype = TcpUtil.getbyte(in);\n    this.oid = TcpUtil.getint(in);\n    int count = TcpUtil.getshort(in);\n\n    for (int t = 0; t &lt; count; t++) {\n        short key = TcpUtil.getshort(in);\n        TYPE value = TypeUtil.next(in);\n        this.putValue(key, value);\n    }\n\n    readTrustRangePart(count, in);\n    return this;\n}\n<\/pre>\n\n\n\n<p class=\"wp-block-paragraph\">\u201cThere\nis nothing special to improve, isn\u2019t it a good idea to use the byte buffer of\nNIO? If we use memory maps, then we can skip the conversion phase in the\nmiddle..\u201c<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Since\nit is easier to handle bytes and it is more convenient, so we opted for\nByteBuffer.<\/p>\n\n\n\n<pre class=\"EnlighterJSRAW\" data-enlighter-language=\"generic\" data-enlighter-theme=\"atomic\" data-enlighter-highlight=\"\" data-enlighter-linenumbers=\"\" data-enlighter-lineoffset=\"\" data-enlighter-title=\"\" data-enlighter-group=\"\">@Override\npublic IRecord read(ByteBuffer bb, boolean db) {\n    if (!db) {\n        this.time = bb.getLong();\n    }\n\n    this.otype = bb.get();\n    this.oid = bb.getInt();\n    int count = bb.getShort();\n\n    for (int t = 0; t &lt; count; t++) {\n        short key = bb.getShort();\n        TYPE value = TypeUtilV2.next(bb);\n        this.putValue(key, value);\n    }\n\n    return this;\n}\n<\/pre>\n\n\n\n<p class=\"wp-block-paragraph\">Shall we apply the code changes and check the viewed results again?<\/p>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1024\" height=\"543\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_14-1024x543.png\" alt=\"\" class=\"wp-image-2843\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_14-1024x543.png 1024w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_14-300x159.png 300w\" sizes=\"auto, (max-width: 1024px) 100vw, 1024px\" \/><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">Well..\nFirst of all, the color of FlameScope became thinner than before.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">It\nmeans that the time to execute a task in the thread became shorter.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">At\nthe bottom FlameGraph, you can see that AbstractRecord.toObjectDB accounts for\n9.03%. It is just a number, but about 10% of call frequency is reduced!<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">How\nabout comparing it with the X-View chart?<\/p>\n\n\n\n<ul class=\"wp-block-list\"><li>Before improvment<\/li><\/ul>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1024\" height=\"541\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_15-1024x541.png\" alt=\"\" class=\"wp-image-2844\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_15-1024x541.png 1024w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_15-300x158.png 300w\" sizes=\"auto, (max-width: 1024px) 100vw, 1024px\" \/><\/figure>\n\n\n\n<ul class=\"wp-block-list\"><li>After improvment<\/li><\/ul>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1024\" height=\"571\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_16-1024x571.png\" alt=\"\" class=\"wp-image-2846\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_16-1024x571.png 1024w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_16-300x167.png 300w\" sizes=\"auto, (max-width: 1024px) 100vw, 1024px\" \/><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">Now, we still see the waves but there are a lot fewer entities in the time section from 40ms to 110ms. We have been able to improve the response time for much more requests than we thought!<\/p>\n\n\n\n<h4 class=\"wp-block-heading\">Improvement attempts \u2013 2<\/h4>\n\n\n\n<p class=\"wp-block-paragraph\">Developer\nY did not stop here, but he couldn\u2019t put down the urge to reduce the response\ntime for transactions looking like waves.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">After making greater efforts, he used the memory-mapped file mentioned in <strong>Improvement attempt \u2013 1<\/strong> to change the read parts.<\/p>\n\n\n\n<pre class=\"EnlighterJSRAW\" data-enlighter-language=\"generic\" data-enlighter-theme=\"atomic\" data-enlighter-highlight=\"\" data-enlighter-linenumbers=\"\" data-enlighter-lineoffset=\"\" data-enlighter-title=\"\" data-enlighter-group=\"\">private val map = inner.raf().channel.map(FileChannel.MapMode.READ_ONLY, 0, inner.length())<\/pre>\n\n\n\n<p class=\"wp-block-paragraph\">We used the read-only memory map to pursue simplicity in implementation.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Trying to calm down his beating heart, developer Y applied the code changes and moved to the SFR screen, and press the View button!<\/p>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1024\" height=\"578\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_17-1024x578.png\" alt=\"\" class=\"wp-image-2847\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_17-1024x578.png 1024w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_17-300x169.png 300w\" sizes=\"auto, (max-width: 1024px) 100vw, 1024px\" \/><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">Oh..\nNow, we no longer see anything related to RandomAccess in TopMethod.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Is there any difference when we use X-View to view it?<\/p>\n\n\n\n<figure class=\"wp-block-image\"><img loading=\"lazy\" decoding=\"async\" width=\"1024\" height=\"572\" src=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_18-1024x572.png\" alt=\"\" class=\"wp-image-2848\" srcset=\"https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_18-1024x572.png 1024w, https:\/\/jennifersoft.com\/en\/wp-content\/uploads\/sites\/3\/2022\/05\/SFR_18-300x168.png 300w\" sizes=\"auto, (max-width: 1024px) 100vw, 1024px\" \/><\/figure>\n\n\n\n<p class=\"wp-block-paragraph\">Finally, most of the response time for transactions is reduced to below 10ms except for some transactions.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Now,\nwe can see that the dashboard viewing function is improved.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">The\nissue with slow individual requests (even if it is just 200ms..) can be\nimproved significantly. We can very well handle multiple requests that are not\nin compliance with the recommendation?!<\/p>\n\n\n\n<h3 class=\"wp-block-heading\">Conclusion<\/h3>\n\n\n\n<p class=\"wp-block-paragraph\">I\ncan recall many incidents I went through because I relied too much on profiles\nto improve the performance.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Sometimes,\nit was hard to view too many profiles or had hard times analyzing them because\nthe individual response time for the profile was too low.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Whenever\nit happens, I wanted to create a performance analysis tool but I wanted to\novercome the reality that made me display various comments in the logs or rely\non other analysis tools.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">For a long period of time, I read the source codes of VisualVM and looked for multiple open sources, trying to look for a good stacktrace based analysis tool.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">At that time, sampling was very new to us, so, unfortunately, it took more than 5 years to create a function from a scratch.<\/p>\n","protected":false},"excerpt":{"rendered":"Since we improved the Java performance by using the stacktrace analysis function for individual transactions introduced in https:\/\/jennifersoft.com\/ko\/blog\/tech\/2021-10-18\/&nbsp; last time,&#8230;","protected":false},"author":18,"featured_media":2810,"comment_status":"open","ping_status":"closed","sticky":true,"template":"","format":"standard","meta":{"_acf_changed":false,"footnotes":""},"categories":[78],"tags":[],"class_list":["post-2807","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-tech"],"acf":[],"_links":{"self":[{"href":"https:\/\/jennifersoft.com\/en\/wp-json\/wp\/v2\/posts\/2807","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/jennifersoft.com\/en\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/jennifersoft.com\/en\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/jennifersoft.com\/en\/wp-json\/wp\/v2\/users\/18"}],"replies":[{"embeddable":true,"href":"https:\/\/jennifersoft.com\/en\/wp-json\/wp\/v2\/comments?post=2807"}],"version-history":[{"count":8,"href":"https:\/\/jennifersoft.com\/en\/wp-json\/wp\/v2\/posts\/2807\/revisions"}],"predecessor-version":[{"id":2849,"href":"https:\/\/jennifersoft.com\/en\/wp-json\/wp\/v2\/posts\/2807\/revisions\/2849"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/jennifersoft.com\/en\/wp-json\/wp\/v2\/media\/2810"}],"wp:attachment":[{"href":"https:\/\/jennifersoft.com\/en\/wp-json\/wp\/v2\/media?parent=2807"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/jennifersoft.com\/en\/wp-json\/wp\/v2\/categories?post=2807"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/jennifersoft.com\/en\/wp-json\/wp\/v2\/tags?post=2807"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}