Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

perfetto_cmd.cc:840 #8

Closed
wingyippp opened this issue Feb 4, 2020 · 4 comments
Closed

perfetto_cmd.cc:840 #8

wingyippp opened this issue Feb 4, 2020 · 4 comments

Comments

@wingyippp
Copy link

wingyippp commented Feb 4, 2020

Failed to invoke perfetto: perfetto_cmd.cc:840 Failed to open /data/misc/perfetto-traces/profile-shell. If you get permission denied in /data/misc/perfetto-traces, the file might have been created by another user, try deleting it first. (errno: 2, No such file or directory)

Got this error when running the cmd "tools/heap_profile [process_name]".
My device is not rooted, so I cannot access /data/.

@wingyippp wingyippp changed the title perfetto_cmd.cc:791 perfetto_cmd.cc:840 Feb 4, 2020
@primiano
Copy link
Collaborator

primiano commented Feb 4, 2020

@wingyippp , what happens if you do adb shell rm /data/misc/perfetto-traces/profile-shell
@segfaulthunter maybe the script should use unique file names (and delete them after pull)?

@wingyippp
Copy link
Author

@wingyippp , what happens if you do adb shell rm /data/misc/perfetto-traces/profile-shell
@segfaulthunter maybe the script should use unique file names (and delete them after pull)?

adb shell rm /data/misc/perfetto-traces/profile-shell
rm: /data/misc/perfetto-traces/profile-shell: No such file or directory

Then run the cmd again "tools/heap_profile [process_name]", I got the same error show above.

P.S. My device is Android 10.0

@fmayer
Copy link
Contributor

fmayer commented Feb 4, 2020

Which device are you running on?

Could you try running adb shell setprop persist.traced.enable 1 and then retrying?

@wingyippp
Copy link
Author

Which device are you running on?

Could you try running adb shell setprop persist.traced.enable 1 and then retrying?

MY-MB2:perfetto wingyipye$ adb shell setprop persist.traced.enable 1
MY-MB2:perfetto wingyipye$ tools/heap_profile --name [process_name]
Profiling active. Press Ctrl+C to terminate.
You may disconnect your device.

Wrote profiles to /var/folders/s2/_l4q4mv16w3b_lrg1_p636jx49_ckw/T//heap_profile-ElYmfFC (symlink /var/folders/s2/_l4q4mv16w3b_lrg1_p636jx49_ckw/T/heap_profile-latest)
These can be viewed using pprof. Googlers: head to pprof/ and upload them.

It's OK now. Thank you!
My device is Galaxy S9+ (SM-G9650/DS)

primiano pushed a commit that referenced this issue Jan 12, 2023
TSAN reported the problem below on a CI run.

There's a possible sequence of events that can lead to this race (I'm
not sure it's the only one):
* The perfetto SDK thread calls the OnStop callback.
* The perfetto SDK thread is now inside WaitableTestEvent::Notify().
* The perfetto SDK thread sets notified_ to true and it unlocks the
  mutex, but does not call `cv_.notify_one()`.
* The main thread executes `WaitableTestEvent::Wait()`, which at this
  point can return.
* The main thread finishes executing the test and destroys the tracing
  sessions, which destroys the WaitableTestEvent and therefore `cv_`.
* The perfetto SDK thread resumes execution and tries to execute
  `cv_.notify_one()`, but that races with `cv_` destructor.

In order to prevent this race, we can just call `cv_.notify_one()` under
the lock. It might be less efficient, but it's correct.

This reverts part of https://r.android.com/1373304

https://ci.perfetto.dev/#!/logs/20221219192758--cls-2345694-4--linux-clang-x86_64-tsan

```
[00:07:40] [ RUN      ] PerfettoApiTest/PerfettoApiTest.TrackEventObserver_TwoDataSources/System
[00:07:40] [901.194] ing_service_impl.cc:980 Configured tracing session 1, #sources:1, duration:500 ms, #buffers:1, total buffer size:1024 KB, total sessions:1, uid:1337 session name: ""
[00:07:41] [901.697] ng_service_impl.cc:1921 FlushAndDisableTracing(1) done, success=1
[00:07:41] [901.698] ing_service_impl.cc:980 Configured tracing session 2, #sources:1, duration:500 ms, #buffers:1, total buffer size:1024 KB, total sessions:2, uid:1337 session name: ""
[00:07:41] [902.200] ng_service_impl.cc:1921 FlushAndDisableTracing(2) done, success=1
[00:07:42] ==================
[00:07:42] WARNING: ThreadSanitizer: data race (pid=7841)
[00:07:42]   Write of size 8 at 0x7b2000019c40 by main thread:
[00:07:42]     #0 pthread_cond_destroy ??:? (perfetto_integrationtests+0x315f8d) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #1 std::Cr::condition_variable::~condition_variable() ??:? (libc++.so+0xad729) (BuildId: bea413d45487d5c2)
[00:07:42]     #2 (anonymous namespace)::PerfettoApiTest::TearDown() api_integrationtest.cc:? (perfetto_integrationtests+0x398609) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #3 testing::Test::Run() ??:? (perfetto_integrationtests+0x8de94f) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #4 testing::TestInfo::Run() ??:? (perfetto_integrationtests+0x8e0a2c) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #5 testing::TestSuite::Run() ??:? (perfetto_integrationtests+0x8e1b14) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #6 testing::internal::UnitTestImpl::RunAllTests() ??:? (perfetto_integrationtests+0x8f9e3f) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #7 testing::UnitTest::Run() ??:? (perfetto_integrationtests+0x8f8d36) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #8 main api_integrationtest_main.cc:? (perfetto_integrationtests+0x4d7aa4) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]
[00:07:42]   Previous read of size 8 at 0x7b2000019c40 by thread T3:
[00:07:42]     #0 pthread_cond_signal ??:? (perfetto_integrationtests+0x315c28) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #1 std::Cr::condition_variable::notify_one() ??:? (libc++.so+0xad479) (BuildId: bea413d45487d5c2)
[00:07:42]     #2 void std::Cr::__function::__policy_invoker<void ()>::__call_impl<std::Cr::__function::__default_alloc_func<(anonymous namespace)::PerfettoApiTest::NewTrace(perfetto::protos::gen::TraceConfig const&, perfetto::BackendType, int)::{lambda()#1}, void ()> >(std::Cr::__function::__policy_storage const*) api_integrationtest.cc:? (perfetto_integrationtests+0x39ba0a) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #3 perfetto::base::UnixTaskRunner::RunImmediateAndDelayedTask() unix_task_runner.cc:? (perfetto_integrationtests+0x594cfd) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #4 perfetto::base::UnixTaskRunner::Run() unix_task_runner.cc:? (perfetto_integrationtests+0x594133) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #5 perfetto::base::ThreadTaskRunner::RunTaskThread(std::Cr::function<void (perfetto::base::UnixTaskRunner*)>) thread_task_runner.cc:? (perfetto_integrationtests+0x592e4f) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #6 void* std::Cr::__thread_proxy[abi:v160000]<std::Cr::tuple<std::Cr::unique_ptr<std::Cr::__thread_struct, std::Cr::default_delete<std::Cr::__thread_struct> >, void (perfetto::base::ThreadTaskRunner::*)(std::Cr::function<void (perfetto::base::UnixTaskRunner*)>), perfetto::base::ThreadTaskRunner*, std::Cr::function<void (perfetto::base::UnixTaskRunner*)> > >(void*) thread_task_runner.cc:? (perfetto_integrationtests+0x59380b) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]
[00:07:42]   Location is heap block of size 120 at 0x7b2000019c00 allocated by main thread:
[00:07:42]     #0 operator new(unsigned long) ??:? (perfetto_integrationtests+0x3941a7) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #1 (anonymous namespace)::PerfettoApiTest::NewTrace(perfetto::protos::gen::TraceConfig const&, int) api_integrationtest.cc:? (perfetto_integrationtests+0x39b864) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #2 (anonymous namespace)::PerfettoApiTest::NewTraceWithCategories(std::Cr::vector<std::Cr::basic_string<char, std::Cr::char_traits<char>, std::Cr::allocator<char> >, std::Cr::allocator<std::Cr::basic_string<char, std::Cr::char_traits<char>, std::Cr::allocator<char> > > >, perfetto::protos::gen::TrackEventConfig, perfetto::protos::gen::TraceConfig) api_integrationtest.cc:? (perfetto_integrationtests+0x3a6385) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #3 (anonymous namespace)::PerfettoApiTest_TrackEventObserver_TwoDataSources_Test::TestBody() api_integrationtest.cc:? (perfetto_integrationtests+0x4a61d2) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #4 testing::Test::Run() ??:? (perfetto_integrationtests+0x8de8c3) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #5 testing::TestInfo::Run() ??:? (perfetto_integrationtests+0x8e0a2c) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #6 testing::TestSuite::Run() ??:? (perfetto_integrationtests+0x8e1b14) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #7 testing::internal::UnitTestImpl::RunAllTests() ??:? (perfetto_integrationtests+0x8f9e3f) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #8 testing::UnitTest::Run() ??:? (perfetto_integrationtests+0x8f8d36) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #9 main api_integrationtest_main.cc:? (perfetto_integrationtests+0x4d7aa4) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]
[00:07:42]   Thread T3 'TracingMuxer' (tid=7845, running) created by main thread at:
[00:07:42]     #0 pthread_create ??:? (perfetto_integrationtests+0x3147ab) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #1 perfetto::base::ThreadTaskRunner::ThreadTaskRunner(std::Cr::basic_string<char, std::Cr::char_traits<char>, std::Cr::allocator<char> > const&) thread_task_runner.cc:? (perfetto_integrationtests+0x592b80) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #2 perfetto::(anonymous namespace)::PlatformPosix::CreateTaskRunner(perfetto::Platform::CreateTaskRunnerArgs const&) platform_posix.cc:? (perfetto_integrationtests+0x8c524a) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #3 perfetto::internal::TracingMuxerImpl::TracingMuxerImpl(perfetto::TracingInitArgs const&) tracing_muxer_impl.cc:? (perfetto_integrationtests+0x5a731c) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #4 perfetto::internal::TracingMuxerImpl::InitializeInstance(perfetto::TracingInitArgs const&) tracing_muxer_impl.cc:? (perfetto_integrationtests+0x5ad7fb) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #5 perfetto::Tracing::InitializeInternal(perfetto::TracingInitArgs const&) tracing.cc:? (perfetto_integrationtests+0x5c0f0d) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #6 (anonymous namespace)::ConcurrentSessionTest_ConcurrentBackends_Test::TestBody() api_integrationtest.cc:? (perfetto_integrationtests+0x4c3af4) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #7 testing::Test::Run() ??:? (perfetto_integrationtests+0x8de8c3) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #8 testing::TestInfo::Run() ??:? (perfetto_integrationtests+0x8e0a2c) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #9 testing::TestSuite::Run() ??:? (perfetto_integrationtests+0x8e1b14) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #10 testing::internal::UnitTestImpl::RunAllTests() ??:? (perfetto_integrationtests+0x8f9e3f) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #11 testing::UnitTest::Run() ??:? (perfetto_integrationtests+0x8f8d36) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]     #12 main api_integrationtest_main.cc:? (perfetto_integrationtests+0x4d7aa4) (BuildId: 2d1df55c4bda2cdd)
[00:07:42]
[00:07:42] SUMMARY: ThreadSanitizer: data race ??:? in __interceptor_pthread_cond_destroy
[00:07:42] ==================
```

Change-Id: Ic822dba258b81a6c032633cf63763bd578739024
primiano pushed a commit that referenced this issue Sep 17, 2024
Some of our integration tests are randomly failing in CI with:

```
[00:16:35] [ RUN      ] Run/HeapprofdEndToEnd.ConcurrentSession/StaticModeCustom
[00:16:35] [810.227] approfd_producer.cc:255 Disconnected from tracing service
[00:16:35] [810.428] approfd_producer.cc:255 Disconnected from tracing service
[00:16:35] [810.473] ng_service_impl.cc:1125 Configured tracing session 1, #sources:1, duration:5000 ms, #buffers:1, total buffer size:10240 KB, total sessions:1, uid:1337 session name: ""
[00:16:35] [810.829] approfd_producer.cc:245 Connected to the service, mode [child].
[00:16:35] [810.830] approfd_producer.cc:367 Setting up datasource: non-statsd initiator.
[00:16:36] [811.472] end_to_end_test.cc:1706 Starting concurrent.
[00:16:36] [811.473]      paged_memory.cc:69 PERFETTO_CHECK(ptr && ptr != MAP_FAILED) (errno: 12, Cannot allocate memory)
[00:16:36]
[00:16:36] -----BEGIN PERFETTO PRE-CRASH LOG-----
[00:16:36] trace_uuid: ccd77e58-4684-4fcd-ce84-d54022f
[00:16:36] [810.079] ng_service_impl.cc:2102 FlushAndDisableTracing(2) done, success=1
[00:16:36] [810.139] _end_to_end_test.cc:726 Stats for 16809: unwinding_errors: 0?heap_samples: 198?map_reparses: 0?unwinding_time_us: [-inf, 1]: 0; [1, 2]: 0; [2, 4]: 0; [4, 8]: 0; [8, 16]: 98; [16, 32]: 96; [32, 64]: 3; [64, 128]: 0; [128, 256]: 0; [256, 512]: 0;
[00:16:36] [810.139] _end_to_end_test.cc:842 Shutting down profile target.
[00:16:36] [810.147] ng_service_impl.cc:2713 Tracing session 2 ended, total sessions:1
[00:16:36] [810.156] ng_service_impl.cc:2713 Tracing session 1 ended, total sessions:0
[00:16:36] [810.473] ng_service_impl.cc:1125 Configured tracing session 1, #sources:1, duration:5000 ms, #buffers:1, total buffer size:10240 KB, total sessions:1, uid:1337 session name: ""
[00:16:36] [811.472] end_to_end_test.cc:1706 Starting concurrent.
[00:16:36] [811.473]      paged_memory.cc:69 PERFETTO_CHECK(ptr && ptr != MAP_FAILED) (errno: 12, Cannot allocate memory)
[00:16:36]
[00:16:36] -----END PERFETTO PRE-CRASH LOG-----
[00:16:36] [811.661] approfd_producer.cc:255 Disconnected from tracing service
[00:16:36] test/ci/linux_tests.sh: line 32: 16041 Illegal instruction     (core dumped) ${OUT_PATH}/perfetto_integrationtests
```

It turns out this as little to do with heapprofd, it's just that mmap is
not able to allocate memory in trace_processor most of the times:

```
[00:02:56] AddressSanitizer: CHECK failed: sanitizer_common.cpp:61 "((0 && "unable to mmap")) != (0)" (0x0, 0x0) (tid=13072)
[00:02:56]     #0 0x56e38cb2 in __asan::CheckUnwind() /b/s/w/ir/cache/builder/src/third_party/llvm/compiler-rt/lib/asan/asan_rtl.cpp:69:3
[00:02:56]     #1 0x56e4d5bb in __sanitizer::CheckFailed(char const*, int, char const*, unsigned long long, unsigned long long) /b/s/w/ir/cache/builder/src/third_party/llvm/compiler-rt/lib/sanitizer_common/sanitizer_termination.cpp:86:5
[00:02:56]     #2 0x56e3f580 in __sanitizer::ReportMmapFailureAndDie(unsigned int, char const*, char const*, int, bool) /b/s/w/ir/cache/builder/src/third_party/llvm/compiler-rt/lib/sanitizer_common/sanitizer_common.cpp:61:3
[00:02:56]     #3 0x56e4640b in __sanitizer::MmapOrDieOnFatalError(unsigned int, char const*) /b/s/w/ir/cache/builder/src/third_party/llvm/compiler-rt/lib/sanitizer_common/sanitizer_posix.cpp:74:5
[00:02:56]     #4 0x56da6fdd in __sanitizer::LargeMmapAllocator<__asan::AsanMapUnmapCallback, __sanitizer::LargeMmapAllocatorPtrArrayStatic, __sanitizer::LocalAddressSpaceView>::Allocate(__sanitizer::AllocatorStats*, unsigned int, unsigned int) /b/s/w/ir/cache/builder/src/third_party/llvm/compiler-rt/lib/asan/../sanitizer_common/sanitizer_allocator_secondary.h:98:9
[00:02:56]     #5 0x56da6e19 in __sanitizer::CombinedAllocator<__sanitizer::SizeClassAllocator32<__asan::AP32<__sanitizer::LocalAddressSpaceView>>, __sanitizer::LargeMmapAllocatorPtrArrayStatic>::Allocate(__sanitizer::SizeClassAllocator32LocalCache<__sanitizer::SizeClassAllocator32<__asan::AP32<__sanitizer::LocalAddressSpaceView>>>*, unsigned int, unsigned int) /b/s/w/ir/cache/builder/src/third_party/llvm/compiler-rt/lib/asan/../sanitizer_common/sanitizer_allocator_combined.h:71:24
[00:02:56]     #6 0x56da2b5b in __asan::Allocator::Allocate(unsigned int, unsigned int, __sanitizer::BufferedStackTrace*, __asan::AllocType, bool) /b/s/w/ir/cache/builder/src/third_party/llvm/compiler-rt/lib/asan/asan_allocator.cpp:582:29
[00:02:56]     #7 0x56da3668 in __asan::asan_memalign(unsigned int, unsigned int, __sanitizer::BufferedStackTrace*, __asan::AllocType) /b/s/w/ir/cache/builder/src/third_party/llvm/compiler-rt/lib/asan/asan_allocator.cpp:1060:16
[00:02:56]     #8 0x56e657a7 in operator new(unsigned int) /b/s/w/ir/cache/builder/src/third_party/llvm/compiler-rt/lib/asan/asan_new_delete.cpp:86:3
[00:02:56]     #9 0xf7dc6a49 in void* std::__Cr::__libcpp_operator_new<unsigned int>(unsigned int) /ci/ramdisk/src/out/dist/../../buildtools/libcxx/include/new:270:10
[00:02:56]     #10 0xf7dc6a49 in std::__Cr::__libcpp_allocate(unsigned int, unsigned int) /ci/ramdisk/src/out/dist/../../buildtools/libcxx/include/new:294:10
[00:02:56]     #11 0xf7dc6a49 in std::__Cr::allocator<char>::allocate(unsigned int) /ci/ramdisk/src/out/dist/../../buildtools/libcxx/include/__memory/allocator.h:119:32
[00:02:56]     #12 0xf7dc6a49 in std::__Cr::__allocation_result<std::__Cr::allocator_traits<std::__Cr::allocator<char>>::pointer> std::__Cr::__allocate_at_least<std::__Cr::allocator<char>>(std::__Cr::allocator<char>&, unsigned int) /ci/ramdisk/src/out/dist/../../buildtools/libcxx/include/__memory/allocate_at_least.h:41:19
[00:02:56]     #13 0xf7dc6a49 in std::__Cr::basic_string<char, std::__Cr::char_traits<char>, std::__Cr::allocator<char>>::__grow_by(unsigned int, unsigned int, unsigned int, unsigned int, unsigned int, unsigned int) /ci/ramdisk/src/out/dist/../../buildtools/libcxx/include/string:2426:23
```

I've looked at the virtual address space and it's very fragmented, the
ASAN allocator seems to leave around a lot of 1MB sections.

I'm assuming that ASAN on 32-bit devices is harder to support because of
the limited amount of address space.

We don't really need 32-bit coverage for ASAN, we have 64-bit coverage
for ASAN (and 32-bit ASAN on android is becoming less relevant with
HWASAN).

Let's use this configuration to have some coverage for a 32-bit build.

Change-Id: I02ed354757874dd51b0c1c2b739d91e3c6584119
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants