545995 - Early #include of IPDL-generated files can lead to broken logging in release builds

Status: RESOLVED WORKSFORME

(Core :: IPC, defect)

Description

[Jason Duell]

This may be something we just have to look out for, rather than something we can "fix":

IPDL-generated files #include chromium files that wind up #including prlog.h (NSPR's logging header).  In many places in our tree we #define PR_FORCE_LOGGING before including prlog.h (which forces logging to be on for a given module in a non-debug build), but if one accidentally places an IPDL include before this, prlog.h will not see PR_FORCE_LOGGING.  If one is lucky (as I was) this happens inconsistently within a module, and the code that initializes the module's PRLogModuleInfo variable is disabled, and you get segfaults on a tinderbox opt build.  If you're not lucky, you've accidentally turned off logging in some or all of your module in release builds.

The problem is compounded by the common idiom in Mozilla code where we #define a LOG() macro that calls PR_LOG (I count 74 instances of this in the tree).  The Chromium headers also #define LOG (very differently), and so any code that #includes IPDL-generated headers, and also #defines LOG, needs to do something like this:

  #if MOZ_IPC
  #ifdef PR_LOG
  #error "nsHttp.h must come before any IPDL-generated files or other files that #include prlog.h"
  #endif
  #define PR_FORCE_LOG
  #include "some_IPDL_generated_file.h"
  #undef LOG
  #endif // MOZ_IPC  
  ...
  #define LOG PR_LOG(...)

The check for #ifdef PR_LOG requires nsHttp.h (in my module's case) to be #included before any IPDL-generated headers.  Without this, we could still silently disable logging on a per-compilation unit basis.

We could obviously fix the LOG issue with mass renaming in either our or the chromium codebase, but I don't see any clever way to avoid the FORCE_PR_LOG issue, other than via this "code recipe".  Anyone have any ideas?

Yet another way that this fix is fragile:  I can't just #include any old IPDL-generated header.  If I try to use "PNecko.h", for instance, I get errors  when I later #include "PNeckoChild.h", because that file #includes chromium's id_map.h, which uses LOG (and expects chromium's #def of LOG, but instead got ours).  So we need to have a guarantee that the IPDL-generated file that we include sucks in every header we'll use from chromium that uses LOG.  For now, at least, that seems to work for me with PNeckoChild.h.  Cjones can tell us if we're likely to get in any trouble with this in other cases.

Comment 1

[Jason Duell]

The actual code fix for http (slightly more complicated) for this issue can be seen by diffing attachment #426811 [details] [diff] [review] to bug 530952 with the previous patch for that bug.

Comment 2

[Jason Duell]

Actually you'd want to diff attachment 426813 [details] [diff] [review] to bug 530952 with the previous patch.

Comment 3

[Jason Duell]

Footgun remains, but we've worked around it in existing uses in necko at least.

Comment 4

[Jason Duell]

To clarify: this bug fixes "missing" logging that happens when logging is turned off (like in release builds) but certain files try to set PR_FORCE_LOGGING (so they log anyway, even in releases).  It affects files on a per .cpp basis, which is why I centralized the hack that ensures we don't hit the bug (but for HTTP only: there's still lots of other uses of LOG in the tree that might start getting hit as we add #include <anything that includes e10s code.h>).

The real fix here is to rename LOG in the whole tree.