First handshake times out resulting callback polling.

[Glenn Thompson]

Hi,

Quick background:
I've  been using Cometd 2.4 happily for well over a year.  Recently, I was forced to get my application working in Tomcat 7.  Specifically Tomcat 7.0.42
I thought I had it working, however I get illegal state exceptions that would require me to restart Tomcat to recover.  So I decided to upgrade to 2.6 before posting to the list.  Knowing Tomcat is not the ideal environment, I figured I need the latest code to have a chance.

I'm having difficulty getting my application to run under 2.6.  My development environment does not involve Tomcat at all.  I use the jetty maven plug-in and I run Jetty 8.1.1.v20120215.   I have a custom Service that I wire using annotations.  I had to make a few import changes for the cometd annotations and I have upgraded to jquery 1.9.1.  I have double checked that I'm including 2.6 js files as well.  In my development environment I run the Comet Service on a separate instance/port from the application servlet so, jsonp kicks in and I see no issues there.  However, I can't get a long-polling connection.  The initial handshake request is sent with ["long-polling", "callback-polling"] but it times out and then the second is sent with only "callback-polling".  That succeeds.  It *appears* to long-poll until a second tab hits the service.   Then the last tab in seems to long-poll and the first tab begins making back to back connect requests with no delay.  This appears to be driven by the interval parameter which I have set to 0.  When I set it to 2000 the requests were 2 seconds a part.  I'm puzzled why that parameter drives this behaviour as the connect request is for callback-polling.  I turned on the request log for the jetty plug-in.  The first handshake request does not show up in the request log so I guess it makes sense that the original request times out.  I should mention that I manually configure BayeuxServerImpl. I set only options and allowedTransports.  Do I need to manually set the transports themselves?  I hadn't done that previously.

Any ideas about the potential cause?
Any specific details needed to help clarify my environment?

Thanks,
Glenn

[Glenn Thompson]

Hi,

I'm going to keep posting more details in hope that someone can bail me out here:-) 

I forgot to mention that I connect to my comet servlet both via (ssl using user certs) and (non ssl from my application servlet).  The details of which are application related but I can elaborate if needed.  

The initial handshake request times out with a readyState = 0, responseText = "", status = 0, statusText = "error".  Not much info coming back from the request.  The network tab in firebug shows that the request has been aborted.  So I wasn't able to click into the request to see the request itself.  However, I switched over to chrome   Dev tools which also shows an abort, however I was able to see more of the request:

1. Request URL:
   https://localhost:8081/rexgrp/cometsrv/cometd/handshake
2. Request Headersview parsed
1. OPTIONS https://localhost:8081/rexgrp/cometsrv/cometd/handshake HTTP/1.1 Access-Control-Request-Method: POST Origin: https://localhost:9292 Referer: https://localhost:9292/rexgrp/sampleapps/DevTools.jsp?debug=true User-Agent: Mozilla/5.0 (X11; Linux i686) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/29.0.1547.76 Safari/537.36 Access-Control-Request-Headers: accept, origin, content-type

But what puzzles me is that the request as its shown in the summary list of requests shows the Method as OPTIONS and notice that no Request Method: GET/POST  is shown like for regular requests. Do I need to configure Jetty to accept OPTIONS requests?  I know I've had issues with REPORT passing through reverse proxies.

Thanks,

Glenn

[Simone Bordet]

Hi,

Great troubleshooting.

What you are experiencing is a cross domain request, which indeed
fires a under-the-covers OPTIONS request.
You probably downloaded the cometd.js file from http:// url and trying
to connect to https:// or to a different domain.
This results in a cross domain call, and you need to configure the
server for that, otherwise the browser does not allow you to open a
XMLHttpRequest to that server (and that's why you fall back to
callback-polling).

Jetty ships a portable Servlet filter that you can use, see
http://docs.cometd.org/reference/#java_server_configuration, the
section about the CrossOriginFilter.
You can use the filter in Tomcat too, but we're happier if you stick
with Jetty :)

Let us know if configuring the CrossOriginFilter did it for you.

--
Simone Bordet
----
http://cometd.org
http://webtide.com
http://intalio.com
Developer advice, training, services and support
from the Jetty & CometD experts.
Intalio, the modern way to build business applications.

[Glenn Thompson]

Thanks Simone,

I thought I have it configured.  But I'll double check that,  I just recently went to Spring Security and I must have messed up the configuration of that filter.

I'll post back when I get it nailed.

I much prefer Jetty for sure.  But bureaucracies are tough to get past:-)

Thanks,

Glenn

[Glenn Thompson]

Hi,

Still no luck under development env. 

Item 1:

I *was* configured to use the cross-origin filter.  But only for the Comet Servlet.  Is that a problem? Originally I used the default init params.

my latest config looks like so:

<filter>

<filter-name>cross-origin</filter-name>

<filter-class>org.eclipse.jetty.servlets.CrossOriginFilter</filter-class>

<async-supported>true</async-supported>

<init-param>

<param-name>allowedMethods</param-name>

<param-value>GET,POST,HEAD,OPTIONS,PUT</param-value>

</init-param>

<init-param>

<param-name>allowedHeaders</param-name>

<param-value>Content-Type,X-Requested-With,accept,Origin,Access-Control-Request-Method,Access-Control-Request-Headers</param-value>

</init-param>

<init-param>

<param-name>allowCredentials</param-name>

<param-value>true</param-value>

</init-param>

</filter>

<filter-mapping>

<filter-name>cross-origin</filter-name>

<url-pattern>/cometd/*</url-pattern>

</filter-mapping>

I have also tried to add this filter to my SpringSecurity chain, I used the default settings in that case.  I will need to write a FilterConfig class to provide init parameters.  I probably need that anyway given I've started using SpringSecurity and, at some point, I will probably need to use Filters that don't support property configuration. 

Item 2:

When I revert back to my old stuff I don't see the OPTIONS request go out in firebug or chrome. I'm lost on that front:-)  

Item 3:

It seems that some of my issues may be related to maxConnections/interval.  My app is predicated around multiple connections from the same browser.  I can explain that if you need to know why.  Basically I live in many iFrames that react in various visual ways to server state pushed to the iframes.  Iframes come in because of a desktop architecture we use called OWF. Ozone Widget Framework.

I've seen this behavior before when I was first getting started with comet. Our init parameters were not being honored.   As soon as we went over 2 connections comet switched over to call-back polling.  But it didn't run away like it does now.  Now it appears to use the interval (which I thought was for long polling) for the callback polls.  Before it would poll every couple seconds.  We brute forced it by setting configuration parameters programmatically to 20. The most recent code looks like so:

   @Bean(initMethod = "start", destroyMethod = "stop")

    public BayeuxServer bayeuxServer() {

        logger.info("Configurer.bayeuxServer Entered.");

        BayeuxServerImpl bean = new BayeuxServerImpl();

        bean.setOption(BayeuxServerImpl.LOG_LEVEL,

                cometConfiguration.getLogLevel());

        bean.setOption("maxSessionsPerBrowser",

                cometConfiguration.getMaxSessionsPerBrowser());

        bean.setOption("allowMultiSessionsNoBrowser",

                cometConfiguration.isAllowMultiSessionsNoBrowser());

        bean.setOption("metaConnectDeliverOnly",

                cometConfiguration.isMetaConnectDeliverOnly());

        bean.setOption("multiSessionInterval",

                cometConfiguration.getMultiSessionInterval());

        bean.setOption("timeout", cometConfiguration.getTimeout());

        bean.setOption("ws.timeout", cometConfiguration.getWsTimeout());

        bean.setOption("interval", cometConfiguration.getInterval());

        bean.setOption("ws.interval", cometConfiguration.getWsInterval());

        bean.setOption("maxInterval", cometConfiguration.getMaxInterval());

        bean.setOption("ws.maxInterval", cometConfiguration.getWsMaxInterval());

        bean.setOption("maxLazyTimeout", cometConfiguration.getMaxLazyTimeout());

        bean.setOption("jsonDebug", cometConfiguration.isJsonDebug());

        bean.setOption("long-polling.json.metaConnectDeliverOnly",

                cometConfiguration.isLongPollingJsonMetaConnectDeliverOnly());

        

        logger.info(bean.getAllowedTransports().toString());

        List<String> allowedTransports = new ArrayList<String>();

        allowedTransports.add("long-polling");

        allowedTransports.add("callback-polling");

        bean.setAllowedTransports(allowedTransports);

        /*

         * add dequeue listener and populate with username. 

         */

        bean.addListener(new BayeuxServer.SessionListener() {

            public void sessionAdded(ServerSession session) {

                logger.info("Init-ing dequeuelistener with UN: "

                        + SecurityUtils.getUsername());

                session.addListener(new SecurityDequeueListener(SecurityUtils

                        .getUsername()));

            }

            public void sessionRemoved(ServerSession session, boolean timedout) {

            }

        });

        /*

         * Used for debug

         */

        bean.addExtension(new LoggingExtension());

        /*

         * It looks like Ordinal coded sets get converted to an Array of longs

         * somewhere along the way. So I fix this in CometdRexPublisher for now.

         */

        // bean.addExtension(new RexEventEncoderExtension());

        return bean;

    }

The resulting logs from this look like so:

10:02:50,483  INFO 15743436:132 -  - allowMultiSessionsNoBrowser=true

10:02:50,483  INFO 15743436:132 -  - interval=0

10:02:50,483  INFO 15743436:132 -  - jsonDebug=false

10:02:50,484  INFO 15743436:132 -  - logLevel=3

10:02:50,484  INFO 15743436:132 -  - long-polling.json.metaConnectDeliverOnly=false

10:02:50,484  INFO 15743436:132 -  - maxInterval=15000

10:02:50,484  INFO 15743436:132 -  - maxLazyTimeout=5000

10:02:50,484  INFO 15743436:132 -  - maxSessionsPerBrowser=20

10:02:50,485  INFO 15743436:132 -  - metaConnectDeliverOnly=false

10:02:50,485  INFO 15743436:132 -  - multiSessionInterval=1500

10:02:50,485  INFO 15743436:132 -  - timeout=30000

10:02:50,485  INFO 15743436:132 -  - ws.interval=2500

10:02:50,485  INFO 15743436:132 -  - ws.maxInterval=15000

10:02:50,485  INFO 15743436:132 -  - ws.timeout=15000

10:02:50,488  INFO 15743436:109 -  - Added channel /meta

10:02:50,489  INFO 15743436:109 -  - Added channel /meta/handshake

10:02:50,490  INFO 15743436:109 -  - Added channel /meta/connect

10:02:50,490  INFO 15743436:109 -  - Added channel /meta/subscribe

10:02:50,491  INFO 15743436:109 -  - Added channel /meta/unsubscribe

10:02:50,491  INFO 15743436:109 -  - Added channel /meta/disconnect

10:02:50,495  INFO 15743436:109 -  - Allowed Transports: [long-polling, callback-polling]

Item 4:

Given that I've put in so much work into going from 2.4 to 2.6 I really want to stay on 2.6.  But I can't get it to work as it did with 2.4 even in my development environment.  I'm reverting back to a mid point to make sure I didn't introduce this issue with SpringSecurity without knowing.

Item 5:

I'm trying to push for Jetty.  

[Glenn Thompson]

Hi again,

BTW I just upgraded my dev env as well.  Before I used 8.1.1 of Jetty.  I upgraded to 8.1.13.  for development I run two separate jetty instances using the maven jetty plugin.  One runs out custom cometd service(just manages dynamic channel creation)  The other runs all the "widgets"  which are simply apps that run in iframes.

Thanks for any help,

Glenn 

On Thursday, September 19, 2013 9:39:39 AM UTC-6, Glenn Thompson wrote:

[Glenn Thompson]

Hey again.

CORS Long-polling still is not working in my local dev environment.  I'm using 8.1.13 running the maven jetty plugin.  I have verified that the cross origin filter is being called for all the callback-polling requests and that it is the first filter in the chain..  I do not get an OPTIONS request on the server side that I can see.  I have used a debugger on both the client and server sides of the initial handshake.  The first request that goes out to the cometd service is a handshake as a POST.  How/where does the OPTIONS request get submitted?  Does the browser do this for me?  I don't see it.  Like I mentioned before, I see an Abort of the handshake in firebug. It shows OPTIONS as the method.  If my debugging is correct, the request I make is a post which errors out before the request timeout.  I never see a preflightRequest in the filter.  I even tried a plugin called Force CORS 1.4

I also had a question about jsonp.  So do the callback polls using jsonp "long-poll"?  I think I've mis-understood this for some time now.  I see the requests hold for the full 30 seconds(when no messages are queued)  before they return.  But they are jsonp requests.  I have reverted back to old code using 2.4 and I'm still using jsonp requests.  The only difference I'm seeing for the old code using 2.4 is that I don't get run away requests(quickly repeated polls) when I go over two tabs.  I'm pretty darn sure I'm seen a connectionType of "long-polling"  in my dev environment before.  But now I'm doubting everything.

Any help is appreciated.  

Glenn

[Glenn Thompson]

So I really think the key to my problem is the fact that the initial handshake request gets canceled. Any ideas on how I might prevent that.  I really don't think that the OPTIONS request ever reaches the server.

Glenn

[Glenn Thompson]

Hi,

At this point I've managed convince our quality assurance folks that Jetty is the better route to go.  Of course that means I need to help our SAs with configuration scripts:-)

I have yet to get a CORS request to work with cometd.  I have decided to revert to 2.4.  As it turns out they were not working in 2.4 either.  Honestly, CORS isn't my real issue at the moment.  I can live with jsonp requests in development and load balancing will prevent CORS requests for production. My real issue is the run-away connect attempts.  As soon as I bring up a second client instance in the same browser, I get repeated connects separated in time by the value of the "interval" setting.  The connects show successful yet they don't long poll/block or whatever the proper term is for jsonp request.  The interesting part is that my server side java clients show that they are long-polling.  However they suffer from the same problem.  Repeated connects that log as successful but repeat every "interval" amount.  I'm sure/hopeful that It's my issue.  But I'm very behind on new capability.  So I'm going to punt on upgrading to 2.6.  I was upgrading in hopes that it would work better under Tomcat.  I've eliminated Tomcat for the short term thankfully.

I'd like to state one last time that this behavior seems a bit like when the maxSessionPerBrowser option is exceeded.  But that has always manifested itself as repeated connects using "multiSessionInterval" if I recall correctly.

If you have any insights I'd love to hear them.  But I'm out of gas on this problem at the moment.

Thanks,

Glenn

[Flo]

It is definitely the browser who denies to send an OPTION request.

Are you sure your browser has picked up the cometd js files for 2.6, cause this version works fine for me (I'm using dojo bindings). You might double check whether the xhr object used for the long polling transport has been configured with withCredentials=true.

If you did not come across the link below yet, it really contains valuable information and helped me to overcome my cors issues and I'm running it now without problems.
https://developer.mozilla.org/en-US/docs/HTTP/Access_control_CORS

Regards,
Florian

[Glenn Thompson]

Hi Florian,

I'll double check this.  For some reason I think I only set withCredentials on the server side.  

Thanks,

Glenn