401767 - Leopard GDB complains of .o files having newer timestamp than executable

Status: RESOLVED FIXED

(Firefox Build System :: General, defect, P2)

Description

[Nick Kreeger]

Starting a Mozilla (trunk) build into the GDB that is supplied with Leopard results in excessive output of .o vs. executable timestamp conflicts:

...
warning: .o file "/<Full Path>/sm_debug/SMDebug/layout/build/nsJSEnvironment.o" more recent than executable timestamp
...

I initially filed a bug with Apple.. and here is the response I got:

When using DWARF, the debug information is left in the .o files, and the linker writes a reference to the .o file in the main executable when it links up the executable, so the debugger can find it.  This reference includes the timestamp of the .o file as it was when the link was done.  Then in gdb, there is a straight comparison between the current mtime of the file, and that written by the linker.  If the timestamps are different, gdb is correct to complain, since the bad effects of using debug information that probably doesn't correspond to the executable you are debugging can be serious.

gdb should'nt get this wrong if the .o files have in fact NOT been touched, since it just uses stat, and the time in the exectuable...  You can verify this yourself, however.  First, to see the timestamps recorded in the binary by the linker do:

> nm -ap <PATH TO BINARY> | grep OSO

gdbrulez:tot-new-co/build/gdb > nm -ap gdb | grep OSO
47194799 - 00 0001   OSO /Users/jingham/build/gdb/gdb.o

The times are in hex (without the leading "0x") in the first field, so in this case the time is 0x47194799.

You can compare this to the time returned by "stat -r" for that .o file:

gdbrulez:tot-new-co/build/gdb > stat -r /Volumes/Users/jingham/build/gdb/gdb.o
234881035 9174576 0100644 1 2560 11 0 2784 1193768845 1192839065 1192839065 1192839065 4096 8 0 /Volumes/Users/jingham/build/gdb/gdb.o
> gdb
...
(gdb) p/x 1192839065
$1 = 0x47194799

So ours are equal.  Is it indeed the case for you that the .o file's stat time is more recent than that in the executable?  It seems more likely that something else is touching your .o files after the link.

If you have indeed not rebuilt the .o files between the time you did the final link and the time you started debugging, then you'll need to figure out what else in your build system is touching these files, and get it not to do that.  If you have to touch the .o files for some reason, then make a dSYM file with dsymutil right after linking but before you touch the .o files, and then use that dSYM file for debugging instead.


Using this bug as a tracker.

Comment 1

[Michael Mullin]

Are there any work arounds I can do to solve this problem for myself?

Comment 2

[Vladimir Vukicevic [:vlad] [:vladv] (needinfo me, slow to respond)]

Well:

warning: .o file "/Users/vladimir/proj/mozilla-cvs/firefox/toolkit/library/nsAppData.o" more recent than executable timestamp

vladimir@h-232[47]% nm -ap ~/proj/mozilla-cvs/firefox/dist/bin/XUL | grep OSO | grep nsAppData.o
47289b5a - 00 0001   OSO /Users/vladimir/proj/mozilla-cvs/firefox/toolkit/library/nsAppData.o

vladimir@h-232[48]% stat -r ~/proj/mozilla-cvs/firefox/toolkit/library/nsAppData.o
234881026 1548048 0120755 1 501 501 0 29 1193843546 1193843546 1193843546 1193843546 4096 8 0 /Users/vladimir/proj/mozilla-cvs/firefox/toolkit/library/nsAppData.o

(gdb) p/x 1193843546
$1 = 0x47289b5a

Sure looks equal to me.

Comment 3

[Nick Kreeger]

I got this followup from the Apple radar bug - been too swamped to give it a try:

<GMT30-Oct-2007 19:53:30GMT> SABRINA FULLHART:
before you touch the .o files, and then use that dSYM file for debugging instead

Comment 4

[Matthew Gregan [:kinetik]]

So... this was starting to get on my nerves, so I did a bit more poking
around.  The warning is emitted by open_bfd_from_oso in GDB's dbxread.c.
open_bfd_from_oso is called with a |struct partial_symtab| which contains a
filename of
/Users/kinetik/work/mozilla-cvs/mozilla/toolkit/xre/nsXREDirProvider.cpp.
This is passed to bfd_openr, which returns a |struct bfd| which contains a
filename of
/Users/kinetik/work/mozilla-cvs/obj-i386-apple-darwin9.0.0/toolkit/library/nsConsoleWriter.o.

This second filename is actually a symlink to the first in our build system.
The second filename is passed to bfd_get_mtime, which eventually calls fstat
on the already open file descriptor for the file, and the return value is
stored in mtime.  This gives us the current mtime of the actual file.

The stored mtime is read from the oso_mtime field of the passed in |struct
partial_symtab|.  This value is not the same as the mtime we read from the
actual file, and it turns out is actually the mtime of the symlink.  What's
interesting is that the filename passed in via |struct partial_symtab| is
the path to the actual file, not the symlink.

Comment 5

[Matthew Gregan [:kinetik]]

Er, whoops.  I meant to say that /Users/kinetik/work/mozilla-cvs/obj-i386-apple-darwin9.0.0/toolkit/library/nsConsoleWriter.o is a symlink to ../../toolkit/xre/nsXREDirProvider.o.  So when resolving from the source file named passed in via the partial_symtab, we end up with the path to the symlink, not to the original object file.  The problem seems to be that the mtime stored in the object file is read from the symlink, not from the real file.

Comment 6

[Matthew Gregan [:kinetik]]

Hrm, rereading my last comments it looks like I had some trouble with synchronization between my brain and the paste buffer.  Sorry about that.  To clarify what I was trying to say earlier:

For any given object file that GDB warns about, it turns out that the object file is a symlink to the same file in another directory (e.g. toolkit/library/showOSAlert.o -> toolkit/xre/showOSAlert.o).  Tracing through open_bfd_from_oso in GDB shows that the mtime read from the OSO debug info is the same as the mtime on the symlink itself, not the target object file.  The current mtime is read via fstat on the file descriptor for the opened BFD, which returns the mtime of the object file (not the symlink).

Breakpoint 1, open_bfd_from_oso (pst=0x84273c, cached=0xbfffd51c) at /Users/kinetik/src/gdb-768/src/gdb/dbxread.c:3332
3332	  *cached = 0;
(gdb) p pst->filename
$1 = 0x8427a0 "showOSAlert.cpp"
(gdb) p pst->oso_name
$2 = 0x8427cc "/Users/kinetik/work/mozilla-cvs/obj-i386-apple-darwin9.1.0/toolkit/library/showOSAlert.o"
(gdb) p pst->oso_mtime
$3 = 1195452747
(gdb) p pst->objfile->name
$4 = 0x4487b0 "/Users/kinetik/work/mozilla-cvs/obj-i386-apple-darwin9.1.0/toolkit/library/XUL"
3357	      mtime = bfd_get_mtime (retval);
(gdb) p mtime
$5 = 1195452542

% ls -l toolkit/library/showOSAlert.o 
lrwxr-xr-x  1 kinetik  staff  31 19 Nov 19:12 toolkit/library/showOSAlert.o@ -> ../../toolkit/xre/showOSAlert.o
% stat -f "%m" toolkit/library/showOSAlert.o
1195452747
% stat -f "%m" toolkit/xre/showOSAlert.o    
1195452542
% nm -ap toolkit/library/XUL | grep 'OSO.*showOSAlert'
4741294b - 00 0001   OSO /Users/kinetik/work/mozilla-cvs/obj-i386-apple-darwin9.1.0/toolkit/library/showOSAlert.o
% gdb
(gdb) p/d 0x4741294b
$1 = 1195452747

It seems wrong that the mtime recorded in the OSO debug info entry in toolkit/library/XUL is from the symlink rather than the symlink target, so I guess that is the root problem here, but I'm not a toolchain expert.

Comment 7

[Stan Shebs]

This is fallout from my fix for basic dwarf2 debugging in 363590 . Apparently touching the dylib post-symlink is not sufficient to fix up all the mtime checks.

Comment 8

[Josh Aas]

Nominating as blocking 1.9 because even though this is debug-only, we really shouldn't make everyone who deals with debugging Gecko 1.9 over the next few years deal with it. *Super* annoying.

Comment 9

[Stan Shebs]

OK, doing the symlinking before making the dylib seems to work, ld being happy to chase though links. Gonna do a bit more testing before posting a patch.

Comment 10

[Stan Shebs]

Attachment: better dwarf2 patch for rules.mk

This patch simply moves the symlinking of unpacked .o files up before the main library link. It works because the linker does symlinks just fine, and everything happens in the proper order, rather than trying to fix it up later.

Comment 11

[Reed Loden [:reed]]

Stan, is this ready to be check-in? If so, add the checkin-needed keyword, and I'll land it for you.

Comment 12

[Stan Shebs]

Attachment: better dwarf2 patch for rules.mk, tweaked

I moved an echo command out of the loop, so build log gets a note about the symlinking, but only once per shared lib, so it helps for build debugging without cluttering up the log. Retested build, just to be safe.

Comment 13

[Josh Aas]

landed on trunk, thanks Stan

Comment 14

[Daniel Holbert [:dholbert] (PTO until 2/24)]

Attachment: tentative branch patch

I had some missing .o files when compiling a Branch debug build, and Stan directed me to the trunk patches for bug 363590 and for this bug here.

I'm attaching a patch that is the result of combining & tweaking those two patches so that they apply cleanly to branch.  This patch fixed my "missing .o files" issue on my branch build -- I'm not sure it's correct, but I'm posting it here in case anyone else finds it useful.