Re: [RFC][gdb/testsuite] Add check-readmore

[Tom de Vries via Gdb-patches <gdb-patches@sourceware.org>]

[-- Attachment #1: Type: text/plain, Size: 5021 bytes --]

On 8/26/21 5:09 AM, Simon Marchi wrote:
> 
> 
> On 2021-06-08 3:24 a.m., Tom de Vries wrote:
>> Hi,
>>
>> Consider the gdb output:
>> ...
>> 27        return SYSCALL_CANCEL (nanosleep, requested_time, remaining);^M
>> (gdb) ^M
>> Thread 2 "run-attach-whil" stopped.^M
>> ...
>>
>> When trying to match the gdb prompt using gdb_test which uses '$gdb_prompt $',
>> it may pass or fail.
>>
>> This sort of thing needs to be fixed (see commit b0e2f96b56b), but there's
>> currently no way to reliably find this type of FAILs.
>>
>> We have check-read1, but that one actually make the test pass reliably.
>>
>> We need something like the opposite of check-read1: something that makes
>> expect read a bit slower, or more exhaustively.
>>
>> Add a new test target check-readmore that implements this.
>>
>> Atm there are still two methods of implementing this in read1.c:
>> - the first method waits a bit before doing a read
>> - the second method does a read and then decides whether to
>>   return or to wait a bit and do another read.
>>
>> Atm the first method is enabled by default, given that it is more foolproof.
>> The second method tries to be smart about waiting less than the first method,
>> but consequently needs to make decisions about error codes, which is more
>> fragile.
>>
>> Tested on x86_64-linux, both with method 1 and 2.
>>
>> Any comments?
> 
> Is there an advantage to method 2 over method 1?

Yes.

Consider attached debug patch, and then running test-case
gdb.base/info-macros.exp:
...
$ rm -f LOG; ./test.sh -readmore
...
which gives us attached LOG.gz.

We get sequences like this:
...
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 4096
READ: fd: 5, COUNT: 4096, RES: 2659
...

With method 1, we wait some time before for _each_ read.

With method 2, we wait some time after the last read, and only for that
read.

There's an incentive to increase sleep time, because larger sleep time
has the potential of catching more errors.

OTOH there's an incentive to not let sleep time to grow to large because
that will cause unnecessary timeouts.

The first method multiplies sleep time quite rapidly and will hit the
timeouts sooner than method 2.

And besides the timeouts, method 2 is faster than method 1.

The drawback of method2 is that it's technically more complicated: it
inspects the return status of read, and potentially does a second read.
 It needs to know whether to do the second read, and it needs to know
which errors from the second read to ignore.  There's simply more scope
for errors and corner-cases.

> If not, I'd just go
> with the simplest.  I could imagine a modified method 2 version where we
> read in a loop though, until we reached "count" bytes or the file
> descriptor has no more data to offer (still with a 10ms wait between
> each read, to give the writer time to produce more data).

Agreed, there could be some benefit in doing this in a loop.  It would
add a benefit similar to increasing the timeout, without the drawback of
waiting unnecessary while the buffer is already full.

Thanks,
- Tom

[-- Attachment #2: 0002-debug.patch --]
[-- Type: text/x-patch, Size: 1195 bytes --]

debug

---
 gdb/testsuite/lib/read1.c | 9 +++++++--
 1 file changed, 7 insertions(+), 2 deletions(-)

diff --git a/gdb/testsuite/lib/read1.c b/gdb/testsuite/lib/read1.c
index 1f3cd4393a1..eded36d6c1f 100644
--- a/gdb/testsuite/lib/read1.c
+++ b/gdb/testsuite/lib/read1.c
@@ -32,6 +32,7 @@ ssize_t
 read (int fd, void *buf, size_t count)
 {
   static ssize_t (*read2) (int fd, void *buf, size_t count) = NULL;
+  static FILE *log = NULL;
   if (read2 == NULL)
     {
       /* Use setenv (v, "", 1) rather than unsetenv (v) to work around
@@ -40,6 +41,7 @@ read (int fd, void *buf, size_t count)
 	 for existence from another interp".  */
       setenv ("LD_PRELOAD", "", 1);
       read2 = dlsym (RTLD_NEXT, "read");
+      log = fopen ("/home/vries/gdb_versions/devel/LOG", "a");
     }
 
 #ifdef READMORE
@@ -48,10 +50,13 @@ read (int fd, void *buf, size_t count)
 #if 1
   /* READMORE, method 1.  */
 
+#if 0
   if (isatty (fd) != 0)
     usleep (10 * 1000);
-  return read2 (fd, buf, count);
-
+#endif
+  ssize_t res = read2 (fd, buf, count);
+  fprintf (log, "READ: fd: %d, COUNT: %zd, RES: %zd\n", fd, count, res);
+  return res;
 #else
   /* READMORE, method 2.  */
   ssize_t res, res2;

[-- Attachment #3: LOG.gz --]
[-- Type: application/gzip, Size: 678 bytes --]