Fix scoped marker so begin/end ATP timestamps correct

Change-Id: Ic944d3fc00d7bc31b756c0e6c327b99eb489537e

src/hip_hcc.cpp

@@ -196,7 +196,7 @@ thread_local ShortTid tls_shortTid;
 //=================================================================================================
 // Top-level "free" functions:
 //=================================================================================================
-void recordApiTrace(const std::string &s)
+void recordApiTrace(std::string *fullStr, const std::string &apiStr)
 {
     auto apiSeqNum = tls_shortTid.incApiSeqNum();
     auto tid = tls_shortTid.tid();
@@ -212,11 +212,16 @@ void recordApiTrace(const std::string &s)
         g_dbStopTriggers.pop_back();
     };
 
+    fullStr->reserve(16 + apiStr.length());
+    *fullStr = std::to_string(tid) + ".";
+    *fullStr += std::to_string(apiSeqNum);
+    *fullStr += " ";
+    *fullStr += apiStr;
+
 
     if (COMPILE_HIP_DB && HIP_TRACE_API) {
-        fprintf (stderr, "%s<<hip-api tid:%d.%lu %s\n%s" , API_COLOR, tid, apiSeqNum, s.c_str(), API_COLOR_END);
+        fprintf (stderr, "%s<<hip-api tid:%s%s\n" , API_COLOR, fullStr->c_str(), API_COLOR_END);
     }
-    SCOPED_MARKER(s.c_str(), "HIP", NULL);
 }
 
 
@@ -1332,15 +1337,15 @@ void ihipInit()
 
     // Some flags have both compile-time and runtime flags - generate a warning if user enables the runtime flag but the compile-time flag is disabled.
     if (HIP_DB && !COMPILE_HIP_DB) {
-        fprintf (stderr, "warning: env var HIP_DB=0x%x but COMPILE_HIP_DB=0.  (perhaps enable COMPILE_HIP_DB in src code before compiling?)", HIP_DB);
+        fprintf (stderr, "warning: env var HIP_DB=0x%x but COMPILE_HIP_DB=0.  (perhaps enable COMPILE_HIP_DB in src code before compiling?)\n", HIP_DB);
     }
 
     if (HIP_TRACE_API && !COMPILE_HIP_TRACE_API) {
-        fprintf (stderr, "warning: env var HIP_TRACE_API=0x%x but COMPILE_HIP_TRACE_API=0.  (perhaps enable COMPILE_HIP_TRACE_API in src code before compiling?)", HIP_DB);
+        fprintf (stderr, "warning: env var HIP_TRACE_API=0x%x but COMPILE_HIP_TRACE_API=0.  (perhaps enable COMPILE_HIP_TRACE_API in src code before compiling?)\n", HIP_DB);
     }
 
     if (HIP_PROFILE_API && !COMPILE_HIP_ATP_MARKER) {
-        fprintf (stderr, "warning: env var HIP_PROFILE_API=0x%x but COMPILE_HIP_ATP_MARKER=0.  (perhaps enable COMPILE_HIP_ATP_MARKER in src code before compiling?)", HIP_PROFILE_API);
+        fprintf (stderr, "warning: env var HIP_PROFILE_API=0x%x but COMPILE_HIP_ATP_MARKER=0.  (perhaps enable COMPILE_HIP_ATP_MARKER in src code before compiling?)\n", HIP_PROFILE_API);
     }
 
     if (HIP_DB) {
@@ -1459,19 +1464,21 @@ hipStream_t ihipSyncAndResolveStream(hipStream_t stream)
 void ihipPrintKernelLaunch(const char *kernelName, const grid_launch_parm *lp, const hipStream_t stream)
 {
     if (HIP_PROFILE_API || (COMPILE_HIP_DB && HIP_TRACE_API)) {
+        std::stringstream os_pre;
         std::stringstream os;
-        os  << "<<hip-api tid:" << tls_shortTid.tid() << "." << tls_shortTid.incApiSeqNum()
+        os_pre  << "<<hip-api tid:";
+        os  << tls_shortTid.tid() << "." << tls_shortTid.incApiSeqNum()
             << " hipLaunchKernel '" << kernelName << "'"
             << " gridDim:"  << lp->grid_dim
             << " groupDim:" << lp->group_dim
             << " sharedMem:+" << lp->dynamic_group_mem_bytes
             << " " << *stream;
 
+        MARKER_BEGIN(os.str().c_str(), "HIP");
 
         if (COMPILE_HIP_DB && HIP_TRACE_API) {
             std::cerr << API_COLOR << os.str() << API_COLOR_END << std::endl;
         }
-        SCOPED_MARKER(os.str().c_str(), "HIP", NULL);
     }
 }
 
@@ -1572,6 +1579,7 @@ void ihipPostLaunchKernel(hipStream_t stream, grid_launch_parm &lp)
     tprintf(DB_SYNC, "ihipPostLaunchKernel, unlocking stream\n");
 
     stream->lockclose_postKernelCommand(lp.av);
+    MARKER_END();
 }
 
 

src/hip_hcc.h

@@ -160,24 +160,29 @@ extern const char *API_COLOR_END;
 // through ptr-to-args (ie the pointers allocated by hipMalloc).
 #if COMPILE_HIP_ATP_MARKER
 #include "CXLActivityLogger.h"
-#define SCOPED_MARKER(markerName,group,userString) amdtScopedMarker(markerName, group, userString)
+#define MARKER_BEGIN(markerName,group) amdtBeginMarker(markerName, group, nullptr);
+#define MARKER_END() amdtEndMarker();
 #define RESUME_PROFILING amdtResumeProfiling(AMDT_ALL_PROFILING);
 #define STOP_PROFILING   amdtStopProfiling(AMDT_ALL_PROFILING);
 #else
 // Swallow scoped markers:
-#define SCOPED_MARKER(markerName,group,userString)
+#define MARKER_BEGIN(markerName,group)
+#define MARKER_END()
 #define RESUME_PROFILING 
 #define STOP_PROFILING   
 #endif
 
 
-extern void recordApiTrace(const std::string &s);
+extern void recordApiTrace(std::string *fullStr, const std::string &apiStr);
 
 #if COMPILE_HIP_ATP_MARKER || (COMPILE_HIP_TRACE_API & 0x1)
 #define API_TRACE(...)\
 {\
     if (HIP_PROFILE_API || (COMPILE_HIP_DB && HIP_TRACE_API)) {\
-        recordApiTrace(std::string(__func__) + " (" + ToString(__VA_ARGS__) + ')');\
+        std::string apiStr = std::string(__func__) + " (" + ToString(__VA_ARGS__) + ')';\
+        std::string fullStr;\
+        recordApiTrace(&fullStr, apiStr);\
+        MARKER_BEGIN(fullStr.c_str(), "HIP");\
     }\
 }
 #else
@@ -207,6 +212,7 @@ extern void recordApiTrace(const std::string &s);
         if ((COMPILE_HIP_TRACE_API & 0x2) && HIP_TRACE_API) {\
             fprintf(stderr, "  %ship-api tid:%d.%lu %-30s ret=%2d (%s)>>%s\n", (localHipStatus == 0) ? API_COLOR:KRED, tls_shortTid.tid(),tls_shortTid.apiSeqNum(),  __func__, localHipStatus, ihipErrorString(localHipStatus), API_COLOR_END);\
         }\
+        if (HIP_PROFILE_API) { MARKER_END(); }\
         localHipStatus;\
     })