Last Comment Bug 480735 - Startup timeline
: Startup timeline
Status: RESOLVED FIXED
[ts]
: dev-doc-needed
Product: Core
Classification: Components
Component: General (show other bugs)
: Trunk
: All All
: -- normal (vote)
: mozilla1.9.3a5
Assigned To: Vladimir Vukicevic [:vlad] [:vladv]
:
:
Mentors:
Depends on: 560717 582466
Blocks: 447581 503605 604849
  Show dependency treegraph
 
Reported: 2009-02-28 11:18 PST by Vladimir Vukicevic [:vlad] [:vladv]
Modified: 2011-02-01 06:30 PST (History)
33 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
startup-instrument.patch (32.41 KB, patch)
2009-02-28 11:18 PST, Vladimir Vukicevic [:vlad] [:vladv]
no flags Details | Diff | Splinter Review
startup-instrument.patch (50.98 KB, patch)
2009-05-27 14:57 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
startup-instrument.patch - unbitrotted (again) (48.25 KB, patch)
2009-07-08 14:23 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
Added macros that wrap the nsFuntionTimer functionality (49.79 KB, patch)
2009-07-09 11:50 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
WIP - does not build (51.32 KB, patch)
2009-07-13 17:06 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
PR_LOG conversion take 1. No Buildy:( (51.54 KB, patch)
2009-07-14 15:18 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
PR_LOG conversion take 2 (51.41 KB, patch)
2009-07-14 18:18 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
WIP - linking fails (50.51 KB, patch)
2009-07-15 11:46 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
WIP: scoping issues - syntax problem? (50.97 KB, patch)
2009-07-16 09:26 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
WIP - libxul build issue (50.91 KB, patch)
2009-07-16 16:47 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
WIP - Cpp Patch (6.89 KB, patch)
2009-07-16 18:15 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
WIP - JS patch (5.97 KB, patch)
2009-07-16 18:16 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
WIP - Instrumentation patch (37.02 KB, patch)
2009-07-16 18:17 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
nsAppRunner Instrumentation Patch for testing current linking error (1.98 KB, patch)
2009-07-20 14:40 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
updated patch (14.74 KB, patch)
2009-07-20 16:15 PDT, Vladimir Vukicevic [:vlad] [:vladv]
benjamin: review-
Details | Diff | Splinter Review
WIP - removing more fprintf calls (14.74 KB, patch)
2009-07-21 16:41 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
v0.2 - instrumentation - unbitrotted (36.90 KB, patch)
2009-07-21 16:42 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
v0.3 - instrumentation - latest (36.65 KB, patch)
2009-07-22 10:46 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
0.1 FunctionTimer Patch (4.64 KB, patch)
2009-07-27 12:09 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
add PR_GetLogModule (2.73 KB, patch)
2009-07-30 13:31 PDT, Vladimir Vukicevic [:vlad] [:vladv]
no flags Details | Diff | Splinter Review
add PR_GetLogModule, v2 (2.52 KB, patch)
2009-07-30 14:47 PDT, Vladimir Vukicevic [:vlad] [:vladv]
wtc: review-
Details | Diff | Splinter Review
functiontimer code (10.14 KB, patch)
2009-07-30 16:25 PDT, Vladimir Vukicevic [:vlad] [:vladv]
no flags Details | Diff | Splinter Review
add PR_GetLogModule, v3 (4.52 KB, patch)
2009-08-08 13:27 PDT, Vladimir Vukicevic [:vlad] [:vladv]
no flags Details | Diff | Splinter Review
add PR_GetLogModule, v4 (4.71 KB, patch)
2009-08-11 12:55 PDT, Vladimir Vukicevic [:vlad] [:vladv]
wtc: review+
gal: review+
Details | Diff | Splinter Review
v 0.4 instrumentation-patch - unbitrotted (36.79 KB, patch)
2009-08-21 17:18 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
v 0.5 instrumentation-patch - unbitrotted (36.54 KB, patch)
2009-08-24 13:13 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
v 0.6 unbitrotted instrumentation patch (39.64 KB, patch)
2009-09-21 17:47 PDT, David Dahl :ddahl
no flags Details | Diff | Splinter Review
Timeline Crash Stacks and output on Windows 7 (18.63 KB, text/plain)
2009-09-21 17:50 PDT, David Dahl :ddahl
no flags Details
v 0.6 unbitrotted instrumentation patch (40.32 KB, patch)
2009-12-02 15:10 PST, :Ehsan Akhgari
no flags Details | Diff | Splinter Review
backtrace from debug build crash on start (2.34 KB, text/plain)
2009-12-04 15:02 PST, David Dahl :ddahl
no flags Details
updated code (9.31 KB, patch)
2010-03-30 10:40 PDT, Vladimir Vukicevic [:vlad] [:vladv]
no flags Details | Diff | Splinter Review
updated (13.66 KB, patch)
2010-04-15 13:45 PDT, Vladimir Vukicevic [:vlad] [:vladv]
no flags Details | Diff | Splinter Review
updated, v2 (14.18 KB, patch)
2010-04-16 16:49 PDT, Vladimir Vukicevic [:vlad] [:vladv]
benjamin: review+
Details | Diff | Splinter Review
(AAv1-CC) Copy it to comm-central [Moved to bug 604849] (1.22 KB, patch)
2010-04-21 02:34 PDT, Serge Gautherie (:sgautherie)
no flags Details | Diff | Splinter Review

Description Vladimir Vukicevic [:vlad] [:vladv] 2009-02-28 11:18:33 PST
Created attachment 364702 [details] [diff] [review]
startup-instrument.patch

The attached patch generates a timeline of a bunch of events during startup, focusing on the time between XRE_main start and calling Run().  Bugs resulting from this data should be marked as blocking this bug.
Comment 1 David Dahl :ddahl 2009-05-27 14:57:07 PDT
Created attachment 379970 [details] [diff] [review]
startup-instrument.patch

Unbitrotted the patch - builds on trunk (as of today)
Comment 2 David Dahl :ddahl 2009-07-08 14:23:07 PDT
Created attachment 387534 [details] [diff] [review]
startup-instrument.patch - unbitrotted (again)

WIP - saving work. Starting to figure out the best way to make this part of the trunk tree
Comment 3 David Dahl :ddahl 2009-07-09 11:50:32 PDT
Created attachment 387688 [details] [diff] [review]
Added macros that wrap the nsFuntionTimer functionality

Still a work in progress...

I added #ifdef NS_FUNCTION_TIMER, then I created some macros to wrap the ft init and ft.Mark as well as fta init and fta.Mark

I am not sure how to set up an ac_add_option or make argument to define NS_FUNCTION_TIMER
Comment 4 Brian Crowder 2009-07-09 11:55:43 PDT
ddahl:  Have you looked at the timeline code that already existed, out of curiosity?
Comment 5 David Dahl :ddahl 2009-07-09 12:58:37 PDT
brian: no, I have not. Is there a bug that describes it?
Comment 6 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-09 13:22:43 PDT
The existing timeline stuff is pretty grungry code and pretty hard to maintain; it also doesn't easily help with "tell me how long this function takes", which is the goal here.  Eventually the idea is to have this always built and enabled.
Comment 7 Brian Crowder 2009-07-09 14:15:34 PDT
ddahl:  No clue if it's documented anywhere.

vlad:  Can we gut the old stuff, then?
Comment 8 David Dahl :ddahl 2009-07-09 16:24:23 PDT
vlad: I added this to the end of xpcom/glue/Makefile.in:

DEFINES += -DNS_FUNCTION_TIMER

It does not seem like nsFunctionTimer is ever getting compiled now.

I commented out the #ifdef NS_FUNCTION_TIMER and recompiled, but it does not seem to create the macros defined in nsFunctionTimer.h

I also added some blatant syntax errors in nsFunctionTimer.h, but they were not caught. 

sorry for the noob questions. 

Not sure what I am doing wrong.
Comment 9 David Dahl :ddahl 2009-07-10 15:46:31 PDT
Things that need nailing down:

1. Figure out how to establish 'NS_FUNCTION_TIMER' as something that can be defined globally to turn on the "active macros" for this patch. - perhaps ted can show me how?

2. Clean up the JS implementation and make a globally-defined JS function that is a noop if the NS_FUNCTION_TIMER is not defined. (this is not as clean as the macro approach in C++land)

3. open a related bug that tracks the development of the python "output collection" and JS "visualization" via similie-widgets, example is here: http://mozilla.ddahl.com/startup/timeline-similie.html
Comment 10 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-10 21:17:26 PDT
Comment on attachment 387688 [details] [diff] [review]
Added macros that wrap the nsFuntionTimer functionality

To get the define in, you need to add it to configure.in, as a new AC_ARG_ENABLE... search for AC_DEFINE and see how it's used in some others.


Some comments:

>+#ifdef NS_FUNCTION_TIMER
>+
>+#define NS_FUNCTION_TIMER_INIT(description, ...) nsFunctionTimer ft(description, __VA_ARGS__)
>+#define NS_FUNCTION_TIMER_MARK(description, ...) ft.Mark(description, __VA_ARGS__)

Can't call this object ft all the time in a macro... better would be:

#define NS_FUNCTION_TIMER_DECLARE(_name, _desc, ...)  nsFunctionTimer _name(_desc, __VA_ARGS__)

etc.. that is, explicitly declare the name.

Maybe some convenience functions though that would declare a single timer with the function name.. something like

#define NS_FUNCTION_TIME_THIS  nsFunctionTimer ft__this(__FUNCTION__)
Comment 11 David Dahl :ddahl 2009-07-13 16:54:35 PDT
I've asked around about this error, no one seems to know what is happening.

nsIOService.cpp
/home/ddahl/code/moz/mozilla-central/mozilla/netwerk/base/src/nsIOService.cpp:199:47: warning: ISO C99 requires rest arguments to be used

/home/ddahl/code/moz/mozilla-central/mozilla/netwerk/base/src/nsIOService.cpp:199: error: expected primary-expression before ‘)’ token

make[6]: *** [nsIOService.o] Error 1
make[5]: *** [libs] Error 2
make[4]: *** [libs] Error 2
make[3]: *** [libs_tier_necko] Error 2
make[2]: *** [tier_necko] Error 2
make[1]: *** [default] Error 2
make: *** [build] Error 2


Here is the offending line of code:

NS_FUNCTION_TIMER_INIT("nsIOService::Init");


Here is the macro:

#define NS_FUNCTION_TIMER_INIT(description, ...) nsFunctionTimer ft(description, __VA_ARGS__)
Comment 12 David Dahl :ddahl 2009-07-13 16:55:39 PDT
Oh forgot to mention does it matter that nsFunctionTimer has an overloaded constructor?
Comment 13 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-13 16:59:41 PDT
That won't work -- if you have varargs in a macro you have to actually use the args.  Something that might work is:

NS_FUNCTION_TIMER_INIT(...)  nsFunctionTimer (__VA_ARGS__)

also, you can't call these objects "ft".  Use something like ft__autogen or similar.  I also wouldn't call the macro _INIT; _DECLARE is too wordy, so maybe just omit it and call it NS_FUNCTION_TIMER(...).

But, again, like I mentioned, a convenience helper like NS_TIME_FUNCTION is what you want here -- you can get the function name from __FUNCTION__ already, so the common usage would be something like:

NS_TIME_FUNCTION;

which would expand out into  nsFunctionTimer ft__autogen("%s", __FUNCTION__)

or similar.
Comment 14 David Dahl :ddahl 2009-07-13 17:06:41 PDT
Created attachment 388373 [details] [diff] [review]
WIP - does not build
Comment 15 David Dahl :ddahl 2009-07-13 17:48:55 PDT
So when using the convenience helper would the macro be defined like so:

#define NS_TIME_FUNCTION(...) nsFunctionTimer ft__autogen("%s", __FUNCTION__)(__VA_ARGS__) 

// and:

#define NS_TIME_FUNCTION_MARK(...) ft__autogen("%s", __FUNCTION__).Mark(__VA_ARGS__)

Or something like that? do the "__" in ft__autogen act like a placeholder for the __FUNCTION__ name?

Sorry for the dumb question. In python I would do something like 

macro_name = "ft_%s" % __name__

to do string replacement of the function name into the macro_name string
Comment 16 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-13 22:21:22 PDT
Nope, not quite.  There are two separate things.  One is a straightforward "time this function" shorthand.  This would be:

#define NS_TIME_FUNCTION   nsFunctionTimer ft__autogen("%s", __FUNCTION__)
#define NS_TIME_FUNCTION_MARK(...)   ft_autogen.Mark(__VA_ARGS__)

the __ in "ft__autogen" has no meaning, it's just there as a variable name that someone is highly unlikely to use in their own code.  __FUNCTION__ is special in the preprocessor, and expands out to a string containing the current function name (like __VA_ARGS__ expands out to the contents of "...").

Usage would be something like:

void Foo() {
  NS_TIME_FUNCTION;
  ...
  NS_TIME_FUNCTION_MARK("Some Step");
}

which expands out to:

void Foo() {
  nsFunctionTimer ft__autogen("%s", "Foo");
  ...
  ft__autogen.Mark("Some Step");
}

You would also want:

#define NS_TIME_FUNCTION_MIN(_ms)  nsFunctionTimer ft__autogen((_ms), "%s", __FUNCTION__)

to allow a minimum time in ms to be specified for any output.

Those are the convenience functions that would be used in most cases.  But you'd also want:

#define NS_TIME_FUNCTION_FMT(...)  nsFunctionTimer ft__autogen(__VA_ARGS__)
#define NS_TIME_FUNCTION_MIN_FMT(_ms, ...)  nsFunctionTimer ft__autogen((_ms), __VA_ARGS__)

to allow someone to use their own format string for the display instead of just using the function name.

Any other usage, e.g. using a custom object name, should just be handled by direct calls to nsFunctionTimer I guess, with some appropriate #ifdef NS_FUNCTION_TIMING around it... but I can't imagine where that would appear, though perhaps in an inner block or something?
Comment 17 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-13 22:25:06 PDT
(In reply to comment #7)
> vlad:  Can we gut the old stuff, then?

Yeah, we probably should.. looking at http://mxr.mozilla.org/mozilla-central/search?string=timeline is pretty funny.  Some timing of startup, and some intricate timing of nsCharsetMenu and nsPlatformCharset, as well as some timing of pyxpcom... and that's it.

Though hmm... we should probably convert this to use nspr logging instead of just straight printfs before checking in as well.  The logging stuff isn't too high overhead, right?
Comment 18 David Dahl :ddahl 2009-07-14 15:18:03 PDT
Created attachment 388577 [details] [diff] [review]
PR_LOG conversion take 1. No Buildy:(

Scoping issues on this try. I *think* the nsFunctionTimer class is in ok shape. The following error points to the scope of the MACRO.


nsCategoryManager.cpp
In file included from /home/ddahl/code/moz/mozilla-central/mozilla/xpcom/components/nsCategoryManager.cpp:64:
../../dist/include/nsFunctionTimer.h:118:31: warning: anonymous variadic macros were introduced in C99
../../dist/include/nsFunctionTimer.h:120:30: warning: anonymous variadic macros were introduced in C99
../../dist/include/nsFunctionTimer.h:122:39: warning: anonymous variadic macros were introduced in C99
/home/ddahl/code/moz/mozilla-central/mozilla/xpcom/components/nsCategoryManager.cpp: In function ‘nsresult NS_CreateServicesFromCategory(const char*, nsISupports*, const char*)’:
/home/ddahl/code/moz/mozilla-central/mozilla/xpcom/components/nsCategoryManager.cpp:910: error: ‘ft_autogen’ was not declared in this scope
make[5]: *** [nsCategoryManager.o] Error 1
make[4]: *** [libs] Error 2
make[3]: *** [libs_tier_xpcom] Error 2
make[2]: *** [tier_xpcom] Error 2
make[1]: *** [default] Error 2
make: *** [build] Error 2
Comment 19 David Dahl :ddahl 2009-07-14 18:18:18 PDT
Created attachment 388607 [details] [diff] [review]
PR_LOG conversion take 2

Not quite sure how to declare the PR_LOG module. Followed examples in mxr, to no avail.

nsObserverList.cpp
In file included from /home/ddahl/code/moz/mozilla-central/mozilla/xpcom/ds/nsObserverList.cpp:45:
../../dist/include/nsFunctionTimer.h:115:31: warning: anonymous variadic macros were introduced in C99
../../dist/include/nsFunctionTimer.h:117:30: warning: anonymous variadic macros were introduced in C99
../../dist/include/nsFunctionTimer.h:119:39: warning: anonymous variadic macros were introduced in C99
In file included from /home/ddahl/code/moz/mozilla-central/mozilla/xpcom/ds/nsObserverList.cpp:45:
../../dist/include/nsFunctionTimer.h:19: error: ‘PRLogModuleInfo* PR_NewLogModule(const char*)’ cannot appear in a constant-expression
../../dist/include/nsFunctionTimer.h:19: error: a function call cannot appear in a constant-expression
../../dist/include/nsFunctionTimer.h:19: error: invalid in-class initialization of static data member of non-integral type ‘PRLogModuleInfo*’
../../dist/include/nsFunctionTimer.h: In constructor ‘nsFunctionTimer::nsFunctionTimer(const char*, ...)’:
../../dist/include/nsFunctionTimer.h:55: error: ‘funcTimerLogModule’ was not declared in this scope
../../dist/include/nsFunctionTimer.h: In member function ‘void nsFunctionTimer::Mark(const char*, ...)’:
../../dist/include/nsFunctionTimer.h:78: error: ‘funcTimerLogModule’ was not declared in this scope
../../dist/include/nsFunctionTimer.h: In destructor ‘nsFunctionTimer::~nsFunctionTimer()’:
../../dist/include/nsFunctionTimer.h:96: error: ‘funcTimerLogModule’ was not declared in this scope
make[5]: *** [nsObserverList.o] Error 1
make[4]: *** [libs] Error 2
make[3]: *** [libs_tier_xpcom] Error 2
make[2]: *** [tier_xpcom] Error 2
make[1]: *** [default] Error 2
make: *** [build] Error 2
Comment 20 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-14 19:03:16 PDT
Comment on attachment 388607 [details] [diff] [review]
PR_LOG conversion take 2

For future patches, can you split out nsFunctionTimer.{h,cpp} from the actual instrumentation?  Would make it easier to review, and I think the instrumentation will need separate review.  Ideally we'd also figure out how to put the impl of this one and the js one in the same spot, but don't worry about that for now.

>--- /dev/null
>+++ b/xpcom/glue/nsFunctionTimer.h
>@@ -0,0 +1,132 @@
>+#ifndef _NSFUNCTIONTIMER_H_
>+#define _NSFUNCTIONTIMER_H_
>+
>+#define FORCE_PR_LOG
>+#include <prlog.h>
>+
>+#include "prtime.h"
>+
>+#if defined(WINCE)
>+#include <windows.h>
>+#else
>+#include <stdio.h>
>+#endif
>+
>+#include <stdarg.h>
>+
>+class nsFunctionTimer {
>+public:
>+  static PRLogModuleInfo* funcTimerLogModule;

this is right, though style nit... put a s in front of static members, that is sFuncTimerLogModule.

>+  funcTimerLogModule = PR_NewLogModule("nsFuncTimer");

That won't work :)

You need to create nsFunctionTimer.cpp, include the .h, and then do:

PRLogModuleInfo *nsFunctionTimer::funcTimerLogModule = PR_NewLogModule("functimer");


>+#ifdef WINCE
>+    PR_LOG(funcTimerLogModule, PR_LOG_NOTICE, (L"> %S", mString));
>+    // RETAILMSG(1, (L"> %S\r\n", mString));
>+#else
>+    // fprintf(stderr, "> %s\r\n", mString);
>+    PR_LOG(funcTimerLogModule, PR_LOG_NOTICE, ("> %s", mString));
>+#endif

Get rid of the WINCE ifdefs -- no need for them.  wide strings (L"...") were used with RETAILMSG because that's what it expects, but PR_LOG always expects normal 8-bit strings.
Comment 21 David Dahl :ddahl 2009-07-15 11:46:20 PDT
Created attachment 388747 [details] [diff] [review]
WIP - linking fails

sdwilsh gave me a hand trying to set up the sFuncTimerLogModule via a Logging Callback function with PR_CallOnce. Linking dies anyway, which was doing this when I created nsFunctionTimer.cpp. sdwilsh's method does not need the .cpp file, or so he thinks:)

../../toolkit/xre/libxulapp_s.a(nsAppRunner.o): In function `nsFunctionTimer::~nsFunctionTimer()':
nsAppRunner.cpp:(.text._ZN15nsFunctionTimerD1Ev[nsFunctionTimer::~nsFunctionTimer()]+0x61): undefined reference to `nsFunctionTimer::sFuncTimerLogModule'
/usr/bin/ld: ../../toolkit/xre/libxulapp_s.a(nsAppRunner.o): relocation R_386_GOTOFF against undefined hidden symbol `nsFunctionTimer::sFuncTimerLogModule' can not be used when making a shared object
/usr/bin/ld: final link failed: Bad value
collect2: ld returned 1 exit status
make[4]: *** [libxul.so] Error 1
make[3]: *** [libs_tier_toolkit] Error 2
make[2]: *** [tier_toolkit] Error 2
make[1]: *** [default] Error 2
make: *** [build] Error 2
Comment 22 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-15 14:26:15 PDT
Yes, he's wrong, don't do that :)  Just make a cpp file....
Comment 23 David Dahl :ddahl 2009-07-16 09:25:10 PDT
Searching for "NS_EXPORT" in mxr only revealed a single instance of using it to export an entire class. 

I tried it like this:

class NS_EXPORT nsFunctionTimer {
...
}

I still have scoping issues though.

One error (i cannot find it in my scrollback) was to the effect that I did not declare arguments for the class - as if it were a function.

Here is the latest error:

/home/ddahl/code/moz/mozilla-central/mozilla/xpcom/glue/nsStringAPI.cpp: In member function ‘PRInt32 nsAString::RFind(const nsAString&, PRInt32, PRInt32 (*)(const PRUnichar*, const PRUnichar*, PRUint32)) const’:
/home/ddahl/code/moz/mozilla-central/mozilla/xpcom/glue/nsStringAPI.cpp:419: warning: comparison between signed and unsigned integer expressions
/home/ddahl/code/moz/mozilla-central/mozilla/xpcom/glue/nsStringAPI.cpp: In member function ‘PRInt32 nsAString::RFind(const char*, PRInt32, PRBool) const’:
/home/ddahl/code/moz/mozilla-central/mozilla/xpcom/glue/nsStringAPI.cpp:444: warning: comparison between signed and unsigned integer expressions
/home/ddahl/code/moz/mozilla-central/mozilla/xpcom/glue/nsStringAPI.cpp: In member function ‘PRInt32 nsACString::RFind(const nsACString&, PRInt32, PRInt32 (*)(const char*, const char*, PRUint32)) const’:
/home/ddahl/code/moz/mozilla-central/mozilla/xpcom/glue/nsStringAPI.cpp:828: warning: comparison between signed and unsigned integer expressions
/home/ddahl/code/moz/mozilla-central/mozilla/xpcom/glue/nsStringAPI.cpp: In member function ‘PRInt32 nsACString::RFind(const char*, PRInt32, PRInt32 (*)(const char*, const char*, PRUint32)) const’:
/home/ddahl/code/moz/mozilla-central/mozilla/xpcom/glue/nsStringAPI.cpp:857: warning: comparison between signed and unsigned integer expressions
nsFunctionTimer.cpp

/home/ddahl/code/moz/mozilla-central/mozilla/xpcom/glue/nsFunctionTimer.cpp:41: error: expected initializer before ‘*’ token
/home/ddahl/code/moz/mozilla-central/mozilla/xpcom/glue/nsFunctionTimer.cpp: In static member function ‘static PRLogModuleInfo* nsFunctionTimer::GetFuncTimerLogModule()’:
/home/ddahl/code/moz/mozilla-central/mozilla/xpcom/glue/nsFunctionTimer.cpp:46: error: ‘sFuncTimerLogModule’ was not declared in this scope
make[5]: *** [nsFunctionTimer.o] Error 1
make[4]: *** [libs] Error 2
make[3]: *** [libs_tier_xpcom] Error 2
make[2]: *** [tier_xpcom] Error 2
make[1]: *** [default] Error 2
make: *** [build] Error 2
Comment 24 David Dahl :ddahl 2009-07-16 09:26:32 PDT
Created attachment 388928 [details] [diff] [review]
WIP: scoping issues - syntax problem?
Comment 25 David Dahl :ddahl 2009-07-16 16:47:51 PDT
Created attachment 389046 [details] [diff] [review]
WIP - libxul build issue

c++  -fno-rtti -fno-exceptions -Wall -Wpointer-arith -Woverloaded-virtual -Wsynth -Wno-ctor-dtor-privacy -Wno-non-virtual-dtor -Wcast-align -Wno-invalid-offsetof -Wno-long-long -pedantic -fno-strict-aliasing -fshort-wchar -pthread -pipe  -DNDEBUG -DTRIMMED -Os -freorder-blocks -fno-reorder-functions  -fPIC -shared -Wl,-z,defs -Wl,-h,libxul.so -o libxul.so  nsStaticXULComponents.o nsUnicharUtils.o nsCompressedCharMap.o nsBidiUtils.o nsRDFResource.o     -lpthread   -Wl,-rpath-link,/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/dist/bin -Wl,-rpath-link,/usr/local/lib  -Wl,--whole-archive ../../embedding/browser/gtk/src/libgtkembedmoz.a ../../toolkit/xre/libxulapp_s.a  ../../staticlib/components/libxpconnect.a ../../staticlib/components/libnecko.a ../../staticlib/components/libuconv.a ../../staticlib/components/libi18n.a ../../staticlib/components/libchardet.a ../../staticlib/components/libjar50.a ../../staticlib/components/libpref.a ../../staticlib/components/libcaps.a ../../staticlib/components/libhtmlpars.a ../../staticlib/components/libimglib2.a ../../staticlib/components/libgklayout.a ../../staticlib/components/libdocshell.a ../../staticlib/components/libembedcomponents.a ../../staticlib/components/libwebbrwsr.a ../../staticlib/components/libnsappshell.a ../../staticlib/components/libtxmgr.a ../../staticlib/components/libchrome.a ../../staticlib/components/libcommandlines.a ../../staticlib/components/libtoolkitcomps.a ../../staticlib/components/libpipboot.a ../../staticlib/components/libpipnss.a ../../staticlib/components/libgkplugin.a ../../staticlib/components/libmozfind.a ../../staticlib/components/libappcomps.a ../../staticlib/components/libunixproxy.a ../../staticlib/components/libxpinstall.a ../../staticlib/components/libjsd.a ../../staticlib/components/libautoconfig.a ../../staticlib/components/libauth.a ../../staticlib/components/libcookie.a ../../staticlib/components/libpermissions.a ../../staticlib/components/libuniversalchardet.a ../../staticlib/components/libcomposer.a ../../staticlib/components/librdf.a ../../staticlib/components/libwindowds.a ../../staticlib/components/libintlapp.a ../../staticlib/components/libfileview.a ../../staticlib/components/libstoragecomps.a ../../staticlib/components/libplaces.a ../../staticlib/components/libtkautocomplete.a ../../staticlib/components/libsatchel.a ../../staticlib/components/libpippki.a ../../staticlib/components/libucvmath.a ../../staticlib/components/libwidget_gtk2.a ../../staticlib/components/libsystem-pref.a ../../staticlib/components/libgkgfxthebes.a ../../staticlib/components/libaccessibility.a ../../staticlib/components/libremoteservice.a ../../staticlib/components/libspellchecker.a ../../staticlib/components/libzipwriter.a ../../staticlib/libxpcom_core.a ../../staticlib/libucvutil_s.a ../../staticlib/libgkgfx.a ../../staticlib/libgfxshared_s.a ../../staticlib/libmozreg_s.a ../../staticlib/libmorkreader_s.a ../../staticlib/libgtkxtbin.a ../../staticlib/libgfxpsshar.a ../../staticlib/libthebes.a  -Wl,--no-whole-archive -L../../dist/lib -lsqlite3 -L../../dist/bin -L../../dist/lib  -L../../dist/bin -L../../dist/lib -L../../jpeg -lmozjpeg -L../../modules/libimg/png -lmozpng ../../gfx/qcms/libmozqcms.a -L/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/dist/bin -lmozjs -L../../dist/bin -L../../dist/lib -lcrmf -lsmime3 -lssl3 -lnss3 -lnssutil3 -lsoftokn3 ../../gfx/cairo/cairo/src/libmozcairo.a ../../gfx/cairo/libpixman/src/libmozlibpixman.a   -lXrender -lfreetype -lfontconfig  -L../../modules/zlib/src -lmozz -L/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/dist/lib -lplds4 -lplc4 -lnspr4 -lpthread -ldl -L//lib -ldbus-glib-1 -ldbus-1 -lgobject-2.0 -lglib-2.0    -lX11  -lXext  -lpangoft2-1.0 -lpango-1.0 -lfreetype -lfontconfig -lgobject-2.0 -lgmodule-2.0 -lglib-2.0   -lgtk-x11-2.0 -latk-1.0 -lpangoft2-1.0 -lfreetype -lfontconfig -lgdk-x11-2.0 -lgdk_pixbuf-2.0 -lm -lpangocairo-1.0 -lgio-2.0 -lpango-1.0 -lcairo -lgobject-2.0 -lgmodule-2.0 -lglib-2.0   -lXt -lgthread-2.0 -lfreetype -lz  -lasound -ldl -lm     
../../toolkit/xre/libxulapp_s.a(nsAppRunner.o): In function `nsFunctionTimer::~nsFunctionTimer()':
nsAppRunner.cpp:(.text._ZN15nsFunctionTimerD1Ev[nsFunctionTimer::~nsFunctionTimer()]+0x60): undefined reference to `nsFunctionTimer::GetFuncTimerLogModule()'
../../toolkit/xre/libxulapp_s.a(nsAppRunner.o): In function `nsFunctionTimer::nsFunctionTimer(char const*, ...)':
nsAppRunner.cpp:(.text._ZN15nsFunctionTimerC1EPKcz[nsFunctionTimer::nsFunctionTimer(char const*, ...)]+0x50): undefined reference to `nsFunctionTimer::GetFuncTimerLogModule()'
../../toolkit/xre/libxulapp_s.a(nsAppRunner.o): In function `nsFunctionTimer::Mark(char const*, ...)':
nsAppRunner.cpp:(.text._ZN15nsFunctionTimer4MarkEPKcz[nsFunctionTimer::Mark(char const*, ...)]+0xbb): undefined reference to `nsFunctionTimer::GetFuncTimerLogModule()'
../../staticlib/components/libnecko.a(nsSocketTransportService2.o): In function `nsSocketTransportService::Init()':
nsSocketTransportService2.cpp:(.text+0x90e): undefined reference to `nsFunctionTimer::GetFuncTimerLogModule()'
../../staticlib/components/libembedcomponents.a(nsAppStartupNotifier.o): In function `nsAppStartupNotifier::Observe(nsISupports*, char const*, unsigned short const*)':
nsAppStartupNotifier.cpp:(.text+0x548): undefined reference to `nsFunctionTimer::GetFuncTimerLogModule()'
../../staticlib/components/libtoolkitcomps.a(nsAppStartup.o):nsAppStartup.cpp:(.text+0xb49): more undefined references to `nsFunctionTimer::GetFuncTimerLogModule()' follow
collect2: ld returned 1 exit status
make[1]: *** [libxul.so] Error 1
make[1]: Leaving directory `/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/toolkit/library'
make: *** [default] Error 2
make: Leaving directory `/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/toolkit/library'
Comment 26 David Dahl :ddahl 2009-07-16 18:15:54 PDT
Created attachment 389060 [details] [diff] [review]
WIP - Cpp Patch

saving my work - splitting up the patch into 3: CPP, JS and Instrumentation
Comment 27 David Dahl :ddahl 2009-07-16 18:16:39 PDT
Created attachment 389061 [details] [diff] [review]
WIP - JS patch
Comment 28 David Dahl :ddahl 2009-07-16 18:17:23 PDT
Created attachment 389062 [details] [diff] [review]
WIP - Instrumentation patch
Comment 29 David Dahl :ddahl 2009-07-20 14:02:50 PDT
Tried a few different approaches to get NS_EXPORT to make the functionTimer global. I tried going back and forth with the PRLogModuleInfo method inside the header file and then inside the cpp file. No dice, I still get this linking error:

c++  -fno-rtti -fno-exceptions -Wall -Wpointer-arith -Woverloaded-virtual -Wsynth -Wno-ctor-dtor-privacy -Wno-non-virtual-dtor -Wcast-align -Wno-invalid-offsetof -Wno-long-long -pedantic -fno-strict-aliasing -fshort-wchar -pthread -pipe  -DNDEBUG -DTRIMMED -Os -freorder-blocks -fno-reorder-functions  -fPIC -shared -Wl,-z,defs -Wl,-h,libxul.so -o libxul.so  nsStaticXULComponents.o nsUnicharUtils.o nsCompressedCharMap.o nsBidiUtils.o nsRDFResource.o     -lpthread   -Wl,-rpath-link,/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/dist/bin -Wl,-rpath-link,/usr/local/lib  -Wl,--whole-archive ../../embedding/browser/gtk/src/libgtkembedmoz.a ../../toolkit/xre/libxulapp_s.a  ../../staticlib/components/libxpconnect.a ../../staticlib/components/libnecko.a ../../staticlib/components/libuconv.a ../../staticlib/components/libi18n.a ../../staticlib/components/libchardet.a ../../staticlib/components/libjar50.a ../../staticlib/components/libpref.a ../../staticlib/components/libcaps.a ../../staticlib/components/libhtmlpars.a ../../staticlib/components/libimglib2.a ../../staticlib/components/libgklayout.a ../../staticlib/components/libdocshell.a ../../staticlib/components/libembedcomponents.a ../../staticlib/components/libwebbrwsr.a ../../staticlib/components/libnsappshell.a ../../staticlib/components/libtxmgr.a ../../staticlib/components/libchrome.a ../../staticlib/components/libcommandlines.a ../../staticlib/components/libtoolkitcomps.a ../../staticlib/components/libpipboot.a ../../staticlib/components/libpipnss.a ../../staticlib/components/libgkplugin.a ../../staticlib/components/libmozfind.a ../../staticlib/components/libappcomps.a ../../staticlib/components/libunixproxy.a ../../staticlib/components/libxpinstall.a ../../staticlib/components/libjsd.a ../../staticlib/components/libautoconfig.a ../../staticlib/components/libauth.a ../../staticlib/components/libcookie.a ../../staticlib/components/libpermissions.a ../../staticlib/components/libuniversalchardet.a ../../staticlib/components/libcomposer.a ../../staticlib/components/librdf.a ../../staticlib/components/libwindowds.a ../../staticlib/components/libintlapp.a ../../staticlib/components/libfileview.a ../../staticlib/components/libstoragecomps.a ../../staticlib/components/libplaces.a ../../staticlib/components/libtkautocomplete.a ../../staticlib/components/libsatchel.a ../../staticlib/components/libpippki.a ../../staticlib/components/libucvmath.a ../../staticlib/components/libwidget_gtk2.a ../../staticlib/components/libsystem-pref.a ../../staticlib/components/libgkgfxthebes.a ../../staticlib/components/libaccessibility.a ../../staticlib/components/libremoteservice.a ../../staticlib/components/libspellchecker.a ../../staticlib/components/libzipwriter.a ../../staticlib/libxpcom_core.a ../../staticlib/libucvutil_s.a ../../staticlib/libgkgfx.a ../../staticlib/libgfxshared_s.a ../../staticlib/libmozreg_s.a ../../staticlib/libmorkreader_s.a ../../staticlib/libgtkxtbin.a ../../staticlib/libgfxpsshar.a ../../staticlib/libthebes.a  -Wl,--no-whole-archive -L../../dist/lib -lsqlite3 -L../../dist/bin -L../../dist/lib  -L../../dist/bin -L../../dist/lib -L../../jpeg -lmozjpeg -L../../modules/libimg/png -lmozpng ../../gfx/qcms/libmozqcms.a -L/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/dist/bin -lmozjs -L../../dist/bin -L../../dist/lib -lcrmf -lsmime3 -lssl3 -lnss3 -lnssutil3 -lsoftokn3 ../../gfx/cairo/cairo/src/libmozcairo.a ../../gfx/cairo/libpixman/src/libmozlibpixman.a   -lXrender -lfreetype -lfontconfig  -L../../modules/zlib/src -lmozz -L/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/dist/lib -lplds4 -lplc4 -lnspr4 -lpthread -ldl -L//lib -ldbus-glib-1 -ldbus-1 -lgobject-2.0 -lglib-2.0    -lX11  -lXext  -lpangoft2-1.0 -lpango-1.0 -lfreetype -lfontconfig -lgobject-2.0 -lgmodule-2.0 -lglib-2.0   -lgtk-x11-2.0 -latk-1.0 -lpangoft2-1.0 -lfreetype -lfontconfig -lgdk-x11-2.0 -lgdk_pixbuf-2.0 -lm -lpangocairo-1.0 -lgio-2.0 -lpango-1.0 -lcairo -lgobject-2.0 -lgmodule-2.0 -lglib-2.0   -lXt -lgthread-2.0 -lfreetype -lz  -lasound -ldl -lm     
../../toolkit/xre/libxulapp_s.a(nsAppRunner.o): In function `ScopedXPCOMStartup::SetWindowCreator(nsINativeAppSupport*)':
nsAppRunner.cpp:(.text+0x136f): undefined reference to `nsFunctionTimer::sFuncTimerLogModule'
../../toolkit/xre/libxulapp_s.a(nsAppRunner.o): In function `nsFunctionTimer::nsFunctionTimer(char const*, ...)':
nsAppRunner.cpp:(.text._ZN15nsFunctionTimerC1EPKcz[nsFunctionTimer::nsFunctionTimer(char const*, ...)]+0x59): undefined reference to `nsFunctionTimer::sFuncTimerLogModule'
nsAppRunner.cpp:(.text._ZN15nsFunctionTimerC1EPKcz[nsFunctionTimer::nsFunctionTimer(char const*, ...)]+0x94): undefined reference to `nsFunctionTimer::sFuncTimerLogModule'
../../staticlib/components/libnecko.a(nsSocketTransportService2.o): In function `nsSocketTransportService::Init()':
nsSocketTransportService2.cpp:(.text+0x90e): undefined reference to `nsFunctionTimer::GetFuncTimerLogModule()'
../../staticlib/components/libembedcomponents.a(nsAppStartupNotifier.o): In function `nsAppStartupNotifier::Observe(nsISupports*, char const*, unsigned short const*)':
nsAppStartupNotifier.cpp:(.text+0x548): undefined reference to `nsFunctionTimer::GetFuncTimerLogModule()'
../../staticlib/components/libnsappshell.a(nsAppShellService.o): In function `nsFunctionTimer::~nsFunctionTimer()':
nsAppShellService.cpp:(.text._ZN15nsFunctionTimerD1Ev[nsFunctionTimer::~nsFunctionTimer()]+0x60): undefined reference to `nsFunctionTimer::GetFuncTimerLogModule()'
../../staticlib/components/libtoolkitcomps.a(nsAppStartup.o): In function `nsAppStartup::Init()':
nsAppStartup.cpp:(.text+0xb49): undefined reference to `nsFunctionTimer::GetFuncTimerLogModule()'
collect2: ld returned 1 exit status
make[1]: *** [libxul.so] Error 1
make[1]: Leaving directory `/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/toolkit/library'
make: *** [default] Error 2
make: Leaving directory `/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/toolkit/library'
Comment 30 David Dahl :ddahl 2009-07-20 14:40:30 PDT
Created attachment 389562 [details] [diff] [review]
nsAppRunner Instrumentation Patch for testing current linking error

Adding a tiny patch that calls NS_TIME_FUNCTION once and NS_TIME_FUNCTION_MARK once. You should be able to build the Cpp patch without any instrumentation patches, once you add this one you cannot link with libxul.
Comment 31 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-20 16:15:18 PDT
Created attachment 389576 [details] [diff] [review]
updated patch

Ok, here's an updated patch that I think is good to go.. fixes some minor things in the previous patches:

1) needed NS_COM to get the proper exports from xpcom;

2) Can't use the PR_LOG macros and FORCE_PR_LOGGING in an include file; we have to make the PRLog function calls directly;

3) Duplicates the code between js and xpcom -- there wasn't a good way to get around this;

4) Moved xpcom piece to xpcom/base (not glue).

Requesting review from brendan on the JS piece, and bsmedberg on the xpcom piece.  (It doesn't really have much to do with xpcom, we just have no good place to put things like this!)
Comment 32 David Dahl :ddahl 2009-07-20 17:14:29 PDT
i cleared my queue, applied this patch, and still have linking issues, different linking problems anyway:

c++  -fno-rtti -fno-exceptions -Wall -Wpointer-arith -Woverloaded-virtual -Wsynth -Wno-ctor-dtor-privacy -Wno-non-virtual-dtor -Wcast-align -Wno-invalid-offsetof -Wno-long-long -pedantic -fno-strict-aliasing -fshort-wchar -pthread -pipe  -DNDEBUG -DTRIMMED -Os -freorder-blocks -fno-reorder-functions  -fPIC -shared -Wl,-z,defs -Wl,-h,libxul.so -o libxul.so  nsStaticXULComponents.o nsUnicharUtils.o nsCompressedCharMap.o nsBidiUtils.o nsRDFResource.o     -lpthread   -Wl,-rpath-link,/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/dist/bin -Wl,-rpath-link,/usr/local/lib  -Wl,--whole-archive ../../embedding/browser/gtk/src/libgtkembedmoz.a ../../toolkit/xre/libxulapp_s.a  ../../staticlib/components/libxpconnect.a ../../staticlib/components/libnecko.a ../../staticlib/components/libuconv.a ../../staticlib/components/libi18n.a ../../staticlib/components/libchardet.a ../../staticlib/components/libjar50.a ../../staticlib/components/libpref.a ../../staticlib/components/libcaps.a ../../staticlib/components/libhtmlpars.a ../../staticlib/components/libimglib2.a ../../staticlib/components/libgklayout.a ../../staticlib/components/libdocshell.a ../../staticlib/components/libembedcomponents.a ../../staticlib/components/libwebbrwsr.a ../../staticlib/components/libnsappshell.a ../../staticlib/components/libtxmgr.a ../../staticlib/components/libchrome.a ../../staticlib/components/libcommandlines.a ../../staticlib/components/libtoolkitcomps.a ../../staticlib/components/libpipboot.a ../../staticlib/components/libpipnss.a ../../staticlib/components/libgkplugin.a ../../staticlib/components/libmozfind.a ../../staticlib/components/libappcomps.a ../../staticlib/components/libunixproxy.a ../../staticlib/components/libxpinstall.a ../../staticlib/components/libjsd.a ../../staticlib/components/libautoconfig.a ../../staticlib/components/libauth.a ../../staticlib/components/libcookie.a ../../staticlib/components/libpermissions.a ../../staticlib/components/libuniversalchardet.a ../../staticlib/components/libcomposer.a ../../staticlib/components/librdf.a ../../staticlib/components/libwindowds.a ../../staticlib/components/libintlapp.a ../../staticlib/components/libfileview.a ../../staticlib/components/libstoragecomps.a ../../staticlib/components/libplaces.a ../../staticlib/components/libtkautocomplete.a ../../staticlib/components/libsatchel.a ../../staticlib/components/libpippki.a ../../staticlib/components/libucvmath.a ../../staticlib/components/libwidget_gtk2.a ../../staticlib/components/libsystem-pref.a ../../staticlib/components/libgkgfxthebes.a ../../staticlib/components/libaccessibility.a ../../staticlib/components/libremoteservice.a ../../staticlib/components/libspellchecker.a ../../staticlib/components/libzipwriter.a ../../staticlib/libxpcom_core.a ../../staticlib/libucvutil_s.a ../../staticlib/libgkgfx.a ../../staticlib/libgfxshared_s.a ../../staticlib/libmozreg_s.a ../../staticlib/libmorkreader_s.a ../../staticlib/libgtkxtbin.a ../../staticlib/libgfxpsshar.a ../../staticlib/libthebes.a  -Wl,--no-whole-archive -L../../dist/lib -lsqlite3 -L../../dist/bin -L../../dist/lib  -L../../dist/bin -L../../dist/lib -L../../jpeg -lmozjpeg -L../../modules/libimg/png -lmozpng ../../gfx/qcms/libmozqcms.a -L/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/dist/bin -lmozjs -L../../dist/bin -L../../dist/lib -lcrmf -lsmime3 -lssl3 -lnss3 -lnssutil3 -lsoftokn3 ../../gfx/cairo/cairo/src/libmozcairo.a ../../gfx/cairo/libpixman/src/libmozlibpixman.a   -lXrender -lfreetype -lfontconfig  -L../../modules/zlib/src -lmozz -L/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/dist/lib -lplds4 -lplc4 -lnspr4 -lpthread -ldl -L//lib -ldbus-glib-1 -ldbus-1 -lgobject-2.0 -lglib-2.0    -lX11  -lXext  -lpangoft2-1.0 -lpango-1.0 -lfreetype -lfontconfig -lgobject-2.0 -lgmodule-2.0 -lglib-2.0   -lgtk-x11-2.0 -latk-1.0 -lpangoft2-1.0 -lfreetype -lfontconfig -lgdk-x11-2.0 -lgdk_pixbuf-2.0 -lm -lpangocairo-1.0 -lgio-2.0 -lpango-1.0 -lcairo -lgobject-2.0 -lgmodule-2.0 -lglib-2.0   -lXt -lgthread-2.0 -lfreetype -lz  -lasound -ldl -lm     
../../staticlib/components/libnecko.a(nsSocketTransportService2.o): In function `nsSocketTransportService::Init()':
nsSocketTransportService2.cpp:(.text+0x90e): undefined reference to `nsFunctionTimer::GetFuncTimerLogModule()'
../../staticlib/components/libgklayout.a(nsPageFrame.o): In function `nsPageFrame::DrawHeaderFooter(nsIRenderingContext&, nsPageFrame::nsHeaderFooterEnum, int, nsString const&, nsRect const&, int, int, int)':
nsPageFrame.cpp:(.text+0xbec): undefined reference to `HasRTLChars(nsAString_internal&)'
../../staticlib/components/libgklayout.a(nsTextBoxFrame.o): In function `nsTextBoxFrame::CalculateTitleForWidth(nsPresContext*, nsIRenderingContext&, int)':
nsTextBoxFrame.cpp:(.text+0x42b): undefined reference to `HasRTLChars(nsAString_internal&)'
../../staticlib/components/libembedcomponents.a(nsAppStartupNotifier.o): In function `nsAppStartupNotifier::Observe(nsISupports*, char const*, unsigned short const*)':
nsAppStartupNotifier.cpp:(.text+0x548): undefined reference to `nsFunctionTimer::GetFuncTimerLogModule()'
../../staticlib/components/libnsappshell.a(nsAppShellService.o): In function `nsFunctionTimer::~nsFunctionTimer()':
nsAppShellService.cpp:(.text._ZN15nsFunctionTimerD1Ev[nsFunctionTimer::~nsFunctionTimer()]+0x60): undefined reference to `nsFunctionTimer::GetFuncTimerLogModule()'
../../staticlib/components/libtoolkitcomps.a(nsAppStartup.o): In function `nsAppStartup::Init()':
nsAppStartup.cpp:(.text+0xb49): undefined reference to `nsFunctionTimer::GetFuncTimerLogModule()'
/usr/bin/ld: libxul.so: hidden symbol `HasRTLChars(nsAString_internal&)' isn't defined
/usr/bin/ld: final link failed: Nonrepresentable section on output
collect2: ld returned 1 exit status
make[1]: *** [libxul.so] Error 1
make[1]: Leaving directory `/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/toolkit/library'
make: *** [default] Error 2
make: Leaving directory `/home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/toolkit/library'


The weird thing is that a total rebuild appears to work, no errors, but when you run the browser you get: 

ddahl-t500 ~/code/moz/mozilla-central/mozilla % ../obj-i686-pc-linux-gnu-optimize/dist/bin/firefox -P -no-remote
../obj-i686-pc-linux-gnu-optimize/dist/bin/firefox-bin: error while loading shared libraries: libxul.so: cannot open shared object file: No such file or directory


I built toolkit/library to get the previous error.
Comment 33 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-20 17:27:01 PDT
You need to do a clean build; you're pulling in things that don't have the right dependencies, since the header file changed locations.. and so files aren't getting rebuilt.

If you read the errors, you'll see things like:

nsSocketTransportService2.cpp:(.text+0x90e): undefined reference to
`nsFunctionTimer::GetFuncTimerLogModule()'

nsFunctionTimer::GetFuncTimerLogModule() doesn't exist any more.
Comment 34 David Dahl :ddahl 2009-07-20 17:30:25 PDT
Yeah - sorry. Just started a complete rm -fr clobber build.
Comment 35 David Dahl :ddahl 2009-07-21 16:41:30 PDT
Created attachment 389812 [details] [diff] [review]
WIP - removing more fprintf calls

Getting rid of fprintf calls.
Comment 36 David Dahl :ddahl 2009-07-21 16:42:37 PDT
Created attachment 389814 [details] [diff] [review]
v0.2 - instrumentation - unbitrotted

slight tweak to XRE_Main
Comment 37 David Dahl :ddahl 2009-07-22 10:46:05 PDT
Created attachment 390001 [details] [diff] [review]
v0.3 - instrumentation - latest

This is the latest instrumentation patch
Comment 38 Benjamin Smedberg [:bsmedberg] 2009-07-23 11:40:20 PDT
Comment on attachment 389576 [details] [diff] [review]
updated patch

Can you use namespaces for new code? mozilla::FunctionTimer and mozilla::FunctionTimerLog and mozilla/FunctionTimer.h

Also, I'd like to see the macros at the top of functiontimer.h instead of the bottom, since that's primarily what consumers will be using.

Also, needs a file-scope doccomment explaining in general how to use the macros... from reading them, you'd put NS_TIME_FUNCTION at the top of your function?

Is __FUNCTION__ portable or do you not care?
Comment 39 David Dahl :ddahl 2009-07-23 18:10:13 PDT
I just tested __FUNCTION__ on msvc so it seems "portable enough" - as a native code noob, what other compilers should we be concerned with? Do we use gcc everywhere else?
Comment 40 Mike Shaver (:shaver -- probably not reading bugmail closely) 2009-07-23 18:15:33 PDT
It's portable enough -- if some freaky compiler doesn't handle it, we can add a configure test then and they can get something lamer, or no support for it at all.
Comment 41 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-24 13:49:11 PDT
__FUNCTION__ is fine; though it's often not good enough, msvc has __PRETTY_FUNCTION__ which is super verbose.  Either way, that's not an issue.

But turns out I can't put nsFunctionTimer.h (or whatever) in xpcom, even if I move it to xpcom glue or something; there are things that don't link with this.  I can do it include-file-only if I can modify NSPR, or I can create a mozilla utility library that gets linked in to everything.  I'm leaning towards the latter.
Comment 42 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-24 13:50:41 PDT
(er,gcc has PRETTY_FUNCTION, not msvc; msvc has __FUNCSIG__)
Comment 43 Brendan Eich [:brendan] 2009-07-24 14:05:47 PDT
What about putting it in JS? Only half :-P.

NSPR still seems the best place.

/be
Comment 44 David Dahl :ddahl 2009-07-24 16:41:57 PDT
(In reply to comment #41)

> But turns out I can't put nsFunctionTimer.h (or whatever) in xpcom, even if I
> move it to xpcom glue or something; there are things that don't link with this.
>  I can do it include-file-only if I can modify NSPR, or I can create a mozilla
> utility library that gets linked in to everything.  I'm leaning towards the
> latter.

vlad:

I just got the namespaces implemented int he cpp parts, and am about to update the jsftimer.h and .cpp. As far as moving this into a utility lib, will the code have to change drastically?
Comment 45 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-24 19:17:16 PDT
it won't, we just have to figure out where to put it; a copy in xpcom and a copy in js isn't good enough (and having two copies sucked to being with, I just couldn't figure out how to do it otherwise).

Putting PR_GetLogModule(name) in nspr would work, which would act as a "get-or-create" operation on the given name, but modifying nspr is even harder.
Comment 46 Brendan Eich [:brendan] 2009-07-24 21:45:38 PDT
(In reply to comment #45)
> Putting PR_GetLogModule(name) in nspr would work, which would act as a
> "get-or-create" operation on the given name, but modifying nspr is even harder.

Has wtc heard the pitch yet?

/be
Comment 47 David Dahl :ddahl 2009-07-27 12:09:54 PDT
Created attachment 390863 [details] [diff] [review]
0.1 FunctionTimer Patch

About done addressing review comments, not sure how to use this patch on the JS side, do we need an xpconnect component that wraps the JS_TIME_FUNCTION macros?

* still need to flesh out the doccomments.
Comment 48 Wan-Teh Chang 2009-07-27 13:37:23 PDT
(In reply to comment #46)
> (In reply to comment #45)
> > Putting PR_GetLogModule(name) in nspr would work, which would act as a
> > "get-or-create" operation on the given name, but modifying nspr is even harder.
> 
> Has wtc heard the pitch yet?

No, I haven't.  Brendan first cc'ed me in comment 43, and
I thought he was talking about the __FUNCTION__ macro.
Comment 49 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-30 13:31:42 PDT
Created attachment 391687 [details] [diff] [review]
add PR_GetLogModule

wtc, here's the piece I'd like to add to nspr; unfortunately I can't figure out how to use plhash from prlog.cpp -- what am I missing here?  Might be able to use a simple linked list here as well, as the number of modules is likely to be small, but that'll probably change if/when people start using this mechanism more in the future.

ddahl, I'll attach an updated patch for the actual implementation soon, as soon as we figure out this piece.
Comment 50 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-30 13:41:42 PDT
... though the other option is to just move this entirely into nspr, since I see that nspr does have a c++ section.
Comment 51 Wan-Teh Chang 2009-07-30 13:56:55 PDT
Comment on attachment 391687 [details] [diff] [review]
add PR_GetLogModule

Vlad, thanks for the patch.  PLHashTable is in the "plds4" library,
which depends on the "nspr4" library, so you can't use PLHashTable
in the "nspr4" library.  You will need to implement the table of
log modules manually, as a linked list or some other data structure.

Another problem with this patch is that it is not thread-safe.  I
guess you're just using it to illustrate what you're trying to do.

The C++ section in NSPR is dead code.  It probably should be CVS
removed.
Comment 52 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-30 14:47:29 PDT
Created attachment 391710 [details] [diff] [review]
add PR_GetLogModule, v2

Maybe something like this?  (I had completely forgotten about thread safety!)  Not great from a lookup perf point of view, but if it becomes a problem we can fix that in some other way.
Comment 53 Vladimir Vukicevic [:vlad] [:vladv] 2009-07-30 16:25:57 PDT
Created attachment 391737 [details] [diff] [review]
functiontimer code

This builds on top of PR_GetLogModule; not r?'ing until we figure that piece out.
Comment 54 Wan-Teh Chang 2009-08-04 11:12:11 PDT
Comment on attachment 391710 [details] [diff] [review]
add PR_GetLogModule, v2

Vlad, thanks for the patch.  I have some questions and suggested changes
below.

>+** ... Note that only
>+** log modules created by PR_GetLogModule are tracked, not those
>+** created by PR_NewLogModule.

This limitation is surprising.  Why can't PR_GetLogModule track the log
modules created by PR_NewLogModule?

Please document these subtle issues:
- We can't enhance PR_NewLogModule because ... (I guess PR_NewLogModule
  inadvertently allow modules with the same name)
- PR_GetLogModule addresses the following issues in PR_NewLogModule (I
  guess: unique module names, no need to create a log module in some
  "init" function)
- The log modules created by PR_NewLogModule and PR_GetLogModule must
  be tracked separately because ... (I certainly hope we can just use
  a single list of log modules)

>+typedef struct _PRLogModuleInfoLink PRLogModuleInfoLink;
>+struct _PRLogModuleInfoLink {
>+    PRLogModuleInfo *logModule;
>+    PRLogModuleInfoLink *next;
>+};

Why can't you use the PRLogModuleInfo structure, which already has a
'next' member?

>+static PRLogModuleInfoLink *_pr_logModules = NULL;
>+/* initialized in prinit */
>+extern PRLock *_pr_logModulesLock;

The log modules created by PR_NewLogModule are already linked into
a list: logModules.  If you must use a separate linked list for the
log modules created by PR_GetLogModule, please declare it near the
declaration for logModules to stress the fact that they're related.

By the way, I found that PR_NewLogModule adds the newly created log
module to logModules without the protection of a lock.  That is a
bug.  Let's just use your _pr_logModulesLock to protect it.

>+PR_IMPLEMENT(PRLogModuleInfo*) PR_GetLogModule(const char *name)
>+{
>+    PRLogModuleInfo *lm = NULL;
>+    PRLogModuleInfoLink *link = _pr_logModules;
>+
>+    while (link) {
>+        if (strcmp(link->logModule->name, name) == 0)
>+            break;
>+
>+        link = link->next;
>+    }

This while loop, which traverses the linked list, should also be
protected with the lock.
Comment 55 Vladimir Vukicevic [:vlad] [:vladv] 2009-08-08 13:27:11 PDT
Created attachment 393384 [details] [diff] [review]
add PR_GetLogModule, v3

Updated NSPR patch.  Thanks for the comments, wtc -- I didn't even realize that there already was an existing linked list of log modules, somehow missed that while looking through the code.

This could become even simpler if we were to just have NewLogModule return an existing log module if it had the same name.  Given that you can't destroy log modules, does that sound like an acceptable change?  In that case, no new API would be required, and I'm pretty sure behaviour wouldn't change even if someone was creating multiple log modules with the same name before (unless they were manually reaching in to the struct and fiddling bits for their particular instance after it's been initialized).
Comment 56 Vladimir Vukicevic [:vlad] [:vladv] 2009-08-11 12:55:12 PDT
Created attachment 393839 [details] [diff] [review]
add PR_GetLogModule, v4

Fix in previous patch -- since NewLogModule now grabs the PRLock, we need to initialize the PRLock in PR_Init before we call NewLogModule, or bad things happen.  (This leads to weird crashes on startup, since NewLogModule is used in global data...)
Comment 57 Wan-Teh Chang 2009-08-12 11:27:44 PDT
Comment on attachment 393839 [details] [diff] [review]
add PR_GetLogModule, v4

r=wtc.  Thanks for the patch.  I will think about whether
we can just change PR_NewLogModule to return an existing
module if a module by that name already exists.  NSPR
has strict backward compatibility requirements, so this
kind of subtle behavior change needs a lot of thought.
Often we just add a new variant of the function to be
safe.

In nsprpub/pr/src/io/prlog.c

> /*
>+ * Lock used to lock the set of modules we have.
>+ * Initialized in prinit.
>+ */

Nit: "Initialized" => "Defined and initialized"
     prinit => prinit.c

I would mention the name of the variable 'logModules' explicitly.

>+PR_IMPLEMENT(PRLogModuleInfo*) PR_GetLogModule(const char *name)
>+{
>+    PRLogModuleInfo *lm;
>+
>+    if (!_pr_initialized) _PR_ImplicitInitialization();
>+
>+    lm = _PR_FindLogModule(name);
>+    if (lm)
>+        return lm;

The fast code path, calling _PR_FindLogModule without holding
a lock, is not thread-safe.  Let's delete it and just rely on
the slow code path in the critical section below.

In nsprpub/pr/src/misc/prinit.c:

>+/* Lock protecting PR_GetLockModules' linked list */

Nit: Lock protecting the logModules linked list in prlog.c

>+    /* Must happen before any PR_NewLogModule calls! */
>+    _pr_logModulesLock = PR_NewLock();
>+    PR_ASSERT(NULL != _pr_logModulesLock);

It would be better to move this code to right above the
first PR_NewLogModule call to make the point clear.

Are you sure we can call PR_NewLock() this early?

Another approach is to allow PR_NewLogModule to be called
with _pr_logModulesLock being NULL, which would indicate
we're inside NSPR initialization.  We do similar things
elsewhere in prlog.c:
http://bonsai.mozilla.org/cvsblame.cgi?file=mozilla/nsprpub/pr/src/io/prlog.c&rev=3.50&mark=451-453#440
Comment 58 Vladimir Vukicevic [:vlad] [:vladv] 2009-08-12 11:41:59 PDT
(In reply to comment #57)
> (From update of attachment 393839 [details] [diff] [review])
> >+PR_IMPLEMENT(PRLogModuleInfo*) PR_GetLogModule(const char *name)
> >+{
> >+    PRLogModuleInfo *lm;
> >+
> >+    if (!_pr_initialized) _PR_ImplicitInitialization();
> >+
> >+    lm = _PR_FindLogModule(name);
> >+    if (lm)
> >+        return lm;
> 
> The fast code path, calling _PR_FindLogModule without holding
> a lock, is not thread-safe.  Let's delete it and just rely on
> the slow code path in the critical section below.

It is -- modules can never be deleted, and new modules are always added to the front of the list.  The module pointer there should always be valid (barring a partial update of the pointer value in memory or something, which I don't think can ever happen... we could use an atomic swap to ensure, I guess, when creating a new module).

I don't want to remove the fast path because that maens that every GetLogModule call will require a mutex lock/unlock, which seems excessive for places where we're using GetLogModule explicitly because there's no convenient place to store a cached pointer to one.

> >+    /* Must happen before any PR_NewLogModule calls! */
> >+    _pr_logModulesLock = PR_NewLock();
> >+    PR_ASSERT(NULL != _pr_logModulesLock);
> 
> It would be better to move this code to right above the
> first PR_NewLogModule call to make the point clear.
> 
> Are you sure we can call PR_NewLock() this early?

No, but I'm not sure whether it can be called at any point in that function -- that is, there's nothing in there that indicates "this is early initialization", just a somewhat haphazard collection of inits.

> Another approach is to allow PR_NewLogModule to be called
> with _pr_logModulesLock being NULL, which would indicate
> we're inside NSPR initialization.  We do similar things
> elsewhere in prlog.c:
> http://bonsai.mozilla.org/cvsblame.cgi?file=mozilla/nsprpub/pr/src/io/prlog.c&rev=3.50&mark=451-453#440

that's a good idea; I'll do that.
Comment 59 Wan-Teh Chang 2009-08-12 19:03:45 PDT
Vlad, it is risky to make that kind of assumption about what
you can do without holding a lock.  I am not qualified to
review lock-free code.
Comment 60 Andreas Gal :gal 2009-08-14 11:01:53 PDT
Comment on attachment 393839 [details] [diff] [review]
add PR_GetLogModule, v4

The race seems harmless to me. We grab the head pointer of a list that is never mutated. Additions happen at the front by updating the head pointer. As long the update of the head pointer happens after the link was set, this should be always safe.
Comment 61 Wan-Teh Chang 2009-08-14 11:21:25 PDT
(In reply to comment #58)
>
> I don't want to remove the fast path because that maens that every GetLogModule
> call will require a mutex lock/unlock, which seems excessive for places where
> we're using GetLogModule explicitly because there's no convenient place to
> store a cached pointer to one.

Vlad, I think PR_CallOnce should work for you:
https://developer.mozilla.org/en/PR_CallOnce

static PRLogModuleInfo *lm_foo;
static PRCallOnceType lm_foo_once;

static PRStatus InitFooLogModule(void)
{
  lm_foo = PR_NewLogModule("foo");
  return PR_SUCCESS;
}

Then, instead of PR_GetLogModule("foo"), you call this function:

PRLogModuleInfo *GetFooLogModule(void)
{
  PR_CallOnce(&lm_foo_once, InitFooLogModule);
  return lm_foo;
}
Comment 62 Vladimir Vukicevic [:vlad] [:vladv] 2009-08-14 11:52:41 PDT
(In reply to comment #61)
> (In reply to comment #58)
> >
> > I don't want to remove the fast path because that maens that every GetLogModule
> > call will require a mutex lock/unlock, which seems excessive for places where
> > we're using GetLogModule explicitly because there's no convenient place to
> > store a cached pointer to one.
> 
> Vlad, I think PR_CallOnce should work for you:
> https://developer.mozilla.org/en/PR_CallOnce
> 
> static PRLogModuleInfo *lm_foo;
> static PRCallOnceType lm_foo_once;

^ this is the convenient place to store a cached pointer that I don't have -- I have no way to create static data, since the entire implementation lives in a header that gets included by many different components :-)  I can't just export it from xpcom either, since js code ends up using it as well.
Comment 63 David Dahl :ddahl 2009-08-21 17:18:35 PDT
Created attachment 395996 [details] [diff] [review]
v 0.4 instrumentation-patch - unbitrotted

Doesn't build do to some more scope fun:

/home/ddahl/code/moz/mozilla-central/mozilla/xpcom/ds/nsObserverList.cpp:149: error: ‘NS_TIME_FUNCTION_MARK’ was not declared in this scope
make[5]: *** [nsObserverList.o] Error 1
make[4]: *** [libs] Error 2
make[3]: *** [libs_tier_xpcom] Error 2
make[2]: *** [tier_xpcom] Error 2
make[1]: *** [default] Error 2
make: *** [build] Error 2
Comment 64 David Dahl :ddahl 2009-08-21 17:24:30 PDT
Comment on attachment 395996 [details] [diff] [review]
v 0.4 instrumentation-patch - unbitrotted

Actually - there are a bunch of #include nsFunctionTimer.h lines that need to be changed to #include FunctionTimer.h
Comment 65 David Dahl :ddahl 2009-08-24 13:11:37 PDT
latest patches a segfaulting, here is my valgrind output:

ddahl-t500 139~/code/moz/mozilla-central/mozilla % valgrind -v ~/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/dist/bin/firefox -P opt-new --no-remote
==24801== Memcheck, a memory error detector.
==24801== Copyright (C) 2002-2007, and GNU GPL'd, by Julian Seward et al.
==24801== Using LibVEX rev 1854, a library for dynamic binary translation.
==24801== Copyright (C) 2004-2007, and GNU GPL'd, by OpenWorks LLP.
==24801== Using valgrind-3.3.1, a dynamic binary instrumentation framework.
==24801== Copyright (C) 2000-2007, and GNU GPL'd, by Julian Seward et al.
==24801== 
--24801-- Command line
--24801--    /home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/dist/bin/firefox
--24801--    -P
--24801--    opt-new
--24801--    --no-remote
--24801-- Startup, with flags:
--24801--    -v
--24801-- Contents of /proc/version:
--24801--   Linux version 2.6.28-15-generic (buildd@palmer) (gcc version 4.3.3 (Ubuntu 4.3.3-5ubuntu4) ) #49-Ubuntu SMP Tue Aug 18 18:40:08 UTC 2009
--24801-- Arch and hwcaps: X86, x86-sse1-sse2
--24801-- Page sizes: currently 4096, max supported 4096
--24801-- Valgrind library directory: /home/ddahl/lib/valgrind
--24801-- Reading syms from /lib/ld-2.9.so (0x4000000)
--24801-- Reading debug info from /lib/ld-2.9.so...
--24801-- ... CRC mismatch (computed 049232cc wanted 022486d8)
--24801--    object doesn't have a symbol table
--24801-- Reading syms from /bin/dash (0x8048000)
--24801--    object doesn't have a symbol table
--24801-- Reading syms from /home/ddahl/lib/valgrind/x86-linux/memcheck (0x38000000)
--24801--    object doesn't have a dynamic symbol table
--24801-- Reading suppressions file: /home/ddahl/lib/valgrind/default.supp
--24801-- Reading syms from /home/ddahl/lib/valgrind/x86-linux/vgpreload_core.so (0x4020000)
==24801== Conditional jump or move depends on uninitialised value(s)
==24801==    at 0x40168CD: (within /lib/ld-2.9.so)
==24801==    by 0x40075B1: (within /lib/ld-2.9.so)
==24801==    by 0x40010C4: (within /lib/ld-2.9.so)
==24801==    by 0x400E035: (within /lib/ld-2.9.so)
==24801==    by 0x4000F7B: (within /lib/ld-2.9.so)
==24801==    by 0x4003551: (within /lib/ld-2.9.so)
==24801==    by 0x40147B0: (within /lib/ld-2.9.so)
==24801==    by 0x4000C1C: (within /lib/ld-2.9.so)
==24801==    by 0x4000816: (within /lib/ld-2.9.so)
==24801== 
==24801== Conditional jump or move depends on uninitialised value(s)
==24801==    at 0x40168DC: (within /lib/ld-2.9.so)
==24801==    by 0x40075B1: (within /lib/ld-2.9.so)
==24801==    by 0x40010C4: (within /lib/ld-2.9.so)
==24801==    by 0x400E035: (within /lib/ld-2.9.so)
==24801==    by 0x4000F7B: (within /lib/ld-2.9.so)
==24801==    by 0x4003551: (within /lib/ld-2.9.so)
==24801==    by 0x40147B0: (within /lib/ld-2.9.so)
==24801==    by 0x4000C1C: (within /lib/ld-2.9.so)
==24801==    by 0x4000816: (within /lib/ld-2.9.so)
==24801== 
==24801== Conditional jump or move depends on uninitialised value(s)
==24801==    at 0x40168EB: (within /lib/ld-2.9.so)
==24801==    by 0x40075B1: (within /lib/ld-2.9.so)
==24801==    by 0x40010C4: (within /lib/ld-2.9.so)
==24801==    by 0x400E035: (within /lib/ld-2.9.so)
==24801==    by 0x4000F7B: (within /lib/ld-2.9.so)
==24801==    by 0x4003551: (within /lib/ld-2.9.so)
==24801==    by 0x40147B0: (within /lib/ld-2.9.so)
==24801==    by 0x4000C1C: (within /lib/ld-2.9.so)
==24801==    by 0x4000816: (within /lib/ld-2.9.so)
==24801== 
==24801== Conditional jump or move depends on uninitialised value(s)
==24801==    at 0x4016A63: (within /lib/ld-2.9.so)
==24801==    by 0x40075B1: (within /lib/ld-2.9.so)
==24801==    by 0x40010C4: (within /lib/ld-2.9.so)
==24801==    by 0x400E035: (within /lib/ld-2.9.so)
==24801==    by 0x4000F7B: (within /lib/ld-2.9.so)
==24801==    by 0x4003551: (within /lib/ld-2.9.so)
==24801==    by 0x40147B0: (within /lib/ld-2.9.so)
==24801==    by 0x4000C1C: (within /lib/ld-2.9.so)
==24801==    by 0x4000816: (within /lib/ld-2.9.so)
==24801== 
==24801== Conditional jump or move depends on uninitialised value(s)
==24801==    at 0x4016A63: (within /lib/ld-2.9.so)
==24801==    by 0x4005CF2: (within /lib/ld-2.9.so)
==24801==    by 0x400766C: (within /lib/ld-2.9.so)
==24801==    by 0x40010C4: (within /lib/ld-2.9.so)
==24801==    by 0x400E035: (within /lib/ld-2.9.so)
==24801==    by 0x4000F7B: (within /lib/ld-2.9.so)
==24801==    by 0x4003551: (within /lib/ld-2.9.so)
==24801==    by 0x40147B0: (within /lib/ld-2.9.so)
==24801==    by 0x4000C1C: (within /lib/ld-2.9.so)
==24801==    by 0x4000816: (within /lib/ld-2.9.so)
--24801-- Reading syms from /home/ddahl/lib/valgrind/x86-linux/vgpreload_memcheck.so (0x4023000)
--24801-- Reading syms from /lib/tls/i686/cmov/libc-2.9.so (0x4045000)
--24801-- Reading debug info from /lib/tls/i686/cmov/libc-2.9.so...
--24801-- ... CRC mismatch (computed 7ee64c88 wanted 8d898f0d)
--24801--    object doesn't have a symbol table
==24801== 
==24801== Conditional jump or move depends on uninitialised value(s)
==24801==    at 0x400BF23: (within /lib/ld-2.9.so)
==24801==    by 0x400325B: (within /lib/ld-2.9.so)
==24801==    by 0x40147B0: (within /lib/ld-2.9.so)
==24801==    by 0x4000C1C: (within /lib/ld-2.9.so)
==24801==    by 0x4000816: (within /lib/ld-2.9.so)
==24801== 
==24801== Conditional jump or move depends on uninitialised value(s)
==24801==    at 0x400A9EC: (within /lib/ld-2.9.so)
==24801==    by 0x400325B: (within /lib/ld-2.9.so)
==24801==    by 0x40147B0: (within /lib/ld-2.9.so)
==24801==    by 0x4000C1C: (within /lib/ld-2.9.so)
==24801==    by 0x4000816: (within /lib/ld-2.9.so)
==24801== 
==24801== Conditional jump or move depends on uninitialised value(s)
==24801==    at 0x400B6C1: (within /lib/ld-2.9.so)
==24801==    by 0x400325B: (within /lib/ld-2.9.so)
==24801==    by 0x40147B0: (within /lib/ld-2.9.so)
==24801==    by 0x4000C1C: (within /lib/ld-2.9.so)
==24801==    by 0x4000816: (within /lib/ld-2.9.so)
==24801== 
==24801== Conditional jump or move depends on uninitialised value(s)
==24801==    at 0x400A6C6: (within /lib/ld-2.9.so)
==24801==    by 0x4003364: (within /lib/ld-2.9.so)
==24801==    by 0x40147B0: (within /lib/ld-2.9.so)
==24801==    by 0x4000C1C: (within /lib/ld-2.9.so)
==24801==    by 0x4000816: (within /lib/ld-2.9.so)
==24801== 
==24801== Conditional jump or move depends on uninitialised value(s)
==24801==    at 0x400A6CE: (within /lib/ld-2.9.so)
==24801==    by 0x4003364: (within /lib/ld-2.9.so)
==24801==    by 0x40147B0: (within /lib/ld-2.9.so)
==24801==    by 0x4000C1C: (within /lib/ld-2.9.so)
==24801==    by 0x4000816: (within /lib/ld-2.9.so)
==24801== 
==24801== Conditional jump or move depends on uninitialised value(s)
==24801==    at 0x400A9EC: (within /lib/ld-2.9.so)
==24801==    by 0x4003364: (within /lib/ld-2.9.so)
==24801==    by 0x40147B0: (within /lib/ld-2.9.so)
==24801==    by 0x4000C1C: (within /lib/ld-2.9.so)
==24801==    by 0x4000816: (within /lib/ld-2.9.so)
--24801-- REDIR: 0x40bca60 (rindex) redirected to 0x40270e0 (rindex)
--24801-- REDIR: 0x40bbf00 (index) redirected to 0x40271d0 (index)
--24801-- REDIR: 0x40b8930 (malloc) redirected to 0x4026cd0 (malloc)
--24801-- REDIR: 0x40c1390 (strchrnul) redirected to 0x4028470 (strchrnul)
--24801-- REDIR: 0x40bc5e0 (strlen) redirected to 0x4027490 (strlen)
--24801-- REDIR: 0x40be850 (memcpy) redirected to 0x4027900 (memcpy)
--24801-- REDIR: 0x40be3a0 (mempcpy) redirected to 0x40284d0 (mempcpy)
--24801-- REDIR: 0x40bc070 (strcmp) redirected to 0x4027790 (strcmp)
--24801-- REDIR: 0x40b6520 (free) redirected to 0x4025af0 (free)
--24801-- REDIR: 0x40b8de0 (realloc) redirected to 0x4026de0 (realloc)
--24802-- REDIR: 0x40bc0e0 (strcpy) redirected to 0x40274f0 (strcpy)
--24803-- REDIR: 0x40bc0e0 (strcpy) redirected to 0x40274f0 (strcpy)
--24801-- REDIR: 0x40bc0e0 (strcpy) redirected to 0x40274f0 (strcpy)
zsh: segmentation fault  valgrind -v  -P opt-new --no-remote
ddahl-t500 139~/code/moz/mozilla-central/mozilla %
Comment 66 David Dahl :ddahl 2009-08-24 13:13:56 PDT
Created attachment 396281 [details] [diff] [review]
v 0.5 instrumentation-patch - unbitrotted

tiny tweak to unbitrot XRE_Main()
Comment 67 David Dahl :ddahl 2009-08-24 14:39:58 PDT
this patch is building ok, actually. (After a clobber build)
Comment 68 David Dahl :ddahl 2009-09-21 17:47:07 PDT
Created attachment 401985 [details] [diff] [review]
v 0.6 unbitrotted instrumentation patch
Comment 69 David Dahl :ddahl 2009-09-21 17:50:51 PDT
Created attachment 401987 [details]
Timeline Crash Stacks and output on Windows 7

Just posting some crash stacks and output from the debugger. This seems to crash at random times and places, but I am looking for a pattern.
Comment 70 Dietrich Ayala (:dietrich) 2009-11-24 10:33:27 PST
Vlad, what is this blocked on? Comment #62 sounds dead-end-y. Is there an 80% solution, that we could get now? Some timeline is better than no timeline.
Comment 71 :Ehsan Akhgari 2009-12-02 15:10:48 PST
Created attachment 415735 [details] [diff] [review]
v 0.6 unbitrotted instrumentation patch

This is an unbitrotted version of attachment 401985 [details] [diff] [review].
Comment 72 David Dahl :ddahl 2009-12-04 15:02:02 PST
Created attachment 416176 [details]
backtrace from debug build crash on start

ehsan wanted me to build on linux and attach backtrace
Comment 73 :Ehsan Akhgari 2009-12-04 15:06:12 PST
On a mac debug build, I got this assertion, which happens way earlier than the crash David is seeing:

#0      0x97ef1732 in __kill
#1      0x97ef1724 in kill$UNIX2003
#2      0x97f8498d in raise
#3      0x97f9aa44 in abort
#4      0x000a36ea in PR_Assert at prlog.c:625
#5      0x000bd266 in PR_NewLock at ptsynch.c:178
#6      0x000b1057 in _PR_InitStuff at prinit.c:177
#7      0x000b1275 in _PR_ImplicitInitialization at prinit.c:259
#8      0x000a2f2b in PR_NewLogModule at prlog.c:404
#9      0x0039cdb8 in __static_initialization_and_destruction_0 at nsTimerImpl.h:55
#10     0x0039cde2 in global constructors keyed to nsStringInputStream_classInfoGlobal at nsXPComInit.cpp:838
#11     0x8fe0ed6d in __dyld__ZN16ImageLoaderMachO18doModInitFunctionsERKN11ImageLoader11LinkContextE
#12     0x8fe0d31e in __dyld__ZN11ImageLoader23recursiveInitializationERKNS_11LinkContextEj
#13     0x8fe0d2c2 in __dyld__ZN11ImageLoader23recursiveInitializationERKNS_11LinkContextEj
#14     0x8fe0d2c2 in __dyld__ZN11ImageLoader23recursiveInitializationERKNS_11LinkContextEj
#15     0x8fe0d2c2 in __dyld__ZN11ImageLoader23recursiveInitializationERKNS_11LinkContextEj
#16     0x8fe0d3d1 in __dyld__ZN11ImageLoader15runInitializersERKNS_11LinkContextE
#17     0x8fe024a9 in __dyld__ZN4dyld24initializeMainExecutableEv
#18     0x8fe07950 in __dyld__ZN4dyld5_mainEPK12macho_headermiPPKcS5_S5_
#19     0x8fe018b1 in __dyld__ZN13dyldbootstrap5startEPK12macho_headeriPPKcl
#20     0x8fe01057 in __dyld__dyld_start
Comment 74 David Dahl :ddahl 2009-12-04 15:29:14 PST
Ehsan:  I removed the instrumentation patch and re-built, the browser starts ok. I recommend making some new test instrumentation patches that are much small and localized to track down the culprit. On windows it was usually the observer instrumentation that crashed.
Comment 75 David Dahl :ddahl 2009-12-04 15:30:55 PST
Actually it looks like the browser did hang for a few seconds, then quit ok. Weird. I will help debuig this more next week if you want.
Comment 76 :Ehsan Akhgari 2009-12-07 14:08:24 PST
(In reply to comment #75)
> Actually it looks like the browser did hang for a few seconds, then quit ok.
> Weird. I will help debuig this more next week if you want.

That would be wonderful, as I have not yet been able to get it to work.  :-(
Comment 77 Vladimir Vukicevic [:vlad] [:vladv] 2010-03-30 10:40:30 PDT
Created attachment 435950 [details] [diff] [review]
updated code

Ok, let's get this going again.  This doesn't use NSPR at all, so we don't have any of the problems associated with initialization or cross-process stuff; I'll make the JS side of things look for a symbol inside libxul first, but that's not included here.

This makes FunctionTimer.h globally available; bsmedberg, that look ok?
Comment 78 Benjamin Smedberg [:bsmedberg] 2010-04-06 14:02:17 PDT
Comment on attachment 435950 [details] [diff] [review]
updated code

>diff --git a/xpcom/base/FunctionTimer.h b/xpcom/base/FunctionTimer.h

>+#ifndef NS_FUNCTIONTIMER_H__
>+#define NS_FUNCTIONTIMER_H__

nit, please use mozilla_FunctionTimer_h

>+/****
>+ **** KEEP THIS FILE IN SYNC WITH js/src/jsftimer.h !
>+ ****/

stale comment, I think? 

>+#include <stdarg.h>
>+#include <string.h>
>+
>+#include <prtime.h>
>+#include <prinit.h>

I'd prefer this code in general to use TimeStamps instead of PRTime, to get better resolution where available and also avoid clock-adjust and overflow issues which that class solves.


>+// Add a timer for this block, using the printf-style format.
>+// Both function entry and exit will be printed.
>+#define NS_TIME_FUNCTION_FMT(...)                                       \
>+    mozilla::FunctionTimer ft__autogen(__VA_ARGS__)

I'm fine with --enable-functiontimer requiring C99 variable-arg macros. I wish there were a configure test for them. Could you file a followup if there's not one already available?


>+namespace mozilla {
>+
>+class NS_COM FunctionTimerLog {

nit here and below, opening brace of class in column 0

>+public:
>+    FunctionTimerLog(const char *fname);

As noted on IRC, I can't find anyone constructing one of these, so I'm interested to know where the filename comes from (you said it was a mis-qrefeshed patch, perhaps)
Comment 79 Vladimir Vukicevic [:vlad] [:vladv] 2010-04-15 13:45:27 PDT
Created attachment 439333 [details] [diff] [review]
updated

Ok, here's the updated framework, for real this time.

* mozilla/FunctionTimer.h
* uses TimeStamp

I had to change TimeStamp's initialization to use a static helper object, because xpcom init was too late for FunctionTimer's usage of it.  TimeStamp really isn't an XPCOM thing anyway (neither is FT, really).

https://wiki.mozilla.org/Platform/FunctionTimer_Usage has some usage instructions.  I'm still waiting for try server builds to finish, but that could be a while due to MV's internet problems.
Comment 80 Vladimir Vukicevic [:vlad] [:vladv] 2010-04-16 16:49:12 PDT
Created attachment 439649 [details] [diff] [review]
updated, v2

same as before, but fixes [v]sprintf usage due to #define shenanigans on all platforms.  builds on tryserver.
Comment 81 Vladimir Vukicevic [:vlad] [:vladv] 2010-04-16 16:49:47 PDT
I just realized that the TimeStamp usage means that this can't ever go into js. Hrm.  That's unfortunate, will have to work around that somehow.
Comment 82 Benjamin Smedberg [:bsmedberg] 2010-04-19 08:36:48 PDT
Comment on attachment 439649 [details] [diff] [review]
updated, v2

>diff --git a/xpcom/base/FunctionTimer.cpp b/xpcom/base/FunctionTimer.cpp

>+// needed to get vsnprintf with glibc
>+#ifndef _XOPEN_SOURCE
>+#define _XOPEN_SOURCE 500
>+#endif

man pages say  _ISOC99_SOURCE works as well, can we use that? Tt seems clearer to me, at least until we can require c++0x.

>+struct TimerInitialization {

nit, opening brace of struct in column 0

I might be too pedantic, in which case ignore me, but I think this would be simpler to understand without the TimerInitialization class, and just use a function to initialize, e.g.

int FunctionTimer::sBufSize = FunctionTimer::InitTimers(); // static initialization (InitTimers returns int, not void)

>+int
>+FunctionTimer::ft_vsnprintf(char *str, int maxlen, const char *fmt, va_list args)
>+{
>+#ifdef _MSC_VER
>+    return _vsnprintf(str, maxlen, fmt, args);
>+#else
>+    return vsnprintf(str, maxlen, fmt, args);
>+#endif
>+}

In other files we typically use

#ifdef _MSC_VER
#define vsnprintf _vsnprintf
#endif

>diff --git a/xpcom/base/FunctionTimer.h b/xpcom/base/FunctionTimer.h

>+class NS_COM FunctionTimerLog {

nit, brace in column 0, same for FunctionTimer below

>diff --git a/xpcom/ds/TimeStamp.cpp b/xpcom/ds/TimeStamp.cpp
>--- a/xpcom/ds/TimeStamp.cpp
>+++ b/xpcom/ds/TimeStamp.cpp
>@@ -41,6 +41,17 @@
> 
> namespace mozilla {
> 
>+struct TimeStampInitialization {

ditto

>+  TimeStampInitialization() {
>+    TimeStamp::Startup();
>+  }
>+  ~TimeStampInitialization() {
>+    TimeStamp::Shutdown();
>+  }
>+};
>

Hrm, it seems silly to me to destroy this lock on shutdown. Why bother? But since it already is this way, that's ok.

r=me with nits/notes
Comment 83 Vladimir Vukicevic [:vlad] [:vladv] 2010-04-20 13:25:38 PDT
Checked in with fixes.

http://hg.mozilla.org/mozilla-central/rev/e3798bb6927d

I'm going to close this bug and file a new bug shortly for the instrumentation work.
Comment 84 Vladimir Vukicevic [:vlad] [:vladv] 2010-04-20 13:28:43 PDT
bug 560647 is the tracking bug for instrumentation work.
Comment 85 David :Bienvenu 2010-04-20 14:28:05 PDT
I think this broke TB builds - http://tinderbox.mozilla.org/showlog.cgi?log=Thunderbird/1271796118.1271798200.32517.gz#err0
Comment 86 Andrew Sutherland [:asuth] 2010-04-20 14:39:22 PDT
(In reply to comment #85)
> I think this broke TB builds -
> http://tinderbox.mozilla.org/showlog.cgi?log=Thunderbird/1271796118.1271798200.32517.gz#err0

It may be better to characterize that as "Thunderbird's mozilla-central windows builds are on fire and it's possible this will be the case for Firefox too, but Thunderbird understands that mozilla-central does not and should not be concerned about breakage in comm-central if that does not turn out to be the case".
Comment 87 David :Bienvenu 2010-04-20 14:42:27 PDT
Er, yes, I'm just hoping for some hints as to why this broke TB and how to fix it. I think Firefox builds are fine, so perhaps there's some config change we need to make...
Comment 88 David :Bienvenu 2010-04-20 14:48:52 PDT
perhaps it's because we're building xpcom as a dll, at least in debug builds
Comment 89 David :Bienvenu 2010-04-20 15:06:25 PDT
putting the static char *sbuf2; on its own line seems to fix the issue here...
Comment 90 Andrew Sutherland [:asuth] 2010-04-20 15:31:30 PDT
for posterity, vlad pushed such a change:
http://hg.mozilla.org/mozilla-central/rev/fdc3abea224b
Comment 91 Serge Gautherie (:sgautherie) 2010-04-21 02:34:53 PDT
Created attachment 440441 [details] [diff] [review]
(AAv1-CC) Copy it to comm-central
[Moved to bug 604849]
Comment 92 Robert Kaiser 2010-04-21 09:34:55 PDT
Comment on attachment 440441 [details] [diff] [review]
(AAv1-CC) Copy it to comm-central
[Moved to bug 604849]

Do we win anything by having this in comm-central, i.e. do we need the NS_FUNCTION_TIMER var in application code? Or is this used in generic m-c code only anyhow?
Comment 93 Justin Wood (:Callek) 2010-04-21 11:54:51 PDT
Comment on attachment 440441 [details] [diff] [review]
(AAv1-CC) Copy it to comm-central
[Moved to bug 604849]

this needs a new bug; not reviewing here.
Comment 94 Serge Gautherie (:sgautherie) 2010-04-22 01:16:44 PDT
(In reply to comment #92)

See "v 0.6 unbitrotted instrumentation patch" as an example:

> do we need the NS_FUNCTION_TIMER var in application code?

NS_FUNCTION_TIMER, no; but FunctionTimer.h (which depends on it), yes.

> Or is this used in generic m-c code only anyhow?

I assume (c-c) apps may want to use this tool too.

Vladimir, did I figured it out wrongly?
Comment 95 Eric Shepherd [:sheppy] 2011-01-27 13:37:27 PST
Is this available in only core code, or can components use it?
Comment 96 Eric Shepherd [:sheppy] 2011-02-01 06:30:06 PST
fwiw, I've been looking at this code for a while, and it scares me enough that I would really prefer that someone else jot down notes or docs about this instead of trying to guess how this works. :)

Note You need to log in before you can comment on or make changes to this bug.