[2.3.1.Final] Errai keeps reconnecting ([errai] http session has expired. resetting bus and attempting reconnection.)

[wendro]

I did attach additional logging when I was playing with 3.0-SNAPSHOT and I see that errai keeps reconnecting in 2.3.1.Final.

[errai] http session has expired. resetting bus and attempting reconnection.

The full log from browser below:

[errai] http session has expired. resetting bus and attempting reconnection. LogUtil.java:45
[errai] wait for: org.jboss.errai.bus.client.framework.ClientMessageBus LogUtil.java:45
[errai] wait for: org.jboss.errai.bus.client.framework.RpcProxyLoader LogUtil.java:45
[errai] sending initial handshake to remote bus LogUtil.java:45
[errai] received response from initial handshake. LogUtil.java:45
[errai] remote services available: [ServerBus, pl.app.shared.service.EmailService:RPC, pl.app.shared.service.FolderService:RPC, 
pl.app.shared.service.DocumentService:RPC, pl.app.shared.service.SystemService:RPC, AuthenticationService, AuthorizationService, 
pl.app.shared.service.WorkflowService:RPC, pl.app.shared.service.UserService:RPC, pl.app.shared.service.GenericObjectService:RPC, 
ServerEchoService] LogUtil.java:45
[errai] received capabilities notice from server. supported capabilities of remote: LongPollAvailable LogUtil.java:45
[errai] initializing long poll subsystem LogUtil.java:45
[errai] vote For: org.jboss.errai.bus.client.framework.RpcProxyLoader LogUtil.java:45
[errai]   still waiting for -> [org.jboss.errai.bus.client.framework.ClientMessageBus] LogUtil.java:45
[errai] received FinishStateSync message. preparing to bring up the federation LogUtil.java:45
[errai] vote For: org.jboss.errai.bus.client.framework.ClientMessageBus LogUtil.java:45
[errai] received final vote for initialization ... LogUtil.java:45
[errai] executing 1 post init task(s) LogUtil.java:45
[errai] transmitting deferred messages now ... LogUtil.java:45
[errai] [error] failed to transmit deferred message: ToSubject=cdi.event:Dispatcher, CommandType=AttachRemote LogUtil.java:45
[errai]     -> no subscribers to deliver to for subject: cdi.event:Dispatcher LogUtil.java:45
[errai] bus federation complete. now operating normally. 

I did play with http session timoue. I have even set it to -1 in web.xml to not expire at all with no luck at all.

It does reconnect often:

13:44:09,386 INFO  [pl.app.web.client.Application] (http--0.0.0.0-8080-1) Errai Bus connected!
13:45:09,648 INFO  [pl.app.web.client.Application] (http--0.0.0.0-8080-1) Errai Bus connected!
13:46:09,876 INFO  [pl.app.web.client.Application] (http--0.0.0.0-8080-1) Errai Bus connected!
13:47:10,136 INFO  [pl.app.web.client.Application] (http--0.0.0.0-8080-4) Errai Bus connected!
13:48:10,389 INFO  [pl.app.web.client.Application] (http--0.0.0.0-8080-4) Errai Bus connected!
13:49:10,650 INFO  [pl.app.web.client.Application] (http--0.0.0.0-8080-1) Errai Bus connected!
13:50:10,916 INFO  [pl.app.web.client.Application] (http--0.0.0.0-8080-4) Errai Bus connected!

Any ideas how to make it stop?

[jfuerth]

Hi Michal,

This problem was caused by a bug in the server bus's QueueSession cleanup logic: when one QueueSession within a given HttpSession expired, all existing QueueSessions within that HttpSession were also killed. This has been fixed on the 3.0 branch, so the 3.0 M1 release that went out a week ago will not exhibit this problem.

We are also now planning to make a 2.4 release in the near future. It will also include this fix.

-Jonathan

[csa]

Hi Michal,

Just switching back to 2.3.0.Final should also solve this issue. I have now also backported the fix to the 2.3 branch and published new snapshots. So, 2.3.2-SNAPSHOT should also work!

Cheers,

Christian

[wendro]

The problem with reconnection is fixed in 3.0-SNAPSHOT - [3.0-SNAPSHOT] Problem with errai initialization .

I was to much consumed with testing ui and clicking through app, when I left it for a moment I encoutentered that the reconnection is still going - but in a slittly diffrent way

09:26:17,456 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: ClientBus : 60d6b799b9d8986784bb5f1091f3974cbfcbff95a6e7499d27cab0ef6060a4

09:26:17,457 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: SSEAgent : 60d6b799b9d8986784bb5f1091f3974cbfcbff95a6e7499d27cab0ef6060a4

09:26:17,458 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: ClientBusErrors : 60d6b799b9d8986784bb5f1091f3974cbfcbff95a6e7499d27cab0ef6060a4

09:26:17,460 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: ClientBus : 60d6b799b9d8986784bb5f1091f3974cbfcbff95a6e7499d27cab0ef6060a4

09:26:17,461 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: cdi.event:ClientDispatcher : 60d6b799b9d8986784bb5f1091f3974cbfcbff95a6e7499d27cab0ef6060a4

09:26:17,467 INFO  [pl.app.client.Application] (http--0.0.0.0-8080-2) Errai Bus connected!

09:28:18,697 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: ClientBus : 722041bd81239629d7329132c82e4f3ddf3d9b2317660bef737f9c08f934

09:28:18,697 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: SSEAgent : 722041bd81239629d7329132c82e4f3ddf3d9b2317660bef737f9c08f934

09:28:18,698 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: ClientBusErrors : 722041bd81239629d7329132c82e4f3ddf3d9b2317660bef737f9c08f934

09:28:18,699 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: ClientBus : 722041bd81239629d7329132c82e4f3ddf3d9b2317660bef737f9c08f934

09:28:18,699 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: cdi.event:ClientDispatcher : 722041bd81239629d7329132c82e4f3ddf3d9b2317660bef737f9c08f934

09:28:18,708 INFO  [pl.app.client.Application] (http--0.0.0.0-8080-2) Errai Bus connected!

09:31:19,938 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: ClientBus : dda6c12616f7e2f21d55fd563e849c8611d2effbb2851d6be80bd7fa54c895

09:31:19,939 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: SSEAgent : dda6c12616f7e2f21d55fd563e849c8611d2effbb2851d6be80bd7fa54c895

09:31:19,939 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: ClientBusErrors : dda6c12616f7e2f21d55fd563e849c8611d2effbb2851d6be80bd7fa54c895

09:31:19,940 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: ClientBus : dda6c12616f7e2f21d55fd563e849c8611d2effbb2851d6be80bd7fa54c895

09:31:19,941 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: cdi.event:ClientDispatcher : dda6c12616f7e2f21d55fd563e849c8611d2effbb2851d6be80bd7fa54c895

09:31:19,947 INFO  [pl.app.client.Application] (http--0.0.0.0-8080-2) Errai Bus connected!

09:33:21,188 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: ClientBus : 21fb7b6f66b9ebf870813118e51381fd2664454eef4d173a50a0ef27e59be2

09:33:21,189 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: SSEAgent : 21fb7b6f66b9ebf870813118e51381fd2664454eef4d173a50a0ef27e59be2

09:33:21,190 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: ClientBusErrors : 21fb7b6f66b9ebf870813118e51381fd2664454eef4d173a50a0ef27e59be2

09:33:21,190 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: ClientBus : 21fb7b6f66b9ebf870813118e51381fd2664454eef4d173a50a0ef27e59be2

09:33:21,191 INFO  [pl.app.server.common.errai.ErraiApplicationListener] (http--0.0.0.0-8080-5) bus subscribed: cdi.event:ClientDispatcher : 21fb7b6f66b9ebf870813118e51381fd2664454eef4d173a50a0ef27e59be2

09:33:21,202 INFO  [pl.app.client.Application] (http--0.0.0.0-8080-5) Errai Bus connected!

[errai] components failed to initialize 0.js:10673

[errai]    [failed] -> org.jboss.errai.enterprise.client.cdi.api.CDI 0.js:10673

[errai] SSE channel disconnected. 0.js:10673

[errai] the connection to the server has been interrupted ... 0.js:10673

[errai] attempting reconnection ...  0.js:10673

POST http://jasmine:8080/app/out.47247-22285.erraiBus?z=12&clientId=47247-22285 401 (Unauthorized) 0.js:3660

[errai] session expired while in state CONNECTION_INTERRUPTED: attempting to reset ... 0.js:10673

[errai] init polling system reset ... 0.js:10673

[errai] stopping bus ... 0.js:10673

[errai] bus initialization started ... 0.js:10673

[errai] wait for: org.jboss.errai.bus.client.api.ClientMessageBus 0.js:10673

[errai] bus initialization started ... 0.js:10673

[errai] wait for: org.jboss.errai.bus.client.api.ClientMessageBus 0.js:10673

[errai] session expired while in state LOCAL_ONLY: attempting to reset ... 0.js:10673

[errai] init polling system reset ... 0.js:10673

[errai] stopping bus ... 0.js:10673

[errai] bus initialization started ... 0.js:10673

[errai] wait for: org.jboss.errai.bus.client.api.ClientMessageBus 0.js:10673

[errai] bus initialization started ... 0.js:10673

[errai] wait for: org.jboss.errai.bus.client.api.ClientMessageBus 0.js:10673

[errai] sending handshake message to remote bus 0.js:10673

[errai] aborting startup. bus is not in correct state. (current state: CONNECTING) 0.js:10673

[errai] aborting startup. bus is not in correct state. (current state: CONNECTING) 0.js:10673

[errai] received handshake response from server. preparing to bring up the federation 0.js:10673

[errai] transitioning to new handler: SSE 0.js:10673

Sat Jun 15 09:26:17 GMT+200 2013 pl.app.client.Application

INFO: Errai Bus connected!