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]

Reported by amplus@java.net

[glassfishrobot]

Issue-Links:
blocks
GRIZZLY-174

[glassfishrobot]

Was assigned to swchan2@java.net

[glassfishrobot]

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

[glassfishrobot]

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

[glassfishrobot]

swchan2@java.net said:
reassigned ...

[glassfishrobot]

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]

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]

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]

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]

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

[glassfishrobot]

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

[glassfishrobot]

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]

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]

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]

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

[glassfishrobot]

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