Detecting threading problems faster

John Hendrikx john.hendrikx at gmail.com
Fri Aug 9 19:15:05 UTC 2024


Feel free, it is also somewhere on my github.  I'm not entirely 
confident it works for all cases, but it can be tweaked. Here's the 
missing piece you may need:

/**

* Tracks time spent (in milliseconds) between calls of {@link 
#enterNested()}and {@link #exitNested()}

* excluding time spent in deeper nested levels. This allows to find the 
time spent at a certain

* nesting level without including time spent at any deeper nestings.

*/

publicclassNestedTimeTracker{

privatefinalDeque<Long> startTimes= newArrayDeque<>();

privatefinalDeque<Long> cumulativeDurations= newArrayDeque<>();

{

cumulativeDurations.add(0L); // Add root level, always present (this is 
never used, the entry is there to avoid having to check if we're at root 
level)

}

publicintgetCurrentLevel() {

returnstartTimes.size();

}

publicvoidenterNested() {

enterNested(System.currentTimeMillis());

}

publicvoidenterNested(longcurrentTimeMillis) {

startTimes.addLast(currentTimeMillis);

cumulativeDurations.add(0L);

}

publicvoidexitNested() {

exitNested(System.currentTimeMillis());

}

publiclongexitNested(longcurrentTimeMillis) {

longstartTime = startTimes.removeLast();

longtimeSpentInNested = cumulativeDurations.removeLast(); // nested 
time, not part of this level

longtotalTime = currentTimeMillis - startTime; // total time, including 
nested levels

longtimeSpentAtThisLevel = totalTime - timeSpentInNested;

// Consolidate total time spent in next higher level:

cumulativeDurations.addLast(cumulativeDurations.removeLast() + totalTime);

returntimeSpentAtThisLevel;

}

}

--John

On 08/08/2024 12:47, Thiago Milczarek Sayão wrote:
> Nice! I will steal it if you don't mind.
>
> Em qua., 7 de ago. de 2024 às 15:55, John Hendrikx 
> <john.hendrikx at gmail.com> escreveu:
>
>     For detecting long running tasks on the FX thread, there are some
>     other options which you can do as a user (but perhaps we can
>     support it directly within FX).  I use this kind of code to detect
>     long running things on the FX thread:
>
>     /**
>
>     * Adds a slow event warning whenever an event takes more than 10
>     msto process. Note
>
>     * that time spent in nested event loops cannot be properly taken
>     into account as time
>
>     * spent in nested event loops will be part of the event that
>     triggered it giving false
>
>     * positives. In order for this time to be accurately reflected,
>     the methods to enter
>
>     * a nested event loop in this class should be used instead of the
>     ones in {@link Platform}.
>
>     *
>
>     * @paramscene a Scene to which to add the slow event warning
>     detection, cannot be null
>
>     */
>
>     publicstaticvoidaddSlowEventWarning(Scene scene) {
>
>     finalEventDispatcher eventDispatcher = scene.getEventDispatcher();
>
>     scene.setEventDispatcher(newEventDispatcher() {
>
>     privateScheduledFuture<StackTraceElement[]> future;
>
>     @Override
>
>     publicEvent dispatchEvent(Event event, EventDispatchChain tail) {
>
>     if(future!= null) {
>
>     future.cancel(false);
>
>     }
>
>     longstartTime = System.currentTimeMillis();
>
>     TIME_TRACKER.enterNested(startTime); // nesting can happen in two
>     ways, an event triggering another event, or when a nested event
>     loop is entered
>
>     Event returnedEvent = eventDispatcher.dispatchEvent(event, tail);
>
>     longendTime = System.currentTimeMillis();
>
>     longtimeSpentInNested = TIME_TRACKER.exitNested(endTime);
>
>     if(timeSpentInNested > 10) {
>
>     longtotal = endTime - startTime;
>
>     LOGGER.warning("Slow Event (self/total: "+ timeSpentInNested +
>     "/"+ total + " ms @ level "+ TIME_TRACKER.getCurrentLevel() + "):
>     "+ event);
>
>     }
>
>     returnreturnedEvent;
>
>     }
>
>     });
>
>     }
>
>     --John
>
>     On 05/08/2024 17:17, Thiago Milczarek Sayão wrote:
>>     Hi,
>>
>>     Interesting idea. We have this problem specially when Junior
>>     developers touch the code.
>>
>>     The other way around would be nice too - if some I/O task
>>     executes on the FX thread.
>>
>>     This can make the OS think the application hanged and offer to
>>     kill it, since it won't respond to "pings". And I/O tasks
>>     processing time may vary between installations. Also causes
>>     "white screens" since it blocks painting.
>>
>>     -- Thiago.
>>
>>     Em seg., 5 de ago. de 2024 às 11:59, Kevin Rushforth
>>     <kevin.rushforth at oracle.com> escreveu:
>>
>>>         Wouldn't it be better to implement this check in assert to
>>>         avoid any impact in production?
>>
>>         No. Using an assert in a case like this is an anti-pattern. A
>>         call to assert in a library such as JavaFX is only
>>         appropriate for checking an invariant in internal logic. If
>>         we are going to go down this route of doing a thread check
>>         when mutating properties of "live" nodes, we will throw the
>>         same IllegalStateException that is currently thrown by some
>>         methods on Stage and Scene.
>>
>>         As for the proposal itself, adding this check is an
>>         interesting idea. We considered doing this back in the JDK 7
>>         (JavaFX 2) time frame, but decided not to pursue it then. I
>>         think the idea is worth further discussion. I would limit any
>>         thread checking to setting the property. It would be too
>>         restrictive (and largely unnecessary) to prevent reading a
>>         property from the application thread.
>>
>>         The things to consider would be:
>>
>>         1. What is the performance hit of doing this check on the
>>         setting of every property?
>>         2. What is the effect on bound properties?
>>         3. How intrusive is it in the code?
>>         4. Should we add a property to enable / disable the thread
>>         check, possibly a three- or four-valued property
>>         (allow|warn|debug?|deny), as was recently done in JEP 471 for
>>         sun.misc.Unsafe memory access methods. If so, what should the
>>         default be?
>>
>>         My quick take is that if this can be done in a minimally
>>         intrusive manner with low overhead, we should consider
>>         pursing this. As for 4, my preference would be to add a
>>         three- or four-valued system property to control the check,
>>         with "warn" as the default initially, changing the default to
>>         "disallow" in a subsequent version. This would, of course,
>>         require a lot of testing.
>>
>>         -- Kevin
>>
>>
>>         On 8/4/2024 8:40 PM, quizynox wrote:
>>>         Hello,
>>>
>>>         Wouldn't it be better to implement this check in assert to
>>>         avoid any impact in production?
>>>
>>>         пн, 5 авг. 2024 г. в 03:30, John Hendrikx
>>>         <john.hendrikx at gmail.com>:
>>>
>>>             Hi list,
>>>
>>>             I know of quite some bugs and users that have been
>>>             bitten by the
>>>             threading model used by JavaFX.  Basically, anything
>>>             directly or
>>>             indirectly linked to an active Scene must be accessed on
>>>             the FX thread.
>>>             However, as FX also allows manipulating nodes and
>>>             properties before
>>>             they're displayed, there can be no "hard" check
>>>             everywhere to ensure we
>>>             are on the FX thread (specifically, in properties).
>>>
>>>             Now, I think this situation is annoying, as a simple
>>>             mistake where a
>>>             Platform.runLater wrapper was forgotten usually results
>>>             in programs
>>>             operating mostly flawlessly, but then fail in mysterious
>>>             and random and
>>>             hard to reproduce ways.  The blame is often put on FX as
>>>             the resulting
>>>             exceptions will almost never show the user code which
>>>             was the actual
>>>             culprit.  It can result in FX being perceived as
>>>             unstable or buggy.
>>>
>>>             So I've been thinking if there isn't something we can do
>>>             to detect these
>>>             bugs originating from user code much earlier, similar to
>>>             the
>>>             `ConcurrentModificationException` the collection classes
>>>             do when
>>>             accessed in nested or concurrent contexts.
>>>
>>>             I think it may be possible to have properties check
>>>             whether they're part
>>>             of an active scene without too much of an performance
>>>             impact, possibly
>>>             even behind a switch. It would work like this:
>>>
>>>             Properties involved with Nodes will have an associated
>>>             bean instance
>>>             (`getBean`).  This is an object, but we could check here
>>>             if this
>>>             instance implements an interface:
>>>
>>>                   if (getBean() instanceof MayBePartOfSceneGraph x) {
>>>                         if (x.isPartOfActiveScene() &&
>>>             !isOnFxThread()) {
>>>                              throw new
>>>             IllegalStateException("Property must only be
>>>             used from the FX Application Thread");
>>>                         }
>>>                   }
>>>
>>>             This check could be done on every set of the property,
>>>             and potentially
>>>             on every get as well.  It should be relatively cheap,
>>>             but will expose
>>>             problematic code patterns at a much earlier stage. 
>>>             There's a chance
>>>             that this will "break" some programs that seemed to be
>>>             behaving
>>>             correctly as well, so we may want to put it behind a
>>>             switch until such
>>>             programs (or libraries) can be fixed.
>>>
>>>             What do you all think?
>>>
>>>             --John
>>>
>>>             (*) Names of methods/interfaces are only used for
>>>             illustration purposes,
>>>             we can think of good names if this moves forward.
>>>
>>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/openjfx-dev/attachments/20240809/d2823815/attachment-0001.htm>


More information about the openjfx-dev mailing list