org.apache.shiro.session.ExpiredSessionException: Session with id异常排查

TomCosin

已于 2022-03-16 15:14:30 修改

阅读量2.6k

点赞数

分类专栏：疑难BUG 文章标签： apache java tomcat

于 2022-03-15 19:57:29 首次发布

本文链接：https://blog.csdn.net/TomCosin/article/details/123510615

版权

疑难BUG 专栏收录该内容

9 篇文章 2 订阅

订阅专栏

org.apache.shiro.session.ExpiredSessionException: Session with id异常排查

系统运行过程中报出异常

Caused by: org.apache.shiro.session.ExpiredSessionException: Session with id [aa21ba8b-7f3a-4236-a2f8-3b440524f55e] has expired. Last access time: 3/14/22 2:55 PM. Current time: 3/14/22 3:26 PM. Session timeout is set to 1800 seconds (30 minutes) at org.apache.shiro.session.mgt.SimpleSession.validate(SimpleSession.java:292) ~[shiro-core-1.6.0.jar:1.6.0] at org.apache.shiro.session.mgt.AbstractValidatingSessionManager.doValidate(AbstractValidatingSessionManager.java:186) ~[shiro-core-1.6.0.jar:1.6.0] at org.apache.shiro.session.mgt.AbstractValidatingSessionManager.validate(AbstractValidatingSessionManager.java:143) ~[shiro-core-1.6.0.jar:1.6.0] at org.apache.shiro.session.mgt.AbstractValidatingSessionManager.doGetSession(AbstractValidatingSessionManager.java:120) ~[shiro-core-1.6.0.jar:1.6.0] at org.apache.shiro.session.mgt.AbstractNativeSessionManager.lookupSession(AbstractNativeSessionManager.java:148) ~[shiro-core-1.6.0.jar:1.6.0] at org.apache.shiro.session.mgt.AbstractNativeSessionManager.lookupRequiredSession(AbstractNativeSessionManager.java:152) ~[shiro-core-1.6.0.jar:1.6.0] at org.apache.shiro.session.mgt.AbstractNativeSessionManager.getAttribute(AbstractNativeSessionManager.java:249) ~[shiro-core-1.6.0.jar:1.6.0] at org.apache.shiro.session.mgt.DelegatingSession.getAttribute(DelegatingSession.java:141) ~[shiro-core-1.6.0.jar:1.6.0] at org.apache.shiro.session.ProxiedSession.getAttribute(ProxiedSession.java:121) ~[shiro-core-1.6.0.jar:1.6.0] at org.apache.shiro.subject.support.DelegatingSubject.getRunAsPrincipalsStack(DelegatingSubject.java:473) ~[shiro-core-1.6.0.jar:1.6.0] at org.apache.shiro.subject.support.DelegatingSubject.getPrincipals(DelegatingSubject.java:157) ~[shiro-core-1.6.0.jar:1.6.0] at org.apache.shiro.subject.support.DelegatingSubject.getPrincipal(DelegatingSubject.java:153) ~[shiro-core-1.6.0.jar:1.6.0] at org.apache.shiro.web.servlet.ShiroHttpServletRequest.getSubjectPrincipal(ShiroHttpServletRequest.java:96) ~[shiro-web-1.6.0.jar:1.6.0] at org.apache.shiro.web.servlet.ShiroHttpServletRequest.getUserPrincipal(ShiroHttpServletRequest.java:112) ~[shiro-web-1.6.0.jar:1.6.0] at org.springframework.web.servlet.FrameworkServlet.getUsernameForRequest(FrameworkServlet.java:1159) ~[spring-webmvc-5.1.6.RELEASE.jar:5.1.6.RELEASE] at org.springframework.web.servlet.FrameworkServlet.publishRequestHandledEvent(FrameworkServlet.java:1144) ~[spring-webmvc-5.1.6.RELEASE.jar:5.1.6.RELEASE] at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1022) ~[spring-webmvc-5.1.6.RELEASE.jar:5.1.6.RELEASE] at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:908) ~[spring-webmvc-5.1.6.RELEASE.jar:5.1.6.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:648) ~[servlet-api.jar:?] at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:882) ~[spring-webmvc-5.1.6.RELEASE.jar:5.1.6.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:729) ~[servlet-api.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:292) ~[catalina.jar:8.0.51] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207) ~[catalina.jar:8.0.51] at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) ~[tomcat-websocket.jar:8.0.51] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240) ~[catalina.jar:8.0.51] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207) ~[catalina.jar:8.0.51] at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61) ~[shiro-web-1.6.0.jar:1.6.0] at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108) ~[shiro-web-1.6.0.jar:1.6.0] at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137) ~[shiro-web-1.6.0.jar:1.6.0] … 66 more

重点查看：SimpleSession.validate(SimpleSession.java:292)、FrameworkServlet.publishRequestHandledEvent(FrameworkServlet.java:1144)

产生原因

根据异常栈信息排查出业务逻辑链：接口在调用时（耗时大概20s），方法入栈后，shiro中的session在此时过期，方法出栈后，进入FrameworkServlet类调用发布事件方法publishRequestHandledEvent，（该方法用于请求完毕后发布请求事件，给开发人员提供扩展使用，如果没有该事件的订阅对象，这个时间不会产生影响）该方法需要获取session中信息，此时shiro进行校验时发现过期，抛出异常。

注：正常流程session在进入请求时会续期，但是由于项目情况特殊，报错请求的接口被续期排除，导致后续报错。

参考：

FrameworkServlet

/**
* FrameworkServlet为spring的抽象类，DispatcherServlet就是继承了他，这里在处理请求之后，发布了ServletRequestHandledEvent事件，错误就是构建事件时* getUsernameForRequest方法，导致shiro校验session抛出异常。
* Process this request, publishing an event regardless of the outcome.
* <p>The actual event handling is performed by the abstract
* {@link #doService} template method.
*/
protected final void processRequest(HttpServletRequest request, HttpServletResponse response)
    throws ServletException, IOException {

    long startTime = System.currentTimeMillis();
    Throwable failureCause = null;

    LocaleContext previousLocaleContext = LocaleContextHolder.getLocaleContext();
    LocaleContext localeContext = buildLocaleContext(request);

    RequestAttributes previousAttributes = RequestContextHolder.getRequestAttributes();
    ServletRequestAttributes requestAttributes = buildRequestAttributes(request, response, previousAttributes);

    WebAsyncManager asyncManager = WebAsyncUtils.getAsyncManager(request);
    asyncManager.registerCallableInterceptor(FrameworkServlet.class.getName(), new RequestBindingInterceptor());

    initContextHolders(request, localeContext, requestAttributes);

    try {
        doService(request, response);
    }
    catch (ServletException | IOException ex) {
        failureCause = ex;
        throw ex;
    }
    catch (Throwable ex) {
        failureCause = ex;
        throw new NestedServletException("Request processing failed", ex);
    }

    finally {
        resetContextHolders(request, previousLocaleContext, previousAttributes);
        if (requestAttributes != null) {
            requestAttributes.requestCompleted();
        }
        logResult(request, response, failureCause, asyncManager);
        publishRequestHandledEvent(request, response, startTime, failureCause);
    }
}

shiro的SimpleSession

/**
* shiro校验session代码
* 在许多流程中，shiro都会进行校验，如果有类似错误，基本都是由于shiro的校验引起
*/
public void validate() throws InvalidSessionException {
    //check for stopped:
    if (isStopped()) {
        //timestamp is set, so the session is considered stopped:
        String msg = "Session with id [" + getId() + "] has been " +
            "explicitly stopped.  No further interaction under this session is " +
            "allowed.";
        throw new StoppedSessionException(msg);
    }

    //check for expiration
    if (isTimedOut()) {
        expire();

        //throw an exception explaining details of why it expired:
        Date lastAccessTime = getLastAccessTime();
        long timeout = getTimeout();

        Serializable sessionId = getId();

        DateFormat df = DateFormat.getInstance();
        String msg = "Session with id [" + sessionId + "] has expired. " +
            "Last access time: " + df.format(lastAccessTime) +
            ".  Current time: " + df.format(new Date()) +
            ".  Session timeout is set to " + timeout / MILLIS_PER_SECOND + " seconds (" +
            timeout / MILLIS_PER_MINUTE + " minutes)";
        if (log.isTraceEnabled()) {
            log.trace(msg);
        }
        throw new ExpiredSessionException(msg);
    }
}