Allow stopping and restarting profiler. Ignore empty queue error code…

… from W3DN_Submit

gui.c

@@ -16,17 +16,22 @@
 
 enum EObject {
     OID_Window,
-    OID_ControlLayout,
+    OID_TracingLayout,
     OID_Trace,
     OID_Pause,
+    OID_ProfilingLayout,
+    OID_StartProfiling,
+    OID_FinishProfiling,
     OID_Ogles2Errors,
     OID_NovaErrors,
     OID_Count // KEEP LAST
 };
 
 enum EGadget {
     GID_Trace,
-    GID_Pause
+    GID_Pause,
+    GID_StartProfiling,
+    GID_FinishProfiling
 };
 
 static Object* objects[OID_Count];
@@ -50,10 +55,11 @@ static Object* create_gui(LONG profiling)
         WINDOW_AppPort, port, // Iconification needs it
         WINDOW_Layout, IIntuition->NewObject(NULL, "layout.gadget",
             LAYOUT_Orientation, LAYOUT_ORIENT_VERT,
-            LAYOUT_Label, "Control",
-            LAYOUT_BevelStyle, BVS_GROUP,
-            LAYOUT_AddChild, objects[OID_ControlLayout] = IIntuition->NewObject(NULL, "layout.gadget",
+
+            LAYOUT_AddChild, objects[OID_TracingLayout] = IIntuition->NewObject(NULL, "layout.gadget",
                 LAYOUT_Orientation, LAYOUT_ORIENT_HORIZ,
+                LAYOUT_Label, "Tracing",
+                LAYOUT_BevelStyle, BVS_GROUP,
                 LAYOUT_AddChild, objects[OID_Trace] = IIntuition->NewObject(NULL, "button.gadget",
                     GA_Text, "Trace",
                     GA_ID, GID_Trace,
@@ -67,6 +73,25 @@ static Object* create_gui(LONG profiling)
                     GA_Disabled, profiling ? TRUE : FALSE,
                     TAG_DONE),
                 TAG_DONE), // horizontal layout.gadget
+
+            LAYOUT_AddChild, objects[OID_ProfilingLayout] = IIntuition->NewObject(NULL, "layout.gadget",
+                LAYOUT_Orientation, LAYOUT_ORIENT_HORIZ,
+                LAYOUT_Label, "Profiling",
+                LAYOUT_BevelStyle, BVS_GROUP,
+                LAYOUT_AddChild, objects[OID_StartProfiling] = IIntuition->NewObject(NULL, "button.gadget",
+                    GA_Text, "Start",
+                    GA_ID, GID_StartProfiling,
+                    GA_RelVerify, TRUE,
+                    GA_Disabled, TRUE,
+                    TAG_DONE),
+                LAYOUT_AddChild, objects[OID_FinishProfiling] = IIntuition->NewObject(NULL, "button.gadget",
+                    GA_Text, "Finish",
+                    GA_ID, GID_FinishProfiling,
+                    GA_RelVerify, TRUE,
+                    GA_Disabled, FALSE,
+                    TAG_DONE),
+                TAG_DONE), // horizontal layout.gadget
+
             LAYOUT_AddChild, IIntuition->NewObject(NULL, "layout.gadget",
                 LAYOUT_Orientation, LAYOUT_ORIENT_VERT,
                 LAYOUT_Label, "Information",
@@ -92,6 +117,7 @@ static Object* create_gui(LONG profiling)
                     BUTTON_BevelStyle, BVS_NONE,
                     TAG_DONE),
                 TAG_DONE), // vertical layout.gadget
+
             TAG_DONE), // vertical layout.gadget
         TAG_DONE); // window.class
 }
@@ -101,9 +127,14 @@ static void refresh_object(Object * object)
     IIntuition->RefreshGList((struct Gadget *)object, window, NULL, -1);
 }
 
-static void refresh_buttons(void)
+static void refresh_tracing_buttons(void)
+{
+    refresh_object(objects[OID_TracingLayout]);
+}
+
+static void refresh_profiling_buttons(void)
 {
-    refresh_object(objects[OID_ControlLayout]);
+    refresh_object(objects[OID_ProfilingLayout]);
 }
 
 static void refresh_errors(void)
@@ -115,34 +146,62 @@ static void refresh_errors(void)
     refresh_object(objects[OID_NovaErrors]);
 }
 
-static void on_trace(void)
+static void trace(void)
 {
     IIntuition->SetAttrs(objects[OID_Trace], GA_Disabled, TRUE, TAG_DONE);
     IIntuition->SetAttrs(objects[OID_Pause], GA_Disabled, FALSE, TAG_DONE);
 
-    refresh_buttons();
+    refresh_tracing_buttons();
     resume_log();
 }
 
-static void on_pause()
+static void pause(void)
 {
     IIntuition->SetAttrs(objects[OID_Trace], GA_Disabled, FALSE, TAG_DONE);
     IIntuition->SetAttrs(objects[OID_Pause], GA_Disabled, TRUE, TAG_DONE);
 
-    refresh_buttons();
+    refresh_tracing_buttons();
     pause_log();
 }
 
+static void start_profiling(void)
+{
+    IIntuition->SetAttrs(objects[OID_StartProfiling], GA_Disabled, TRUE, TAG_DONE);
+    IIntuition->SetAttrs(objects[OID_FinishProfiling], GA_Disabled, FALSE, TAG_DONE);
+
+    refresh_profiling_buttons();
+
+    ogles2_start_profiling();
+    warp3dnova_start_profiling();
+}
+
+static void finish_profiling(void)
+{
+    IIntuition->SetAttrs(objects[OID_StartProfiling], GA_Disabled, FALSE, TAG_DONE);
+    IIntuition->SetAttrs(objects[OID_FinishProfiling], GA_Disabled, TRUE, TAG_DONE);
+
+    refresh_profiling_buttons();
+
+    warp3dnova_finish_profiling();
+    ogles2_finish_profiling();
+}
+
 static void handle_gadgets(int id)
 {
     //printf("Gadget %d\n", id);
 
     switch (id) {
         case GID_Trace:
-            on_trace();
+            trace();
             break;
         case GID_Pause:
-            on_pause();
+            pause();
+            break;
+        case GID_StartProfiling:
+            start_profiling();
+            break;
+        case GID_FinishProfiling:
+            finish_profiling();
             break;
     }
 }

logger.c

@@ -7,25 +7,39 @@
 
 static BOOL paused = FALSE;
 
+static void logLineImpl(const char * fmt, va_list ap)
+{
+    char buffer[16 * 1024];
+    const int len = vsnprintf(buffer, sizeof(buffer), fmt, ap);
+
+    IExec->DebugPrintF("%s\n", buffer);
+
+    if (len >= (int)sizeof(buffer)) {
+        IExec->DebugPrintF("*** Line truncated: %d bytes buffer needed ***\n", len);
+    }
+
+}
+
 void logLine(const char * fmt, ...)
 {
     if (!paused) {
-        char buffer[16 * 1024];
-        int len;
-
         va_list ap;
         va_start(ap, fmt);
 
-        len = vsnprintf(buffer, sizeof(buffer), fmt, ap);
+        logLineImpl(fmt, ap);
 
         va_end(ap);
+    }
+}
 
-        IExec->DebugPrintF("%s\n", buffer);
+void logAlways(const char * fmt, ...)
+{
+    va_list ap;
+    va_start(ap, fmt);
 
-        if (len >= (int)sizeof(buffer)) {
-            IExec->DebugPrintF("*** Line truncated: %d bytes buffer needed ***\n", len);
-        }
-    }
+    logLineImpl(fmt, ap);
+
+    va_end(ap);
 }
 
 void pause_log(void)

logger.h

@@ -2,6 +2,7 @@
 #define LOGGER_H
 
 void logLine(const char * fmt, ...) __attribute__ ((format (printf, 1, 2)));
+void logAlways(const char * fmt, ...) __attribute__ ((format (printf, 1, 2)));
 
 void pause_log(void);
 void resume_log(void);

ogles2_module.c

@@ -179,7 +179,6 @@ static void find_process_name(struct Ogles2Context * context)
 }
 
 static char versionBuffer[64] = "ogles2.library version unknown";
-static char errorBuffer[32];
 
 static BOOL open_ogles2_library(void)
 {
@@ -202,6 +201,8 @@ const char* ogles2_version_string(void)
 
 const char* ogles2_errors_string(void)
 {
+    static char errorBuffer[32];
+
     snprintf(errorBuffer, sizeof(errorBuffer), "OpenGL ES 2 errors: %u", errorCount);
     return errorBuffer;
 }
@@ -224,26 +225,26 @@ static void profileResults(struct Ogles2Context* const context)
     PROF_FINISH_CONTEXT
 
     const double drawcalls = context->profiling[DrawElements].callCount + context->profiling[DrawArrays].callCount;
-    const double swaps = context->profiling[SwapBuffers].callCount;
+    const uint64 swaps = context->profiling[SwapBuffers].callCount;
 
     sort(context);
 
-    resume_log();
-
-    logLine("OpenGL ES 2.0 profiling results for %s:", context->name);
-    logLine("--------------------------------------------------------");
+    logAlways("\nOpenGL ES 2.0 profiling results for %s:", context->name);
 
     PROF_PRINT_TOTAL
 
-    logLine("Draw calls (glDraw*) per frame %.6f. Draw calls per second %.6f", drawcalls / swaps, drawcalls / seconds);
-    logLine("Frames (buffer swaps) per second %.6f", swaps / seconds);
+    if (swaps > 0) {
+        logAlways("  Draw calls (glDraw*) per frame %.6f. Draw calls per second %.6f", drawcalls / swaps, drawcalls / seconds);
+    }
+
+    logAlways("  Frames (buffer swaps) per second %.6f", swaps / seconds);
 
-    logLine("%30s | %10s | %10s | %20s | %20s | %30s",
-        "function", "call count", "errors", "duration (ms)", "% of combined time", "% of CPU time (incl. driver)");
+    logAlways("%30s | %10s | %10s | %20s | %30s | %30s",
+        "function", "call count", "errors", "duration (ms)", timeUsedBuffer, "% of CPU time (incl. driver)");
 
     for (int i = 0; i < Ogles2FunctionCount; i++) {
         if (context->profiling[i].callCount > 0) {
-            logLine("%30s | %10llu | %10llu | %20.6f | %20.2f | %30.2f",
+            logAlways("%30s | %10llu | %10llu | %20.6f | %30.2f | %30.2f",
                 mapOgles2Function(context->profiling[i].index),
                 context->profiling[i].callCount,
                 context->profiling[i].errors,
@@ -254,8 +255,41 @@ static void profileResults(struct Ogles2Context* const context)
     }
 
     primitiveStats(&context->counter, seconds, drawcalls);
+}
+
+void ogles2_start_profiling(void)
+{
+    logAlways("OGLES2 profiler context started by user");
 
-    logLine("--------------------------------------------------------");
+    if (mutex) {
+        IExec->MutexObtain(mutex);
+
+        for (size_t c = 0; c < MAX_CLIENTS; c++) {
+            if (contexts[c]) {
+                // TODO: concurrency issues?
+                PROF_INIT(contexts[c], Ogles2FunctionCount)
+            }
+        }
+
+        IExec->MutexRelease(mutex);
+    }
+}
+
+void ogles2_finish_profiling(void)
+{
+    logAlways("OGLES2 profiler context finished by user");
+
+    if (mutex) {
+        IExec->MutexObtain(mutex);
+
+        for (size_t c = 0; c < MAX_CLIENTS; c++) {
+            if (contexts[c]) {
+                profileResults(contexts[c]);
+            }
+        }
+
+        IExec->MutexRelease(mutex);
+    }
 }
 
 // We patch IExec->GetInterface to be able to patch later IOGLES2 interface.

ogles2_module.h

@@ -8,4 +8,7 @@ void ogles2_free(void);
 const char* ogles2_version_string(void);
 const char* ogles2_errors_string(void);
 
+void ogles2_start_profiling(void);
+void ogles2_finish_profiling(void);
+
 #endif

profiling.c

@@ -14,45 +14,50 @@ int tickComparison(const void* first, const void* second)
 
 void primitiveStats(const PrimitiveCounter* const counter, const double seconds, const double drawcalls)
 {
-    logLine("Primitive statistics (in vertices):");
+    logAlways("  Primitive statistics:");
 
     const uint64 total = counter->triangles + counter->triangleStrips + counter->triangleFans +
         counter->lines + counter->lineStrips + counter->lineLoops + counter->points;
 
-    logLine("  Total vertices %llu, per second %.6f, per draw call %.6f", total, total / seconds, total / drawcalls);
+    if (total == 0) {
+        logAlways("    Nothing was drawn, vertex count 0");
+        return;
+    }
+
+    logAlways("    Total vertices %llu, per second %.6f, per draw call %.6f, consisting of:", total, total / seconds, total / drawcalls);
 
     if (counter->triangles) {
-        logLine("  Triangles %llu, per second %.6f, per draw call %.6f", counter->triangles,
+        logAlways("    - Triangles %llu, per second %.6f, per draw call %.6f", counter->triangles,
             counter->triangles / seconds, counter->triangles / drawcalls);
     }
 
     if (counter->triangleStrips) {
-        logLine("  Triangle strips %llu, per second %.6f, per draw call %.6f", counter->triangleStrips,
+        logAlways("    - Triangle strips %llu, per second %.6f, per draw call %.6f", counter->triangleStrips,
             counter->triangleStrips / seconds, counter->triangleStrips / drawcalls);
     }
 
     if (counter->triangleFans) {
-        logLine("  Triangle fans %llu, per second %.6f, per draw call %.6f", counter->triangleFans,
+        logAlways("    - Triangle fans %llu, per second %.6f, per draw call %.6f", counter->triangleFans,
             counter->triangleFans / seconds, counter->triangleFans / drawcalls);
     }
 
     if (counter->lines) {
-        logLine("  Lines %llu, per second %.6f, per draw call %.6f", counter->lines,
+        logAlways("    - Lines %llu, per second %.6f, per draw call %.6f", counter->lines,
             counter->lines / seconds, counter->lines / drawcalls);
     }
 
     if (counter->lineStrips) {
-        logLine("  Line strips %llu, per second %.6f, per draw call %.6f", counter->lineStrips,
+        logAlways("    - Line strips %llu, per second %.6f, per draw call %.6f", counter->lineStrips,
             counter->lineStrips / seconds, counter->lineStrips / drawcalls);
     }
 
     if (counter->lineLoops) {
-        logLine("  Line loops %llu, per second %.6f, per draw call %.6f", counter->lineLoops,
+        logAlways("    - Line loops %llu, per second %.6f, per draw call %.6f", counter->lineLoops,
             counter->lineLoops / seconds, counter->lineLoops / drawcalls);
     }
 
     if (counter->points) {
-        logLine("  Points %llu, per second %.6f, per draw call %.6f", counter->points,
+        logAlways("    - Points %llu, per second %.6f, per draw call %.6f", counter->points,
             counter->points / seconds, counter->points / drawcalls);
     }
 }