Unable to debug GWT in firefox

[keinhaar]

• GWT version: 2.10.0, 2.8.1
• Browser (with version): Firefox 102.5.0.esr
• Operating System: Windows and Debian

---

Description

It is impossible to debug a GWT Application with Firefox, because Firefox throws lots of Exceptions on any MouseEvent after a breakpoint was hit, and thread was resumed.
The Error Messages are:
Uncaught Error: java.lang.AssertionError: Negative entryDepth value at exit -1

Steps to reproduce

1. Create a minimal GWT App. The Sample App created by the Eclipse Wizard is good.
2. Load the App in Firefox, and set a breakpoint in the onClick method.
3. Click the send Button
4. Resume Execution. Firefox will halt on debugger statements. Resume again...
5. Move mouse. Exceptions will be in the console.
6. Click send Button again. nothing will happen.

   @Override
   public void onModuleLoad()
   {
      final Button sendButton = new Button("Send");
      RootPanel.get("sendButtonContainer").add(sendButton);
      sendButton.addClickHandler(new ClickHandler()
      {
         @Override
         public void onClick(ClickEvent event)
         {
            GWT.log("TEST");
         }
      });
   }

Known workarounds

None.
Edge and Chromium don't have the Problem.

[niloc132]

Does this break with any other FF edition than the ESR? Is there any chance that a plugin/extension could be affecting this? Any other prior exceptions in your logs before this is hit?

The Impl.java class has no ff vs chrome implementation specifics, and is mostly driven through this code, which is typically called from JS using $entry() (such as the event handler for your button in the example):

gwt/user/src/com/google/gwt/core/client/impl/Impl.java

Lines 332 to 368 in 18c5d99

	/**
	* Implements {@link #entry(JavaScriptObject)}.
	*/
	private static Object entry0(Object jsFunction, Object thisObj, Object args) throws Throwable {
	boolean initialEntry = enter();
	try {
	/*
	* Always invoke the UCE if we have one so that the exception never
	* percolates up to the browser's event loop, even in a reentrant
	* situation.
	*/
	if (GWT.getUncaughtExceptionHandler() != null) {
	/*
	* This try block is guarded by the if statement so that we don't molest
	* the exception object traveling up the stack unless we're capable of
	* doing something useful with it.
	*/
	try {
	return apply(jsFunction, thisObj, args);
	} catch (Throwable t) {
	reportUncaughtException(t);
	return undefined();
	}
	} else {
	// Can't handle any exceptions, let them percolate normally
	return apply(jsFunction, thisObj, args);
	}
	/*
	* DO NOT ADD catch(Throwable t) here, it would always wrap the thrown
	* value. Instead, entry() has a general catch-all block.
	*/
	} finally {
	exit(initialEntry);
	}
	}

First enter() is called, which tests that value, then increments it before running any code that should be executed before the invoked java (such as your event handler). Before this, the entryDepth is assumed to be 0 or positive, and after this, it will be positive, since it was incremented.

gwt/user/src/com/google/gwt/core/client/impl/Impl.java

Lines 313 to 330 in 18c5d99

	private static boolean enter() {
	assert entryDepth >= 0 : "Negative entryDepth value at entry " + entryDepth;
	if (GWT.isScript() && entryDepth != 0) {
	double now = Duration.currentTimeMillis();
	if (now - watchdogEntryDepthLastScheduled > WATCHDOG_ENTRY_DEPTH_CHECK_INTERVAL_MS) {
	watchdogEntryDepthLastScheduled = now;
	watchdogEntryDepthTimerId = watchdogEntryDepthSchedule();
	}
	}
	// We want to disable some actions in the reentrant case
	if (entryDepth++ == 0) {
	SchedulerImpl.INSTANCE.flushEntryCommands();
	return true;
	}
	return false;
	}

Then, all the java runs, and finally exit() is called at the end of entry0(). This might run any finally commands, then will decrement entryDepth (bringing it back down to either 0 or some other positive value), and then return control to the calling JS.

gwt/user/src/com/google/gwt/core/client/impl/Impl.java

Lines 373 to 388 in 18c5d99

	private static void exit(boolean initialEntry) {
	if (initialEntry) {
	SchedulerImpl.INSTANCE.flushFinallyCommands();
	}
	// Decrement after we call flush
	entryDepth--;
	assert entryDepth >= 0 : "Negative entryDepth value at exit " + entryDepth;
	if (initialEntry) {
	assert entryDepth == 0 : "Depth not 0" + entryDepth;
	if (GWT.isScript() && watchdogEntryDepthTimerId != -1) {
	watchdogEntryDepthCancel(watchdogEntryDepthTimerId);
	watchdogEntryDepthTimerId = -1;
	}
	}
	}

Somehow it seems that your code is calling exit() without calling enter, or something else that is modifying entryDepth in a way that isn't allowed or expected.

After that, watchdogEntryDepthRun() should be run which seems to zero out the entryDepth, though I'm not at this time why, since the try/finally above should manage that.

The only way this could get out of balance that I can see (aside from some code calling Impl methods where it shouldn't) is if SchedulerImpl.INSTANCE.flushEntryCommands() were to throw so that entryDepth couldn't be decremented - but that would produce the opposite effect from what you are seeing.

[keinhaar]

i've seen this Impl code, but did not understand it completly.
anyway, i stripped down the example app to the onModuleLoad() you see above. just a standard gwt button with clickhandler. nothing more. no javascript code.
the application works just fine until i set a breakpoint in the firefox devtools.
i will try tomorrow with a fresh, current firefox installation without any plugins.

[keinhaar]

Tried with the current Firefox Version 107. No Plugins installed. The same error still occurs.
It's repeated with any mouse move. 100+ per second. Unfortunately the Stacktrace does not say very much.

Uncaught Error: java.lang.AssertionError: Negative entryDepth value at entry -1
    KA_g$ aa-0.js:3854
    VA_g$ aa-0.js:3917
    EA_g$ aa-0.js:3770
    Nsd_g$ aa-0.js:16889
    Xsd_g$ aa-0.js:16943
    Vjc_g$ aa-0.js:11726
    EJ_g$ aa-0.js:4856
    GJ_g$ aa-0.js:4892
    FJ_g$/< aa-0.js:4876
    EventListener.handleEvent*MGc_g$/< aa-0.js:13879
    vHc_g$ aa-0.js:14078
    MGc_g$ aa-0.js:13878
    YGc_g$ aa-0.js:14015
    rGc_g$ aa-0.js:13701
    SGc_g$ aa-0.js:13923
    $Gc_g$ aa-0.js:14035
    PBc_g$ aa-0.js:12864
    GOc_g$ aa-0.js:15051
    mPc_g$ aa-0.js:15300
    POc_g$ aa-0.js:15120
    RQc_g$ aa-0.js:15808
    w_g$ aa-0.js:3122
    Tlc_g$ aa-0.js:12201
    initializeModules_0_g$ aa-0.js:28
    DJ_g$ aa-0.js:4840
    GJ_g$ aa-0.js:4910
    FJ_g$/< aa-0.js:4876
    klc_g$ aa-0.js:41
     aa-0.js:25715

[niloc132]

I attempted to reproduce this on linux+ff107 and failed. I also tried a windows 10 VM, running firefox 107, and could not reproduce there either.

Here's the git repo for my project, can you confirm? It was generated from the webapp-modular archetype for the ltgt maven plugin. There is a readme file to show how to run this.
https://github.com/niloc132/gwt-bug-9787

I can see from your stack trace that you are testing in SDM - I've uploaded the generated SDM output to a website to make it easier to test in other browsers. I have not yet found a browser that errors instead of behaving as I would expect. Note that the JS is only generated for user.agent=gecko1_8, as this was copied from a running SDM instance, which could in theory mean that it won't work from some other browsers, but in practice it shouldn't matter (and hasnt failed in my testing). No sourcemaps are included.
https://niloc132.github.io/gwt-bug-9787/

Can you confirm that this hosted build behaves for you, and that building locally from the linked project also succeeds for you? If you can reproduce on the website, I'd like to know more about your FF installation (and see if we can find anyone else who can confirm this). If not, if you can reproduce this from building locally, it sounds like you could possibly have a bad set of GWT jars or some other setup problem locally. If you cannot reproduce with either, I'd like to see all details of the sample project you made.

[keinhaar]

I can reproduce the error with both, the website and the local build. Stacktrace looks different, but the Behavior is the same.
Your code looks nearly exactly like my code (i build it with the eclipse gwt plugin)

Maybe my English is to bad, and/or i did not explain it correctly.
The log messages are on the console, and they are counted for each click. Everything works fine until you set a breakpoint.
For the test page on github.io open the firefox developer tools and set a breakpoint on line 16123 in app-0.js. That line should look like ZA_g$('TEST'), which represents the line 17 of the Java Source App.java which is GWT.log("TEST");
Now, click on the send button, and firefox will stop on the breakpoint on line 16123. Until here everything works as expected.
now resume execution. firefox will stop immediately again on line 4484 on a "debugger;" statement. If you move around the mouse over the application you will now see a quickly growing number of error messages, and the "TEST" String will no longer be logged until you reload the Application.

[niloc132]

Ah! I'm very sorry, you were clear, and I misunderstood. I can reproduce it now, and will get back to you when I know more.

[keinhaar]

Maybe this is caused, because there are 2 threads?
I noticed that one thread must be running, because the error messages in the console are repeated even if the debugger is on hold on the debugger-statement. If you do the same with a normal html page with included script, the whole page is blocked and no events are processed any more.
But i don't know why this would be only a problem if debugging.

[niloc132]

JS only has a single thread per "process" - web/shared/service workers can operate on their own thread, but objects aren't shared, they can't read and write each others variables and fields (only special "shared array buffers" can directly be shared, other "Transferable" types have "move" semantics instead of "copy").

I still don't know what's going on here, but I do know a few things:

• GWT doesn't seem to have added this, though FF might have gotten pickier - GWT 2.8 had this bug according to your report, and I can reproduce this in many cases now, so firefox changed something...
• User and com.google.gwt.user.client.ui.Button aren't required to cause this, but $entry or something like it is, either because of the code itself or because it wraps every call, and that try/finally with bookkeeping is necessary to cause this. I have a sample where I can use elemental2 to create the button, but as jsinterop doesn't use $entry, I had to artificially introduce the $entry call to cause the bug.
• An onclick handler on the button isn't sufficient, there seems to also need to be a mouseover handler - this is what was causing the error to happen so many times. My speculation is that this, combined with some state management on the way in/out of each event, is what is breaking when FF's debugger is running. However...
• This only happens with SDM. If you turn on assertions in prod mode, compile to PRETTY, turn on incremental, none of those allow the bug to happen in prod mode. On the other hand, if you turn off incremental, and try different styles in SDM, the bug still happens (note that SDM is always in draft mode, and always has assertions enabled). Copying the output from SDM to a plain server (like github.io, above) also lets it still happen. This suggests that the bug might be specific to GWT.isProd() returning false? If so, it should be possible to tweak the compiler to build "prod" code where isProd is false, and possibly prune down the output to just the bug by letting the compiler optimize more heavily.

I'll update when I have any actual progress to report.

[tbroyer]

Could it somehow be due to GWT code running inside an iframe? In any case, if there are errors while execution is stopped on a breakpoint, that's a bug in Firefox. The different behavior between SDM and prod mode would be weird though.

[niloc132]

SDM unfortunately only functions with CrossSiteIframeLinker or DirectInstallLinker, so I can't test the iframe theory easily without being able to repro the bug with non-SDM generated output. It doesn't seem likely though since prod JS is also via iframe, and all of my tests are using launcherDir from the same origin, so that's the same SDM or prod.

I don't believe it is actually error'ing while paused, but it might be continuing to execute something which gets the entry depth out of whack.

[keinhaar]

I can confirm that this does not happen in production mode. So it seems to be something in GWT and Super Dev Mode.
I've modified my sources a little bit by adding emulated stack mode and logging, and replaced GWT.log by Logger.getLogger("123").severe("TEST)

  <set-property name="compiler.stackMode"
     value="emulated" />
  <set-configuration-property name="compiler.emulatedStack.recordLineNumbers"
     value="true"/>
  <set-configuration-property name="compiler.emulatedStack.recordFileNames"
     value="true"/>  
  <inherits name="com.google.gwt.logging.Logging" />

The result is still the same in SDM, but the stacktrace changed.

Fri Dec 02 09:57:22 GMT+100 2022 com.google.gwt.logging.client.LogConfiguration
SEVERE: Negative entryDepth value at entry -1
java.lang.AssertionError: Negative entryDepth value at entry -1
	at Unknown.AA_g$(Throwable.java:75)
	at Unknown.avd_g$(Error.java:30)
	at Unknown.kvd_g$(AssertionError.java:51)
	at Unknown.AJ_g$(Impl.java:314)
	at Unknown.CJ_g$(Impl.java:336)
	at Unknown.anonymous(Impl.java:78)
	at Unknown.AJ_g$(Impl.java:314)
	at Unknown.CJ_g$(Impl.java:336)
	at Unknown.anonymous(Impl.java:78)
	at Unknown.AJ_g$(Impl.java:314)
	at Unknown.CJ_g$(Impl.java:336)
	at Unknown.anonymous(Impl.java:78)
	at Unknown.AJ_g$(Impl.java:314)
	at Unknown.CJ_g$(Impl.java:336)
	at Unknown.anonymous(Impl.java:78)
	at Unknown.AJ_g$(Impl.java:314)
	at Unknown.CJ_g$(Impl.java:336)
	at Unknown.anonymous(Impl.java:78)
	at Unknown.AJ_g$(Impl.java:314)
	at Unknown.CJ_g$(Impl.java:336)
	at Unknown.anonymous(Impl.java:78)
	at Unknown.AJ_g$(Impl.java:314)
	at Unknown.CJ_g$(Impl.java:336)
	at Unknown.anonymous(Impl.java:78)
	at Unknown.DJ_g$(Impl.java:380)
	at Unknown.CJ_g$(Impl.java:366)
	at Unknown.anonymous(Impl.java:78)
Uncaught Error: java.lang.AssertionError: Negative entryDepth value at entry -1
    GA_g$ aa-0.js:6185
    RA_g$ aa-0.js:6286
    AA_g$ aa-0.js:6068
    avd_g$ aa-0.js:28301
    kvd_g$ aa-0.js:28385
    Rjc_g$ aa-0.js:18750
    AJ_g$ aa-0.js:7809
    CJ_g$ aa-0.js:7859
    BJ_g$/< aa-0.js:7836
    AJ_g$ aa-0.js:7808
    CJ_g$ aa-0.js:7859
    BJ_g$/< aa-0.js:7836
    EventListener.handleEvent*SJc_g$/< aa-0.js:23653
    BKc_g$ aa-0.js:23920
    SJc_g$ aa-0.js:23650
    cKc_g$ aa-0.js:23825
    xJc_g$ aa-0.js:23390
    YJc_g$ aa-0.js:23714
    eKc_g$ aa-0.js:23853
    VEc_g$ aa-0.js:21820
    MRc_g$ aa-0.js:25486
    sSc_g$ aa-0.js:25849
    VRc_g$ aa-0.js:25586
    XTc_g$ aa-0.js:26602
    w_g$ aa-0.js:5094
    Plc_g$ aa-0.js:19535
    initializeModules_0_g$ aa-0.js:43
    zJ_g$ aa-0.js:7786
    CJ_g$ aa-0.js:7878
    BJ_g$/< aa-0.js:7836
    glc_g$ aa-0.js:57
     aa-0.js:43974
Caused by: null

I noticed, that the emulated Stacktrace gets longer with every mousemove. Looks like a loop, or emulated Stacktrace not beeing cleaned up?
If there's anything else, that i can Test - just ask.

[niloc132]

I've got a fairly minimal plain html/js test case that demonstrates this - as @tbroyer suspected, it is related to running in an iframe. So far, the requirements are

• JS that runs in an iframe,
• but calls setTimeout on the top window
• where the timeout can elapse while in the iframe's JS

In these circumstances, the timer can elapse and run from within the current stack, instead of waiting until the current event finishes and returns.

With a setup like this, no dom events need elapse, only timeouts and breakpoints. Here's a smallish sample that will cause this, still with the structure of the GWT Impl logic (note that it is the watchdog timer in Impl.java that is ultimately responsible for this bug):

<!doctype html>
<html>
<head>
</head>
<body>
<script>
    if (window.top === window) {
        var ifr = document.createElement('iframe');
        ifr.src = window.location.href;
        document.body.append(ifr);
    } else {
        var $wnd = window.top;

        var depth = 0;
        function entryImpl(func, that, args) {
            var initial = enter();
            try {
                func.apply(that, args);
            } finally {
                exit(initial);
            }
        }

        function entry(func) {
            return function () {
                entryImpl(func, this, arguments);
            }
        }

        function enter() {
            if (depth < 0) {
                debugger;
                throw "fail, depth < 0: " + depth;
            }
            if (depth++ === 0) {
                return true;
            }
            $wnd.setTimeout(resetEntryDepth, 10);
            return false;
        }

        function exit(initial) {
            --depth;
            if (initial) {
                if (depth !== 0) {
                    debugger;
                    throw "Depth not 0 at outermost exit: " + depth;
                }
            } else {
                if (depth < 1) {
                    debugger;
                    throw "Depth is too low: " + depth;
                }
            }
        }
        function resetEntryDepth() {
            if (depth !== 0) {
                depth = 0;
            }
        }

        function timer() {

            $wnd.setTimeout(entry(function() {
                timer();

                $wnd.console.log("before breakpoint " + depth);
                debugger;
                $wnd.console.log("after breakpoint " + depth);
            }), 1000);
        }
        timer();
    }
</script>
</body>
</html>

I'll tidy this up a bit more and submit a bug to Firefox.

For mitigation in GWT, you can copy the Impl.java class and change the watchdogEntryDepthSchedule call to use setTImeout instead of $wnd.setTimeout:

diff --git a/user/src/com/google/gwt/core/client/impl/Impl.java b/user/src/com/google/gwt/core/client/impl/Impl.java
index 879a3eb4b7..29c8cbeb2f 100644
--- a/user/src/com/google/gwt/core/client/impl/Impl.java
+++ b/user/src/com/google/gwt/core/client/impl/Impl.java
@@ -393,7 +393,7 @@ public final class Impl {
   }-*/;
 
   private static native void watchdogEntryDepthCancel(int timerId) /*-{
-    $wnd.clearTimeout(timerId);
+    clearTimeout(timerId);
   }-*/;
 
   private static void watchdogEntryDepthRun() {
@@ -406,6 +406,6 @@ public final class Impl {
   }
 
   private static native int watchdogEntryDepthSchedule() /*-{
-    return $wnd.setTimeout(@Impl::watchdogEntryDepthRun(), 10);
+    return setTimeout(@Impl::watchdogEntryDepthRun(), 10);
   }-*/;
 }

I don't think this is a reasonable fix to make to GWT itself, since there is nothing that says a browser couldnt have the same bug on the iframe's setTimeout etc, but it does look like we could remove the watchdog entirely, or only conditionally enable it.

We should also consider adding a -disableAssertions flag to CodeServer and DevMode, to make it possible to temporarily ignore these.

[keinhaar]

Thanks a lot for your investigation!!!
I managed to make this work without modifying gwt itself. Instead i've super sourced the Impl class. This is OK as a workaround until a patch is available.
Works for me with plain Firefox dev tools, and also with my enhanced SDBG version, where i currently add firefox support.
Would be nice, if this makes it's way into standard gwt. maybe as option?