Intermittent push issue with dynamic endpoint

UI Components for JSF
Post Reply
BruceK
Posts: 4
Joined: 21 Jun 2017, 22:12

21 Jun 2017, 22:32

We are running into an issue that slowly gets worse and worse over a 2-3 day period. We have a single push channel per user setup as "/session/#{id}" and a p:socket with a channel of "/session/#{username}". This seems to work fine at first. Looking at logs all Broadcasters are created correctly and work fine. Over time though the channel "/session/#{username}" gets mapped to broadcaster "/session/" instead of broadcaster "/session/#{username}". In order to fix this we have to recycle the servers. The EL variable #{username} is getting resolved correctly as when I do a network trace the end of the URI is /session/[username]?... The issue is that when itgoes to associate the atmosphere resource it just gets mapped to "/session/" I have not been able to determine what additional logging would show me why this is happening. It works fine for a day or 2 and then just starts having issues and "/session/" starts taking along time I am guessing due to a backlog of push requests across a single broadcaster that is not working properly.

Here is a sample from the logs on one of our clustered servers that this issue is appearing on VERY frequently
The following should map to /session/KIPER, but its mapping to /session/ instead


2017-06-21 12:57:43,503 TRACE::::KIPER: Query String translated to headers {X-Atmosphere-Framework=2.3.1-javascript, X-Atmosphere-Transport=long-polling, X-Atmosphere-TrackMessageSize=true, X-atmo-protocol=true, X-Atmosphere-tracking-id=d4405a5d-ab49-4369-bd21-77d08991d14b, _=1498075063512}: org.atmosphere.cpr.AtmosphereFramework.configureQueryStringAsRequest(AtmosphereFramework.java:2500)
2017-06-21 12:57:43,505 TRACE::::KIPER: Checking cached message for d4405a5d-ab49-4369-bd21-77d08991d14b: org.atmosphere.cpr.DefaultBroadcaster.retrieveTrackedBroadcast(DefaultBroadcaster.java:1035)
2017-06-21 12:57:43,505 TRACE::::KIPER: Associating AtmosphereResource d4405a5d-ab49-4369-bd21-77d08991d14b with Broadcaster /session/: org.atmosphere.cpr.DefaultBroadcaster.cacheAndSuspend(DefaultBroadcaster.java:1415)
2017-06-21 12:57:43,505 TRACE::::KIPER: Excluded from /session/ : d4405a5d-ab49-4369-bd21-77d08991d14b: org.atmosphere.cpr.DefaultBroadcaster.removeAtmosphereResource(DefaultBroadcaster.java:1508)
2017-06-21 12:57:43,505 TRACE::::KIPER: Removing AtmosphereResource d4405a5d-ab49-4369-bd21-77d08991d14b for Broadcaster /session/: org.atmosphere.cpr.DefaultBroadcaster.removeAtmosphereResource(DefaultBroadcaster.java:1519)
2017-06-21 12:57:43,506 TRACE::::KIPER: Checking cached message for d4405a5d-ab49-4369-bd21-77d08991d14b: org.atmosphere.cpr.DefaultBroadcaster.retrieveTrackedBroadcast(DefaultBroadcaster.java:1035)



Same exact code on a different server within the cluster that seems to be more stable, but still experiences the same issues every once in awhile has the following log which is correct. It is properly mapped to /session/KACA


2017-06-21 12:58:37,347 TRACE::::KACA: Query String translated to headers {X-Atmosphere-Framework=2.3.1-javascript, X-Atmosphere-Transport=long-polling, X-Atmosphere-TrackMessageSize=true, X-atmo-protocol=true, X-Atmosphere-tracking-id=3ee739f8-cbb8-434d-9665-c685f7c3835a, _=1498075117277}: org.atmosphere.cpr.AtmosphereFramework.configureQueryStringAsRequest(AtmosphereFramework.java:2500)
2017-06-21 12:58:37,349 TRACE::::KACA: Checking cached message for 3ee739f8-cbb8-434d-9665-c685f7c3835a: org.atmosphere.cpr.DefaultBroadcaster.retrieveTrackedBroadcast(DefaultBroadcaster.java:1035)
2017-06-21 12:58:37,349 TRACE::::KACA: Associating AtmosphereResource 3ee739f8-cbb8-434d-9665-c685f7c3835a with Broadcaster /session/KACA: org.atmosphere.cpr.DefaultBroadcaster.cacheAndSuspend(DefaultBroadcaster.java:1415)
2017-06-21 12:58:37,349 TRACE::::KACA: Excluded from /session/KACA : 3ee739f8-cbb8-434d-9665-c685f7c3835a: org.atmosphere.cpr.DefaultBroadcaster.removeAtmosphereResource(DefaultBroadcaster.java:1508)
2017-06-21 12:58:37,350 TRACE::::KACA: Removing AtmosphereResource 3ee739f8-cbb8-434d-9665-c685f7c3835a for Broadcaster /session/KACA: org.atmosphere.cpr.DefaultBroadcaster.removeAtmosphereResource(DefaultBroadcaster.java:1519)
2017-06-21 12:58:37,350 TRACE::::KACA: Checking cached message for 3ee739f8-cbb8-434d-9665-c685f7c3835a: org.atmosphere.cpr.DefaultBroadcaster.retrieveTrackedBroadcast(DefaultBroadcaster.java:1035)
2017-06-21 12:58:37,350 TRACE::::KACA: Associating AtmosphereResource 3ee739f8-cbb8-434d-9665-c685f7c3835a with Broadcaster /session/KACA: org.atmosphere.cpr.DefaultBroadcaster.cacheAndSuspend(DefaultBroadcaster.java:1415)

BruceK
Posts: 4
Joined: 21 Jun 2017, 22:12

23 Jun 2017, 21:37

Found one issue. EventBus is not threadsafe due to MetaBroadcaster in Atmosphere not being thread safe. I ran 300 push requests async through EventBus and between 10-20 actually made it through to the browser. Used @Inject to grab Atmosphere BroadcasterFactory so I can do a straight lookup and directly call broadcast on Broadcaster and all 300 push requests made it through to the browser with and faster then the 10-20 using EventBus made it in.

Still digging in to see why Atmosphere resources are being assigned to the parent broadcaster "/session/" instead of the appropriate broadcaster "/session/#{username}" JavaScript url/channel is properly calling "/session/#{username}"

BruceK
Posts: 4
Joined: 21 Jun 2017, 22:12

28 Jun 2017, 15:31

Associating Atmosphere Resource to /session/ as opposed to /session/#{username} appears to be an issue only on a single server and the strange thing is that not all Atmosphere resources are assigned to /session/. Only some of them get assigned to /session/ with the others properly assigned to /session/#{username} as expected. At this point we are down to a single server and intermittent issues. Its session based intermittent as well. If a user resource is assigned to /session/ it will be assigned to that the entire time and if it gets assigned to /session/#{username} it will always hit the correct broadcaster.

Same codebase is pushed out to all our clustered instances. We are running JBoss EAP 6.4 with 4 app servers clustered horizontally and vertically. Trying to debug the path to see where this issue could occur as well as a fix to this. We are tempted to just ditch PrimePush and go straight to atmosphere as it is causing lots of client issues.

BruceK
Posts: 4
Joined: 21 Jun 2017, 22:12

21 Jul 2017, 17:22

I have finally found the issue and entered an atmosphere defect.

Basically whats happening is that due to our security and filters in place there is a split instance where a request can come through with just "primepush/session/". Atmosphere then creates an endpoint handler map entry for the base dynamic endpoint in this case its /session/[a-zA-Z0-9-&\.*_~=@;\\?]+. Once this happens, due to the logic in atmosphere DefaultEndpointMapper, anytime a valid request comes in that has not been mapped it falls back to this /session/[a-zA-Z0-9-&\.*_~=@;\\?]+ mapping.

Scenario
"primepush/session/User1" request comes through and handler gets mapped to "/session/User1"
"primepush/session/" request comes through due to a split second disconnect between our security and our filter picking up a dead session and handler gets mapped to "/session/[a-zA-Z0-9-&\.*_~=@;\\?]+"
"primepush/session/User2" request comes through. DefaultEndpointMapper runs through the list and finds that since an exact match found nothing it does a second level match which picks up "/session/[a-zA-Z0-9-&\.*_~=@;\\?]+" and maps it

Once this happens any request that comes through that doesn't have a mapping gets mapped to /session/[a-zA-Z0-9-&\.*_~=@;\\?]+ as opposed to the appropriate "/session/#{id}" based on request.

We can run for a couple days before this issue crops up and causes all push requests to stop working for any user that did not previously log into that node.

Post Reply

Return to “PrimeFaces”

  • Information