!880 Add trace for musl linker

Merge pull request !880 from yinchuang/musl_trace

libc-test/src/functionalext/trace/trace_marker.c

@@ -15,6 +15,7 @@
 
 #include <trace/trace_marker.h>
 
+#include <errno.h>
 #include <fcntl.h>
 #include <pthread.h>
 #include <stdbool.h>
@@ -25,6 +26,8 @@
 #include <unistd.h>
 
 #define BUFFER_LEN 10240
+#define READ_BUFFER_SIZE 4096
+#define OUTFILE "/data/local/tmp/musl.trace"
 #define EXPECT_TRUE(c)                \
     do                                \
     {                                 \
@@ -38,21 +41,64 @@
             t_error("[%s] failed \n"); \
     } while (0)
 
+#ifndef TRACE_TEMP_FAILURE_RETRY
+#define TRACE_TEMP_FAILURE_RETRY(exp)          \
+    ({                                         \
+    long int _rc;                              \
+    do {                                       \
+        _rc = (long int)(exp);                 \
+    } while ((_rc == -1) && (errno == EINTR)); \
+    _rc;                                       \
+    })
+#endif
+
 typedef void (*TEST_FUN)(void);
 static const int WAIT_TIME = 1;
-static const int count = 10;
+static const int count = 100;
+
+static void clear_trace()
+{
+    if (access("/sys/kernel/tracing/trace", F_OK) == 0) {
+        system("echo > /sys/kernel/tracing/trace");
+    }
+
+    if (access("/sys/kernel/debug/tracing/trace", F_OK) == 0) {
+        system("echo > /sys/kernel/tracing/trace");
+    }
+
+    return;
+}
+
+static void dump_trace(int trace_fd)
+{
+    char buffer[READ_BUFFER_SIZE];
+    int nwrite;
+    int nread;
+    int out_fd = open(OUTFILE, O_WRONLY | O_CREAT);
+    if (out_fd == -1) {
+        return;
+    }
+    do {
+        nread = TRACE_TEMP_FAILURE_RETRY(read(trace_fd, buffer, READ_BUFFER_SIZE));
+        if ((nread == 0) || (nread == -1)) {
+            break;
+        }
+        nwrite = TRACE_TEMP_FAILURE_RETRY(write(out_fd, buffer, nread));
+    } while (nwrite > 0);
+    close(out_fd);
+}
 
 /**
  * @tc.name      : trace_marker
  * @tc.desc      : Test trace_marker_begin and trace_marker_end.
  * @tc.level     : Level 0
  */
-
 static void trace_marker_0010(void)
 {
+    clear_trace();
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-    trace_marker_begin("Musl_Trace_Marker_0100", "");
-    trace_marker_end();
+    trace_marker_begin(HITRACE_TAG_MUSL, "Musl_Trace_Marker_0010", "");
+    trace_marker_end(HITRACE_TAG_MUSL);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -67,7 +113,7 @@ static void trace_marker_0010(void)
     char buf_begin[BUFFER_LEN] = {0};
     char buf_end[BUFFER_LEN] = {0};
 
-    int buf_begin_fd = snprintf(buf_begin, BUFFER_LEN, "B|%d|%s", getpid(), "Musl_Trace_Marker_0100");
+    int buf_begin_fd = snprintf(buf_begin, BUFFER_LEN, "B|%d|%s", getpid(), "Musl_Trace_Marker_0010");
     if (buf_begin_fd < 0) {
         close(trace_fd);
         return;
@@ -100,9 +146,10 @@ static void trace_marker_0010(void)
  */
 static void trace_marker_0020(void)
 {
+    clear_trace();
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-    trace_marker_async_begin("async_begin_0200", "trace_async",1);
-    trace_marker_async_end("async_end_0200", "trace_async",1);
+    trace_marker_async_begin(HITRACE_TAG_MUSL, "async_begin_0200", "trace_async",1);
+    trace_marker_async_end(HITRACE_TAG_MUSL, "async_end_0200", "trace_async",1);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -150,9 +197,10 @@ static void trace_marker_0020(void)
  */
 static void trace_marker_0030(void)
 {
+    clear_trace();
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
     int traceCount = 5;
-    trace_marker_count("traceCount", traceCount);
+    trace_marker_count(HITRACE_TAG_MUSL, "traceCount", traceCount);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -195,6 +243,7 @@ static void trace_marker_0030(void)
  */
 static void trace_marker_0040(void)
 {
+    clear_trace();
     bool trace_sucess = false;
     char buffer_fir[BUFFER_LEN] = {0};
     char buffer_sec[BUFFER_LEN] = {0};
@@ -208,8 +257,8 @@ static void trace_marker_0040(void)
     } else if (fpid == 0) {
         int pidChild = getpid();
         system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-        trace_marker_begin("Trace_Marker0400_Forkfir", "");
-        trace_marker_end();
+        trace_marker_begin(HITRACE_TAG_MUSL, "Trace_Marker0400_Forkfir", "");
+        trace_marker_end(HITRACE_TAG_MUSL);
         system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
         int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY | O_APPEND);
@@ -246,8 +295,8 @@ static void trace_marker_0040(void)
         exit(pidChild);
     } else {
         system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-        trace_marker_begin("Trace_Marker0400_Forksec", "");
-        trace_marker_end();
+        trace_marker_begin(HITRACE_TAG_MUSL, "Trace_Marker0400_Forksec", "");
+        trace_marker_end(HITRACE_TAG_MUSL);
         system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
         int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY | O_APPEND);
@@ -291,6 +340,7 @@ static void trace_marker_0040(void)
  */
 static void trace_marker_0050(void)
 {
+    clear_trace();
     bool trace_async_sucess = false;
     char buffer_forkFir[BUFFER_LEN] = {0};
     char buffer_forkSec[BUFFER_LEN] = {0};
@@ -304,8 +354,8 @@ static void trace_marker_0050(void)
     } else if (fpid == 0) {
         int pidChild = getpid();
         system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-        trace_marker_async_begin("async0500_Forkfir", "begin_fir", 2);
-        trace_marker_async_end("async0500_Forkfir", "end_fir", 2);
+        trace_marker_async_begin(HITRACE_TAG_MUSL, "async0500_Forkfir", "begin_fir", 2);
+        trace_marker_async_end(HITRACE_TAG_MUSL, "async0500_Forkfir", "end_fir", 2);
         system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
         int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY | O_APPEND);
@@ -342,8 +392,8 @@ static void trace_marker_0050(void)
         exit(pidChild);
     } else {
         system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-        trace_marker_async_begin("async0500_Forksec", "begin_sec", 3);
-        trace_marker_async_end("async0500_Forksec", "end_sec", 3);
+        trace_marker_async_begin(HITRACE_TAG_MUSL, "async0500_Forksec", "begin_sec", 3);
+        trace_marker_async_end(HITRACE_TAG_MUSL, "async0500_Forksec", "end_sec", 3);
         system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
         int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY | O_APPEND);
@@ -387,6 +437,7 @@ static void trace_marker_0050(void)
  */
 static void trace_marker_0060(void)
 {
+    clear_trace();
     int traceCount = 5;
     bool trace_count_sucess = false;
     char buffer_forkFir[BUFFER_LEN] = {0};
@@ -401,7 +452,7 @@ static void trace_marker_0060(void)
         int pidChild = getpid();
 
         system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-        trace_marker_count("traceCount_forkfir", traceCount);
+        trace_marker_count(HITRACE_TAG_MUSL, "traceCount_forkfir", traceCount);
         system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
         int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY | O_APPEND);
@@ -432,7 +483,7 @@ static void trace_marker_0060(void)
         exit(pidChild);
     } else {
         system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-        trace_marker_count("traceCount_forksec", traceCount);
+        trace_marker_count(HITRACE_TAG_MUSL, "traceCount_forksec", traceCount);
         system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
         int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY | O_APPEND);
@@ -466,8 +517,8 @@ static void trace_marker_0060(void)
 static void *ThreadTraceMarkerFir(void *arg)
 {
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-    trace_marker_begin("Trace_Marker_Threadfir", "pthreadfir");
-    trace_marker_end();
+    trace_marker_begin(HITRACE_TAG_MUSL, "Trace_Marker_Threadfir", "pthreadfir");
+    trace_marker_end(HITRACE_TAG_MUSL);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -512,8 +563,8 @@ static void *ThreadTraceMarkerFir(void *arg)
 static void *ThreadTraceMarkerSec(void *arg)
 {
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-    trace_marker_begin("Trace_Marker_Threadsec", "pthreadsec");
-    trace_marker_end();
+    trace_marker_begin(HITRACE_TAG_MUSL, "Trace_Marker_Threadsec", "pthreadsec");
+    trace_marker_end(HITRACE_TAG_MUSL);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -562,6 +613,7 @@ static void *ThreadTraceMarkerSec(void *arg)
  */
 static void trace_marker_0070(void)
 {
+    clear_trace();
     int res;
     const char msgThread1[1024] = {"msgThread1"};
     const char msgThread2[1024] = {"msgThread2"};
@@ -582,8 +634,8 @@ static void trace_marker_0070(void)
 static void *ThreadTraceMarkerAsyncFir(void *arg)
 {
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-    trace_marker_async_begin("Async_Threadfir", "begin_threadfir",4);
-    trace_marker_async_end("Async_Threadfir", "end_threadfir", 4);
+    trace_marker_async_begin(HITRACE_TAG_MUSL, "Async_Threadfir", "begin_threadfir",4);
+    trace_marker_async_end(HITRACE_TAG_MUSL, "Async_Threadfir", "end_threadfir", 4);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -628,8 +680,8 @@ static void *ThreadTraceMarkerAsyncFir(void *arg)
 static void *ThreadTraceMarkerAsyncSec(void *arg)
 {
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-    trace_marker_async_begin("Async_Threadsec", "begin_threadsec",5);
-    trace_marker_async_end("Async_Threadsec", "end_threadsec",5);
+    trace_marker_async_begin(HITRACE_TAG_MUSL, "Async_Threadsec", "begin_threadsec",5);
+    trace_marker_async_end(HITRACE_TAG_MUSL, "Async_Threadsec", "end_threadsec",5);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -678,6 +730,7 @@ static void *ThreadTraceMarkerAsyncSec(void *arg)
  */
 static void trace_marker_0080(void)
 {
+    clear_trace();
     int res;
     const char msgThread1[1024] = {"msgThread3"};
     const char msgThread2[1024] = {"msgThread4"};
@@ -699,7 +752,7 @@ static void *ThreadTraceMarkerCountFir(void *arg)
 {
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
     int traceCount = 5;
-    trace_marker_count("traceCount_Threadfir", traceCount);
+    trace_marker_count(HITRACE_TAG_MUSL, "traceCount_Threadfir", traceCount);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -740,7 +793,7 @@ static void *ThreadTraceMarkerCountSec(void *arg)
 {
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
     int traceCount = 5;
-    trace_marker_count("traceCount_Threadsec", traceCount);
+    trace_marker_count(HITRACE_TAG_MUSL, "traceCount_Threadsec", traceCount);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -783,6 +836,7 @@ static void *ThreadTraceMarkerCountSec(void *arg)
  */
 static void trace_marker_0090(void)
 {
+    clear_trace();
     int res;
     const char msgThread1[1024] = {"msgThread5"};
     const char msgThread2[1024] = {"msgThread6"};
@@ -807,9 +861,10 @@ static void trace_marker_0090(void)
  */
 static void trace_marker_0100(void)
 {
+    clear_trace();
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-    trace_marker_begin("Musl_Trace_Marker_0100", NULL);
-    trace_marker_end();
+    trace_marker_begin(HITRACE_TAG_MUSL, "Musl_Trace_Marker_0100", NULL);
+    trace_marker_end(HITRACE_TAG_MUSL);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -858,13 +913,14 @@ static void trace_marker_0100(void)
  */
 static void trace_marker_0110(void)
 {
+    clear_trace();
     char message[1026]= {0};
     memset(message, 1, 1025);
     message[1025] = '\0';
 
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-    trace_marker_begin(message, "");
-    trace_marker_end();
+    trace_marker_begin(HITRACE_TAG_MUSL, message, "");
+    trace_marker_end(HITRACE_TAG_MUSL);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -914,9 +970,10 @@ static void trace_marker_0110(void)
  */
 static void trace_marker_0120(void)
 {
+    clear_trace();
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-    trace_marker_begin(NULL, "");
-    trace_marker_end();
+    trace_marker_begin(HITRACE_TAG_MUSL, NULL, "");
+    trace_marker_end(HITRACE_TAG_MUSL);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -957,9 +1014,10 @@ static void trace_marker_0120(void)
  */
 static void trace_marker_0140(void)
 {
+    clear_trace();
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-    trace_marker_async_begin("async_begin_0200", NULL,1);
-    trace_marker_async_end("async_end_0200", NULL,1);
+    trace_marker_async_begin(HITRACE_TAG_MUSL, "async_begin_0200", NULL,1);
+    trace_marker_async_end(HITRACE_TAG_MUSL, "async_end_0200", NULL,1);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -1009,13 +1067,14 @@ static void trace_marker_0140(void)
  */
 static void trace_marker_0150(void)
 {
+    clear_trace();
     char message[1026]= {0};
     memset(message, 1, 1025);
     message[1025] = '\0';
 
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-    trace_marker_async_begin(message, "trace_async",1);
-    trace_marker_async_end(message, "trace_async",1);
+    trace_marker_async_begin(HITRACE_TAG_MUSL, message, "trace_async",1);
+    trace_marker_async_end(HITRACE_TAG_MUSL, message, "trace_async",1);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -1063,9 +1122,10 @@ static void trace_marker_0150(void)
  */
 static void trace_marker_0160(void)
 {
+    clear_trace();
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-    trace_marker_async_begin(NULL, "trace_async",1);
-    trace_marker_async_end(NULL, "trace_async",1);
+    trace_marker_async_begin(HITRACE_TAG_MUSL, NULL, "trace_async",1);
+    trace_marker_async_end(HITRACE_TAG_MUSL, NULL, "trace_async",1);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -1113,13 +1173,14 @@ static void trace_marker_0160(void)
  */
 static void trace_marker_0180(void)
 {
+    clear_trace();
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
     int traceCount = 5;
     char message[1026]= {0};
     memset(message, 1, 1025);
     message[1025] = '\0';
 
-    trace_marker_count(message, traceCount);
+    trace_marker_count(HITRACE_TAG_MUSL, message, traceCount);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -1162,9 +1223,10 @@ static void trace_marker_0180(void)
  */
 static void trace_marker_0190(void)
 {
+    clear_trace();
     system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
     int traceCount = 5;
-    trace_marker_count(NULL, traceCount);
+    trace_marker_count(HITRACE_TAG_MUSL, NULL, traceCount);
     system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
 
     int trace_fd = open("/sys/kernel/tracing/trace", O_CLOEXEC | O_RDONLY);
@@ -1217,7 +1279,7 @@ TEST_FUN G_Fun_Array[] = {
     trace_marker_0160,
     trace_marker_0180,
     trace_marker_0190,
-    };
+};
 
 int main(void)
 {
@@ -1227,4 +1289,4 @@ int main(void)
     }
 
     return t_status;
-}
+}
\ No newline at end of file

libc-test/src/functionalext/trace/trace_stresstest.c

@@ -49,8 +49,8 @@ static void trace_marker_stresstest_0010(void)
         while (traceCount <= 5000) {
             snprintf(buf, BUFFER_LEN, "%d", traceCount);
             system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-            trace_marker_async_begin("Trace_Marker_Async_Begin", buf, 1);
-            trace_marker_async_end("Trace_Marker_Async_End", buf, 1);
+            trace_marker_async_begin(HITRACE_TAG_MUSL, "Trace_Marker_Async_Begin", buf, 1);
+            trace_marker_async_end(HITRACE_TAG_MUSL, "Trace_Marker_Async_End", buf, 1);
             system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
             printf("trace_marker_async_begin has been running times is:%d\n", traceCount);
             traceCount++;
@@ -69,8 +69,8 @@ static void trace_marker_stresstest_0010(void)
             while (traceCount <= 5000) {
                 snprintf(buf, BUFFER_LEN, "%d", traceCount);
                 system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-                trace_marker_begin("Trace_Marker", buf);
-                trace_marker_end();
+                trace_marker_begin(HITRACE_TAG_MUSL, "Trace_Marker", buf);
+                trace_marker_end(HITRACE_TAG_MUSL);
                 system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
                 printf("trace_marker_begin has been running times is:%d\n", traceCount);  
                 traceCount++;
@@ -82,7 +82,7 @@ static void trace_marker_stresstest_0010(void)
 
             while (traceCount <= 5000) {
                 system("cd /sys/kernel/debug/tracing;echo 1 > tracing_on");
-                trace_marker_count("traceCount", traceCount);
+                trace_marker_count(HITRACE_TAG_MUSL, "traceCount", traceCount);
                 system("cd /sys/kernel/debug/tracing;echo 0 > tracing_on");
                 printf("trace_marker_count has been running times is:%d\n", traceCount);
                 traceCount++;

porting/linux/user/include/trace/trace_marker.h

@@ -16,6 +16,8 @@
 #ifndef _TRACE_TRACE_MARKER_H
 #define _TRACE_TRACE_MARKER_H
 
+#include <stdint.h>
+
 #define TRACE_MARKER_MESSAGE_LEN 1024
 
 #ifdef __cplusplus
@@ -23,42 +25,55 @@ extern "C"
 {
 #endif
 
+static const uint64_t HITRACE_TAG_ALWAYS = (1ULL << 0); // This tag is always enabled.
+static const uint64_t HITRACE_TAG_MUSL = (1ULL << 12); // musl tag.
+
+/**
+  * @brief Reset trace_marker trace switch status
+  */
+void trace_marker_reset(void);
+
 /**
   * @brief Write the function call information to the trace_marker node in kernel space,
   *        used on the same thread as trace_marker_end(),with the symbol "B".
+  * @param label The tagLabel of current sub-system.
   * @param message The function of information.
   * @param value The value which want to trace.
   */
-void trace_marker_begin(const char *message, const char *value);
+void trace_marker_begin(uint64_t label, const char *message, const char *value);
 
 /**
   * @brief Write the terminator to the trace_marker node of the kernel space,
   *        used on the same thread as trace_marker_begin(),with the symbol "E".
+  * @param label The tagLabel of current sub-system.
   */
-void trace_marker_end(void);
+void trace_marker_end(uint64_t label);
 
 /**
   * @brief Write the function call information to the trace_marker node in kernel space,
   *        used in a different thread than trace_marker_async_end(),with the symbol "S".
+  * @param label The tagLabel of current sub-system.
   * @param message The function of information.
   * @param value The value which want to trace.
   */
-void trace_marker_async_begin(const char *message, const char *value, int taskId);
+void trace_marker_async_begin(uint64_t label, const char *message, const char *value, int taskId);
 
 /**
   * @brief Write the terminator to the trace_marker node in kernel space,
   *        used in a different thread than trace_marker_async_begin(),with the symbol "F".
+  * @param label The tagLabel of current sub-system.
   * @param message The function of information.
   * @param value The value which want to trace.
   */
-void trace_marker_async_end(const char *message, const char *value, int taskId);
+void trace_marker_async_end(uint64_t label, const char *message, const char *value, int taskId);
 
 /**
   * @brief Marks a pre-traced numeric variable,with the symbol "C".
+  * @param label The tagLabel of current sub-system.
   * @param message The function of information.
   * @param value The value which want to trace.
   */
-void trace_marker_count(const char *message, int value);
+void trace_marker_count(uint64_t label, const char *message, int value);
 
 #ifdef __cplusplus
 }

porting/linux/user/ldso/dynlink.c

@@ -37,6 +37,8 @@
 #include "pthread_impl.h"
 #include "fork_impl.h"
 #include "strops.h"
+#include "trace/trace_marker.h"
+
 #ifdef OHOS_ENABLE_PARAMETER
 #include "sys_param.h"
 #endif
@@ -304,6 +306,8 @@ static void init_namespace(struct dso *app)
 	char file_path[sizeof "/etc/ld-musl-namespace-" + sizeof (LDSO_ARCH) + sizeof ".ini" + 1] = {0};
 	(void)snprintf(file_path, sizeof file_path, "/etc/ld-musl-namespace-%s.ini", LDSO_ARCH);
 	LD_LOGI("init_namespace file_path:%{public}s", file_path);
+	trace_marker_reset();
+	trace_marker_begin(HITRACE_TAG_MUSL, "parse linker config", file_path);
 	int ret = conf->parse(file_path, app_path);
 	if (ret < 0) {
 		LD_LOGE("init_namespace ini file parse failed!");
@@ -311,6 +315,7 @@ static void init_namespace(struct dso *app)
 		if (!sys_path) get_sys_path(conf);
 		init_default_namespace(app);
 		configor_free();
+		trace_marker_end(HITRACE_TAG_MUSL);
 		return;
 	}
 
@@ -326,6 +331,7 @@ static void init_namespace(struct dso *app)
 	if (!nsl) {
 		LD_LOGE("init nslist fail!");
 		configor_free();
+		trace_marker_end(HITRACE_TAG_MUSL);
 		return;
 	}
 	strlist *s_ns = conf->get_namespaces();
@@ -345,6 +351,7 @@ static void init_namespace(struct dso *app)
 		set_ns_inherits(nsl->nss[i], conf);
 	}
 	configor_free();
+	trace_marker_end(HITRACE_TAG_MUSL);
 	return;
 }
 
@@ -2474,7 +2481,13 @@ static void do_init_fini(struct dso **queue)
 		if (dyn[0] & (1<<DT_INIT_ARRAY)) {
 			size_t n = dyn[DT_INIT_ARRAYSZ]/sizeof(size_t);
 			size_t *fn = laddr(p, dyn[DT_INIT_ARRAY]);
+			if (p != &ldso) {
+				trace_marker_begin(HITRACE_TAG_MUSL, "calling constructors: ", p->name);
+			}
 			while (n--) ((void (*)(void))*fn++)();
+			if (p != &ldso) {
+				trace_marker_end(HITRACE_TAG_MUSL);
+			}
 		}
 
 		pthread_mutex_lock(&init_fini_lock);
@@ -3094,6 +3107,8 @@ static void *dlopen_impl(
 	pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &cs);
 	pthread_rwlock_wrlock(&lock);
 	__inhibit_ptc();
+	trace_marker_reset();
+	trace_marker_begin(HITRACE_TAG_MUSL, "dlopen: ", file);
 
 	debug.state = RT_ADD;
 	_dl_debug_state();
@@ -3170,12 +3185,14 @@ static void *dlopen_impl(
 			LD_LOGE("dlopen_impl create loadtask failed");
 			goto end;
 		}
+		trace_marker_begin(HITRACE_TAG_MUSL, "loading: entry so", file);
 		if (!load_library_header(task)) {
 			error(noload ?
 				"Library %s is not already loaded" :
 				"Error loading shared library %s: %m",
 				file);
 			LD_LOGE("dlopen_impl load library header failed for %{public}s", task->name);
+			trace_marker_end(HITRACE_TAG_MUSL); // "loading: entry so" trace end.
 			goto end;
 		}
 		if (reserved_address) {
@@ -3188,6 +3205,7 @@ static void *dlopen_impl(
 			"Library %s is not already loaded" :
 			"Error loading shared library %s: %m",
 			file);
+		trace_marker_end(HITRACE_TAG_MUSL); // "loading: entry so" trace end.
 		goto end;
 	}
 	if (!task->isloaded) {
@@ -3210,6 +3228,7 @@ static void *dlopen_impl(
 	free_loadtasks(tasks);
 	tasks = NULL;
 #else
+		trace_marker_begin(HITRACE_TAG_MUSL, "loading: entry so", file);
 		p = load_library(file, head, ns, true, reserved_address ? &reserved_params : NULL);
 	}
 
@@ -3218,11 +3237,13 @@ static void *dlopen_impl(
 			"Library %s is not already loaded" :
 			"Error loading shared library %s: %m",
 			file);
+		trace_marker_end(HITRACE_TAG_MUSL); // "loading: entry so" trace end.
 		goto end;
 	}
 	/* First load handling */
 	load_deps(p, reserved_address && reserved_address_recursive ? &reserved_params : NULL);
 #endif
+	trace_marker_end(HITRACE_TAG_MUSL); // "loading: entry so" trace end.
 	extend_bfs_deps(p);
 	pthread_mutex_lock(&init_fini_lock);
 	int constructed = p->constructed;
@@ -3246,9 +3267,11 @@ static void *dlopen_impl(
 		}
 	}
 	struct dso *reloc_head_so = p;
+	trace_marker_begin(HITRACE_TAG_MUSL, "linking: entry so", p->name);
 	if (!p->relocated) {
 		reloc_all(p, extinfo);
 	}
+	trace_marker_end(HITRACE_TAG_MUSL);
 	reloc_head_so->is_reloc_head_so_dep = false;
 	for (size_t i=0; reloc_head_so->deps[i]; i++) {
 		reloc_head_so->deps[i]->is_reloc_head_so_dep = false;
@@ -3297,6 +3320,7 @@ end:
 		free(ctor_queue);
 	}
 	pthread_setcancelstate(cs, 0);
+	trace_marker_end(HITRACE_TAG_MUSL); // "dlopen: " trace end.
 	return p;
 }
 
@@ -3544,8 +3568,11 @@ static void *do_dlsym(struct dso *p, const char *s, const char *v, void *ra)
 			ns = caller->namespace;
 		}
 	}
+	trace_marker_reset();
+	trace_marker_begin(HITRACE_TAG_MUSL, "dlsym: ", (s == NULL ? "(NULL)" : s));
 	struct verinfo verinfo = { .s = s, .v = v, .use_vna_hash = false };
 	struct symdef def = find_sym2(p, &verinfo, 0, use_deps, ns);
+	trace_marker_end(HITRACE_TAG_MUSL);
 	if (!def.sym) {
 		LD_LOGE("do_dlsym failed: symbol not found. so=%{public}s s=%{public}s v=%{public}s", p->name, s, v);
 		error("Symbol not found: %s, version: %s", s, strlen(v) > 0 ? v : "null");
@@ -3580,7 +3607,8 @@ static int dlclose_impl(struct dso *p)
 
 	if (--(p->nr_dlopen) > 0)
 		return 0;
-
+	trace_marker_reset();
+	trace_marker_begin(HITRACE_TAG_MUSL, "dlclose", p->name);
 	/* call destructors if needed */
 	if (p->constructed) {
 		size_t dyn[DYN_CNT];
@@ -3588,8 +3616,10 @@ static int dlclose_impl(struct dso *p)
 		if (dyn[0] & (1<<DT_FINI_ARRAY)) {
 			n = dyn[DT_FINI_ARRAYSZ] / sizeof(size_t);
 			size_t *fn = (size_t *)laddr(p, dyn[DT_FINI_ARRAY]) + n;
+			trace_marker_begin(HITRACE_TAG_MUSL, "calling destructors:", p->name);
 			while (n--)
 				((void (*)(void))*--fn)();
+			trace_marker_end(HITRACE_TAG_MUSL);
 		}
 		p->constructed = 0;
 	}
@@ -3667,6 +3697,7 @@ static int dlclose_impl(struct dso *p)
 	if (p->tls.size == 0) {
 		free(p);
 	}
+	trace_marker_end(HITRACE_TAG_MUSL);
 
 	return 0;
 }
@@ -4054,7 +4085,7 @@ void* dlopen_ext(const char *file, int mode, const dl_extinfo *extinfo)
 		mode,
 		caller_addr,
 		extinfo ? extinfo->flag : 0);
-  	return dlopen_impl(file, mode, NULL, caller_addr, extinfo);
+	return dlopen_impl(file, mode, NULL, caller_addr, extinfo);
 }
 
 #ifdef LOAD_ORDER_RANDOMIZATION

porting/linux/user/src/trace/trace_marker.c

@@ -24,22 +24,58 @@
 #include <sys/types.h>
 #include <unistd.h>
 #include "musl_log.h"
+#ifdef OHOS_ENABLE_PARAMETER
+#include "sys_param.h"
+#endif
 
 #ifndef MUSL_TEMP_FAILURE_RETRY
-#define MUSL_TEMP_FAILURE_RETRY(exp)            \
-    ({                                     \
-    long int _rc;                          \
-    do {                                   \
-        _rc = (long int)(exp);             \
+#define MUSL_TEMP_FAILURE_RETRY(exp)           \
+    ({                                         \
+    long int _rc;                              \
+    do {                                       \
+        _rc = (long int)(exp);                 \
     } while ((_rc == -1) && (errno == EINTR)); \
-    _rc;                                   \
+    _rc;                                       \
     })
 #endif
 
+#define LIKELY(exp) (__builtin_expect(!!(exp), 1))
+
+#ifdef OHOS_ENABLE_PARAMETER
+#define TRACE_PROPERTY_FLAG "debug.hitrace.tags.enableflags"
+static uint64_t g_trace_switch_status = 0;
+
+uint64_t get_uint64_sysparam(CachedHandle cachedhandle)
+{
+    char *param_value = CachedParameterGet(cachedhandle);
+    if (param_value != NULL) {
+        return strtoull(param_value, NULL, 0);
+    }
+    return 0;
+}
+#endif
+
+void trace_marker_reset(void)
+{
+#ifdef OHOS_ENABLE_PARAMETER
+    static CachedHandle trace_switch_handle = NULL;
+    if (trace_switch_handle == NULL) {
+        trace_switch_handle = CachedParameterCreate(TRACE_PROPERTY_FLAG, "0");
+    }
+    g_trace_switch_status = get_uint64_sysparam(trace_switch_handle);
+#else
+    return;
+#endif
+}
+
 // Check whether the user space trace function is enabled
-static inline bool is_enable_trace(void)
+static inline bool is_enable_trace(uint64_t label)
 {
-    return true;
+#ifdef OHOS_ENABLE_PARAMETER
+    return (((g_trace_switch_status & label) != 0) || ((g_trace_switch_status & HITRACE_TAG_ALWAYS) != 0));
+#else
+    return false;
+#endif
 }
 
 // Get the fd of trace_marker
@@ -54,9 +90,9 @@ static inline int get_trace_marker_fd(void)
 
 /* Write the function call information to the trace_marker node in kernel space,
 used on the same thread as trace_marker_end(),with the symbol "B". */
-void trace_marker_begin(const char *message, const char *value)
+void trace_marker_begin(uint64_t label, const char *message, const char *value)
 {
-    if (!is_enable_trace() || message == NULL) {
+    if (LIKELY((!is_enable_trace(label) || message == NULL))) {
         return;
     }
 
@@ -68,7 +104,7 @@ void trace_marker_begin(const char *message, const char *value)
     char buf[TRACE_MARKER_MESSAGE_LEN] = {0};
     int len = 0;
     if (value == NULL) {
-        len = snprintf(buf, TRACE_MARKER_MESSAGE_LEN, "B|%d %s", getpid(), message);
+        len = snprintf(buf, TRACE_MARKER_MESSAGE_LEN, "B|%d|%s", getpid(), message);
     } else {
         len = snprintf(buf, TRACE_MARKER_MESSAGE_LEN, "B|%d|%s %s", getpid(), message, value);
     }
@@ -87,9 +123,9 @@ void trace_marker_begin(const char *message, const char *value)
 
 /* Write the terminator to the trace_marker node of the kernel space,
 used on the same thread as trace_marker_begin(),with the symbol "E". */
-void trace_marker_end(void)
+void trace_marker_end(uint64_t label)
 {
-    if (!is_enable_trace()) {
+    if (LIKELY(!is_enable_trace(label))) {
         return;
     }
 
@@ -115,9 +151,9 @@ void trace_marker_end(void)
 
 /* Write the function call information to the trace_marker node in kernel space,
 used in a different thread than trace_marker_async_end(),with the symbol "S". */
-void trace_marker_async_begin(const char *message, const char *value, int taskId)
+void trace_marker_async_begin(uint64_t label, const char *message, const char *value, int taskId)
 {
-    if (!is_enable_trace() || message == NULL) {
+    if (LIKELY((!is_enable_trace(label) || message == NULL))) {
         return;
     }
 
@@ -148,9 +184,9 @@ void trace_marker_async_begin(const char *message, const char *value, int taskId
 
 /* Write the terminator to the trace_marker node in kernel space,
 used in a different thread than trace_marker_async_begin(),with the symbol "F". */
-void trace_marker_async_end(const char *message, const char *value, int taskId)
+void trace_marker_async_end(uint64_t label, const char *message, const char *value, int taskId)
 {
-    if (!is_enable_trace() || message == NULL) {
+    if (LIKELY((!is_enable_trace(label) || message == NULL))) {
         return;
     }
 
@@ -180,9 +216,9 @@ void trace_marker_async_end(const char *message, const char *value, int taskId)
 }
 
 // A numeric variable used to mark a pre trace, with the symbol "C".
-void trace_marker_count(const char *message, int value)
+void trace_marker_count(uint64_t label, const char *message, int value)
 {
-    if (!is_enable_trace() || message == NULL) {
+    if (LIKELY((!is_enable_trace(label) || message == NULL))) {
         return;
     }
 

scripts/runtest.sh

@@ -7,6 +7,7 @@ touch /data/tests/libc-test/REPORT
 touch /data/tests/libc-test/FileList.txt
 touch /data/tests/libc-test/SkipList.txt
 echo 'root:This.is.a.test:18997:0:99999:7:::'>/etc/shadow
+param set debug.hitrace.tags.enableflags 1
 
 ARCH=arm
 ABILIST=$(param get const.product.cpu.abilist)