Detecting a problem with Ice client proxy object call using Javascript

alverson

I will do that but something has changed between 3.6b and 3.6.0 because I only switch between the two Ice.js files and one works and the other doesn't. Both my Javascript client and C++ server applications are exactly the same. I'll need to stick with the 3.6b version for now because it works. I even pointed out the exact function that changed, so it is obviously working differently.

I have to say this version has given me the most problems than any other version that I've used and I've gone through several upgrades since 3.4.

alverson

I will try to come up with a complete sample but it'll be a little difficult to whittle down the app to something reasonable I can send you.

I just thought maybe there was something obvious that I'm missing with the new version.

benoit

Hi,

I don't think you're comparing the same files, with 3.6b the code is coming from ConnectionRequestHandler.js whereas it's from ConnectRequestHandler.js with 3.6.0.

The different code path indicates that with 3.6b the connection is already established when the request is being sent whereas with 3.6.0, it indicates that the request is being queued while the connection is being established.

Can you please enable network/protocol tracing in your JavaScript client to figure out why the connection establishment is behaving differently under 3.6b and 3.6.0? You can set Ice.Trace.Network=2 and Ice.Trace.Protocol=2 in the properties of the Ice.InitializationData structure provided to the communicator initialization method to set these properties.

Cheers,
Benoit.

alverson

I've turned on the trace and have attached several files containing the following:

Creation and usage of proxy.txt - contains the code for the creation of the proxy and the usage of the proxy.
Trace with 3.6b.txt - trace with Ice.js for 3.6b
Trace with 3.6.0.txt - trace with Ice.js for 3.6.0.

I've whittled down to a single call on the proxy (loadTrackingSources).

You will see that for the 3.6b version the call is initiated (loadTrackingSources started in the 3.6b trace file) and it completes (loadTrackingSources completed in the 3.6b trace file) and for the 3.6.0 version the call is initiated (loadTrackingSources started in the 3.6.0 trace file) but it never completes.

I also have another question. After a period of time, the ws connection is automatically closed. This sometimes causes me a problem (which is what started this whole thread to begin with) when I make a subsequent call to the proxy. I do not want the ws connection to close. How do I prevent the ws connection from closing automatically?

xdm

Can you test to move the tracing of "loadTrackingSources started" inside the if block, and confirm the proxy has been initialized at this point.

So replace:

console.log("loadTrackingSources started");
if (webClientDbMgrPrx) {
...

With:

if (webClientDbMgrPrx) {
  console.log("loadTrackingSources started");
  ...

alverson

I did that and got the same results.

Obtaining proxy:

-- 07-01-2015 9:39:40 AM.354 Protocol: sending asynchronous request
message type = 0 (request)
compression status = 0 (not compressed; do not compress response, if any)
message size = 102
request id = 3
identity = ResourceAllocationManager-ESB
facet = WebClientDbMgr
operation = ice_isA
mode = 1 (nonmutating)
context =
encoding = 1.1

Method was called on proxy as before but nothing happens after that.

benoit

Hi,

Something looks wrong indeed. Unfortunately, we can't reproduce it. Could you get the state of the ConnectRequestHandler object in the debugger? It's the object with the sendAsyncRequest method is called where your request is being queued (line 15805 in Ice.js). Seeing the full stack trace of the call would also be helpful.

Cheers,
Benoit.

alverson

It is hard to capture all the data in that object. What specifically would you like to see? I've attached snapshots of what I have so far. As well as the stack.

As I noted earlier, that routine has changed between 3.6b and 3.6.0Attachment not found.Attachment not found.

alverson

What is suppose to execute after request is queued:

sendAsyncRequest: function(out)
{
if(!this._initialized)
{
out.__cancelable(this); // This will throw if the request is canceled
}

if(!this.initialized())
{
this._requests.push(out);
return AsyncStatus.Queued;
}
return out.__invokeRemote(this._connection, this._compress, this._response);
},

The 3.6b version is different:

sendAsyncRequest: function(out)
{
return out.__send(this._connection, this._compress, this._response);
},

benoit

Once the request is queued, it is supposed to be sent by ConnectRequestHandler.flushRequests() when the connection is established (i.e.: when setConnection is called on the ConnectRequestHandler object).

In 3.6b, it's taking a different code path, it's not executing ConnectRequestHandler.sendAsyncRequest but ConnectionRequestHandler.sendAsyncRequest.

Can you confirm that you're not using Glacier2? Which browser/OS do you use?

Could you try to surround the "this.flushRequests()" call line 15882 with a try/catch block as shown below:

                try
                {
                    this.flushRequests();
                }
                catch(ex)
                {
                    console.log("unexpected exception:\n" + ex);
                }

The state of the ConnectRequestHandler object is not valid and it's not clear to me why, I suspect an exception is being thrown in flushRequests (in theory _initialized should be true since the _connection member is not null).

Cheers,
Benoit.

alverson

See errors below in red:

communicator created
IceMgrModule.js (line 30)
-- 07-01-2015 4:03:14 PM.343 Network: trying to establish ws connection to 127.0.0.1:8080
Ice360.js (line 4456)

-- 07-01-2015 4:03:14 PM.711 Protocol: received validate connection
message type = 3 (validate connection)
compression status = 0 (not compressed; do not compress response, if any)
message size = 14

Ice360.js (line 4456)

-- 07-01-2015 4:03:14 PM.712 Network: established ws connection
local address = <not available>
remote address = 127.0.0.1:8080

Ice360.js (line 4456)
before flushRequests
Ice360.js (line 15882)

-- 07-01-2015 4:03:14 PM.717 Protocol: sending asynchronous request
message type = 0 (request)
compression status = 0 (not compressed; do not compress response, if any)
message size = 98
request id = 1
identity = ResourceAllocationManager-ESB
facet =
operation = ice_isA
mode = 1 (nonmutating)
context =
encoding = 1.1

Ice360.js (line 4456)

unexpected exception:
TypeError: this._proxies[k].__updateRequestHandler is not a function

Ice360.js (line 15889)

-- 07-01-2015 4:03:14 PM.720 Protocol: received reply
message type = 2 (reply)
compression status = 0 (not compressed; do not compress response, if any)
message size = 26
request id = 1
reply status = 0 (ok)
encoding = 1.1

Ice360.js (line 4456)
before flushRequests
Ice360.js (line 15882)

-- 07-01-2015 4:03:14 PM.727 Protocol: sending asynchronous request
message type = 0 (request)
compression status = 0 (not compressed; do not compress response, if any)
message size = 108
request id = 2
identity = ResourceAllocationManager-ESB
facet = VisibilityManager
operation = ice_isA
mode = 1 (nonmutating)
context =
encoding = 1.1

Ice360.js (line 4456)

unexpected exception:
TypeError: this._proxies[k].__updateRequestHandler is not a function

Ice360.js (line 15889)
before flushRequests
Ice360.js (line 15882)

-- 07-01-2015 4:03:14 PM.734 Protocol: sending asynchronous request
message type = 0 (request)
compression status = 0 (not compressed; do not compress response, if any)
message size = 102
request id = 3
identity = ResourceAllocationManager-ESB
facet = WebClientDbMgr
operation = ice_isA
mode = 1 (nonmutating)
context =
encoding = 1.1

Ice360.js (line 4456)

unexpected exception:
TypeError: this._proxies[k].__updateRequestHandler is not a function

Ice360.js (line 15889)

-- 07-01-2015 4:03:14 PM.746 Protocol: received reply
message type = 2 (reply)
compression status = 0 (not compressed; do not compress response, if any)
message size = 26
request id = 2
reply status = 0 (ok)
encoding = 1.1

Ice360.js (line 4456)

-- 07-01-2015 4:03:14 PM.747 Protocol: received reply
message type = 2 (reply)
compression status = 0 (not compressed; do not compress response, if any)
message size = 26
request id = 3
reply status = 0 (ok)
encoding = 1.1

Ice360.js (line 4456)
loadTrackingSources started

alverson

Forgot to add:

I am currently not using Glacier2. At some point I might, but not right now.

I am using Firefox.

benoit

Hi,

I believe this is caused by the bogus for/in loop on the _proxies array in ConnectRequestHandler. On your browser, this loop most likely iterates over some array properties which is wrong and ends up raising this unexpected exception.

Can you try replacing line 15979 with the following:

                   for(var k = 0; i < this._proxies.length; ++k)

I'm surprised we didn't hit this issue during testing. This is likely related to the Firefox version you're using. Which Firefox version and OS do you use?

A workaround for this bug would be to disable connection caching with ice_connectionCached(false) on the proxy.

Cheers,
Benoit.

alverson

I will give that a shot.

I'm using Firefox 38.0.5 on Win 7.

alverson

That worked....great job:)

With 3.6b, I've had issues with ws connections closing automatically. It seems to cause problems when I attempt to access the proxy after it closes. How can I prevent that from happening?

xdm

The automatic closing of connections is controlled by Active Connection Management (ACM), you can disable it by setting Ice.ACM.Close property value to 0 in your client.

joegeorge

We've published new npm and bower packages fixing this issue. You can install them by running the following npm or bower command:

npm install ice@latest
bower install ice#master

Cheers,
Joe