aboutsummaryrefslogtreecommitdiff
path: root/libc/bionic/bionic_systrace.cpp
Commit message (Collapse)AuthorAgeFilesLines
* Fix recursive deadlock inside bionic_systraceDaniele Di Proietto2022-01-251-2/+34
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | The first time should_trace() returns true, bionic_trace_begin() calls open() on trace_marker. The problem is that open() can call bionic_trace_begin(). We've observed this happening, for example when: * fdtrack is enabled. dlopen("libfdtrack.so") can be used to enable fdtrack on a process. * ThreadA is busy unwinding inside fdtrack and is holding an fdtrack internal mutex. * ThreadB calls bionic_trace_begin() for the first time since the property "debug.atrace.tags.enableflags" contains ATRACE_TAG_BIONIC. * ThreadB calls open("/sys/kernel/tracing/trace_marker"). Since fdtrack is enabled, ThreadB tries to do unwinding as well. * ThreadB, inside fdtrack's unwinding tries to grab the same mutex that ThreadA is holding. * Mutex contention is reported using bionic_systrace, therefore bionic_trace_begin() is called again on ThreadB. * ThreadB tries to grab g_lock in bionin_systrace.cpp, but that's already held by ThreadB itself, earlier on the stack. Therefore ThreadB is stuck. I managed to reproduce the above scenario by manually pausing ThreadA inside unwinding with a debugger and letting ThreadB hitting bionic_trace_begin() for the first time. We could avoid using g_lock while calling open() (either by releasing g_lock and reacquiring it later, or by using atomics), but bionic_trace_begin() would try to call open() again. In my tests, open() does not call bionic_trace_begin() a third time, because fdtrack has reentrancy protection, but there might be another code path inside open that calls bionic_trace_begin again (it could be racy or only happen in certain configurations). This commit fixes the problem by implementing reentrancy protection in bionic_systrace. Sample callstack from ThreadA deadlocked before the fix: ``` * frame #0: 0x0000007436db077c libc.so`syscall at syscall.S:41 frame #1: 0x0000007436db0ba0 libc.so`bionic_trace_begin(char const*) [inlined] __futex(ftx=0x000000743737a548, op=<unavailable>, value=2, timeout=0x0000000000000000, bitset=-1) at bionic_futex.h:45:16 frame #2: 0x0000007436db0b8c libc.so`bionic_trace_begin(char const*) [inlined] __futex_wait_ex(ftx=0x000000743737a548, value=2) at bionic_futex.h:66:10 frame #3: 0x0000007436db0b78 libc.so`bionic_trace_begin(char const*) [inlined] Lock::lock(this=0x000000743737a548) at bionic_lock.h:67:7 frame #4: 0x0000007436db0b74 libc.so`bionic_trace_begin(char const*) [inlined] should_trace() at bionic_systrace.cpp:38:10 frame #5: 0x0000007436db0b74 libc.so`bionic_trace_begin(message="Contending for pthread mutex") at bionic_systrace.cpp:59:8 frame #6: 0x0000007436e193e4 libc.so`NonPI::MutexLockWithTimeout(pthread_mutex_internal_t*, bool, timespec const*) [inlined] NonPI::NormalMutexLock(mutex=0x0000007296cae9f0, shared=0, use_realtime_clock=false, abs_timeout_or_null=0x0000000000000000) at pthread_mutex.cpp:592:17 frame #7: 0x0000007436e193c8 libc.so`NonPI::MutexLockWithTimeout(mutex=0x0000007296cae9f0, use_realtime_clock=false, abs_timeout_or_null=0x0000000000000000) at pthread_mutex.cpp:719:16 frame #8: 0x0000007436e1912c libc.so`::pthread_mutex_lock(mutex_interface=<unavailable>) at pthread_mutex.cpp:839:12 [artificial] frame #9: 0x00000071a4e5b290 libfdtrack.so`std::__1::mutex::lock() [inlined] std::__1::__libcpp_mutex_lock(__m=<unavailable>) at __threading_support:256:10 frame #10: 0x00000071a4e5b28c libfdtrack.so`std::__1::mutex::lock(this=<unavailable>) at mutex.cpp:31:14 frame #11: 0x00000071a4e32634 libfdtrack.so`unwindstack::Elf::Step(unsigned long, unwindstack::Regs*, unwindstack::Memory*, bool*, bool*) [inlined] std::__1::lock_guard<std::__1::mutex>::lock_guard(__m=0x0000007296cae9f0) at __mutex_base:104:27 frame #12: 0x00000071a4e32618 libfdtrack.so`unwindstack::Elf::Step(this=0x0000007296cae9c0, rel_pc=66116, regs=0x0000007266ca0470, process_memory=0x0000007246caa130, finished=0x0000007ff910efb4, is_signal_frame=0x0000007ff910efb0) at Elf.cpp:206:31 frame #13: 0x00000071a4e2b3b0 libfdtrack.so`unwindstack::LocalUnwinder::Unwind(this=0x00000071a4ea1528, frame_info=<unavailable>, max_frames=34) at LocalUnwinder.cpp:102:22 frame #14: 0x00000071a4e2a3ec libfdtrack.so`fd_hook(event=<unavailable>) at fdtrack.cpp:119:18 frame #15: 0x0000007436dbf684 libc.so`::__open_2(pathname=<unavailable>, flags=<unavailable>) at open.cpp:72:10 frame #16: 0x0000007436db0a04 libc.so`bionic_trace_begin(char const*) [inlined] open(pathname=<unavailable>, flags=524289) at fcntl.h:63:12 frame #17: 0x0000007436db09f0 libc.so`bionic_trace_begin(char const*) [inlined] get_trace_marker_fd() at bionic_systrace.cpp:49:25 frame #18: 0x0000007436db09c0 libc.so`bionic_trace_begin(message="pthread_create") at bionic_systrace.cpp:63:25 ``` Bug: 213642769 Change-Id: I10d331859045cb4a8609b007f5c6cf2577ff44df
* bionic: fix broken end atrace eventsLalit Maganti2021-09-291-1/+15
| | | | | | | | | | | | | | | | | | | When calling write on an FD for trace_marker, it is expected that the pointer passed will be paged into memory. If this isn't the case, the kernel will ignore the string passed and instead write "<faulted>" to the ring buffer. For end events, we were passing a constant string which resides in the rodata section of the ELF file. If this section is paged out, we end up not closing atrace stacks correctly leading to very broken traces. For even more context, see the associated bug. Fix this issue by reading the constant string to the stack first which should mean the string is always paged in. Bug: 197620214 Change-Id: I6a444ac6fe83a6a9fb696c5621e392eca7e9437a
* Revert "Adding system property tracing"Bowgo Tsai2021-07-211-27/+16
| | | | | | | | | | | | | | | | | 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 61a5a8380d6417e9b85bb2f6a4a694ef4222031f)
* Revert "bionic_systrace: moving global static variables"Bowgo Tsai2021-07-211-11/+15
| | | | | | | | | | | | This reverts commit 1e1c7845aab0542306f61d8e8c880aca096ea336. Reason for revert: makes property get/set non-reentrant Bug: 193050299 Test: build and boot a device Change-Id: If59e3dc25684a3c2b1d3ff74f995311afe6c6e89 Merged-In: If59e3dc25684a3c2b1d3ff74f995311afe6c6e89 (cherry picked from commit 3ec21f527acbaefb5f7a114125bc7a93baa780c7)
* bionic_systrace: moving global static variablesBowgo Tsai2020-08-251-15/+11
| | | | | | | | | | | | | | | | | | | | | | Some global static variables are only used within a single function, so moving them inside the function which requires them. This also ensures those static variables of class types are initialized before they are being used. For example, this is needed for CachedProperty(), as some of the member method, e.g., CachedProperty().Get(), might be invoked, e.g., in __libc_preinit(), before the constructor is invoked. This happens after we added property trace points in commit Id2b93acb2ce02b308c0e4889f836159151af3b46. For g_lock, we don't move them because it can be initialized by setting its memory to 0. And it's used in two functions. https://android.googlesource.com/platform/bionic/+/refs/heads/master/libc/private/bionic_lock.h Bug: 147275573 Test: atest CtsBionicTestCases Test: adb shell perfetto -o /data/misc/perfetto-traces/test_trace -t 10s bionic sysprop Change-Id: I99565ce2442d34f33830778915c737eed834f8b3
* Adding system property tracingBowgo Tsai2020-08-191-16/+27
| | | | | | | | | | | | | | | | | | | | | | | Introducing a new systrace tag, TRACE_TAG_SYSPROP, for use with system property. For property set, the tracing is added in __system_property_set() instead of __system_property_update() / __system_property_add() so we can record control properties like ctl.*, sys.powerctl.*, etc.., which won't be updated via the latter two functions. Bug: 147275573 Test: atest CtsBionicTestCases Test: adb shell perfetto -o /data/misc/perfetto-traces/test_trace -t 10s bionic Test: adb shell perfetto -o /data/misc/perfetto-traces/test_trace -t 10s sysprop Test: adb shell /data/benchmarktest64/bionic-benchmarks/bionic-benchmarks \ --benchmark_filter=BM_property --bionic_cpu=4, then compares the results of property benchmarks before and after the change, didn't see significant difference. Change-Id: Id2b93acb2ce02b308c0e4889f836159151af3b46 Merged-In: Id2b93acb2ce02b308c0e4889f836159151af3b46 (cherry picked from commit 26970c34937e2339876d6ba335a56769d6f0d75e)
* bionic: Check /sys/kernel/tracing for tracefsHridya Valsaraju2020-02-071-1/+4
| | | | | | | | | tracefs will be mounted at /sys/kernel/tracing when debugfs is not mounted. Bug: 134669095 Test: atest bionic-unit-tests-static Change-Id: Ic224cf13500efc570da8b6a27ce925bbcf068fdd
* Avoid calling snprintf in bionic_trace_begin.Josh Gao2019-07-111-1/+2
| | | | | | | | | | | snprintf always calls free (on a null pointer) in its epilogue, which results in infinite recursion if free calls a function that calls bionic_trace_begin (e.g. when perfetto attempts to lock a mutex in RecordFree). Bug: http://b/137284735 Test: treehugger Change-Id: I51c5b32e8f4e394be4602e06c7b94797df73c37b
* Make trace end conform with other trace end printsPhilip Cuadra2019-01-281-1/+1
| | | | | | | Add | to make bionic's trace end print match other trace end prints. Test: took systrace with bionic tag enabled Change-Id: Ieabb139dd224aa8045be914f21c0432d42a93755
* Move static variable out of should_trace().Wei Li2018-01-261-3/+2
| | | | | | | | | | | | | | | | | | | | | | | | | | Static variable initialization calls pthread_mutex_lock() and may lead to deadlock if should_trace() is called in pthread_mutex_lock context. Here is a stack of blocked init process: __cxa_guard_acquire -> should_trace -> bionic_trace_begin -> __pthread_mutex_lock_with_timeout -> __cxa_guard_release -> should_trace -> bionic_trace_begin -> __pthread_mutex_lock_with_timeout -> mutex::lock -> LogMessage::~LogMessage ...... So we need to move it out Test: 1 Compiled and booted. 2 Reboot pressure test for more than 30000 times. Change-Id: I8d97745161f1aa8942b63338208ea74830768ae1 Signed-off-by: Wei Li <sirius.liwei@huawei.com> Signed-off-by: Jinguang Dong <dongjinguang@huawei.com>
* Move libc_log code into libasync_safe.Christopher Ferris2017-05-031-1/+0
| | | | | | | | | | | | | | | | | | This library is used by a number of different libraries in the system. Make it easy for platform libraries to use this library and create an actual exported include file. Change the names of the functions to reflect the new name of the library. Run clang_format on the async_safe_log.cpp file since the formatting is all over the place. Bug: 31919199 Test: Compiled for angler/bullhead, and booted. Test: Ran bionic unit tests. Test: Ran the malloc debug tests. Change-Id: I8071bf690c17b0ea3bc8dc5749cdd5b6ad58478a
* Move bionic_systrace.cpp over to CachedProperty.Elliott Hughes2017-04-171-38/+8
| | | | | | | | | This is the last bionic caller that was manually trying to cache property values. Bug: N/A Test: builds and boots Change-Id: Id66c0a05d8448f08c39dbf7189241e75615d44b4
* Add end() method to bionic's ScopedTrace classDimitry Ivanov2017-03-201-7/+24
| | | | | | Bug: http://b/27195126 Test: make Change-Id: I8243629200606ca87b11cbd479ca093add42eb56
* Do not set properties in bionic_systraceTom Cherry2015-12-101-16/+14
| | | | | | | | | | | | | | | | | Currently, if the debug.atrace.tags.enableflags property is not found, it is set to a safe value such that a pointer to this property can be stored for later access. This may result in selinux denials because not all processes write permissions for this property or permission to connect to the property write socket at all. Change I6d953c0c281fd72ad3eba8a479fd258023579b5b writes this property to a safe value upon boot, which greatly decreases the cases in which this property will not be accessible and removes the need to write it here. This commit removes this write. Bug 26115803 Change-Id: Ief72c5f731d3a1231b5080eb531fa0a491a8b1d1
* Don't abort when failed to write tracing message.Yabin Cui2015-07-221-38/+47
| | | | | | | Also make the code thread-safe with lock. Bug: 20666100 Change-Id: I0f331a617b75280f36179c187418450230d713ef
* Add missing includes.Elliott Hughes2015-01-281-0/+1
| | | | Change-Id: Ibf549266a19a67eb9158d341a69dddfb654be669
* Remove bogus transitive includes.Elliott Hughes2014-12-291-0/+1
| | | | | | | <signal.h> shouldn't get you the contents of <errno.h>, and <fcntl.h> shouldn't get you the contents of <unistd.h>. Change-Id: I347499cd8671bfee98e6b8e875a97cab3a3655d3
* More cases where libc should use O_CLOEXEC.Elliott Hughes2014-08-261-1/+1
| | | | Change-Id: Idfa111aeebc5deca2399dae919e8b72eb54c23c0
* Added a bionic systrace class and tracing to pthread_mutex.cpp.Brigid Smith2014-07-281-0/+107
bionic_systrace.h contains an implementation of tracing that can be used with systrace.py and its associated viewer. pthread_mutex now uses this tracing to track pthread_mutex contention, which can be enabled by using the "bionic" command line option to systrace. Bug: 15116468 Change-Id: I30ed5b377c91ca4c36568a0e647ddf95d4e4a61a
generated by cgit v1.2.3 (git 2.25.1) at 2026-01-14 08:06:50 +0000