Skip to content

backport gh-1077 to 1.3.x. Fix NullPointerException in entryRemoved. #1316

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
wants to merge 7 commits into from

Conversation

jtodt
Copy link

@jtodt jtodt commented Jan 16, 2019

backport #gh-1077 to 1.3.x. Fix NullPointerException in entryRemoved.
detected with hazelcast 3.11, spring session 1.3.4, spring boot 1.5

#gh-1077

We detected Nullpointer on session timeouts:

2019-01-16 13:01:00,151 ERROR [hz._hzInstance_1_xxx.event-4] ? (?:?) - [xxx.xxx.xxx.xxx]:xxxx [xxx] [3.11] hz._hzInstance_1_xxx.event-4 caught an exception while processing task:com.hazelcast.spi.impl.eventservice.impl.LocalEventDispatcher@6b58bdef
java.lang.NullPointerException
        at org.springframework.session.events.AbstractSessionEvent.<init>(AbstractSessionEvent.java:45)
        at org.springframework.session.events.SessionDestroyedEvent.<init>(SessionDestroyedEvent.java:41)
        at org.springframework.session.events.SessionDeletedEvent.<init>(SessionDeletedEvent.java:39)
        at org.springframework.session.hazelcast.HazelcastSessionRepository.entryRemoved(HazelcastSessionRepository.java:273)
        at com.hazelcast.map.impl.MapListenerAdaptors$2$1.onEvent(MapListenerAdaptors.java:87)
        at com.hazelcast.map.impl.MapListenerAdaptors$2$1.onEvent(MapListenerAdaptors.java:84)
        at com.hazelcast.map.impl.InternalMapListenerAdapter.onEvent(InternalMapListenerAdapter.java:56)
        at com.hazelcast.map.impl.InternalMapListenerAdapter.onEvent(InternalMapListenerAdapter.java:35)
        at com.hazelcast.map.impl.event.MapEventPublishingService.callListener(MapEventPublishingService.java:172)
        at com.hazelcast.map.impl.event.MapEventPublishingService.dispatchEntryEventData(MapEventPublishingService.java:184)
        at com.hazelcast.map.impl.event.MapEventPublishingService.dispatchEvent(MapEventPublishingService.java:83)
        at com.hazelcast.map.impl.event.MapEventPublishingService.dispatchEvent(MapEventPublishingService.java:47)
        at com.hazelcast.map.impl.MapService.dispatchEvent(MapService.java:106)
        at com.hazelcast.map.impl.MapService.dispatchEvent(MapService.java:77)
        at com.hazelcast.spi.impl.eventservice.impl.LocalEventDispatcher.run(LocalEventDispatcher.java:64)
        at com.hazelcast.util.executor.StripedExecutor$Worker.process(StripedExecutor.java:226)
        at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:209)

… entryRemoved.

detected with hazelcast 3.11, spring session 1.3.4, spring boot 1.5
@pivotal-issuemaster
Copy link

@niwostufe0 Please sign the Contributor License Agreement!

Click here to manually synchronize the status of this Pull Request.

See the FAQ for frequently asked questions.

@pivotal-issuemaster
Copy link

@niwostufe0 Thank you for signing the Contributor License Agreement!

@rwinch
Copy link
Member

rwinch commented Jan 16, 2019

Thanks for the PR! It appears the build is failing due to checkstyle errors. Can you please update the PR to have fixes for that? You can find the errors using ./gradlew checkstyleMain checkstyleTest.

@vpavic vpavic self-assigned this Jan 16, 2019
@vpavic
Copy link
Contributor

vpavic commented Jan 16, 2019

Thanks for the PR @niwostufe0. Can you clarify what's the exact scenario you're encountering this problem? A sample to reproduce the problem would be most helpful.

In Spring Session 1.3, it shouldn't be possible to hit a case where #entryRemoved gets an event with null old value - handling for this was added specifically in Spring Session 2.0 due to added support for change session id operation, which in HazelcastSessionRepository is implemented using IMap#delete that doesn't deserialize removed value to improve performance and hence doesn't have it available in the resulting event.

@vpavic vpavic added the status: waiting-for-feedback We need additional information before we can continue label Jan 16, 2019
@jtodt
Copy link
Author

jtodt commented Jan 16, 2019

Hi, it seems to happen only when the session run into its timeout, after e.g. 30 min inactivity. I understood the point with IMap#delete. But maybe the delete comes from hazelcast cluster itself before spring session module try to access the session by key and get a null for it. I‘m not that deep into the session timeout behavior and what’s happening exactly there but i‘ll try to isolate this problem more for you. We don‘t have this 100% reproducible but saw it several times on different test env‘s (3-40 Nodes) over the last week. I found topics from others with similar problems with redis. I can post the links here as well if you want? It is maybe a „deep“ interesting problem. I read more than once now „that there is no code path to null“ But there is one somehow and if we are lucky it’s a problem for multiple cache provider we can find here.

@jtodt
Copy link
Author

jtodt commented Jan 17, 2019

we run with hazelcast config

    <map name="spring:session:sessions">
        <backup-count>0</backup-count>
        <async-backup-count>1</async-backup-count>
        <max-idle-seconds>1800</max-idle-seconds>
        <in-memory-format>BINARY</in-memory-format>
        <eviction-policy>NONE</eviction-policy>
    </map>

maybe the <max-idle-seconds>1800</max-idle-seconds> could cause the problem ?
in the app we do

session.setMaxInactiveInterval(1800);

as well.

does spring session take care about timeouts it self and the cache provider should be configured to hold data endless?

@jtodt
Copy link
Author

jtodt commented Jan 17, 2019

side topic (small patch): i replaced IMap#delete with IMap#remove for better performance because return value won't be serialized/deserialized

@vpavic
Copy link
Contributor

vpavic commented Jan 17, 2019

Please don't change the scope of the PR before we even determined the root of the problem you're trying to address here - we need to IMap#remove in HazelcastSessionRepository#delete in order to support the session destroyed events.

@jtodt
Copy link
Author

jtodt commented Jan 17, 2019

ok understood. i reverted the last change. i'll try to implement an test to reproduce the NullPointerException.

@jtodt
Copy link
Author

jtodt commented Jan 29, 2019

Hi i think i have it now. It seems not to be a problem within the spring session module.
We call #IMap.delete(key) directly on the hazelcast IMap beside the HazelcastSessionRepository. This is the source of the Problem i think. We do this to simulate session timeouts in test environments. I'll rewrite this timeout simulation and use the HazelcastSessionRepository direcly to invalidate sessions. I think we can close this issue. Thanks for your time.

@jtodt jtodt closed this Jan 29, 2019
@jtodt jtodt deleted the 1.3.x branch January 29, 2019 08:30
@vpavic
Copy link
Contributor

vpavic commented Jan 29, 2019

Thanks for following up and letting us know @jtodt - glad to hear you had it resolved.

@vpavic vpavic added status: invalid and removed status: waiting-for-feedback We need additional information before we can continue labels Jan 29, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants