Closed Bug 467271 Opened 11 years ago Closed 11 years ago

JS not being PGOed on win32

Categories

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

x86
Windows XP
defect
Not set
major

Tracking

(Not tracked)

VERIFIED FIXED

People

(Reporter: RyanVM, Assigned: ted)

References

Details

(Keywords: fixed1.9.1, regression)

Attachments

(1 file, 1 obsolete file)

During a PGO build, all of the pgc files are supposed to be deleted from dist/bin. However, js3250!1.pgc remains.
Do you have a build log from when this happens? I'd like to see if there are any error messages when pgomerge.py is run on js3250.dll. It would be in the second  build pass, in the export phase.
I did a logged build, and this is what came up:
PGOMGR : warning PG0188: No .PGC files matching 'js3250!*.pgc' were found.
PGOMGR : warning PG0188: No .PGC files matching 'js!*.pgc' were found.
js3250.pgd(0) : warning C4961: No profile data was merged into 'js3250.pgd', profile-guided optimizations disabled
js.pgd(0) : warning C4961: No profile data was merged into 'js.pgd', profile-guided optimizations disabled
   Creating library js3250.lib and object js3250.exp
   Creating library js.lib and object js.exp

For the record, if I look for other .pgc files in the log, normal looking entries like the one below appear.
Microsoft (R) Profile Guided Optimization Manager 8.00.50727.762
Copyright (C) Microsoft Corporation. All rights reserved.

Merging ..\..\dist\bin\xul!1.pgc
Those "No .PGC files matching..." lines are normal, as the linker tries to run pgomgr by itself, and there aren't ever files there for it. I just looked at a Firefox nightly config, and saw this:

make[4]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32-nightly/build/obj-firefox/js/src'
/local/bin/make export
make[5]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32-nightly/build/obj-firefox/js/src'
make[6]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32-nightly/build/obj-firefox/js/src/config'
make[7]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32-nightly/build/obj-firefox/js/src/config/mkdepend'
make[7]: Leaving directory `/e/builds/moz2_slave/mozilla-central-win32-nightly/build/obj-firefox/js/src/config/mkdepend'
make[6]: Leaving directory `/e/builds/moz2_slave/mozilla-central-win32-nightly/build/obj-firefox/js/src/config'
/d/mozilla-build/python25/python /e/builds/moz2_slave/mozilla-central-win32-nightly/build/js/src/build/win32/pgomerge.py \
	  js ./dist/bin
mkdir -p nanojit
make[5]: Leaving directory `/e/builds/moz2_slave/mozilla-central-win32-nightly/build/obj-firefox/js/src'
/local/bin/make libs
make[5]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32-nightly/build/obj-firefox/js/src'
link -NOLOGO -DLL -OUT:js3250.dll -PDB:js3250.pdb -SUBSYSTEM:WINDOWS  jsapi.obj jsarena.obj jsarray.obj jsatom.obj jsbool.obj jscntxt.obj jsdate.obj jsdbgapi.obj jsdhash.obj jsdtoa.obj jsemit.obj jsexn.obj jsfun.obj jsgc.obj jshash.obj jsinterp.obj jsinvoke.obj jsiter.obj jslock.obj jslog2.obj jslong.obj jsmath.obj jsnum.obj jsobj.obj json.obj jsopcode.obj jsparse.obj jsprf.obj jsregexp.obj jsscan.obj jsscope.obj jsscript.obj jsstr.obj jsutil.obj jsxdrapi.obj jsxml.obj prmjtime.obj jstracer.obj Assembler.obj Fragmento.obj LIR.obj RegAlloc.obj avmplus.obj Nativei386.obj jsbuiltins.obj    js3240.res -NXCOMPAT -SAFESEH -DYNAMICBASE -MANIFEST:NO  -DEBUG -OPT:REF -OPT:nowin98 -LTCG:PGUPDATE   -OPT:NOICF e:/builds/moz2_slave/mozilla-central-win32-nightly/build/obj-firefox/dist/lib/nspr4.lib e:/builds/moz2_slave/mozilla-central-win32-nightly/build/obj-firefox/dist/lib/plc4.lib e:/builds/moz2_slave/mozilla-central-win32-nightly/build/obj-firefox/dist/lib/plds4.lib  kernel32.lib user32.lib gdi32.lib winmm.lib wsock32.lib advapi32.lib   
PGOMGR : warning PG0188: No .PGC files matching 'js3250!*.pgc' were found.
js3250.pgd(0) : warning C4961: No profile data was merged into 'js3250.pgd', profile-guided optimizations disabled
   Creating library js3250.lib and object js3250.exp

Specifically:
/d/mozilla-build/python25/python /e/builds/moz2_slave/mozilla-central-win32-nightly/build/js/src/build/win32/pgomerge.py \
	  js ./dist/bin

I notice that it's looking for the pgc files in js/src/dist/bin, where they're not going to be because the DLL file that was run during the profiling phase is in ../../dist/bin. I would expect this to mean that PGO isn't working at all for JS since the JS-autoconf landing, which surprises me greatly.

Jim: is there a way to specify the top-level dist/bin directory here:
http://mxr.mozilla.org/mozilla-central/source/config/rules.mk#846
so that this will work as intended?
I think one would need to pass it in as a parameter to js/src/configure.in.  As suggested in bug 467583, perhaps js/src should just use the top-level dist directory when being built in-tree.
So, is this happening with the official builds too?
Looks like it, yes.
If this is happening with official builds, that means that js3250.dll isn't getting PGO-optimized currently. That's a big deal and should block the release.
Flags: blocking1.9.1?
Summary: js3250!1.pgc remain in dist/bin during a PGO build → js3250!1.pgc remains in dist/bin during a PGO build
This should block. I just realized it's in Build Config. I think sayrer would agree.
Flags: blocking1.9.1? → blocking1.9.1+
Severity: normal → major
Jim, can you take this?
Assignee: nobody → jim
I've got a plausible patch for this on bug 467583; testing on a PGO build now.
Status: NEW → ASSIGNED
OK, with Jim's patch applied, I was surprised to see no change in my Sunspider numbers. So, I did a logged build and this seems relevant:
Microsoft (R) Profile Guided Optimization Manager 8.00.50727.762
Copyright (C) Microsoft Corporation. All rights reserved.

Merging ..\..\dist\bin\js3250!1.pgc
PGOMGR : warning PG1052: The instrumentation data file '..\..\dist\bin\js3250!1.pgc' belongs to a different profile database.
make[5]: Leaving directory `/c/mozbuild/mozilla/objdir-fx/js/src'
make[5]: Entering directory `/c/mozbuild/mozilla/objdir-fx/js/src'
PGOMGR : warning PG0188: No .PGC files matching 'js!*.pgc' were found.
PGOMGR : warning PG0188: No .PGC files matching 'js3250!*.pgc' were found.
js3250.pgd(0) : warning C4961: No profile data was merged into 'js3250.pgd', profile-guided optimizations disabled
js.pgd(0) : warning C4961: No profile data was merged into 'js.pgd', profile-guided optimizations disabled
   Creating library js3250.lib and object js3250.exp
   Creating library js.lib and object js.exp
Generating code
Generating code

So, Jim's patch does indeed get js3250!1.pgc removed from dist/bin, but not in useful form!
Ryan: was that a completely clean build? Jim's patch doesn't change anything that would change the way that the pgd/pgc files would be generated. Just wondering if you have some extra cruft hanging out.
I did a full clobber immediately after first applying the patch, but not before this specific build. Last time I checked, PGO builds don't require full clobbers between every build, right? I'll try again when I get home from work tonight with another full clobber just to be sure.
Right, but in this particular case you may have old pgc files laying around.
I've been able to confirm that after killing my objdir, I still get this error. Moreover, the Tinderbox logs from after bug 467853 landed also show the same error:
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1229983954.1229995932.24361.gz&fulltext=1
/d/mozilla-build/python25/python /e/builds/moz2_slave/mozilla-central-win32/build/js/src/build/win32/pgomerge.py \
	  js ./../../dist/bin
Microsoft (R) Profile Guided Optimization Manager 8.00.50727.762
Copyright (C) Microsoft Corporation. All rights reserved.

Merging ..\..\dist\bin\js3250!1.pgc
PGOMGR : warning PG1052: The instrumentation data file '..\..\dist\bin\js3250!1.pgc' belongs to a different profile database.

I've also confirmed that the Tinderbox logs prior to that landing don't show the error when pgomerge.py runs on js/src.

As I mentioned on IRC earlier, I think it might be related to js3250.lib appearing to be built multiple times during the process, but maybe I'm off-base.

So, the good news is that js3250!1.pgc isn't remaining in dist/bin anymore. The bad news is that it appears that it's still not being used for PGO :-)
The MSDN page for that error message:
http://msdn.microsoft.com/en-us/library/710x59s4.aspx
says ".pgc files were found on disk whose names are correct for the merging into the current .pgd file, but the time stamp on the .pgc file shows that it was created for a different application than the one currently being profiled." I wonder if it's just choking on timestamp differences? Jim: with your patch from bug 467583 we should be using nsinstall to copy the produced DLL from js/src to ../../dist/bin, but are we still invoking the install-runtime-libs target (which uses install) and then clobbering the resulting DLL without preserving timestamps?
Actually, huh (from the log Ryan linked):

link -NOLOGO -DLL -OUT:js3250.dll -PDB:js3250.pdb -SUBSYSTEM:WINDOWS  jsapi.obj jsarena.obj jsarray.obj jsatom.obj jsbool.obj jscntxt.obj jsdate.obj jsdbgapi.obj jsdhash.obj jsdtoa.obj jsemit.obj jsexn.obj jsfun.obj jsgc.obj jshash.obj jsinterp.obj jsinvoke.obj jsiter.obj jslock.obj jslog2.obj jslong.obj jsmath.obj jsnum.obj jsobj.obj json.obj jsopcode.obj jsparse.obj jsprf.obj jsregexp.obj jsscan.obj jsscope.obj jsscript.obj jsstr.obj jsutil.obj jsxdrapi.obj jsxml.obj prmjtime.obj jstracer.obj Assembler.obj Fragmento.obj LIR.obj RegAlloc.obj avmplus.obj Nativei386.obj jsbuiltins.obj     -NXCOMPAT -SAFESEH -DYNAMICBASE -MANIFEST:NO  -DEBUG -OPT:REF -OPT:nowin98 -LTCG:PGINSTRUMENT   -OPT:NOICF e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/nspr4.lib e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/plc4.lib e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/plds4.lib  kernel32.lib user32.lib gdi32.lib winmm.lib wsock32.lib advapi32.lib   
link -NOLOGO -OUT:js.exe -PDB:js.pdb  -NXCOMPAT -SAFESEH -DYNAMICBASE -MANIFEST:NO  -DEBUG -OPT:REF -OPT:nowin98 -LTCG:PGINSTRUMENT   -OPT:NOICF js.obj jsapi.obj jsarena.obj jsarray.obj jsatom.obj jsbool.obj jscntxt.obj jsdate.obj jsdbgapi.obj jsdhash.obj jsdtoa.obj jsemit.obj jsexn.obj jsfun.obj jsgc.obj jshash.obj jsinterp.obj jsinvoke.obj jsiter.obj jslock.obj jslog2.obj jslong.obj jsmath.obj jsnum.obj jsobj.obj json.obj jsopcode.obj jsparse.obj jsprf.obj jsregexp.obj jsscan.obj jsscope.obj jsscript.obj jsstr.obj jsutil.obj jsxdrapi.obj jsxml.obj prmjtime.obj jstracer.obj Assembler.obj Fragmento.obj LIR.obj RegAlloc.obj avmplus.obj Nativei386.obj jsbuiltins.obj  e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/nspr4.lib e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/plc4.lib e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/plds4.lib   kernel32.lib user32.lib gdi32.lib winmm.lib wsock32.lib advapi32.lib
   Creating library js3250.lib and object js3250.exp
   Creating library js.lib and object js.exp
Generating code
Generating code
Finished generating code
Finished generating code
chmod +x js3250.dll
/d/mozilla-build/moztools/bin/nsinstall -m 755 js3250.lib ./../../dist/lib
/d/mozilla-build/moztools/bin/nsinstall -m 755 js3250.dll ./../../dist/bin
/d/mozilla-build/moztools/bin/nsinstall -m 755 js.exe ./../../dist/bin
/d/mozilla-build/moztools/bin/nsinstall -m 755 host_jskwgen.exe host_jsoplengen.exe ./../../dist/host/bin
make[6]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src/config'
make[7]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src/config/mkdepend'
/d/mozilla-build/moztools/bin/nsinstall -m 755 mkdepend.exe ../../../../dist/host/bin
make[7]: Leaving directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src/config/mkdepend'
make[6]: Leaving directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src/config'
/d/mozilla-build/moztools/bin/nsinstall -m 755 js3250.lib ../../dist/sdk/lib
make[5]: Leaving directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src'
/local/bin/make tools
make[5]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src'
make[6]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src/config'
make[7]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src/config/mkdepend'
make[7]: Nothing to be done for `tools'.
make[7]: Leaving directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src/config/mkdepend'
make[6]: Leaving directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src/config'
make[5]: Leaving directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src'
make[4]: Leaving directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src'
/local/bin/make export_tier_js
make[4]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox'
export_tier_js
make[5]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox'
/bin/perl /e/builds/moz2_slave/mozilla-central-win32/build/build/autoconf/make-makefile -t /e/builds/moz2_slave/mozilla-central-win32/build -d .  config/js/Makefile
creating config/js/Makefile
make[5]: Leaving directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox'
make[5]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/config/js'
/local/bin/make -C ../../js/src JS_MOZ_INSTALL=t install
make[6]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src'
/d/mozilla-build/moztools/bin/nsinstall -m 644 js-config.h jsautocfg.h jsautokw.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/js.msg /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsapi.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsarray.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsarena.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsatom.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsbit.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsbool.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsclist.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jscntxt.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jscompat.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsdate.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsdbgapi.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsdhash.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsdtoa.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsemit.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsfun.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsgc.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jshash.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsinterp.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsiter.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jslock.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jslong.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsmath.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsnum.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsobj.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/json.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsopcode.tbl /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsopcode.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsotypes.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsparse.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsprf.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsproto.tbl /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsprvtd.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jspubtd.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsregexp.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsscan.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsscope.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsscript.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsstaticcheck.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsstddef.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsstr.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jstracer.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jstypes.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsutil.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsversion.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsxdrapi.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsxml.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/builtins.tbl /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jsbuiltins.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/nanojit/Assembler.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/nanojit/LIR.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/nanojit/avmplus.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/nanojit/Fragmento.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/nanojit/Native.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/nanojit/Nativei386.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/nanojit/RegAlloc.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/nanojit/nanojit.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/nanojit/TraceTreeDrawer.h /e/builds/moz2_slave/mozilla-central-win32/build/js/src/jscpucfg.h e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/include/js
link -NOLOGO -OUT:js.exe -PDB:js.pdb  -NXCOMPAT -SAFESEH -DYNAMICBASE -MANIFEST:NO  -DEBUG -OPT:REF -OPT:nowin98 -LTCG:PGINSTRUMENT   -OPT:NOICF js.obj jsapi.obj jsarena.obj jsarray.obj jsatom.obj jsbool.obj jscntxt.obj jsdate.obj jsdbgapi.obj jsdhash.obj jsdtoa.obj jsemit.obj jsexn.obj jsfun.obj jsgc.obj jshash.obj jsinterp.obj jsinvoke.obj jsiter.obj jslock.obj jslog2.obj jslong.obj jsmath.obj jsnum.obj jsobj.obj json.obj jsopcode.obj jsparse.obj jsprf.obj jsregexp.obj jsscan.obj jsscope.obj jsscript.obj jsstr.obj jsutil.obj jsxdrapi.obj jsxml.obj prmjtime.obj jstracer.obj Assembler.obj Fragmento.obj LIR.obj RegAlloc.obj avmplus.obj Nativei386.obj jsbuiltins.obj  e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/nspr4.lib e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/plc4.lib e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/plds4.lib   kernel32.lib user32.lib gdi32.lib winmm.lib wsock32.lib advapi32.lib
link -NOLOGO -DLL -OUT:js3250.dll -PDB:js3250.pdb -SUBSYSTEM:WINDOWS  jsapi.obj jsarena.obj jsarray.obj jsatom.obj jsbool.obj jscntxt.obj jsdate.obj jsdbgapi.obj jsdhash.obj jsdtoa.obj jsemit.obj jsexn.obj jsfun.obj jsgc.obj jshash.obj jsinterp.obj jsinvoke.obj jsiter.obj jslock.obj jslog2.obj jslong.obj jsmath.obj jsnum.obj jsobj.obj json.obj jsopcode.obj jsparse.obj jsprf.obj jsregexp.obj jsscan.obj jsscope.obj jsscript.obj jsstr.obj jsutil.obj jsxdrapi.obj jsxml.obj prmjtime.obj jstracer.obj Assembler.obj Fragmento.obj LIR.obj RegAlloc.obj avmplus.obj Nativei386.obj jsbuiltins.obj     -NXCOMPAT -SAFESEH -DYNAMICBASE -MANIFEST:NO  -DEBUG -OPT:REF -OPT:nowin98 -LTCG:PGINSTRUMENT   -OPT:NOICF e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/nspr4.lib e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/plc4.lib e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/plds4.lib  kernel32.lib user32.lib gdi32.lib winmm.lib wsock32.lib advapi32.lib   
   Creating library js.lib and object js.exp
Generating code
   Creating library js3250.lib and object js3250.exp
Generating code
Finished generating code
/d/mozilla-build/moztools/bin/nsinstall -m 755 js-config js.exe e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/bin
Finished generating code
chmod +x js3250.dll
/d/mozilla-build/moztools/bin/nsinstall -m 755 js3250.dll e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib
/d/mozilla-build/moztools/bin/nsinstall -m 755 js3250.lib e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib
make[6]: Leaving directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src'
/local/bin/make -C ../../js/src JS_MOZ_INSTALL=t install-runtime-libs libdir=../../dist/bin
make[6]: Entering directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src'
link -NOLOGO -DLL -OUT:js3250.dll -PDB:js3250.pdb -SUBSYSTEM:WINDOWS  jsapi.obj jsarena.obj jsarray.obj jsatom.obj jsbool.obj jscntxt.obj jsdate.obj jsdbgapi.obj jsdhash.obj jsdtoa.obj jsemit.obj jsexn.obj jsfun.obj jsgc.obj jshash.obj jsinterp.obj jsinvoke.obj jsiter.obj jslock.obj jslog2.obj jslong.obj jsmath.obj jsnum.obj jsobj.obj json.obj jsopcode.obj jsparse.obj jsprf.obj jsregexp.obj jsscan.obj jsscope.obj jsscript.obj jsstr.obj jsutil.obj jsxdrapi.obj jsxml.obj prmjtime.obj jstracer.obj Assembler.obj Fragmento.obj LIR.obj RegAlloc.obj avmplus.obj Nativei386.obj jsbuiltins.obj     -NXCOMPAT -SAFESEH -DYNAMICBASE -MANIFEST:NO  -DEBUG -OPT:REF -OPT:nowin98 -LTCG:PGINSTRUMENT   -OPT:NOICF e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/nspr4.lib e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/plc4.lib e:/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/dist/lib/plds4.lib  kernel32.lib user32.lib gdi32.lib winmm.lib wsock32.lib advapi32.lib   
   Creating library js3250.lib and object js3250.exp
Generating code
Finished generating code
chmod +x js3250.dll
/d/mozilla-build/moztools/bin/nsinstall -m 755 js3250.dll ../../dist/bin
/d/mozilla-build/moztools/bin/nsinstall -m 755 js3250.lib ../../dist/bin
make[6]: Leaving directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/js/src'
/d/mozilla-build/moztools/bin/nsinstall -m 755 ../../dist/bin/js-config ../../dist/sdk/bin
make[5]: Leaving directory `/e/builds/moz2_slave/mozilla-central-win32/build/obj-firefox/config/js'

The install-runtime-libs target appears to be re-linking js3250.dll for some reason!
See bug 471097 comment 6 for an explanation of why this happens.
It seems like bug 471188 is going to resolve this.
Depends on: 471188
Assignee: jim → ted.mielczarek
Summary: js3250!1.pgc remains in dist/bin during a PGO build → JS not being PGOed on win32
With the patch for bug 471188 applied to a clean tree and objdir, js3250.lib no longer ends up in dist/bin. However, I'm still seeing this error during the PGO linking stage.

make[5]: Entering directory `/c/mozbuild/mozilla-central/objdir-fx/js/src'
make[6]: Entering directory `/c/mozbuild/mozilla-central/objdir-fx/js/src/config'
make[6]: Leaving directory `/c/mozbuild/mozilla-central/objdir-fx/js/src/config'
Microsoft (R) Profile Guided Optimization Manager 8.00.50727.762
Copyright (C) Microsoft Corporation. All rights reserved.

Merging ..\..\dist\bin\js3250!1.pgc
PGOMGR : warning PG1052: The instrumentation data file '..\..\dist\bin\js3250!1.pgc' belongs to a different profile data
base.
make[5]: Leaving directory `/c/mozbuild/mozilla-central/objdir-fx/js/src'
make[4]: Leaving directory `/c/mozbuild/mozilla-central/objdir-fx'
make[4]: Entering directory `/c/mozbuild/mozilla-central/objdir-fx'
libs_tier_js
make[5]: Entering directory `/c/mozbuild/mozilla-central/objdir-fx/js/src'
PGOMGR : warning PG0188: No .PGC files matching 'js!*.pgc' were found.
PGOMGR : warning PG0188: No .PGC files matching 'js3250!*.pgc' were found.

So still the same issue?
The plot thickens. I cloned revision 237234abe806 to a new repo, which was the last revision in mozilla-central prior to the 2008/10/29 landing of the js build system patches. Here's what I get during the PGO linking phase of the resulting build:

make[5]: Entering directory `/c/mozbuild/mozilla-old/objdir-fx/js/src'
Creating ../../dist/include/js
Microsoft (R) Profile Guided Optimization Manager 8.00.50727.762
Copyright (C) Microsoft Corporation. All rights reserved.

Merging ..\..\dist\bin\js3250!1.pgc
PGOMGR : warning PG1052: The instrumentation data file '..\..\dist\bin\js3250!1.pgc' belongs to a different profile data
base.
make[5]: Leaving directory `/c/mozbuild/mozilla-old/objdir-fx/js/src'
make[4]: Leaving directory `/c/mozbuild/mozilla-old/objdir-fx'
make[4]: Entering directory `/c/mozbuild/mozilla-old/objdir-fx'
libs_tier_js
make[5]: Entering directory `/c/mozbuild/mozilla-old/objdir-fx/js/src'
PGOMGR : warning PG0188: No .PGC files matching 'js!*.pgc' were found.
PGOMGR : warning PG0188: No .PGC files matching 'js3250!*.pgc' were found.
js.pgd(0) : warning C4961: No profile data was merged into 'js.pgd', profile-guided optimizations disabled
js3250.pgd(0) : warning C4961: No profile data was merged into 'js3250.pgd', profile-guided optimizations disabled
   Creating library js3250.lib and object js3250.exp
   Creating library js.lib and object js.exp

Look familiar? :-)

So, I would say that the patch in bug 471188 does indeed get us back to where we were before. However, we still have the pesky issue of JS apparently not actually getting PGOed. It just turns out that that might have always been the case (which is kind of scary).
(In reply to comment #21)
> So, I would say that the patch in bug 471188 does indeed get us back to where
> we were before. However, we still have the pesky issue of JS apparently not
> actually getting PGOed. It just turns out that that might have always been the
> case (which is kind of scary).

Or awesome: easy performance win!
We had results published in blogs last year that showed PGO'ed JS wins. I don't believe we never PGO'ed SpiderMonkey.

/be
I agree. SunSpider was one of the tests I used when I was originally working on Win32 PGO. Seems unlikely that we'd have significant (~10%) perf wins there without actually PGOing SpiderMonkey. I can reproduce Ryan's results in comment 20, so I'm going to continue to look at this.

Strangely, if I run the first half of the PGO build process (make -C objdir/ MOZ_PROFILE_GENERATE=1), then run Firefox, then manually merge the pgc file, it appears to work:
$ pgomgr -merge ./dist/bin/js3250\!1.pgc ./js/src/js3250.pgd
Microsoft (R) Profile Guided Optimization Manager 8.00.50727.762
Copyright (C) Microsoft Corporation. All rights reserved.

Merging ./dist/bin/js3250!1.pgc

But running "make -C js/src MOZ_PROFILE_USE=1" gives the error from comment 20.
After making comment #21, I had two other thoughts. This is a regression from an even earlier checkin (probably more likely), or is it possible that the 10% SS PGO win came purely from libxul's PGOing? As we saw with the OSX painting fix last year, it is possible for non-JS changes to have a dramatic effect on SS scores.

I'm going to try hunting down a regression range tonight. Unfortunately, the tinderbox logs that might have helped track this down have been long-since purged, so it's going to have to be done the long way.
(In reply to comment #15)
> /d/mozilla-build/python25/python
> /e/builds/moz2_slave/mozilla-central-win32/build/js/src/build/win32/pgomerge.py
> \
>       js ./../../dist/bin
> Microsoft (R) Profile Guided Optimization Manager 8.00.50727.762
> Copyright (C) Microsoft Corporation. All rights reserved.
> 
> Merging ..\..\dist\bin\js3250!1.pgc
> PGOMGR : warning PG1052: The instrumentation data file
> '..\..\dist\bin\js3250!1.pgc' belongs to a different profile database.

I'm looking at this log, trying to figure out why it looks wrong, and it finally hit. The PGO build code didn't expect there to be a shared library and an executable in the same directory, so it's trying to merge js3250!1.pgc into js.pgd (which goes with the JS shell). D'oh! Should be an easy patch (on top of the patch from bug 471188).
This patch appears to work. I'm going to do a full PGO clobber build to check.
This works. (Turns out it works better if you actually fix the copies of the files in js/src.)
Attachment #355961 - Attachment is obsolete: true
Attachment #355985 - Flags: review?(benjamin)
Attachment #355985 - Flags: review?(benjamin) → review+
Not a real big win:
** TOTAL **:           1.03x as fast     1356.6ms +/- 0.9%   1318.6ms +/- 1.0%     significant

Full comparison:
http://pastebin.mozilla.org/608419

That's my local PGO build vs. yesterday's nightly (pre the TM merge from last night on both counts). shaver notes that we probably don't even hit the tracer in our current profiling scenario, where we startup, load a mostly-blank page, and shut down. (We execute almost no content JS.)
Thats definitively a bad profile choice. I PGO'd using icc and sunspider as profile input and final target and got 40% speedup (ballpark).
Well, it's not *terrible*. Keep in mind that we're PGOing the entire platform here, so this does buy us ~10% on most of our other performance tests. We just happen to not be giving spidermonkey very good profiling input.
Blocks: 472706
Pushed to m-c:
http://hg.mozilla.org/mozilla-central/rev/2e8178964532

I'll get this and all the required deps in 1.9.1 once they bake for a bit.
Status: ASSIGNED → RESOLVED
Closed: 11 years ago
Resolution: --- → FIXED
(and we'll deal with getting better profiling input in bug 472706)
How come we missed this regression in the performance plots?
Confirmed no more whining about a bad .pgc file during PGO linking.

Also nice:
1075 of 3114 ( 34.52) profiled functions will be compiled for speed
3114 of 3114 functions (100.0) were optimized using profile data
743657492 of 743657492 instructions (100.0) were optimized using profile data

(And the 34.52% number definitely suggests room for more speed improvement in bug 472706 - though it still beats libxul's paltry 3.14% hands-down)

SunSpider Before/After:
Revision 4de172f0d8b8 - 1343.6ms +/- 1.5%
Current Tip - 1308.0ms +/- 1.5%
So the same 1.03x as fast as Ted saw.

-V.FIXED
Status: RESOLVED → VERIFIED
(In reply to comment #34)
> How come we missed this regression in the performance plots?

I suspect it's not a very big deal in the post-tracemonkey world with the profiling input we're feeding it. Hopefully bug 472706 will help here.
Ryan, could you try using sunspider as profile instead of empty browser startup? Only if its easy to do but I would really be curious to see the results.
Traces use C-compiled builtins a lot, and much of that has preferred paths that PGO probably finds.
Asked for approval on all the dep bugs here, so we can get this into 1.9.1.
a191's now been granted on all those deps, although there was no patch on bug 472881 fwiw.
Right, that was a dupe of bug 471359 (which had a patch and you granted approval on). Thanks!
Blocks: 475111
Product: Core → Firefox Build System
You need to log in before you can comment on or make changes to this bug.