Spring-session: NullPointerException in sessionDestroyed listener

[bpapez]

We are using Spring Session version 1.1.1.RELEASE with Redis and sometimes see the following stacktrace in the log:

2016-04-20 11:07:33,986: ERROR [RedisOperationsSessionRepository] - Error publishing org.springframework.session.events.SessionExpiredEvent[source=org.springframework.session.data.redis.RedisOperationsSessionRepository@3ec0b82f].
java.lang.NullPointerException
       at org.springframework.session.web.http.ExpiringSessionHttpSession.getId(ExpiringSessionHttpSession.java:61)
       at org.jahia.bin.listeners.JahiaContextLoaderListener.sessionDestroyed(JahiaContextLoaderListener.java:446)
       at org.springframework.session.web.http.SessionEventHttpSessionListenerAdapter.onApplicationEvent(SessionEventHttpSessionListenerAdapter.java:62)
       at org.springframework.session.web.http.SessionEventHttpSessionListenerAdapter.onApplicationEvent(SessionEventHttpSessionListenerAdapter.java:40)
       at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:96)
       at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:334)
       at org.springframework.session.data.redis.RedisOperationsSessionRepository.publishEvent(RedisOperationsSessionRepository.java:557)
       at org.springframework.session.data.redis.RedisOperationsSessionRepository.handleExpired(RedisOperationsSessionRepository.java:549)
       at org.springframework.session.data.redis.RedisOperationsSessionRepository.onMessage(RedisOperationsSessionRepository.java:515)
       at org.springframework.data.redis.listener.RedisMessageListenerContainer.executeListener(RedisMessageListenerContainer.java:245)
       at org.springframework.data.redis.listener.RedisMessageListenerContainer.processMessage(RedisMessageListenerContainer.java:235)
       at org.springframework.data.redis.listener.RedisMessageListenerContainer$1.run(RedisMessageListenerContainer.java:960)
       at java.lang.Thread.run(Thread.java:745)

Is this a bug or an expected behaviour? Do we have to expect that NullPointerException or could it be prevented?

[rwinch]

@bpapez Thanks for the report!

As noted on the javadoc for getSession() it is possible for the Session to be null:

Gets the Session that was destroyed. For some SessionRepository implementations it may not be possible to get the original session in which case this may be null.

If you want to guarantee obtaining the session id, you can get it from getSessionId()

What is interesting is that you are getting a null value for the Redis implementation. As of 1.1 sessions created by Spring Session's Redis implementation should be be non-null. Did you by chance use Spring Session prior to 1.1? If so, the sessions that are null might be a session that was originally created before. In that case it would be expected that the session is null.

[bpapez]

No, we have never used Spring Session version prior to 1.1.0. That's the version we started with. We have just switched to 1.1.1 a week ago. Notice that we never got null on HttpSessionEvent.getSession(). However we get a NullPointerException, when calling getId() on that session object then.

[rwinch]

@bpapez Thanks for the response.

Notice that we never got null on HttpSessionEvent.getSession(). However we get a NullPointerException, when calling getId() on that session object then.

That is a good point. This looks like a bug, but I'm not certain what is causing it at the moment.

[LintelXu]

Got the same problem when using 1.2.1.RELEASE, have you solved it? @bpapez @rwinch

[bpapez]

@Lintel-X no, unfortunately I did not have time to work on it further.

[LintelXu]

@bpapez Thanks for your apply

[hellohol]

Got the same problem when using 1.2.2.RELEASE, have you solved it? @bpapez @rwinch @Lintel-X

[reavells]

Also on spring session 1.2.2 with this issue so interested in any future solutions...

[maxiagrace]

Got the same problem when using 1.3.0.RC1. Do you have a plan to resolve it ? @rwinch

[sudokai]

From time to time, it's happening to me in production as well, but I can't reproduce it in development. Otherwise, I could run a bisect.

[hobo05]

Also happening to me in production, but without the stacktrace for some reason, just NullPointerException

ERROR redisMessageListenerContainer-8045742 RedisOperationsSessionRepository - Error publishing org.springframework.session.events.SessionExpiredEvent[source=org.springframework.session.data.redis.RedisOperationsSessionRepository@4116df4b].
java.lang.NullPointerException

[Stefanus-Januar]

We use AWS elastic cache with redis and spring session 1.3.1

Every logout, we clear our user cache by listening sessionDestroyed event.

Same like the others, we could not reproduce in development.

Error publishing org.springframework.session.events.SessionDeletedEvent[source=org.springframework.session.data.redis.RedisOperationsSessionRepository@5d9ca152].
java.lang.NullPointerException: null
    at org.springframework.session.web.http.ExpiringSessionHttpSession.getAttribute(ExpiringSessionHttpSession.java:89)
    at com.mycompany.gateway.config.listener.SessionListener.sessionDestroyed(SessionListener.java:25)
    at org.springframework.session.web.http.SessionEventHttpSessionListenerAdapter.onApplicationEvent(SessionEventHttpSessionListenerAdapter.java:67)
    at org.springframework.session.web.http.SessionEventHttpSessionListenerAdapter.onApplicationEvent(SessionEventHttpSessionListenerAdapter.java:41)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:167)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:393)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:347)
    at org.springframework.session.data.redis.RedisOperationsSessionRepository.publishEvent(RedisOperationsSessionRepository.java:576)
    at org.springframework.session.data.redis.RedisOperationsSessionRepository.handleDeleted(RedisOperationsSessionRepository.java:558)
    at org.springframework.session.data.redis.RedisOperationsSessionRepository.onMessage(RedisOperationsSessionRepository.java:528)
    at org.springframework.data.redis.listener.RedisMessageListenerContainer.executeListener(RedisMessageListenerContainer.java:249)
    at org.springframework.data.redis.listener.RedisMessageListenerContainer.processMessage(RedisMessageListenerContainer.java:239)
    at org.springframework.data.redis.listener.RedisMessageListenerContainer$1.run(RedisMessageListenerContainer.java:967)
    at java.lang.Thread.run(Thread.java:748)
...

However at the same time (I can assure this is the same session), there is a success log for the similar event which trigger the same class (SessionListener)

Publishing event: org.springframework.security.web.session.HttpSessionDestroyedEvent[source=org.springframework.session.web.http.ExpiringSessionHttpSession@48804e7a]
POST request for "https://staging.mycompany.com/oauth/revoke-token" resulted in 200

From this log, I assume my listener is triggered 2 times with the same session

[vpavic]

I've taken a closer look at the code involved in this, and there's definitely a path for this NPE to occur.

The HttpSession that HttpSessionListeners are interacting with is implemented by ExpiringSessionHttpSession (note that this is HttpSessionAdapter in master/2.0) and this class can be constructed with null passed in place of Session. This will happen in SessionEventHttpSessionListenerAdapter#createHttpSessionEvent if null is returned from AbstractSessionEvent#getSession which is, as explained by @rwinch in one of previous comments, indeed possible.

Going further, Spring Session's event will be created without a reference to the actual Session object if there was no Session returned in RedisOperationsSessionRepository#onMessage which would indicate that the actual session record was deleted from Redis before the expiration/deletion event was processed.

All of you affected, I assume the production environment you're experiencing the problem in is a cluster with multiple active instances of the app and that the development environment where you cannot reproduce the problem is single instance?

[Stefanus-Januar]

Hi @vpavic thx for your feedback.

In my case, I have 2 instances (spring session) which are connected with same redis with different database spring.redis.database = 0 & spring.redis.database = 1, and also they have their own session.

Based on your feedback, i will try to validate the session.
Make sure no more NPE and get success message as well

@Slf4j
public class SessionListener implements HttpSessionListener {

    private Oauth2ClientService oauth2ClientService;

    public SessionListener(Oauth2ClientService oauth2ClientService) {
        this.oauth2ClientService = oauth2ClientService;
    }

    @Override
    public void sessionCreated(HttpSessionEvent se) {}

    @Override
    public void sessionDestroyed(HttpSessionEvent se) {
        if (se.getSession() != null ) {
            log.info("Start removing cache");
            log.info(se.getSession().getAttribute("Tenant").toString());
            oauth2ClientService.invalidateToken(se.getSession());
            log.info("Cache is removed successfully");
        }
    }
}

[vpavic]

Hi @Stefanus-Januar, thanks for providing feedback.

if (se.getSession() != null ) {

This won't help you - as explained above, the problem is that ExpiringSessionHttpSession, which implements HttpSession returned from HttpSessionEvent#getSession can be constructed with null delegate (see here).

This means that the session obtained from the event won't be null, but any invocation on its properties will lead to NPE since there's no delegate.

In my case, I have 2 instances (spring session) which are connected with same redis with different database spring.redis.database = 0 & spring.redis.database = 1, and also they have their own session.

Can you clarify this a bit? So effectively you don't have multiple apps sharing the same session store?

[vpavic]

Regarding the changes we need to make, for starters we need to ensure that ExpiringSessionHttpSession (HttpSessionAdapter in Session 2.0 i.e. master branch) cannot be constructed with null delegate Spring Session's session. This would imply that the subclasses of Spring Session's AbstractSessionEvent that only have a reference to sessionId but not entire Session cannot be used to generate HttpSessionEvent.

However we still need to figure out which sequence of actions causes null to be returned in RedisOperationsSessionRepository#onMessage.

Any thoughts on this @rwinch?

[Stefanus-Januar]

This means that the session obtained from the event won't be null, but any invocation on its properties will lead to NPE since there's no delegate.

You are right
(Please ignore the sequence due to timestamp precision)

Can you clarify this a bit? So effectively you don't have multiple apps sharing the same session store?

Yes

[vpavic]

We've made some improvements on this topic in 2.0.0.RC2 - see #939.
The changes that were made are basically what was described in my previous comment - the NPE reported in this issue shouldn't be possible any more, and we're detecting and logging the state that used to lead to NPE (see this).

That being said I'm still leaving this open as we didn't determine what's causing the session to be deleted from the store before the event is published. We'd appreciate if someone affected by this could give 2.0.0.RC2 a spin, preferably with org.springframework.session.data.redis.RedisOperationsSessionRepository and org.springframework.session.data.redis.RedisSessionExpirationPolicy loggers set to DEBUG level.

[vpavic]

I've forgot to drop a note here, recently released 1.3.2.RELEASE includes the changes described in previous comment - see #984. If anyone affected by this problem is able to provide feedback that would be appreciated.

[sudokai]

We see this problem fairly frequently. Will update and post back.

[vpavic]

If anyone affected here is using multiple databases within the same Redis instance please take a look at #1128 as the issue should be resolved.

Otherwise, we'd still like to see more input that would help us get to the bottom of this.

[spring-projects-issues]

If you would like us to look at this issue, please provide the requested information. If the information is not provided within the next 7 days this issue will be closed.

[spring-projects-issues]

Closing due to lack of requested feedback. If you would like us to look at this issue, please provide the requested information and we will re-open the issue.