Arthas created by Alibaba is a tool that allows developers to connect to running Java applications without stopping them or suspending threads for debugging the application from the console.
It offers features like monitoring invocation statistics, searching for classes and methods in the classloaders, view method invocation details (like parameters), show the stack trace of a method invocation, monitor system metrics and others.
In the following examples I’m going to demonstrate some of these features applied to a running web application.
Installation
Using Linux/Mac/*nix….
curl -L https://alibaba.github.io/arthas/install.sh |sh
Wind*ws users visit Maven Central and visit the latest binary here, unzip the downloaded zip-file, change to the bin directory and call Arthas like this:
as.bat $PID
Examples of Usage
For the following examples I’ll be connecting Arthas to a running Spring Boot application take from my tutorial “https://www.hascode.com/2015/07/integrating-swagger-into-a-spring-boot-restful-webservice-with-springfox/[Integrating Swagger into a Spring Boot RESTful Webservice with Springfox]”.
Connecting to an Application
Having started Arthas, we’re now asked to connect to a running Java application – in this case, we’re choosing the Spring Boot application mentioned above:
Afterwards we notice the following entries in the output from our Spring Bot application:
Tue Oct 3016:15:54 CET 2018 com.taobao.arthas.agent.ArthasClassloader@307e0d2f JM.Log:INFO Log root path: /home/soma/logs/
Tue Oct 3016:15:54 CET 2018 com.taobao.arthas.agent.ArthasClassloader@307e0d2f JM.Log:INFO Set arthas log path: /home/soma/logs/arthas
If no running Java process is detected, Arthas will quit and display the following hint:
./as.sh
Arthas script version: 3.0.4
Error: no available java process to attach.
Usage:
./as.sh [-b [-f SCRIPT_FILE]][debug][--use-version VERSION][--attach-only][@IP:TELNET_PORT:HTTP_PORT][debug] : start the agent in debug mode
: the target Java Process ID
[IP] : the target's IP
[TELNET_PORT] : the target's PORT for telnet
[HTTP_PORT] : the target's PORT for http
[-b] : batch mode, which will disable interactive process selection.
[-f] : specify the path to batch script file.
[--attach-only] : only attach the arthas agent to target jvm.
[--use-version] : use the specified arthas version to attach.
Example:
./as.sh
./as.sh @[IP]
./as.sh @[IP:PORT]
./as.sh debug
./as.sh -b
./as.sh -b -f /path/to/script
./as.sh --attach-only
./as.sh --use-version 2.0.20161221142407
Feature Overview
When typing in help, Arthas displays available commands.
For more details on each command, simply type help command.
$ help
NAME DESCRIPTION
help Display Arthas Help
keymap Display all the available keymap for the specified connection.
sc Search all the classes loaded by JVM
sm Search the method of classes loaded by JVM
classloader Show classloader info
jad Decompile class
getstatic Show the static field of a class
monitor Monitor method execution statistics, e.g. total/success/failure count, average rt, fail rate, etc.
stack Display the stack trace for the specified class and method
thread Display thread info, thread stack
trace Trace the execution time of specified method invocation.
watch Display the input/output parameter, return object, and thrown exception of specified method invocation
tt Time Tunnel
jvm Display the target JVM information
dashboard Overview of target jvm's thread, memory, gc, vm, tomcat info.
dump Dump class byte array from JVM
options View and change various Arthas options
cls Clear the screen
reset Reset all the enhanced classes
version Display Arthas version
shutdown Shut down Arthas server and exit the console
session Display current session information
sysprop Display, and change the system properties.
redefine Redefine classes. @see Instrumentation#redefineClasses(ClassDefinition...)
Search all the classes loaded by JVM
We’re searching for all loaded classes matching the pattern com.hascode.tutorial.*:
$ sc 'com.hascode.*'
com.hascode.tutorial.Application$FastClassBySpringCGLIB$2be61ff4
com.hascode.tutorial.Application
com.hascode.tutorial.CurrentDateController
com.hascode.tutorial.Application$EnhancerBySpringCGLIB$b7e53eca$FastClassBySpringCGLIB$5d6e31fa
com.hascode.tutorial.FormattedDate
com.hascode.tutorial.Application$EnhancerBySpringCGLIB$b7e53eca
Affect(row-cnt:6) cost in8 ms.
Search the method of classes loaded by JVM
Searching for all methods in the class com.hascode.tutorial.CurrentDateController.
$ sm com.hascode.tutorial.CurrentDateController
com.hascode.tutorial.CurrentDateController->
com.hascode.tutorial.CurrentDateController->formatCurrentDate
Affect(row-cnt:2) cost in7 ms.
Show classloader info
Displays the classloaders used by our application.
$ classloader
name numberOfInstances loadedCountTotal
sun.misc.Launcher$AppClassLoader13640
BootstrapClassLoader 12537
com.taobao.arthas.agent.ArthasClassloader 11032
sun.reflect.DelegatingClassLoader 5858
sun.misc.Launcher$ExtClassLoader10
Affect(row-cnt:5) cost in7 ms.
Decompile Class
We’re decompiling the class com.hascode.tutorial.CurrentDateController.
$ jad com.hascode.tutorial.CurrentDateController
ClassLoader:
+-sun.misc.Launcher$AppClassLoader@73d16e93
+-sun.misc.Launcher$ExtClassLoader@3b1cd4e6
Location:
/data/project/spring-boot-swagger-tutorial/build/classes/main//** Decompiled with CFR 0_132.
*/
package com.hascode.tutorial;
import com.hascode.tutorial.FormattedDate;
import java.time.LocalDateTime;
import java.time.format.DateTimeFormatter;
import java.time.temporal.TemporalAccessor;
import java.util.concurrent.atomic.AtomicLong;
import org.springframework.web.bind.annotation.PathVariable;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;
@RestController
public class CurrentDateController {
private final AtomicLong counter = new AtomicLong();
@RequestMapping(value={"/currentdate/{pattern}"})
public FormattedDate formatCurrentDate(@PathVariable String pattern){
DateTimeFormatter fmt = DateTimeFormatter.ofPattern(pattern);
return new FormattedDate(this.counter.incrementAndGet(), pattern, fmt.format(LocalDateTime.now()));
}}
Affect(row-cnt:1) cost in503 ms.
Monitor method execution statistics
In the following example we’re monitoring method execution statistics for the CurrentDateController’s formatCurrentDate method.
Available parameters are shown with help monitor
$ help monitor
USAGE:
monitor [-c ][-h][-n ][-E] class-pattern method-pattern
SUMMARY:
Monitor method execution statistics, e.g. total/success/failure count, average rt, fail rate, etc.
Examples:
monitor org.apache.commons.lang.StringUtils isBlank
monitor org.apache.commons.lang.StringUtils isBlank -c5
monitor -E org\.apache\.commons\.lang\.StringUtils isBlank
WIKI:
https://alibaba.github.io/arthas/monitor
OPTIONS:
-c, --cycle The monitor interval (in seconds), 60 seconds by default
-h, --help this help
-n, --limits Threshold of execution times
-E, --regex Enable regular expression to match (wildcard matching by default)
Path and classname of Pattern Matching
Method of Pattern Matching
So to monitor the method with a monitor interval of 5 seconds, an execution time treshold of 10, we’re using the following command:
$ monitor -c5-n10 com.hascode.tutorial.CurrentDateController formatCurrentDate
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in33 ms.
timestamp class method total success fail avg-rt(ms) fail-rate
---------------------------------------------------------------------------------------------------------------------------------2018-10-3015:32:08 com.hascode.tutorial.CurrentDateController formatCurrentDate 181800.230.00%
timestamp class method total success fail avg-rt(ms) fail-rate
---------------------------------------------------------------------------------------------------------------------------------2018-10-3015:32:13 com.hascode.tutorial.CurrentDateController formatCurrentDate 222200.200.00%
timestamp class method total success fail avg-rt(ms) fail-rate
---------------------------------------------------------------------------------------------------------------------------------2018-10-3015:32:18 com.hascode.tutorial.CurrentDateController formatCurrentDate 222200.220.00%
timestamp class method total success fail avg-rt(ms) fail-rate
---------------------------------------------------------------------------------------------------------------------------------2018-10-3015:32:23 com.hascode.tutorial.CurrentDateController formatCurrentDate 111100.200.00%
timestamp class method total success fail avg-rt(ms) fail-rate
---------------------------------------------------------------------------------------------------------------------------------2018-10-3015:32:28 com.hascode.tutorial.CurrentDateController formatCurrentDate 8800.260.00%
timestamp class method total success fail avg-rt(ms) fail-rate
---------------------------------------------------------------------------------------------------------------------------------2018-10-3015:32:33 com.hascode.tutorial.CurrentDateController formatCurrentDate 8800.160.00%
timestamp class method total success fail avg-rt(ms) fail-rate
---------------------------------------------------------------------------------------------------------------------------------2018-10-3015:32:38 com.hascode.tutorial.CurrentDateController formatCurrentDate 141400.190.00%
timestamp class method total success fail avg-rt(ms) fail-rate
---------------------------------------------------------------------------------------------------------------------------------2018-10-3015:32:43 com.hascode.tutorial.CurrentDateController formatCurrentDate 171700.170.00%
timestamp class method total success fail avg-rt(ms) fail-rate
---------------------------------------------------------------------------------------------------------------------------------2018-10-3015:32:48 com.hascode.tutorial.CurrentDateController formatCurrentDate 9900.180.00%
timestamp class method total success fail avg-rt(ms) fail-rate
---------------------------------------------------------------------------------------------------------------------------------2018-10-3015:32:53 com.hascode.tutorial.CurrentDateController formatCurrentDate 191900.200.00%
Command execution times exceed limit: 10, so command will exit. You can set it with -n option.
Display the stack trace for the specified class and method
We’re displaying the stack trace for com.hascode.tutorial.CurrentDateController.
$ stack com.hascode.tutorial.CurrentDateController
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:2) cost in32 ms.
ts=2018-10-3015:35:01;thread_name=http-nio-8080-exec-7;id=2a;is_daemon=true;priority=5;TCCL=org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedWebappClassLoader@565a8af8
@sun.reflect.GeneratedMethodAccessor31.invoke()
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:137)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:110)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:776)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:705)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)[..]
Display thread info, thread stack
Just as the title says..
$ thread
Threads Total: 32, NEW: 0, RUNNABLE: 14, BLOCKED: 0, WAITING: 14, TIMED_WAITING: 4, TERMINATED: 0
ID NAME GROUP PRIORITY STATE %CPU TIME INTERRUPTE DAEMON
58 as-command-execute-daemon system 10 RUNNABLE 900:0falsetrue30 nioEventLoopGroup-2-2 system 10 RUNNABLE 90:0falsefalse23 AsyncAppender-Worker-arthas-cache system 9 WAITING 00:0falsetrue21 Attach Listener system 9 RUNNABLE 00:0falsetrue14 ContainerBackgroundProcessor[Stan main 5 TIMED_WAIT 00:0falsetrue20 DestroyJavaVM main 5 RUNNABLE 00:2falsefalse3 Finalizer system 8 WAITING 00:0falsetrue16 NioBlockingSelector.BlockPoller-1 main 5 RUNNABLE 00:0falsetrue2 Reference Handler system 10 WAITING 00:0falsetrue4 Signal Dispatcher system 9 RUNNABLE 00:0falsetrue15 container-0 main 5 TIMED_WAIT 00:0falsefalse19 http-nio-8080-Acceptor-0 main 5 RUNNABLE 00:0falsetrue17 http-nio-8080-ClientPoller-0 main 5 RUNNABLE 00:0falsetrue18 http-nio-8080-ClientPoller-1 main 5 RUNNABLE 00:0falsetrue36 http-nio-8080-exec-1 main 5 WAITING 00:0falsetrue46 http-nio-8080-exec-10 main 5 WAITING 00:0falsetrue37 http-nio-8080-exec-2 main 5 WAITING 00:0falsetrue38 http-nio-8080-exec-3 main 5 WAITING 00:0falsetrue39 http-nio-8080-exec-4 main 5 WAITING 00:0falsetrue40 http-nio-8080-exec-5 main 5 WAITING 00:0falsetrue41 http-nio-8080-exec-6 main 5 WAITING 00:0falsetrue42 http-nio-8080-exec-7 main 5 WAITING 00:0falsetrue43 http-nio-8080-exec-8 main 5 WAITING 00:0falsetrue45 http-nio-8080-exec-9 main 5 WAITING 00:0falsetrue25 job-timeout system 9 TIMED_WAIT 00:0falsetrue26 nioEventLoopGroup-2-1 system 10 RUNNABLE 00:0falsefalse33 nioEventLoopGroup-2-3 system 10 RUNNABLE 00:0falsefalse48 nioEventLoopGroup-2-4 system 10 RUNNABLE 00:0falsefalse52 nioEventLoopGroup-2-5 system 10 RUNNABLE 00:0falsefalse27 nioEventLoopGroup-3-1 system 10 RUNNABLE 00:0falsefalse28 pool-1-thread-1 system 5 TIMED_WAIT 00:0falsefalse29 pool-2-thread-1 system 5 WAITING 00:0falsefalse
Affect(row-cnt:0) cost in119 ms.
Trace the execution time of specified method invocations
We’re tracing the exection time of the com.hascode.tutorial.CurrentDateController’s formatCurrentDate method.
$ trace com.hascode.tutorial.CurrentDateController formatCurrentDate
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in35 ms.
`---ts=2018-10-3015:37:34;thread_name=http-nio-8080-exec-8;id=2b;is_daemon=true;priority=5;TCCL=org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedWebappClassLoader@565a8af8
`---[0.463018ms] com.hascode.tutorial.CurrentDateController:formatCurrentDate()
+---[0.08954ms] java.time.format.DateTimeFormatter:ofPattern()
+---[0.008516ms] java.util.concurrent.atomic.AtomicLong:incrementAndGet()
+---[0.069382ms] java.time.LocalDateTime:now()
+---[0.02449ms] java.time.format.DateTimeFormatter:format()`---[0.058308ms] com.hascode.tutorial.FormattedDate:()
Display parameters, return objects, and thrown exceptions for method invocations
We’re watching the first parameter com.hascode.tutorial.CurrentDateController’s formatCurrentDate method.
$ watch com.hascode.tutorial.CurrentDateController formatCurrentDate params[0]
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in37 ms.
ts=2018-10-3015:38:40;result=@String[yyyy-MM]
Time Tunnel
We’re capturing timings for com.hascode.tutorial.CurrentDateController’s formatCurrentDate method.
$ tt -t com.hascode.tutorial.CurrentDateController formatCurrentDate
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in39 ms.
INDEX TIMESTAMP COST(ms) IS-RET IS-EXP OBJECT CLASS METHOD
--------------------------------------------------------------------------------------------------------------------------------------10002018-10-3015:40:130.448587truefalse 0x599e8629 CurrentDateController formatCurrentDate
10012018-10-3015:40:151.544891truefalse 0x599e8629 CurrentDateController formatCurrentDate
10022018-10-3015:40:150.192611truefalse 0x599e8629 CurrentDateController formatCurrentDate
10032018-10-3015:40:160.254755truefalse 0x599e8629 CurrentDateController formatCurrentDate
10042018-10-3015:40:170.279749truefalse 0x599e8629 CurrentDateController formatCurrentDate
$ tt -l com.hascode.tutorial.CurrentDateController formatCurrentDate
INDEX TIMESTAMP COST(ms) IS-RET IS-EXP OBJECT CLASS METHOD
--------------------------------------------------------------------------------------------------------------------------------------10002018-10-3015:40:130.448587truefalse 0x599e8629 CurrentDateController formatCurrentDate
10012018-10-3015:40:151.544891truefalse 0x599e8629 CurrentDateController formatCurrentDate
10022018-10-3015:40:150.192611truefalse 0x599e8629 CurrentDateController formatCurrentDate
10032018-10-3015:40:160.254755truefalse 0x599e8629 CurrentDateController formatCurrentDate
10042018-10-3015:40:170.279749truefalse 0x599e8629 CurrentDateController formatCurrentDate
Affect(row-cnt:5) cost in2 ms.
Dump class byte array from JVM
We’re dumping the class com.hascode.tutorial.CurrentDateController:
$ dump com.hascode.tutorial.CurrentDateController
HASHCODE CLASSLOADER LOCATION
73d16e93 +-sun.misc.Launcher$AppClassLoader@73d16e93 /home/soma/logs/arthas/classdump/sun.misc.Launcher$AppClassLoader-73d16e93/
+-sun.misc.Launcher$ExtClassLoader@3b1cd4e6 com/hascode/tutorial/CurrentDateController.class
Affect(row-cnt:1) cost in32 ms.
Reading and Setting System Properties
We’re first reading the properties:
$ sysprop
KEY VALUE
--------------------------------------------------------------------------------------------------------------------------------------
java.runtime.name Java(TM) SE Runtime Environment
sun.boot.library.path /usr/lib/jvm/jdk1.8.0_151/jre/lib/amd64
java.vm.version 25.151-b12
java.vm.vendor Oracle Corporation
java.vendor.url http://java.oracle.com/
path.separator :
java.vm.name Java HotSpot(TM)64-Bit Server VM
file.encoding.pkg sun.io
user.country US
sun.java.launcher SUN_STANDARD
sun.os.patch.level unknown
java.vm.specification.nam Java Virtual Machine Specification
e
user.dir /data/project/spring-boot-swagger-tutorial
PID 18043[..]
Then we’re changing the property production.mode to true:
$ sysprop production.mode true
Successfully changed the system property.
production.mode=true
Resources
Debugging and Troubleshooting Java
For more detailed information about tools and methods for analyzing Java applications, please feel free to visit my snippet list here: http://app.hascode.com/forensic/