本文要点
mLogging
**对象,
它在每个**Message
**处理前后都会被调用: dispatchMessage
**执行了耗时操作! Handler机制图
由此,我们便可以通过**
mLogging
**对象 对**dispatchMessage
**执行的时间进行监控;
public static void loop() {
final Looper me = myLooper();
if (me == null) {
throw new RuntimeException("No Looper; Looper.prepare() wasn't called on this thread.");
}
final MessageQueue queue = me.mQueue;
// Make sure the identity of this thread is that of the local process,
// and keep track of what that identity token actually is.
Binder.clearCallingIdentity();
final long ident = Binder.clearCallingIdentity();
// Allow overriding a threshold with a system prop. e.g.
// adb shell 'setprop log.looper.1000.main.slow 1 && stop && start'
final int thresholdOverride =
SystemProperties.getInt("log.looper."
+ Process.myUid() + "."
+ Thread.currentThread().getName()
+ ".slow", 0);
boolean slowDeliveryDetected = false;
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;
long slowDispatchThresholdMs = me.mSlowDispatchThresholdMs;
long slowDeliveryThresholdMs = me.mSlowDeliveryThresholdMs;
if (thresholdOverride > 0) {
slowDispatchThresholdMs = thresholdOverride;
slowDeliveryThresholdMs = thresholdOverride;
}
final boolean logSlowDelivery = (slowDeliveryThresholdMs > 0) && (msg.when > 0);
final boolean logSlowDispatch = (slowDispatchThresholdMs > 0);
final boolean needStartTime = logSlowDelivery || logSlowDispatch;
final boolean needEndTime = logSlowDispatch;
if (traceTag != 0 && Trace.isTagEnabled(traceTag)) {
Trace.traceBegin(traceTag, msg.target.getTraceName(msg));
}
final long dispatchStart = needStartTime ? SystemClock.uptimeMillis() : 0;
final long dispatchEnd;
try {
msg.target.dispatchMessage(msg);
dispatchEnd = needEndTime ? SystemClock.uptimeMillis() : 0;
} finally {
if (traceTag != 0) {
Trace.traceEnd(traceTag);
}
}
if (logSlowDelivery) {
if (slowDeliveryDetected) {
if ((dispatchStart - msg.when) <= 10) {
Slog.w(TAG, "Drained");
slowDeliveryDetected = false;
}
} else {
if (showSlowLog(slowDeliveryThresholdMs, msg.when, dispatchStart, "delivery",
msg)) {
// Once we write a slow delivery log, suppress until the queue drains.
slowDeliveryDetected = true;
}
}
}
if (logSlowDispatch) {
showSlowLog(slowDispatchThresholdMs, dispatchStart, dispatchEnd, "dispatch", msg);
}
if (logging != null) {
logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);
}
// Make sure that during the course of dispatching the
// identity of the thread wasn't corrupted.
final long newIdent = Binder.clearCallingIdentity();
if (ident != newIdent) {
Log.wtf(TAG, "Thread identity changed from 0x"
+ Long.toHexString(ident) + " to 0x"
+ Long.toHexString(newIdent) + " while dispatching to "
+ msg.target.getClass().getName() + " "
+ msg.callback + " what=" + msg.what);
}
msg.recycleUnchecked();
}
}
会不断地读取消息队列队头进行处理:
logging.println()
** 执行之后再次调用
我们可以从打印日志的前缀来判断Message处理的**开始
**和**结束
**;
Looper.getMainLooper().setMessageLogging();
**,
来设置我们自己的Logging;
这样每次Message处理的前后,
调用的就是我们自己的Logging;>>>>> Dispatching
**,
我们就可以执行一个代码,
即在指定的阈值时间之后,
在子线程中开始执行一个【获取当前子线程的堆栈信息以及当前的一些场景信息(如内存大小、变量、网络状态等)】的任务;如果匹配到**<<<<< Finished
**,
则说明在指定的阈值时间内,Message被执行完成,没有发生卡顿,
那便将这个任务取消掉;
性能监控组件
**,
可以用**通知的方式
** 弹出卡顿信息,同时用**logcat
**打印出关于卡顿的详细信息;
可以检测所有线程中执行的任何方法,又不需要手动埋点,
设置好阈值等配置,就“坐享其成”,等卡顿问题“愿者上钩”!! 【方案的**不足
** 以及**框架源码解析
** 在下面实战之后总结!!】
implementation 'com.github.markzhai:blockcanary-android:1.5.0'
BlockCanary.install(this, new AppBlockCanaryContext()).start();
第一个参数是**上下文
**,
第二个参数是需要传入一个**Block的配置类实例
**【BlockCanaryContext类实例或者其子类实例】:public class TestApp extends Application {
@Override
public void onCreate() {
super.onCreate();
...
//AndroidPerformanceMonitor测试
BlockCanary.install(this, new AppBlockCanaryContext()).start();
}
}
AppBlockCanaryContext
**是我们自定义的类,**
配置了**BlockCanary
**的各种信息,
代码较多,可以看下GitHub,这里就不贴全部代码了~
下面两个配置方法分别是
给出一个**uid
**,可以用于在上报时上报**当前的用户信息
**;
第二个是自定义**卡顿的阈值时间
**,过了阈值便认为是卡顿,
这里指定的是**500ms
**; /**
* Implement in your project.
*
* @return user id
*/
public String provideUid() {
return "uid";
}
/**
* Config block threshold (in millis), dispatch over this duration is regarded as a BLOCK. You may set it
* from performance of device.
*
* @return threshold in mills
*/
public int provideBlockThreshold() {
return 500;
}
MainActivity
**的**onCreate()
**中,
让主线程沉睡两秒(2000ms > 设定的阈值500ms);
后台弹出界面
**, 桌面上便会出现这个图标:
进去之后就可以看到了相应的信息了:
当然,我们可以在logcat中定位关键词**blockInfo
**,
看到同样的详细的信息:
如上,
Block框架打印出来了【当前子线程的**堆栈信息
**以及当前的一些**场景信息
**(如内存大小、变量、网络状态等)】,
从 time-start
到 time-end
**的**时间间隔
**又可以知道**阻塞的时间
**,如上图展示出来的,正是我们设置的**2秒
**!!!!**
也可以看到**uid键
**的值 便是我们刚刚设定的**字符串“uid”
**;
同时还直接帮我们定位到**卡顿问题的出处
**!!!
可见得BlockCanary已然 成功检测到**
卡顿
**问题的各种具体信息了!!!
由于篇幅原因,笔者把以下解析内容提取出来单独作一篇博客哈~
目录 1. 监控周期的 定义 2. dump模块 / 关于.log文件 3. 采集堆栈周期的 设定 4. 框架的 配置存储类 以及 文件系统操作封装 5. 文件写入过程(生成.log文件的源码) 6. 上传文件 7. 设计模式、技巧 8. 框架中各个主要类的功能划分
【假设初始方案,整个**监控周期
**只采集一次】
如上图,
假设主线程
在**时间点T1(开始阻塞)
**与**T2(阻塞结束)
**之间的时间段中发生了卡顿,
而**卡顿检测方案
**是在**T2时刻
**,
也就是 阻塞时间完全结束 (前提是**T2-T1大于阈值
**,确定了是卡顿问题)的时刻,
方案**才开始
**获取**卡顿堆栈的信息
**,
而**实际发生卡顿
**(如发生**违例耗时处理过程
**)的**时间点
**,
可能是在这个时间段内,而非获取信息的T2点,
那有可能,
耗时操作
**在**时间段内
**,即在T2点之前就已经**执行完成
**了,**
T2点获取到的可能不是卡顿发生的准确时刻,
也就是说**T2时刻
**获取到的信息,不能够完全**反映卡顿的现场
**;
最后的T2点的堆栈信息只是表象,不能反映真正的问题;
我们需要缩小采集堆栈信息的周期,进行**高频采集
**,详细如下;
startMonitor
**开始监控(Message分发、处理前),**
接着**高频采集堆栈
**!!!
阻塞结束,Message分发、处理后,前后时间差——阻塞时间超过阈值,即发生卡顿,便调用**endMonitor
**;
记录 高频采集好的堆栈信息 到文件中
**;【具体源码解析见上面解析部分(另一篇博客)】**
在合适的时机**上报
**给服务器;【相关方案以及源码解析见上面解析部分(另一篇博客)】
卡顿现场
**不能还原的问题;- **突破点:一个卡顿下多个堆栈大概率有重复;**
- **解决:对一个卡顿下的堆栈进行hash排重,**
参考: