From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from smtp-out1.suse.de (smtp-out1.suse.de [195.135.220.28]) by sourceware.org (Postfix) with ESMTPS id 4BA9A385AC3C for ; Wed, 17 Nov 2021 09:22:39 +0000 (GMT) DMARC-Filter: OpenDMARC Filter v1.4.1 sourceware.org 4BA9A385AC3C Received: from imap2.suse-dmz.suse.de (imap2.suse-dmz.suse.de [192.168.254.74]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature ECDSA (P-521) server-digest SHA512) (No client certificate requested) by smtp-out1.suse.de (Postfix) with ESMTPS id 50C76212CB; Wed, 17 Nov 2021 09:22:38 +0000 (UTC) Received: from imap2.suse-dmz.suse.de (imap2.suse-dmz.suse.de [192.168.254.74]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature ECDSA (P-521) server-digest SHA512) (No client certificate requested) by imap2.suse-dmz.suse.de (Postfix) with ESMTPS id 37B7C13780; Wed, 17 Nov 2021 09:22:38 +0000 (UTC) Received: from dovecot-director2.suse.de ([192.168.254.65]) by imap2.suse-dmz.suse.de with ESMTPSA id t7tsDN7JlGFydQAAMHmgww (envelope-from ); Wed, 17 Nov 2021 09:22:38 +0000 Subject: Re: [PATCH v2 00/32] Rewrite the DWARF "partial" reader To: Tom Tromey Cc: gdb-patches@sourceware.org References: <20211104180907.2360627-1-tom@tromey.com> <4a288a6a-63c4-e36e-da20-01ae3fd0955c@suse.de> <87a6i31woz.fsf@tromey.com> From: Tom de Vries Message-ID: Date: Wed, 17 Nov 2021 10:22:37 +0100 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101 Thunderbird/78.12.0 MIME-Version: 1.0 In-Reply-To: <87a6i31woz.fsf@tromey.com> Content-Type: text/plain; charset=utf-8 Content-Language: en-US Content-Transfer-Encoding: 7bit X-Spam-Status: No, score=-7.1 required=5.0 tests=BAYES_00, DKIM_SIGNED, DKIM_VALID, DKIM_VALID_AU, DKIM_VALID_EF, NICE_REPLY_A, SPF_HELO_NONE, SPF_PASS, TXREP autolearn=ham autolearn_force=no version=3.4.4 X-Spam-Checker-Version: SpamAssassin 3.4.4 (2020-01-24) on server2.sourceware.org X-BeenThere: gdb-patches@sourceware.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: Gdb-patches mailing list List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 17 Nov 2021 09:22:41 -0000 On 11/17/21 12:56 AM, Tom Tromey wrote: > Tom> This triggered a fair amount of times: > Tom> ... > Tom> $ grep -c "has duplicate debug_info_offset 0x0, ignoring .debug_aranges" LOG > Tom> 40 > > I think this is something of a latent bug, and the fix I applied is to > skip DWZ units in this loop. I don't think .debug_aranges can refer to > a CU coming from the DWZ file. > Ack, that makes sense to me. > Tom> $ grep -c "DW_FORM_GNU_strp_alt used without .debug_str" LOG > Tom> 16 > Tom> ... > > I think this happens because I failed to consider DWZ files in the > pre-reading patch. I've applied a fix to pre-read some of the debug > sections from this file. I couldn't reproduce the bug myself. > Both problems are gone in the latest version, thanks. > I really appreciate the testing you've done. No problem :) > I'll send v3 of the series > once I do some more testing... I plan to regression test with a few > different approaches (dwz, probably split DWARF too). Meanwhile the > unpolished version is on the 'submit/no-more-psym' branch in my github. > I've done now the experiment I set out to do: I build with -O2 two configurations: - merge-base (git merge-base master no-more-psym) - no-more-psym and ran the loop over .debug files, twice (with gdb worker-threads defaulting to 4 on my dual-core-4-thread CPU). results merge-base: real 2m44.899s user 2m43.299s sys 0m11.635s real 2m44.451s user 2m43.121s sys 0m11.515s results no-more-psym: real 1m47.708s user 2m0.686s sys 0m12.500s real 1m47.426s user 2m0.960s sys 0m12.089s That's 35% real time reduction on average. Then I picked the largest file: /usr/lib/debug/usr/lib64/libLLVM.so.10-10.0.1-lp152.35.10.x86_64.debug, and used just that one. results merge-base: real 0m35.661s user 0m35.654s sys 0m0.172s real 0m35.692s user 0m35.654s sys 0m0.207s results no-more-psym: real 0m13.268s user 0m18.084s sys 0m0.620s real 0m13.362s user 0m18.181s sys 0m0.582s That's a 62% real time reduction. Interesting to see that in both comparisons we have speedup because of: - doing less (decrease in user time) - doing things in parallel (real < user) Indeed, switching off parallelism using "maint set worker-threads 0" while redoing the last measurement still gives us a nice speedup: real 0m15.498s user 0m15.120s sys 0m0.380s real 0m15.540s user 0m15.152s sys 0m0.401s Thanks, - Tom