From 04262e9f842edf20168399b6a70f0d67e518fe69 Mon Sep 17 00:00:00 2001 From: Mathias Agopian Date: Mon, 13 Sep 2010 22:57:58 -0700 Subject: Add logging of various important graphics events There are 16 events logged in the event log: SF_APP_DEQUEUE_BEFORE SF_APP_DEQUEUE_AFTER SF_APP_LOCK_BEFORE SF_APP_LOCK_AFTER SF_APP_QUEUE SF_REPAINT SF_COMPOSITION_COMPLETE SF_UNLOCK_CLIENTS SF_SWAP_BUFFERS SF_REPAINT_DONE SF_FB_POST_BEFORE SF_FB_POST_AFTER SF_FB_DEQUEUE_BEFORE SF_FB_DEQUEUE_AFTER SF_FB_LOCK_BEFORE SF_FB_LOCK_AFTER all events log the buffer conserned and a timestamp in microseconds. by default the logging is not enabled, to turn it on: adb shell service call SurfaceFlinger 1006 i31 1 adb shell setprop debug.graphic_log 1 The effect is immediate in SurfaceFlinger, but applications need to be restarted. Change-Id: Ifc2e31f7aed072d9a7dede20ff2ce59231edbec1 --- libs/surfaceflinger_client/Surface.cpp | 19 +++++++- libs/ui/Android.mk | 1 + libs/ui/FramebufferNativeWindow.cpp | 35 ++++++++++++-- libs/ui/GraphicLog.cpp | 84 ++++++++++++++++++++++++++++++++++ 4 files changed, 135 insertions(+), 4 deletions(-) create mode 100644 libs/ui/GraphicLog.cpp (limited to 'libs') diff --git a/libs/surfaceflinger_client/Surface.cpp b/libs/surfaceflinger_client/Surface.cpp index cb76091..560ea67 100644 --- a/libs/surfaceflinger_client/Surface.cpp +++ b/libs/surfaceflinger_client/Surface.cpp @@ -32,6 +32,7 @@ #include #include #include +#include #include #include @@ -568,7 +569,13 @@ int Surface::dequeueBuffer(android_native_buffer_t** buffer) if (err != NO_ERROR) return err; + GraphicLog& logger(GraphicLog::getInstance()); + logger.log(GraphicLog::SF_APP_DEQUEUE_BEFORE, mIdentity, -1); + ssize_t bufIdx = mSharedBufferClient->dequeue(); + + logger.log(GraphicLog::SF_APP_DEQUEUE_AFTER, mIdentity, bufIdx); + if (bufIdx < 0) { LOGE("error dequeuing a buffer (%s)", strerror(bufIdx)); return bufIdx; @@ -617,13 +624,20 @@ int Surface::lockBuffer(android_native_buffer_t* buffer) return err; int32_t bufIdx = getBufferIndex(GraphicBuffer::getSelf(buffer)); + + GraphicLog& logger(GraphicLog::getInstance()); + logger.log(GraphicLog::SF_APP_LOCK_BEFORE, mIdentity, bufIdx); + err = mSharedBufferClient->lock(bufIdx); + + logger.log(GraphicLog::SF_APP_LOCK_AFTER, mIdentity, bufIdx); + LOGE_IF(err, "error locking buffer %d (%s)", bufIdx, strerror(-err)); return err; } int Surface::queueBuffer(android_native_buffer_t* buffer) -{ +{ status_t err = validate(); if (err != NO_ERROR) return err; @@ -633,6 +647,9 @@ int Surface::queueBuffer(android_native_buffer_t* buffer) } int32_t bufIdx = getBufferIndex(GraphicBuffer::getSelf(buffer)); + + GraphicLog::getInstance().log(GraphicLog::SF_APP_QUEUE, mIdentity, bufIdx); + mSharedBufferClient->setTransform(bufIdx, mNextBufferTransform); mSharedBufferClient->setCrop(bufIdx, mNextBufferCrop); mSharedBufferClient->setDirtyRegion(bufIdx, mDirtyRegion); diff --git a/libs/ui/Android.mk b/libs/ui/Android.mk index 9f49348..c4a09d6 100644 --- a/libs/ui/Android.mk +++ b/libs/ui/Android.mk @@ -9,6 +9,7 @@ LOCAL_SRC_FILES:= \ GraphicBuffer.cpp \ GraphicBufferAllocator.cpp \ GraphicBufferMapper.cpp \ + GraphicLog.cpp \ KeyLayoutMap.cpp \ KeyCharacterMap.cpp \ Input.cpp \ diff --git a/libs/ui/FramebufferNativeWindow.cpp b/libs/ui/FramebufferNativeWindow.cpp index 6f8948d..a36d555 100644 --- a/libs/ui/FramebufferNativeWindow.cpp +++ b/libs/ui/FramebufferNativeWindow.cpp @@ -29,6 +29,7 @@ #include #include +#include #include @@ -174,6 +175,14 @@ int FramebufferNativeWindow::setSwapInterval( return fb->setSwapInterval(fb, interval); } +// only for debugging / logging +int FramebufferNativeWindow::getCurrentBufferIndex() const +{ + Mutex::Autolock _l(mutex); + const int index = mCurrentBufferIndex; + return index; +} + int FramebufferNativeWindow::dequeueBuffer(ANativeWindow* window, android_native_buffer_t** buffer) { @@ -181,18 +190,24 @@ int FramebufferNativeWindow::dequeueBuffer(ANativeWindow* window, Mutex::Autolock _l(self->mutex); framebuffer_device_t* fb = self->fbDev; + int index = self->mBufferHead++; + if (self->mBufferHead >= self->mNumBuffers) + self->mBufferHead = 0; + + GraphicLog& logger(GraphicLog::getInstance()); + logger.log(GraphicLog::SF_FB_DEQUEUE_BEFORE, index); + // wait for a free buffer while (!self->mNumFreeBuffers) { self->mCondition.wait(self->mutex); } // get this buffer self->mNumFreeBuffers--; - int index = self->mBufferHead++; - if (self->mBufferHead >= self->mNumBuffers) - self->mBufferHead = 0; + self->mCurrentBufferIndex = index; *buffer = self->buffers[index].get(); + logger.log(GraphicLog::SF_FB_DEQUEUE_AFTER, index); return 0; } @@ -202,11 +217,17 @@ int FramebufferNativeWindow::lockBuffer(ANativeWindow* window, FramebufferNativeWindow* self = getSelf(window); Mutex::Autolock _l(self->mutex); + const int index = self->mCurrentBufferIndex; + GraphicLog& logger(GraphicLog::getInstance()); + logger.log(GraphicLog::SF_FB_LOCK_BEFORE, index); + // wait that the buffer we're locking is not front anymore while (self->front == buffer) { self->mCondition.wait(self->mutex); } + logger.log(GraphicLog::SF_FB_LOCK_AFTER, index); + return NO_ERROR; } @@ -217,7 +238,15 @@ int FramebufferNativeWindow::queueBuffer(ANativeWindow* window, Mutex::Autolock _l(self->mutex); framebuffer_device_t* fb = self->fbDev; buffer_handle_t handle = static_cast(buffer)->handle; + + const int index = self->mCurrentBufferIndex; + GraphicLog& logger(GraphicLog::getInstance()); + logger.log(GraphicLog::SF_FB_POST_BEFORE, index); + int res = fb->post(fb, handle); + + logger.log(GraphicLog::SF_FB_POST_AFTER, index); + self->front = static_cast(buffer); self->mNumFreeBuffers++; self->mCondition.broadcast(); diff --git a/libs/ui/GraphicLog.cpp b/libs/ui/GraphicLog.cpp new file mode 100644 index 0000000..b55ce23 --- /dev/null +++ b/libs/ui/GraphicLog.cpp @@ -0,0 +1,84 @@ +/* + * Copyright (C) 2010 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. + */ + + +#include +#include +#include +#include +#include +#include + +#include + +namespace android { + +ANDROID_SINGLETON_STATIC_INSTANCE(GraphicLog) + +static inline +void writeInt32(uint8_t* base, size_t& pos, int32_t value) { + int32_t v = htole32(value); + base[pos] = EVENT_TYPE_INT; + memcpy(&base[pos+1], &v, sizeof(int32_t)); + pos += 1+sizeof(int32_t); +} + +static inline +void writeInt64(uint8_t* base, size_t& pos, int64_t value) { + int64_t v = htole64(value); + base[pos] = EVENT_TYPE_LONG; + memcpy(&base[pos+1], &v, sizeof(int64_t)); + pos += 1+sizeof(int64_t); +} + +void GraphicLog::logImpl(int32_t tag, int32_t buffer) +{ + uint8_t scratch[2 + 2 + sizeof(int32_t) + sizeof(int64_t)]; + size_t pos = 0; + scratch[pos++] = EVENT_TYPE_LIST; + scratch[pos++] = 2; + writeInt32(scratch, pos, buffer); + writeInt64(scratch, pos, ns2ms( systemTime( SYSTEM_TIME_MONOTONIC ) )); + android_bWriteLog(tag, scratch, sizeof(scratch)); +} + +void GraphicLog::logImpl(int32_t tag, int32_t identity, int32_t buffer) +{ + uint8_t scratch[2 + 3 + sizeof(int32_t) + sizeof(int32_t) + sizeof(int64_t)]; + size_t pos = 0; + scratch[pos++] = EVENT_TYPE_LIST; + scratch[pos++] = 3; + writeInt32(scratch, pos, buffer); + writeInt32(scratch, pos, identity); + writeInt64(scratch, pos, ns2ms( systemTime( SYSTEM_TIME_MONOTONIC ) )); + android_bWriteLog(tag, scratch, sizeof(scratch)); +} + +GraphicLog::GraphicLog() + : mEnabled(0) +{ + char property[PROPERTY_VALUE_MAX]; + if (property_get("debug.graphic_log", property, NULL) > 0) { + mEnabled = atoi(property); + } +} + +void GraphicLog::setEnabled(bool enable) +{ + mEnabled = enable; +} + +} -- cgit v1.1