</script><metaname="aes-config"content="pid=xux-opensource&user_type=101&uid=&username=&dim10=arthas"><scriptsrc="//g.alicdn.com/alilog/mlog/aplus_v2.js"id="beacon-aplus"exparams="clog=o&aplus&sidx=aplusSidx&ckx=aplusCkx"></script><scriptsrc="//g.alicdn.com/aes/??tracker/1.0.34/index.js,tracker-plugin-pv/2.4.5/index.js,tracker-plugin-event/1.2.5/index.js,tracker-plugin-jserror/1.0.13/index.js,tracker-plugin-api/1.1.14/index.js,tracker-plugin-perf/1.1.8/index.js,tracker-plugin-eventTiming/1.0.4/index.js"></script><title>trace | arthas</title><metaname="description"content="arthas user document">
</code></pre><divclass="line-numbers"aria-hidden="true"><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div></div></div><divclass="custom-container tip"><pclass="custom-container-title">TIP</p><p>The <code>#24</code> in the result indicates that in the run function, the <code>primeFactors()</code> function was called on line <code>24</code> of the source file.</p></div><h3id="specify-the-max-number-of-matched-classes"tabindex="-1"><aclass="header-anchor"href="#specify-the-max-number-of-matched-classes"aria-hidden="true">#</a> Specify the max number of matched Classes</h3><divclass="language-bash ext-sh line-numbers-mode"><preclass="language-bash"><code>$ trace demo.MathGame run <spanclass="token parameter variable">-m</span><spanclass="token number">1</span>
</code></pre><divclass="line-numbers"aria-hidden="true"><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div></div></div><h3id="trace-times-limit"tabindex="-1"><aclass="header-anchor"href="#trace-times-limit"aria-hidden="true">#</a> Trace times limit</h3><p>If the method invoked many times, use <code>-n</code> options to specify trace times. For example, the command will exit when received a trace result.</p><divclass="language-bash ext-sh line-numbers-mode"><preclass="language-bash"><code>$ trace demo.MathGame run <spanclass="token parameter variable">-n</span><spanclass="token number">1</span>
Command execution <spanclass="token builtin class-name">times</span> exceed limit: <spanclass="token number">1</span>, so <spanclass="token builtin class-name">command</span> will exit. You can <spanclass="token builtin class-name">set</span> it with <spanclass="token parameter variable">-n</span> option.
</code></pre><divclass="line-numbers"aria-hidden="true"><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div></div></div><h3id="include-jdk-method"tabindex="-1"><aclass="header-anchor"href="#include-jdk-method"aria-hidden="true">#</a> Include jdk method</h3><ul><li><code>--skipJDKMethod <value></code> skip jdk method trace, default value true.</li></ul><divclass="language-bash ext-sh line-numbers-mode"><preclass="language-bash"><code>$ trace <spanclass="token parameter variable">--skipJDKMethod</span><spanclass="token boolean">false</span> demo.MathGame run
</code></pre><divclass="line-numbers"aria-hidden="true"><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div></div></div><divclass="custom-container tip"><pclass="custom-container-title">TIP</p><p>Only the call path which's time cost is higher than <code>10ms</code> will be shown. This feature is handy to focus on what's needed to focus when troubleshoot.</p></div><ul><li>Here Arthas provides the similar functionality JProfile and other commercial software provide. Compared to these professional softwares, Arthas doesn't deduce the time cost <code>trace</code> itself takes, therefore it is not as accurate as these softwares offer. More classes and methods on the calling path, more inaccurate <code>trace</code> output is, but it is still helpful for diagnostics where the bottleneck is.</li><li>"[12.033735ms]" means the method on the node takes <code>12.033735</code> ms.</li><li>"[min=0.005428ms,max=0.094064ms,total=0.105228ms,count=3] demo:call()" means aggregating all same method calls into one single line. The minimum time cost is <code>0.005428</code> ms, the maximum time cost is <code>0.094064</code> ms, and the total time cost for all method calls (<code>3</code> times in total) to "demo:call()" is <code>0.105228ms</code>. If "throws Exception" appears in this line, it means some exceptions have been thrown from this method calls.</li><li>The total time cost may not equal to the sum of the time costs each sub method call takes, this is because Arthas instrumented code takes time too.</li></ul><h3id="trace-multiple-classes-or-multiple-methods"tabindex="-1"><aclass="header-anchor"href="#trace-multiple-classes-or-multiple-methods"aria-hidden="true">#</a> Trace multiple classes or multiple methods</h3><p>The trace command will only trace the subcalls in the method to the trace, and will not trace down multiple layers. Because traces are expensive, multi-layer traces can lead to a lot of classes and methods that ultimately have to be traced.</p><p>You can use the regular expression to match multiple classes and methods on the path to achieve a multi-layer trace effect to some extent.</p><divclass="language-bash ext-sh line-numbers-mode"><preclass="language-bash"><code>Trace <spanclass="token parameter variable">-E</span> com.test.ClassA<spanclass="token operator">|</span>org.test.ClassB method1<spanclass="token operator">|</span>method2<spanclass="token operator">|</span>method3
</code></pre><divclass="line-numbers"aria-hidden="true"><divclass="line-number"></div></div></div><h3id="exclude-the-specified-class"tabindex="-1"><aclass="header-anchor"href="#exclude-the-specified-class"aria-hidden="true">#</a> Exclude the specified class</h3><divclass="custom-container tip"><pclass="custom-container-title">TIP</p><p>The watch/trace/monitor/stack/tt commands all support the <code>--exclude-class-pattern</code> parameter</p></div><p>Use the <code>--exclude-class-pattern</code> parameter to exclude the specified class, for example:</p><divclass="language-bash ext-sh line-numbers-mode"><preclass="language-bash"><code><spanclass="token function">watch</span> javax.servlet.Filter * --exclude-class-pattern com.demo.TestFilter
</code></pre><divclass="line-numbers"aria-hidden="true"><divclass="line-number"></div></div></div><h3id="dynamic-trace"tabindex="-1"><aclass="header-anchor"href="#dynamic-trace"aria-hidden="true">#</a> Dynamic trace</h3><divclass="custom-container tip"><pclass="custom-container-title">TIP</p><p>Supported since version 3.3.0.</p></div><p>Open terminal 1, trace the <code>run</code> method in the above demo, and you can see the printout <code>listenerId: 1</code> .</p><divclass="language-bash ext-sh line-numbers-mode"><preclass="language-bash"><code><spanclass="token punctuation">[</span>arthas@59161<spanclass="token punctuation">]</span>$ trace demo.MathGame run
</code></pre><divclass="line-numbers"aria-hidden="true"><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div></div></div><p>Now to drill down into the sub method <code>primeFactors</code>, you can open a new terminal 2 and use the <code>telnet localhost 3658</code> connects to the arthas, then trace <code>primeFactors</code> with the specify <code>listenerId</code>.</p><divclass="language-bash ext-sh line-numbers-mode"><preclass="language-bash"><code><spanclass="token punctuation">[</span>arthas@59161<spanclass="token punctuation">]</span>$ trace demo.MathGame primeFactors <spanclass="token parameter variable">--listenerId</span><spanclass="token number">1</span>
</code></pre><divclass="line-numbers"aria-hidden="true"><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div></div></div><p>At Terminal 2 prints the results, indicating that a method has been enhanced: <code>Affect(class count: 1 , method count: 1)</code>, but no more results are printed.</p><p>At terminal 1, you can see that the trace result has increased by one layer:</p><divclass="language-bash ext-sh line-numbers-mode"><preclass="language-bash"><code><spanclass="token variable"><spanclass="token variable">`</span>---ts<spanclass="token operator">=</span><spanclass="token number">2020</span>-07-09 <spanclass="token number">16</span>:49:29<spanclass="token punctuation">;</span><spanclass="token assign-left variable">thread_name</span><spanclass="token operator">=</span>main<spanclass="token punctuation">;</span><spanclass="token assign-left variable">id</span><spanclass="token operator">=</span><spanclass="token number">1</span><spanclass="token punctuation">;</span><spanclass="token assign-left variable">is_daemon</span><spanclass="token operator">=</span>false<spanclass="token punctuation">;</span><spanclass="token assign-left variable">priority</span><spanclass="token operator">=</span><spanclass="token number">5</span><spanclass="token punctuation">;</span><spanclass="token assign-left variable">TCCL</span><spanclass="token operator">=</span>sun.misc.Launcher$AppClassLoader@3d4eac69
</code></pre><divclass="line-numbers"aria-hidden="true"><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div></div></div><p>Dynamic trace by specifying <code>listenerId</code>, you can go deeper and deeper. In addition, commands such as <code>watch</code>/<code>tt</code>/<code>monitor</code> also support similar functionality.</p><h2id="trace-result-time-inaccuracy-problem"tabindex="-1"><aclass="header-anchor"href="#trace-result-time-inaccuracy-problem"aria-hidden="true">#</a> Trace result time inaccuracy problem</h2><p>For example, in the following result: <code>0.705196 > (0.152743 + 0.145825)</code></p><divclass="language-bash ext-sh line-numbers-mode"><preclass="language-bash"><code>$ trace demo.MathGame run <spanclass="token parameter variable">-n</span><spanclass="token number">1</span>
</code></pre><divclass="line-numbers"aria-hidden="true"><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div></div></div><p>So where is the rest of the time consumed?</p><ol><li><p>Methods that are not traced to. For example, methods under <code>java.*</code> are ignored by default. This can be printed out by adding the <code>-skipJDKMethod false</code> parameter.</p><divclass="language-bash ext-sh line-numbers-mode"><preclass="language-bash"><code>$ trace demo.MathGame run <spanclass="token parameter variable">--skipJDKMethod</span><spanclass="token boolean">false</span>
</code></pre><divclass="line-numbers"aria-hidden="true"><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div><divclass="line-number"></div></div></div></li><li><p>Instruction consumption. For example, instructions such as <code>i++</code>, <code>getfield</code>, etc.</p></li><li><p>Possible JVM pause during code execution, such as GC, entering synchronization blocks, etc.</p></li></ol><h3id="use-the-v-parameter-to-print-more-information"tabindex="-1"><aclass="header-anchor"href="#use-the-v-parameter-to-print-more-information"aria-hidden="true">#</a> Use the -v parameter to print more information</h3><divclass="custom-container tip"><pclass="custom-container-title">TIP</p><p>The watch/trace/monitor/stack/tt commands all support the <code>-v</code> parameter.</p></div><p>When the command is executed, there is no output result. There are two possibilities:</p><ol><li>The matched function is not executed</li><li>The result of the conditional expression is false</li></ol><p>But the user cannot tell which situation is.</p><p>Using the <code>-v</code> option, the specific value and execution result of <code>Condition express</code> will be printed for easy confirmation.</p></div><!--[--><!--]--></div><footerclass="page-meta right-menu-padding"data-v-fdd717e0><divclass="meta-item edit-link"><aclass="external-link meta-item-label"href="https://github.com/alibaba/arthas/edit/master/site/docs/en/doc/trace.md"rel="noopener noreferrer"target="_blank"aria-label="Edit this page on GitHub"><!--[--><!--]--><span>Edit this page on GitHub</span><span><svgclass="external-link-icon"xmlns="http://www.w3.org/2000/svg"aria-hidden="true"focusable="false"x="0px"y="0px"viewbox="0 0 100 100"width="15"height="15"><pathfill="currentColor"d="M18.8,85.1h56l0,0c2.2,0,4-1.8,4-4v-32h-8v28h-48v-48h28v-8h-32l0,0c-2.2,0-4,1.8-4,4v56C14.8,83.3,16.6,85.1,18.8,85.1z"></path><polygonfill="currentColor"points="45.7,48.7 51.3,54.3 77.2,28.5 77.2,37.2 85.2,37.2 85.2,14.9 62.8,14.9 62.8,22.9 71.5,22.9"></polygon></svg><spanclass="external-link-icon-sr-only">open in new window</span></span><!--[--><!--]--></a></div><divclass="meta-item last-updated"><spanclass="meta-item-label">Last Updated: </span><!----></div><divclass="meta-item contributors"><spanclass="meta-item-label">Contributors: </span><spanclass="meta-item-info"><!--[--><!--[--><spanclass="contributor"title="email: hengyunabc@gmail.com">hengyunabc</span><!--[-->, <!--]--><!--]--><!--[--><spanclass="contributor"title="email: hengyunabc@users.noreply.github.com">hengyunabc</span><!--[-->, <!--]--><!--]--><!--[--><spanclass="contributor"title="email: i@fatpandac.com">Fatpandac</span><!--[-->, <!--]--><!--]--><!--[--><spanclass="contributor"title="email: wz9712203617@gmail.com">GGGGGHT</span><!--[-->, <!--]--><!--]--><!--[--><spanclass="contributor"title="email: haoyixing@kuaishou.com">haoyixing</span><!--[-->, <!--]--><!--]--><!--[--><spanclass="contributor"title="email: 35672972+pandaapo@users.noreply.github.com">pandaapo</span><!--[-->, <!--]--><!--]--><!--[--><spanclass="contributor"title="email: 26602940+0xflotus@users.noreply.github.com">0xflotus</span><!--[-->, <!--]--><!--]--><!--[--><spanclass="contributor"title="email: LHearen@126.com">Hearen</span><!--[-->, <!--]--><!--]--><!--[--><spanclass="contributor"title="email: hollowman186@vip.qq.com">Hollow Man</span><!--[-->, <!--]--><!--]--><!--[--><spanclass="contributor"title="email: favoorr@gmail.com">Jerry</span><!--[-->, <!--]--><!--]--><!--[--><spanclass="contributor"title="email: lhearen@gmail.com">LHearen</span><!--[-->, <!--]--><!--]--><!--[--><spanclass="contributor"title="email: ian.luo@gmail.com">beiwei30</span><!----><!--]--><!--]--></span></div></footer><navclass="pag
