[PATCH] GDB/testsuite: Bump up `match_max'

[PATCH] GDB/testsuite: Bump up `match_max'

[Maciej W. Rozycki]

Hi,

 This fixes:

PASS: gdb.base/info-macros.exp: info macro  -a  --  FOO
ERROR: internal buffer is full.
UNRESOLVED: gdb.base/info-macros.exp: info macros 2
ERROR: internal buffer is full.
UNRESOLVED: gdb.base/info-macros.exp: info macros 3
ERROR: internal buffer is full.
UNRESOLVED: gdb.base/info-macros.exp: info macros 4
FAIL: gdb.base/info-macros.exp: info macros *$pc
ERROR: internal buffer is full.
UNRESOLVED: gdb.base/info-macros.exp: next
FAIL: gdb.base/info-macros.exp: info macros
ERROR: internal buffer is full.
UNRESOLVED: gdb.base/info-macros.exp: next
FAIL: gdb.base/info-macros.exp: info macros 6
ERROR: internal buffer is full.
UNRESOLVED: gdb.base/info-macros.exp: next
FAIL: gdb.base/info-macros.exp: info macros 7
ERROR: internal buffer is full.
UNRESOLVED: gdb.base/info-macros.exp: info macros info-macros.c:42 (PRMS gdb/NNNN)

with the arm-eabi target tested on the i686-mingw32 host where GCC defines 
enough macros to exhaust expect's 30000 characters of buffer space.

 OK to apply?

2014-05-17  Maciej W. Rozycki  <macro@codesourcery.com>

	gdb/testsuite/
	* lib/gdb.exp (default_gdb_init): Bump `match_max' up from
	30000 to 65536.

  Maciej

gdb-test-match-max.diff
Index: gdb-fsf-trunk-quilt/gdb/testsuite/lib/gdb.exp
===================================================================
--- gdb-fsf-trunk-quilt.orig/gdb/testsuite/lib/gdb.exp	2014-05-13 02:52:11.347706187 +0100
+++ gdb-fsf-trunk-quilt/gdb/testsuite/lib/gdb.exp	2014-05-17 21:36:38.618201312 +0100
@@ -3539,8 +3539,9 @@ proc default_gdb_init { args } {
     
     # Unlike most tests, we have a small number of tests that generate
     # a very large amount of output.  We therefore increase the expect
-    # buffer size to be able to contain the entire test output.
-    match_max -d 30000
+    # buffer size to be able to contain the entire test output.  This
+    # is especially needed by gdb.base/info-macros.exp.
+    match_max -d 65536
     # Also set this value for the currently running GDB. 
     match_max [match_max -d]
 

Re: [PATCH] GDB/testsuite: Bump up `match_max'

[Tom Tromey]

>>>>> "Maciej" == Maciej W Rozycki <macro@codesourcery.com> writes:

Maciej> 2014-05-17  Maciej W. Rozycki  <macro@codesourcery.com>

Maciej> 	gdb/testsuite/
Maciej> 	* lib/gdb.exp (default_gdb_init): Bump `match_max' up from
Maciej> 	30000 to 65536.

Ok.

I wonder whether you timed the test suite?
The expect man page says:

    This may be changed with the function match_max.  (Note that excessively
    large values can slow down the pattern matcher.)

If it is notably slower then it would be better to rewrite the macro
tests to avoid this need.

Tom

Re: [PATCH] GDB/testsuite: Bump up `match_max'

[Joel Brobecker]

> I wonder whether you timed the test suite?
> The expect man page says:
> 
>     This may be changed with the function match_max.  (Note that excessively
>     large values can slow down the pattern matcher.)
> 
> If it is notably slower then it would be better to rewrite the macro
> tests to avoid this need.

Funny you would say that! I was reviewing the patch, and decided to
do exactly that. Ran into trouble (fresh install), but almost there...

-- 
Joel

Re: [PATCH] GDB/testsuite: Bump up `match_max'

[Joel Brobecker]

> > I wonder whether you timed the test suite?
> > The expect man page says:
> > 
> >     This may be changed with the function match_max.  (Note that excessively
> >     large values can slow down the pattern matcher.)
> > 
> > If it is notably slower then it would be better to rewrite the macro
> > tests to avoid this need.
> 
> Funny you would say that! I was reviewing the patch, and decided to
> do exactly that. Ran into trouble (fresh install), but almost there...

Here are the results. As I hoped, it doesn't seem to introduce
any noticeable difference (at -j16 on an 8-thread machine).

    Before: 1093.79s user 153.20s system 589% cpu 3:31.68 total
    After:  1097.58s user 155.08s system 589% cpu 3:32.39 total

-- 
Joel

Re: [PATCH] GDB/testsuite: Bump up `match_max'

[Doug Evans]

On Mon, May 19, 2014 at 7:37 AM, Joel Brobecker <brobecker@adacore.com> wrote:
>> > I wonder whether you timed the test suite?
>> > The expect man page says:
>> >
>> >     This may be changed with the function match_max.  (Note that excessively
>> >     large values can slow down the pattern matcher.)
>> >
>> > If it is notably slower then it would be better to rewrite the macro
>> > tests to avoid this need.
>>
>> Funny you would say that! I was reviewing the patch, and decided to
>> do exactly that. Ran into trouble (fresh install), but almost there...
>
> Here are the results. As I hoped, it doesn't seem to introduce
> any noticeable difference (at -j16 on an 8-thread machine).
>
>     Before: 1093.79s user 153.20s system 589% cpu 3:31.68 total
>     After:  1097.58s user 155.08s system 589% cpu 3:32.39 total

Hi.
fwiw, I did several runs of before/after with the testsuite running
serially and didn't find any statistical difference.
All runs were in the range 14:07s to 14:25s elapsed, and sometimes
with-patch was faster.
Not unexpected I guess - most of the time what's actually in the
buffer is pretty small, much less than the buffer size, so other
factors would (generally) have more of an influence on run time.

Re: [PATCH] GDB/testsuite: Bump up `match_max'

[Maciej W. Rozycki]

On Mon, 19 May 2014, Doug Evans wrote:

> >> > I wonder whether you timed the test suite?
> >> > The expect man page says:
> >> >
> >> >     This may be changed with the function match_max.  (Note that excessively
> >> >     large values can slow down the pattern matcher.)
> >> >
> >> > If it is notably slower then it would be better to rewrite the macro
> >> > tests to avoid this need.
> >>
> >> Funny you would say that! I was reviewing the patch, and decided to
> >> do exactly that. Ran into trouble (fresh install), but almost there...
> >
> > Here are the results. As I hoped, it doesn't seem to introduce
> > any noticeable difference (at -j16 on an 8-thread machine).
> >
> >     Before: 1093.79s user 153.20s system 589% cpu 3:31.68 total
> >     After:  1097.58s user 155.08s system 589% cpu 3:32.39 total
> 
> fwiw, I did several runs of before/after with the testsuite running
> serially and didn't find any statistical difference.
> All runs were in the range 14:07s to 14:25s elapsed, and sometimes
> with-patch was faster.
> Not unexpected I guess - most of the time what's actually in the
> buffer is pretty small, much less than the buffer size, so other
> factors would (generally) have more of an influence on run time.

 Have we reached consensus?  At this point of discussion I don't have 
anything to add -- all has been already written AFAICT.  Thank you all for 
verifying the change.

  Maciej

Re: [PATCH] GDB/testsuite: Bump up `match_max'

[Joel Brobecker]

>  Have we reached consensus?  At this point of discussion I don't have 
> anything to add -- all has been already written AFAICT.  Thank you all for 
> verifying the change.

Yes. I think Tom gave the OK, and I would have too if he hadn't.
Doug and I were just confirming that there is no performance impact.

-- 
Joel

Re: [PATCH] GDB/testsuite: Bump up `match_max'

[Maciej W. Rozycki]

On Tue, 20 May 2014, Joel Brobecker wrote:

> >  Have we reached consensus?  At this point of discussion I don't have 
> > anything to add -- all has been already written AFAICT.  Thank you all for 
> > verifying the change.
> 
> Yes. I think Tom gave the OK, and I would have too if he hadn't.
> Doug and I were just confirming that there is no performance impact.

 Committed now, thanks.

  Maciej

[PATCH] gdb/testsuite: Bump up 'match_max'

[Thiago Jung Bauermann]

This fixes "ERROR: internal buffer is full." in gdb.base/maint.exp when
running with "make check-read1".

Also take the opportunity to fix stray whitespace in the vicinity.
---
 gdb/testsuite/lib/gdb.exp | 9 +++++----
 1 file changed, 5 insertions(+), 4 deletions(-)

diff --git a/gdb/testsuite/lib/gdb.exp b/gdb/testsuite/lib/gdb.exp
index de22da8d8a8c..c6ee4628f8f5 100644
--- a/gdb/testsuite/lib/gdb.exp
+++ b/gdb/testsuite/lib/gdb.exp
@@ -6533,13 +6533,14 @@ proc default_gdb_init { test_file_name } {
     if { $gdb_wrapper_target != [current_target_name] } {
 	set gdb_wrapper_initialized 0
     }
-    
+
     # Unlike most tests, we have a small number of tests that generate
     # a very large amount of output.  We therefore increase the expect
     # buffer size to be able to contain the entire test output.  This
-    # is especially needed by gdb.base/info-macros.exp.
-    match_max -d 65536
-    # Also set this value for the currently running GDB. 
+    # is especially needed by gdb.base/info-macros.exp and
+    # gdb.base/maint.exp.
+    match_max -d 196608
+    # Also set this value for the currently running GDB.
     match_max [match_max -d]
 
     # We want to add the name of the TCL testcase to the PASS/FAIL messages.

Re: [PATCH] gdb/testsuite: Bump up 'match_max'

[Simon Marchi]

On 2023-10-03 15:53, Thiago Jung Bauermann via Gdb-patches wrote:
> This fixes "ERROR: internal buffer is full." in gdb.base/maint.exp when
> running with "make check-read1".
> 
> Also take the opportunity to fix stray whitespace in the vicinity.
> ---
>  gdb/testsuite/lib/gdb.exp | 9 +++++----
>  1 file changed, 5 insertions(+), 4 deletions(-)
> 
> diff --git a/gdb/testsuite/lib/gdb.exp b/gdb/testsuite/lib/gdb.exp
> index de22da8d8a8c..c6ee4628f8f5 100644
> --- a/gdb/testsuite/lib/gdb.exp
> +++ b/gdb/testsuite/lib/gdb.exp
> @@ -6533,13 +6533,14 @@ proc default_gdb_init { test_file_name } {
>      if { $gdb_wrapper_target != [current_target_name] } {
>  	set gdb_wrapper_initialized 0
>      }
> -    
> +
>      # Unlike most tests, we have a small number of tests that generate
>      # a very large amount of output.  We therefore increase the expect
>      # buffer size to be able to contain the entire test output.  This
> -    # is especially needed by gdb.base/info-macros.exp.
> -    match_max -d 65536
> -    # Also set this value for the currently running GDB. 
> +    # is especially needed by gdb.base/info-macros.exp and
> +    # gdb.base/maint.exp.
> +    match_max -d 196608
> +    # Also set this value for the currently running GDB.
>      match_max [match_max -d]
>  
>      # We want to add the name of the TCL testcase to the PASS/FAIL messages.

Do you have details about what fails specifically?  It runs fine here,
so I'm curious which part of the test fills the buffer exactly.  Also,
my understanding is that check-read1 should have no effect on this, it
shouldn't fill the buffer more than a regular "make check".  It only
makes it such that read system calls return at most 1 byte.

Simon

Re: [PATCH] gdb/testsuite: Bump up 'match_max'

[Thiago Jung Bauermann]

Hello Simon,

Thanks for looking into this.

Simon Marchi <simark@simark.ca> writes:

> On 2023-10-03 15:53, Thiago Jung Bauermann via Gdb-patches wrote:
>> This fixes "ERROR: internal buffer is full." in gdb.base/maint.exp when
>> running with "make check-read1".
>> 
>> Also take the opportunity to fix stray whitespace in the vicinity.
>> ---
>>  gdb/testsuite/lib/gdb.exp | 9 +++++----
>>  1 file changed, 5 insertions(+), 4 deletions(-)
>> 
>> diff --git a/gdb/testsuite/lib/gdb.exp b/gdb/testsuite/lib/gdb.exp
>> index de22da8d8a8c..c6ee4628f8f5 100644
>> --- a/gdb/testsuite/lib/gdb.exp
>> +++ b/gdb/testsuite/lib/gdb.exp
>> @@ -6533,13 +6533,14 @@ proc default_gdb_init { test_file_name } {
>>      if { $gdb_wrapper_target != [current_target_name] } {
>>  	set gdb_wrapper_initialized 0
>>      }
>> -    
>> +
>>      # Unlike most tests, we have a small number of tests that generate
>>      # a very large amount of output.  We therefore increase the expect
>>      # buffer size to be able to contain the entire test output.  This
>> -    # is especially needed by gdb.base/info-macros.exp.
>> -    match_max -d 65536
>> -    # Also set this value for the currently running GDB. 
>> +    # is especially needed by gdb.base/info-macros.exp and
>> +    # gdb.base/maint.exp.
>> +    match_max -d 196608
>> +    # Also set this value for the currently running GDB.
>>      match_max [match_max -d]
>>  
>>      # We want to add the name of the TCL testcase to the PASS/FAIL messages.
>
> Do you have details about what fails specifically?  It runs fine here,

I think that what causes trouble is the fact that the line tables of the
dynamic linker are huge.

What happens is that when testing "maint info line-table w/o a file
name", expect times out in the middle of "maint info line-table" output
while it's listing the line-table of dl-load.c. A bit after that I get
the first 2 "ERROR: internal buffer is full." (I get between 2 and 5
such ERRORs depending on the machine).

Then there are a few more errors while printing the line table of
elf/rtld.c.

> so I'm curious which part of the test fills the buffer exactly.  Also,

Interesting. This fails on all 4 of the machines I tried, covering
aarch64-linux, armv8l-linux-gnueabihf and x86_84-linux. Do you have
libc6 debuginfo installed?

In any case, I put the testsuite logs of regular "make check" and "make
check-read1" with default timeout and with 3600s timeout for
gdb.base/maint.exp here:

https://people.linaro.org/~thiago.bauermann/read1-maint.exp/

> my understanding is that check-read1 should have no effect on this, it
> shouldn't fill the buffer more than a regular "make check".  It only
> makes it such that read system calls return at most 1 byte.

I don't know how expect manages its internal buffer. I initially wrote
that "maybe timed out tests cause the unmatched output accumulate in the
buffer?", but then I tested with gdb_test_timeout set to 3600: I didn't
get timeouts anymore, but I still got the "internal buffer is full"
errors, which caused the respective tests to be marked UNRESOLVED.

So all this to say that I don't know what is going on, TBH...

-- 
Thiago

Re: [PATCH] gdb/testsuite: Bump up 'match_max'

[Simon Marchi]

On 2023-10-04 18:43, Thiago Jung Bauermann wrote:
> 
> Hello Simon,
> 
> Thanks for looking into this.
> 
> Simon Marchi <simark@simark.ca> writes:
> 
>> On 2023-10-03 15:53, Thiago Jung Bauermann via Gdb-patches wrote:
>>> This fixes "ERROR: internal buffer is full." in gdb.base/maint.exp when
>>> running with "make check-read1".
>>>
>>> Also take the opportunity to fix stray whitespace in the vicinity.
>>> ---
>>>  gdb/testsuite/lib/gdb.exp | 9 +++++----
>>>  1 file changed, 5 insertions(+), 4 deletions(-)
>>>
>>> diff --git a/gdb/testsuite/lib/gdb.exp b/gdb/testsuite/lib/gdb.exp
>>> index de22da8d8a8c..c6ee4628f8f5 100644
>>> --- a/gdb/testsuite/lib/gdb.exp
>>> +++ b/gdb/testsuite/lib/gdb.exp
>>> @@ -6533,13 +6533,14 @@ proc default_gdb_init { test_file_name } {
>>>      if { $gdb_wrapper_target != [current_target_name] } {
>>>  	set gdb_wrapper_initialized 0
>>>      }
>>> -    
>>> +
>>>      # Unlike most tests, we have a small number of tests that generate
>>>      # a very large amount of output.  We therefore increase the expect
>>>      # buffer size to be able to contain the entire test output.  This
>>> -    # is especially needed by gdb.base/info-macros.exp.
>>> -    match_max -d 65536
>>> -    # Also set this value for the currently running GDB. 
>>> +    # is especially needed by gdb.base/info-macros.exp and
>>> +    # gdb.base/maint.exp.
>>> +    match_max -d 196608
>>> +    # Also set this value for the currently running GDB.
>>>      match_max [match_max -d]
>>>  
>>>      # We want to add the name of the TCL testcase to the PASS/FAIL messages.
>>
>> Do you have details about what fails specifically?  It runs fine here,
> 
> I think that what causes trouble is the fact that the line tables of the
> dynamic linker are huge.
> 
> What happens is that when testing "maint info line-table w/o a file
> name", expect times out in the middle of "maint info line-table" output
> while it's listing the line-table of dl-load.c. A bit after that I get
> the first 2 "ERROR: internal buffer is full." (I get between 2 and 5
> such ERRORs depending on the machine).
> 
> Then there are a few more errors while printing the line table of
> elf/rtld.c.
> 
>> so I'm curious which part of the test fills the buffer exactly.  Also,
> 
> Interesting. This fails on all 4 of the machines I tried, covering
> aarch64-linux, armv8l-linux-gnueabihf and x86_84-linux. Do you have
> libc6 debuginfo installed?

I do, on my Ubuntu system, but my build wasn't configured to use it.  I
added --with-separate-debug-dir=/usr/lib/debug to my build (it defaults
to /usr/local/lib/debug), and now my GDB picks up the debug info for
libc.

The "maint info line-table" test is specifically written in a way to
deal with large output.  It uses gdb_test_multiple with different -re
patterns to match the different expected lines.  expect reads some
output from GDB, then tries to match any -re line.  If there's a match,
the text that matched is removed from the expect buffer.  When there
isn't enough data in the buffer, expect reads more GDB output.  This
way, we consume the GDB output line by line and avoid having all the
huge output of the command in the buffer at the same time.

See this commit:

https://gitlab.com/gnutools/binutils-gdb/-/commit/f610ab6d3cbab5d8b8ef3f3a93dd81a800ec5725

I added some "puts" in each -re clause, to see which matched (see diff
at the end).  With "make check", it looks fine, this -re (which matches
table entries) gets matched often:

  -re "^$decimal\[ \t\]+$decimal\[ \t\]+$hex\[ \t\]+$hex\[^\r\n\]*\r\n"

But with "make check-read1", it doesn't get matched and we accumulate
lots of output in the buffer.  I follow the test execution with `tail -F
testsuite/gdb.log` on another terminal, and I see the output coming in
slower and slower (presumably because expect tries to match our patterns
on an ever growing buffer).

So I think this is what you should dig into, why doesn't this -re get
matched with read1.  Note that the ^ at the beginning of the regex means
that this regex will match only against some output at the very
beginning of the buffer.  So if there is some unmatched output in the
buffer before what this line intends to match, it won't match.

The culprits are likely the regexes that finish with an unbounded
repetition like [^\r\n]*.  When characters are read one by one in the
buffer, the regex can match early and leave something in the buffer that
it would have otherwise matched, if the reads were done in big chunks as
usual (this is precisely the kind of issue that read1 means to uncover).
Those regexes would need to be modified to consume the entire line, even
with read1.

Simon


diff --git a/gdb/testsuite/gdb.base/maint.exp b/gdb/testsuite/gdb.base/maint.exp
index c05d0987e7f..99574f59c44 100644
--- a/gdb/testsuite/gdb.base/maint.exp
+++ b/gdb/testsuite/gdb.base/maint.exp
@@ -388,14 +388,17 @@ gdb_test_multiple "maint info line-table" \
     "maint info line-table w/o a file name" {
     -re "symtab: \[^\n\r\]+${srcfile} \\(\\(struct symtab \\*\\) $hex\\)\r\nlinetable: \\(\\(struct linetable \\*\\) $hex\\):\r\nINDEX\[ \t\]+LINE\[ \t\]+REL-ADDRESS\[ \t\]+UNREL-ADDRESS\[^\r\n\]*" {
        set saw_srcfile 1
+       puts ">>> header a: $expect_out(0,string)"
        exp_continue
     }
     -re "symtab: \[^\n\r\]+ \\(\\(struct symtab \\*\\) $hex\\)\r\nlinetable: \\(\\(struct linetable \\*\\) $hex\\):\r\nINDEX\[ \t\]+LINE\[ \t\]+REL-ADDRESS\[ \t\]+UNREL-ADDRESS\[^\r\n\]*" {
        # Match each symtab to avoid overflowing expect's buffer.
+       puts ">>> header b: '$expect_out(0,string)'"
        exp_continue
     }
     -re "symtab: \[^\n\r\]+ \\(\\(struct symtab \\*\\) $hex\\)\r\nlinetable: \\(\\(struct linetable \\*\\) 0x0\\):\r\nNo line table.\r\n" {
        # For symtabs with no linetable.
+       puts ">>> header no lt: '$expect_out(0,string)'"
        exp_continue
     }
     -re "^$decimal\[ \t\]+$decimal\[ \t\]+$hex\[ \t\]+$hex\[^\r\n\]*\r\n" {
@@ -414,17 +417,21 @@ gdb_test_multiple "maint info line-table" \
        #  455       END 0x00007ffff7df1d3f
        #
        # Match each line to avoid overflowing expect's buffer.
+       puts ">>> match line: '$expect_out(0,string)'"
        exp_continue
     }
     -re "^$decimal\[ \t\]+END\[ \t\]+$hex\[ \t\]+$hex\[^\r\n\]*\r\n" {
        # Matches an end marker in the above.
+       puts ">>> match end: '$expect_out(0,string)'"
        exp_continue
     }
     -re "^\r\n" {
        # Empty line between tables.
+       puts ">>> match empty: '$expect_out(0,string)'"
        exp_continue
     }
     -re "^$gdb_prompt $" {
+       puts ">>> fini: '$expect_out(0,string)'"
        gdb_assert $saw_srcfile $gdb_test_name
     }
 }

Re: [PATCH] gdb/testsuite: Bump up 'match_max'

[Thiago Jung Bauermann]

Simon Marchi <simark@simark.ca> writes:

> On 2023-10-04 18:43, Thiago Jung Bauermann wrote:
>> 
>> Hello Simon,
>> 
>> Thanks for looking into this.
>> 
>> Simon Marchi <simark@simark.ca> writes:
>> 
>>> On 2023-10-03 15:53, Thiago Jung Bauermann via Gdb-patches wrote:
>>>> This fixes "ERROR: internal buffer is full." in gdb.base/maint.exp when
>>>> running with "make check-read1".
>>>>
>>>> Also take the opportunity to fix stray whitespace in the vicinity.
>>>> ---
>>>>  gdb/testsuite/lib/gdb.exp | 9 +++++----
>>>>  1 file changed, 5 insertions(+), 4 deletions(-)
>>>>
>>>> diff --git a/gdb/testsuite/lib/gdb.exp b/gdb/testsuite/lib/gdb.exp
>>>> index de22da8d8a8c..c6ee4628f8f5 100644
>>>> --- a/gdb/testsuite/lib/gdb.exp
>>>> +++ b/gdb/testsuite/lib/gdb.exp
>>>> @@ -6533,13 +6533,14 @@ proc default_gdb_init { test_file_name } {
>>>>      if { $gdb_wrapper_target != [current_target_name] } {
>>>>  	set gdb_wrapper_initialized 0
>>>>      }
>>>> -    
>>>> +
>>>>      # Unlike most tests, we have a small number of tests that generate
>>>>      # a very large amount of output.  We therefore increase the expect
>>>>      # buffer size to be able to contain the entire test output.  This
>>>> -    # is especially needed by gdb.base/info-macros.exp.
>>>> -    match_max -d 65536
>>>> -    # Also set this value for the currently running GDB. 
>>>> +    # is especially needed by gdb.base/info-macros.exp and
>>>> +    # gdb.base/maint.exp.
>>>> +    match_max -d 196608
>>>> +    # Also set this value for the currently running GDB.
>>>>      match_max [match_max -d]
>>>>  
>>>>      # We want to add the name of the TCL testcase to the PASS/FAIL messages.
>>>
>>> Do you have details about what fails specifically?  It runs fine here,
>> 
>> I think that what causes trouble is the fact that the line tables of the
>> dynamic linker are huge.
>> 
>> What happens is that when testing "maint info line-table w/o a file
>> name", expect times out in the middle of "maint info line-table" output
>> while it's listing the line-table of dl-load.c. A bit after that I get
>> the first 2 "ERROR: internal buffer is full." (I get between 2 and 5
>> such ERRORs depending on the machine).
>> 
>> Then there are a few more errors while printing the line table of
>> elf/rtld.c.
>> 
>>> so I'm curious which part of the test fills the buffer exactly.  Also,
>> 
>> Interesting. This fails on all 4 of the machines I tried, covering
>> aarch64-linux, armv8l-linux-gnueabihf and x86_84-linux. Do you have
>> libc6 debuginfo installed?
>
> I do, on my Ubuntu system, but my build wasn't configured to use it.  I
> added --with-separate-debug-dir=/usr/lib/debug to my build (it defaults
> to /usr/local/lib/debug), and now my GDB picks up the debug info for
> libc.
>
> The "maint info line-table" test is specifically written in a way to
> deal with large output.  It uses gdb_test_multiple with different -re
> patterns to match the different expected lines.  expect reads some
> output from GDB, then tries to match any -re line.  If there's a match,
> the text that matched is removed from the expect buffer.  When there
> isn't enough data in the buffer, expect reads more GDB output.  This
> way, we consume the GDB output line by line and avoid having all the
> huge output of the command in the buffer at the same time.
>
> See this commit:
>
> https://gitlab.com/gnutools/binutils-gdb/-/commit/f610ab6d3cbab5d8b8ef3f3a93dd81a800ec5725
>
> I added some "puts" in each -re clause, to see which matched (see diff
> at the end).  With "make check", it looks fine, this -re (which matches
> table entries) gets matched often:
>
>   -re "^$decimal\[ \t\]+$decimal\[ \t\]+$hex\[ \t\]+$hex\[^\r\n\]*\r\n"
>
> But with "make check-read1", it doesn't get matched and we accumulate
> lots of output in the buffer.  I follow the test execution with `tail -F
> testsuite/gdb.log` on another terminal, and I see the output coming in
> slower and slower (presumably because expect tries to match our patterns
> on an ever growing buffer).
>
> So I think this is what you should dig into, why doesn't this -re get
> matched with read1.  Note that the ^ at the beginning of the regex means
> that this regex will match only against some output at the very
> beginning of the buffer.  So if there is some unmatched output in the
> buffer before what this line intends to match, it won't match.
>
> The culprits are likely the regexes that finish with an unbounded
> repetition like [^\r\n]*.  When characters are read one by one in the
> buffer, the regex can match early and leave something in the buffer that
> it would have otherwise matched, if the reads were done in big chunks as
> usual (this is precisely the kind of issue that read1 means to uncover).
> Those regexes would need to be modified to consume the entire line, even
> with read1.

Thank you for the detailed explanation and for the debug patch! I'll dig
further into it and see if I can fix the testcase.

-- 
Thiago

Re: [PATCH] gdb/testsuite: Bump up 'match_max'

[Andrew Burgess]

Thiago Jung Bauermann via Gdb-patches <gdb-patches@sourceware.org>
writes:

> Simon Marchi <simark@simark.ca> writes:
>
>> On 2023-10-04 18:43, Thiago Jung Bauermann wrote:
>>> 
>>> Hello Simon,
>>> 
>>> Thanks for looking into this.
>>> 
>>> Simon Marchi <simark@simark.ca> writes:
>>> 
>>>> On 2023-10-03 15:53, Thiago Jung Bauermann via Gdb-patches wrote:
>>>>> This fixes "ERROR: internal buffer is full." in gdb.base/maint.exp when
>>>>> running with "make check-read1".
>>>>>
>>>>> Also take the opportunity to fix stray whitespace in the vicinity.
>>>>> ---
>>>>>  gdb/testsuite/lib/gdb.exp | 9 +++++----
>>>>>  1 file changed, 5 insertions(+), 4 deletions(-)
>>>>>
>>>>> diff --git a/gdb/testsuite/lib/gdb.exp b/gdb/testsuite/lib/gdb.exp
>>>>> index de22da8d8a8c..c6ee4628f8f5 100644
>>>>> --- a/gdb/testsuite/lib/gdb.exp
>>>>> +++ b/gdb/testsuite/lib/gdb.exp
>>>>> @@ -6533,13 +6533,14 @@ proc default_gdb_init { test_file_name } {
>>>>>      if { $gdb_wrapper_target != [current_target_name] } {
>>>>>  	set gdb_wrapper_initialized 0
>>>>>      }
>>>>> -    
>>>>> +
>>>>>      # Unlike most tests, we have a small number of tests that generate
>>>>>      # a very large amount of output.  We therefore increase the expect
>>>>>      # buffer size to be able to contain the entire test output.  This
>>>>> -    # is especially needed by gdb.base/info-macros.exp.
>>>>> -    match_max -d 65536
>>>>> -    # Also set this value for the currently running GDB. 
>>>>> +    # is especially needed by gdb.base/info-macros.exp and
>>>>> +    # gdb.base/maint.exp.
>>>>> +    match_max -d 196608
>>>>> +    # Also set this value for the currently running GDB.
>>>>>      match_max [match_max -d]
>>>>>  
>>>>>      # We want to add the name of the TCL testcase to the PASS/FAIL messages.
>>>>
>>>> Do you have details about what fails specifically?  It runs fine here,
>>> 
>>> I think that what causes trouble is the fact that the line tables of the
>>> dynamic linker are huge.
>>> 
>>> What happens is that when testing "maint info line-table w/o a file
>>> name", expect times out in the middle of "maint info line-table" output
>>> while it's listing the line-table of dl-load.c. A bit after that I get
>>> the first 2 "ERROR: internal buffer is full." (I get between 2 and 5
>>> such ERRORs depending on the machine).
>>> 
>>> Then there are a few more errors while printing the line table of
>>> elf/rtld.c.
>>> 
>>>> so I'm curious which part of the test fills the buffer exactly.  Also,
>>> 
>>> Interesting. This fails on all 4 of the machines I tried, covering
>>> aarch64-linux, armv8l-linux-gnueabihf and x86_84-linux. Do you have
>>> libc6 debuginfo installed?
>>
>> I do, on my Ubuntu system, but my build wasn't configured to use it.  I
>> added --with-separate-debug-dir=/usr/lib/debug to my build (it defaults
>> to /usr/local/lib/debug), and now my GDB picks up the debug info for
>> libc.
>>
>> The "maint info line-table" test is specifically written in a way to
>> deal with large output.  It uses gdb_test_multiple with different -re
>> patterns to match the different expected lines.  expect reads some
>> output from GDB, then tries to match any -re line.  If there's a match,
>> the text that matched is removed from the expect buffer.  When there
>> isn't enough data in the buffer, expect reads more GDB output.  This
>> way, we consume the GDB output line by line and avoid having all the
>> huge output of the command in the buffer at the same time.
>>
>> See this commit:
>>
>> https://gitlab.com/gnutools/binutils-gdb/-/commit/f610ab6d3cbab5d8b8ef3f3a93dd81a800ec5725
>>
>> I added some "puts" in each -re clause, to see which matched (see diff
>> at the end).  With "make check", it looks fine, this -re (which matches
>> table entries) gets matched often:
>>
>>   -re "^$decimal\[ \t\]+$decimal\[ \t\]+$hex\[ \t\]+$hex\[^\r\n\]*\r\n"
>>
>> But with "make check-read1", it doesn't get matched and we accumulate
>> lots of output in the buffer.  I follow the test execution with `tail -F
>> testsuite/gdb.log` on another terminal, and I see the output coming in
>> slower and slower (presumably because expect tries to match our patterns
>> on an ever growing buffer).
>>
>> So I think this is what you should dig into, why doesn't this -re get
>> matched with read1.  Note that the ^ at the beginning of the regex means
>> that this regex will match only against some output at the very
>> beginning of the buffer.  So if there is some unmatched output in the
>> buffer before what this line intends to match, it won't match.
>>
>> The culprits are likely the regexes that finish with an unbounded
>> repetition like [^\r\n]*.  When characters are read one by one in the
>> buffer, the regex can match early and leave something in the buffer that
>> it would have otherwise matched, if the reads were done in big chunks as
>> usual (this is precisely the kind of issue that read1 means to uncover).
>> Those regexes would need to be modified to consume the entire line, even
>> with read1.
>
> Thank you for the detailed explanation and for the debug patch! I'll dig
> further into it and see if I can fix the testcase.

The patch below is what you are looking for.

Thanks,
Andrew

---

diff --git a/gdb/testsuite/gdb.base/maint.exp b/gdb/testsuite/gdb.base/maint.exp
index c05d0987e7f..d24b0affbaf 100644
--- a/gdb/testsuite/gdb.base/maint.exp
+++ b/gdb/testsuite/gdb.base/maint.exp
@@ -386,11 +386,11 @@ gdb_test "maint" \
 set saw_srcfile 0
 gdb_test_multiple "maint info line-table" \
     "maint info line-table w/o a file name" {
-    -re "symtab: \[^\n\r\]+${srcfile} \\(\\(struct symtab \\*\\) $hex\\)\r\nlinetable: \\(\\(struct linetable \\*\\) $hex\\):\r\nINDEX\[ \t\]+LINE\[ \t\]+REL-ADDRESS\[ \t\]+UNREL-ADDRESS\[^\r\n\]*" {
+    -re "symtab: \[^\n\r\]+${srcfile} \\(\\(struct symtab \\*\\) $hex\\)\r\nlinetable: \\(\\(struct linetable \\*\\) $hex\\):\r\nINDEX\[ \t\]+LINE\[ \t\]+REL-ADDRESS\[ \t\]+UNREL-ADDRESS\[^\r\n\]*\r\n" {
 	set saw_srcfile 1
 	exp_continue
     }
-    -re "symtab: \[^\n\r\]+ \\(\\(struct symtab \\*\\) $hex\\)\r\nlinetable: \\(\\(struct linetable \\*\\) $hex\\):\r\nINDEX\[ \t\]+LINE\[ \t\]+REL-ADDRESS\[ \t\]+UNREL-ADDRESS\[^\r\n\]*" {
+    -re "symtab: \[^\n\r\]+ \\(\\(struct symtab \\*\\) $hex\\)\r\nlinetable: \\(\\(struct linetable \\*\\) $hex\\):\r\nINDEX\[ \t\]+LINE\[ \t\]+REL-ADDRESS\[ \t\]+UNREL-ADDRESS\[^\r\n\]*\r\n" {
 	# Match each symtab to avoid overflowing expect's buffer.
 	exp_continue
     }

Re: [PATCH] gdb/testsuite: Bump up 'match_max'

[Thiago Jung Bauermann]

Hello Andrew,

Andrew Burgess <aburgess@redhat.com> writes:

> Thiago Jung Bauermann via Gdb-patches <gdb-patches@sourceware.org>
> writes:
>
>> Simon Marchi <simark@simark.ca> writes:
>>
>>> On 2023-10-04 18:43, Thiago Jung Bauermann wrote:
>>>> 
>>>> Hello Simon,
>>>> 
>>>> Thanks for looking into this.
>>>> 
>>>> Simon Marchi <simark@simark.ca> writes:
>>>> 
>>> The "maint info line-table" test is specifically written in a way to
>>> deal with large output.  It uses gdb_test_multiple with different -re
>>> patterns to match the different expected lines.  expect reads some
>>> output from GDB, then tries to match any -re line.  If there's a match,
>>> the text that matched is removed from the expect buffer.  When there
>>> isn't enough data in the buffer, expect reads more GDB output.  This
>>> way, we consume the GDB output line by line and avoid having all the
>>> huge output of the command in the buffer at the same time.
>>>
>>> See this commit:
>>>
>>> https://gitlab.com/gnutools/binutils-gdb/-/commit/f610ab6d3cbab5d8b8ef3f3a93dd81a800ec5725
>>>
>>> I added some "puts" in each -re clause, to see which matched (see diff
>>> at the end).  With "make check", it looks fine, this -re (which matches
>>> table entries) gets matched often:
>>>
>>>   -re "^$decimal\[ \t\]+$decimal\[ \t\]+$hex\[ \t\]+$hex\[^\r\n\]*\r\n"
>>>
>>> But with "make check-read1", it doesn't get matched and we accumulate
>>> lots of output in the buffer.  I follow the test execution with `tail -F
>>> testsuite/gdb.log` on another terminal, and I see the output coming in
>>> slower and slower (presumably because expect tries to match our patterns
>>> on an ever growing buffer).
>>>
>>> So I think this is what you should dig into, why doesn't this -re get
>>> matched with read1.  Note that the ^ at the beginning of the regex means
>>> that this regex will match only against some output at the very
>>> beginning of the buffer.  So if there is some unmatched output in the
>>> buffer before what this line intends to match, it won't match.
>>>
>>> The culprits are likely the regexes that finish with an unbounded
>>> repetition like [^\r\n]*.  When characters are read one by one in the
>>> buffer, the regex can match early and leave something in the buffer that
>>> it would have otherwise matched, if the reads were done in big chunks as
>>> usual (this is precisely the kind of issue that read1 means to uncover).
>>> Those regexes would need to be modified to consume the entire line, even
>>> with read1.
>>
>> Thank you for the detailed explanation and for the debug patch! I'll dig
>> further into it and see if I can fix the testcase.
>
> The patch below is what you are looking for.

Indeed it is! I was just going to start digging into this issue. Thank
you very much for fixing it.

I tested it on the machines I mentioned before, and all tests pass in
all of them. It even runs a lot faster now, too.

Tested-by: Thiago Jung Bauermann <thiago.bauermann@linaro.org>

-- 
Thiago

Re: [PATCH] gdb/testsuite: Bump up 'match_max'

[Andrew Burgess]

Thiago Jung Bauermann <thiago.bauermann@linaro.org> writes:

> Hello Andrew,
>
> Andrew Burgess <aburgess@redhat.com> writes:
>
>> Thiago Jung Bauermann via Gdb-patches <gdb-patches@sourceware.org>
>> writes:
>>
>>> Simon Marchi <simark@simark.ca> writes:
>>>
>>>> On 2023-10-04 18:43, Thiago Jung Bauermann wrote:
>>>>> 
>>>>> Hello Simon,
>>>>> 
>>>>> Thanks for looking into this.
>>>>> 
>>>>> Simon Marchi <simark@simark.ca> writes:
>>>>> 
>>>> The "maint info line-table" test is specifically written in a way to
>>>> deal with large output.  It uses gdb_test_multiple with different -re
>>>> patterns to match the different expected lines.  expect reads some
>>>> output from GDB, then tries to match any -re line.  If there's a match,
>>>> the text that matched is removed from the expect buffer.  When there
>>>> isn't enough data in the buffer, expect reads more GDB output.  This
>>>> way, we consume the GDB output line by line and avoid having all the
>>>> huge output of the command in the buffer at the same time.
>>>>
>>>> See this commit:
>>>>
>>>> https://gitlab.com/gnutools/binutils-gdb/-/commit/f610ab6d3cbab5d8b8ef3f3a93dd81a800ec5725
>>>>
>>>> I added some "puts" in each -re clause, to see which matched (see diff
>>>> at the end).  With "make check", it looks fine, this -re (which matches
>>>> table entries) gets matched often:
>>>>
>>>>   -re "^$decimal\[ \t\]+$decimal\[ \t\]+$hex\[ \t\]+$hex\[^\r\n\]*\r\n"
>>>>
>>>> But with "make check-read1", it doesn't get matched and we accumulate
>>>> lots of output in the buffer.  I follow the test execution with `tail -F
>>>> testsuite/gdb.log` on another terminal, and I see the output coming in
>>>> slower and slower (presumably because expect tries to match our patterns
>>>> on an ever growing buffer).
>>>>
>>>> So I think this is what you should dig into, why doesn't this -re get
>>>> matched with read1.  Note that the ^ at the beginning of the regex means
>>>> that this regex will match only against some output at the very
>>>> beginning of the buffer.  So if there is some unmatched output in the
>>>> buffer before what this line intends to match, it won't match.
>>>>
>>>> The culprits are likely the regexes that finish with an unbounded
>>>> repetition like [^\r\n]*.  When characters are read one by one in the
>>>> buffer, the regex can match early and leave something in the buffer that
>>>> it would have otherwise matched, if the reads were done in big chunks as
>>>> usual (this is precisely the kind of issue that read1 means to uncover).
>>>> Those regexes would need to be modified to consume the entire line, even
>>>> with read1.
>>>
>>> Thank you for the detailed explanation and for the debug patch! I'll dig
>>> further into it and see if I can fix the testcase.
>>
>> The patch below is what you are looking for.
>
> Indeed it is! I was just going to start digging into this issue. Thank
> you very much for fixing it.
>
> I tested it on the machines I mentioned before, and all tests pass in
> all of them. It even runs a lot faster now, too.
>
> Tested-by: Thiago Jung Bauermann <thiago.bauermann@linaro.org>

Thanks.  Pushed the patch below.

Thanks,
Andrew

---

commit 2f349e7d2ac51d29994db57498accd38f893f200
Author: Andrew Burgess <aburgess@redhat.com>
Date:   Fri Oct 6 18:01:42 2023 +0100

    gdb/testsuite: match complete lines in gdb.base/maint.exp
    
    This thread:
    
      https://inbox.sourceware.org/gdb-patches/20231003195338.334948-1-thiago.bauermann@linaro.org/
    
    pointed out that within gdb.base/maint.exp, some regexps within a
    gdb_test_multiple were failing to match a complete line, while later
    regexps within the gdb_test_multiple made use of the '^' anchor, and
    so assumed that earlier lines had been completely matched and removed
    from expect's buffer.
    
    When testing with READ1 set this assumption was failing.
    
    Fix this by extending the offending patterns with a trailing '\r\n'.
    
    Tested-by: Thiago Jung Bauermann <thiago.bauermann@linaro.org>

diff --git a/gdb/testsuite/gdb.base/maint.exp b/gdb/testsuite/gdb.base/maint.exp
index c05d0987e7f..d24b0affbaf 100644
--- a/gdb/testsuite/gdb.base/maint.exp
+++ b/gdb/testsuite/gdb.base/maint.exp
@@ -386,11 +386,11 @@ gdb_test "maint" \
 set saw_srcfile 0
 gdb_test_multiple "maint info line-table" \
     "maint info line-table w/o a file name" {
-    -re "symtab: \[^\n\r\]+${srcfile} \\(\\(struct symtab \\*\\) $hex\\)\r\nlinetable: \\(\\(struct linetable \\*\\) $hex\\):\r\nINDEX\[ \t\]+LINE\[ \t\]+REL-ADDRESS\[ \t\]+UNREL-ADDRESS\[^\r\n\]*" {
+    -re "symtab: \[^\n\r\]+${srcfile} \\(\\(struct symtab \\*\\) $hex\\)\r\nlinetable: \\(\\(struct linetable \\*\\) $hex\\):\r\nINDEX\[ \t\]+LINE\[ \t\]+REL-ADDRESS\[ \t\]+UNREL-ADDRESS\[^\r\n\]*\r\n" {
 	set saw_srcfile 1
 	exp_continue
     }
-    -re "symtab: \[^\n\r\]+ \\(\\(struct symtab \\*\\) $hex\\)\r\nlinetable: \\(\\(struct linetable \\*\\) $hex\\):\r\nINDEX\[ \t\]+LINE\[ \t\]+REL-ADDRESS\[ \t\]+UNREL-ADDRESS\[^\r\n\]*" {
+    -re "symtab: \[^\n\r\]+ \\(\\(struct symtab \\*\\) $hex\\)\r\nlinetable: \\(\\(struct linetable \\*\\) $hex\\):\r\nINDEX\[ \t\]+LINE\[ \t\]+REL-ADDRESS\[ \t\]+UNREL-ADDRESS\[^\r\n\]*\r\n" {
 	# Match each symtab to avoid overflowing expect's buffer.
 	exp_continue
     }