diff options
Diffstat (limited to 'tools/lock_agent/java')
-rw-r--r-- | tools/lock_agent/java/com/android/lock_checker/LockHook.java | 290 | ||||
-rw-r--r-- | tools/lock_agent/java/com/android/lock_checker/OnThreadLockChecker.java | 368 |
2 files changed, 658 insertions, 0 deletions
diff --git a/tools/lock_agent/java/com/android/lock_checker/LockHook.java b/tools/lock_agent/java/com/android/lock_checker/LockHook.java new file mode 100644 index 000000000000..95b318101316 --- /dev/null +++ b/tools/lock_agent/java/com/android/lock_checker/LockHook.java @@ -0,0 +1,290 @@ +/* + * Copyright (C) 2019 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.android.lock_checker; + +import android.os.Handler; +import android.os.HandlerThread; +import android.os.Looper; +import android.os.Message; +import android.os.Process; +import android.util.Log; +import android.util.LogWriter; + +import com.android.internal.os.SomeArgs; +import com.android.internal.util.StatLogger; + +import dalvik.system.AnnotatedStackTraceElement; + +import libcore.util.HexEncoding; + +import java.io.PrintWriter; +import java.nio.charset.Charset; +import java.security.MessageDigest; +import java.security.NoSuchAlgorithmException; +import java.util.Map; +import java.util.concurrent.ConcurrentLinkedQueue; +import java.util.concurrent.atomic.AtomicInteger; + +/** + * Entry class for lock inversion infrastructure. The agent will inject calls to preLock + * and postLock, and the hook will call the checker, and store violations. + */ +public class LockHook { + private static final String TAG = "LockHook"; + + private static final Charset sFilenameCharset = Charset.forName("UTF-8"); + + private static final HandlerThread sHandlerThread; + private static final WtfHandler sHandler; + + private static final AtomicInteger sTotalObtainCount = new AtomicInteger(); + private static final AtomicInteger sTotalReleaseCount = new AtomicInteger(); + private static final AtomicInteger sDeepestNest = new AtomicInteger(); + + /** + * Whether to do the lock check on this thread. + */ + private static final ThreadLocal<Boolean> sDoCheck = ThreadLocal.withInitial(() -> true); + + interface Stats { + int ON_THREAD = 0; + } + + static final StatLogger sStats = new StatLogger(new String[] { "on-thread", }); + + private static final ConcurrentLinkedQueue<Object> sViolations = new ConcurrentLinkedQueue<>(); + private static final int MAX_VIOLATIONS = 50; + + private static final LockChecker[] sCheckers; + + static { + sHandlerThread = new HandlerThread("LockHook:wtf", Process.THREAD_PRIORITY_BACKGROUND); + sHandlerThread.start(); + sHandler = new WtfHandler(sHandlerThread.getLooper()); + + sCheckers = new LockChecker[] { new OnThreadLockChecker() }; + } + + static <T> boolean shouldDumpStacktrace(StacktraceHasher hasher, Map<String, T> dumpedSet, + T val, AnnotatedStackTraceElement[] st, int from, int to) { + final String stacktraceHash = hasher.stacktraceHash(st, from, to); + if (dumpedSet.containsKey(stacktraceHash)) { + return false; + } + dumpedSet.put(stacktraceHash, val); + return true; + } + + static void updateDeepestNest(int nest) { + for (;;) { + final int knownDeepest = sDeepestNest.get(); + if (knownDeepest >= nest) { + return; + } + if (sDeepestNest.compareAndSet(knownDeepest, nest)) { + return; + } + } + } + + static void wtf(String message) { + sHandler.wtf(message); + } + + static void doCheckOnThisThread(boolean check) { + sDoCheck.set(check); + } + + /** + * This method is called when a lock is about to be held. (Except if it's a + * synchronized, the lock is already held.) + */ + public static void preLock(Object lock) { + if (Thread.currentThread() != sHandlerThread && sDoCheck.get()) { + sDoCheck.set(false); + try { + sTotalObtainCount.incrementAndGet(); + for (LockChecker checker : sCheckers) { + checker.pre(lock); + } + } finally { + sDoCheck.set(true); + } + } + } + + /** + * This method is called when a lock is about to be released. + */ + public static void postLock(Object lock) { + if (Thread.currentThread() != sHandlerThread && sDoCheck.get()) { + sDoCheck.set(false); + try { + sTotalReleaseCount.incrementAndGet(); + for (LockChecker checker : sCheckers) { + checker.post(lock); + } + } finally { + sDoCheck.set(true); + } + } + } + + private static class WtfHandler extends Handler { + private static final int MSG_WTF = 1; + + WtfHandler(Looper looper) { + super(looper); + } + + public void wtf(String msg) { + sDoCheck.set(false); + SomeArgs args = SomeArgs.obtain(); + args.arg1 = msg; + obtainMessage(MSG_WTF, args).sendToTarget(); + sDoCheck.set(true); + } + + @Override + public void handleMessage(Message msg) { + switch (msg.what) { + case MSG_WTF: + SomeArgs args = (SomeArgs) msg.obj; + Log.wtf(TAG, (String) args.arg1); + args.recycle(); + break; + } + } + } + + /** + * Generates a hash for a given stacktrace of a {@link Throwable}. + */ + static class StacktraceHasher { + private byte[] mLineNumberBuffer = new byte[4]; + private final MessageDigest mHash; + + StacktraceHasher() { + try { + mHash = MessageDigest.getInstance("MD5"); + } catch (NoSuchAlgorithmException e) { + throw new RuntimeException(e); + } + } + + public String stacktraceHash(Throwable t) { + mHash.reset(); + for (StackTraceElement e : t.getStackTrace()) { + hashStackTraceElement(e); + } + return HexEncoding.encodeToString(mHash.digest()); + } + + public String stacktraceHash(AnnotatedStackTraceElement[] annotatedStack, int from, + int to) { + mHash.reset(); + for (int i = from; i <= to; i++) { + hashStackTraceElement(annotatedStack[i].getStackTraceElement()); + } + return HexEncoding.encodeToString(mHash.digest()); + } + + private void hashStackTraceElement(StackTraceElement e) { + if (e.getFileName() != null) { + mHash.update(sFilenameCharset.encode(e.getFileName()).array()); + } else { + if (e.getClassName() != null) { + mHash.update(sFilenameCharset.encode(e.getClassName()).array()); + } + if (e.getMethodName() != null) { + mHash.update(sFilenameCharset.encode(e.getMethodName()).array()); + } + } + + final int line = e.getLineNumber(); + mLineNumberBuffer[0] = (byte) ((line >> 24) & 0xff); + mLineNumberBuffer[1] = (byte) ((line >> 16) & 0xff); + mLineNumberBuffer[2] = (byte) ((line >> 8) & 0xff); + mLineNumberBuffer[3] = (byte) ((line >> 0) & 0xff); + mHash.update(mLineNumberBuffer); + } + } + + static void addViolation(Object o) { + sViolations.offer(o); + while (sViolations.size() > MAX_VIOLATIONS) { + sViolations.poll(); + } + } + + /** + * Dump stats to the given PrintWriter. + */ + public static void dump(PrintWriter pw, String indent) { + final int oc = LockHook.sTotalObtainCount.get(); + final int rc = LockHook.sTotalReleaseCount.get(); + final int dn = LockHook.sDeepestNest.get(); + pw.print("Lock stats: oc="); + pw.print(oc); + pw.print(" rc="); + pw.print(rc); + pw.print(" dn="); + pw.print(dn); + pw.println(); + + for (LockChecker checker : sCheckers) { + pw.print(indent); + pw.print(" "); + checker.dump(pw); + pw.println(); + } + + sStats.dump(pw, indent); + + pw.print(indent); + pw.println("Violations:"); + for (Object v : sViolations) { + pw.print(indent); // This won't really indent a multiline string, + // though. + pw.println(v); + } + } + + /** + * Dump stats to logcat. + */ + public static void dump() { + // Dump to logcat. + PrintWriter out = new PrintWriter(new LogWriter(Log.WARN, TAG), true); + dump(out, ""); + out.close(); + } + + interface LockChecker { + void pre(Object lock); + + void post(Object lock); + + int getNumDetected(); + + int getNumDetectedUnique(); + + String getCheckerName(); + + void dump(PrintWriter pw); + } +} diff --git a/tools/lock_agent/java/com/android/lock_checker/OnThreadLockChecker.java b/tools/lock_agent/java/com/android/lock_checker/OnThreadLockChecker.java new file mode 100644 index 000000000000..0f3a28598741 --- /dev/null +++ b/tools/lock_agent/java/com/android/lock_checker/OnThreadLockChecker.java @@ -0,0 +1,368 @@ +/* + * Copyright (C) 2019 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.android.lock_checker; + +import android.util.Log; + +import dalvik.system.AnnotatedStackTraceElement; +import dalvik.system.VMStack; + +import java.io.PrintWriter; +import java.util.ArrayList; +import java.util.List; +import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.ConcurrentMap; +import java.util.concurrent.LinkedBlockingQueue; +import java.util.concurrent.atomic.AtomicInteger; + + +class OnThreadLockChecker implements LockHook.LockChecker { + private static final String TAG = "LockCheckOnThread"; + + private static final boolean SKIP_RECURSIVE = true; + + private final Thread mChecker; + + private final AtomicInteger mNumDetected = new AtomicInteger(); + + private final AtomicInteger mNumDetectedUnique = new AtomicInteger(); + + // Queue for possible violations, to handle them on the sChecker thread. + private final LinkedBlockingQueue<Violation> mQueue = new LinkedBlockingQueue<>(); + + // The stack of locks held on the current thread. + private final ThreadLocal<List<Object>> mHeldLocks = ThreadLocal + .withInitial(() -> new ArrayList<>(10)); + + // A cached stacktrace hasher for each thread. The hasher caches internal objects and is not + // thread-safe. + private final ThreadLocal<LockHook.StacktraceHasher> mStacktraceHasher = ThreadLocal + .withInitial(() -> new LockHook.StacktraceHasher()); + + // A map of stacktrace hashes we have seen. + private final ConcurrentMap<String, Boolean> mDumpedStacktraceHashes = + new ConcurrentHashMap<>(); + + OnThreadLockChecker() { + mChecker = new Thread(() -> checker()); + mChecker.setName(TAG); + mChecker.setPriority(Thread.MIN_PRIORITY); + mChecker.start(); + } + + private static class LockPair { + // Consider WeakReference. It will require also caching the String + // description for later reporting, though. + Object mFirst; + Object mSecond; + + private int mCachedHashCode; + + LockPair(Object first, Object second) { + mFirst = first; + mSecond = second; + computeHashCode(); + } + + public void set(Object newFirst, Object newSecond) { + mFirst = newFirst; + mSecond = newSecond; + computeHashCode(); + } + + private void computeHashCode() { + final int prime = 31; + int result = 1; + result = prime * result + ((mFirst == null) ? 0 : System.identityHashCode(mFirst)); + result = prime * result + ((mSecond == null) ? 0 : System.identityHashCode(mSecond)); + mCachedHashCode = result; + } + + @Override + public int hashCode() { + return mCachedHashCode; + } + + @Override + public boolean equals(Object obj) { + if (this == obj) { + return true; + } + if (obj == null) { + return false; + } + if (getClass() != obj.getClass()) { + return false; + } + LockPair other = (LockPair) obj; + return mFirst == other.mFirst && mSecond == other.mSecond; + } + } + + private static class OrderData { + final int mTid; + final String mThreadName; + final AnnotatedStackTraceElement[] mStack; + + OrderData(int tid, String threadName, AnnotatedStackTraceElement[] stack) { + this.mTid = tid; + this.mThreadName = threadName; + this.mStack = stack; + } + } + + private static ConcurrentMap<LockPair, OrderData> sLockOrderMap = new ConcurrentHashMap<>(); + + @Override + public void pre(Object lock) { + handlePre(Thread.currentThread(), lock); + } + + @Override + public void post(Object lock) { + handlePost(Thread.currentThread(), lock); + } + + private void handlePre(Thread self, Object lock) { + List<Object> heldLocks = mHeldLocks.get(); + + LockHook.updateDeepestNest(heldLocks.size() + 1); + + heldLocks.add(lock); + if (heldLocks.size() == 1) { + return; + } + + // Data about this location. Cached and lazily initialized. + AnnotatedStackTraceElement[] annotatedStack = null; + OrderData orderData = null; + + // Reused tmp pair; + LockPair tmp = new LockPair(lock, lock); + + int size = heldLocks.size() - 1; + for (int i = 0; i < size; i++) { + Object alreadyHeld = heldLocks.get(i); + if (SKIP_RECURSIVE && lock == alreadyHeld) { + return; + } + + // Check if we've already seen alreadyHeld -> lock. + tmp.set(alreadyHeld, lock); + if (sLockOrderMap.containsKey(tmp)) { + continue; // Already seen. + } + + // Note: could insert the OrderData now. This would mean we only + // report one instance for each order violation, but it avoids + // the expensive hashing in handleViolation for duplicate stacks. + + // Locking alreadyHeld -> lock, check whether the inverse exists. + tmp.set(lock, alreadyHeld); + + // We technically need a critical section here. Add synchronized and + // skip + // instrumenting this class. For now, a concurrent hash map is good + // enough. + + OrderData oppositeData = sLockOrderMap.getOrDefault(tmp, null); + if (oppositeData != null) { + if (annotatedStack == null) { + annotatedStack = VMStack.getAnnotatedThreadStackTrace(self); + } + postViolation(self, alreadyHeld, lock, annotatedStack, oppositeData); + continue; + } + + // Enter our occurrence. + if (annotatedStack == null) { + annotatedStack = VMStack.getAnnotatedThreadStackTrace(self); + } + if (orderData == null) { + orderData = new OrderData((int) self.getId(), self.getName(), annotatedStack); + } + sLockOrderMap.putIfAbsent(new LockPair(alreadyHeld, lock), orderData); + + // Check again whether we might have raced with the opposite. + oppositeData = sLockOrderMap.getOrDefault(tmp, null); + if (oppositeData != null) { + postViolation(self, alreadyHeld, lock, annotatedStack, oppositeData); + } + } + } + + private void handlePost(Thread self, Object lock) { + List<Object> heldLocks = mHeldLocks.get(); + if (heldLocks.isEmpty()) { + Log.wtf("LockCheckMine", "Empty thread list on post()"); + return; + } + int index = heldLocks.size() - 1; + if (heldLocks.get(index) != lock) { + Log.wtf("LockCheckMine", "post(" + Violation.describeLock(lock) + ") vs [..., " + + Violation.describeLock(heldLocks.get(index)) + "]"); + return; + } + heldLocks.remove(index); + } + + private static class Violation { + int mSelfTid; + String mSelfName; + Object mAlreadyHeld; + Object mLock; + AnnotatedStackTraceElement[] mStack; + OrderData mOppositeData; + + Violation(Thread self, Object alreadyHeld, Object lock, + AnnotatedStackTraceElement[] stack, OrderData oppositeData) { + this.mSelfTid = (int) self.getId(); + this.mSelfName = self.getName(); + this.mAlreadyHeld = alreadyHeld; + this.mLock = lock; + this.mStack = stack; + this.mOppositeData = oppositeData; + } + + private static String getAnnotatedStackString(AnnotatedStackTraceElement[] stackTrace, + int skip, String extra, int prefixAfter, String prefix) { + StringBuilder sb = new StringBuilder(); + for (int i = skip; i < stackTrace.length; i++) { + AnnotatedStackTraceElement element = stackTrace[i]; + sb.append(" ").append(i >= prefixAfter ? prefix : "").append("at ") + .append(element.getStackTraceElement()).append('\n'); + if (i == skip && extra != null) { + sb.append(" ").append(extra).append('\n'); + } + if (element.getHeldLocks() != null) { + for (Object held : element.getHeldLocks()) { + sb.append(" ").append(i >= prefixAfter ? prefix : "") + .append(describeLocking(held, "locked")).append('\n'); + } + } + } + return sb.toString(); + } + + private static String describeLocking(Object lock, String action) { + return String.format("- %s %s", action, describeLock(lock)); + } + + private static int getTo(AnnotatedStackTraceElement[] stack, Object searchFor) { + // Extract the range of the annotated stack. + int to = stack.length - 1; + for (int i = 0; i < stack.length; i++) { + Object[] locks = stack[i].getHeldLocks(); + if (locks != null) { + for (Object heldLock : locks) { + if (heldLock == searchFor) { + to = i; + break; + } + } + } + } + return to; + } + + private static String describeLock(Object lock) { + return String.format("<0x%08x> (a %s)", System.identityHashCode(lock), + lock.getClass().getName()); + } + + public String toString() { + StringBuilder sb = new StringBuilder(); + sb.append("Lock inversion detected!\n"); + sb.append(" Locked "); + sb.append(describeLock(mLock)); + sb.append(" -> "); + sb.append(describeLock(mAlreadyHeld)); + sb.append(" on thread ").append(mOppositeData.mTid).append(" (") + .append(mOppositeData.mThreadName).append(")"); + sb.append(" at:\n"); + sb.append(getAnnotatedStackString(mOppositeData.mStack, 4, + describeLocking(mAlreadyHeld, "will lock"), getTo(mOppositeData.mStack, mLock) + + 1, " | ")); + sb.append(" Locking "); + sb.append(describeLock(mAlreadyHeld)); + sb.append(" -> "); + sb.append(describeLock(mLock)); + sb.append(" on thread ").append(mSelfTid).append(" (").append(mSelfName).append(")"); + sb.append(" at:\n"); + sb.append(getAnnotatedStackString(mStack, 4, describeLocking(mLock, "will lock"), + getTo(mStack, mAlreadyHeld) + 1, " | ")); + + return sb.toString(); + } + } + + private void postViolation(Thread self, Object alreadyHeld, Object lock, + AnnotatedStackTraceElement[] annotatedStack, OrderData oppositeData) { + mQueue.offer(new Violation(self, alreadyHeld, lock, annotatedStack, oppositeData)); + } + + private void handleViolation(Violation v) { + mNumDetected.incrementAndGet(); + // Extract the range of the annotated stack. + int to = Violation.getTo(v.mStack, v.mAlreadyHeld); + + if (LockHook.shouldDumpStacktrace(mStacktraceHasher.get(), mDumpedStacktraceHashes, + Boolean.TRUE, v.mStack, 0, to)) { + mNumDetectedUnique.incrementAndGet(); + LockHook.wtf(v.toString()); + LockHook.addViolation(v); + } + } + + private void checker() { + LockHook.doCheckOnThisThread(false); + + for (;;) { + try { + Violation v = mQueue.take(); + handleViolation(v); + } catch (InterruptedException e) { + // TODO Auto-generated catch block + e.printStackTrace(); + } + } + } + + @Override + public int getNumDetected() { + return mNumDetected.get(); + } + + @Override + public int getNumDetectedUnique() { + return mNumDetectedUnique.get(); + } + + @Override + public String getCheckerName() { + return "Standard LockChecker"; + } + + @Override + public void dump(PrintWriter pw) { + pw.print(getCheckerName()); + pw.print(": d="); + pw.print(getNumDetected()); + pw.print(" du="); + pw.print(getNumDetectedUnique()); + } +} |