tequilaOS/platform_bionic
2
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity

Merge "Disable info messages by default for malloc debug." am: e6fd53b751

Browse source 
am: f2905f4ce3

Change-Id: Iddb4900532ef816f8bf061a142cd0ec74b45a850
This commit is contained in:
Christopher Ferris 2019-04-02 13:40:11 -07:00 committed by android-build-merger
commit 8e1ffaf89f
10 changed files with 124 additions and 80 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

4
libc/bionic/malloc_common_dynamic.cpp
View file

@ -307,8 +307,6 @@ bool FinishInstallHooks(libc_globals* globals, const char* options, const char*
atomic_store(&globals->current_dispatch_table, &globals->malloc_dispatch_table);
}
info_log("%s: malloc %s enabled", getprogname(), prefix);
// Use atexit to trigger the cleanup function. This avoids a problem
// where another atexit function is used to cleanup allocated memory,
// but the finalize function was already called. This particular error
@ -316,7 +314,7 @@ bool FinishInstallHooks(libc_globals* globals, const char* options, const char*
int ret_value = __cxa_atexit(MallocFiniImpl, nullptr, nullptr);
if (ret_value != 0) {
// We don't consider this a fatal error.
info_log("failed to set atexit cleanup function: %d", ret_value);
warning_log("failed to set atexit cleanup function: %d", ret_value);
}
return true;
}

3
libc/malloc_debug/Config.cpp
View file

@ -135,6 +135,9 @@ const std::unordered_map<std::string, Config::OptionInfo> Config::kOptions = {
{
"abort_on_error", {ABORT_ON_ERROR, &Config::VerifyValueEmpty},
},
{
"verbose", {VERBOSE, &Config::VerifyValueEmpty},
},
};
bool Config::ParseValue(const std::string& option, const std::string& value, size_t min_value,

1
libc/malloc_debug/Config.h
View file

@ -45,6 +45,7 @@ constexpr uint64_t LEAK_TRACK = 0x100;
constexpr uint64_t RECORD_ALLOCS = 0x200;
constexpr uint64_t BACKTRACE_FULL = 0x400;
constexpr uint64_t ABORT_ON_ERROR = 0x800;
constexpr uint64_t VERBOSE = 0x1000;
// In order to guarantee posix compliance, set the minimum alignment
// to 8 bytes for 32 bit systems and 16 bytes for 64 bit systems.

12
libc/malloc_debug/PointerData.cpp
View file

@ -105,8 +105,10 @@ bool PointerData::Initialize(const Config& config) NO_THREAD_SAFETY_ANALYSIS {
error_log("Unable to set up backtrace signal enable function: %s", strerror(errno));
return false;
}
info_log("%s: Run: 'kill -%d %d' to enable backtracing.", getprogname(),
config.backtrace_signal(), getpid());
if (config.options() & VERBOSE) {
info_log("%s: Run: 'kill -%d %d' to enable backtracing.", getprogname(),
config.backtrace_signal(), getpid());
}
}
if (config.options() & BACKTRACE) {
@ -117,8 +119,10 @@ bool PointerData::Initialize(const Config& config) NO_THREAD_SAFETY_ANALYSIS {
error_log("Unable to set up backtrace dump signal function: %s", strerror(errno));
return false;
}
info_log("%s: Run: 'kill -%d %d' to dump the backtrace.", getprogname(),
config.backtrace_dump_signal(), getpid());
if (config.options() & VERBOSE) {
info_log("%s: Run: 'kill -%d %d' to dump the backtrace.", getprogname(),
config.backtrace_dump_signal(), getpid());
}
}
backtrace_dump_ = false;

15
libc/malloc_debug/README.md
View file

@ -401,6 +401,21 @@ log message.
**NOTE**: If leak\_track is enabled, no abort occurs if leaks have been
detected when the process is exiting.
### verbose
As of Android Q, all info messages will be turned off by default. For example,
in Android P and older, enabling malloc debug would result in this message
in the log:
08-16 15:54:16.060 26947 26947 I libc : /system/bin/app_process64: malloc debug enabled
In android Q, this message will not be displayed because these info messages
slow down process start up. However, if you want to re-enable these messages,
add the verbose option. All of the "Run XXX" messages are also silenced unless
the verbose option is specified. This is an example of the type
of messages that are no longer displayed:
09-10 01:03:50.070 557 557 I malloc_debug: /system/bin/audioserver: Run: 'kill -47 557' to dump the backtrace.
Additional Errors
-----------------
There are a few other error messages that might appear in the log.

6
libc/malloc_debug/RecordData.cpp
View file

@ -181,8 +181,10 @@ bool RecordData::Initialize(const Config& config) {
}
pthread_setspecific(key_, nullptr);
info_log("%s: Run: 'kill -%d %d' to dump the allocation records.", getprogname(),
config.record_allocs_signal(), getpid());
if (config.options() & VERBOSE) {
info_log("%s: Run: 'kill -%d %d' to dump the allocation records.", getprogname(),
config.record_allocs_signal(), getpid());
}
num_entries_ = config.record_allocs_num_entries();
entries_ = new const RecordEntry*[num_entries_];

5
libc/malloc_debug/malloc_debug.cpp
View file

@ -30,6 +30,7 @@
#include <inttypes.h>
#include <malloc.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/cdefs.h>
#include <sys/param.h>
@ -252,6 +253,10 @@ bool debug_initialize(const MallocDispatch* malloc_dispatch, int* malloc_zygote_
// of different error cases.
backtrace_startup();
if (g_debug->config().options() & VERBOSE) {
info_log("%s: malloc debug enabled", getprogname());
}
return true;
}

18
libc/malloc_debug/tests/malloc_debug_config_tests.cpp
View file

@ -743,3 +743,21 @@ TEST_F(MallocDebugConfigTest, trigger_abort_fail) {
"which does not take a value\n");
ASSERT_STREQ((log_msg + usage_string).c_str(), getFakeLogPrint().c_str());
}
TEST_F(MallocDebugConfigTest, verbose) {
ASSERT_TRUE(InitConfig("verbose")) << getFakeLogPrint();
ASSERT_EQ(VERBOSE, config->options());
ASSERT_STREQ("", getFakeLogBuf().c_str());
ASSERT_STREQ("", getFakeLogPrint().c_str());
}
TEST_F(MallocDebugConfigTest, trigger_verbose_fail) {
ASSERT_FALSE(InitConfig("verbose=200")) << getFakeLogPrint();
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string log_msg(
"6 malloc_debug malloc_testing: value set for option 'verbose' "
"which does not take a value\n");
ASSERT_STREQ((log_msg + usage_string).c_str(), getFakeLogPrint().c_str());
}

4
libc/malloc_debug/tests/malloc_debug_system_tests.cpp
View file

@ -195,7 +195,7 @@ TEST(MallocTests, DISABLED_smoke) {}
TEST(MallocDebugSystemTest, smoke) {
pid_t pid;
ASSERT_NO_FATAL_FAILURE(Exec("MallocTests.DISABLED_smoke", "backtrace", &pid));
ASSERT_NO_FATAL_FAILURE(Exec("MallocTests.DISABLED_smoke", "verbose backtrace", &pid));
ASSERT_NO_FATAL_FAILURE(FindStrings(pid, std::vector<const char*>{"malloc debug enabled"}));
}
@ -399,7 +399,7 @@ static void VerifyLeak(const char* test_prefix) {
pid_t pid;
SCOPED_TRACE(testing::Message() << functions[i].name << " expected size " << functions[i].size);
std::string test = std::string("MallocTests.DISABLED_") + test_prefix + functions[i].name;
EXPECT_NO_FATAL_FAILURE(Exec(test.c_str(), "backtrace leak_track", &pid));
EXPECT_NO_FATAL_FAILURE(Exec(test.c_str(), "verbose backtrace leak_track", &pid));
std::string expected_leak = android::base::StringPrintf("leaked block of size %zu at", functions[i].size);
EXPECT_NO_FATAL_FAILURE(FindStrings(

136
libc/malloc_debug/tests/malloc_debug_unit_tests.cpp
View file

@ -154,7 +154,7 @@ std::string ShowDiffs(uint8_t* a, uint8_t* b, size_t size) {
return diff;
}
void VerifyAllocCalls(bool backtrace_enabled) {
void VerifyAllocCalls(bool all_options) {
size_t alloc_size = 1024;
// Verify debug_malloc.
@ -209,21 +209,28 @@ void VerifyAllocCalls(bool backtrace_enabled) {
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log;
if (backtrace_enabled) {
if (all_options) {
expected_log += android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to enable backtracing.\n",
SIGRTMAX - 19, getpid());
expected_log += android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
expected_log += android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the allocation records.\n",
SIGRTMAX - 18, getpid());
}
expected_log += "4 malloc_debug malloc_testing: malloc debug enabled\n";
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, fill_generic) {
Init("fill");
Init("verbose fill");
VerifyAllocCalls(false);
}
TEST_F(MallocDebugTest, fill_on_alloc_generic) {
Init("fill_on_alloc");
Init("verbose fill_on_alloc");
VerifyAllocCalls(false);
}
@ -241,6 +248,46 @@ TEST_F(MallocDebugTest, fill_on_alloc_partial) {
ASSERT_STREQ("", getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, verbose_only) {
Init("verbose");
ASSERT_STREQ("", getFakeLogBuf().c_str());
ASSERT_STREQ("4 malloc_debug malloc_testing: malloc debug enabled\n", getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, verbose_backtrace_enable_on_signal) {
Init("verbose backtrace_enable_on_signal");
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to enable backtracing.\n",
SIGRTMAX - 19, getpid());
expected_log += android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
expected_log += "4 malloc_debug malloc_testing: malloc debug enabled\n";
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, verbose_backtrace) {
Init("verbose backtrace");
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
expected_log += "4 malloc_debug malloc_testing: malloc debug enabled\n";
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, verbose_record_allocs) {
Init("verbose record_allocs");
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the allocation records.\n",
SIGRTMAX - 18, getpid());
expected_log += "4 malloc_debug malloc_testing: malloc debug enabled\n";
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, fill_on_free) {
Init("fill_on_free free_track free_track_backtrace_num_frames=0");
@ -302,7 +349,9 @@ TEST_F(MallocDebugTest, free_track_partial) {
}
TEST_F(MallocDebugTest, all_options) {
Init("guard backtrace fill expand_alloc free_track leak_track");
Init(
"guard backtrace backtrace_enable_on_signal fill expand_alloc free_track leak_track "
"record_allocs verify_pointers abort_on_error verbose");
VerifyAllocCalls(true);
}
@ -667,9 +716,6 @@ TEST_F(MallocDebugTest, leak_track_no_frees_with_backtrace) {
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
expected_log += android::base::StringPrintf(
"6 malloc_debug +++ malloc_testing leaked block of size 1024 at %p (leak 1 of 3)\n",
pointer3);
expected_log += "6 malloc_debug Backtrace at time of allocation:\n";
@ -1096,10 +1142,7 @@ TEST_F(MallocDebugTest, get_malloc_leak_info_empty) {
ASSERT_EQ(0U, backtrace_size);
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
ASSERT_STREQ("", getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, get_malloc_leak_info_single) {
@ -1143,10 +1186,7 @@ TEST_F(MallocDebugTest, get_malloc_leak_info_single) {
debug_free(pointer);
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
ASSERT_STREQ("", getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, get_malloc_leak_info_multi) {
@ -1226,10 +1266,7 @@ TEST_F(MallocDebugTest, get_malloc_leak_info_multi) {
debug_free(pointers[2]);
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
ASSERT_STREQ("", getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, get_malloc_backtrace_with_header) {
@ -1261,10 +1298,7 @@ TEST_F(MallocDebugTest, get_malloc_backtrace_with_header) {
initialized = false;
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
ASSERT_STREQ("", getFakeLogPrint().c_str());
}
static std::string SanitizeHeapData(const std::string& data) {
@ -1375,9 +1409,6 @@ END
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
expected_log += android::base::StringPrintf(
"6 malloc_debug Dumping to file: /data/local/tmp/backtrace_heap.%d.txt\n\n", getpid());
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
}
@ -1649,13 +1680,7 @@ TEST_F(MallocDebugTest, backtrace_enable_on_signal) {
debug_free_malloc_leak_info(info);
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to enable backtracing.\n",
SIGRTMAX - 19, getpid());
expected_log += android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
ASSERT_STREQ("", getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, backtrace_same_stack) {
@ -1712,10 +1737,7 @@ TEST_F(MallocDebugTest, backtrace_same_stack) {
debug_free(pointers[3]);
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
ASSERT_STREQ("", getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, backtrace_same_stack_zygote) {
@ -1774,10 +1796,7 @@ TEST_F(MallocDebugTest, backtrace_same_stack_zygote) {
debug_free(pointers[3]);
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
ASSERT_STREQ("", getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, backtrace_same_stack_mix_zygote) {
@ -1844,10 +1863,7 @@ TEST_F(MallocDebugTest, backtrace_same_stack_mix_zygote) {
debug_free(pointers[3]);
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
ASSERT_STREQ("", getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, backtrace_frame_data_nullptr_same_size) {
@ -1891,10 +1907,7 @@ TEST_F(MallocDebugTest, backtrace_frame_data_nullptr_same_size) {
debug_free(pointers[3]);
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
ASSERT_STREQ("", getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, overflow) {
@ -2022,10 +2035,7 @@ TEST_F(MallocDebugTest, zygote_set) {
debug_free(pointer);
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the backtrace.\n",
SIGRTMAX - 17, getpid());
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
ASSERT_STREQ("", getFakeLogPrint().c_str());
}
TEST_F(MallocDebugTest, max_size) {
@ -2193,10 +2203,7 @@ void VerifyRecordAllocs() {
ASSERT_STREQ(expected.c_str(), actual.c_str());
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the allocation records.\n",
SIGRTMAX - 18, getpid());
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
ASSERT_STREQ("", getFakeLogPrint().c_str());
debug_free(pointer);
}
@ -2251,10 +2258,7 @@ TEST_F(MallocDebugTest, record_allocs_max) {
ASSERT_STREQ(expected.c_str(), actual.c_str());
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the allocation records.\n",
SIGRTMAX - 18, getpid());
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
ASSERT_STREQ("", getFakeLogPrint().c_str());
debug_free(pointer);
}
@ -2293,10 +2297,7 @@ TEST_F(MallocDebugTest, record_allocs_thread_done) {
ASSERT_STREQ(expected.c_str(), actual.c_str());
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the allocation records.\n",
SIGRTMAX - 18, getpid());
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());
ASSERT_STREQ("", getFakeLogPrint().c_str());
debug_free(pointer);
}
@ -2348,9 +2349,6 @@ TEST_F(MallocDebugTest, record_allocs_file_name_fail) {
ASSERT_STREQ("", getFakeLogBuf().c_str());
std::string expected_log = android::base::StringPrintf(
"4 malloc_debug malloc_testing: Run: 'kill -%d %d' to dump the allocation records.\n",
SIGRTMAX - 18, getpid());
expected_log += android::base::StringPrintf(
"6 malloc_debug Cannot create record alloc file %s: Too many symbolic links encountered\n",
RECORD_ALLOCS_FILE);
ASSERT_STREQ(expected_log.c_str(), getFakeLogPrint().c_str());