958596 - Add logging code for debugging the APZC tree

Status: RESOLVED FIXED

(Core :: Panning and Zooming, defect)

Description

[Botond Ballo [:botond]]

It would be nice to have an APZC tree dump in the same vein as a layer dump.

Some desirable features of this dump:
  - show all layers
  - for layers that have an APZC, indicate this
      - print out some information about its APZC, such as
          - its ScrollableLayerGuid
          - some metrics
          - the content element for which it was created

Comment 1

[Botond Ballo [:botond]]

Attachment: Original out-of-tree implementation

I have a patch in my local tree that does this. It uses some utilities which are contained in a separate repository at https://bitbucket.org/botond/mozilla-debug/.

I would like to clean up those utilities and the patch at some point and get them into m-c. Until then, I'm posting the patch as-is in case it's useful to someone.

Comment 2

[Botond Ballo [:botond]]

Attachment: Part 1 - Export Logging.h from gfx/2d

Comment 3

[Botond Ballo [:botond]]

Attachment: Part 2 - Add support for gfx logging on android and b2g

Comment 4

[Botond Ballo [:botond]]

Attachment: Part 3 - Add gfx logging support for 'char'

Comment 5

[Botond Ballo [:botond]]

Attachment: Part 4 - Allow gfx logging of any rect, size, and point

Comment 6

[Botond Ballo [:botond]]

Attachment: Part 5 - Allow writing a log statement that does not end in a newline

Comment 7

[Botond Ballo [:botond]]

Attachment: Part 6 - Add a tree logging utility

Comment 8

[Botond Ballo [:botond]]

Attachment: *prototype* code that illustrates usage of tree logging utility

Comment 9

[Botond Ballo [:botond]]

The attached patches implement the required enhancements to the gfx logging utility. Tomorrow I will post patches that implement the actual APZC tree logging using the enhanced logging utility.

Comment 10

[Bas Schouten (:bas.schouten)]

Comment on attachment 8363355 [details] [diff] [review]
Part 5 - Allow writing a log statement that does not end in a newline

Review of attachment 8363355 [details] [diff] [review]:
-----------------------------------------------------------------

Do you know whether the compiler will compile this into branchless code? I suspect so but I'd like us to be sure.

Comment 11

[Botond Ballo [:botond]]

(In reply to Bas Schouten (:bas.schouten) from comment #10)
> Comment on attachment 8363355 [details] [diff] [review]
> Part 5 - Allow writing a log statement that does not end in a newline
> 
> Review of attachment 8363355 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Do you know whether the compiler will compile this into branchless code? I
> suspect so but I'd like us to be sure.

Maybe we can add a MOZ_LIKELY around the condition?

Comment 12

[Botond Ballo [:botond]]

Attachment: Part 7 - Allow TreeLog logging to be conditioned on a pref

Comment 13

[Botond Ballo [:botond]]

Attachment: Part 8 - Add a Describe() method to nsIContent

Comment 14

[Botond Ballo [:botond]]

Attachment: Part 9 - Add a content description field to FrameMetrics and populate it if the apz.printtree pref is on

Comment 15

[Botond Ballo [:botond]]

Attachment: Part 10 - Print the APZC tree for debugging

Comment 16

[Botond Ballo [:botond]]

All right, that should be all the patches.

BenWa, I'm asking you for feedback on how I conditioned the logging on the pref (see also the Part 7 patch) to make sure it's OK for performance.

Comment 17

[Timothy Nikkel (:tnikkel)]

Comment on attachment 8363891 [details] [diff] [review]
Part 9 - Add a content description field to FrameMetrics and populate it if the apz.printtree pref is on

> APZCTreeManager::APZCTreeManager()
>     : mTreeLock("APZCTreeLock"),
>       mTouchCount(0)
> {
>   MOZ_ASSERT(NS_IsMainThread());
>   AsyncPanZoomController::InitializeGlobalState();
>+  Preferences::AddBoolVarCache(&gPrintApzcTree, "apz.printtree", gPrintApzcTree);
> }

We should probably call AddBoolVarCache only once, instead of each time we create a APZCTreeManager.

Comment 18

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 8363890 [details] [diff] [review]
Part 8 - Add a Describe() method to nsIContent

This should be using an outparam for the string for both methods, not a return value.

>+#include <sstream>

Why is this needed?

Attribute values can contain newlines, so if you're really relying on Describe() to produce one-line strings, you need to change how you're dealing with attributes.  On the other hand, if the "short" and "one-line" bits are aspirational and not actual requirements then this is probably ok.

Comment 19

[Botond Ballo [:botond]]

(In reply to Timothy Nikkel (:tn) from comment #17)
> Comment on attachment 8363891 [details] [diff] [review]
> Part 9 - Add a content description field to FrameMetrics and populate it if
> the apz.printtree pref is on
> 
> > APZCTreeManager::APZCTreeManager()
> >     : mTreeLock("APZCTreeLock"),
> >       mTouchCount(0)
> > {
> >   MOZ_ASSERT(NS_IsMainThread());
> >   AsyncPanZoomController::InitializeGlobalState();
> >+  Preferences::AddBoolVarCache(&gPrintApzcTree, "apz.printtree", gPrintApzcTree);
> > }
> 
> We should probably call AddBoolVarCache only once, instead of each time we
> create a APZCTreeManager.

Yeah, I just discovered this patch has other problems (the variable is only initialized in the parent process on B2G, but RecordFrameMetrics() needs to read it in the child process). I'll have to rethink this.

Comment 20

[Botond Ballo [:botond]]

Comment on attachment 8363891 [details] [diff] [review]
Part 9 - Add a content description field to FrameMetrics and populate it if the apz.printtree pref is on

This patch does not work. I will reupload a correct version shortly.

Comment 21

[Botond Ballo [:botond]]

Attachment: Part 8 - Add a Describe() method to nsIContent

Revised Part 8 patch to address review comments. The "one line" part is indeed aspirational, as this is method is meant to be used for debugging.

Comment 22

[Botond Ballo [:botond]]

Attachment: Part 8 - Add a Describe() method to nsIContent

Whoops, forgot to update one part. Fixed.

Comment 23

[Benoit Girard (:BenWa)]

Comment on attachment 8363893 [details] [diff] [review]
Part 10 - Print the APZC tree for debugging

Review of attachment 8363893 [details] [diff] [review]:
-----------------------------------------------------------------

::: gfx/layers/composite/APZCTreeManager.cpp
@@ +48,5 @@
>        mTouchCount(0)
>  {
>    MOZ_ASSERT(NS_IsMainThread());
>    AsyncPanZoomController::InitializeGlobalState();
>    Preferences::AddBoolVarCache(&gPrintApzcTree, "apz.printtree", gPrintApzcTree);

We can't read preference off the main thread. This needs to be done from gfxPlatform. IMO the preference should probably be layers.apzc.dump or under gfx. Ideally pref TLD-ish thing should be modules.

@@ +49,5 @@
>  {
>    MOZ_ASSERT(NS_IsMainThread());
>    AsyncPanZoomController::InitializeGlobalState();
>    Preferences::AddBoolVarCache(&gPrintApzcTree, "apz.printtree", gPrintApzcTree);
> +  sApzcTreeLog.ConditionOnPref(&gPrintApzcTree);

I do like the idea of a preference conditional logging module.

@@ +130,5 @@
>    Collect(mRootApzc, &apzcsToDestroy);
>    mRootApzc = nullptr;
>  
>    if (aRoot) {
> +    sApzcTreeLog << "[start]\n";

I'd rather have this logging resemble the layers.dump more closely. Not a fan of logging [start]/[end], esp. without context, it should be more descriptive.

Comment 24

[Botond Ballo [:botond]]

(In reply to Benoit Girard (:BenWa) from comment #23)
> Comment on attachment 8363893 [details] [diff] [review]
> Part 10 - Print the APZC tree for debugging
> 
> Review of attachment 8363893 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> ::: gfx/layers/composite/APZCTreeManager.cpp
> @@ +48,5 @@
> >        mTouchCount(0)
> >  {
> >    MOZ_ASSERT(NS_IsMainThread());
> >    AsyncPanZoomController::InitializeGlobalState();
> >    Preferences::AddBoolVarCache(&gPrintApzcTree, "apz.printtree", gPrintApzcTree);
> 
> We can't read preference off the main thread. This needs to be done from
> gfxPlatform. IMO the preference should probably be layers.apzc.dump or under
> gfx. Ideally pref TLD-ish thing should be modules.

AsyncPanZoomController::InitializeGlobalState() does the exact same thing to other APZ preferences.

Comment 25

[Botond Ballo [:botond]]

(In reply to Botond Ballo [:botond] from comment #24)
> (In reply to Benoit Girard (:BenWa) from comment #23)
> > Comment on attachment 8363893 [details] [diff] [review]
> > Part 10 - Print the APZC tree for debugging
> > 
> > Review of attachment 8363893 [details] [diff] [review]:
> > -----------------------------------------------------------------
> > 
> > ::: gfx/layers/composite/APZCTreeManager.cpp
> > @@ +48,5 @@
> > >        mTouchCount(0)
> > >  {
> > >    MOZ_ASSERT(NS_IsMainThread());
> > >    AsyncPanZoomController::InitializeGlobalState();
> > >    Preferences::AddBoolVarCache(&gPrintApzcTree, "apz.printtree", gPrintApzcTree);
> > 
> > We can't read preference off the main thread. This needs to be done from
> > gfxPlatform. IMO the preference should probably be layers.apzc.dump or under
> > gfx. Ideally pref TLD-ish thing should be modules.
> 
> AsyncPanZoomController::InitializeGlobalState() does the exact same thing to
> other APZ preferences.

And regarding naming, all other APZ prefs are prefixed with 'apz.'.

Comment 26

[Benoit Girard (:BenWa)]

Those are bugs, so going forward we shouldn't make it worse.

Comment 27

[Botond Ballo [:botond]]

Attachment: Part 9 - Add a content description field to FrameMetrics and populate it if the apz.printtree pref is on

This is working now.

Comment 28

[Botond Ballo [:botond]]

(In reply to Benoit Girard (:BenWa) from comment #26)
> Those are bugs, so going forward we shouldn't make it worse.

We discussed this in person, summarizing for the record:
  - The APZCTreeManager constructor is called on the main thread, so reading 
    preferences from there is fine.
  - apz.* naming is fine for now, apz might become a module at some point anyways.

Comment 29

[Botond Ballo [:botond]]

Attachment: Sample output of APZC tree in logcat

Comment 30

[Kartikaya Gupta (email:[e-mail])]

Comment on attachment 8363950 [details] [diff] [review]
Part 9 - Add a content description field to FrameMetrics and populate it if the apz.printtree pref is on

Review of attachment 8363950 [details] [diff] [review]:
-----------------------------------------------------------------

::: gfx/layers/FrameMetrics.h
@@ +6,5 @@
>  #ifndef GFX_FRAMEMETRICS_H
>  #define GFX_FRAMEMETRICS_H
>  
>  #include <stdint.h>                     // for uint32_t, uint64_t
> +#include <string>

For completeness add a comment similar to the other includes

Comment 31

[Kartikaya Gupta (email:[e-mail])]

Comment on attachment 8363893 [details] [diff] [review]
Part 10 - Print the APZC tree for debugging

Review of attachment 8363893 [details] [diff] [review]:
-----------------------------------------------------------------

I have two concerns here: one is the thread safety with respect to TreeLog. Right now all the logging is done from the compositor thread but if we start adding log output in other functions which may run on other threads then would that be problematic? The other is the performance implications because it looks like we'll do a bunch of work to serialize stuff even if the pref is disabled. But I don't want to prematurely optimize this so I'm fine with leaving it for now and worrying about it if it becomes a problem.

::: gfx/layers/composite/APZCTreeManager.cpp
@@ +40,5 @@
>  {
>    return gPrintApzcTree;
>  }
>  
> +gfx::TreeLog sApzcTreeLog("apzctree");

Assuming this patch needs to be rebased, since the GetApzcTreePrintPref just above is no longer in the queue

@@ +130,5 @@
>    Collect(mRootApzc, &apzcsToDestroy);
>    mRootApzc = nullptr;
>  
>    if (aRoot) {
> +    sApzcTreeLog << "[start]\n";

I agree with BenWa's comment about making [start] and [end] more descriptive. I probably would have gone with <apzc-tree> and </apzc-tree> myself but if you can make it look closer to the layers dump that's fine too.

Comment 32

[Botond Ballo [:botond]]

(In reply to Kartikaya Gupta (email:[e-mail]) from comment #31)
> I have two concerns here: one is the thread safety with respect to TreeLog.
> Right now all the logging is done from the compositor thread but if we start
> adding log output in other functions which may run on other threads then
> would that be problematic? 

My intention was to use TreeLog just for the APZC tree logging for now. I can add a comment saying so. If we later want to log stuff from the main thread, I think we can further enhance the logging mechanism to provide the appropriate thread safety at that time.

> The other is the performance implications because
> it looks like we'll do a bunch of work to serialize stuff even if the pref
> is disabled.

Can you give an example of what would be serialized? Since 'TreeLog::operator<<(Whatever)' exits early if the pref is disabled, 'Log::operator<<(Whatever)', which is what would do any serialization, is never called. Nor do we compute FrameMetrics::mContentDescription if the pref is disabled.

> ::: gfx/layers/composite/APZCTreeManager.cpp
> @@ +40,5 @@
> >  {
> >    return gPrintApzcTree;
> >  }
> >  
> > +gfx::TreeLog sApzcTreeLog("apzctree");
> 
> Assuming this patch needs to be rebased, since the GetApzcTreePrintPref just
> above is no longer in the queue

Yep.

> @@ +130,5 @@
> >    Collect(mRootApzc, &apzcsToDestroy);
> >    mRootApzc = nullptr;
> >  
> >    if (aRoot) {
> > +    sApzcTreeLog << "[start]\n";
> 
> I agree with BenWa's comment about making [start] and [end] more
> descriptive. I probably would have gone with <apzc-tree> and </apzc-tree>
> myself but if you can make it look closer to the layers dump that's fine too.

Each line of the output is prefixed with "apzctree" (see the attached example output). Is it OK like that?

Comment 33

[Botond Ballo [:botond]]

(In reply to Botond Ballo [:botond] from comment #32)
> My intention was to use TreeLog just for the APZC tree logging for now.

s/TreeLog/sApzcTreeLog. Of course other TreeLog instances can be created and used elsewhere.

Comment 34

[Bas Schouten (:bas.schouten)]

(In reply to Botond Ballo [:botond] from comment #11)
> (In reply to Bas Schouten (:bas.schouten) from comment #10)
> > Comment on attachment 8363355 [details] [diff] [review]
> > Part 5 - Allow writing a log statement that does not end in a newline
> > 
> > Review of attachment 8363355 [details] [diff] [review]:
> > -----------------------------------------------------------------
> > 
> > Do you know whether the compiler will compile this into branchless code? I
> > suspect so but I'd like us to be sure.
> 
> Maybe we can add a MOZ_LIKELY around the condition?

We could also make it a template parameter? ;)

Comment 35

[Kartikaya Gupta (email:[e-mail])]

(In reply to Botond Ballo [:botond] from comment #32)
> My intention was to use TreeLog just for the APZC tree logging for now. I
> can add a comment saying so. If we later want to log stuff from the main
> thread, I think we can further enhance the logging mechanism to provide the
> appropriate thread safety at that time.

Sounds good.

> Can you give an example of what would be serialized? Since
> 'TreeLog::operator<<(Whatever)' exits early if the pref is disabled,
> 'Log::operator<<(Whatever)', which is what would do any serialization, is
> never called. Nor do we compute FrameMetrics::mContentDescription if the
> pref is disabled.

My bad, I misread the earlier patch. This is fine then.

> > I agree with BenWa's comment about making [start] and [end] more
> > descriptive. I probably would have gone with <apzc-tree> and </apzc-tree>
> > myself but if you can make it look closer to the layers dump that's fine too.
> 
> Each line of the output is prefixed with "apzctree" (see the attached
> example output). Is it OK like that?

That's fine by me.

Comment 36

[Botond Ballo [:botond]]

(In reply to Bas Schouten (:bas.schouten) from comment #34)
> (In reply to Botond Ballo [:botond] from comment #11)
> > (In reply to Bas Schouten (:bas.schouten) from comment #10)
> > > Comment on attachment 8363355 [details] [diff] [review]
> > > Part 5 - Allow writing a log statement that does not end in a newline
> > > 
> > > Review of attachment 8363355 [details] [diff] [review]:
> > > -----------------------------------------------------------------
> > > 
> > > Do you know whether the compiler will compile this into branchless code? I
> > > suspect so but I'd like us to be sure.
> > 
> > Maybe we can add a MOZ_LIKELY around the condition?
> 
> We could also make it a template parameter? ;)

We could. It would complicate things a bit because you could no longer say things like "gfxDebug(NoNewline) << ...", we'd need to instead have a "gfxDebugNoNewline" macro that expands to the different type. I think MOZ_LIKELY is good enough, but if you feel strongly about it, feel free to say so and r-. ;)

Comment 37

[Botond Ballo [:botond]]

Attachment: Part 9 - Add a content description field to FrameMetrics and populate it if the apz.printtree pref is on

Address review comment. Carrying r+.

Comment 38

[Botond Ballo [:botond]]

Attachment: Part 10 - Print the APZC tree for debugging

Rebase and address review comment. Carrying r+.

Comment 39

[Botond Ballo [:botond]]

Attachment: Part 11 - Allow gfx logging of long long

Comment 40

[Botond Ballo [:botond]]

Attachment: Part 12 - Include the ScrollableLayerGuid in APZC tree log

Comment 41

[Botond Ballo [:botond]]

Attachment: Sample output of APZC tree in logcat

Update sample output to include SLGs.

Comment 42

[Kartikaya Gupta (email:[e-mail])]

Comment on attachment 8364032 [details] [diff] [review]
Part 12 - Include the ScrollableLayerGuid in APZC tree log

Review of attachment 8364032 [details] [diff] [review]:
-----------------------------------------------------------------

::: gfx/layers/FrameMetrics.h
@@ +408,5 @@
>  };
>  
> +template <int LogLevel>
> +gfx::Log<LogLevel>& operator<<(gfx::Log<LogLevel>& log, const ScrollableLayerGuid& aGuid) {
> +  return log << '(' << aGuid.mLayersId << ", " << aGuid.mPresShellId << ", " << aGuid.mScrollId << ')';

Actually, I'd prefer if you removed the spaces after the commas. Not just for consistency with printing other objects but also it's more visually grouped and easier to grab in awk scripts (which I tend to use not infrequently on log output).

Comment 43

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 8363911 [details] [diff] [review]
Part 8 - Add a Describe() method to nsIContent

r=me

Comment 44

[Botond Ballo [:botond]]

Attachment: Part 12 - Include the ScrollableLayerGuid in APZC tree log

Updated part 12 patch to remove spaces between the SLG components. Carrying r+.

Comment 45

[Botond Ballo [:botond]]

These patches cause a linker error "undefined reference to 'GetGFX2DLog()'" on Fennec. Not sure why yet. Possibly including Logging.h from FrameMetrics.h changes whether or not PR_LOGGING is defined inside Logging.h.

Comment 46

[Botond Ballo [:botond]]

Attachment: Part 0 - Adjust condition for defining GetGFX2DLog

(In reply to Botond Ballo [:botond] from comment #45)
> These patches cause a linker error "undefined reference to 'GetGFX2DLog()'"
> on Fennec. Not sure why yet. Possibly including Logging.h from
> FrameMetrics.h changes whether or not PR_LOGGING is defined inside Logging.h.

The problem was that both the declaration of GetGFX2DLog() in Logging.h, and its definition in Factory.cpp, were guarded by '#ifdef PR_LOGGING'. When building on Fennec, PR_LOGGING is not defined by the build system, but it is defined in prlog.h, and LayersTypes.h includes prlog.h if DEBUG is defined. LayersTypes.h is not included by Factory.cpp, but is by ContentClient.cpp, which is in the same unified source file as APZCTreeManager.cpp, which now includes Logging.h. As a result, PR_LOGGING was being defined in Logging.h, but not in Factory.cpp, so the declaration of GetGFX2DLog() was being compiled but not the definition, and we got the linker error.

The attached patch resolves the problem by adjusting the guards for the declaration and definition of GetGFX2DLog() to be '#if defined(DEBUG) || defined(PR_LOGGING)".

Comment 47

[Botond Ballo [:botond]]

Try run: https://tbpl.mozilla.org/?tree=Try&rev=7e752884e09e

Comment 48

[Kartikaya Gupta (email:[e-mail])]

(In reply to Botond Ballo [:botond] from comment #46)
> The attached patch resolves the problem by adjusting the guards for the
> declaration and definition of GetGFX2DLog() to be '#if defined(DEBUG) ||
> defined(PR_LOGGING)".

I don't know if the standalone-ness of Moz2D will allow it but I would have preferred explicitly including prlog.h in both Logging.h and Factory.cpp.

(In reply to Botond Ballo [:botond] from comment #47)
> Try run: https://tbpl.mozilla.org/?tree=Try&rev=7e752884e09e

Looks like the compiler didn't like you trying to outsmart it :p

Comment 49

[Botond Ballo [:botond]]

(In reply to Kartikaya Gupta (email:[e-mail]) from comment #48)
> (In reply to Botond Ballo [:botond] from comment #46)
> > The attached patch resolves the problem by adjusting the guards for the
> > declaration and definition of GetGFX2DLog() to be '#if defined(DEBUG) ||
> > defined(PR_LOGGING)".
> 
> I don't know if the standalone-ness of Moz2D will allow it but I would have
> preferred explicitly including prlog.h in both Logging.h and Factory.cpp.

Bas, is it OK to unconditionally include prlog.h from gfx/2d/Logging.h?

Comment 50

[Botond Ballo [:botond]]

Attachment: Part 9 - Add a content description field to FrameMetrics and populate it if the apz.printtree pref is on

(In reply to Kartikaya Gupta (email:[e-mail]) from comment #48)
> (In reply to Botond Ballo [:botond] from comment #47)
> > Try run: https://tbpl.mozilla.org/?tree=Try&rev=7e752884e09e
> 
> Looks like the compiler didn't like you trying to outsmart it :p

Updated Part 9 patch to be a little less smart and avoid the unused variable error. Carrying r+.

Comment 51

[Botond Ballo [:botond]]

New try push: https://tbpl.mozilla.org/?tree=Try&rev=2f7504009e4f

Comment 52

[Botond Ballo [:botond]]

(In reply to Botond Ballo [:botond] [c++ standards meeting Feb 10-15] from comment #51)
> New try push: https://tbpl.mozilla.org/?tree=Try&rev=2f7504009e4f

Unfortunately we still have a build error on Windows XP, because nsGlobalWindow.cpp includes (indirectly) FrameMetrics.h, which now includes Logging.h, which includes windows.h, but nsGlobalWindow.cpp asserts [1] that windows.h is not included.

I'm not sure what the purpose of preventing windows.h from being included from nsGlobalWindow.cpp is, but assuming there's a good reason for that, we can work around this by moving the inline definition of OutputMessage() in Logging.h (which uses a Windows API on Windows) out of line into cpp file. Bas, can we do this?

[1] http://hg.mozilla.org/mozilla-central/annotate/879038dcacb7/dom/base/nsGlobalWindow.cpp#l13491

Comment 53

[Botond Ballo [:botond]]

Attachment: Part -1 - Define OutputMessage() in Factory.cpp rather than Logging.h

(In reply to Botond Ballo [:botond] from comment #52)
> Unfortunately we still have a build error on Windows XP, because
> nsGlobalWindow.cpp includes (indirectly) FrameMetrics.h, which now includes
> Logging.h, which includes windows.h, but nsGlobalWindow.cpp asserts [1] that
> windows.h is not included.
> 
> I'm not sure what the purpose of preventing windows.h from being included
> from nsGlobalWindow.cpp is, but assuming there's a good reason for that, we
> can work around this by moving the inline definition of OutputMessage() in
> Logging.h (which uses a Windows API on Windows) out of line into cpp file.
> Bas, can we do this?

The attached patch does this.

One more try push: https://tbpl.mozilla.org/?tree=Try&rev=10818e37426e

Comment 54

[Bas Schouten (:bas.schouten)]

Comment on attachment 8378061 [details] [diff] [review]
Part -1 - Define OutputMessage() in Factory.cpp rather than Logging.h

Review of attachment 8378061 [details] [diff] [review]:
-----------------------------------------------------------------

I'd rather not if we want to be able to do fast release build logging. I'd hate to add a needless extra function call overhead. As a hack we could just manually declare OutputMessage?

Comment 55

[Botond Ballo [:botond]]

Attachment: Part -1 - Avoid including windows.h in Logging.h

(In reply to Bas Schouten (:bas.schouten) from comment #54)
> I'd rather not if we want to be able to do fast release build logging. I'd
> hate to add a needless extra function call overhead. As a hack we could just
> manually declare OutputMessage?

I assume you meant here manually declare OutpuDebugStringA, which the only API we use from windows.h, instead of including windows.h. The attached patch does that.

Comment 56

[Botond Ballo [:botond]]

One more Try: https://tbpl.mozilla.org/?tree=Try&rev=810211094cbe

Comment 57

[Botond Ballo [:botond]]

Attachment: Part -1 - Avoid including windows.h in Logging.h

(In reply to Botond Ballo [:botond] from comment #56)
> One more Try: https://tbpl.mozilla.org/?tree=Try&rev=810211094cbe

Silly me. If windows.h isn't included, then WINAPI and LPCSTR, which appear in the signature of my "manually-declared" OutputDebugStringA, aren't defined either. I need to use their expansions directly.

Trying again: https://tbpl.mozilla.org/?tree=Try&rev=3c4651d030ad

Comment 58

[Botond Ballo [:botond]]

(In reply to Botond Ballo [:botond] from comment #57)
> Trying again: https://tbpl.mozilla.org/?tree=Try&rev=3c4651d030ad

And failed again, something about linkage this time. I'm getting tired of this. I'll set up a local Windows XP build and get it to compile locally there.

Comment 59

[Botond Ballo [:botond]]

(In reply to Botond Ballo [:botond] from comment #58)
> (In reply to Botond Ballo [:botond] from comment #57)
> > Trying again: https://tbpl.mozilla.org/?tree=Try&rev=3c4651d030ad
> 
> And failed again, something about linkage this time. I'm getting tired of
> this. I'll set up a local Windows XP build and get it to compile locally
> there.

That turned out to be a good idea - I had to go through another four edit/compile cycles on my local build before getting it to compile. For the record, the magic incantations were 'extern "C"' and '__declspec(dllimport)' at the beginning of the declaration of OutputDebugStringA, in that order.

Unfortunately, it still does not link, because it seems Factory.cpp, which provides the definitions for some things defined in Logging.h, does not get linked on Windows XP. In fact, it seems the entire gfx/2d module is not linked on Windows XP. Prior to my patches, this was OK because gfx/2d/Logging.h was only included by things in the gfx/2d module. However, my patches introduce the use of gfx/2d/Logging.h from other modules. I will have to discuss this with Bas to arrive at a solution.

Comment 60

[Botond Ballo [:botond]]

(In reply to Botond Ballo [:botond] from comment #46)
> The attached patch resolves the problem by adjusting the guards for the
> declaration and definition of GetGFX2DLog() to be '#if defined(DEBUG) ||
> defined(PR_LOGGING)".

Unfortunately, this breaks APZC tree printing in debug builds because the messages now go the PR log...

Comment 61

[Botond Ballo [:botond]]

Attachment: Part 1 - Allow gfx/2d/Logging.h to be used outside of gfx/2d

(In reply to Botond Ballo [:botond] from comment #59)
> Unfortunately, it still does not link, because it seems Factory.cpp, which
> provides the definitions for some things defined in Logging.h, does not get
> linked on Windows XP. In fact, it seems the entire gfx/2d module is not
> linked on Windows XP. Prior to my patches, this was OK because
> gfx/2d/Logging.h was only included by things in the gfx/2d module. However,
> my patches introduce the use of gfx/2d/Logging.h from other modules. I will
> have to discuss this with Bas to arrive at a solution.

So it turns out gfx/2d _is_ being linked on Windows XP, but into a separate 'gkmedia' library rather than into xul. As a result, things defined in gfx/2d but used outside of it (e.g. sGfxLogLevel) need to marked with GFX2D_API, which expands to __declspec(dllexport) inside gfx/2d, and __declspec(dllimport) elsewhere.

Once I added that I ran into an additional problem where the expansion of GFX2D_API is conditioned on MOZ_GFX, which is defined only in gfx/2d. I changed it to be conditioned on GKMEDIAS_SHARED_LIBRARY, which is defined whenever we are creating this separate 'gkmedia' library (and adjusted configure.in accordingly to make the symbol GKMEDIAS_SHARED_LIBRARY available to source code), and that worked fine.

I ran into one final issue, where a function that shouldn't have been marked GFX2D_API because it was defined inline (http://mxr.mozilla.org/mozilla-central/source/gfx/2d/Rect.h?force=1#100), was. I corrected this, and finally got the result to compile and link on Windows XP.

The attached patch consolidates the current Part -1, Part 0, and Part 1 patches, and includes the changes I just describes, since all of these concern allowing gfx/2d/Logging.h to be used outside of gfx/2d.

New Try push: https://tbpl.mozilla.org/?tree=Try&rev=a2ace943c5f3

Note that the issue I raised in comment #60 remains to be resolved.

Comment 62

[Botond Ballo [:botond]]

Attachment: Part 2 - Add support for gfx logging on android and b2g

(In reply to Botond Ballo [:botond] from comment #60)
> (In reply to Botond Ballo [:botond] from comment #46)
> > The attached patch resolves the problem by adjusting the guards for the
> > declaration and definition of GetGFX2DLog() to be '#if defined(DEBUG) ||
> > defined(PR_LOGGING)".
> 
> Unfortunately, this breaks APZC tree printing in debug builds because the
> messages now go the PR log...

Fixed this for now by adjusting the preprocessor conditions in OutputMessage() such that on b2g and android, we always use logcat rather than the PR log. In the longer term we can get the PR log to play more nicely with b2g/android.

New try push: https://tbpl.mozilla.org/?tree=Try&rev=cd1b3dd2482b

Comment 63

[Bas Schouten (:bas.schouten)]

Comment on attachment 8379913 [details] [diff] [review]
Part 1 - Allow gfx/2d/Logging.h to be used outside of gfx/2d

Review of attachment 8379913 [details] [diff] [review]:
-----------------------------------------------------------------

Looks fine to me.

Comment 64

[Botond Ballo [:botond]]

(In reply to Botond Ballo [:botond] from comment #62)
> New try push: https://tbpl.mozilla.org/?tree=Try&rev=cd1b3dd2482b

Unfortunately, this is showing errors on some Linux and OS X platforms, such as:

package-manifest:40: Missing file(s): bin/libgkmedias.so

I'm pretty sure this is related to the configure.in change I made (making GKMEDIAS_SHARED_LIBRARY available to source code), though I'm not quite sure how...

Comment 65

[Kartikaya Gupta (email:[e-mail])]

Comment on attachment 8379913 [details] [diff] [review]
Part 1 - Allow gfx/2d/Logging.h to be used outside of gfx/2d

Review of attachment 8379913 [details] [diff] [review]:
-----------------------------------------------------------------

::: configure.in
@@ +7715,5 @@
>  if test "$OS_ARCH" = "WINNT"; then
>    GKMEDIAS_SHARED_LIBRARY=1
>  fi
>  AC_SUBST(GKMEDIAS_SHARED_LIBRARY)
> +AC_DEFINE(GKMEDIAS_SHARED_LIBRARY)

I think you might want to move this AC_DEFINE inside the WINNT check above.

Comment 66

[Botond Ballo [:botond]]

(In reply to Kartikaya Gupta (email:[e-mail]) from comment #65)
> ::: configure.in
> @@ +7715,5 @@
> >  if test "$OS_ARCH" = "WINNT"; then
> >    GKMEDIAS_SHARED_LIBRARY=1
> >  fi
> >  AC_SUBST(GKMEDIAS_SHARED_LIBRARY)
> > +AC_DEFINE(GKMEDIAS_SHARED_LIBRARY)
> 
> I think you might want to move this AC_DEFINE inside the WINNT check above.

That did the trick. Thanks!

New try push is clean: https://tbpl.mozilla.org/?tree=Try&rev=ca797da79dc6

Landed: https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?changeset=63d96f3e3e42

Comment 67

[Ed Morley [:emorley]]

(In reply to Botond Ballo [:botond] from comment #66)
> Landed:
> https://hg.mozilla.org/integration/mozilla-inbound/
> pushloghtml?changeset=63d96f3e3e42

Backed out for:
https://tbpl.mozilla.org/php/getParsedLog.php?id=35223589&tree=Mozilla-Inbound

remote:   https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?changeset=ecfb4d63943f

Comment 68

[Botond Ballo [:botond]]

(In reply to Ed Morley [:edmorley UTC+0] from comment #67)
> (In reply to Botond Ballo [:botond] from comment #66)
> > Landed:
> > https://hg.mozilla.org/integration/mozilla-inbound/
> > pushloghtml?changeset=63d96f3e3e42
> 
> Backed out for:
> https://tbpl.mozilla.org/php/getParsedLog.php?id=35223589&tree=Mozilla-
> Inbound

Right. Try build was clean, but it was optimized builds only. I still have a linker error for the Windows XP _debug_ build... Sorry about that.

Comment 69

[Botond Ballo [:botond]]

Attachment: Part 1 - Allow gfx/2d/Logging.h to be used outside of gfx/2d

(In reply to Botond Ballo [:botond] from comment #68)
> Try build was clean, but it was optimized builds only. I still have a
> linker error for the Windows XP _debug_ build... Sorry about that.

I needed a GFX2D_API in front of GetGFX2DLog(), similarly to how I needed one in front of sGfxLogLevel.

Updated Part 1 patch, carrying r+.

One more try build, this time for both debug and release builds, to be absolutely sure nothing is busted: https://tbpl.mozilla.org/?tree=Try&rev=7d7ad2d1ffdf.

Comment 70

[Botond Ballo [:botond]]

Relanded: https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?changeset=e4c0e3d3a768

Comment 71

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

Backed out in http://hg.mozilla.org/integration/mozilla-inbound/rev/c9f4f70e46e1 because this seems to have turned several Android tests permanently orange (they were starred as Bug 912238 on your try push, but this seems to have made that failure happen constantly):

Android 4.0 mochitest-6, mochitest-7 and tspaint all turned orange because of this push:
https://tbpl.mozilla.org/php/getParsedLog.php?id=35252067&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=35251554&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=35250076&tree=Mozilla-Inbound

robocheck-2 failed in a similar way once, but hasn't since: https://tbpl.mozilla.org/php/getParsedLog.php?id=35250554&tree=Mozilla-Inbound

Comment 72

[Kartikaya Gupta (email:[e-mail])]

Might as well fix bug 912238 properly then.

Comment 73

[Botond Ballo [:botond]]

ReTrying after bug 912238 landing: https://tbpl.mozilla.org/?tree=Try&rev=b5d023b54a1b

Comment 74

[Botond Ballo [:botond]]

(In reply to Botond Ballo [:botond] from comment #73)
> ReTrying after bug 912238 landing:
> https://tbpl.mozilla.org/?tree=Try&rev=b5d023b54a1b

We are still seeing some Talos failures. I did some targeted Try pushes to bisect the patchset:

https://tbpl.mozilla.org/?tree=Try&rev=153ab7477ea4
https://tbpl.mozilla.org/?tree=Try&rev=0b9b2d76d41f
https://tbpl.mozilla.org/?tree=Try&rev=6ae5ecc17b02
https://tbpl.mozilla.org/?tree=Try&rev=3b785af1de27
https://tbpl.mozilla.org/?tree=Try&rev=745452e62bd2

They suggest that the problem is caused by the Part 10 patch, which actually adds the tree logging to APZCTreeManager. Given that the problem seems to be with the shutdown sequence, the culprit is usually the static variable 'gfx::TreeLog sApzcTreeLog' that the patch introduces, whose destructor flushes the log. Perhaps by the time the destructor is called, it's too late in the shutdown sequence to be doing things like that?

Comment 75

[Botond Ballo [:botond]]

Attachment: Part 10 - Print the APZC tree for debugging

(In reply to Botond Ballo [:botond] from comment #74)
> We are still seeing some Talos failures. I did some targeted Try pushes to
> bisect the patchset:
> 
> https://tbpl.mozilla.org/?tree=Try&rev=153ab7477ea4
> https://tbpl.mozilla.org/?tree=Try&rev=0b9b2d76d41f
> https://tbpl.mozilla.org/?tree=Try&rev=6ae5ecc17b02
> https://tbpl.mozilla.org/?tree=Try&rev=3b785af1de27
> https://tbpl.mozilla.org/?tree=Try&rev=745452e62bd2
> 
> They suggest that the problem is caused by the Part 10 patch, which actually
> adds the tree logging to APZCTreeManager. Given that the problem seems to be
> with the shutdown sequence, the culprit is probably the static variable
> 'gfx::TreeLog sApzcTreeLog' that the patch introduces, whose destructor
> flushes the log. Perhaps by the time the destructor is called, it's too late
> in the shutdown sequence to be doing things like that?

Updated Part 10 patch to make the tree log a member of APZCTreeManager rather than a static storage duration object. This ensures that its destructor is called earlier in the shutdown sequence.

This Try push confirms that the Talos failures are gone: https://tbpl.mozilla.org/?tree=Try&rev=34136a76b430

Note that Kats has already reviewed this patch; the only change since then is the tree log being changed from a static variable to a member of APZCTreeManager.

Comment 76

[Benoit Girard (:BenWa)]

Comment on attachment 8384218 [details] [diff] [review]
Part 10 - Print the APZC tree for debugging

Review of attachment 8384218 [details] [diff] [review]:
-----------------------------------------------------------------

::: gfx/layers/composite/APZCTreeManager.h
@@ +340,5 @@
>     * been scrolled as far as it can, any overscroll will be handed off to
>     * the next APZC in the chain.
>     */
>    Vector< nsRefPtr<AsyncPanZoomController> > mOverscrollHandoffChain;
> +  /* For logging the APZC tree for debugging (enabled by th e apz.printtree

typo, the

Comment 77

[Botond Ballo [:botond]]

Relanded again: https://hg.mozilla.org/integration/b2g-inbound/pushloghtml?changeset=0ed4786b22de

Comment 78

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/1e198a326d40
https://hg.mozilla.org/mozilla-central/rev/6d773a03f680
https://hg.mozilla.org/mozilla-central/rev/f6a8fd3cc486
https://hg.mozilla.org/mozilla-central/rev/5de6d97667b0
https://hg.mozilla.org/mozilla-central/rev/e4c8a1eb2975
https://hg.mozilla.org/mozilla-central/rev/210e09a2d111
https://hg.mozilla.org/mozilla-central/rev/8a1799d0ec17
https://hg.mozilla.org/mozilla-central/rev/6d0217b266f6
https://hg.mozilla.org/mozilla-central/rev/3da14f8555f7
https://hg.mozilla.org/mozilla-central/rev/12eceba2ed2b
https://hg.mozilla.org/mozilla-central/rev/62b54b8fa885
https://hg.mozilla.org/mozilla-central/rev/0ed4786b22de

Comment 79

[(no longer active)]

One hunk from the part 1 of this patch conflicted with bug 978776, which I fixed here:

<https://hg.mozilla.org/integration/mozilla-inbound/rev/6cf800d6a85e>

FWIW, moz2d is now in libxul, and GKMEDIAS_SHARED_LIBRARY is the wrong condition to test for here since it tells you whether gkmedias is built as a shared library, not whether moz2d is inside it.