diff options
author | Brad Fitzpatrick <bradfitz@android.com> | 2010-03-24 16:14:09 -0700 |
---|---|---|
committer | Brad Fitzpatrick <bradfitz@android.com> | 2010-03-24 23:57:34 -0700 |
commit | 2c5da313dd72c284fbc2c11839f8a452ab5ce574 (patch) | |
tree | 3ab1cc50bd2ed74d7fd26861c13ad4a59cd60544 /core/jni/android_util_Binder.cpp | |
parent | 450e9d00ea3e8211ef2bf5c0c3eba4f5f4622193 (diff) | |
download | frameworks_base-2c5da313dd72c284fbc2c11839f8a452ab5ce574.zip frameworks_base-2c5da313dd72c284fbc2c11839f8a452ab5ce574.tar.gz frameworks_base-2c5da313dd72c284fbc2c11839f8a452ab5ce574.tar.bz2 |
Log blocking Binder calls to the EventLog.
This mimics what we do already for SQLiteDatabase's db_operation and
ContentProvider's content_query_operation and
content_update_operation: over a threshold things are always logged,
and under which they're sub-sampled.
Change-Id: Ia0280b9b07b336ee88b17be2a31a7af0fd7c5770
Diffstat (limited to 'core/jni/android_util_Binder.cpp')
-rw-r--r-- | core/jni/android_util_Binder.cpp | 97 |
1 files changed, 96 insertions, 1 deletions
diff --git a/core/jni/android_util_Binder.cpp b/core/jni/android_util_Binder.cpp index 5182a77..ea90b59 100644 --- a/core/jni/android_util_Binder.cpp +++ b/core/jni/android_util_Binder.cpp @@ -22,12 +22,15 @@ #include <fcntl.h> #include <sys/stat.h> +#include <sys/types.h> #include <stdio.h> #include <utils/Atomic.h> #include <binder/IInterface.h> #include <binder/IPCThreadState.h> #include <utils/Log.h> +#include <utils/SystemClock.h> +#include <cutils/logger.h> #include <binder/Parcel.h> #include <binder/ProcessState.h> #include <binder/IServiceManager.h> @@ -740,7 +743,7 @@ static jstring android_os_BinderProxy_getInterfaceDescriptor(JNIEnv* env, jobjec { IBinder* target = (IBinder*) env->GetIntField(obj, gBinderProxyOffsets.mObject); if (target != NULL) { - String16 desc = target->getInterfaceDescriptor(); + const String16& desc = target->getInterfaceDescriptor(); return env->NewString(desc.string(), desc.size()); } jniThrowException(env, "java/lang/RuntimeException", @@ -759,6 +762,87 @@ static jboolean android_os_BinderProxy_isBinderAlive(JNIEnv* env, jobject obj) return alive ? JNI_TRUE : JNI_FALSE; } +static int getprocname(pid_t pid, char *buf, size_t len) { + char filename[20]; + FILE *f; + + sprintf(filename, "/proc/%d/cmdline", pid); + f = fopen(filename, "r"); + if (!f) { *buf = '\0'; return 1; } + if (!fgets(buf, len, f)) { *buf = '\0'; return 2; } + fclose(f); + return 0; +} + +static bool push_eventlog_string(char** pos, const char* end, const char* str) { + jint len = strlen(str); + int space_needed = 1 + sizeof(len) + len; + if (end - *pos < space_needed) { + LOGW("not enough space for string. remain=%d; needed=%d", + (end - *pos), space_needed); + return false; + } + **pos = EVENT_TYPE_STRING; + (*pos)++; + memcpy(*pos, &len, sizeof(len)); + *pos += sizeof(len); + memcpy(*pos, str, len); + *pos += len; + return true; +} + +static bool push_eventlog_int(char** pos, const char* end, jint val) { + int space_needed = 1 + sizeof(val); + if (end - *pos < space_needed) { + LOGW("not enough space for int. remain=%d; needed=%d", + (end - *pos), space_needed); + return false; + } + **pos = EVENT_TYPE_INT; + (*pos)++; + memcpy(*pos, &val, sizeof(val)); + *pos += sizeof(val); + return true; +} + +// From frameworks/base/core/java/android/content/EventLogTags.logtags: +#define LOGTAG_BINDER_OPERATION 52004 + +static void conditionally_log_binder_call(int64_t start_millis, + IBinder* target, jint code) { + int duration_ms = static_cast<int>(uptimeMillis() - start_millis); + + int sample_percent; + if (duration_ms >= 500) { + sample_percent = 100; + } else { + sample_percent = 100 * duration_ms / 500; + if (sample_percent == 0) { + return; + } + if (sample_percent < (random() % 100 + 1)) { + return; + } + } + + char process_name[40]; + getprocname(getpid(), process_name, sizeof(process_name)); + String8 desc(target->getInterfaceDescriptor()); + + char buf[LOGGER_ENTRY_MAX_PAYLOAD]; + buf[0] = EVENT_TYPE_LIST; + buf[1] = 5; + char* pos = &buf[2]; + char* end = &buf[LOGGER_ENTRY_MAX_PAYLOAD - 1]; // leave room for final \n + if (!push_eventlog_string(&pos, end, desc.string())) return; + if (!push_eventlog_int(&pos, end, code)) return; + if (!push_eventlog_int(&pos, end, duration_ms)) return; + if (!push_eventlog_string(&pos, end, process_name)) return; + if (!push_eventlog_int(&pos, end, sample_percent)) return; + *(pos++) = '\n'; // conventional with EVENT_TYPE_LIST apparently. + android_bWriteLog(LOGTAG_BINDER_OPERATION, buf, pos - buf); +} + static jboolean android_os_BinderProxy_transact(JNIEnv* env, jobject obj, jint code, jobject dataObj, jobject replyObj, jint flags) @@ -786,9 +870,20 @@ static jboolean android_os_BinderProxy_transact(JNIEnv* env, jobject obj, LOGV("Java code calling transact on %p in Java object %p with code %d\n", target, obj, code); + + // Only log the binder call duration for things on the Java-level main thread. + const bool is_main_thread = (getpid() == gettid()); + int64_t start_millis; + if (is_main_thread) { + start_millis = uptimeMillis(); + } //printf("Transact from Java code to %p sending: ", target); data->print(); status_t err = target->transact(code, *data, reply, flags); //if (reply) printf("Transact from Java code to %p received: ", target); reply->print(); + if (is_main_thread) { + conditionally_log_binder_call(start_millis, target, code); + } + if (err == NO_ERROR) { return JNI_TRUE; } else if (err == UNKNOWN_TRANSACTION) { |