1 2 Previous Next 16 Replies Latest reply on Jun 4, 2012 7:08 AM by bfluri

    Errai client-side startup problem

    nva

      My application runs perfectly in both, development and production mode on my local development machine. When deploying on the production server, loading the first GWT page fails with the following message in the browsers error console:

       

      [errai] wait for: org.jboss.errai.marshalling.client.api.MarshallerFramework

      3CBD9F88BFDE1B7991023B07305EEF32.cache.html:978[errai] vote For: org.jboss.errai.marshalling.client.api.MarshallerFramework

      3CBD9F88BFDE1B7991023B07305EEF32.cache.html:978[errai] wait for: org.jboss.errai.bus.client.framework.ClientMessageBus

      3CBD9F88BFDE1B7991023B07305EEF32.cache.html:978[errai] wait for: org.jboss.errai.bus.client.framework.RpcProxyLoader

      3CBD9F88BFDE1B7991023B07305EEF32.cache.html:978[errai] sending initial handshake to remote bus

      3CBD9F88BFDE1B7991023B07305EEF32.cache.html:978[errai] wait for: org.jboss.errai.ioc.client.Container

      3CBD9F88BFDE1B7991023B07305EEF32.cache.html:978[errai] IOC bootstrapper successfully initialized.

      3CBD9F88BFDE1B7991023B07305EEF32.cache.html:978[errai] IOC container bootstrapped.

      3CBD9F88BFDE1B7991023B07305EEF32.cache.html:978[errai] 9 beans successfully deployed.

      3CBD9F88BFDE1B7991023B07305EEF32.cache.html:978[errai] vote For: org.jboss.errai.ioc.client.Container

      3CBD9F88BFDE1B7991023B07305EEF32.cache.html:978[errai]   still waiting for -> [org.jboss.errai.bus.client.framework.ClientMessageBus, org.jboss.errai.bus.client.framework.RpcProxyLoader]

      3CBD9F88BFDE1B7991023B07305EEF32.cache.html:978[errai] components failed to initialize

      3CBD9F88BFDE1B7991023B07305EEF32.cache.html:978[errai]    [failed] -> org.jboss.errai.bus.client.framework.ClientMessageBus

      3CBD9F88BFDE1B7991023B07305EEF32.cache.html:978[errai]    [failed] -> org.jboss.errai.bus.client.framework.RpcProxyLoader

       

      The effect is that the html and javascripts load, can be seen in the page source, but the page remains empty to the user.

       

      The production environment is jetty6 on a machine in a DMZ and currently we have port forwarders on the firewall to allow connectivity from the outside. Tried apache mod_proxy too and had the same problem.

       

      I've checked the basics, connectivity, paths, etc. Since there are no entries in the server-side log, I suspect that the handshake to the remote bus times out. Any ideas what could cause that or how to get more debug information? Thanks!

       

      Am currently using Errai 2.0.0.Final, but this has been happening with all CR and Beta versions too.

        • 1. Re: Errai client-side startup problem
          cbrock

          Yes, it definitely appears that the connection to the server is timing out. You may need to look at the network requests in whatever browser you're working in to get more details as to what might be going wrong.

          1 of 1 people found this helpful
          • 2. Re: Errai client-side startup problem
            nva

            Thanks, the problem is intermittent (the worst kind). Everything worked until the next jetty restart. This is what I see in the last request that remains in a pending state when connecting via an ssh portforwarder and going around the firewall on the production server:

             

            POST http://localhost:18080/dtt/out.63421-23936.erraiBus?z=1 HTTP/1.1

            Origin: http://localhost:18080

            phase: connection

            RemoteQueueID: 63421-23936

            User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.168 Safari/535.19

            Content-Type: application/json; charset=UTF-8

            Referer: http://localhost:18080/dtt/

             

            And the response headers as Chrome sees them:

             

            HTTP/1.1 0

             

            Interesting that the production server is a virtual machine. Restarting the host also helped. But the problem keeps recurring and I would like to get to the bottom so that we can set up the environment properly.

            • 3. Re: Errai client-side startup problem
              jfuerth

              HI Valentin,

               

              Unfortunately, this looks like a tricky one. As you say, intermittent problems are the worst kind.

               

              Here are some things you might want to try if you haven't already:

               

              1. Try disabling long polling in the DefaultBlockingServlet by setting the system property org.jboss.errai.bus.do_long_poll=false. This option is really only intended for testing, but it's possible the proxies have introduced some sort of "pinch point" in the HTTP data path that's stalling the long polls.

              2. Check if there's something in your server-side application that's blocking for a long time (for example, a thread race condition leading to deadlock). When the app wedges up, get a thread dump from the VM by sending Jetty a SIGQUIT (or use the jstack program that comes with the JDK).

              3. Try staying connected to the app from various places (including locations inside the DMZ network) and see if they all freeze up at the same time, or if they lock up one at a time.

               

              Sorry I don't have any specific insights here, but the more things you try, the more likely we can figure out what's going on.

               

              Best regards,

               

              Jonathan

              1 of 1 people found this helpful
              • 4. Re: Errai client-side startup problem
                nva

                Thanks Jonathan, the pointers you provided was exactly what I needed. At the moment - since the restart of the VMWare host - the problem doesn't manifest. It's definitely something in our environment. Will keep this thread posted with the development.

                • 5. Re: Errai client-side startup problem
                  almac

                  We are seeing what looks like the same problem here, though I have some more details on the aberrant behavior which might help to figure out what is going on.  Here is a synopsis:

                  • environment:  happens reproducibly in our demo environment, which is a jetty server running weak single-core VM on an overtaxed machine --- however, similar behavior can be demonstrated on a developer workstation.
                  • symptom: our client freezes at the "Loading JavaScript, please wait..." --- actually, under the cover, it has just sent the initial POST request to initialize the server (and logged "sending initial handshake to remote bus"), and is sitting around waiting for the response.
                  • steps to reproduce:
                    1. start the jetty server
                    2. wait until it unpacks the warfile, starts up the server side, and "[bus] buffer status [freebytes: ...]" is logged
                    3. try to connect a client

                   

                  We can get different, related behaviors after Step 3, however.  I've got three interesting cases.

                   

                  Case 1 - Single client connects to a fast(er) server:

                  • Client issues intial POST request, and waits.
                  • Some short time later (e.g. around a minute), server responds.
                  • Client continues with initialization and runs as expected.
                  • When subsequent clients (re)connect, the response to the initial POST takes about 100ms.

                   

                  Case 2 - Single client connects to a slow server:

                  • Client issue initial POST request, and waits.
                  • Around 45 seconds later, client logs "components failed to initialize".
                  • Around 15 minutes later, server emits response to that POST.
                  • Client logs "received response from initial handshake", continues initialization, but generally hangs waiting for the RpcProxyLoader component.
                  • BUT, reloading the client page (or any new client connections) after that generally proceed successfully with any big delay after initial POST.

                   

                  Case 3 - Four clients connect to a slow server:

                  • Clients issue initial POST requests, and wait.
                  • Around 45 seconds later, clients log "components failed to initialize".
                  • Around 25 minutes later, server emits responses to those POSTs.
                  • Clients log "received response from initial handshake", continue initialization, but generally hang waiting for the RpcProxyLoader component.
                  • AND, reloading the client page (or any new client connections) after that generally no longer have the big delay after the initial POST, but they fail anyway, showing two instances of "received response from initial handshake" (etc) in the client-side log.

                   

                  I'll add a client-side log from "Case 3" to the end of this posting.  The delay between the client's initial POST and the server's response is corroborated by packet captures on the server VM; i.e., I doubt that the VM networking has anything to do with the problem.  I've only tested this with the DefaultBlockingServlet. (We switched away from the JettyContinuationsServlet a few months ago because we were experiencing other strange delays/latency in message handling.) The attached log is from a system using the AsyncDispatcher, although we see the same behavior with the SimpleDispatcher.

                   

                  Here are my theories about this behavior:

                  1. The server-side does some lengthy/complex initialization *after* it receives the first client request. On a slow machine, this causes it to sit and think for a long time before responding to those first clients.
                  2. If that delay is too long, something(s) timeout on the client-side, and/or server-side --- but other things don't.  When the client finally receives a response, the original request handler still tries to handle it, but other components have already given up, so it does not succeed.
                  3. Something is not being locked properly on the server-side, so that if multiple clients connect while the server is still doing its complex initialization, the state gets confused enough that it cannot properly handle future startup of new clients.

                   

                  If true, 2 and 3 would be bugs of one sort or another. 1 would be an anti-feature --- if that's really what is going on, I think we'd prefer a setting (and/or default behavior) to just do all the initialization at server startup, and not defer anything until the first client request came in.

                   

                  Here is a grab from the firefox web-console for a client in Case 3 (with some editing/notes):

                  {{------------------------ initial page load -----------------------------------------------}}
                  [14:21:07.516] Unknown property 'zoom'.  Declaration dropped. @ http://localhost:9090/project/project.RemoteClient/gwt/standard/standard.css:44
                  [14:21:07.522] Error in parsing value for 'cursor'.  Declaration dropped. @ http://localhost:9090/project/project.RemoteClient/gwt/standard/standard.css:53
                  [14:21:07.572] Error in parsing value for 'filter'.  Declaration dropped. @ http://localhost:9090/project/project.RemoteClient/gwt/standard/standard.css:490
                  [14:21:07.659] Error in parsing value for 'vertical-align'.  Declaration dropped. @ http://localhost:9090/project/project.RemoteClient/gwt/standard/standard.css:1073
                  [14:21:11.181] [errai] wait for: org.jboss.errai.marshalling.client.api.MarshallerFramework @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:21:11.194] [errai] vote For: org.jboss.errai.marshalling.client.api.MarshallerFramework @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:21:11.199] [errai] wait for: org.jboss.errai.bus.client.framework.ClientMessageBus @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:21:11.202] [errai] wait for: org.jboss.errai.bus.client.framework.RpcProxyLoader @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:21:11.206] [errai] sending initial handshake to remote bus @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:21:11.216] [errai] wait for: org.jboss.errai.ioc.client.Container @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:21:11.219] [errai] IOC bootstrapper successfully initialized. @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:21:11.237] [errai] IOC container bootstrapped. @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:21:11.241] [errai] 9 beans successfully deployed. @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:21:11.243] [errai] vote For: org.jboss.errai.ioc.client.Container @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:21:11.246] [errai]   still waiting for -> [org.jboss.errai.bus.client.framework.ClientMessageBus, org.jboss.errai.bus.client.framework.RpcProxyLoader] @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  --
                  [14:21:56.124] [errai] components failed to initialize @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:21:56.129] [errai]    [failed] -> org.jboss.errai.bus.client.framework.ClientMessageBus @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:21:56.131] [errai]    [failed] -> org.jboss.errai.bus.client.framework.RpcProxyLoader @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  --
                  [14:44:59.005] [errai] received response from initial handshake. @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:44:59.016] [errai] remote services available: [ServerBus, project.shared.protocol.RemoteMProtocol$MRpcInterface:RPC, project.shared.protocol.RemoteRProtocol$RRpcInterface:RPC, AuthenticationService, AuthorizationService, project.shared.protocol.DemoControlsRpcInterface:RPC, project.shared.protocol.RemoteCRpcInterface:RPC, ServerEchoService] @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:44:59.021] [errai] received capabilities notice from server. supported capabilities of remote: LongPollAvailable @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:44:59.024] [errai] initializing long poll subsystem @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:44:59.272] [errai] received FinishStateSync message. preparing to bring up the federation @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:44:59.301] [errai] vote For: org.jboss.errai.bus.client.framework.ClientMessageBus @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:44:59.305] [errai]   still waiting for -> [org.jboss.errai.bus.client.framework.RpcProxyLoader] @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:03.316] [errai] vote For: org.jboss.errai.bus.client.framework.RpcProxyLoader @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:24.602] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=22 [HTTP/1.1 200 OK 123ms]
                  [14:45:25.338] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=23 [HTTP/1.1 200 OK 128ms]
                  [14:45:25.499] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=24 [HTTP/1.1 200 OK 128ms]
                  [14:45:25.686] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=25 [HTTP/1.1 200 OK 124ms]
                  [14:45:26.446] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=26 [HTTP/1.1 200 OK 120ms]
                  [14:45:26.622] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=27 [HTTP/1.1 200 OK 119ms]
                  [14:45:28.808] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=28 [HTTP/1.1 200 OK 121ms]
                  [14:45:31.317] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=29 [HTTP/1.1 200 OK 169ms]
                  [14:45:31.853] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=30 [HTTP/1.1 200 OK 109ms]
                  [14:45:31.961] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=31 [HTTP/1.1 200 OK 113ms]
                  [14:45:32.264] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=32 [HTTP/1.1 200 OK 122ms]
                  [14:45:34.730] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=33 [HTTP/1.1 200 OK 181ms]
                  [14:45:36.821] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=34 [HTTP/1.1 200 OK 115ms]
                  [14:45:37.592] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=35 [HTTP/1.1 200 OK 110ms]
                  [14:45:39.830] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=36 [HTTP/1.1 200 OK 298ms]
                  [14:45:40.622] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=37 [HTTP/1.1 200 OK 158ms]
                  [14:45:40.886] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=38 [HTTP/1.1 200 OK 220ms]
                  [14:45:43.378] GET http://localhost:9090/project/in.53267-61069.erraiBus?z=39 [HTTP/1.1 200 OK 211ms]
                  {{----------------- reload the client page ----------------------------------}}
                  [14:45:45.108] GET http://localhost:9090/project/RemoteClient.html#mission_manager [HTTP/1.1 304 Not Modified 103ms]
                  [14:45:46.264] GET http://localhost:9090/project/project.RemoteClient/project.RemoteClient.nocache.js [HTTP/1.1 304 Not Modified 106ms]
                  [14:45:47.336] GET http://localhost:9090/project/project.RemoteClient/gwt/standard/standard.css [HTTP/1.1 304 Not Modified 103ms]
                  [14:45:49.238] [errai] wait for: org.jboss.errai.marshalling.client.api.MarshallerFramework @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:49.252] [errai] vote For: org.jboss.errai.marshalling.client.api.MarshallerFramework @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:49.258] [errai] wait for: org.jboss.errai.bus.client.framework.ClientMessageBus @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:49.261] [errai] wait for: org.jboss.errai.bus.client.framework.RpcProxyLoader @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:49.265] [errai] sending initial handshake to remote bus @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:49.275] [errai] wait for: org.jboss.errai.ioc.client.Container @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:49.279] [errai] IOC bootstrapper successfully initialized. @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:49.296] [errai] IOC container bootstrapped. @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:49.301] [errai] 9 beans successfully deployed. @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:49.304] [errai] vote For: org.jboss.errai.ioc.client.Container @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:49.307] [errai]   still waiting for -> [org.jboss.errai.bus.client.framework.ClientMessageBus, org.jboss.errai.bus.client.framework.RpcProxyLoader] @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:51.086] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=1 [HTTP/1.1 200 OK 111ms]
                  [14:45:51.242] [errai] received response from initial handshake. @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:51.254] [errai] remote services available: [ServerBus, project.shared.protocol.RemoteMProtocol$MRpcInterface:RPC, project.shared.protocol.RemoteRProtocol$RRpcInterface:RPC, AuthenticationService, AuthorizationService, project.shared.protocol.DemoControlsRpcInterface:RPC, project.shared.protocol.RemoteCRpcInterface:RPC, ServerEchoService] @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:51.261] [errai] received capabilities notice from server. supported capabilities of remote: LongPollAvailable @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:51.264] [errai] initializing long poll subsystem @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:51.834] [errai] received FinishStateSync message. preparing to bring up the federation @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:51.862] [errai] vote For: org.jboss.errai.bus.client.framework.ClientMessageBus @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:51.866] [errai]   still waiting for -> [org.jboss.errai.bus.client.framework.RpcProxyLoader] @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:52.308] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 108ms]
                  [14:45:52.323] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 109ms]
                  [14:45:52.331] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 110ms]
                  [14:45:53.006] [errai] vote For: org.jboss.errai.bus.client.framework.RpcProxyLoader @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:53.121] [errai] received final vote for initialization ... @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:53.126] [errai] executing 1 post init task(s) @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:53.131] Fri May 18 14:45:53 GMT-700 2012 project.client.RemoteClient
                  INFO: Initializing RemoteC... @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:5053
                  [14:45:53.167] Fri May 18 14:45:53 GMT-700 2012 project.client.RemoteClient
                  INFO: Initializing RemoteDemoControls... @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:5053
                  [14:45:53.203] Fri May 18 14:45:53 GMT-700 2012 project.client.RemoteClient
                  INFO: Initializing RemoteRClient... @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:5053
                  [14:45:53.224] Fri May 18 14:45:53 GMT-700 2012 project.client.RemoteRClient
                  INFO: initialization fetch with id={0,0} @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:5053
                  [14:45:53.250] [errai] transmitting deferred messages now ... @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:53.274] [errai] bus federation complete. now operating normally. @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:53.748] POST http://localhost:9090/project/project.RemoteClient/remote_logging [HTTP/1.1 200 OK 305ms]
                  [14:45:53.763] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 129ms]
                  [14:45:53.865] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 115ms]
                  [14:45:53.883] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 214ms]
                  [14:45:53.898] POST http://localhost:9090/project/project.RemoteClient/remote_logging [HTTP/1.1 200 OK 285ms]
                  [14:45:53.912] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 272ms]
                  [14:45:53.929] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 189ms]
                  [14:45:53.948] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 186ms]
                  [14:45:53.963] POST http://localhost:9090/project/project.RemoteClient/remote_logging [HTTP/1.1 200 OK 268ms]
                  [14:45:53.980] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 267ms]
                  [14:45:53.995] POST http://localhost:9090/project/project.RemoteClient/remote_logging [HTTP/1.1 200 OK 260ms]
                  [14:45:54.019] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 307ms]
                  [14:45:54.048] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 313ms]
                  [14:45:54.063] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 312ms]
                  [14:45:54.077] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 320ms]
                  [14:45:54.095] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 322ms]
                  [14:45:54.137] [errai] sending initial handshake to remote bus @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:55.148] GET http://localhost:9090/project/in.49249-9806.erraiBus?z=2 [HTTP/1.1 200 OK 104ms]
                  [14:45:55.539] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=0 [HTTP/1.1 200 OK 113ms]
                  [14:45:55.557] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=4 [HTTP/1.1 200 OK 111ms]
                  [14:45:55.587] [errai] received response from initial handshake. @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:55.597] [errai] remote services available: [ServerBus, project.shared.protocol.RemoteMProtocol$MRpcInterface:RPC, project.shared.protocol.RemoteRProtocol$RRpcInterface:RPC, AuthenticationService, AuthorizationService, project.shared.protocol.DemoControlsRpcInterface:RPC, project.shared.protocol.RemoteCRpcInterface:RPC, ServerEchoService] @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:55.603] [errai] received capabilities notice from server. supported capabilities of remote: LongPollAvailable @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:55.607] [errai] initializing long poll subsystem @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:57.295] [errai] received FinishStateSync message. preparing to bring up the federation @ http://localhost:9090/project/project.RemoteClient/0A8A087FBB91EE7A6AE182CC5A26AEE3.cache.html:2203
                  [14:45:57.938] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=3 [HTTP/1.1 200 OK 111ms]
                  [14:45:57.957] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=3 [HTTP/1.1 200 OK 120ms]
                  [14:45:57.973] POST http://localhost:9090/project/out.49249-9806.erraiBus?z=3 [HTTP/1.1 200 OK 113ms]
                  [14:45:57.988] GET http://localhost:9090/project/in.49249-9806.erraiBus?z=5 [HTTP/1.1 200 OK 188ms]
                  [14:45:58.309] GET http://localhost:9090/project/in.49249-9806.erraiBus?z=6 [HTTP/1.1 200 OK 109ms]
                  ...
                  [14:47:26.261] GET http://localhost:9090/project/in.49249-9806.erraiBus?z=149 [HTTP/1.1 200 OK 112ms]
                  [14:47:30.490] GET http://localhost:9090/project/in.49249-9806.erraiBus?z=150 [HTTP/1.1 200 OK 110ms]
                  [14:47:30.511] GET http://localhost:9090/project/in.49249-9806.erraiBus?z=151 [HTTP/1.1 200 OK 122ms]
                  ... {{forever}}
                  • 6. Re: Errai client-side startup problem
                    nva

                    The problem reproduces for me exactly as Alvin described it. The time between jetty startup and client successfully initialising the errai bus is 10-15 minutes on a not too overtaxed machine. This happens in production mode only, however. In development/hosted mode there is no significant delay.

                    • 7. Re: Errai client-side startup problem
                      jfuerth

                      Alvin, the symptoms you're describing match perfectly with a problem we actually fixed just before 2.0.0.Final:

                       

                      https://issues.jboss.org/browse/ERRAI-292

                       

                      Although the issue is worded as a Linux deployment problem, the root cause was overuse of SecureRandom for generating client session identifiers. This could cause long delays on any platform.

                       

                      Alvin, are you seeing these problems with Errai 2.0.0.Final?

                       

                      -Jonathan

                      • 8. Re: Errai client-side startup problem
                        almac

                        Indeed, yes, my post/log was written while using 2.0.0.Final.

                        • 9. Re: Errai client-side startup problem
                          almac

                          From SecureHashUtil (in 2.0.0.Final):

                          random.setSeed(SecureRandom.getInstance(secureRandomAlgorithm).generateSeed(128));

                          That's 128 *bytes*, e.g. 1024 bits of seed --- isn't that a bit much?

                          • 10. Re: Errai client-side startup problem
                            bfluri

                            We encounter the same problem. After a deployment on our Linux machine, the very first page request takes almost 10 minutes to complete. The first out.X-X.errai POST request has a very long time to complete.

                            • 11. Re: Errai client-side startup problem
                              jfuerth

                              Okay, it sounds like the entropy pool in Linux is still too small even for our reduced demands on SecureRandom.

                               

                              To answer your question, yes, IMO, 1024 bits of seed is more than necessary. We've just pushed a revised seed generator to both the 2.1 and 2.0.1 branches. Once the snapshot build is out, could you try it and see if it helps?

                               

                              -Jonathan

                              • 12. Re: Errai client-side startup problem
                                crobster

                                I found the fixed version to be an improvment, but still taking longer than you'd expect. I was deploying to a 12 core 64gb box. 

                                 

                                After some digging around I found:

                                 

                                http://stackoverflow.com/questions/137212/how-to-solve-performance-problem-with-java-securerandom

                                Adding param: -Djava.security.egd=file:/dev/./urandom , seems to overcome the problem

                                • 13. Re: Errai client-side startup problem
                                  nva

                                  Chris' suggestion works for me beautifully too. (Errai 2.0.0.Final, jetty) I tried other jetty tweaks that either made no difference or broke the startup comletely. This one works. Thanks!

                                  • 14. Re: Errai client-side startup problem
                                    bfluri

                                    Thank you Chris for that suggestion. It works like a charme

                                     

                                    What I don't understand: why does it take so long to create a seed; what's the idea behind this seed algorithm? During that time, the CPU of the production system is hardly used? Do you have some references for me to read?

                                    1 2 Previous Next