Preface:
We know that Android carton is mainly caused by time-consuming operations in the main thread, so how can we easily and quickly get the execution time of all time-consuming methods in the main thread? Today we will introduce two plans
Scheme 1: use the special keyword of logging.print of loop() method in loop.java to print time-consuming:
When the message is distributed, the looper.loop() method of the main thread will traverse all messages for distribution and perform time-consuming tasks. Let's look at the loop() method of the source code:
for (;;) {
Message msg = queue.next(); // might block
if (msg == null) {
// No message indicates that the message queue is quitting.
return;
}
// This must be in a local variable, in case a UI event sets the logger
final Printer logging = me.mLogging;
if (logging != null) {
logging.println(">>>>> Dispatching to " + msg.target + " " +
msg.callback + ": " + msg.what);
}
final long traceTag = me.mTraceTag;
... ...
... ...
if (logging != null) {
logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);
}
It can be found that after the distribution and execution of each message, there are special characters > > > > and < < in the logging.print() method. Then we can use this special character as the start and end flag of the message execution, and then print the execution time of the message in the main thread. The specific code is as follows:
/**
* Scheme 1: only time-consuming messages can be printed, and it is impossible to know which message is time-consuming
*/
private void methodOne() {
outputMainLooper();
}
private void outputMainLooper() {
Looper.getMainLooper().setMessageLogging(new Printer() {
@Override
public void println(String x) {
if (x.startsWith(">>>>>")) {
startTime = System.currentTimeMillis();
} else if (x.startsWith("<<<<<")) {
long end = System.currentTimeMillis();
//The time threshold can be defined by yourself. Here is 10
if ((end - startTime) > 10) {
Log.i("buder mainLoop ------ : ", (end - startTime)+ " ");
}
}
}
});
}This scheme can simply and quickly print out the specific execution time of the message in the main thread, but our purpose is to find out which method is time-consuming. We need to print out the stack information of the time-consuming method to help us quickly locate the stuck point. Therefore, scheme one only prints the time-consuming message and cannot locate the specific function.
Scheme 2: use sendMessageAtTime() and dispatchMessage() methods of Handler.java to find out the time-consuming function and print the time-consuming function:
We know that the main thread sends messages, and finally calls the sendMessageAtTime method to enter the message queue, and then the message is distributed and executed through dispatchMessage. Then we can use these two methods to monitor who sent the message and the execution time of the message. In order to do this, we use the epic framework to hook the two functions, as follows:
Step 1: add library dependency in gradle:
implementation 'me.weishu:epic:0.6.0'
Step 2: hook sendMessageAtTime and dispatchMessage
/**
* Scheme 2: print time-consuming messages and time-consuming messages
*/
private void methodTwo() {
final long[] startTime = {0};
//Who is the specific msg message
DexposedBridge.findAndHookMethod(Handler.class, "sendMessageAtTime", Message.class, long.class, new XC_MethodHook() {
@Override
protected void beforeHookedMethod(MethodHookParam param) throws Throwable {
super.beforeHookedMethod(param);
sMsgDetail.put((Message) param.args[0], Log.getStackTraceString(new Throwable()).replace("java.lang.Throwable", ""));
}
@Override
protected void afterHookedMethod(MethodHookParam param) throws Throwable {
super.afterHookedMethod(param);
}
});
//hook dispatchMessage, printing time-consuming
DexposedBridge.findAndHookMethod(Handler.class, "dispatchMessage", Message.class, new XC_MethodHook() {
@Override
protected void beforeHookedMethod(MethodHookParam param) throws Throwable {
startTime[0] = System.currentTimeMillis();
super.beforeHookedMethod(param);
}
@Override
protected void afterHookedMethod(MethodHookParam param) throws Throwable {
super.afterHookedMethod(param);
long costTime = System.currentTimeMillis() - startTime[0];
String stackMessage = null;
//The time threshold can be defined by yourself. Here is 10
if (costTime > 10) {
stackMessage = sMsgDetail.get(param.args[0]);
Log.i("buder", costTime + "***********");
Log.e("buder", stackMessage);
}
}
});
}After executing the method, you can see clearly where the time-consuming operation is executed in the program:
Here we print out the time-consuming of the two schemes, and see that lines 24 and 36 of MainActivity contain time-consuming operations.
Full code:
- MainActivity.java, click event simulation time-consuming task:
public class MainActivity extends AppCompatActivity {
private Button mButton;
@Override
protected void onCreate(Bundle savedInstanceState) {
super.onCreate(savedInstanceState);
setContentView(R.layout.activity_main);
mButton = findViewById(R.id.btn);
mButton.setOnClickListener(new View.OnClickListener() {
@Override
public void onClick(View v) {
//Time consuming operation task 1
new Handler().postDelayed(new Runnable() {
@Override
public void run() {
for(int i = 0; i < 100000; i++) {
System.out.println("test 1");
}
Toast toast = Toast.makeText(getApplicationContext(),"Click Finish", Toast.LENGTH_LONG);
toast.show();
}
}, 1000);
//Time consuming operation task 2
new Handler().post(new Runnable() {
@Override
public void run() {
for(int i = 0; i < 200000; i++) {
System.out.println("test 1");
}
}
});
}
});
}
}- DemoApplication.java includes the above two statistical schemes:
- Remember to add android:name=".DemoApplication" to Manifest
public class DemoApplication extends Application {
private long startTime = 0;
private static ConcurrentHashMap<Message, String> sMsgDetail = new ConcurrentHashMap<>();
@Override
protected void attachBaseContext(Context base) {
super.attachBaseContext(base);
//Obtain time-consuming scheme I
methodOne();
//Obtain time consuming scheme II
methodTwo();
}
/**
* Scheme 2: print time-consuming messages and time-consuming messages
*/
private void methodTwo() {
final long[] startTime = {0};
//Who is the specific msg message
DexposedBridge.findAndHookMethod(Handler.class, "sendMessageAtTime", Message.class, long.class, new XC_MethodHook() {
@Override
protected void beforeHookedMethod(MethodHookParam param) throws Throwable {
super.beforeHookedMethod(param);
sMsgDetail.put((Message) param.args[0], Log.getStackTraceString(new Throwable()).replace("java.lang.Throwable", ""));
}
@Override
protected void afterHookedMethod(MethodHookParam param) throws Throwable {
super.afterHookedMethod(param);
}
});
//hook dispatchMessage, printing time-consuming
DexposedBridge.findAndHookMethod(Handler.class, "dispatchMessage", Message.class, new XC_MethodHook() {
@Override
protected void beforeHookedMethod(MethodHookParam param) throws Throwable {
startTime[0] = System.currentTimeMillis();
super.beforeHookedMethod(param);
}
@Override
protected void afterHookedMethod(MethodHookParam param) throws Throwable {
super.afterHookedMethod(param);
long costTime = System.currentTimeMillis() - startTime[0];
String stackMessage = null;
//The time threshold can be defined by yourself. Here is 100
if (costTime > 100) {
stackMessage = sMsgDetail.get(param.args[0]);
Log.i("buder", costTime + "***********");
Log.e("buder", stackMessage);
}
}
});
}
/**
* Scheme 1: only time-consuming messages can be printed, and it is impossible to know which message is time-consuming
*/
private void methodOne() {
outputMainLooper();
}
private void outputMainLooper() {
Looper.getMainLooper().setMessageLogging(new Printer() {
@Override
public void println(String x) {
if (x.startsWith(">>>>>")) {
startTime = System.currentTimeMillis();
} else if (x.startsWith("<<<<<")) {
long end = System.currentTimeMillis();
//The time threshold can be defined by yourself. Here is 100
if ((end - startTime) > 100) {
Log.i("buder mainLoop ------ : ", (end - startTime)+ " ");
}
}
}
});
}
@Override
public void onCreate() {
super.onCreate();
}
}Full address: https://github.com/buder-cp/base_component_learn/tree/master/timeConsumingPrinter
Reference blog: https://blog.csdn.net/qq_20798591/article/details/104354723
epic related: http://weishu.me/
android-hacker/epic : https://gitter.im/android-hacker/epic?at=5ac9c6951130fe3d36b39c6a
