Merge changes Ib2bad794,I82436292

am: e98d1e68ce

Change-Id: I9a7976262216e9196bb1bc5a5b2bd5736346b109

libc/bionic/bionic_systrace.cpp

@@ -48,10 +48,11 @@ static bool should_trace() {
   // case an audit will be logged, and during boot before the property server has
   // been started, in which case we store the global property_area serial to prevent
   // the costly find operation until we see a changed property_area.
-  if (!g_pinfo && g_property_area_serial != __system_property_area_serial()) {
+  if (g_pinfo == nullptr && g_property_area_serial != __system_property_area_serial()) {
     g_property_area_serial = __system_property_area_serial();
     g_pinfo = __system_property_find(SYSTRACE_PROPERTY_NAME);
   }
+
   if (g_pinfo) {
     // Find out which tags have been enabled on the command line and set
     // the value of tags accordingly.  If the value of the property changes,
@@ -61,10 +62,11 @@ static bool should_trace() {
     // not to move.
     uint32_t cur_serial = __system_property_serial(g_pinfo);
     if (cur_serial != g_property_serial) {
-      g_property_serial = cur_serial;
-      char value[PROP_VALUE_MAX];
-      __system_property_read(g_pinfo, 0, value);
-      g_tags = strtoull(value, nullptr, 0);
+      __system_property_read_callback(g_pinfo,
+              [] (void*, const char*, const char* value, uint32_t serial) {
+                g_property_serial = serial;
+                g_tags = strtoull(value, nullptr, 0);
+              }, nullptr);
     }
     result = ((g_tags & ATRACE_TAG_BIONIC) != 0);
   }
@@ -81,7 +83,7 @@ static int get_trace_marker_fd() {
   return g_trace_marker_fd;
 }
 
-ScopedTrace::ScopedTrace(const char* message) {
+void bionic_trace_begin(const char* message) {
   if (!should_trace()) {
     return;
   }
@@ -102,7 +104,7 @@ ScopedTrace::ScopedTrace(const char* message) {
   TEMP_FAILURE_RETRY(write(trace_marker_fd, buf, len));
 }
 
-ScopedTrace::~ScopedTrace() {
+void bionic_trace_end() {
   if (!should_trace()) {
     return;
   }
@@ -114,3 +116,18 @@ ScopedTrace::~ScopedTrace() {
 
   TEMP_FAILURE_RETRY(write(trace_marker_fd, "E", 1));
 }
+
+ScopedTrace::ScopedTrace(const char* message) : called_end_(false) {
+  bionic_trace_begin(message);
+}
+
+ScopedTrace::~ScopedTrace() {
+  End();
+}
+
+void ScopedTrace::End() {
+  if (!called_end_) {
+    bionic_trace_end();
+    called_end_ = true;
+  }
+}

libc/private/bionic_systrace.h

@@ -28,8 +28,13 @@ class __LIBC_HIDDEN__ ScopedTrace {
   explicit ScopedTrace(const char* message);
   ~ScopedTrace();
 
+  void End();
  private:
+  bool called_end_;
   DISALLOW_COPY_AND_ASSIGN(ScopedTrace);
 };
 
+void bionic_trace_begin(const char* message);
+void bionic_trace_end();
+
 #endif

linker/linker.cpp

@@ -1861,6 +1861,9 @@ static std::string android_dlextinfo_to_string(const android_dlextinfo* info) {
 void* do_dlopen(const char* name, int flags,
                 const android_dlextinfo* extinfo,
                 const void* caller_addr) {
+  std::string trace_prefix = std::string("dlopen: ") + (name == nullptr ? "(nullptr)" : name);
+  ScopedTrace trace(trace_prefix.c_str());
+  ScopedTrace loading_trace((trace_prefix + " - loading and linking").c_str());
   soinfo* const caller = find_containing_library(caller_addr);
   android_namespace_t* ns = get_caller_namespace(caller);
 
@@ -1937,6 +1940,8 @@ void* do_dlopen(const char* name, int flags,
 
   ProtectedDataGuard guard;
   soinfo* si = find_library(ns, translated_name, flags, extinfo, caller);
+  loading_trace.End();
+
   if (si != nullptr) {
     void* handle = si->to_handle();
     LD_LOG(kLogDlopen,

linker/linker_logger.h

@@ -32,6 +32,7 @@
 #include <stdlib.h>
 #include <limits.h>
 #include "private/bionic_macros.h"
+#include "private/bionic_systrace.h"
 
 #define LD_LOG(type, x...) \
   { \

linker/linker_soinfo.cpp

@@ -409,11 +409,17 @@ void soinfo::call_constructors() {
     si->call_constructors();
   });
 
-  TRACE("\"%s\": calling constructors", get_realpath());
+  if (!is_linker()) {
+    bionic_trace_begin((std::string("calling constructors: ") + get_realpath()).c_str());
+  }
 
   // DT_INIT should be called before DT_INIT_ARRAY if both are present.
   call_function("DT_INIT", init_func_, get_realpath());
   call_array("DT_INIT_ARRAY", init_array_, init_array_count_, false, get_realpath());
+
+  if (!is_linker()) {
+    bionic_trace_end();
+  }
 }
 
 void soinfo::call_destructors() {