Bug 30934 - Stopping at a breakpoint takes minutes if a source file has long lines
Summary: Stopping at a breakpoint takes minutes if a source file has long lines
Status: UNCONFIRMED
Alias: None
Product: gdb
Classification: Unclassified
Component: cli (show other bugs)
Version: 13.1
: P2 normal
Target Milestone: ---
Assignee: Not yet assigned to anyone
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2023-10-02 18:57 UTC by Hi-Angel
Modified: 2023-10-12 09:18 UTC (History)
3 users (show)

See Also:
Host:
Target:
Build:
Last reconfirmed:


Attachments
testcase (105.19 KB, text/x-c++src)
2023-10-02 18:57 UTC, Hi-Angel
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Hi-Angel 2023-10-02 18:57:56 UTC
Created attachment 15149 [details]
testcase

No idea why it's taking so long, given I do not execute any commands that would trigger showing these long lines, but debugging such a file with gdb is nigh impossible. After showing an initial message that it's about to stop on a breakpoint it just hangs for many minutes with 100% CPU load.

# Steps to reproduce

1. Download the attached file
2. Run commands:

    $ g++ test.cpp -o a -g3 -O0
    $ gdb -q --nx ./a
    Reading symbols from ./a...
    (gdb) br 56
    Breakpoint 1 at 0x1564: file test.cpp, line 56.
    (gdb) r
    Starting program: /tmp/a

    This GDB supports auto-downloading debuginfo from the following URLs:
      <https://debuginfod.archlinux.org>
    Enable debuginfod for this session? (y or [n])
    Debuginfod has been disabled.
    To make this setting permanent, add 'set debuginfod enabled off' to .gdbinit.
    [Thread debugging using libthread_db enabled]
    Using host libthread_db library "/usr/lib/libthread_db.so.1".

    Breakpoint 1, Solution::numOfSubarrays (this=0x7ffffff9c076, arr=std::vector of length 100000, capacity 100000 = {...}) at test.cpp:56

## Expected

After stopping at breakpoint 1 it immediately gives the prompt for typing further commands

## Actual

It the `Breakpoint 1` text appears, it just hangs for many minutes.
Comment 1 Tom Tromey 2023-10-02 22:54:15 UTC
Does it happen if you use '-g' rather than '-g3'?
I wonder if this is the gcc and/or linker bug that we've hit before.
Comment 2 Hi-Angel 2023-10-03 04:08:38 UTC
(In reply to Tom Tromey from comment #1)
> Does it happen if you use '-g' rather than '-g3'?
> I wonder if this is the gcc and/or linker bug that we've hit before.

Yeah, still hangs for minutes with 100% CPU load.

Worth noting also, you can't make gdb stop whatever it's doing, have to either wait for that to finish or to kill gdb with SIGKILL.
Comment 3 Hi-Angel 2023-10-03 04:15:04 UTC
I think this bug is low-priority though because such file is unlikely to come up IRL, only perhaps if as part of autogenerated code…
Comment 4 Tom de Vries 2023-10-03 08:30:31 UTC
Reproduced.  Doing a ^C gives us:
...
Breakpoint 1, Solution::numOfSubarrays (this=0x7ffffff9c15f, arr=...) at test.cpp:56
^C
Thread 1 "gdb" received signal SIGINT, Interrupt.
0x00007ffff5a42870 in boost::re_detail_106600::perl_matcher<__gnu_cxx::__normal_iterator<char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<boost::sub_match<__gnu_cxx::__normal_iterator<char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > > >, boost::regex_traits<char, boost::cpp_regex_traits<char> > >::find_restart_word() () from /usr/lib64/libsource-highlight.so.4
(gdb) bt
#0  0x00007ffff5a42870 in boost::re_detail_106600::perl_matcher<__gnu_cxx::__normal_iterator<char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<boost::sub_match<__gnu_cxx::__normal_iterator<char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > > >, boost::regex_traits<char, boost::cpp_regex_traits<char> > >::find_restart_word() ()
   from /usr/lib64/libsource-highlight.so.4
#1  0x00007ffff5a3ef74 in boost::re_detail_106600::perl_matcher<__gnu_cxx::__normal_iterator<char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<boost::sub_match<__gnu_cxx::__normal_iterator<char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > > >, boost::regex_traits<char, boost::cpp_regex_traits<char> > >::find_imp() () from /usr/lib64/libsource-highlight.so.4
#2  0x00007ffff5a87c21 in srchilite::RegexHighlightRule::tryToMatch(__gnu_cxx::__normal_iterator<char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, __gnu_cxx::__normal_iterator<char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, srchilite::HighlightToken&, srchilite::MatchingParameters const&) () from /usr/lib64/libsource-highlight.so.4
#3  0x00007ffff5a69781 in srchilite::HighlightState::findBestMatch(__gnu_cxx::__normal_iterator<char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, __gnu_cxx::__normal_iterator<char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, srchilite::HighlightToken&, srchilite::MatchingParameters const&) const () from /usr/lib64/libsource-highlight.so.4
#4  0x00007ffff5a6c5b5 in srchilite::SourceHighlighter::highlightParagraph(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) () from /usr/lib64/libsource-highlight.so.4
#5  0x00007ffff5a6dcc9 in srchilite::SourceFileHighlighter::highlight(std::istream&) ()
   from /usr/lib64/libsource-highlight.so.4
#6  0x00007ffff5a4f52b in srchilite::SourceHighlight::highlight(std::istream&, std::ostream&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) () from /usr/lib64/libsource-highlight.so.4
#7  0x00000000009d9ab3 in source_cache::ensure (this=this@entry=0x21c8740 <g_source_cache>, s=0x25db0a0)
    at /data/vries/gdb/src/gdb/source-cache.c:254
#8  0x00000000009dab49 in source_cache::get_source_lines (this=0x21c8740 <g_source_cache>, s=s@entry=0x25db0a0, 
    first_line=first_line@entry=56, last_line=last_line@entry=56, lines=lines@entry=0x7fffffffcbb0)
    at /data/vries/gdb/src/gdb/source-cache.c:364
#9  0x00000000009dedbd in print_source_lines_base (s=s@entry=0x25db0a0, line=line@entry=56, 
    stopline=stopline@entry=57, flags=...) at /data/vries/gdb/src/gdb/source.c:1387
#10 0x00000000009df1d5 in print_source_lines (s=s@entry=0x25db0a0, line=line@entry=56, stopline=stopline@entry=57, 
    flags=..., flags@entry=...) at /data/vries/gdb/src/gdb/source.c:1474
#11 0x0000000000a0aa4d in print_frame_info (fp_opts=..., frame=..., print_level=print_level@entry=0, 
    print_what=<optimized out>, print_what@entry=SRC_AND_LOC, print_args=print_args@entry=1, 
    set_current_sal=set_current_sal@entry=1) at /data/vries/gdb/src/gdb/stack.c:1164
#12 0x0000000000a0b048 in print_stack_frame (frame=..., print_level=print_level@entry=0, 
    print_what=print_what@entry=SRC_AND_LOC, set_current_sal=set_current_sal@entry=1)
    at /data/vries/gdb/src/gdb/stack.c:367
#13 0x0000000000740fef in print_stop_location (ws=<synthetic pointer>...) at /data/vries/gdb/src/gdb/infrun.c:8785
#14 print_stop_event (uiout=0x2529d30, displays=<optimized out>) at /data/vries/gdb/src/gdb/infrun.c:8801
#15 0x000000000075c9e3 in interps_notify<bpstat*, int> (method=&virtual interp::on_normal_stop(bpstat*, int))
    at /data/vries/gdb/src/gdb/interps.c:369
#16 interps_notify_normal_stop (bs=bs@entry=0x26ef7f0, print_frame=print_frame@entry=1)
    at /data/vries/gdb/src/gdb/interps.c:402
#17 0x0000000000741a2e in notify_normal_stop (print_frame=1, bs=0x26ef7f0) at /data/vries/gdb/src/gdb/infrun.c:6371
#18 normal_stop () at /data/vries/gdb/src/gdb/infrun.c:9065
#19 0x000000000074f9b1 in fetch_inferior_event () at /data/vries/gdb/src/gdb/infrun.c:4512
#20 0x0000000000fdaf2d in gdb_wait_for_event (block=block@entry=0)
    at /data/vries/gdb/src/gdbsupport/event-loop.cc:694
#21 0x0000000000fdb67f in gdb_do_one_event (mstimeout=mstimeout@entry=-1)
    at /data/vries/gdb/src/gdbsupport/event-loop.cc:217
#22 0x0000000000a6d109 in wait_sync_command_done () at /data/vries/gdb/src/gdb/top.c:427
#23 0x0000000000a70155 in maybe_wait_sync_command_done (was_sync=0) at /data/vries/gdb/src/gdb/top.c:444
#24 execute_command (p=<optimized out>, p@entry=<error reading variable: value has been optimized out>, from_tty=1, 
    from_tty@entry=<error reading variable: value has been optimized out>) at /data/vries/gdb/src/gdb/top.c:577
#25 0x00000000007c7675 in catch_command_errors (command=<optimized out>, arg=<optimized out>, 
    from_tty=<optimized out>, do_bp_actions=do_bp_actions@entry=true) at /data/vries/gdb/src/gdb/main.c:518
#26 0x00000000007c77af in execute_cmdargs (cmdarg_vec=cmdarg_vec@entry=0x7fffffffd810, 
    file_type=file_type@entry=CMDARG_FILE, cmd_type=cmd_type@entry=CMDARG_COMMAND, ret=ret@entry=0x7fffffffd7fc)
    at /data/vries/gdb/src/gdb/main.c:617
#27 0x00000000007c8ee7 in captured_main_1 (context=context@entry=0x7fffffffda00)
    at /data/vries/gdb/src/gdb/main.c:1293
#28 0x00000000007c991b in captured_main (data=data@entry=0x7fffffffda00) at /data/vries/gdb/src/gdb/main.c:1314
#29 gdb_main (args=args@entry=0x7fffffffda20) at /data/vries/gdb/src/gdb/main.c:1343
#30 0x0000000000427fb5 in main (argc=18, argv=0x7fffffffdb48) at /data/vries/gdb/src/gdb/gdb.c:39
(gdb) 
...

Seems to be stuck in srchilite::SourceHighlighter::highlightParagraph.
Comment 5 Tom de Vries 2023-10-03 08:49:08 UTC
(In reply to Hi-Angel from comment #0)
> No idea why it's taking so long, given I do not execute any commands that
> would trigger showing these long lines,

This is because source_cache::ensure annotates a file at at time rather than a line at at time.

> but debugging such a file with gdb
> is nigh impossible. 

With "set style sources off" I get:
...
$ time gdb -q a.out -ex "b 56" -ex "set style sources off" -ex run -ex "set confirm off" -ex quit
Reading symbols from a.out...
Breakpoint 1 at 0x400ff5: file test.cpp, line 56.
Starting program: /data/vries/gdb/a.out 

Breakpoint 1, Solution::numOfSubarrays (this=0x7ffffff9c15f, arr=...) at test.cpp:56
56	        return (int) t;

real	0m0.135s
user	0m0.254s
sys	0m0.028s
...

So you can use as workaround:
- "set style sources off", or
- build with --disable-source-highlight and still use source styling with 
  the Python Pygments package, for me that takes about 1 sec.
Comment 6 Tom de Vries 2023-10-03 09:21:16 UTC
I was curious, how long does it actually take for me with gdb:
...
$ time gdb -q a.out -ex "b 56" -ex run -ex "set confirm off" -ex quit
Reading symbols from a.out...
Breakpoint 1 at 0x400ff5: file test.cpp, line 56.
Starting program: /data/vries/gdb/a.out 

Breakpoint 1, Solution::numOfSubarrays (this=0x7ffffff9c15f, arr=...) at test.cpp:56
56	        return (int) t;

real	2m17.593s
user	2m16.012s
sys	0m1.728s
...

I guess we're basically looking at:
...
$ time source-highlight test.cpp > /dev/null
Processing test.cpp ... created test.cpp.html

real	2m13.220s
user	2m10.213s
sys	0m3.004s
...
and when using pygments:
...
$ time pygmentize test.cpp > /dev/null

real	0m2.017s
user	0m2.005s
sys	0m0.012s
...
Comment 7 Tom de Vries 2023-10-03 09:23:50 UTC
(In reply to Tom de Vries from comment #5)
> So you can use as workaround:
> - build with --disable-source-highlight 

I just found that the same effect can be achieved by "maintenance set gnu-source-highlight enabled off", so there's no need to rebuild.
Comment 8 Tom Tromey 2023-10-03 16:34:52 UTC
GNU source highlight is basically unmaintained (I did the last
release and I don't know the source code at all...).
Maybe we should consider dropping it.
Anyway this bug should probably be moved there.
Comment 9 Tom de Vries 2023-10-03 21:07:52 UTC
FTR:
...
$ wc test.cpp
    80    229 293884 test.cpp
...
Comment 10 Tom de Vries 2023-10-03 21:25:14 UTC
(In reply to Tom Tromey from comment #8)
> GNU source highlight is basically unmaintained (I did the last
> release and I don't know the source code at all...).
> Maybe we should consider dropping it.

If not (yet) dropping it for some reason, at the very least we could reverse the order of preference between pygments and source-highlight.

Possibly also wrap source-highlight (or both) in some timeout stray-jacket.

> Anyway this bug should probably be moved there.
Comment 11 Tom de Vries 2023-10-05 06:35:14 UTC
(In reply to Tom Tromey from comment #8)
> Anyway this bug should probably be moved there.

https://savannah.gnu.org/bugs/index.php?64747
Comment 12 Tom de Vries 2023-10-10 11:12:20 UTC
(In reply to Tom de Vries from comment #11)
> (In reply to Tom Tromey from comment #8)
> > Anyway this bug should probably be moved there.
> 
> https://savannah.gnu.org/bugs/index.php?64747

I've posted a tentative patch there, with execution time dropping to 3s.
Comment 13 Tom de Vries 2023-10-11 07:28:19 UTC
(In reply to Tom de Vries from comment #12)
> (In reply to Tom de Vries from comment #11)
> > (In reply to Tom Tromey from comment #8)
> > > Anyway this bug should probably be moved there.
> > 
> > https://savannah.gnu.org/bugs/index.php?64747
> 
> I've posted a tentative patch there, with execution time dropping to 3s.

Patch submitted here ( https://savannah.gnu.org/patch/?10400 ).
Comment 14 Tom de Vries 2023-10-11 13:44:18 UTC
(In reply to Hi-Angel from comment #2)
> Worth noting also, you can't make gdb stop whatever it's doing, have to
> either wait for that to finish or to kill gdb with SIGKILL.

Submitted RFC ( https://sourceware.org/pipermail/gdb-patches/2023-October/203157.html ) to address that.
Comment 15 Hi-Angel 2023-10-11 17:10:47 UTC
(In reply to Tom de Vries from comment #14)
> Submitted RFC (
> https://sourceware.org/pipermail/gdb-patches/2023-October/203157.html ) to
> address that.

Re: "RFC: is the warning a good idea, or overkill?"

Yes, I think it is a good idea. A user pressing ^C too quickly has to know they interrupted some ongoing process and lost source highlight.

(sorry for replying here and not on ML but I'm not subscribed. I wish one of these days they'll make a "reply" button on mailing-lists web-ui that would open your email client with a MESSAGE-ID + title 😊)
Comment 16 Tom de Vries 2023-10-11 17:43:13 UTC
(In reply to Hi-Angel from comment #15)
> (sorry for replying here and not on ML but I'm not subscribed. I wish one of
> these days they'll make a "reply" button on mailing-lists web-ui that would
> open your email client with a MESSAGE-ID + title 😊)

If you go to https://inbox.sourceware.org/gdb-patches/ , you can click on the thread you're interested in, and then click the reply link on the message you want to reply to, which will take you to the reply instructions.  There are 3 different ways, the 3rd is a mailto link that could work for you.