Strange Error: Reentrancy error: some client,attempted to display a message to the console while in a console,listener

classic Classic list List threaded Threaded
1 message Options
Reply | Threaded
Open this post in threaded view
|

Strange Error: Reentrancy error: some client,attempted to display a message to the console while in a console,listener

ISHIKAWA,chiaki
Hi,

I am not sure where to ask and so ask three mailing lists.

First off, TB 38.0.1 after many months of waiting  solved many outstanding
issues,
Great.
I hope we can correct many remaining issues in the months ahead.

I am testing full debug build of C-C TB locally.
This is done by running
|make xpcshell-tests| to run xpcshell unit tests.

I have noticed a few new errors in the last week or so after the code
has been refreshed.

These errors/warnings are new additions and I am trying to eliminate them.

A case in point. A strange error I have never seen before.

PROCESS | 14289 | [14289] WARNING: Reentrancy error: some client
attempted to display a message to the console while in a console
listener. The following message was discarded: "[JavaScript Error:
"TypeError: do_print is not a function" {file:
"/NREF-COMM-CENTRAL/comm-central/mozilla/testing/xpcshell/head.js" line:
130}]": file
/NREF-COMM-CENTRAL/comm-central/mozilla/xpcom/base/nsConsoleService.cpp,
line 198


I looked at nsConsoleService.cpp:
comm-central/mozilla/xpcom/base/nsConsoleService.cpp, line 198


193   if (NS_IsMainThread() && mDeliveringMessage) {
194     nsCString msg;
195     aMessage->ToString(msg);
196     NS_WARNING(nsPrintfCString("Reentrancy error: some client attempted "
197       "to display a message to the console while in a console listener. "
198       "The following message was discarded: \"%s\"", msg.get()).get());
199     return NS_ERROR_FAILURE;
200   }

My understanding: It looks that when a thread tries to print
something to the console while it is in a console listener, the
code, in this case, C-C TB suppresses/discards the new message because
such printing may lead to an infinite recursion as in this case.

Basically, here a warning is going to be printed by the routine that
was invoked, but then since |do_print| is not deemed a function in
JS-side of execution, and the thread would have called the display
routine again, and during new invocation, there probably this warning
about missing function
definition of |do_print| is regenerated, ... ad infinitum. (This is a
possibility and the code tries to avoid invoking output to the console
recursively.)


Now, this warning about suppressing/discarding error message is only
printed for DEBUG BUILD (|NS_WARNING| is used).

I think that is why not many people seem to have noticed this issue.

I am afraid this is a serious issue since a proper error message about
printing mechanism is getting lost.

So anyway, then I checked head.js. That is where mysterious errors are produced.

comm-central/ mozilla/ testing/ xpcshell/ head.js

I found the situation strange because |do_print| is declared as a
function at the top level if I am not mistaken.

Maybe the error is generated before |do_print()| is defined?


621 /**
622  * Prints a message to the output log.
623  */
624 function do_print(msg, data) {
625   msg = _wrap_with_quotes_if_necessary(msg);
626   data = data ? data : null;
627   _testLogger.info(msg, data);
628 }

And it was referenced in |observe|

129     observe : function (msg) {
130       do_print("CONSOLE_MESSAGE: (" + levelNames[msg.logLevel] + ")
" + msg.toString());
131     }


Funny, thought I. This is because |do_print| ought to be visible to
|observe| (*IIF* it has been defined at runtime before |observe| is called.)
I moved the definition of |do_print| to an earlier position, but
It did not seem to make any difference.

But I thought, OK, here is a listener, and maybe the runtime
context/closure/whatever under which |observe| may operate is not
quite the same as that of the definition time, and I copied the
|do_print| definition to |observe| body so that it *IS* always visible.

This was done by adding the following inside|observe| body just before
|do_print| is called.

      let do_print = function (msg, data) {
        msg = _wrap_with_quotes_if_necessary(msg);
        data = data ? data : null;
        _testLogger.info(msg, data);
      }

Of course, this shut up the warning/error about |do_print|.
But then I have complaints about |_wrap_with_quotes_if_necessary| and
|_testLogger| naturally.

When I copied the definition of other functions such as
|_wrap_with_quotes_if_necessary| and |_testLogger|, using "id =
function (arg) {...}" construct one by one as the error message
suggests |observe| is missing, eventually I could eliminate all the
warnings except for one about |Components|

PROCESS | 3996 | JavaScript error:
/NREF-COMM-CENTRAL/comm-central/mozilla/testing/xpcshell/head.js, line
159: TypeError: Components is undefined

At this point, finally, I said, this IS strange (!)
|Components| ought to be visible to all JS code (?!)
Or isn't it implicit and the file needs an import or something?
Or am I missing something?
Or maybe now head.js is invoked in an incorrect manner by the test
framework?

Since the errors are rather new, I checked the log.
I noticed this "head.js" have a four patches applied in the last two months, and
one of them was as follows, but it was backed out. But the name suggests a
possible
relation to the weired behavior and error I see.

Bug 996652 - Scope the private symbols of head.js (edit)

Any suggestions?

TIA

CI

PS: I think you need a full debug version to observe this strange error, but
not seeing it does not mean TB is A OK. Something weired is happening under
the hood and we are simply not told about it in non-debug build!


_______________________________________________
dev-tech-js-engine mailing list
[hidden email]
https://lists.mozilla.org/listinfo/dev-tech-js-engine