Grizzly doesn't seem to hold a long polling request

[glassfishrobot]

I’m trying to port an existing Jetty Bayeux java client to work with Grizzly. I’m using the demo chat application since that has been ported from Jetty already.

Here is my dilemma:

When running against Jetty server the handshake connection goes something like this:

Client Server Handshake Handshake reply successful Connect(/meta/connect) Connect reply successful Connect(/meta/connect) Jetty holds on to the Request -> long polling Publish etc...

When I run the same code against Grizzly it goes like this: Client Server Handshake Handshake reply successful Connect(/meta/connect) Connect reply successful Connect(/meta/connect) Connect reply successful Connect(/meta/connect) Connect reply successful

Etc... until the client crashes. Grizzly doesn't seem to hold on to the long polling request.

I have tried modifying my code so that the java client stops connecting after the first successful connect reply, then I am able to publish messages but I'm not receiving any pushes from other clients connected to the chat since the initial connect isn't being held by the server. I find this a bit odd since the web based chat client works fine. Below is a copy of the conversations

---

Jetty client Jetty Server (working):

2008-07-23 18:58:23.864::INFO: Request: message=[{"version": "1.0", "minimumVersion": "0.9", "channel": "/meta/handshake", "id": "0", "ext": {"json-comment-filtered": true}}] 2008-07-23 18:58:23.083::INFO: Response: [{"id":"0","minimumVersion":"0.9","supportedConnectionTypes":["long-polling","callback-polling"],"successful":true,"channel":"/meta/handshake","advice":

{"reconnect":"retry","interval":0,"timeout":120000}

,"clientId":"1mrrarg95sbvv8u0gg","version":"1.0"}]

2008-07-23 18:58:23.03::INFO: Request: message=

{"channel":"/meta/connect","clientId":"1mrrarg95sbvv8u0gg","connectionType":"long-polling"}

2008-07-23 18:58:23.018::INFO: Response: [{"successful":true,"advice":

{"reconnect":"retry","interval":0,"timeout":120000}

,"channel":"/meta/connect"}]

2008-07-23 18:58:23.018::INFO: Request: message=

{"channel":"/meta/connect","clientId":"1mrrarg95sbvv8u0gg","connectionType":"long-polling"}

// HOLDS LONG POLLING REQUEST

2008-07-23 18:58:34.639::INFO: Request: message=[

{"subscription":"/chat/demo","channel":"/meta/subscribe","clientId":"1mrrarg95sbvv8u0gg"}

,{"id":"1216839514703","data":

{"user":"GrizzlyClient","join":true,"chat":"GrizzlyClient has joined"}

,"channel":"/chat/demo","clientId":"1mrrarg95sbvv8u0gg"}]

2008-07-23 18:58:34.654::INFO: Response: [

{"successful":true,"subscription":"/chat/demo","channel":"/meta/subscribe"}

,

{"id":"1216839514703","successful":true,"channel":"/chat/demo"}

,

{"id":"1216839514703","data":["GrizzlyClient"],"channel":"/chat/demo"}

,{"data":

{"chat":"GrizzlyClient has joined","join":true,"user":"GrizzlyClient"}

,"id":"1216839514703","channel":"/chat/demo"}]

2008-07-23 18:58:45.101::INFO: Request: message=[{"id":"1216839525437","data":

{"user":"GrizzlyClient","chat":"Hello"}

,"channel":"/chat/demo","clientId":"1mrrarg95sbvv8u0gg"}] 2008-07-23 18:58:45.116::INFO: Response: [

{"id":"1216839525437","successful":true,"channel":"/chat/demo"}

,{"data":

{"chat":"Hello","user":"GrizzlyClient"}

,"id":"1216839525437","channel":"/chat/demo"}]

2008-07-23 18:58:53.924::INFO: Request: message=[{"id":"1216839533468","data":{"user":"GrizzlyClient","leave":true,"chat":"Grizzly client has 2008-07-23 18:58:53.940::INFO: Response: [

{"id":"1216839533468","successful":true,"channel":"/chat/demo"}

,{"data":

{"leave":true,"chat":"Grizzly client has left","user":"GrizzlyClient"}

,"id":"1216839533468","channel":"/chat/demo"}]

2008-07-23 18:58:53.940::INFO: Request: message=[

{"subscription":"/chat/demo","channel":"/meta/unsubscribe","clientId":"1mrrarg95sbvv8u0gg"}

,

{"channel":"/meta/disconnect","clientId":"1mrrarg95sbvv8u0gg"}

] 2008-07-23 18:58:53.940::INFO: Response: [

{"successful":true,"channel":"/meta/connect"}

]

---

Jetty client Grizzly server (not working)

2008-07-23 16:58:28.659::INFO: Request: message=[{"version": "1.0", "minimumVersion": "0.9", "channel": "/meta/handshake", "id": "0", "ext": {"json-comment-filtered": true}}] 2008-07-23 16:58:29.971::INFO: Response: /*[{"channel":"/meta/handshake","version":"1.0","supportedConnectionTypes":["long-polling","callback-polling"],"minimumVersion":"0.9","id":"0","clientId":"72daf174eac043c1","successful":true,"advice":

{"reconnect":"retry","interval":0,"multiple-clients":false}

,"authSuccessful":true}]*/

2008-07-23 16:58:29.050::INFO: Request: message=

{"channel":"/meta/connect","clientId":"72daf174eac043c1","connectionType":"long-polling"}

2008-07-23 16:58:29.050::INFO: Response: /*[{"channel":"/meta/connect","clientId":"72daf174eac043c1","successful":true,"advice":

{"reconnect":"retry","interval":0,"multiple-clients":false}

,"timestamp":"Wed, 23 Jul 2008 16:58:29 GMT"}]*/

2008-07-23 16:58:29.050::INFO: Request: message=

{"channel":"/meta/connect","clientId":"72daf174eac043c1","connectionType":"long-polling"}

2008-07-23 16:58:29.096::INFO: Response: /*[{"channel":"/meta/connect","clientId":"72daf174eac043c1","successful":true,"advice":

{"reconnect":"retry","interval":0,"multiple-clients":false}

,"timestamp":"Wed, 23 Jul 2008 16:58:29 GMT"}]*/

2008-07-23 16:58:29.096::INFO: Request: message=

{"channel":"/meta/connect","clientId":"72daf174eac043c1","connectionType":"long-polling"}

2008-07-23 16:58:29.096::INFO: Response: /*[{"channel":"/meta/connect","clientId":"72daf174eac043c1","successful":true,"advice":

{"reconnect":"retry","interval":0,"multiple-clients":false}

,"timestamp":"Wed, 23 Jul 2008 16:58:29 GMT"}]*/

Environment

Operating System: Windows XP Platform: PC

Affected Versions

[1.8.0]

[glassfishrobot]

• Issue Imported From: https://github.com/javaee/grizzly/issues/217
• Original Issue Raised By:@glassfishrobot
• Original Issue Assigned To: @glassfishrobot
• Original Issue Closed By:@glassfishrobot

[glassfishrobot]

@glassfishrobot Commented Reported by amplus@java.net

[glassfishrobot]

@glassfishrobot Commented amplus@java.net said: Created an attachment (id=11) Console test client, unzip and see README.txt

[glassfishrobot]

@glassfishrobot Commented swchan2@java.net said: reassigned ...

[glassfishrobot]

@glassfishrobot Commented swchan2@java.net said: I think there is an issue for the client. I have downloaded the jetty 6.1.11 and then recompiled the test code with lines corresponding client.isInitialized() commented out as the jetty 6.1.11 does not have that method. Then it works without the infinite loop.

[glassfishrobot]

@glassfishrobot Commented amplus@java.net said: This is true I added the isInitialized() method but I don't understand how that method can cause this since it's just a simple getter. I removed it like you did and it did not make any difference for me. How can it be a client issue when almost exactly the same messages are being exchanged (see messages in my original issue report). Pretty much the only difference is that the Grizzly messages are json commented.

If you take the Jetty client 6.11 from source and run it against Grizzly it does not work since the Jetty client chokes on json commented messages. I'm running a modified Jetty client (attached to issue) against Grizzly (modified to support json commented messages and to always send x-www-form-urlencoded messages as opposed to text/json which Grizzly doesn't seem to like). I just downloaded a new snapshot of Grizzly (1.8.5) and it doesn't make any difference for me, the infinite loop problem is still there.

[glassfishrobot]

@glassfishrobot Commented swchan2@java.net said: If I use the attached modified Jetty client, then I still see the infinite loop even when Grizzly return JSON "without comments". I also notice that the client jar is using Jetty 6.1.

[glassfishrobot]

@glassfishrobot Commented swchan2@java.net said: I have discussed with amplus the Jetty client used having several modifications. I have downloaded the Jetty src 6.1.11 and then put two of the modifications as follows: diff BayeuxClient.java.orig BayeuxClient.java 73c73 < private boolean _formEncoded; —

private boolean _formEncoded = true;

diff MessagePool.java MessagePool.java.orig 140c140 < Object batch=_batchJSON.parse(new JSON.StringSource(s), true); —

Object batch=_batchJSON.parse(new JSON.StringSource(s));

Then I wrote a client that used Jetty 1.6.11 (see attachment) and notice the following: 1. It is ok to send a message to chat comet example through java client. One can see the message if there is already a browser client connected. 2. If we send the message through the browser, then the java client do get the message. In other words, the there is a connection between server and Jetty client.

3. The java client will fail with the following error when we invoke publish two times consecutively. In order to debug this, I start one client client first, and then the other clients (with two messages or more). The I see the following:

java.lang.IllegalStateException: unexpected end of array at org.mortbay.util.ajax.JSON.parseArray(JSON.java:858) at org.mortbay.util.ajax.JSON.parse(JSON.java:709) at org.mortbay.util.ajax.JSON.parse(JSON.java:637) at org.mortbay.cometd.MessagePool.parse(MessagePool.java:140) at org.mortbay.cometd.client.BayeuxClient$Exchange.onResponseComplete(BayeuxClient.java:476) at org.mortbay.cometd.client.BayeuxClient$Connect.onResponseComplete(BayeuxClient.java:598) at org.mortbay.jetty.client.HttpExchange.setStatus(HttpExchange.java:127) at org.mortbay.jetty.client.HttpConnection$Handler.messageComplete(HttpConnection.java:434) at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:678) at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:205) at org.mortbay.jetty.client.HttpConnection.handle(HttpConnection.java:240) at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:395) at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:488)

When I try to print the message received, I get the following: /*|||[

{"channel":"/meta/connect","clientId":"c36d4a0839e42ade","successful":true,"timestamp":"Mon, 11 Aug 2008 21:42:07 GMT"}

, {"channel":"/chat/demo","data":

{"user":"swchan2","chat":"message 0"}

,"id":"1218491019800","clientId":"7c9af3b137e8ffe3"}

Then this explains the failure. It is only a partial response. In other words, the client starts processing the response and throws exception before getting all the data.

I also find that if I put a sleep of 500 ms between consecutive clients, then everything work. It is because the client will not aggregate two requests into one.

[glassfishrobot]

@glassfishrobot Commented swchan2@java.net said: Created an attachment (id=12) A Jetty 6.1.11 Client

[glassfishrobot]

@glassfishrobot Commented amplus@java.net said: The client will aggregate the requests if you put startBatch() and endBatch() outside the for loop. You said:

2. If we send the message through the browser, then the java client do get the message. In other words, the there is a connection between server and Jetty client.

Are you doing this with the attached client against Grizzly or Jetty server?

[glassfishrobot]

@glassfishrobot Commented amplus@java.net said: I finally got off my rear and tested Shing-Wai's client which is attached to this issue. I can confirm that it does indeed receive messages from other clients and is working fine if the Jetty client code is changed according to post from Mon Aug 11 20:59:00 +0000 2008 by swchan2.

However I haven't figured out why this client works but not the one I was using. But at least we can see that the problem doesn't lie with Grizzly.

[glassfishrobot]

@glassfishrobot Commented amplus@java.net said: I have just found out what the problem is. The endless loop comes if I start the Bayeux client without subscribing. In other words:

1. If I do:

client = new BayeuxClient(http,address,uri); client.start();

and then wait for user input to tell it to subscribe, the client goes into an endless connect loop.

2. If I do: client = new BayeuxClient(http,address,uri); client.start(); client.subscribe("/chat/demo");

Everything works fine.

In other words, Grizzly doesn't like it if we don't subscribe right after a connect. Would you consider this to be a bug?

I also tried doing client = new BayeuxClient(http,address,uri); client.start(); client.subscribe("/chat/demo"); client.unsubscribe("/chat/demo");

which worked fine without the connect loop. One other thing I noticed, If I do a disconnect after I unsubscribe, Grizzly doesn't seem to drop the client state since I can do a subscribe right after. Actually the Jetty client does a connect right after the Disconnect msg is sent which is probably a bug, it should stop polling in my opinion, but that doesn't change the fact that Grizzly should clean up all client state after a disconnect, shouldn't it? Maybe this issue is the same as in: https://grizzly.dev.java.net/issues/show_bug.cgi?id=221

[glassfishrobot]

@glassfishrobot Commented File: CLClient.java Attached By: swchan2@java.net

[glassfishrobot]

@glassfishrobot Commented File: GrizzlyClient.zip Attached By: amplus@java.net

[glassfishrobot]

@glassfishrobot Commented Issue-Links: blocks GRIZZLY-174

[glassfishrobot]

@glassfishrobot Commented Was assigned to swchan2@java.net

[glassfishrobot]

@glassfishrobot Commented This issue was imported from java.net JIRA GRIZZLY-217

[glassfishrobot]

@glassfishrobot Commented Marked as cannot reproduce on Wednesday, December 16th 2009, 6:13:23 pm