Improve logging around performance critical events

bug:17702227

Add details useful to developers (such as layer size/View name), and
switch away from logging implementation names/details, since they
are generally not relevant to developers.

Change-Id: Iee605d182f241450f7e75a6d0c283d51fa1312f5
diff --git a/libs/hwui/Layer.cpp b/libs/hwui/Layer.cpp
index b95636b..9aa29ca 100644
--- a/libs/hwui/Layer.cpp
+++ b/libs/hwui/Layer.cpp
@@ -20,11 +20,18 @@
 
 #include "Caches.h"
 #include "DeferredDisplayList.h"
-#include "RenderState.h"
 #include "Layer.h"
 #include "LayerRenderer.h"
 #include "OpenGLRenderer.h"
 #include "RenderNode.h"
+#include "RenderState.h"
+#include "utils/TraceUtils.h"
+
+#define ATRACE_LAYER_WORK(label) \
+    ATRACE_FORMAT("%s HW Layer DisplayList %s %ux%u", \
+            label, \
+            (renderNode.get() != NULL) ? renderNode->getName() : "", \
+            getWidth(), getHeight())
 
 namespace android {
 namespace uirenderer {
@@ -223,6 +230,8 @@
 }
 
 void Layer::defer(const OpenGLRenderer& rootRenderer) {
+    ATRACE_LAYER_WORK("Optimize");
+
     updateLightPosFromRenderer(rootRenderer);
     const float width = layer.getWidth();
     const float height = layer.getHeight();
@@ -260,6 +269,9 @@
 void Layer::flush() {
     // renderer is checked as layer may be destroyed/put in layer cache with flush scheduled
     if (deferredList && renderer) {
+        ATRACE_LAYER_WORK("Issue");
+        renderer->startMark((renderNode.get() != NULL) ? renderNode->getName() : "Layer");
+
         renderer->setViewport(layer.getWidth(), layer.getHeight());
         renderer->prepareDirty(dirtyRect.left, dirtyRect.top, dirtyRect.right, dirtyRect.bottom,
                 !isBlend());
@@ -270,10 +282,14 @@
 
         dirtyRect.setEmpty();
         renderNode = NULL;
+
+        renderer->endMark();
     }
 }
 
 void Layer::render(const OpenGLRenderer& rootRenderer) {
+    ATRACE_LAYER_WORK("Direct-Issue");
+
     updateLightPosFromRenderer(rootRenderer);
     renderer->setViewport(layer.getWidth(), layer.getHeight());
     renderer->prepareDirty(dirtyRect.left, dirtyRect.top, dirtyRect.right, dirtyRect.bottom,
diff --git a/libs/hwui/LayerRenderer.cpp b/libs/hwui/LayerRenderer.cpp
index 394c647..83f9c6a 100644
--- a/libs/hwui/LayerRenderer.cpp
+++ b/libs/hwui/LayerRenderer.cpp
@@ -27,6 +27,7 @@
 #include "Matrix.h"
 #include "Properties.h"
 #include "Rect.h"
+#include "utils/TraceUtils.h"
 
 namespace android {
 namespace uirenderer {
@@ -185,7 +186,7 @@
 ///////////////////////////////////////////////////////////////////////////////
 
 Layer* LayerRenderer::createRenderLayer(RenderState& renderState, uint32_t width, uint32_t height) {
-    ATRACE_CALL();
+    ATRACE_FORMAT("Allocate %ux%u HW Layer", width, height);
     LAYER_RENDERER_LOGD("Requesting new render layer %dx%d", width, height);
 
     Caches& caches = Caches::getInstance();
@@ -310,7 +311,7 @@
 
 void LayerRenderer::destroyLayer(Layer* layer) {
     if (layer) {
-        ATRACE_CALL();
+        ATRACE_FORMAT("Destroy %ux%u HW Layer", layer->getWidth(), layer->getHeight());
         LAYER_RENDERER_LOGD("Recycling layer, %dx%d fbo = %d",
                 layer->getWidth(), layer->getHeight(), layer->getFbo());
 
diff --git a/libs/hwui/OpenGLRenderer.cpp b/libs/hwui/OpenGLRenderer.cpp
index d570b0d..80b4c2a 100755
--- a/libs/hwui/OpenGLRenderer.cpp
+++ b/libs/hwui/OpenGLRenderer.cpp
@@ -42,6 +42,7 @@
 #include "ShadowTessellator.h"
 #include "SkiaShader.h"
 #include "utils/GLUtils.h"
+#include "utils/TraceUtils.h"
 #include "Vector.h"
 #include "VertexBuffer.h"
 
@@ -51,21 +52,6 @@
     #define EVENT_LOGD(...)
 #endif
 
-static void atraceFormatBegin(const char* fmt, ...) {
-    const int BUFFER_SIZE = 256;
-    va_list ap;
-    char buf[BUFFER_SIZE];
-
-    va_start(ap, fmt);
-    vsnprintf(buf, BUFFER_SIZE, fmt, ap);
-    va_end(ap);
-
-    ATRACE_BEGIN(buf);
-}
-
-#define ATRACE_FORMAT_BEGIN(fmt, ...) \
-    if (CC_UNLIKELY(ATRACE_ENABLED())) atraceFormatBegin(fmt, ##__VA_ARGS__)
-
 namespace android {
 namespace uirenderer {
 
@@ -466,8 +452,6 @@
 bool OpenGLRenderer::updateLayer(Layer* layer, bool inFrame) {
     if (layer->deferredUpdateScheduled && layer->renderer
             && layer->renderNode.get() && layer->renderNode->isRenderable()) {
-        ATRACE_CALL();
-
         Rect& dirty = layer->dirtyRect;
 
         if (inFrame) {
@@ -525,20 +509,10 @@
     int count = mLayerUpdates.size();
     if (count > 0) {
         startMark("Apply Layer Updates");
-        char layerName[12];
 
         // Note: it is very important to update the layers in order
         for (int i = 0; i < count; i++) {
-            Layer* layer = mLayerUpdates.itemAt(i).get();
-
-            sprintf(layerName, "Layer #%d", i);
-            startMark(layerName);
-            ATRACE_FORMAT_BEGIN("flushLayer %ux%u", layer->getWidth(), layer->getHeight());
-
-            layer->flush();
-
-            ATRACE_END();
-            endMark();
+            mLayerUpdates.itemAt(i)->flush();
         }
 
         mLayerUpdates.clear();
@@ -575,7 +549,7 @@
 }
 
 void OpenGLRenderer::flushLayerUpdates() {
-    ATRACE_CALL();
+    ATRACE_NAME("Update HW Layers");
     syncState();
     updateLayers();
     flushLayers();
diff --git a/libs/hwui/PathCache.cpp b/libs/hwui/PathCache.cpp
index 9ba8854..6f48e4d 100644
--- a/libs/hwui/PathCache.cpp
+++ b/libs/hwui/PathCache.cpp
@@ -255,7 +255,7 @@
 
 PathTexture* PathCache::addTexture(const PathDescription& entry, const SkPath *path,
         const SkPaint* paint) {
-    ATRACE_CALL();
+    ATRACE_NAME("Generate Path Texture");
 
     float left, top, offset;
     uint32_t width, height;
diff --git a/libs/hwui/Program.cpp b/libs/hwui/Program.cpp
index 0dad0dc..e6fd2dc 100644
--- a/libs/hwui/Program.cpp
+++ b/libs/hwui/Program.cpp
@@ -132,7 +132,7 @@
 }
 
 GLuint Program::buildShader(const char* source, GLenum type) {
-    ATRACE_CALL();
+    ATRACE_NAME("Build GL Shader");
 
     GLuint shader = glCreateShader(type);
     glShaderSource(shader, 1, &source, 0);
diff --git a/libs/hwui/RenderNode.cpp b/libs/hwui/RenderNode.cpp
index 13c5499..eb0948f 100644
--- a/libs/hwui/RenderNode.cpp
+++ b/libs/hwui/RenderNode.cpp
@@ -25,7 +25,6 @@
 #include <SkCanvas.h>
 #include <algorithm>
 
-#include <utils/Trace.h>
 
 #include "DamageAccumulator.h"
 #include "Debug.h"
@@ -34,6 +33,7 @@
 #include "LayerRenderer.h"
 #include "OpenGLRenderer.h"
 #include "utils/MathUtils.h"
+#include "utils/TraceUtils.h"
 #include "renderthread/CanvasContext.h"
 
 namespace android {
@@ -426,6 +426,10 @@
                 clipFlags = 0; // all clipping done by saveLayer
             }
 
+            ATRACE_FORMAT("%s alpha caused %ssaveLayer %ux%u",
+                    getName(), clipFlags ? "" : "unclipped ",
+                    layerBounds.getWidth(), layerBounds.getHeight());
+
             SaveLayerOp* op = new (handler.allocator()) SaveLayerOp(
                     layerBounds.left, layerBounds.top, layerBounds.right, layerBounds.bottom,
                     properties().getAlpha() * 255, saveFlags);
diff --git a/libs/hwui/TextureCache.cpp b/libs/hwui/TextureCache.cpp
index 3b8a9a4..5fcb194 100644
--- a/libs/hwui/TextureCache.cpp
+++ b/libs/hwui/TextureCache.cpp
@@ -26,6 +26,7 @@
 #include "Caches.h"
 #include "TextureCache.h"
 #include "Properties.h"
+#include "utils/TraceUtils.h"
 
 namespace android {
 namespace uirenderer {
@@ -266,7 +267,7 @@
         return;
     }
 
-    ATRACE_CALL();
+    ATRACE_FORMAT("Upload %ux%u Texture", bitmap->width(), bitmap->height());
 
     // We could also enable mipmapping if both bitmap dimensions are powers
     // of 2 but we'd have to deal with size changes. Let's keep this simple
diff --git a/libs/hwui/font/Font.cpp b/libs/hwui/font/Font.cpp
index ba878bac..af39f16 100644
--- a/libs/hwui/font/Font.cpp
+++ b/libs/hwui/font/Font.cpp
@@ -363,7 +363,7 @@
 }
 
 void Font::precache(const SkPaint* paint, const char* text, int numGlyphs) {
-    ATRACE_NAME("precacheText");
+    ATRACE_NAME("Precache Glyphs");
 
     if (numGlyphs == 0 || text == NULL) {
         return;
diff --git a/libs/hwui/utils/TraceUtils.h b/libs/hwui/utils/TraceUtils.h
new file mode 100644
index 0000000..ff8ccb8
--- /dev/null
+++ b/libs/hwui/utils/TraceUtils.h
@@ -0,0 +1,56 @@
+/*
+ * Copyright (C) 2014 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.
+ */
+#ifndef TRACE_UTILS_H
+#define TRACE_UTILS_H
+
+#include <utils/Trace.h>
+
+#define ATRACE_FORMAT(fmt, ...) \
+    TraceUtils::TraceEnder __traceEnder = (TraceUtils::atraceFormatBegin(fmt, ##__VA_ARGS__), TraceUtils::TraceEnder())
+
+#define ATRACE_FORMAT_BEGIN(fmt, ...) \
+    TraceUtils::atraceFormatBegin(fmt, ##__VA_ARGS__)
+
+namespace android {
+namespace uirenderer {
+
+class TraceUtils {
+public:
+    class TraceEnder {
+    public:
+        ~TraceEnder() { ATRACE_END(); }
+    };
+
+    static void atraceFormatBegin(const char* fmt, ...) {
+        if (CC_UNLIKELY(!ATRACE_ENABLED())) return;
+
+        const int BUFFER_SIZE = 256;
+        va_list ap;
+        char buf[BUFFER_SIZE];
+
+        va_start(ap, fmt);
+        vsnprintf(buf, BUFFER_SIZE, fmt, ap);
+        va_end(ap);
+
+        ATRACE_BEGIN(buf);
+    }
+
+}; // class TraceUtils
+
+} /* namespace uirenderer */
+} /* namespace android */
+
+#endif /* TRACE_UTILS_H */