From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 87934 invoked by alias); 21 Mar 2018 14:23:59 -0000 Mailing-List: contact elfutils-devel-help@sourceware.org; run by ezmlm Precedence: bulk List-Id: List-Post: List-Help: List-Subscribe: Sender: elfutils-devel-owner@sourceware.org Received: (qmail 87798 invoked by uid 89); 21 Mar 2018 14:23:57 -0000 Authentication-Results: sourceware.org; auth=none X-Virus-Checked: by ClamAV 0.99.4 on sourceware.org X-Virus-Found: No X-Spam-SWARE-Status: No, score=-24.1 required=5.0 tests=AWL,BAYES_00,GIT_PATCH_0,GIT_PATCH_1,GIT_PATCH_2,GIT_PATCH_3,KAM_LAZY_DOMAIN_SECURITY,KAM_SHORT,RCVD_IN_DNSWL_LOW autolearn=ham version=3.3.2 spammy=investigate, interestingly, mod, H*Ad:U*mark X-Spam-Status: No, score=-24.1 required=5.0 tests=AWL,BAYES_00,GIT_PATCH_0,GIT_PATCH_1,GIT_PATCH_2,GIT_PATCH_3,KAM_LAZY_DOMAIN_SECURITY,KAM_SHORT,RCVD_IN_DNSWL_LOW autolearn=ham version=3.3.2 X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on sourceware.org X-Spam-Level: X-HELO: dd17628.kasserver.com Received: from dd17628.kasserver.com (HELO dd17628.kasserver.com) (85.13.138.83) by sourceware.org (qpsmtpd/0.93/v0.84-503-g423c35a) with ESMTP; Wed, 21 Mar 2018 14:23:54 +0000 Received: from agathebauer.localnet (ip5f5bf42a.dynamic.kabel-deutschland.de [95.91.244.42]) by dd17628.kasserver.com (Postfix) with ESMTPSA id 209D36280F50; Wed, 21 Mar 2018 15:23:52 +0100 (CET) From: Milian Wolff To: elfutils-devel@sourceware.org Cc: Mark Wielaard Subject: Re: How to associate Elf with Dwfl_Module returned by dwfl_report_module Date: Wed, 21 Mar 2018 14:23:00 -0000 Message-ID: <1581387.j5xz9UsgaX@agathebauer> In-Reply-To: <1946852.ajpeOdNFGP@agathebauer> References: <3517953.ztkfjMdy38@agathebauer> <20180320220549.GD6269@wildebeest.org> <1946852.ajpeOdNFGP@agathebauer> MIME-Version: 1.0 Content-Type: multipart/signed; boundary="nextPart1773773.Hdl18Jak2Y"; micalg="pgp-sha256"; protocol="application/pgp-signature" X-IsSubscribed: yes X-SW-Source: 2018-q1/txt/msg00094.txt.bz2 --nextPart1773773.Hdl18Jak2Y Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset="iso-8859-1" Content-length: 5449 On Mittwoch, 21. M=E4rz 2018 14:01:41 CET Milian Wolff wrote: > On Dienstag, 20. M=E4rz 2018 23:05:49 CET Mark Wielaard wrote: > > Hi Milian, >=20 > Hey Mark :) >=20 > > On Sat, Mar 17, 2018 at 02:14:48PM +0100, Milian Wolff wrote: > > > a recurring issue in the libdwfl integration of perf and perfparser a= re > > > supposedly overlapping modules. The perf data file contains the exact > > > mappings for all files corresponding to the actual mmap events that > > > occurred during runtime, e.g.: > > >=20 > > > ``` > > > $ perf script --show-mmap-events | grep MMAP | grep stdc > > > heaptrack_print 13962 87163.483450: PERF_RECORD_MMAP2 13962/13962: > > > [0x7fd0aea84000(0x387000) @ 0 08:03 413039 3864781083]: r-xp > > > /usr/lib/libstdc+ +.so.6.0.24 > > > heaptrack_print 13962 87163.483454: PERF_RECORD_MMAP2 13962/13962: > > > [0x7fd0aebfc000(0x1ff000) @ 0x178000 08:03 413039 3864781083]: ---p > > > /usr/lib/ libstdc++.so.6.0.24 > > > heaptrack_print 13962 87163.483458: PERF_RECORD_MMAP2 13962/13962: > > > [0x7fd0aedfb000(0xd000) @ 0x177000 08:03 413039 3864781083]: rw-p > > > /usr/lib/ > > > libstdc++.so.6.0.24 > > > heaptrack_print 13962 87163.484860: PERF_RECORD_MMAP2 13962/13962: > > > [0x7fd0aedfb000(0xc000) @ 0x177000 08:03 413039 3864781083]: r--p > > > /usr/lib/ > > > libstdc++.so.6.0.24 > > > ``` > > > So far, both perf and perfparser are using dwfl_report_elf to report = the > > > file. But that API is deducing the mapping addresses internally, which > > > may or may not be what we saw at runtime. I suspect that this is the > > > reason for some issues we are seeing, such as supposedly overlapping > > > modules. > >=20 > > How exactly are you calling dwfl_report_elf? >=20 > Here's the code for the perf tools: >=20 > https://git.kernel.org/pub/scm/linux/kernel/git/acme/linux.git/tree/tools/ > perf/util/unwind-libdw.c?h=3Dperf/core#n52 >=20 > Here's the code for the perfparser: >=20 > http://code.qt.io/cgit/qt-creator/perfparser.git/tree/app/ > perfsymboltable.cpp#n479 >=20 > Let's concentrate on perf for now, but perfparser has similar logic: >=20 > We parse the mmap events in the perf.data file and store that information. > Note that the perf.data file does not contain events for munmap calls. Th= en > while unwinding the callstack of a perf sample, we lookup the most recent > mmap event for every given instruction pointer address, and ensure that t= he > corresponding ELF was registered with libdw. >=20 > > Specifically are you using false for the add_p_vaddr argument? >=20 > Yes, we are. >=20 > > And could you provide some example where the reported address is > > wrong/different from the start address of the Dwfl_Module? >=20 > I don't think it's the start address that is wrong, rather it's the end > address. But it's hard for me to come up with a small selfcontained examp= le > at this stage. I am regularly seeing broken backtraces for samples where I > have the gut feeling that missing reported ELFs are to blame. But we repo= rt > everything, except for scenarios where the mmap events seemingly overlap. > This overlapping is, as far as I can see, actually a side effect of > remapping taking place in the dynamic linker (i.e. a single dlopen/dynamic > linked library can yield multiple mmap events). One way or another, we end > up with a situation where we cannot report an ELF to dwfl due to two > issues: >=20 > a) either ELF tells us we are overlapping some module and just stops which > is bad, since we would actually much prefer the newly reported ELF to take > precedence >=20 > b) we find an mmap event that with a non-zero pgoff, and have no clue how= to > call dwfl_report_elf and just give up. >=20 > In both cases, I was hopeing for dwfl_report_module to help since it > seemingly allows me to exactly recreate the mapping that was traced > originally. Here's one way to investigate where perf and dwfl disagree on the file=20 mappings: diff --git a/tools/perf/util/unwind-libdw.c b/tools/perf/util/unwind-libdw.c index 7bdd239c795c..739c68b73772 100644 --- a/tools/perf/util/unwind-libdw.c +++ b/tools/perf/util/unwind-libdw.c @@ -48,11 +48,17 @@ static int __report_module(struct addr_location *al, u6= 4=20 ip, mod =3D 0; } =20 - if (!mod) + if (!mod) { + Dwarf_Addr s, e; mod =3D dwfl_report_elf(ui->dwfl, dso->short_name, (dso->symsrc_filename ? dso->symsrc_filename : dso- >long_name), -1, al->map->start, false); =20 + dwfl_module_info(mod, NULL, &s, &e, NULL, NULL, NULL, NULL); + if (al->map->start !=3D s || al->map->end !=3D e) + pr_warning("MEH: %s | mmap: %zx %zx | dwfl: %zx %zx\n", dso- >short_name, al->map->start, al->map->end, s, e); + } + return mod && dwfl_addrmodule(ui->dwfl, ip) =3D=3D mod ? 0 : -1; } =20 On one of my perf.data files with many broken backtraces this gives me: MEH: heaptrack_print | mmap: 56166e9d4000 56166ea39000 | dwfl: 56166e9d4000= =20 56166ea38880 MEH: ld-2.26.so | mmap: 7fd0afc6c000 7fd0afe93000 | dwfl: 7fd0afc6c000=20 7fd0afe920f8 MEH: libc-2.26.so | mmap: 7fd0ae16a000 7fd0ae521000 | dwfl: 7fd0ae16a000=20 7fd0ae5208f0 MEH: libstdc++.so.6.0.24 | mmap: 7fd0aea84000 7fd0aee0b000 | dwfl:=20 7fd0aea84000 7fd0aee0a640 MEH: libzstd.so.1.3.3 | mmap: 7fd0aee0b000 7fd0af087000 | dwfl: 7fd0aee0b00= 0=20 7fd0af086030 Interestingly, here the mmap events observed by perf are actually always=20 *larger* than what dwfl sees... --=20 Milian Wolff mail@milianw.de http://milianw.de= --nextPart1773773.Hdl18Jak2Y Content-Type: application/pgp-signature; name="signature.asc" Content-Description: This is a digitally signed message part. Content-Transfer-Encoding: 7Bit Content-length: 833 -----BEGIN PGP SIGNATURE----- iQIzBAABCAAdFiEEezawi1aUvUGg3A1+8zYW/HGdOX8FAlqyavcACgkQ8zYW/HGd OX8VlxAAj3CTiT1a6mXvoslbA89LV8+Z0tU9u9t3ex5bXWN2LojrRCd55wuE8lQ6 U5kHzncLnkHy1Fq/MHUKPfyQefpmukcYRMoctmfMDKwENl3MAo/LoH5QM+qFlZqf hakMTChKQneVbwNDXresGysYqcJteQNj4dh/vO4MaUCW/VL+dtt2umQ+Ud1g2Skx weCst6p9iMqEXTrWuMRMSYbN5jhBSkFDSaQ5JtJFdqUopUQHuczv4xarHw63smAv K369fLCssDPGHyGqCxih/2JYb4/HXXvNCv5ZPM5etysIE/UUX1CYIO8XTSSPyJEt OW5aE8yS3UJcul3kVILCbbiJAqOwffHElHZTWbFOPH3L+IAM1tZUMtdvfTsmxwDY hHfh7aP7MoD9ecgUIyXxywQxBpZMywuS8CQLu5ReNxLYdCd4mpZa5Rfwm/A8yYRx W1j+ny37MGb/XcG5PRaWuTnMsW//TcCMVei83k6PzIM8EvzqR0ICS0/tQ9IEGD6e rUY2fi6mm0Oy+4Tva9pKvmSeiWtifyENz32IS2aS1J/8siirJTQZ7KVpiadQDiDM ILuN3AG992pPQtVrbc90l49ShqwFrrP/+aYUdKyaQlb4SnAICg3EfN9p2Th5JM98 Dpa7DEOnZESntMee36STXTkfXhfQ4knBkkNzfJZjPxpClud0Vc8= =qrLi -----END PGP SIGNATURE----- --nextPart1773773.Hdl18Jak2Y--