[testsuite] Fix timeout with maint print objfiles

Message ID 20210427141044.2573352-1-luis.machado@linaro.org
State Superseded
Headers show
Series
  • [testsuite] Fix timeout with maint print objfiles
Related show

Commit Message

Pedro Franco de Carvalho via Gdb-patches April 27, 2021, 2:10 p.m.
I'm seeing timeouts from gdb.rust/traits.exp when we attempt to print
things with "maint print objfiles".

This happens for two reasons:

1 - GDB does not explicitly split each entry into its own line, but rather
    relies on the terminal's width to insert line breaks.

2 - When running the GDB testsuite, such width may be unlimited, which will
    prevent GDB from inserting any line breaks.

As a result, the output may be too lengthy and will come in big lines.  Tweak
the support library to match the patterns line-by-line, which gives us more
time to match things. Also fix GDB's output to print one entry per line,
regardless of the terminal width.

A similar approach was used in another testcase using the same command (commit
eaeaf44cfdc9a4096a0dd52fa0606f29d4bfd48e). With the new line breaks, we don't
need a particular pattern, so clean up that test as well.

gdb/ChangeLog:

YYYY-MM-DD  Luis Machado  <luis.machado@linaro.org>

	* psymtab.c (psymbol_functions::dump): Output newline.
	* symmisc.c (dump_objfile): Likewise.

gdb/testsuite/ChangeLog:

YYYY-MM-DD  Luis Machado  <luis.machado@linaro.org>

	* gdb.base/maint.exp: Drop a pattern that is not needed.
	* lib/gdb.exp (readnow): Match line-by-line.
---
 gdb/psymtab.c                    |  2 +-
 gdb/symmisc.c                    |  4 ++--
 gdb/testsuite/gdb.base/maint.exp |  3 ---
 gdb/testsuite/lib/gdb.exp        | 17 ++++++++++++-----
 4 files changed, 15 insertions(+), 11 deletions(-)

-- 
2.25.1

Comments

Pedro Franco de Carvalho via Gdb-patches April 27, 2021, 3:47 p.m. | #1
On 2021-04-27 10:10 a.m., Luis Machado via Gdb-patches wrote:
> I'm seeing timeouts from gdb.rust/traits.exp when we attempt to print

> things with "maint print objfiles".

> 

> This happens for two reasons:

> 

> 1 - GDB does not explicitly split each entry into its own line, but rather

>     relies on the terminal's width to insert line breaks.

> 

> 2 - When running the GDB testsuite, such width may be unlimited, which will

>     prevent GDB from inserting any line breaks.

> 

> As a result, the output may be too lengthy and will come in big lines.  Tweak

> the support library to match the patterns line-by-line, which gives us more

> time to match things. Also fix GDB's output to print one entry per line,

> regardless of the terminal width.

> 

> A similar approach was used in another testcase using the same command (commit

> eaeaf44cfdc9a4096a0dd52fa0606f29d4bfd48e). With the new line breaks, we don't

> need a particular pattern, so clean up that test as well.


I still see some timeout with:

  make check-read1 TESTS="gdb.rust/traits.exp" RUNTESTFLAGS="--target_board=readnow"

I think what happens is that we find "readnow" in the "maint print
objfiles" output very early, and leave the huge following output
un-consumed.

So it's the gdb_test after that, that ends up consuming it and timing
out:

FAIL: gdb.rust/traits.exp: print *td (timeout)

We should make sure that the readnow proc consumes all the output of
"maint print objfiles" before exiting (maybe that was the intention, but
it doesn't work).  You probably need some "exp_continue" in your match
clauses?

> 

> gdb/ChangeLog:

> 

> YYYY-MM-DD  Luis Machado  <luis.machado@linaro.org>

> 

> 	* psymtab.c (psymbol_functions::dump): Output newline.

> 	* symmisc.c (dump_objfile): Likewise.

> 

> gdb/testsuite/ChangeLog:

> 

> YYYY-MM-DD  Luis Machado  <luis.machado@linaro.org>

> 

> 	* gdb.base/maint.exp: Drop a pattern that is not needed.

> 	* lib/gdb.exp (readnow): Match line-by-line.

> ---

>  gdb/psymtab.c                    |  2 +-

>  gdb/symmisc.c                    |  4 ++--

>  gdb/testsuite/gdb.base/maint.exp |  3 ---

>  gdb/testsuite/lib/gdb.exp        | 17 ++++++++++++-----

>  4 files changed, 15 insertions(+), 11 deletions(-)

> 

> diff --git a/gdb/psymtab.c b/gdb/psymtab.c

> index 75a307c89aa..e3032d60343 100644

> --- a/gdb/psymtab.c

> +++ b/gdb/psymtab.c

> @@ -885,7 +885,7 @@ psymbol_functions::dump (struct objfile *objfile)

>  	  printf_filtered ("%s at ",

>  			   psymtab->filename);

>  	  gdb_print_host_address (psymtab, gdb_stdout);

> -	  printf_filtered (", ");

> +	  printf_filtered ("\n");

>  	  wrap_here ("  ");


I think we can remove wrap_here, since we don't rely on wrapping
anymore.

>  	}

>        printf_filtered ("\n\n");

> diff --git a/gdb/symmisc.c b/gdb/symmisc.c

> index d992c671635..d70c5ecda49 100644

> --- a/gdb/symmisc.c

> +++ b/gdb/symmisc.c

> @@ -131,11 +131,11 @@ dump_objfile (struct objfile *objfile)

>  	      printf_filtered ("%s at ",

>  			       symtab_to_filename_for_display (symtab));

>  	      gdb_print_host_address (symtab, gdb_stdout);

> -	      printf_filtered (", ");

>  	      if (SYMTAB_OBJFILE (symtab) != objfile)

>  		{

> -		  printf_filtered ("NOT ON CHAIN!  ");

> +		  printf_filtered (", NOT ON CHAIN!");

>  		}


Can you remove the unnecessary curly braces?

> +	      printf_filtered ("\n");

>  	      wrap_here ("  ");


Same here, I think we can remove wrap_here.

>  	    }

>  	}

> diff --git a/gdb/testsuite/gdb.base/maint.exp b/gdb/testsuite/gdb.base/maint.exp

> index e72392220cc..6831d1ba720 100644

> --- a/gdb/testsuite/gdb.base/maint.exp

> +++ b/gdb/testsuite/gdb.base/maint.exp

> @@ -230,9 +230,6 @@ gdb_test_multiple "maint print objfiles" "" -lbl {

>  	set symtabs 1

>  	exp_continue

>      }

> -    -re " at $hex," {

> -	exp_continue

> -    }

>      -re -wrap "" {

>  	pass $gdb_test_name

>      }

> diff --git a/gdb/testsuite/lib/gdb.exp b/gdb/testsuite/lib/gdb.exp

> index 943112fcc80..01012b9a5a3 100644

> --- a/gdb/testsuite/lib/gdb.exp

> +++ b/gdb/testsuite/lib/gdb.exp

> @@ -7511,17 +7511,24 @@ proc readnow { args } {

>      } else {

>  	set re ""

>      }

> +

> +    global gdb_prompt


This appears to be unused.

And on an unrelated topic, I recently learned you can refer to global
variables as ${::gdb_prompt}.  I now prefer that over declaring them as
"global".


> +    set readnow_p 0

> +    # Given the listing from the following command can be very verbose, match

> +    # the patterns line-by-line.  This prevents timeouts from waiting for

> +    # too much data to come at once.

>      set cmd "maint print objfiles $re"

> -    gdb_test_multiple $cmd "" {

> -	-re -wrap "\r\n.gdb_index: faked for \"readnow\"\r\n.*" {

> -	    return 1

> +    gdb_test_multiple $cmd "" -lbl {

> +	-re "\r\n.gdb_index: faked for \"readnow\"" {

> +	    # Record the we've seen the above pattern.

> +	    set readnow_p 1

>  	}

>  	-re -wrap "" {

> -	    return 0

> +	    # We don't care about any other input.

>  	}

>      }

>  

> -    return 0

> +    return $readnow_p

>  }

>  

>  # Return 1 if partial symbols are available.  Otherwise, return 0.

>
Pedro Franco de Carvalho via Gdb-patches April 27, 2021, 5:51 p.m. | #2
On 4/27/21 12:47 PM, Simon Marchi wrote:
> 

> 

> On 2021-04-27 10:10 a.m., Luis Machado via Gdb-patches wrote:

>> I'm seeing timeouts from gdb.rust/traits.exp when we attempt to print

>> things with "maint print objfiles".

>>

>> This happens for two reasons:

>>

>> 1 - GDB does not explicitly split each entry into its own line, but rather

>>      relies on the terminal's width to insert line breaks.

>>

>> 2 - When running the GDB testsuite, such width may be unlimited, which will

>>      prevent GDB from inserting any line breaks.

>>

>> As a result, the output may be too lengthy and will come in big lines.  Tweak

>> the support library to match the patterns line-by-line, which gives us more

>> time to match things. Also fix GDB's output to print one entry per line,

>> regardless of the terminal width.

>>

>> A similar approach was used in another testcase using the same command (commit

>> eaeaf44cfdc9a4096a0dd52fa0606f29d4bfd48e). With the new line breaks, we don't

>> need a particular pattern, so clean up that test as well.

> 

> I still see some timeout with:

> 

>    make check-read1 TESTS="gdb.rust/traits.exp" RUNTESTFLAGS="--target_board=readnow"

> 

> I think what happens is that we find "readnow" in the "maint print

> objfiles" output very early, and leave the huge following output

> un-consumed.

> 

> So it's the gdb_test after that, that ends up consuming it and timing

> out:

> 

> FAIL: gdb.rust/traits.exp: print *td (timeout)

> 

> We should make sure that the readnow proc consumes all the output of

> "maint print objfiles" before exiting (maybe that was the intention, but

> it doesn't work).  You probably need some "exp_continue" in your match

> clauses?


Exactly. I didn't exercise it with the readnow board.

Adding exp_continue to the readnow match clause seems to fix this.

> 

>>

>> gdb/ChangeLog:

>>

>> YYYY-MM-DD  Luis Machado  <luis.machado@linaro.org>

>>

>> 	* psymtab.c (psymbol_functions::dump): Output newline.

>> 	* symmisc.c (dump_objfile): Likewise.

>>

>> gdb/testsuite/ChangeLog:

>>

>> YYYY-MM-DD  Luis Machado  <luis.machado@linaro.org>

>>

>> 	* gdb.base/maint.exp: Drop a pattern that is not needed.

>> 	* lib/gdb.exp (readnow): Match line-by-line.

>> ---

>>   gdb/psymtab.c                    |  2 +-

>>   gdb/symmisc.c                    |  4 ++--

>>   gdb/testsuite/gdb.base/maint.exp |  3 ---

>>   gdb/testsuite/lib/gdb.exp        | 17 ++++++++++++-----

>>   4 files changed, 15 insertions(+), 11 deletions(-)

>>

>> diff --git a/gdb/psymtab.c b/gdb/psymtab.c

>> index 75a307c89aa..e3032d60343 100644

>> --- a/gdb/psymtab.c

>> +++ b/gdb/psymtab.c

>> @@ -885,7 +885,7 @@ psymbol_functions::dump (struct objfile *objfile)

>>   	  printf_filtered ("%s at ",

>>   			   psymtab->filename);

>>   	  gdb_print_host_address (psymtab, gdb_stdout);

>> -	  printf_filtered (", ");

>> +	  printf_filtered ("\n");

>>   	  wrap_here ("  ");

> 

> I think we can remove wrap_here, since we don't rely on wrapping

> anymore.

> 


I wasn't sure. The wrap function breaks the line if the string length is 
greater than the terminal width, no? In this case, if you have a very 
small terminal, that might influence things.

It doesn't do anything when running the testsuite though. At least for 
me, the width is unlimited in this case.

>>   	}

>>         printf_filtered ("\n\n");

>> diff --git a/gdb/symmisc.c b/gdb/symmisc.c

>> index d992c671635..d70c5ecda49 100644

>> --- a/gdb/symmisc.c

>> +++ b/gdb/symmisc.c

>> @@ -131,11 +131,11 @@ dump_objfile (struct objfile *objfile)

>>   	      printf_filtered ("%s at ",

>>   			       symtab_to_filename_for_display (symtab));

>>   	      gdb_print_host_address (symtab, gdb_stdout);

>> -	      printf_filtered (", ");

>>   	      if (SYMTAB_OBJFILE (symtab) != objfile)

>>   		{

>> -		  printf_filtered ("NOT ON CHAIN!  ");

>> +		  printf_filtered (", NOT ON CHAIN!");

>>   		}

> 

> Can you remove the unnecessary curly braces?

> 


Done.

>> +	      printf_filtered ("\n");

>>   	      wrap_here ("  ");

> 

> Same here, I think we can remove wrap_here.

> 

>>   	    }

>>   	}

>> diff --git a/gdb/testsuite/gdb.base/maint.exp b/gdb/testsuite/gdb.base/maint.exp

>> index e72392220cc..6831d1ba720 100644

>> --- a/gdb/testsuite/gdb.base/maint.exp

>> +++ b/gdb/testsuite/gdb.base/maint.exp

>> @@ -230,9 +230,6 @@ gdb_test_multiple "maint print objfiles" "" -lbl {

>>   	set symtabs 1

>>   	exp_continue

>>       }

>> -    -re " at $hex," {

>> -	exp_continue

>> -    }

>>       -re -wrap "" {

>>   	pass $gdb_test_name

>>       }

>> diff --git a/gdb/testsuite/lib/gdb.exp b/gdb/testsuite/lib/gdb.exp

>> index 943112fcc80..01012b9a5a3 100644

>> --- a/gdb/testsuite/lib/gdb.exp

>> +++ b/gdb/testsuite/lib/gdb.exp

>> @@ -7511,17 +7511,24 @@ proc readnow { args } {

>>       } else {

>>   	set re ""

>>       }

>> +

>> +    global gdb_prompt

> 

> This appears to be unused.

> 

> And on an unrelated topic, I recently learned you can refer to global

> variables as ${::gdb_prompt}.  I now prefer that over declaring them as

> "global".


Interesting. I'll use that from now on. Thanks!

> 

> 

>> +    set readnow_p 0

>> +    # Given the listing from the following command can be very verbose, match

>> +    # the patterns line-by-line.  This prevents timeouts from waiting for

>> +    # too much data to come at once.

>>       set cmd "maint print objfiles $re"

>> -    gdb_test_multiple $cmd "" {

>> -	-re -wrap "\r\n.gdb_index: faked for \"readnow\"\r\n.*" {

>> -	    return 1

>> +    gdb_test_multiple $cmd "" -lbl {

>> +	-re "\r\n.gdb_index: faked for \"readnow\"" {

>> +	    # Record the we've seen the above pattern.

>> +	    set readnow_p 1

>>   	}

>>   	-re -wrap "" {

>> -	    return 0

>> +	    # We don't care about any other input.

>>   	}

>>       }

>>   

>> -    return 0

>> +    return $readnow_p

>>   }

>>   

>>   # Return 1 if partial symbols are available.  Otherwise, return 0.

>>
Pedro Franco de Carvalho via Gdb-patches April 27, 2021, 5:59 p.m. | #3
>>> diff --git a/gdb/psymtab.c b/gdb/psymtab.c

>>> index 75a307c89aa..e3032d60343 100644

>>> --- a/gdb/psymtab.c

>>> +++ b/gdb/psymtab.c

>>> @@ -885,7 +885,7 @@ psymbol_functions::dump (struct objfile *objfile)

>>>         printf_filtered ("%s at ",

>>>                  psymtab->filename);

>>>         gdb_print_host_address (psymtab, gdb_stdout);

>>> -      printf_filtered (", ");

>>> +      printf_filtered ("\n");

>>>         wrap_here ("  ");

>>

>> I think we can remove wrap_here, since we don't rely on wrapping

>> anymore.

>>

> 

> I wasn't sure. The wrap function breaks the line if the string length is greater than the terminal width, no? In this case, if you have a very small terminal, that might influence things.

> 

> It doesn't do anything when running the testsuite though. At least for me, the width is unlimited in this case.


From what I understand, it tells GDB "you could wrap here if what you
print next is going to overshoot the terminal width".  So you use it
between multiple elements printed on the same line.

But doing it just after outputting a \n doesn't make sense.

Simon

Patch

diff --git a/gdb/psymtab.c b/gdb/psymtab.c
index 75a307c89aa..e3032d60343 100644
--- a/gdb/psymtab.c
+++ b/gdb/psymtab.c
@@ -885,7 +885,7 @@  psymbol_functions::dump (struct objfile *objfile)
 	  printf_filtered ("%s at ",
 			   psymtab->filename);
 	  gdb_print_host_address (psymtab, gdb_stdout);
-	  printf_filtered (", ");
+	  printf_filtered ("\n");
 	  wrap_here ("  ");
 	}
       printf_filtered ("\n\n");
diff --git a/gdb/symmisc.c b/gdb/symmisc.c
index d992c671635..d70c5ecda49 100644
--- a/gdb/symmisc.c
+++ b/gdb/symmisc.c
@@ -131,11 +131,11 @@  dump_objfile (struct objfile *objfile)
 	      printf_filtered ("%s at ",
 			       symtab_to_filename_for_display (symtab));
 	      gdb_print_host_address (symtab, gdb_stdout);
-	      printf_filtered (", ");
 	      if (SYMTAB_OBJFILE (symtab) != objfile)
 		{
-		  printf_filtered ("NOT ON CHAIN!  ");
+		  printf_filtered (", NOT ON CHAIN!");
 		}
+	      printf_filtered ("\n");
 	      wrap_here ("  ");
 	    }
 	}
diff --git a/gdb/testsuite/gdb.base/maint.exp b/gdb/testsuite/gdb.base/maint.exp
index e72392220cc..6831d1ba720 100644
--- a/gdb/testsuite/gdb.base/maint.exp
+++ b/gdb/testsuite/gdb.base/maint.exp
@@ -230,9 +230,6 @@  gdb_test_multiple "maint print objfiles" "" -lbl {
 	set symtabs 1
 	exp_continue
     }
-    -re " at $hex," {
-	exp_continue
-    }
     -re -wrap "" {
 	pass $gdb_test_name
     }
diff --git a/gdb/testsuite/lib/gdb.exp b/gdb/testsuite/lib/gdb.exp
index 943112fcc80..01012b9a5a3 100644
--- a/gdb/testsuite/lib/gdb.exp
+++ b/gdb/testsuite/lib/gdb.exp
@@ -7511,17 +7511,24 @@  proc readnow { args } {
     } else {
 	set re ""
     }
+
+    global gdb_prompt
+    set readnow_p 0
+    # Given the listing from the following command can be very verbose, match
+    # the patterns line-by-line.  This prevents timeouts from waiting for
+    # too much data to come at once.
     set cmd "maint print objfiles $re"
-    gdb_test_multiple $cmd "" {
-	-re -wrap "\r\n.gdb_index: faked for \"readnow\"\r\n.*" {
-	    return 1
+    gdb_test_multiple $cmd "" -lbl {
+	-re "\r\n.gdb_index: faked for \"readnow\"" {
+	    # Record the we've seen the above pattern.
+	    set readnow_p 1
 	}
 	-re -wrap "" {
-	    return 0
+	    # We don't care about any other input.
 	}
     }
 
-    return 0
+    return $readnow_p
 }
 
 # Return 1 if partial symbols are available.  Otherwise, return 0.