TL;DR We get @SessionScoped
注入的 bean 实例具有另一个会话的内容
最近,我们的两个客户系统遇到了严重问题。我们的客户在两台具有 Glassfish 4.0 服务器和 WELD 2.0.5 的机器上运行同一 JSF 2.2 应用程序的两个独立实例(向内存泄漏致敬!)。
一些用户报告了一些问题,例如提交表单后,响应会显示与最初登录的用户名不同的用户名。由于我们无法在开发和测试环境中重现此行为,因此我们开始从生产系统中获取日志数据。
我们记录了什么?
在我们的第一次尝试中,我们开始记录哪个用户在某个时间从哪个客户端执行了哪个操作。在爬行日志后,我们发现了这样的序列:
Time Client User Action
.............................
t=0 ClientA UserA Login
t=1 ClientA UserA Logoff
t=2 ClientB UserB Login
t=3 ClientB UserB ActionA
t=4 ClientB *UserA* ActionB
t=5 ClientB UserB Logoff
而替换用户的会话(此处User A
)在替换发生之前并不总是结束(有时会导致一个用户注销另一个用户......)。那么当前登录的用户存储在哪里呢?我们将其作为属性存储在@SessionScoped
豆子被注入@RequestScoped
任何我们需要这些信息的地方。这使我们得出这样的理论:@SessionScoped
豆子有时会混淆。
@Named
@javax.enterprise.context.SessionScoped
public class SessionStateBean {
private User user;
public void setUser(...) { }
public User getUser() { }
}
因此,在第二次尝试中,我们通过以下功能扩展了日志数据:
- 我们开始将用户名存储在 HTTP 会话中,并在每次请求时将其与来自
@SessionScoped
bean.
- 每个实例的
@SessionScoped
bean 收到自己的 UUID,并在 bean 被构造和销毁以及用户属性更改时记录。我们知道有可能@SessionScoped
beans 可以有多个代理、被钝化等,但我们尝试了一下。
关于第一个日志功能,我们开始看到序列显示来自会话作用域 bean 的用户名与存储在 HTTP 会话中的值之间的实际差异:
Time Session Client User Action
.............................
t=0 SessA ClientA UserA Login
t=1 SessA ClientA UserA Logoff
t=2 SessB ClientB UserB Login
t=3 SessB ClientB UserB ActionA
t=4 |SessB ClientB *UserA* ActionB
+-> SessionScope != Session
t=5 SessB ClientB UserB Logoff
考虑到正在处理的所有请求,会话范围值与会话值不匹配的请求大约有。 60 到 150 个请求中的 1 个。
更有趣的是发生了什么事@SessionScoped
bean 实例。既然我们正在追踪@PostConstruct
& @PreDestroy
观察到如下事件、序列:
Time Session Bean Action UserValue
................................
t=0 SessA BeanA Construct (null)
t=1 SessA BeanA SetUser UserA // login
t=2 SessA BeanA SetUser (null) // logout
t=3 SessA BeanA Destroy (null)
// so far so good, now it gets interesting
t=4 SessB BeanA SetUser UserB // login
t=5 SessB BeanA SetUser (null) // logout
t=6 SessC BeanA SetUser UserC // login
t=7 SessC BeanA SetUser (null) // logout
t=8 SessD BeanA SetUser UserD // login
t=9 SessD BeanA SetUser (null) // logout
我们没想到,有时之后@PreDestroy
事件bean实例获取reused无需经历建造和破坏的生命周期。考虑到所有记录的 bean 实例,大约会发生这种情况。 500 颗(系统 A)至 4000 颗(系统 B)中取出 1 颗。当会话范围值和 HTTP 会话值不同时,这种情况并不总是发生,但当我们看到这样的 bean 实例被重用时,总是发生在值不同时。
最初我们假设这些事件更有可能在服务器负载一段时间后发生,但事实证明并非如此。有时它们会在最后一次服务器重新启动后几个小时内发生,有时会在两周后发生。
在互联网上搜索这些问题时,我们无法找到其他人在 WELD 中遇到相同问题或已知错误的实际痕迹(最好的跟踪,但版本错误 https://issues.jboss.org/browse/WELD-1691)、玻璃鱼、灰熊 (最好的踪迹,但太旧了 https://java.net/jira/browse/GRIZZLY-954)、JSF 等
所以我们的问题是:有没有人遇到过类似的问题?这种奇怪的行为是否是我们刚刚试图在错误的位置识别的已知错误?有实际的修复吗?任何提示都很高兴!
Update:我们发现,如果重新启动整个机器,所描述的行为会消失大约两周。如果我们重新启动 Glassfish,几个小时后奇怪的行为就会再次出现。说真的,什么会对 Glassfish 或 JVM 产生如此严重的影响,以至于只有机器重新启动才能改变行为?
目前,我们通过将保存的所有数据放在@SessionScoped
bean 直接进入 HTTP 会话,到目前为止它似乎工作正常。但这种方法实在是太笨拙了……