Re: [PATCH] New testcase for PR tui/25126 (staled source cache)

Andrew Burgess
2020-02-08T00:27:21Z

* Sergio Durigan Junior <sergiodj@redhat.com> [2020-02-07 15:11:46 -0500]:

> On Friday, February 07 2020, I wrote:
>
> > On Friday, February 07 2020, I wrote:
> >
> >> On Friday, February 07 2020, Andrew Burgess wrote:
> >>> I'm not suggesting that you need to track down the cause of this
> >>> issue, but I agree with Luis that we should avoid arbitrary short
> >>> pauses.
> >>>
> >>> I think you could probably use gdb_get_line_number to solve this
> >>> problem, something like this completely untested code:
> >>>
> >>> # In some cases it has been observed that the file-system doesn't
> >>> # immediately reflect the rename. Here we wait for the file to
> >>> # reflect the expected new contents.
> >>> proc wait_for_rename {} {
> >>> global srcfile
> >>> for { set i 0 } { $i < 5 } { incr i } {
> >>> if { ![catch { gdb_get_line_number \
> >>> "pattern only matching the new line" \
> >>> ${srcfile} }] } {
> >>> return
> >>> }
> >>> sleep 1
> >>> }
> >>> error "file failed to rename correctly"
> >>> }
> >>
> >> Ah, cool. I'll adjust that to the code. Thank you.
> >
> > OK, after trying your code, I can say that the problem is not on TCL.
> > wait_for_rename returns successfully, and I've checked that
> > gdb_get_line_number returns the correct value for the line. So, for
> > TCL, the rename succeeded.
> >
> > Here's an interesting thing: I put a gdb_interact after the second "run"
> > command, and then did:
> >
> > (gdb) list
> > 35 printf ("hello\n"); /* break-here */
> > (gdb) shell gdb.
> > gdb.log gdb.sum
> > (gdb) shell outputs/gdb.base/cached-source-file/cached-source-file
> > foo
> > hello
> >
> > See how, for GDB, the inferior doesn't have the 'printf ("foo\n");'
> > line, but when I run it externally I can see "foo" being printed? This
> > means that GCC compiled the correct file, but GDB did not load it again,
> > somehow.
> >
> > I find it extremely interesting how putting a "sleep 1" after the rename
> > magically solves this problem. I would be less intrigued if we had to
> > put "sleep 1" after "gdb_compile", because then it would hint at some
> > race condition happening with GCC and GDB (very unlikely, but easier to
> > understand).
> >
> > I didn't want to, but I guess I'll have to keep investigating this.
> > Unless you (or someone) have any other ideas.
>
> I think I found the issue. On symfile.c:reread_symbols, the check
> performed to see whether the new objfile being loaded is different than
> the previous one is based on calling 'stat' and checking 'st_mtime':
>
> ...
> new_modtime = new_statbuf.st_mtime;
> if (new_modtime != objfile->mtime)
> {
> printf_filtered (_("`%s' has changed; re-reading symbols.\n"),
> objfile_name (objfile));
> ...
>
> According to stat(2), 'st_mtime' is actually 'st_mtim.tv_sec', which
> means the precision of this field is given in seconds. Since Linux 2.6
> 'st_mtim's precision is given in nanoseconds, but we still use the
> seconds field.
>
> Because the testing script runs so fast, it's really likely that the old
> and the new files will have the same 'st_mtime'. Here's the output of
> an 'fprintf' I put in the code:
>
> new_modtime = 1581105949, old_modtime = 1581105949
>
> So yeah, we have a few options here:
>
> 1) For now, I think it's justifiable to use "sleep 1" in the code, to
> force 'st_mtime' to be different between the two files.

I think using sleep 1 is fine in this case, as the comment will now
make it clear that it's not an arbitrary delay, but a specific
_minimum_ delay to ensure the timestamp ticks over.

>
> 2) The GDB code could be modernized to use nanosecond precision, which
> should solve this problem.

Only if you want extra credit :)

Thanks for taking the time (there must be a pun here somewhere) to
investigate this.

Thanks,
Andrew

>
> Thanks,
>
> --
> Sergio
> GPG key ID: 237A 54B1 0287 28BF 00EF 31F4 D0EB 7628 65FC 5E36
> Please send encrypted e-mail if possible
> http://sergiodj.net/
>