Added support multiple trace levels & optimization of file size requi…

…rements

Multiple trace levels will allow user to set the nested call levels
up to which the traces to be limited. It will also reduce file size
requirements.

Also optimized auto trace output to reduce file size by removing
thread ID's from individual lines.

AMD Internal: [CPUPL-806]

Change-Id: I28e08a5bdf1b147469d8ce290ff7cde7f74481bd

aocl_dtl/aocldtl.c

@@ -25,7 +25,7 @@
 
 /* By default the trace level will be set to ALL User can configure this 
       parameter at run time using command line argument */
-uint32 gui32TraceLogLevel = AOCL_DTL_LEVEL_ALL;
+uint32 gui32TraceLogLevel = AOCL_DTL_TRACE_LEVEL;
 
 /* The user can configure the file name in which he wants to dump the data */
 #if AOCL_DTL_TRACE_ENABLE
@@ -71,10 +71,15 @@ void DTL_Initialize(
 {
     /* If user selects invalid trace log level then the dafault trace log level 
       will be AOCL_DTL_LEVEL_ALL */
-    if ((ui32CurrentLogLevel < 1) || (ui32CurrentLogLevel > 4))
+    if ((ui32CurrentLogLevel < 1) || (ui32CurrentLogLevel > AOCL_DTL_LEVEL_ALL))
     {
-        ui32CurrentLogLevel = AOCL_DTL_LEVEL_ALL;
+        gui32TraceLogLevel = AOCL_DTL_LEVEL_ALL;
     }
+	else
+	{
+		/* Assign the user requested log level to the global trace log level */
+		gui32TraceLogLevel = ui32CurrentLogLevel;
+	}
 
 #if AOCL_DTL_TRACE_ENABLE
     /* Create/Open the file to log the traced data */
@@ -86,9 +91,6 @@ void DTL_Initialize(
         AOCL_DEBUGPRINT("Unable to create the trace file %s\n", pchDTL_TRACE_FILE);
         return;
     }
-
-    /* Assign the user requested log level to the global trace log level */
-    gui32TraceLogLevel = ui32CurrentLogLevel;
 #endif
 
 #if AOCL_DTL_LOG_ENABLE
@@ -222,27 +224,39 @@ void DTL_Trace(
       level set while initialization */
     if (ui8LogLevel <= gui32TraceLogLevel)
     {
-        /* this loop is for formating the output log file */
-        for (i = 0; i < ui8LogLevel; i++)
-        {
-            /* print tabs in the output file */
-            fprintf(pOutFile, "\t");
-        }
+
+		/* Indent as per level if is function call trace */
+		if ((ui8LogLevel >= AOCL_DTL_LEVEL_TRACE_1) &&
+			(ui8LogLevel <= AOCL_DTL_LEVEL_TRACE_8))
+		{
+			fprintf(pOutFile, "%d ", (ui8LogLevel - AOCL_DTL_LEVEL_TRACE_1)+1);
+			/* this loop is for formating the output log file */
+			for (i = 0; i < (ui8LogLevel - AOCL_DTL_LEVEL_TRACE_1); i++)
+			{
+				/* print tabs in the output file */
+				fprintf(pOutFile, "\t");
+			}
+		}
+		else
+		{
+			/* For non call traces we will just start the line with astrix */
+			fprintf(pOutFile, "* \t");
+		}
 
         switch (ui8LogType)
         {
         case TRACE_TYPE_FENTRY:
-            fprintf(pOutFile, "Entering %s()...\n", pi8FunctionName);
+            fprintf(pOutFile, "In %s()...\n", pi8FunctionName);
             break;
 
         case TRACE_TYPE_FEXIT:
             if (pi8Message == NULL)
             { /* Function returned successfully */
-                fprintf(pOutFile, "Returning from %s()\n", pi8FunctionName);
+                fprintf(pOutFile, "Out of %s()\n", pi8FunctionName);
             }
             else
             { /* Function failed to complete, use message to get error */
-                fprintf(pOutFile, "Returning from %s() with error %s\n", pi8FunctionName, pi8Message);
+                fprintf(pOutFile, "Out of %s() with error %s\n", pi8FunctionName, pi8Message);
             }
             break;
 
@@ -430,8 +444,7 @@ void __cyg_profile_func_enter(void *pvThisFunc, void *pvCaller)
         }
     }
 
-    fprintf(pOutFile, "\n%u:%lu:+:%p",
-            AOCL_gettid(),
+    fprintf(pOutFile, "\n%lu:+:%p",
             AOCL_getTimestamp(),
             (void *)(pvThisFunc - info.dli_fbase));
 }
@@ -469,8 +482,7 @@ void __cyg_profile_func_exit(void *pvThisFunc, void *pvCaller)
         }
     }
 
-    fprintf(pOutFile, "\n%u:%lu:-:%p",
-            AOCL_gettid(),
+    fprintf(pOutFile, "\n%lu:-:%p",
             AOCL_getTimestamp(),
             (void *)(pvThisFunc - info.dli_fbase));
 }

aocl_dtl/aocldtlcf.h

@@ -24,9 +24,31 @@
    has to enable this macro by making it to 1 else 0 */
 #define AOCL_DTL_LOG_ENABLE         0
 
-#define AOCL_DTL_TRACE_FILE         "aocldtl_trace.wri"
-#define AOCL_DTL_AUTO_TRACE_FILE    "aocldtl_auto_trace.wri"
-#define AOCL_DTL_LOG_FILE           "aocldtl_log.wri"
+/* Select the trace level till which you want to log the data */
+/* By default it will log for all levels */
+#define AOCL_DTL_TRACE_LEVEL         AOCL_DTL_LEVEL_TRACE_5
+
+/* user has to explicitly use the below macros to identify
+   ciriticality of the logged message */
+#define AOCL_DTL_LEVEL_ALL          (14)
+#define AOCL_DTL_LEVEL_TRACE_8      (13)    
+#define AOCL_DTL_LEVEL_TRACE_7      (12)     /* Kernels */
+#define AOCL_DTL_LEVEL_TRACE_6      (11)
+#define AOCL_DTL_LEVEL_TRACE_5      (10)
+#define AOCL_DTL_LEVEL_TRACE_4      (9)
+#define AOCL_DTL_LEVEL_TRACE_3      (8)
+#define AOCL_DTL_LEVEL_TRACE_2      (7)
+#define AOCL_DTL_LEVEL_TRACE_1      (6)       /* BLIS/BLAS API */
+#define AOCL_DTL_LEVEL_VERBOSE      (5)
+#define AOCL_DTL_LEVEL_INFO         (4)
+#define AOCL_DTL_LEVEL_MINOR        (3)
+#define AOCL_DTL_LEVEL_MAJOR        (2)
+#define AOCL_DTL_LEVEL_CRITICAL     (1)
+
+
+#define AOCL_DTL_TRACE_FILE         "aocldtl_trace.txt"
+#define AOCL_DTL_AUTO_TRACE_FILE    "aocldtl_auto_trace.rawfile"
+#define AOCL_DTL_LOG_FILE           "aocldtl_log.txt"
 
 /* The use can use below three macros for different data type while dumping data
  * or specify the size of data type in bytes macro for character data type */
@@ -47,14 +69,7 @@
 /* macro for printing Decimal values */
 #define AOCL_LOG_DECIMAL_VALUE      ('d')
 
-/* user has to explicitly use the below macros to identify
-   ciriticality of the logged message */
-#define AOCL_DTL_LEVEL_ALL          (6)
-#define AOCL_DTL_LEVEL_VERBOSE      (5)
-#define AOCL_DTL_LEVEL_INFO         (4)
-#define AOCL_DTL_LEVEL_MINOR        (3)
-#define AOCL_DTL_LEVEL_MAJOR        (2)
-#define AOCL_DTL_LEVEL_CRITICAL     (1)
+
 
 #endif /* _AOCLDTLCF_H_ */
 

aocl_dtl/aoclflist.c

@@ -78,7 +78,7 @@ AOCL_FAL_FILE *AOCL_FLIST_AddFile(const int8 *pchFilePrefix, AOCL_FLIST_Node **p
 {
     AOCL_FLIST_Node *newNode = NULL, *temp = NULL;
     AOCL_FAL_FILE *file = NULL;
-    int8 pchFileName[40];
+    int8 pchFileName[255];
 
     /* We don't want duplicates so we will check if the file already opened for this thread */
     file = AOCL_FLIST_GetFile(*plist, tid);
@@ -89,7 +89,7 @@ AOCL_FAL_FILE *AOCL_FLIST_AddFile(const int8 *pchFilePrefix, AOCL_FLIST_Node **p
     }
 
     /* We don't have exiting file, lets try to open new one */
-    sprintf(pchFileName, "%d_%s", tid, pchFilePrefix);
+    sprintf(pchFileName, "P%d_T%d_%s", AOCL_getpid(), tid, pchFilePrefix);
 
     file = AOCL_FAL_Open(pchFileName, "wb");
     if (file == NULL)

aocl_dtl/aoclos.c

@@ -14,6 +14,8 @@
 #if defined(__linux__)
 #include <time.h>
 #include <sys/syscall.h>
+#include <sys/types.h>
+#include <unistd.h>
 #endif
 
 #if defined(__linux__)
@@ -29,13 +31,19 @@
 */
 
 uint32 AOCL_gettid(void) __attribute__((no_instrument_function));
+pid_t  AOCL_getpid(void) __attribute__((no_instrument_function));
 uint64 AOCL_getTimestamp(void) __attribute__((no_instrument_function));
 
 uint32 AOCL_gettid(void)
 {
     return syscall(__NR_gettid);
 }
 
+pid_t  AOCL_getpid(void)
+{
+    return getpid();
+}
+
 uint64 AOCL_getTimestamp(void)
 {
     struct timespec tms;
@@ -65,6 +73,12 @@ uint32 AOCL_gettid(void)
     return 0;
 }
 
+pid_t  AOCL_getpid(void)
+{
+	/* stub for other os's */
+    return 0;
+}
+
 uint64 AOCL_getTimestamp(void)
 {
     /* stub for other os's */

aocl_dtl/aoclos.h

@@ -20,6 +20,7 @@
 #define AOCL_free free
 
 uint32 AOCL_gettid(void);
+pid_t  AOCL_getpid(void);
 uint64 AOCL_getTimestamp(void);
 
 #endif /* _AOCL_OS_H_ */

aocl_dtl/etrace_decoder.py

@@ -119,13 +119,12 @@ def decode_symbols_from_trace():
 
     for line in range(len(raw_contents)):
         current_line = raw_contents[line].split(":")
-        if len(current_line) != 4:
+        if len(current_line) != 3:
             continue
 
-        print_string = current_line[0] + " "
-        print_string += current_line[2]
+        print_string = ""
 
-        if current_line[2] == "+":
+        if current_line[1] == "+":
             last_level = "+"
             level.append(1)
         else:
@@ -141,24 +140,24 @@ def decode_symbols_from_trace():
                 print_string += "."
 
         try:
-            print_string += lookup[int(current_line[3], 16)]
+            print_string += lookup[int(current_line[2], 16)]
         except KeyError:
             missing_symbols += 1
-            print_string += current_line[3]
+            print_string += current_line[2]
 
         if line == 1:
-            first_timestamp = int(current_line[1])
+            first_timestamp = int(current_line[0])
             print_string += "(+0us)"
         else:
-            delta_last = int(current_line[1]) - last_timestamp
-            delta_total = int(current_line[1]) - first_timestamp
+            delta_last = int(current_line[0]) - last_timestamp
+            delta_total = int(current_line[0]) - first_timestamp
             print_string += "(+" + str(delta_last) + "us, " + str(delta_total) + "us)"
 
 
         if last_level == "-" and call_only:
             continue
         else:
-            last_timestamp = int(current_line[1])
+            last_timestamp = int(current_line[0])
 
         print (print_string)
 

frame/3/bli_l3_oapi.c

@@ -54,14 +54,14 @@ void PASTEMAC(opname,EX_SUF) \
        BLIS_OAPI_EX_PARAMS  \
      ) \
 { \
-	AOCL_DTL_TRACE_ENTRY(AOCL_DTL_LEVEL_INFO) \
+	AOCL_DTL_TRACE_ENTRY(AOCL_DTL_LEVEL_TRACE_2) \
 	bli_init_once(); \
 \
 	BLIS_OAPI_EX_DECLS \
 \
 	/* If C has a zero dimension, return early.	*/	\
 	if ( bli_obj_has_zero_dim( c ) ) {\
-		AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_INFO) \
+		AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_TRACE_2) \
 		return;									 \
 	}\
 \
@@ -72,7 +72,7 @@ void PASTEMAC(opname,EX_SUF) \
 		 bli_obj_has_zero_dim( b ) ) \
 	{\
 		bli_scalm( beta, c ); \
-		AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_INFO)	\
+		AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_TRACE_2)	\
 		return;\
 	}\
 \
@@ -90,7 +90,7 @@ void PASTEMAC(opname,EX_SUF) \
 		   proceed towards the conventional implementation. */ \
 		err_t result = PASTEMAC(opname,sup)( alpha, a, b, beta, c, cntx, rntm ); \
 		if ( result == BLIS_SUCCESS ) {\
-				AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_INFO) \
+				AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_TRACE_2) \
 			return;					   \
 		} \
 	} \

frame/3/gemm/bli_gemm_blk_var1.c

@@ -46,7 +46,7 @@ void bli_gemm_blk_var1
        thrinfo_t* thread
      )
 {
-	AOCL_DTL_TRACE_ENTRY(AOCL_DTL_LEVEL_INFO);
+	AOCL_DTL_TRACE_ENTRY(AOCL_DTL_LEVEL_TRACE_5);
 	obj_t a1, c1;
 	dim_t my_start, my_end;
 	dim_t b_alg;
@@ -92,6 +92,6 @@ void bli_gemm_blk_var1
 		);
 	}
 
-	AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_INFO);
+	AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_TRACE_5);
 }
 

frame/3/gemm/bli_gemm_blk_var2.c

@@ -46,7 +46,7 @@ void bli_gemm_blk_var2
        thrinfo_t* thread
      )
 {
-	AOCL_DTL_TRACE_ENTRY(AOCL_DTL_LEVEL_INFO);
+	AOCL_DTL_TRACE_ENTRY(AOCL_DTL_LEVEL_TRACE_5);
 	obj_t b1, c1;
 	dim_t my_start, my_end;
 	dim_t b_alg;
@@ -92,6 +92,6 @@ void bli_gemm_blk_var2
 		);
 	}
 
-	AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_INFO);
+	AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_TRACE_5);
 }
 

frame/3/gemm/bli_gemm_blk_var3.c

@@ -45,7 +45,7 @@ void bli_gemm_blk_var3
        thrinfo_t* thread
      )
 {
-	AOCL_DTL_TRACE_ENTRY(AOCL_DTL_LEVEL_INFO);
+	AOCL_DTL_TRACE_ENTRY(AOCL_DTL_LEVEL_TRACE_5);
 	obj_t a1, b1;
 	dim_t b_alg;
 
@@ -111,6 +111,6 @@ void bli_gemm_blk_var3
 		if ( i == 0 ) bli_obj_scalar_reset( c );
 	}
 
-	AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_INFO);
+	AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_TRACE_5);
 }
 

frame/3/gemm/bli_gemm_front.c

@@ -47,7 +47,7 @@ void bli_gemm_front
        cntl_t* cntl
      )
 {
-	AOCL_DTL_TRACE_ENTRY(AOCL_DTL_LEVEL_INFO);
+	AOCL_DTL_TRACE_ENTRY(AOCL_DTL_LEVEL_TRACE_3);
 	bli_init_once();
 
 	obj_t   a_local;
@@ -68,7 +68,7 @@ void bli_gemm_front
 		err_t status = bli_gemm_small( alpha, a, b, beta, c, cntx, cntl );
 		if ( status == BLIS_SUCCESS )
 		{
-			AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_INFO);
+			AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_TRACE_3);
 			return;
 		}
 	}
@@ -289,7 +289,7 @@ void bli_gemm_front
 	}
 #endif
 #endif
-	AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_INFO);
+	AOCL_DTL_TRACE_EXIT(AOCL_DTL_LEVEL_TRACE_3);
 }
 
 // -----------------------------------------------------------------------------