Revert "Adding system property tracing"

Revert submission 1403568-sysprop_trace

Reason for revert: makes property get/set non-reentrant
Reverted Changes:
I6f85f3f52:Add systrace tag for system property
Id2b93acb2:Adding system property tracing
Id78992d23:Add systrace tag for system property
I1ba9fc7bd:Add systrace tag for system property

Bug: 193050299
Test: build and boot a device
Change-Id: Ic7a83fb01a39113d408ed0c95d27f694d5a2649c
Merged-In: Ic7a83fb01a39113d408ed0c95d27f694d5a2649c
(cherry picked from commit 61a5a8380d)
This commit is contained in:
Bowgo Tsai 2021-07-15 10:13:33 +00:00
parent 13a960f0ed
commit 8f14b65032
8 changed files with 19 additions and 214 deletions

View file

@ -1202,6 +1202,7 @@ cc_library_static {
}, },
}, },
whole_static_libs: [ whole_static_libs: [
"libc_bionic_systrace",
"libsystemproperties", "libsystemproperties",
], ],
cppflags: ["-Wold-style-cast"], cppflags: ["-Wold-style-cast"],

View file

@ -14,41 +14,36 @@
* limitations under the License. * limitations under the License.
*/ */
#include "private/bionic_systrace.h"
#include <errno.h> #include <errno.h>
#include <fcntl.h> #include <fcntl.h>
#include <stdio.h> #include <stdio.h>
#include <stdlib.h> #include <stdlib.h>
#include <string.h> #include <string.h>
#include "private/bionic_lock.h"
#include "private/bionic_systrace.h"
#include "private/CachedProperty.h"
#include <async_safe/log.h> #include <async_safe/log.h>
#include <cutils/trace.h> // For ATRACE_TAG_BIONIC. #include <cutils/trace.h> // For ATRACE_TAG_BIONIC.
#include "private/CachedProperty.h"
#include "private/bionic_lock.h"
#define WRITE_OFFSET 32 #define WRITE_OFFSET 32
static Lock g_lock; static Lock g_lock;
static CachedProperty g_debug_atrace_tags_enableflags("debug.atrace.tags.enableflags");
static uint64_t g_tags; static uint64_t g_tags;
static int g_trace_marker_fd = -1; static int g_trace_marker_fd = -1;
static CachedProperty& GetTagsProp() { static bool should_trace() {
static CachedProperty cached_property(kTraceTagsProp);
return cached_property;
}
bool should_trace(const uint64_t enable_tags) {
g_lock.lock(); g_lock.lock();
if (GetTagsProp().DidChange()) { if (g_debug_atrace_tags_enableflags.DidChange()) {
g_tags = strtoull(GetTagsProp().Get(), nullptr, 0); g_tags = strtoull(g_debug_atrace_tags_enableflags.Get(), nullptr, 0);
} }
g_lock.unlock(); g_lock.unlock();
return g_tags & enable_tags; return ((g_tags & ATRACE_TAG_BIONIC) != 0);
} }
int get_trace_marker_fd() { static int get_trace_marker_fd() {
g_lock.lock(); g_lock.lock();
if (g_trace_marker_fd == -1) { if (g_trace_marker_fd == -1) {
g_trace_marker_fd = open("/sys/kernel/tracing/trace_marker", O_CLOEXEC | O_WRONLY); g_trace_marker_fd = open("/sys/kernel/tracing/trace_marker", O_CLOEXEC | O_WRONLY);
@ -60,8 +55,11 @@ int get_trace_marker_fd() {
return g_trace_marker_fd; return g_trace_marker_fd;
} }
// event could be 'B' for begin or 'E' for end. void bionic_trace_begin(const char* message) {
void output_trace(const char* message, const char event) { if (!should_trace()) {
return;
}
int trace_marker_fd = get_trace_marker_fd(); int trace_marker_fd = get_trace_marker_fd();
if (trace_marker_fd == -1) { if (trace_marker_fd == -1) {
return; return;
@ -71,22 +69,13 @@ void output_trace(const char* message, const char event) {
// kernel trace_marker. // kernel trace_marker.
int length = strlen(message); int length = strlen(message);
char buf[length + WRITE_OFFSET]; char buf[length + WRITE_OFFSET];
size_t len = size_t len = async_safe_format_buffer(buf, length + WRITE_OFFSET, "B|%d|%s", getpid(), message);
async_safe_format_buffer(buf, length + WRITE_OFFSET, "%c|%d|%s", event, getpid(), message);
// Tracing may stop just after checking property and before writing the message. // Tracing may stop just after checking property and before writing the message.
// So the write is acceptable to fail. See b/20666100. // So the write is acceptable to fail. See b/20666100.
TEMP_FAILURE_RETRY(write(trace_marker_fd, buf, len)); TEMP_FAILURE_RETRY(write(trace_marker_fd, buf, len));
} }
void bionic_trace_begin(const char* message) {
if (!should_trace()) {
return;
}
output_trace(message);
}
void bionic_trace_end() { void bionic_trace_end() {
if (!should_trace()) { if (!should_trace()) {
return; return;

View file

@ -41,13 +41,12 @@
#include <sys/_system_properties.h> #include <sys/_system_properties.h>
#include <unistd.h> #include <unistd.h>
#include <async_safe/CHECK.h>
#include <async_safe/log.h> #include <async_safe/log.h>
#include <system_properties/prop_trace.h> #include <async_safe/CHECK.h>
#include "private/bionic_defs.h"
#include "platform/bionic/macros.h" #include "platform/bionic/macros.h"
#include "private/ScopedFd.h" #include "private/ScopedFd.h"
#include "private/bionic_defs.h"
static const char property_service_socket[] = "/dev/socket/" PROP_SERVICE_NAME; static const char property_service_socket[] = "/dev/socket/" PROP_SERVICE_NAME;
static const char* kServiceVersionPropertyName = "ro.property_service.version"; static const char* kServiceVersionPropertyName = "ro.property_service.version";
@ -250,8 +249,6 @@ int __system_property_set(const char* key, const char* value) {
if (key == nullptr) return -1; if (key == nullptr) return -1;
if (value == nullptr) value = ""; if (value == nullptr) value = "";
SyspropTrace trace(key, value, nullptr /* prop_info */, PropertyAction::kPropertySet);
if (g_propservice_protocol_version == 0) { if (g_propservice_protocol_version == 0) {
detect_protocol_version(); detect_protocol_version();
} }

View file

@ -16,12 +16,8 @@
#pragma once #pragma once
#include <cutils/trace.h> // For ATRACE_TAG_BIONIC.
#include "platform/bionic/macros.h" #include "platform/bionic/macros.h"
static constexpr char kTraceTagsProp[] = "debug.atrace.tags.enableflags";
// Tracing class for bionic. To begin a trace at a specified point: // Tracing class for bionic. To begin a trace at a specified point:
// ScopedTrace("Trace message"); // ScopedTrace("Trace message");
// The trace will end when the contructor goes out of scope. // The trace will end when the contructor goes out of scope.
@ -37,9 +33,5 @@ class __LIBC_HIDDEN__ ScopedTrace {
BIONIC_DISALLOW_COPY_AND_ASSIGN(ScopedTrace); BIONIC_DISALLOW_COPY_AND_ASSIGN(ScopedTrace);
}; };
int get_trace_marker_fd();
bool should_trace(const uint64_t enable_tags = ATRACE_TAG_BIONIC);
void output_trace(const char* message, const char event = 'B');
void bionic_trace_begin(const char* message); void bionic_trace_begin(const char* message);
void bionic_trace_end(); void bionic_trace_end();

View file

@ -18,11 +18,9 @@ cc_library_static {
"contexts_serialized.cpp", "contexts_serialized.cpp",
"prop_area.cpp", "prop_area.cpp",
"prop_info.cpp", "prop_info.cpp",
"prop_trace.cpp",
"system_properties.cpp", "system_properties.cpp",
], ],
whole_static_libs: [ whole_static_libs: [
"libc_bionic_systrace",
"libpropertyinfoparser", "libpropertyinfoparser",
], ],
header_libs: [ header_libs: [

View file

@ -1,49 +0,0 @@
/*
* Copyright (C) 2020 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#pragma once
#include "platform/bionic/macros.h"
#include "prop_info.h"
// Tracing class for sysprop. To begin a trace at a specified point:
// SyspropTrace trace ("prop_name", "prop_value");
// The trace will end when the constructor goes out of scope.
// For read-only properties (ro.*), also need to pass prop_info struct.
enum class PropertyAction {
kPropertyFind = 0,
kPropertySet,
kPropertyGetReadOnly,
kPropertyGetReadWrite,
};
class __LIBC_HIDDEN__ SyspropTrace {
public:
explicit SyspropTrace(const char* prop_name, const char* prop_value, const prop_info* pi,
PropertyAction action);
~SyspropTrace();
private:
const char* prop_name_;
const char* prop_value_;
const prop_info* prop_info_;
PropertyAction prop_action_;
bool output_trace_;
BIONIC_DISALLOW_COPY_AND_ASSIGN(SyspropTrace);
};

View file

@ -1,113 +0,0 @@
/*
* Copyright (C) 2020 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#include "system_properties/prop_trace.h"
#include <errno.h>
#include <fcntl.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include "private/CachedProperty.h"
#include "private/bionic_lock.h"
#include "private/bionic_systrace.h"
#include <async_safe/log.h>
#include <cutils/trace.h> // For ATRACE_TAG_SYSPROP.
#define PROP_TRACE_MSG_LENGTH 1024
static bool should_trace_prop(const char* prop_name) {
// Should not trace kTraceTagsProp to avoid infinite recursion.
// Because the following g_trace_enable_flags.Get() will get the property value
// of kTraceTagsProp again, which in turn invokes should_trace_prop() here.
if (prop_name == nullptr || !strcmp(prop_name, kTraceTagsProp)) {
return false;
}
return should_trace(ATRACE_TAG_SYSPROP);
}
static void sysprop_trace_end() {
int trace_marker_fd = get_trace_marker_fd();
if (trace_marker_fd == -1) {
return;
}
TEMP_FAILURE_RETRY(write(trace_marker_fd, "E|", 2));
}
static void get_sysprop_trace_end(const prop_info* pi, const char* prop_value,
bool read_only = false) {
const char* output_value;
char message[PROP_TRACE_MSG_LENGTH];
if (read_only) {
if (pi->is_long()) {
output_value = pi->long_value();
} else {
output_value = pi->value;
}
} else {
output_value = prop_value;
}
snprintf(message, sizeof(message), "prop_get: %s, value: %s", pi->name,
output_value ? output_value : "null_value");
output_trace(message, 'E'); // 'E' for end.
}
SyspropTrace::SyspropTrace(const char* prop_name, const char* prop_value, const prop_info* pi,
PropertyAction action)
: prop_name_(prop_name),
prop_value_(prop_value),
prop_info_(pi),
prop_action_(action),
output_trace_(false) {
if (!should_trace_prop(prop_name)) {
return;
}
char message[PROP_TRACE_MSG_LENGTH];
if (prop_action_ == PropertyAction::kPropertyFind) {
snprintf(message, sizeof(message), "prop_find: %s", prop_name_);
} else if (prop_action_ == PropertyAction::kPropertySet) {
snprintf(message, sizeof(message), "prop_set: %s, value: %s", prop_name_,
prop_value_ ? prop_value_ : "null_value");
} else {
// For property get, the prop_value_ will be resolved then printed in the destructor.
snprintf(message, sizeof(message), "prop_get: %s", prop_name_);
}
output_trace(message, 'B'); // 'B' for begin.
output_trace_ = true;
}
SyspropTrace::~SyspropTrace() {
if (!output_trace_) {
return;
}
if (prop_action_ == PropertyAction::kPropertyFind ||
prop_action_ == PropertyAction::kPropertySet) {
sysprop_trace_end();
} else if (prop_action_ == PropertyAction::kPropertyGetReadOnly) {
get_sysprop_trace_end(prop_info_, prop_value_, true /* read_only */);
} else if (prop_action_ == PropertyAction::kPropertyGetReadWrite) {
get_sysprop_trace_end(prop_info_, prop_value_, false /* read_only */);
}
output_trace_ = false;
}

View file

@ -46,7 +46,6 @@
#include "system_properties/context_node.h" #include "system_properties/context_node.h"
#include "system_properties/prop_area.h" #include "system_properties/prop_area.h"
#include "system_properties/prop_info.h" #include "system_properties/prop_info.h"
#include "system_properties/prop_trace.h"
#define SERIAL_DIRTY(serial) ((serial)&1) #define SERIAL_DIRTY(serial) ((serial)&1)
#define SERIAL_VALUE_LEN(serial) ((serial) >> 24) #define SERIAL_VALUE_LEN(serial) ((serial) >> 24)
@ -128,9 +127,6 @@ const prop_info* SystemProperties::Find(const char* name) {
return nullptr; return nullptr;
} }
SyspropTrace trace(name, nullptr /* prop_value */, nullptr /* prop_info */,
PropertyAction::kPropertyFind);
prop_area* pa = contexts_->GetPropAreaForName(name); prop_area* pa = contexts_->GetPropAreaForName(name);
if (!pa) { if (!pa) {
async_safe_format_log(ANDROID_LOG_WARN, "libc", "Access denied finding property \"%s\"", name); async_safe_format_log(ANDROID_LOG_WARN, "libc", "Access denied finding property \"%s\"", name);
@ -205,10 +201,6 @@ void SystemProperties::ReadCallback(const prop_info* pi,
// Read only properties don't need to copy the value to a temporary buffer, since it can never // Read only properties don't need to copy the value to a temporary buffer, since it can never
// change. We use relaxed memory order on the serial load for the same reason. // change. We use relaxed memory order on the serial load for the same reason.
if (is_read_only(pi->name)) { if (is_read_only(pi->name)) {
// The 2nd argument is not required for read-only property tracing, as the
// value can be obtained via pi->value or pi->long_value().
SyspropTrace trace(pi->name, nullptr /* prop_value */, pi /* prop_info */,
PropertyAction::kPropertyGetReadOnly);
uint32_t serial = load_const_atomic(&pi->serial, memory_order_relaxed); uint32_t serial = load_const_atomic(&pi->serial, memory_order_relaxed);
if (pi->is_long()) { if (pi->is_long()) {
callback(cookie, pi->name, pi->long_value(), serial); callback(cookie, pi->name, pi->long_value(), serial);
@ -219,8 +211,6 @@ void SystemProperties::ReadCallback(const prop_info* pi,
} }
char value_buf[PROP_VALUE_MAX]; char value_buf[PROP_VALUE_MAX];
SyspropTrace trace(pi->name, value_buf, pi /* prop_info */,
PropertyAction::kPropertyGetReadWrite);
uint32_t serial = ReadMutablePropertyValue(pi, value_buf); uint32_t serial = ReadMutablePropertyValue(pi, value_buf);
callback(cookie, pi->name, value_buf, serial); callback(cookie, pi->name, value_buf, serial);
} }