【问题标题】:How to hunt down obscure HA clustering bug in Wildfly 8.2.0.Final如何在 Wildfly 8.2.0.Final 中寻找模糊的 HA 集群错误
【发布时间】:2015-07-17 17:19:45
【问题描述】:

设置

我有一个 Wildfly 8.2.0.Final 应用服务器,它使用 full-ha 配置文件以域模式运行集群。该集群由 Wildfly 的两个实例组成,主实例和从属实例,每个实例都运行在自己的虚拟机上。

应用程序

我的项目被部署为应用服务器上的战争文件。出于测试目的,我的负载均衡器使用循环分配请求。

匿名用户可以通过一个按钮使用本项目提供的服务,该按钮将分两步调用,先注册然后登录。登录将使用在注册阶段创建的会话,并提供在注册调用期间创建的凭据。

实现

登录端点是一个请求范围的 CDI bean,在其他成员中,有一个成员保存用户信息。用户信息是一个 SessionScopped EJB Bean,它在会话实例化期间创建并注入到登录端点 CDI bean 中。用户信息应该在集群成员之间分发。

观察到的行为

现在有趣的部分:

  • 使用火狐:
    1. /rest/register -> 200 OK
    2. /rest/login -> 200 OK
  • 在私有模式下使用 Firefox:
    1. /rest/register -> 200 OK
    2. /rest/login -> 200 OK
  • 使用铬:
    1. /rest/register -> 200 OK
    2. /rest/login -> 200 OK
  • 在隐私模式下使用 Chrome:
    1. /rest/register -> 200 OK
    2. /rest/login -> 200 OK
  • 使用 Internet Explorer 11:
    1. /rest/register -> 200 OK
    2. /rest/login -> 200 OK
  • 在私密模式下使用 Internet Explorer 11:
    1. /rest/register -> 200 OK
    2. /rest/login -> 500 内部服务器错误

日志

这是 500 的堆栈跟踪:

    2015-05-07 10:05:31,734 ERROR [io.undertow.request] (default task-11) UT005023: Exception handling request to /testtest/rest/login: org.jboss.resteasy.spi.UnhandledException: java.lang.NullPointerException
        at org.jboss.resteasy.core.ExceptionHandler.handleApplicationException(ExceptionHandler.java:76) [resteasy-jaxrs-3.0.10.Final.jar:]
        at org.jboss.resteasy.core.ExceptionHandler.handleException(ExceptionHandler.java:212) [resteasy-jaxrs-3.0.10.Final.jar:]
        at org.jboss.resteasy.core.SynchronousDispatcher.writeException(SynchronousDispatcher.java:149) [resteasy-jaxrs-3.0.10.Final.jar:]
        at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:372) [resteasy-jaxrs-3.0.10.Final.jar:]
        at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:179) [resteasy-jaxrs-3.0.10.Final.jar:]
        at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:220) [resteasy-jaxrs-3.0.10.Final.jar:]
        at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56) [resteasy-jaxrs-3.0.10.Final.jar:]
        at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51) [resteasy-jaxrs-3.0.10.Final.jar:]
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [jboss-servlet-api_3.1_spec-1.0.0.Final.jar:1.0.0.Final]
        at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:61) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
        at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:56) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:45) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:63) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:58) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:70) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.security.handlers.SecurityInitialHandler.handleRequest(SecurityInitialHandler.java:76) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
        at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:261) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:247) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:76) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:166) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.server.Connectors.executeRootHandler(Connectors.java:197) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
        at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:759) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_65]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_65]
        at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_65]
Caused by: java.lang.NullPointerException
        at org.jboss.weld.context.beanstore.http.AbstractSessionBeanStore.getLockStore(AbstractSessionBeanStore.java:113) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
        at org.jboss.weld.context.beanstore.AttributeBeanStore.lock(AttributeBeanStore.java:210) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
        at org.jboss.weld.context.AbstractContext.get(AbstractContext.java:90) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
        at org.jboss.weld.context.PassivatingContextWrapper$AbstractPassivatingContextWrapper.get(PassivatingContextWrapper.java:76) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
        at org.jboss.weld.bean.proxy.ContextBeanInstance.getInstance(ContextBeanInstance.java:98) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
        at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:78) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
        at ru.exampl.testtest.lobby.UserController$Proxy$_$$_WeldClientProxy.toString(Unknown Source) [classes:]
        at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:106) [log4j-jboss-logmanager-1.1.0.Final.jar:1.1.0.Final]
        at org.apache.log4j.Category.forcedLog(Category.java:119) [log4j-jboss-logmanager-1.1.0.Final.jar:1.1.0.Final]
        at org.apache.log4j.Category.debug(Category.java:80) [log4j-jboss-logmanager-1.1.0.Final.jar:1.1.0.Final]
        at ru.exampl.testtest.rest.LobbyEndpoint.login(LobbyEndpoint.java:100) [classes:]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_65]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_65]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_65]
        at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_65]
        at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:137) [resteasy-jaxrs-3.0.10.Final.jar:]
        at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:296) [resteasy-jaxrs-3.0.10.Final.jar:]
        at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:250) [resteasy-jaxrs-3.0.10.Final.jar:]
        at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:237) [resteasy-jaxrs-3.0.10.Final.jar:]
        at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:356) [resteasy-jaxrs-3.0.10.Final.jar:]

代码

这是导致错误的相关代码(或者在它正常工作的情况下不是):

package ru.exampl.testtest.rest;

[... lots of imports ...]

/**
 * The implementation of some general webservice endpoints.
 */
@RequestScoped
@Path("rest")
public class LobbyEndpoint {

    private transient static final Logger log4j = Logger.getLogger(LobbyEndpoint.class);

    @Inject
    private UserController userController;

    [... more injections ...]

    @POST
    @Path("/login")
    @Consumes(MediaType.APPLICATION_JSON)
    @Produces(MediaType.APPLICATION_JSON)
    public LoginResponse login(LoginRequest request) {
        log4j.log(userController);
        [... lots of code to handle login ...]
    }
}

现在有趣的是,userController 显然不是空的,因为 log4j 知道如何处理和记录空对象。该对象显然有一个引用,但 Weld 无法通过代理访问它。如果没有浏览器列表,这本身就只有一半有趣了

其他信息

老实说,我不知道浏览器如何通过其请求引发这种行为。但为了让事情变得更有趣,我用 tshark 记录了实际的请求,然后修改了 Firefox 以发送与 Internet Explorer 11 发送的完全相同的请求。现在请屏住呼吸:在所有条件相同的情况下,Firefox 不会使 web 应用程序崩溃,而隐私模式下的 Internet Explorer 11 则 100% 的时间会崩溃。

我记录了两个请求以进行演示(您可以在wireshark中查看它们):

实际问题

现在我的问题是:我什至从哪里开始调试呢? 如果整个请求除了标头的顺序之外是相同的,那么 Web 浏览器如何通过代理传递其请求甚至对集群中我的会话同步的结果产生最轻微的影响,从而影响我的应用程序服务器上的请求处理?不涉及时间。在请求中引入随机等待并没有改变任何东西。

【问题讨论】:

  • 我无法查找,但我不会猜到 userController 为空。我猜想userControllertoString() 实现中的某些内容为空并引发此异常。
  • 不,这不可能是原因。我的实际实时代码首先没有此日志消息。我只在调试期间添加了它,同时抛出了越来越多可能的复杂性。例如,当使用 Firefox 调用时,日志消息将仅打印“指针”的值。所以 toString() 应该永远不会失败,除非堆上的地址本身是无效的。

标签: rest session cluster-computing wildfly weld


【解决方案1】:

我有一个类似的堆栈跟踪。但我忘了在 Wildfly 配置的 undertow 部分设置“instance-id”。只要服务器没有尝试复制会话,问题就没有出现。

所以对我来说,解决方案就是像这样设置一个实例 ID:

<subsystem xmlns="urn:jboss:domain:undertow:1.2" instance-id="${jboss.server.name}">

这也可以通过 jboss-cli 设置:

/profile=full-ha/subsystem=undertow:write-attribute(name=instance-id, value="${jboss.server.name}")

[编辑:试图找到解释]

NullpointerException 发生在以下语句中:

lockStore = (LockStore) session.getAttribute(SESSION_KEY);

在此语句中,仅当“会话”为空时才会发生 NPE。 “会话”对象是通过调用由子类实现的 getSession() 方法来获取的。我可以找到两个可能的候选人:

  • LazySessionBeanStore (org.jboss.weld.context.beanstore.http)
  • LazyCyclicSessionBeanStore (org.jboss.weld.context.beanstore.http)
  • EagerSessionBeanStore (org.jboss.weld.context.beanstore.http)

这对我来说并不明显,为什么这些类会为“会话”返回 null。以及这与在 untertow 部分中设置“instance-id”的关系。我可以看到,在这些地方创建了许多日志记录语句。为了更进一步,我会尝试在“org.jboss.weld”上将日志级别设置为“TRACE”。

【讨论】:

  • 我尝试了以下方法:/opt/wildfly-8.2.0.Final-DC/bin/./jboss-cli.sh --connect --command="/profile=full-ha/ subsystem=undertow:read-attribute(name=instance-id)" { "outcome" => "success", "result" => expression "${jboss.node.name}" } 这还不够吗?无论如何我会尝试你的建议。
  • 我不知道你的建议为什么有效。我什至找不到说明为什么它应该有所帮助的文档。但是我试过了,它确实有帮助。所以你显然满足了要求 A):可检验的假设。非常感谢您的宝贵时间。 50 个代表是你的。
  • 我试图开始一个可能的解释。但是失败了;)我真的不知道为什么会这样。目前,我没有系统可以重现这个。
猜你喜欢
  • 2015-04-25
  • 2015-12-12
  • 2015-10-24
  • 1970-01-01
  • 2015-10-09
  • 2019-12-09
  • 1970-01-01
  • 2016-09-03
  • 1970-01-01
相关资源
最近更新 更多