From patchwork Wed Oct 1 19:44:39 2014 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Jan Kratochvil X-Patchwork-Id: 3058 Received: (qmail 21094 invoked by alias); 1 Oct 2014 19:44:49 -0000 Mailing-List: contact gdb-patches-help@sourceware.org; run by ezmlm Precedence: bulk List-Id: List-Unsubscribe: List-Subscribe: List-Archive: List-Post: List-Help: , Sender: gdb-patches-owner@sourceware.org Delivered-To: mailing list gdb-patches@sourceware.org Received: (qmail 21083 invoked by uid 89); 1 Oct 2014 19:44:48 -0000 Authentication-Results: sourceware.org; auth=none X-Virus-Found: No X-Spam-SWARE-Status: No, score=-3.5 required=5.0 tests=AWL, BAYES_00, KAM_STOCKGEN, RP_MATCHES_RCVD, SPF_HELO_PASS, SPF_PASS autolearn=no version=3.3.2 X-HELO: mx1.redhat.com Received: from mx1.redhat.com (HELO mx1.redhat.com) (209.132.183.28) by sourceware.org (qpsmtpd/0.93/v0.84-503-g423c35a) with (AES256-GCM-SHA384 encrypted) ESMTPS; Wed, 01 Oct 2014 19:44:46 +0000 Received: from int-mx13.intmail.prod.int.phx2.redhat.com (int-mx13.intmail.prod.int.phx2.redhat.com [10.5.11.26]) by mx1.redhat.com (8.14.4/8.14.4) with ESMTP id s91JijkP016450 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-GCM-SHA384 bits=256 verify=FAIL) for ; Wed, 1 Oct 2014 15:44:45 -0400 Received: from host2.jankratochvil.net (ovpn-116-49.ams2.redhat.com [10.36.116.49]) by int-mx13.intmail.prod.int.phx2.redhat.com (8.14.4/8.14.4) with ESMTP id s91JieTx023396 (version=TLSv1/SSLv3 cipher=AES128-GCM-SHA256 bits=128 verify=NO) for ; Wed, 1 Oct 2014 15:44:43 -0400 Date: Wed, 1 Oct 2014 21:44:39 +0200 From: Jan Kratochvil To: gdb-patches@sourceware.org Subject: [patch] Fix 100x slowdown regression on DWZ files Message-ID: <20141001194439.GA15161@host2.jankratochvil.net> MIME-Version: 1.0 Content-Disposition: inline User-Agent: Mutt/1.5.23 (2014-03-12) X-IsSubscribed: yes Hi, Bug 16405 - backtrace takes GBs and minutes with dwz -m (edit) https://sourceware.org/bugzilla/show_bug.cgi?id=16405 Since Fedora started to use DWZ DWARF compressor: http://fedoraproject.org/wiki/Features/DwarfCompressor GDB has slowed down a lot. To make it clear - DWZ is DWARF structure rearrangement, "compressor" does not mean any zlib style data compression. This patch reduces LibreOffice backtrace from 5 minutes to 3 seconds (100x) and it also reduces memory consumption 20x. [ benchmark is at the bottom of this mail ] Example of DWZ output: ------------------------------------------------------------------------------ Compilation Unit @ offset 0xc4: <0>: Abbrev Number: 17 (DW_TAG_partial_unit) DW_AT_stmt_list : 0x0 DW_AT_comp_dir : (indirect string, offset: 0x6f): /usr/src/debug/gdb-7.7.1/build-x86_64-redhat-linux-gnu/gdb <1>: Abbrev Number: 9 (DW_TAG_typedef) DW_AT_name : (indirect string, offset: 0x827dc): size_t
DW_AT_decl_file : 4 DW_AT_decl_line : 212 DW_AT_type : <0xae> Compilation Unit @ offset 0xe4: <0>: Abbrev Number: 13 (DW_TAG_partial_unit) DW_AT_stmt_list : 0x0 DW_AT_comp_dir : (indirect string, offset: 0x6f): /usr/src/debug/gdb-7.7.1/build-x86_64-redhat-linux-gnu/gdb <1>: Abbrev Number: 45 (DW_TAG_typedef) DW_AT_name : (indirect string, offset: 0x251): __off_t DW_AT_decl_file : 3 DW_AT_decl_line : 131 DW_AT_type : <0x68> Compilation Unit @ offset 0x62d9f9: <0><62da04>: Abbrev Number: 20 (DW_TAG_compile_unit) [...] <62da12> DW_AT_low_pc : 0x807e10 <62da1a> DW_AT_high_pc : 134 <62da1c> DW_AT_stmt_list : 0xf557e <1><62da20>: Abbrev Number: 7 (DW_TAG_imported_unit) <62da21> DW_AT_import : <0xcf> [Abbrev Number: 17] ------------------------------------------------------------------------------ One can see all DW_TAG_partial_unit have DW_AT_stmt_list 0x0 which causes repeated decoding of that .debug_line unit on each DW_TAG_imported_unit. This was OK before as each DW_TAG_compile_unit has its own .debug_line unit. But since the introduction of DW_TAG_partial_unit by DWZ one should cache read-in DW_AT_stmt_list .debug_line units. Fortunately one does not need to cache whole struct linetable *symtab->linetable and other data from .debug_line mapping PC<->lines ------------------------------------------------------------------------------ Line Number Statements: Extended opcode 2: set Address to 0x45c880 Advance Line by 25 to 26 Copy ------------------------------------------------------------------------------ as the only part of .debug_line which GDB needs for DW_TAG_partial_unit is: ------------------------------------------------------------------------------ The Directory Table: ../../gdb /usr/include/bits [...] The File Name Table: Entry Dir Time Size Name 1 1 0 0 gdb.c 2 2 0 0 string3.h [...] ------------------------------------------------------------------------------ specifically referenced in GDB for DW_AT_decl_file at a single place: ------------------------------------------------------------------------------ fe = &cu->line_header->file_names[file_index - 1]; SYMBOL_SYMTAB (sym) = fe->symtab; ------------------------------------------------------------------------------ This is because for some reason DW_TAG_partial_unit never contains PC-related DWARF information. I do not know exactly why, the compression ratio is a bit lower due to it but thanksfully currently it is that way: dwz.c: ------------------------------------------------------------------------------ /* These attributes reference code, prevent moving DIEs with them. */ case DW_AT_low_pc: case DW_AT_high_pc: case DW_AT_entry_pc: case DW_AT_ranges: die->die_ck_state = CK_BAD; + /* State of checksum computation. Not computed yet, computed and suitable for moving into partial units, currently being computed and finally determined unsuitable for moving into partial units. */ enum { CK_UNKNOWN, CK_KNOWN, CK_BEING_COMPUTED, CK_BAD } die_ck_state : 2; ------------------------------------------------------------------------------ I have also verified also real-world Fedora debuginfo files really comply with that assumption with dwgrep https://github.com/pmachata/dwgrep using: ------------------------------------------------------------------------------ dwgrep -e 'entry ?DW_TAG_partial_unit child* ( ?DW_AT_low_pc , ?DW_AT_high_pc , ?DW_AT_ranges )' /usr/lib/debug/** ------------------------------------------------------------------------------ BTW I think GDB already does not support the whole DW_TAG_imported_unit and DW_TAG_partial_unit usage possibilities as specified by the DWARF standard. I think GDB would not work if DW_TAG_imported_unit was used in some inner level and not at the CU level (readelf -wi level <1>) - this is how DWZ is using DW_TAG_imported_unit. Therefore I do not think further assumptions about DW_TAG_imported_unit and DW_TAG_partial_unit usage by DWZ are a problem for GDB. One could save the whole .debug_line decoded PC<->lines mapping (and not just the DW_AT_decl_file table) but: * there are some problematic corner cases so one could do it incorrectly * there are no real world data to really test such patch extension * such extension could be done perfectly incrementally on top of this patch One could save existing 'struct line_header' in the patch instead of introducing new 'struct dwarf2_line_info'. The problem is dwarf_decode_line_header() currently uses xmalloc while we need the allocation to be bound to objfile->objfile_obstack. With 'struct line_header' one would have to make special objfile-time destruction of those 'struct line_header'. No regressions on {x86_64,x86_64-m32,i686}-fedora21pre-linux-gnu in DWZ mode (contrib/cc-with-tweaks.sh -m, that is dwz -m). I have seen there are several GDB regressions in non-DWZ -> DWZ mode but that is off-topic for this patch. Thanks, Jan ------------------------------------------------------------------------------ benchmark - on Fedora 20 x86_64 and FSF GDB HEAD: echo -e 'thread apply all bt\nset confirm no\nq'|./gdb -p `pidof soffice.bin` -ex 'set pagination off' -ex 'maintenance set per-command space' -ex 'maintenance set per-command symtab' -ex 'maintenance set per-command time' FSF GDB HEAD ("thread apply all bt"): Command execution time: 333.693000 (cpu), 335.587539 (wall) ---sec Space used: 1736404992 (+1477189632 for this command) ----MB #symtabs: 6838113 (+6809597), #primary symtabs: 3666 (+3655), #blocks: 22968 (+22943) vs. THIS PATCH ("thread apply all bt"): Command execution time: 2.595000 (cpu), 2.607573 (wall) -sec Space used: 340058112 (+85917696 for this command) --MB #symtabs: 42221 (+39041), #primary symtabs: 3666 (+3655), #blocks: 22968 (+22943) FSF GDB HEAD ("thread apply all bt full"): Command execution time: 466.751000 (cpu), 468.345837 (wall) ---sec Space used: 2330132480 (+2070974464 for this command) ----MB #symtabs: 9586991 (+9558475), #primary symtabs: 5367 (+5356), #blocks: 31638 (+31613) vs. THIS PATCH ("thread apply all bt full"): Command execution time: 18.907000 (cpu), 18.964125 (wall) --sec Space used: 364462080 (+110325760 for this command) ---MB #symtabs: 58780 (+55600), #primary symtabs: 5367 (+5356), #blocks: 31638 (+31613) gdb/ 2014-10-01 Jan Kratochvil Fix 100x slowdown regression on DWZ files. * dwarf2read.c (struct dwarf2_per_objfile): Add lineinfo_hash. (struct dwarf2_lineinfo, dwarf2_lineinfo_hash, dwarf2_lineinfo_eq): New. (struct dwarf2_cu): Add lineinfo. (handle_DW_AT_stmt_list): Use dwarf2_per_objfile->lineinfo_hash, set cu->lineinfo. (new_symbol_full): Use cu->lineinfo. diff --git a/gdb/dwarf2read.c b/gdb/dwarf2read.c index 9d0ee13..b24c133 100644 --- a/gdb/dwarf2read.c +++ b/gdb/dwarf2read.c @@ -309,8 +309,51 @@ struct dwarf2_per_objfile /* The CUs we recently read. */ VEC (dwarf2_per_cu_ptr) *just_read_cus; + + /* Table containing struct dwarf2_lineinfo. */ + htab_t lineinfo_hash; +}; + +/* Table mapping .debug_line offsets to any symtab where they are + instantiated. */ + +struct dwarf2_lineinfo +{ + /* Offset of line number information in .debug_line section. */ + sect_offset offset; + unsigned offset_in_dwz : 1; + + /* Number of entries in file_to_symtab array. */ + unsigned file_to_symtab_count; + + /* struct is sized to contain FILE_TO_SYMTAB_COUNT elements of this array. + Map each DW_AT_decl_file entry to any instantiation of matching symtab. + This array is numbered from zero, DW_AT_decl_file is numbered from one. */ + struct symtab *file_to_symtab[1]; }; +/* Hash function for a dwarf2_lineinfo. */ + +static hashval_t +dwarf2_lineinfo_hash (const void *item) +{ + const struct dwarf2_lineinfo *ofs = item; + + return ofs->offset.sect_off ^ ofs->offset_in_dwz; +} + +/* Equality function for a dwarf2_lineinfo. */ + +static int +dwarf2_lineinfo_eq (const void *item_lhs, const void *item_rhs) +{ + const struct dwarf2_lineinfo *ofs_lhs = item_lhs; + const struct dwarf2_lineinfo *ofs_rhs = item_rhs; + + return (ofs_lhs->offset.sect_off == ofs_rhs->offset.sect_off + && ofs_lhs->offset_in_dwz == ofs_rhs->offset_in_dwz); +} + static struct dwarf2_per_objfile *dwarf2_per_objfile; /* Default names of the debugging sections. */ @@ -489,6 +532,10 @@ struct dwarf2_cu /* Header data from the line table, during full symbol processing. */ struct line_header *line_header; + /* Table mapping .debug_line offsets to any symtab where they are + instantiated. It contains subset of LINE_HEADER information. */ + struct dwarf2_lineinfo *lineinfo; + /* A list of methods which need to have physnames computed after all type information has been read. */ VEC (delayed_method_info) *method_list; @@ -8975,24 +9022,61 @@ static void handle_DW_AT_stmt_list (struct die_info *die, struct dwarf2_cu *cu, const char *comp_dir, CORE_ADDR lowpc) /* ARI: editCase function */ { + struct objfile *objfile = dwarf2_per_objfile->objfile; struct attribute *attr; + unsigned int line_offset; + struct dwarf2_lineinfo lineinfo; + struct line_header *line_header; + unsigned u; + void **slot; gdb_assert (! cu->per_cu->is_debug_types); attr = dwarf2_attr (die, DW_AT_stmt_list, cu); - if (attr) + if (attr == NULL) + return; + + line_offset = DW_UNSND (attr); + + if (dwarf2_per_objfile->lineinfo_hash == NULL) { - unsigned int line_offset = DW_UNSND (attr); - struct line_header *line_header - = dwarf_decode_line_header (line_offset, cu); + dwarf2_per_objfile->lineinfo_hash = + htab_create_alloc_ex (127, dwarf2_lineinfo_hash, dwarf2_lineinfo_eq, + NULL, &objfile->objfile_obstack, + hashtab_obstack_allocate, + dummy_obstack_deallocate); + } - if (line_header) - { - cu->line_header = line_header; - make_cleanup (free_cu_line_header, cu); - dwarf_decode_lines (line_header, comp_dir, cu, NULL, lowpc); - } + lineinfo.offset.sect_off = line_offset; + lineinfo.offset_in_dwz = cu->per_cu->is_dwz; + slot = htab_find_slot (dwarf2_per_objfile->lineinfo_hash, &lineinfo, INSERT); + + /* For DW_TAG_compile_unit we need info like symtab::linetable which + is not present in *SLOT. */ + if (die->tag == DW_TAG_partial_unit && *slot != NULL) + { + cu->lineinfo = *slot; + return; } + + line_header = dwarf_decode_line_header (line_offset, cu); + if (line_header == NULL) + return; + cu->line_header = line_header; + make_cleanup (free_cu_line_header, cu); + dwarf_decode_lines (line_header, comp_dir, cu, NULL, lowpc); + + cu->lineinfo = obstack_alloc (&objfile->objfile_obstack, + (sizeof (*cu->lineinfo) + + (sizeof (*cu->lineinfo->file_to_symtab) + * (line_header->num_file_names - 1)))); + cu->lineinfo->offset.sect_off = line_offset; + cu->lineinfo->offset_in_dwz = cu->per_cu->is_dwz; + cu->lineinfo->file_to_symtab_count = line_header->num_file_names; + for (u = 0; u < cu->lineinfo->file_to_symtab_count; u++) + cu->lineinfo->file_to_symtab[u] = line_header->file_names[u].symtab; + if (*slot == NULL) + *slot = cu->lineinfo; } /* Process DW_TAG_compile_unit or DW_TAG_partial_unit. */ @@ -17870,17 +17954,12 @@ new_symbol_full (struct die_info *die, struct type *type, struct dwarf2_cu *cu, { int file_index = DW_UNSND (attr); - if (cu->line_header == NULL - || file_index > cu->line_header->num_file_names) + if (cu->lineinfo == NULL + || file_index > cu->lineinfo->file_to_symtab_count) complaint (&symfile_complaints, _("file index out of range")); else if (file_index > 0) - { - struct file_entry *fe; - - fe = &cu->line_header->file_names[file_index - 1]; - SYMBOL_SYMTAB (sym) = fe->symtab; - } + SYMBOL_SYMTAB (sym) = cu->lineinfo->file_to_symtab[file_index - 1]; } switch (die->tag)