[ https://issues.apache.org/jira/browse/GEODE-7763?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17044687#comment-17044687 ]
John Blum edited comment on GEODE-7763 at 2/25/20 8:02 PM: ----------------------------------------------------------- I am currently reviewing the analysis and comments on this ticket. I observed a few discrepancies in the comments. First, is a statement made in this [comment|https://issues.apache.org/jira/browse/GEODE-7763?focusedCommentId=17039238&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-17039238] referring to a "{{put}}" by the {{SessionEventHandlerCacheListenerAdapter}}: {quote}The second during the put in the SessionEventHandlerCacheListenerAdapter here:{quote} Citing this _Stack Trace_: {code:java} 2020-02-12 14:46:34,381 WARN org.springframework.session.data.gemfire.AbstractGemFireOperationsSessionRepository$DeltaCapableGemFireSession [Session Thread 10] XXX DeltaCapableGemFireSession instantiated java.lang.Exception: null at org.springframework.session.data.gemfire.AbstractGemFireOperationsSessionRepository$DeltaCapableGemFireSession.<init>(AbstractGemFireOperationsSessionRepository.java:704) at org.springframework.session.data.gemfire.AbstractGemFireOperationsSessionRepository$GemFireSession.copy(AbstractGemFireOperationsSessionRepository.java:772) at org.springframework.session.data.gemfire.AbstractGemFireOperationsSessionRepository$GemFireSession.from(AbstractGemFireOperationsSessionRepository.java:787) at org.springframework.session.data.gemfire.serialization.data.provider.DataSerializableSessionSerializer.deserialize(DataSerializableSessionSerializer.java:122) at org.springframework.session.data.gemfire.MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests$SpyingDataSerializableSessionSerializer.deserialize(MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java:474) at org.springframework.session.data.gemfire.MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests$SpyingDataSerializableSessionSerializer.deserialize(MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java:439) at org.springframework.session.data.gemfire.serialization.data.AbstractDataSerializableSessionSerializer.fromData(AbstractDataSerializableSessionSerializer.java:107) at org.apache.geode.internal.InternalDataSerializer.readUserObject(InternalDataSerializer.java:1786) at org.apache.geode.internal.InternalDataSerializer.basicReadObject(InternalDataSerializer.java:2878) at org.apache.geode.DataSerializer.readObject(DataSerializer.java:2978) at org.apache.geode.CopyHelper.doDeepCopy(CopyHelper.java:242) at org.apache.geode.CopyHelper.copy(CopyHelper.java:190) at org.apache.geode.internal.cache.EntryEventImpl.getNewValue(EntryEventImpl.java:1063) at java.util.Optional.map(Optional.java:215) at org.springframework.session.data.gemfire.AbstractGemFireOperationsSessionRepository$SessionEventHandlerCacheListenerAdapter.isSession(AbstractGemFireOperationsSessionRepository.java:1732) at java.util.Optional.filter(Optional.java:178) at org.springframework.session.data.gemfire.AbstractGemFireOperationsSessionRepository$SessionEventHandlerCacheListenerAdapter.remember(AbstractGemFireOperationsSessionRepository.java:1699) at java.util.Optional.filter(Optional.java:178) at org.springframework.session.data.gemfire.AbstractGemFireOperationsSessionRepository$SessionEventHandlerCacheListenerAdapter.afterCreate(AbstractGemFireOperationsSessionRepository.java:1481) at org.apache.geode.internal.cache.EnumListenerEvent$AFTER_CREATE.dispatchEvent(EnumListenerEvent.java:130) at org.apache.geode.internal.cache.LocalRegion.dispatchEvent(LocalRegion.java:8485) at org.apache.geode.internal.cache.LocalRegion.dispatchListenerEvent(LocalRegion.java:7049) at org.apache.geode.internal.cache.LocalRegion.invokePutCallbacks(LocalRegion.java:6013) at org.apache.geode.internal.cache.EntryEventImpl.invokeCallbacks(EntryEventImpl.java:2402) at org.apache.geode.internal.cache.ProxyRegionMap$ProxyRegionEntry.dispatchListenerEvents(ProxyRegionMap.java:615) at org.apache.geode.internal.cache.LocalRegion.basicPutPart2(LocalRegion.java:5869) at org.apache.geode.internal.cache.ProxyRegionMap.basicPut(ProxyRegionMap.java:244) at org.apache.geode.internal.cache.LocalRegion.virtualPut(LocalRegion.java:5691) at org.apache.geode.internal.cache.LocalRegionDataView.putEntry(LocalRegionDataView.java:162) at org.apache.geode.internal.cache.LocalRegion.basicPut(LocalRegion.java:5119) at org.apache.geode.internal.cache.LocalRegion.validatedPut(LocalRegion.java:1661) at org.apache.geode.internal.cache.LocalRegion.put(LocalRegion.java:1648) at org.apache.geode.internal.cache.AbstractRegion.put(AbstractRegion.java:421) at org.springframework.data.gemfire.GemfireTemplate.put(GemfireTemplate.java:194) at org.springframework.session.data.gemfire.GemFireOperationsSessionRepository.doSave(GemFireOperationsSessionRepository.java:226) at org.springframework.session.data.gemfire.GemFireOperationsSessionRepository.save(GemFireOperationsSessionRepository.java:186) at org.springframework.session.data.gemfire.AbstractGemFireIntegrationTests.save(AbstractGemFireIntegrationTests.java:409) at org.springframework.session.data.gemfire.MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.lambda$newAddSessionAttributeTask$2(MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java:237) {code} The {{put}} is *NOT* occurring inside the {{SessionEventHandlerCacheListenerAdapter}}. The intended purpose and function of the {{SessionEventHandlerCacheListenerAdapter}} in _Spring Session (for Apache Geode/Pivotal GemFire)_, or SSDG, is to 1) "remember" (by ID) the Sessions this client creates and 2) more importantly, fire/publish {{ApplicationEvents}} in the _Spring_ container to interested application components (i.e. _Spring_ beans managed by the container and annotated with the _Spring_ {{@EventListener}} annotation. Some application components may want to respond to a Session event, such as when a new Session is created (i.e. when a user of our customer's Spring Boot/Pivotal GemFire applications logs in and the application creates a new Session, perhaps). In no way does the {{SessionEventHandlerCacheListenerAdapter}} perform Region data access operations, at least not directly. If you look at the _Stack Trace_ more closely, the Session Region data access operation (i.e. the {{put}}) actually coincides with the Session {{save}} operation using the _Spring Session_ {{SessionRepository}}: {code:java} ... at org.apache.geode.internal.cache.AbstractRegion.put(AbstractRegion.java:421) at org.springframework.data.gemfire.GemfireTemplate.put(GemfireTemplate.java:194) at org.springframework.session.data.gemfire.GemFireOperationsSessionRepository.doSave(GemFireOperationsSessionRepository.java:226) at org.springframework.session.data.gemfire.GemFireOperationsSessionRepository.save(GemFireOperationsSessionRepository.java:186) ... {code} The {{CacheListener}} was only invoked to 1) remember the Session and 2) publish an appropriate _Spring_ container {{ApplicationEvent}}. It is *true* that each Workload Task (possibly) creates 2 instances of the {{[DeltaCapable]GemFireSession}} object, once on *load* and again on *save*. All other instances created are the work of Geode. It makes sense on *load* especially as the Session object stored in Geode on the server-side is being deserialized from the server to the client. The *save* is probably less apparent. Essentially, SSDG can interoperate with different _Spring Session_ providers, e.g. _Spring Session Data Redis_. If a Session object is technically a Redis implementation, possibly created by another _Spring_ application, SSDG does not care and will do the right thing. Therefore, a copy of the "generic" Session object (as it is treated) is made. However, this is only true if the Session object is not a Geode implementation, as seen [here|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/main/java/org/springframework/session/data/gemfire/GemFireOperationsSessionRepository.java#L226], and then [here|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/main/java/org/springframework/session/data/gemfire/AbstractGemFireOperationsSessionRepository.java#L784]. SSDG makes a best effort to not create too much garbage, so long it upholds safety, particularly in a multi-Thread Web/Servlet container environment where multiple HTTP requests can and do access the same "logical" Session, and where each HTTP request is processed by a separate Thread. However, as stated, it is true that the {{SessionEventHandlerCacheListenerAdapter}} is where the second instance of {{[DeltaCapable]GemFireSesion}} is being created, which appears to be simply because SSDG accessed {{EntryEvent.getNewValue}} in order to properly inspect that the Session object is valid. As for {{master}}, well, the second Session object instance creation occurred because the test still has {{copyOnRead}} set to *true*. While this was absolutely critical and necessary in Apache Geode prior to 1.10 (Pivotal GemFire prior to 9.9), it is not as important from 1.10 (GemFire 9.9) onward given the changes to address [GEODE-6152] were resolved in 1.10 (GemFire 9.9). Because Apache Geode and Pivotal GemFire incorrectly returned the same object reference from a client {{PROXY}} Region (specifically a reference to the same Session object from 2 different Threads processing different incoming HTTP client requests), the bug noted in [GEODE-6152] caused significant data loss, particularly in highly-loaded, highly-concurrent Session access as witnessed in a customer's UC. Regarding client {{PROXY}} Regions and {{copyOnRead}} semantics... I do think this would be a welcome and important change inside Apache Geode: {code:java} if (!disableCopyOnRead && !isProxy()) { result = conditionalCopy(result); } {code} Really, the configuration of the cache {{copyOnRead}} property is irrelevant if the client (Session) Region is a {{PROXY}}, since a {{PROXY}} has no, or should have no, local state, as [described|https://geode.apache.org/releases/latest/javadoc/org/apache/geode/cache/client/ClientRegionShortcut.html#PROXY]. Regarding {{LOCAL_LOAD_CREATE}} and the 3rd instance of the Session object created when testing against {{master}}... {quote}The third one created during the get is a LOCAL_LOAD_CREATE event. I'm not sure, but I don't think this one is necessary either.{quote} Followed by the suggested (unsafe) code change... {code:java} public void afterCreate(EntryEvent<Object, Session> event) { if (!event.getOperation().isLocalLoad()) { Optional.ofNullable(event) .filter(this::remember) .ifPresent(it -> getSessionRepository() .publishEvent(newSessionCreatedEvent(toSession(it.getNewValue(), it.getKey())))); } } {code} And specifically... {code:java} if (!event.getOperation().isLocalLoad()) { ... } {code} This is interesting and I have already taken steps to test this change inside of SSDG. The main concern with this change is, SSDG still needs to invoke all the {{ApplicationListeners}} declared inside the _Spring_ container when a {{SessionCreatedEvent}} happens, even if this application (i.e. {{ClientCache}}) was the one that created the Session in the first place. However, and interestingly enough, when I tested with the [ClientServerProxyRegionSessionOperationsIntegrationTests|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/integration-test/java/org/springframework/session/data/gemfire/ClientServerProxyRegionSessionOperationsIntegrationTests.java] SSDG test class and ran in debug mode, I saw that the [SessionEventHandlerCacheListenerAdapter.afterCreate(:EntryEvent)|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/main/java/org/springframework/session/data/gemfire/AbstractGemFireOperationsSessionRepository.java#L1474-L1481] method was called TWICE, once with {{Operation.CREATE}} and again with {{Operation.LOCAL_LOAD_CREATE}}. Seems kind of redundant if you ask me, but whatever. However, I did see that an appropriate _Spring_ {{ApplicationEvent}} for the {{SessionCreatedEvent}} was fired/published, which would trigger the interested {{ApplicationListeners}} or {{@EventListener}} annotated _Spring_ beans, as expected by the test, [here|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/integration-test/java/org/springframework/session/data/gemfire/ClientServerProxyRegionSessionOperationsIntegrationTests.java#L67-L74]. Now that I am remembering correctly, the reason I added the "remember" logic inside the {{SessionEventHandlerCacheListenerAdapter}} in the first place was to specifically prevent an event, e.g. CREATED event, from firing twice due to the mix of nearly identical Geode {{Operation}} types (e.g. {{CREATE}} and {{LOCAL_LOAD_CREATE}}). Effectively, [this|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/main/java/org/springframework/session/data/gemfire/AbstractGemFireOperationsSessionRepository.java#L1478] and [this|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/main/java/org/springframework/session/data/gemfire/AbstractGemFireOperationsSessionRepository.java#L1693-L1701]. However, due to the *inspection* ([this|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/main/java/org/springframework/session/data/gemfire/AbstractGemFireOperationsSessionRepository.java#L1696] and then [this|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/main/java/org/springframework/session/data/gemfire/AbstractGemFireOperationsSessionRepository.java#L1729]) of the Session objct (i.e. "new value"), this is what caused a deserialization and a subsequent {{[DeltaCapable]GemFireSession}} object creation. Continued... was (Author: jblum): I am currently reviewing the analysis and comments on this ticket. I observed a few discrepancies in the comments. First, is a statement made in this [comment|https://issues.apache.org/jira/browse/GEODE-7763?focusedCommentId=17039238&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-17039238] referring to a "{{put}}" by the {{SessionEventHandlerCacheListenerAdapter}}: {quote}The second during the put in the SessionEventHandlerCacheListenerAdapter here:{quote} Citing this _Stack Trace_: {code:java} 2020-02-12 14:46:34,381 WARN org.springframework.session.data.gemfire.AbstractGemFireOperationsSessionRepository$DeltaCapableGemFireSession [Session Thread 10] XXX DeltaCapableGemFireSession instantiated java.lang.Exception: null at org.springframework.session.data.gemfire.AbstractGemFireOperationsSessionRepository$DeltaCapableGemFireSession.<init>(AbstractGemFireOperationsSessionRepository.java:704) at org.springframework.session.data.gemfire.AbstractGemFireOperationsSessionRepository$GemFireSession.copy(AbstractGemFireOperationsSessionRepository.java:772) at org.springframework.session.data.gemfire.AbstractGemFireOperationsSessionRepository$GemFireSession.from(AbstractGemFireOperationsSessionRepository.java:787) at org.springframework.session.data.gemfire.serialization.data.provider.DataSerializableSessionSerializer.deserialize(DataSerializableSessionSerializer.java:122) at org.springframework.session.data.gemfire.MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests$SpyingDataSerializableSessionSerializer.deserialize(MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java:474) at org.springframework.session.data.gemfire.MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests$SpyingDataSerializableSessionSerializer.deserialize(MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java:439) at org.springframework.session.data.gemfire.serialization.data.AbstractDataSerializableSessionSerializer.fromData(AbstractDataSerializableSessionSerializer.java:107) at org.apache.geode.internal.InternalDataSerializer.readUserObject(InternalDataSerializer.java:1786) at org.apache.geode.internal.InternalDataSerializer.basicReadObject(InternalDataSerializer.java:2878) at org.apache.geode.DataSerializer.readObject(DataSerializer.java:2978) at org.apache.geode.CopyHelper.doDeepCopy(CopyHelper.java:242) at org.apache.geode.CopyHelper.copy(CopyHelper.java:190) at org.apache.geode.internal.cache.EntryEventImpl.getNewValue(EntryEventImpl.java:1063) at java.util.Optional.map(Optional.java:215) at org.springframework.session.data.gemfire.AbstractGemFireOperationsSessionRepository$SessionEventHandlerCacheListenerAdapter.isSession(AbstractGemFireOperationsSessionRepository.java:1732) at java.util.Optional.filter(Optional.java:178) at org.springframework.session.data.gemfire.AbstractGemFireOperationsSessionRepository$SessionEventHandlerCacheListenerAdapter.remember(AbstractGemFireOperationsSessionRepository.java:1699) at java.util.Optional.filter(Optional.java:178) at org.springframework.session.data.gemfire.AbstractGemFireOperationsSessionRepository$SessionEventHandlerCacheListenerAdapter.afterCreate(AbstractGemFireOperationsSessionRepository.java:1481) at org.apache.geode.internal.cache.EnumListenerEvent$AFTER_CREATE.dispatchEvent(EnumListenerEvent.java:130) at org.apache.geode.internal.cache.LocalRegion.dispatchEvent(LocalRegion.java:8485) at org.apache.geode.internal.cache.LocalRegion.dispatchListenerEvent(LocalRegion.java:7049) at org.apache.geode.internal.cache.LocalRegion.invokePutCallbacks(LocalRegion.java:6013) at org.apache.geode.internal.cache.EntryEventImpl.invokeCallbacks(EntryEventImpl.java:2402) at org.apache.geode.internal.cache.ProxyRegionMap$ProxyRegionEntry.dispatchListenerEvents(ProxyRegionMap.java:615) at org.apache.geode.internal.cache.LocalRegion.basicPutPart2(LocalRegion.java:5869) at org.apache.geode.internal.cache.ProxyRegionMap.basicPut(ProxyRegionMap.java:244) at org.apache.geode.internal.cache.LocalRegion.virtualPut(LocalRegion.java:5691) at org.apache.geode.internal.cache.LocalRegionDataView.putEntry(LocalRegionDataView.java:162) at org.apache.geode.internal.cache.LocalRegion.basicPut(LocalRegion.java:5119) at org.apache.geode.internal.cache.LocalRegion.validatedPut(LocalRegion.java:1661) at org.apache.geode.internal.cache.LocalRegion.put(LocalRegion.java:1648) at org.apache.geode.internal.cache.AbstractRegion.put(AbstractRegion.java:421) at org.springframework.data.gemfire.GemfireTemplate.put(GemfireTemplate.java:194) at org.springframework.session.data.gemfire.GemFireOperationsSessionRepository.doSave(GemFireOperationsSessionRepository.java:226) at org.springframework.session.data.gemfire.GemFireOperationsSessionRepository.save(GemFireOperationsSessionRepository.java:186) at org.springframework.session.data.gemfire.AbstractGemFireIntegrationTests.save(AbstractGemFireIntegrationTests.java:409) at org.springframework.session.data.gemfire.MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.lambda$newAddSessionAttributeTask$2(MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java:237) {code} The {{put}} is *NOT* occurring inside the {{SessionEventHandlerCacheListenerAdapter}}. The intended purpose and function of the {{SessionEventHandlerCacheListenerAdapter}} in _Spring Session (for Apache Geode/Pivotal GemFire)_, or SSDG, is to 1) "remember" (by ID) the Sessions this client creates and 2) more importantly, fire/publish {{ApplicationEvents}} in the _Spring_ container to interested application components (i.e. _Spring_ beans managed by the container and annotated with the _Spring_ {{@EventListener}} annotation. Some application components may want to respond to a Session event, such as when a new Session is created (i.e. when a user of our customer's Spring Boot/Pivotal GemFire applications logs in and the application creates a new Session, perhaps). In no way does the {{SessionEventHandlerCacheListenerAdapter}} perform Region data access operations, at least not directly. If you look at the _Stack Trace_ more closely, the Session Region data access operation (i.e. the {{put}}) actually coincides with the Session {{save}} operation using the _Spring Session_ {{SessionRepository}}: {code:java} ... at org.apache.geode.internal.cache.AbstractRegion.put(AbstractRegion.java:421) at org.springframework.data.gemfire.GemfireTemplate.put(GemfireTemplate.java:194) at org.springframework.session.data.gemfire.GemFireOperationsSessionRepository.doSave(GemFireOperationsSessionRepository.java:226) at org.springframework.session.data.gemfire.GemFireOperationsSessionRepository.save(GemFireOperationsSessionRepository.java:186) ... {code} The {{CacheListener}} was only invoked to 1) remember the Session and 2) publish an appropriate _Spring_ container {{ApplicationEvent}}. It is *true* that each Workload Task (possibly) creates 2 instances of the {{[DeltaCapable]GemFireSession}} object, once on *load* and again on *save*. All other instances created are the work of Geode. It makes sense on *load* especially as the Session object stored in Geode on the server-side is being deserialized from the server to the client. The *save* is probably less apparent. Essentially, SSDG can interoperate with different _Spring Session_ providers, e.g. _Spring Session Data Redis_. If a Session object is technically a Redis implementation, possibly created by another _Spring_ application, SSDG does not care and will do the right thing. Therefore, a copy of the "generic" Session object (as it is treated) is made. However, this is only true if the Session object is not a Geode implementation, as seen [here|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/main/java/org/springframework/session/data/gemfire/GemFireOperationsSessionRepository.java#L226], and then [here|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/main/java/org/springframework/session/data/gemfire/AbstractGemFireOperationsSessionRepository.java#L784]. SSDG makes a best effort to not create too much garbage, so long it upholds safety, particularly in a multi-Thread Web/Servlet container environment where multiple HTTP requests can and do access the same "logical" Session, and where each HTTP request is processed by a separate Thread. However, as stated, it is true that the {{SessionEventHandlerCacheListenerAdapter}} is where the second instance of {{[DeltaCapable]GemFireSesion}} is being created, which appears to be simply because SSDG accessed {{EntryEvent.getNewValue}} in order to properly inspect that the Session object is valid. As for {{master}}, well, the second Session object instance creation occurred because the test still has {{copyOnRead}} set to *true*. While this was absolutely critical and necessary in Apache Geode prior to 1.10 (Pivotal GemFire prior to 9.9), it is not as important from 1.10 (GemFire 9.9) onward given the changes to address [GEODE-6152] were resolved in 1.10 (GemFire 9.9). Because Apache Geode and Pivotal GemFire incorrectly returned the same object reference from a client {{PROXY}} Region (specifically a reference to the same Session object from 2 different Threads processing different incoming HTTP client requests), the bug noted in [GEODE-6152] caused significant data loss, particularly in highly-loaded, highly-concurrent Session access as witnessed in a customer's UC. Regarding client {{PROXY}} Regions and {{copyOnRead}} semantics... I do think this would be a welcome and important change inside Apache Geode: {code:java} if (!disableCopyOnRead && !isProxy()) { result = conditionalCopy(result); } {code} Really, the configuration of the cache {{copyOnRead}} property is irrelevant if the client (Session) Region is a {{PROXY}}, since a {{PROXY}} has no, or should have no, local state, as [described|https://geode.apache.org/releases/latest/javadoc/org/apache/geode/cache/client/ClientRegionShortcut.html#PROXY]. Regarding {{LOCAL_LOAD_CREATE}} and the 3rd instance of the Session object created when testing against {{master}}... {quote}The third one created during the get is a LOCAL_LOAD_CREATE event. I'm not sure, but I don't think this one is necessary either.{quote} Followed by the suggested (unsafe) code change... {code:java} public void afterCreate(EntryEvent<Object, Session> event) { if (!event.getOperation().isLocalLoad()) { Optional.ofNullable(event) .filter(this::remember) .ifPresent(it -> getSessionRepository() .publishEvent(newSessionCreatedEvent(toSession(it.getNewValue(), it.getKey())))); } } {code} And specifically... {code:java} if (!event.getOperation().isLocalLoad()) { ... } {code} This is interesting and I have already taken steps to test this change inside of SSDG. The main concern with this change is, SSDG still needs to invoke all the {{ApplicationListeners}} declared inside the _Spring_ container when a {{SessionCreatedEvent}} happens, even if this application (i.e. {{ClientCache}}) was the one that created the Session in the first place. However, and interestingly enough, when I tested with the [ClientServerProxyRegionSessionOperationsIntegrationTests|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/integration-test/java/org/springframework/session/data/gemfire/ClientServerProxyRegionSessionOperationsIntegrationTests.java] SSDG test class and ran in debug mode, I saw that the [SessionEventHandlerCacheListenerAdapter.afterCreate(:EntryEvent)|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/main/java/org/springframework/session/data/gemfire/AbstractGemFireOperationsSessionRepository.java#L1474-L1481] method was called TWICE, once with {{Operation.CREATE}} and again with {{Operation.LOCAL_LOAD_CREATE}}. Seems kind of redundant if you ask me, but whatever. However, I did see that an appropriate _Spring_ {{ApplicationEvent}} for the {{SessionCreatedEvent}} was fired/published, which would trigger the interested {{ApplicationListeners}} or {{@EventListener}} annotated _Spring_ beans, as expected by the test, [here|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/integration-test/java/org/springframework/session/data/gemfire/ClientServerProxyRegionSessionOperationsIntegrationTests.java#L67-L74]. Now that I am remembering correctly, the reason I added the "remember" logic inside the {{SessionEventHandlerCacheListenerAdapter}} in the first place was to specifically prevent an event, e.g. CREATED event, from firing twice due to the mix of nearly identical Geode {{Operation}} types (e.g. {{CREATE}} and {{LOCAL_LOAD_CREATE}}). Effectively, [this|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/main/java/org/springframework/session/data/gemfire/AbstractGemFireOperationsSessionRepository.java#L1478] and [this|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/main/java/org/springframework/session/data/gemfire/AbstractGemFireOperationsSessionRepository.java#L1693-L1701]. However, due to the *inspection* ([this|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/main/java/org/springframework/session/data/gemfire/AbstractGemFireOperationsSessionRepository.java#L1696] and then [this|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/main/java/org/springframework/session/data/gemfire/AbstractGemFireOperationsSessionRepository.java#L1729]) of the Session objct (i.e. "new value"), this is what caused a deserialization and a subsequent {{[DeltaCapable]GemFireSession}} object creation. Continued... > Apache Geode 1.11 severely and negatively impacts performance and resource > utilization > -------------------------------------------------------------------------------------- > > Key: GEODE-7763 > URL: https://issues.apache.org/jira/browse/GEODE-7763 > Project: Geode > Issue Type: Bug > Components: client/server > Affects Versions: 1.10.0, 1.11.0 > Reporter: John Blum > Priority: Critical > Labels: performance > Attachments: 1.11-client-stats.gfs, 1.11-server-stats.gfs, > 1.11_thread_dumps.rtf, 1.9-client-stats.gfs, 1.9-server-stats.gfs, 1.9.log, > apache-geode-1.10-client-server-interaction-output.txt, > apache-geode-1.10-client-server-startup-output.txt, > apache-geode-1.11-client-server-interaction-output.txt, > apache-geode-1.11-client-server-startup-output.txt, > geode-7763-geode-changes.diff, geode-7763-ssdg-changes.diff > > > This problem was first observed in Apache Geode 1.11.0. The problem was not > present in Apache Geode 1.9.2. This problem is an issue for Apache Geode > 1.10 as well! > After upgrading _Spring Session for Apache Geode_ (SSDG) 2.3 to _Spring Data > for Apache Geode_ (SDG) Neumann/2.3, which is based on Apache Geode 1.11, > this problem with SSDG's test suite started occurring. > _Spring Session for Apache Geode_ (SSDG) 2.2, which is based on _Spring Data > for Apache Geode_ (SDG) Moore/2.2, pulls in Apache Geode 1.9.2. This problem > did not occur in SSDG 2.2. with Apache Geode 1.9.2. > Out of curiosity, I wondered whether this problem affects (i.e. was actually > introduced in) Apache Geode 1.10.0. So, I configured SSDG 2.3 to pull in SDG > Moore/2.2 but run with Apache Geode 1.10. The problem occurred with Apache > Geode 1.10 as well! > The SSDG test class in question, affected by Geode's deficiencies, is the > [MultiThreadedHighlyConcurrentClientServerSessionOperationsIntegrationTests|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/integration-test/java/org/springframework/session/data/gemfire/MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java]. > The test class was modeled after a customer UC, who were using Spring Session > and Apache Geode/Pivotal GemFire as the HTTP Session state management > provider, therefore it simulates their highly concurrent environment. > The test class has 2 primary parameters: [Thread > Count|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/integration-test/java/org/springframework/session/data/gemfire/MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java#L90] > and the [Workload > Size|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/integration-test/java/org/springframework/session/data/gemfire/MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java#L91]. > The "_Workload Size_" should not be confused with the "_Payload Size_" of the > individual objects passed to the Geode data access operations (i.e. {{gets}}, > {{puts}}, {{removes}}). The "_Workload Size_" merely determines the number > of {{get}}, {{put}} or {{remove}} operations performed on the (Session) > Region over the duration of the test run. Certain operations are "favored" > over others, therefore the number of {{gets}}, {{puts}} and {{removes}} is > weighted. > The "_Payload_" in this case is a (HTTP) {{Session}} object and the "size" is > directly proportional to the number of Session attributes stored in the > Session. > As you can see from the [test class > configuration|https://github.com/spring-projects/spring-session-data-geode/blob/2.2.2.RELEASE/spring-session-data-geode/src/integration-test/java/org/springframework/session/data/gemfire/MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java#L90-L91] > in *SSDG* {{2.2}}, the *Thread Count* was set to *180* and the *Workload > Size* (or number of Region operations) was set to *10,000*. > This had to be significantly adjusted in SSDG 2.3 using Apache Geode 1.11 > (and, as it turns out, Apache Geode 1.10 as well), as can be seen in the > {{2.3.0.M1}} release bits source, > [here|https://github.com/spring-projects/spring-session-data-geode/blob/2.3.0.M1/spring-session-data-geode/src/integration-test/java/org/springframework/session/data/gemfire/MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java#L94-L95]. > It turns out different combinations of the Thread Count (number of workers, > or "concurrent Sessions") and Workload Size ultimately determine whether this > test class passes or not. > In other words, if I increase the Thread Count, then the Workload Size must > decrease, otherwise the test fails! If I increase the Workload Size, then > the Thread Count must decrease, otherwise again the test fails! > I tried with different combinations of Thread Count and Workload Size until > the test passed. More often than not 180 Threads with 3000 Regions > operations worked, but was right on the cusp of failing, therefore, I settled > on 180 Threads (which nearly matches the customers environment of 200 > concurrent client Sessions) and 2000 concurrent Region operations. > The point of the test class is to assert the state of the Session is > consistent at the end of the test run. > However, before this test can even finish, the client, as in the > {{ClientCache}} instance, starts failing with Exceptions, specifically: > {code:java} > java.lang.RuntimeException: Session Access Task Failed > at > org.springframework.session.data.gemfire.MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.safeFutureGet(MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java:298) > at > java.util.stream.ReferencePipeline$4$1.accept(ReferencePipeline.java:210) > at > java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1382) > at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481) > at > java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471) > at > java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:708) > at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) > at java.util.stream.IntPipeline.reduce(IntPipeline.java:456) > at java.util.stream.IntPipeline.sum(IntPipeline.java:414) > at > org.springframework.session.data.gemfire.MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.runSessionWorkload(MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java:313) > at > org.springframework.session.data.gemfire.MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.concurrentSessionAccessIsCorrect(MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java:324) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:498) > at > org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) > at > org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) > at > org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) > at > org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) > at > org.springframework.test.context.junit4.statements.RunBeforeTestExecutionCallbacks.evaluate(RunBeforeTestExecutionCallbacks.java:74) > at > org.springframework.test.context.junit4.statements.RunAfterTestExecutionCallbacks.evaluate(RunAfterTestExecutionCallbacks.java:84) > at > org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) > at > org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75) > at > org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86) > at > org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84) > at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > at > org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:251) > at > org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:97) > at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > at > org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) > at > org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61) > at > org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) > at > org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:70) > at org.junit.runners.ParentRunner.run(ParentRunner.java:363) > at > org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:190) > at org.junit.runner.JUnitCore.run(JUnitCore.java:137) > at > com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:68) > at > com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:33) > at > com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:230) > at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:58) > Caused by: java.util.concurrent.ExecutionException: > org.springframework.dao.DataAccessResourceFailureException: Pool unexpected > socket timed out on client connection=Pooled Connection to localhost:60964: > Connection[DESTROYED]). Server unreachable: could not connect after 1 > attempts; nested exception is > org.apache.geode.cache.client.ServerConnectivityException: Pool unexpected > socket timed out on client connection=Pooled Connection to localhost:60964: > Connection[DESTROYED]). Server unreachable: could not connect after 1 attempts > at java.util.concurrent.FutureTask.report(FutureTask.java:122) > at java.util.concurrent.FutureTask.get(FutureTask.java:192) > at > org.springframework.session.data.gemfire.MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.safeFutureGet(MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java:295) > ... 43 more > Caused by: org.springframework.dao.DataAccessResourceFailureException: Pool > unexpected socket timed out on client connection=Pooled Connection to > localhost:60964: Connection[DESTROYED]). Server unreachable: could not > connect after 1 attempts; nested exception is > org.apache.geode.cache.client.ServerConnectivityException: Pool unexpected > socket timed out on client connection=Pooled Connection to localhost:60964: > Connection[DESTROYED]). Server unreachable: could not connect after 1 attempts > at > org.springframework.data.gemfire.GemfireCacheUtils.convertGemfireAccessException(GemfireCacheUtils.java:235) > at > org.springframework.data.gemfire.GemfireAccessor.convertGemFireAccessException(GemfireAccessor.java:93) > at > org.springframework.data.gemfire.GemfireTemplate.put(GemfireTemplate.java:200) > at > org.springframework.session.data.gemfire.GemFireOperationsSessionRepository.doSave(GemFireOperationsSessionRepository.java:226) > at > org.springframework.session.data.gemfire.GemFireOperationsSessionRepository.save(GemFireOperationsSessionRepository.java:186) > at > org.springframework.session.data.gemfire.AbstractGemFireIntegrationTests.save(AbstractGemFireIntegrationTests.java:409) > at > org.springframework.session.data.gemfire.MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.lambda$newAddSessionAttributeTask$2(MultiThreadedHighlyConcurrentClientServerHttpSessionAccessIntegrationTests.java:216) > at java.util.concurrent.FutureTask.run(FutureTask.java:266) > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) > at java.lang.Thread.run(Thread.java:748) > Caused by: org.apache.geode.cache.client.ServerConnectivityException: Pool > unexpected socket timed out on client connection=Pooled Connection to > localhost:60964: Connection[DESTROYED]). Server unreachable: could not > connect after 1 attempts > at > org.apache.geode.cache.client.internal.OpExecutorImpl.handleException(OpExecutorImpl.java:659) > at > org.apache.geode.cache.client.internal.OpExecutorImpl.handleException(OpExecutorImpl.java:501) > at > org.apache.geode.cache.client.internal.OpExecutorImpl.execute(OpExecutorImpl.java:153) > at > org.apache.geode.cache.client.internal.OpExecutorImpl.execute(OpExecutorImpl.java:108) > at > org.apache.geode.cache.client.internal.PoolImpl.execute(PoolImpl.java:772) > at org.apache.geode.cache.client.internal.PutOp.execute(PutOp.java:89) > at > org.apache.geode.cache.client.internal.ServerRegionProxy.put(ServerRegionProxy.java:159) > at > org.apache.geode.internal.cache.LocalRegion.serverPut(LocalRegion.java:3035) > at > org.apache.geode.internal.cache.LocalRegion.cacheWriteBeforePut(LocalRegion.java:3152) > at > org.apache.geode.internal.cache.ProxyRegionMap.basicPut(ProxyRegionMap.java:238) > at > org.apache.geode.internal.cache.LocalRegion.virtualPut(LocalRegion.java:5580) > at > org.apache.geode.internal.cache.LocalRegionDataView.putEntry(LocalRegionDataView.java:162) > at > org.apache.geode.internal.cache.LocalRegion.basicPut(LocalRegion.java:5036) > at > org.apache.geode.internal.cache.LocalRegion.validatedPut(LocalRegion.java:1635) > at > org.apache.geode.internal.cache.LocalRegion.put(LocalRegion.java:1622) > at > org.apache.geode.internal.cache.AbstractRegion.put(AbstractRegion.java:442) > at > org.springframework.data.gemfire.GemfireTemplate.put(GemfireTemplate.java:197) > ... 8 more > {code} > Attached to this issue are log output files from each of my runs using Apache > Geode 1.10 and 1.11. > The log files serve 2 purposes: 1) to show the version of Apache Geode used > and 2) the errors occurs on the client and server during the run. > Any lines in the log output prefixed with "{{[FORK]}}" originates from the > cache server. The other lines come from the client. There is only a single > client and server in this test case. > It takes a bit of initial time during the run for the failures to start > occurring, which is why this seems like a resource utilization problem. > After first, I suspected issues with the client Pool configuration, or > {{CacheServer}} configuration, adjusting timeouts and so on. I even > suspected memory being an issue for the client and server processes, upping > each to 2 GB+. However, it turns out none of the changes made a bit of > difference. And the truth of the matter is, this (existing) configuration > worked seamlessly until I upgraded to Apache Geode 1.10+ (specifically, 1.11). -- This message was sent by Atlassian Jira (v8.3.4#803005)