APPSERV-114 Addresses possible sources of Race Conditions in InvocationManager #4602

jbee · 2020-04-02T09:28:30Z

Background

Running FT TCK strongly suggested that a race condition in or around the InvocationManger leads to inconsistent context when trying to derive the current application like shown below:

 ComponentInvocation current = invocationManager.getCurrentInvocation();
 if (current == null) {
     return invocationManager.peekAppEnvironment().getName();
 }
 String appName = current.getAppName();
 if (appName == null) {
     appName = current.getModuleName();
 }
 if (appName == null) {
     appName = current.getComponentId();
 }
return appName;

The issue observed was that different application names were returned in a non deterministic manner for the actual same application processing tests.

Summary

The most likely cause is related to the frames that push and pop the stack which is peeked by getCurrentInvocation(). But it could also be related to application environment stack peeked by peekAppEnvironment() for case that not ComponentInvocation was on the stack.
The issue can either be within the implementation of the InvocationMangerImpl but also on the outside as the ComponentInvocation is essentially managed from the outside by calling preInvoke and postInvoke.

Changes:

removes the unnecessary generic of the InvocationArray / InvocationFrames (renamed) inner class
replaces use of Stack with ConcurrentLinkedDeque (synchronized vs. CAS based synchronisation)
replaces ArrayList as bases of frames stack with ConcurrentLinkedDeque (as this is only used via thread local non synchronised should not be an issue but to be sure and to provide better readability of the base class was changed)
replaces ComponentInvocationHandler[] handlers with a single ComponentInvocationHandler that is initialised with ListComponentInvocationHandler in case multiple handlers are actually needed. The underlying List uses ArrayList as it is read-only after being initialised. This allows to simplify the rest of the implementation that only has to assume a single handler.
uses ListComponentInvocationHandler to manage RegisteredComponentInvocationHandler. In this case the underlying List uses a CopyOnWriteArrayList as multiple threads might register handlers concurrently.
replaces the Map for RegisteredComponentInvocationHandler (that are per type) with a thread-safe ConcurrentHashMap as multiple threads can register handlers concurrently.
adds try-finally to preInvoke to make sure that any exception thrown by handlers does not prevent adding of the invocation instance (I'd say this is the best candidate for the observed issue)

Testing

The implementation of InvocationMangerImpl got covered with unit tests to a coverage > 95%.
This mostly intends to make sure the changes in the implementation do not cause unexpected behaviour, in particular throwing exceptions when it should not. The tests do include a few tests that include multiple threads to verify the thread parent-child stack inheritance behaviour, not to show that the class is thread-safe. To allow better reasoning about thread safety the implementation was cleaned and simplified so the use of collection becomes more clear.

Testing Performed

The unit tests were added mostly to make sure changes did not introduce new bugs like NPEs and alike and that the implementation does behave as expected from reading the code.

In addition I ran the FT TCK as that had shown issues before and since it deploying lots of applications.

…dds tests for invocation frame logic

jbee · 2020-04-02T09:32:00Z

...ules/microprofile/metrics/src/main/java/fish/payara/microprofile/metrics/MetricsService.java

@@ -418,15 +419,16 @@ private void deregisterApplication(String applicationName) {
    public String getApplicationName() {
        InvocationManager invocationManager = Globals.getDefaultBaseServiceLocator()
                .getService(InvocationManager.class);
-        if (invocationManager.getCurrentInvocation() == null) {


NB: while the use of thread local should ensure that multiple calls to getCurrentInvocation() should return the same instance it is better to not take changes and do it once. Also improves readability.

jbee · 2020-04-02T09:48:30Z

...s/common/glassfish-api/src/main/java/org/glassfish/api/invocation/InvocationManagerImpl.java

-    private final ThreadLocal<Stack<ApplicationEnvironment>> applicationEnvironments = withInitial(Stack<ApplicationEnvironment>::new);
-    private final ThreadLocal<Deque<Method>> webServiceMethods = withInitial(ArrayDeque<Method>::new);
-
-    private Map<ComponentInvocationType, List<RegisteredComponentInvocationHandler>> regCompInvHandlerMap = new HashMap<>();


NB. Using HashMap here is definitely not thread-safe but should be. But is is hard to see how this can cause the observed issues. However, we do talk about multi-threading so everything is possible :D

jbee · 2020-04-02T09:49:30Z

...s/common/glassfish-api/src/main/java/org/glassfish/api/invocation/InvocationManagerImpl.java

-    // don't need to be synchronized because each thread has its own ArrayList.
-    private InheritableThreadLocal<InvocationArray<ComponentInvocation>> frames;
-
-    private final ThreadLocal<Stack<ApplicationEnvironment>> applicationEnvironments = withInitial(Stack<ApplicationEnvironment>::new);


NB. Replacing Stack here is more of a modernisation to avoid sychronized in favour of CAS based synchronisation.

jbee · 2020-04-02T09:53:11Z

...s/common/glassfish-api/src/main/java/org/glassfish/api/invocation/InvocationManagerImpl.java

-        if (invHandlers != null) {
-            for (ComponentInvocationHandler handler : invHandlers) {
-                handler.beforePreInvoke(invocationType, previousInvocation, invocation);
+        try {


NB. Missing try-finally here to make sure the frames.addLast(invocation); will definitely happen is my best guess on what might have caused the issue observed,

jbee · 2020-04-02T10:00:40Z

...s/common/glassfish-api/src/main/java/org/glassfish/api/invocation/InvocationManagerImpl.java


-            if (invHandlers != null) {
-                for (ComponentInvocationHandler handler : invHandlers) {
-                    handler.afterPostInvoke(invocation.getInvocationType(), prevInv, invocation);


NB. You might have noticed that invocation is passed to afterPostInvoke instead of curInv. I believe this is just a inconsistency in the chosen way to express the logic. At this point curInv is (or really should be) invocation. To avoid any future confusion I unified it to use invocation everywhere as it is done in preInvoke and as I think it makes most sense as this is what is passed to the method as "current". It is unfortunate how the API was designed and that it leaves room for inconsistencies like calling postInvoke with a different value then preInvoke. postInvoke really should not have had an argument as the current is that pushed to the stack when invoking preInvoke. Or the API should have made clear that the argument is only passed to postInvoke to verify that the nesting is correct and that it indeed is the current top of the stack.

I think it is worth a warning when this assumption doesn't hold and you actually have a good spot since you already jump over the invocation head.

This might disclose bugs we have around nested transactions or cleanups.

jbee · 2020-04-02T11:01:11Z

jenkins test please

Pandrex247

It's tricky to fully think through all of the ramifications of your changes, but I can't spot any howlers.
I've ran it through MP Rest Client, OpenTracing, Fault Tolerance, and Metrics as these all poke it in various ways (OpenTracing was the one I was most worried about with the trace propagation) and seems to pass all of these!

It also seems to correctly propagate traces from my MicroProfileOnMicro demo app so the changes don't seem to have negatively affected tracing.

pdudits

Overall quite nice readability improvement

pdudits · 2020-04-17T09:07:40Z

...s/common/glassfish-api/src/main/java/org/glassfish/api/invocation/InvocationManagerImpl.java

+    private final ThreadLocal<Deque<ApplicationEnvironment>> appEnvironments = withInitial(ConcurrentLinkedDeque::new);
+    private final ThreadLocal<Deque<Method>> webServiceMethods = withInitial(ConcurrentLinkedDeque::new);


Isn't ArrayDequeue sufficient here, since it is guaranteed there will not be any cross-thread access as it is thread-local?

I'd say so, yes. Given the importance of the manager this was more of a "better safe then sorry" thing to give me peace of mind. Since we both think it is not necessary we might just make this unsynchronized.

pdudits · 2020-04-17T09:49:26Z

...s/common/glassfish-api/src/main/java/org/glassfish/api/invocation/InvocationManagerImpl.java

    }


-    static class InvocationArray<T extends ComponentInvocation> extends ArrayList<T> {
+    static final class InvocationFrames extends ConcurrentLinkedDeque<ComponentInvocation> {


Also here I don't see InvocationFrames being used outside thread locals, so I'd infer it doesn't need additional CAS overhead and an ArrayDequeue is sufficient.

I'm also afraid that extending rather than delegating makes too many public methods available.

I'm also afraid that extending rather than delegating makes too many public methods available.

InvocationFrames is only used privately.

Again, done this for peace of mind. Could go to ArrayDequeue.

pdudits · 2020-04-17T09:52:17Z

...s/common/glassfish-api/src/main/java/org/glassfish/api/invocation/InvocationManagerImpl.java

-            setRegCompInvHandlers.add(handler);
-        }
+        typeHandlers.computeIfAbsent(type,
+                key -> new ListComponentInvocationHandler(new CopyOnWriteArrayList<>())) // OBS! must be thread safe List here


Isn't this thread safety requirement valid for all constructions of ListComponentInvocationHandler? If so, it is better handled in its constructors by copying whatever list is on input into its own list.

No, the allTypesHandler is composed once during construction and never changed so it does not need any form of synchronisation while the handlers per type can change while being used so they need it.

pdudits · 2020-04-17T10:10:48Z

...s/common/glassfish-api/src/main/java/org/glassfish/api/invocation/InvocationManagerImpl.java


-            if (invHandlers != null) {
-                for (ComponentInvocationHandler handler : invHandlers) {
-                    handler.afterPostInvoke(invocation.getInvocationType(), prevInv, invocation);


I think it is worth a warning when this assumption doesn't hold and you actually have a good spot since you already jump over the invocation head.

This might disclose bugs we have around nested transactions or cleanups.

…ds warning in case postInvoke called with an unecpected invocation instance

jbee · 2020-04-20T11:53:06Z

jenkins test please

jbee · 2020-04-20T11:54:45Z

@pdudits Now uses unsynchronised collections within thread locals. Also added the logging you suggested with uncovered 2 issues in the test setup. 🎉

pdudits · 2020-04-21T13:38:26Z

...s/common/glassfish-api/src/main/java/org/glassfish/api/invocation/InvocationManagerImpl.java

+            LOGGER.log(WARNING, "postInvoke not called with top of the invocation stack. Expected {0} but was: {1}",
+                    new Object[] { current, invocation });


Last Nitpick would be, that only EjbInvocation provides reasonable toString(). It would be great to add one into WebComponentInvocation and ComponentInvocation.

Good point, I remember checking it myself but then forgot to do something about it. Too many context switches. Will look into it tomorrow.

…info in log messages

jbee · 2020-04-22T08:45:25Z

jenkins test please

…manager APPSERV-114 Addresses possible sources of Race Conditions in InvocationManager

jbee added 3 commits April 1, 2020 12:05

APPSERV-114 cleanup invocation handlers

4bb7503

APPSERV-114 use of concurrent collections in InvocationManagerImpl; a…

b585421

…dds tests for invocation frame logic

APPSERV-114 adds tests for AppEnvironment and WebServiceMethod stacks

1eca37c

jbee added this to the 5.202 milestone Apr 2, 2020

jbee self-assigned this Apr 2, 2020

jbee commented Apr 2, 2020

View reviewed changes

jbee changed the title ~~APPSERV-114 Addresses possible sources of Race Conditions in InvocationManager~~ APPSERV-141 Addresses possible sources of Race Conditions in InvocationManager Apr 7, 2020

jbee changed the title ~~APPSERV-141 Addresses possible sources of Race Conditions in InvocationManager~~ APPSERV-114 Addresses possible sources of Race Conditions in InvocationManager Apr 7, 2020

Pandrex247 approved these changes Apr 9, 2020

View reviewed changes

pdudits reviewed Apr 17, 2020

View reviewed changes

APPSERV-114 uses unsynchronised collections withoin thread locals; ad…

d569132

…ds warning in case postInvoke called with an unecpected invocation instance

jbee requested review from pdudits and Pandrex247 April 20, 2020 11:54

pdudits approved these changes Apr 21, 2020

View reviewed changes

APPSERV-114 adds toString to ComponentInvocation to provide relevant …

b5bdaa2

…info in log messages

jbee merged commit fbbd633 into payara:master Apr 22, 2020

Pandrex247 pushed a commit to Pandrex247/Payara that referenced this pull request Jun 15, 2020

Merge pull request payara#4602 from jbee/APPSERV-114-race-invocation-…

3a4ec5e

…manager APPSERV-114 Addresses possible sources of Race Conditions in InvocationManager

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

APPSERV-114 Addresses possible sources of Race Conditions in InvocationManager #4602

APPSERV-114 Addresses possible sources of Race Conditions in InvocationManager #4602

jbee commented Apr 2, 2020 •

edited

Loading

jbee Apr 2, 2020

jbee Apr 2, 2020

jbee Apr 2, 2020

jbee Apr 2, 2020

jbee Apr 2, 2020

pdudits Apr 17, 2020

jbee commented Apr 2, 2020

Pandrex247 left a comment

pdudits left a comment

pdudits Apr 17, 2020

jbee Apr 20, 2020

pdudits Apr 17, 2020

jbee Apr 20, 2020

pdudits Apr 17, 2020

jbee Apr 20, 2020

pdudits Apr 17, 2020

jbee commented Apr 20, 2020

jbee commented Apr 20, 2020

pdudits Apr 21, 2020

jbee Apr 21, 2020

jbee commented Apr 22, 2020

		private final ThreadLocal<Deque<ApplicationEnvironment>> appEnvironments = withInitial(ConcurrentLinkedDeque::new);
		private final ThreadLocal<Deque<Method>> webServiceMethods = withInitial(ConcurrentLinkedDeque::new);

		LOGGER.log(WARNING, "postInvoke not called with top of the invocation stack. Expected {0} but was: {1}",
		new Object[] { current, invocation });

APPSERV-114 Addresses possible sources of Race Conditions in InvocationManager #4602

APPSERV-114 Addresses possible sources of Race Conditions in InvocationManager #4602

Conversation

jbee commented Apr 2, 2020 • edited Loading

Background

Summary

Testing

Testing Performed

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jbee commented Apr 2, 2020

Pandrex247 left a comment

Choose a reason for hiding this comment

pdudits left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jbee commented Apr 20, 2020

jbee commented Apr 20, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jbee commented Apr 22, 2020

jbee commented Apr 2, 2020 •

edited

Loading