diff --git a/app/src/main/java/com/mogo/launcher/lancet/jank/spi/HookInvokerImpl.java b/app/src/main/java/com/mogo/launcher/lancet/jank/spi/HookInvokerImpl.java index f7d53ba4dd..50f85649a5 100644 --- a/app/src/main/java/com/mogo/launcher/lancet/jank/spi/HookInvokerImpl.java +++ b/app/src/main/java/com/mogo/launcher/lancet/jank/spi/HookInvokerImpl.java @@ -12,8 +12,8 @@ import com.mogo.eagle.core.function.api.devatools.perf.IMoGoCpuUsageProvider; import com.mogo.eagle.core.function.call.devatools.CallerDevaToolsManager; import com.mogo.eagle.core.function.main.ARouterUtils; import com.zhjt.service.chain.ChainLog; -import java.util.concurrent.atomic.AtomicLong; import java.util.concurrent.atomic.AtomicReference; +import java.util.concurrent.locks.Lock; @AutoService(IHookInvoker.class) @@ -22,7 +22,6 @@ public class HookInvokerImpl implements IHookInvoker { private final Looper mainLooper = Looper.getMainLooper(); private final ThreadLocal startTime = new ThreadLocal<>(); - private final AtomicLong syncLockStartTime = new AtomicLong(0L); private final ThreadLocal message = new ThreadLocal<>(); @@ -30,16 +29,12 @@ public class HookInvokerImpl implements IHookInvoker { private final AtomicReference holder = new AtomicReference<>(); - private String holderDesc = null; + private final StringBuilder extra = new StringBuilder(); private volatile IMoGoCpuUsageProvider provider; private volatile boolean getProviderRequested = false; - private final long logThreshold = 5; //日志打印阈值 - - private final long dumpStackThreshold = 20; // dump堆栈阈值 - private volatile boolean isCanDump = false; // 是否可以Dump堆栈，加此标记位是防止应用启动过程中，由于dump主线程堆栈导致启动耗时 // 切记: 请勿在此方法中调用其它模块类中的api,可能会出现StackOverFlowException @@ -47,7 +42,12 @@ public class HookInvokerImpl implements IHookInvoker { public void i(Type type, Object caller,String methodName, Object... objects) { startTime.set(SystemClock.elapsedRealtime()); boolean isMainThread = mainLooper == Looper.myLooper(); - handleSynchronizedLock(isMainThread, caller, methodName, objects); + if (type == Type.SYNCHRONIZED_LOCK) { + handleSynchronizedLock(isMainThread, caller, methodName, objects); + } + if (type == Type.AQS_LOCK) { + handleAqsLockEnterBefore(isMainThread, caller, methodName, objects); + } if (!getProviderRequested && provider == null && mainLooper != Looper.myLooper() && ARouterUtils.isInit.get()) { getProviderRequested = true; new Thread(() -> { @@ -70,19 +70,22 @@ public class HookInvokerImpl implements IHookInvoker { // 切记: 请勿在此方法中调用其它模块类中的api,可能会出现StackOverFlowException @Override - public void o(Type type, Object caller,String methodName, Object... objects) { + public void o(Type type, Object caller,String methodName, Object... args) { long now = SystemClock.elapsedRealtime(); Long old = startTime.get(); long cost = now - (old == null ? now : old); - if (mainLooper == Looper.myLooper() && type != Type.SYNCHRONIZED_LOCK) { - handleCostTimeRecord(type, caller, methodName, cost, objects); + boolean isMainThread = mainLooper == Looper.myLooper(); + if (isMainThread && type != Type.SYNCHRONIZED_LOCK) { + handleCostTimeRecord(type, null, caller, methodName, cost, args); } - if (mainLooper == Looper.myLooper() && type == Type.ACTIVITY) { - handleActivity((Activity) caller, methodName); + if (isMainThread && type == Type.ACTIVITY) { + handleActivity((Activity) caller, methodName, args); + } + if (type == Type.AQS_LOCK) { + handleAqsLockEnterAfter(isMainThread, caller, methodName, args); } - if (provider != null) { - if (mainLooper == Looper.myLooper()) { + if (isMainThread) { provider.updateMainThreadTime(); } else { provider.updateOtherThreadTime(); @@ -90,7 +93,32 @@ public class HookInvokerImpl implements IHookInvoker { } } - private void handleCostTimeRecord(Type type, Object caller, String methodName, long cost, Object... args) { + private void handleAqsLockEnterBefore(boolean isMainThread, Object caller, String methodName, Object[] objects) { + if (isMainThread && caller instanceof Lock) { + if ("lock".equals(methodName) || "lockInterruptibly".equals(methodName)) { + if (extra.length() > 0) { + extra.setLength(0); + } + extra.append(caller); + } + } + } + + private void handleAqsLockEnterAfter(boolean isMainThread, Object caller, String methodName, Object[] objects) { + if (isMainThread && caller instanceof Lock) { + if ("lock".equals(methodName) || "lockInterruptibly".equals(methodName)) { + Long start = startTime.get(); + if (start != null) { + long dur = SystemClock.elapsedRealtime() - start; + handleCostTimeRecord(Type.AQS_LOCK, extra, caller, methodName, dur, objects); + } + } + } + } + + private void handleCostTimeRecord(Type type, StringBuilder extra, Object caller, String methodName, long cost, Object... args) { + //日志打印阈值 + long logThreshold = 5; if (cost >= logThreshold) { StringBuilder builder = message.get(); if (builder == null) { @@ -123,6 +151,13 @@ public class HookInvokerImpl implements IHookInvoker { } builder.append("#").append(cost); + if (extra != null && extra.length() > 0) { + builder.append("#"); + builder.append(extra); + extra.setLength(0); + } + // dump堆栈阈值 + long dumpStackThreshold = 20; if (cost >= dumpStackThreshold && isCanDump) { builder.append("\n"); StackTraceElement[] stackTrace = Thread.currentThread().getStackTrace(); @@ -131,13 +166,13 @@ public class HookInvokerImpl implements IHookInvoker { } builder.setLength(builder.length() - 1); } - Log.w("HookHandler", "Jank Detected:" + builder); + Log.w("HookHandler", "Junk Detected:" + builder); linkedLog(type, builder.toString()); } } - private void handleActivity(Activity caller, String methodName) { + private void handleActivity(Activity caller, String methodName, Object... args) { if ("onCreate".equals(methodName)) { try { IMoGoBlockProvider block = CallerDevaToolsManager.INSTANCE.block(); @@ -157,8 +192,14 @@ public class HookInvokerImpl implements IHookInvoker { } catch (Throwable t) { t.printStackTrace(); } - if (!isCanDump) { - isCanDump = true; + } + + if ("onWindowFocusChanged".equals(methodName)) { + if (args.length > 0) { + boolean hasFocus = (boolean)args[0]; + if (hasFocus && !isCanDump) { + isCanDump = true; + } } } @@ -188,70 +229,38 @@ public class HookInvokerImpl implements IHookInvoker { private void handleSynchronizedLock(boolean isMainThread,Object caller, String methodName, Object [] objects) { if (isMainThread) { if ("onMonitorBefore".equals(methodName)) { - syncLockStartTime.set(SystemClock.elapsedRealtime()); + Object monitor = null; if (objects.length > 0) { - this.monitor.set(objects[0]); + this.monitor.set(monitor = objects[0]); } Thread holder = this.holder.get(); - if (holder != null) { - holderDesc = holder.toString(); + StringBuilder sb = new StringBuilder(); + + if (monitor != null) { + sb.append("monitor::").append(monitor.getClass().getName()); } + if (holder != null) { + if (sb.length() > 0) { + sb.append("##holder::").append(holder); + } else { + sb.append("holder::").append(holder); + } + } + if (extra.length() > 0) { + extra.setLength(0); + } + extra.append(sb); } if ("onMonitorEnter".equals(methodName)) { - long elapsedTime = SystemClock.elapsedRealtime() - syncLockStartTime.get(); - if (elapsedTime >= logThreshold) { - StringBuilder builder = message.get(); - if (builder == null) { - builder = new StringBuilder(); - message.set(builder); - } - if (builder.length() > 0) { - builder.setLength(0); - } - builder - .append(Type.SYNCHRONIZED_LOCK) - .append("#") - .append(caller == null ? "caller is null" : caller.getClass().getSimpleName()) - .append("#") - .append(methodName); - if (objects.length > 0) { - builder.append("#("); - } - for (Object o : objects) { - if (o == null) { - continue; - } - builder.append(o.getClass().getSimpleName()) - .append(","); - } - - if (objects.length > 0) { - builder.setLength(builder.length() - 1); - builder.append(")"); - } - builder.append("#").append(elapsedTime); - Object monitor = this.monitor.get(); - if (monitor != null) { - builder.append("#").append("monitor->").append(monitor.getClass().getName()).append("@").append(monitor.hashCode()); - } - if (holderDesc != null) { - builder.append("#").append("holder->").append(holderDesc); - } - if (elapsedTime >= dumpStackThreshold && isCanDump) { - builder.append("\n"); - StackTraceElement[] stackTrace = Thread.currentThread().getStackTrace(); - for (StackTraceElement trace: stackTrace) { - builder.append(trace.getClassName()).append("#").append(trace.getMethodName()).append("#").append(trace.getLineNumber()).append("\n"); - } - builder.setLength(builder.length() - 1); - } - Log.w("HookHandler", "Jank detected:" + builder); - linkedLog(Type.SYNCHRONIZED_LOCK, builder.toString()); + Long startTime = this.startTime.get(); + if (startTime == null) { + return; } + long cost = SystemClock.elapsedRealtime() - startTime; + handleCostTimeRecord(Type.SYNCHRONIZED_LOCK, extra, caller, methodName, cost, objects); } if ("onMonitorExit".equals(methodName)) { this.monitor.remove(); - holderDesc = null; } } else { if ("onMonitorBefore".equals(methodName)) { diff --git a/config.gradle b/config.gradle index 5fbbb59fca..ad66f81eff 100644 --- a/config.gradle +++ b/config.gradle @@ -228,7 +228,7 @@ ext { passport_secret : "com.zhidaoauto:sdk-java:1.0.5-SNAPSHOT", // 主线程卡顿监测 - block_detector : "com.mogo.eagle.core.block:runtime:10.80.0", + block_detector : "com.mogo.eagle.core.block:runtime:10.90.0", //======================== google auto-service =============== google_auto_service : "com.google.auto.service:auto-service:1.0-rc7", diff --git a/core/function-impl/mogo-core-function-devatools/src/main/java/com/zhjt/mogo_core_function_devatools/block/MainBlockLinkedLog.kt b/core/function-impl/mogo-core-function-devatools/src/main/java/com/zhjt/mogo_core_function_devatools/block/MainBlockLinkedLog.kt index 25a4a9ab01..3deea81fff 100644 --- a/core/function-impl/mogo-core-function-devatools/src/main/java/com/zhjt/mogo_core_function_devatools/block/MainBlockLinkedLog.kt +++ b/core/function-impl/mogo-core-function-devatools/src/main/java/com/zhjt/mogo_core_function_devatools/block/MainBlockLinkedLog.kt @@ -5,32 +5,19 @@ import com.zhjt.service.chain.* internal class MainBlockLinkedLog { - fun record(extra: Map>) { + fun record(json: String) { try { - recordInternal(extra) + recordInternal(json) } catch (t: Throwable) { t.printStackTrace() } } - fun recordCpuUsage(extra: Map) { - recordCpuInternal(extra) - } - @ChainLog( linkChainLog = ChainConstant.CHAIN_TYPE_ANR_LEAK, linkCode = ChainConstant.CHAIN_SOURCE_HMI, nodeAliasCode = ChainConstant.CHAIN_CODE_MAIN_BLOCK, paramIndexes = [0] ) - private fun recordInternal(extra: Map>) {} - - - @ChainLog( - linkChainLog = ChainConstant.CHAIN_TYPE_ANR_LEAK, - linkCode = ChainConstant.CHAIN_SOURCE_HMI, - nodeAliasCode = ChainConstant.CHAIN_CODE_MAIN_BLOCK, - paramIndexes = [0] - ) - private fun recordCpuInternal(extra: Map) {} + private fun recordInternal(json: String) {} } \ No newline at end of file diff --git a/core/function-impl/mogo-core-function-devatools/src/main/java/com/zhjt/mogo_core_function_devatools/block/MoGoBlockProviderImpl.kt b/core/function-impl/mogo-core-function-devatools/src/main/java/com/zhjt/mogo_core_function_devatools/block/MoGoBlockProviderImpl.kt index b713ee9d02..47961c8d09 100644 --- a/core/function-impl/mogo-core-function-devatools/src/main/java/com/zhjt/mogo_core_function_devatools/block/MoGoBlockProviderImpl.kt +++ b/core/function-impl/mogo-core-function-devatools/src/main/java/com/zhjt/mogo_core_function_devatools/block/MoGoBlockProviderImpl.kt @@ -12,6 +12,7 @@ import com.mogo.eagle.core.block.runtime.listener.* import com.mogo.eagle.core.block.runtime.report.* import com.mogo.eagle.core.function.api.devatools.block.* import com.mogo.eagle.core.function.call.devatools.CallerDevaToolsManager +import com.mogo.eagle.core.utilcode.util.GsonUtils import java.util.concurrent.TimeUnit.SECONDS internal class MoGoBlockProviderImpl: IMoGoBlockProvider, IBlockListener { @@ -55,15 +56,15 @@ internal class MoGoBlockProviderImpl: IMoGoBlockProvider, IBlockListener { val mainThreadUsage = cpu.remove("MainThreadUsage") val processUsage = cpu.remove("ProcessUsage") if (mainThreadUsage != null && processUsage != null) { - linkedLog.recordCpuUsage(LinkedHashMap().also { itx -> - itx["MainThread"] = "${ "%.2f".format(mainThreadUsage * 1.0f * 100 / processUsage) }% ($mainThreadUsage, $processUsage)" - cpu.entries.sortedByDescending { it.value }.forEach { sorted -> - itx[sorted.key] = "${ "%.2f".format(sorted.value * 1.0f * 100 / processUsage) }% (${sorted.value}, $processUsage)" + map["cpu"] = ArrayList().also { + it.add("MainThread: ${ "%.2f".format(mainThreadUsage * 1.0f * 100 / processUsage) }% ($mainThreadUsage, $processUsage)") + cpu.entries.sortedByDescending { e -> + it.add("${e.key}: ${ "%.2f".format(e.value * 1.0f * 100 / processUsage) }% (${e.value}, $processUsage)") } - }) + } } } - linkedLog.record(map) + linkedLog.record(GsonUtils.toJson(map)) } }) } diff --git a/core/function-impl/mogo-core-function-devatools/src/main/java/com/zhjt/mogo_core_function_devatools/perf/MoGoCpuUsageProviderImpl.kt b/core/function-impl/mogo-core-function-devatools/src/main/java/com/zhjt/mogo_core_function_devatools/perf/MoGoCpuUsageProviderImpl.kt index 5a8dedf7f8..b60e0f29cc 100644 --- a/core/function-impl/mogo-core-function-devatools/src/main/java/com/zhjt/mogo_core_function_devatools/perf/MoGoCpuUsageProviderImpl.kt +++ b/core/function-impl/mogo-core-function-devatools/src/main/java/com/zhjt/mogo_core_function_devatools/perf/MoGoCpuUsageProviderImpl.kt @@ -50,13 +50,20 @@ internal class MoGoCpuUsageProviderImpl: IMoGoCpuUsageProvider { override fun updateOtherThreadTime() { val last = otherThreadLaunchedTime.get() val now = Debug.threadCpuTimeNanos() + var flag = true try { if (last == null) { + flag = false otherThreadLaunchedTime.set(now) return } val duration = now - last - if (duration <= 10000) { + if (duration < 1_000_000) { + //每1毫秒更新线程时间 + flag = false + return + } + if (lock.isLocked) { return } var builder = builder.get() @@ -68,16 +75,24 @@ internal class MoGoCpuUsageProviderImpl: IMoGoCpuUsageProvider { builder.setLength(0) } builder.append(Thread.currentThread().name) - lock.withLock { + val isGetLock = lock.tryLock() + if (!isGetLock) { + return + } + try { while (map.size >= maxSize) { val toEvict = map.entries.iterator().next() map.remove(toEvict.key) } val key = builder.toString() map[key] = map.getOrPut(key) { 0L } + duration + } finally { + lock.unlock() } } finally { - otherThreadLaunchedTime.set(now) + if (flag) { + otherThreadLaunchedTime.set(now) + } } }