gdb/testsuite: Bump up 'match_max'

  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(-)
  

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
  

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...
  

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
     }
 }
  

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 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
     }
  

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 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
     }