[omniORB] One client call (JavaIDL) creates 2 incoming calls on server (omniORB 4.0.5), both windows

[evgeni.rojkov]

Hello omniORB,
have strange behavior using JavaIDL client with omniORB 4.0.5 server, both on windows

- One client call (JavaIDL) creates 2 incoming calls on server (omniORB 4.0.5).

- This client call fails after 5 minutes(!) with org.omg.CORBA.COMM_FAILURE (java.io.IOException: An existing connection was forcibly closed by the remote host)

- Both server calls (answered with about 5K data) get giopStream.cc:831(0,NO,COMM_FAILURE_UnMarshalArguments)

- Implementations are compatible (tested on different hardware), so assume no reason for COMM_FAILURE_UnMarshalArguments

- Calls to another function between same client and server are successful but having also enormous round-trips (20+ sec)

- This client/server were successfully communicating before

- Assume local network problem

Does somebody have an idea what's going wrong here?
Did somebody have similar problem?
Would appreciate any help.

Best regards,
Evgeni Rojkov

**** Server side (omniORB 4.0.5, Windows), 2 incoming calls, both answered, 2 times COMM_FAILURE_UnMarshalArguments ****

06/25/14 11:03:04,988 [10356] INFO cap.omniorb - omniORB: (4) inputMessage: from giop:tcp:172.17.125.17:59388 106 bytes
06/25/14 11:03:04,988 [10356] INFO cap.omniorb - omniORB: (4)
06/25/14 11:03:04,988 [10356] INFO cap.omniorb - omniORB: (4) recieve codeset service context and set TCS to (ISO-8859-1,UTF-16)
06/25/14 11:03:04,988 [10356] INFO cap.omniorb - omniORB: (4) Dispatching remote call 'getBlock' to: root<1> (active)
06/25/14 11:03:04,989 [10356] INFO cap.omniorb - omniORB: (4) sendChunk: to giop:tcp:172.17.125.17:59388 5144 bytes
...
06/25/14 11:03:23,898 [10356] INFO cap.omniorb - omniORB: (4) throw giopStream::CommFailure from giopStream.cc:831(0,NO,COMM_FAILURE_UnMarshalArguments)
06/25/14 11:03:23,898 [10356] INFO cap.omniorb - omniORB: (4) Server connection refcount = 1
06/25/14 11:03:23,898 [10356] INFO cap.omniorb - omniORB: (4) Server connection refcount = 0
06/25/14 11:03:23,898 [10356] INFO cap.omniorb - omniORB: (4) Server close connection from giop:tcp:172.17.125.17:59388
...
06/25/14 11:08:44,923 [6976] INFO cap.omniorb - omniORB: (5) Accepted connection from giop:tcp:172.17.125.17:59766 because of this rule: "* unix,ssl,tcp"
06/25/14 11:08:44,923 [6976] INFO cap.omniorb - omniORB: (5) inputMessage: from giop:tcp:172.17.125.17:59766 286 bytes
06/25/14 11:08:44,923 [6976] INFO cap.omniorb - omniORB: (5) recieve codeset service context and set TCS to (ISO-8859-1,UTF-16)
06/25/14 11:08:44,923 [6976] INFO cap.omniorb - omniORB: (5) Dispatching remote call 'getBlock' to: root<1> (active)
06/25/14 11:08:44,924 [6976] INFO cap.omniorb - omniORB: (5) sendChunk: to giop:tcp:172.17.125.17:59766 5144 bytes
....
06/25/14 11:09:03,829 [6976] INFO cap.omniorb - omniORB: (5) throw giopStream::CommFailure from giopStream.cc:831(0,NO,COMM_FAILURE_UnMarshalArguments)
06/25/14 11:09:03,829 [6976] INFO cap.omniorb - omniORB: (5) Server connection refcount = 1
06/25/14 11:09:03,829 [6976] INFO cap.omniorb - omniORB: (5) Server connection refcount = 0
06/25/14 11:09:03,829 [6976] INFO cap.omniorb - omniORB: (5) Server close connection from giop:tcp:172.17.125.17:59766

**** Client side (JavaIDL, windows), 1 call to server, org.omg.CORBA.COMM_FAILURE after 5 minutes ****

6/25/14 11:02:41,061 DEBUG [Thread-4] gapPump - 5. before connector.getBlock()
6/25/14 11:02:41,061 DEBUG [Thread-4] gapCommunication - connectorToDatasource.getBlock()
6/25/14 11:02:41,061 DEBUG [Thread-4] gapCommunication - connectorToDatasource.checkConnectionWithReconnect()
6/25/14 11:02:41,061 DEBUG [Thread-4] gapCommunication - connectorToDatasource.isConnected() returns true
6/25/14 11:02:41,061 DEBUG [Thread-4] gapCommunication - connected=true/newConnection=false
....
6/25/14 11:08:20,977 DEBUG [Thread-4] gapCommunication - unexpected Exception in connectorToDatasource.getBlock()
org.omg.CORBA.COMM_FAILURE: vmcid: SUN minor code: 208 completed: Maybe
at com.sun.corba.se.impl.logging.ORBUtilSystemException.connectionAbort(ORBUtilSystemException.java:2400)
at com.sun.corba.se.impl.logging.ORBUtilSystemException.connectionAbort(ORBUtilSystemException.java:2418)
at com.sun.corba.se.impl.transport.SocketOrChannelConnectionImpl.readBits(SocketOrChannelConnectionImpl.java:354)
at com.sun.corba.se.impl.transport.SocketOrChannelConnectionImpl.handleEvent(SocketOrChannelConnectionImpl.java:1124)
at com.sun.corba.se.impl.transport.SelectorImpl.run(SelectorImpl.java:289)
Caused by: org.omg.CORBA.COMM_FAILURE: vmcid: SUN minor code: 211 completed: No
at com.sun.corba.se.impl.logging.ORBUtilSystemException.ioexceptionWhenReadingConnection(ORBUtilSystemException.java:2484)
at com.sun.corba.se.impl.logging.ORBUtilSystemException.ioexceptionWhenReadingConnection(ORBUtilSystemException.java:2502)
at com.sun.corba.se.impl.protocol.giopmsgheaders.MessageBase.readGIOPHeader(MessageBase.java:116)
at com.sun.corba.se.impl.transport.CorbaContactInfoBase.createMessageMediator(CorbaContactInfoBase.java:150)
at com.sun.corba.se.impl.transport.SocketOrChannelConnectionImpl.readBits(SocketOrChannelConnectionImpl.java:314)
... 2 more
Caused by: java.io.IOException: An existing connection was forcibly closed by the remote host
at sun.nio.ch.SocketDispatcher.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:25)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:202)
at sun.nio.ch.IOUtil.read(IOUtil.java:169)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:243)
at com.sun.corba.se.impl.transport.SocketOrChannelConnectionImpl.readFully(SocketOrChannelConnectionImpl.java:599)
at com.sun.corba.se.impl.transport.SocketOrChannelConnectionImpl.read(SocketOrChannelConnectionImpl.java:521)
at com.sun.corba.se.impl.protocol.giopmsgheaders.MessageBase.readGIOPHeader(MessageBase.java:112)
... 4 more


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.omniorb-support.com/pipermail/omniorb-list/attachments/20140626/ccf8dcea/attachment-0001.html>

[Duncan Grisby]

On Thu, 2014-06-26 at 12:58 +0000, evgeni.rojkov at durr.com wrote:

> - One client call (JavaIDL) creates 2 incoming calls on server
> (omniORB 4.0.5).

Sorry for coming to this late...

There's nothing in omniORB that would cause it to duplicate an incoming
call like that. The client must be doing it. You could perhaps use
wireshark or similar to observe what's going on at a network level.

> - This client call fails after 5 minutes(!) with
> org.omg.CORBA.COMM_FAILURE (java.io.IOException: An existing
> connection was forcibly closed by the remote host)

That implies that the client thinks the server closed the connection.

> - Both server calls (answered with about 5K data) get
> giopStream.cc:831(0,NO,COMM_FAILURE_UnMarshalArguments)

That is the normal way that omniORB reports closure of an incoming
connection. It's not directly a sign of a problem. It's only a problem
if the client side doesn't think it has closed the connection.

Can you try to connect to the server with an omniORB client on the same
host as the Java client? That way you'll get consistent logging out of
omniORB, which might help identify what the issue is.

Duncan.

--
-- Duncan Grisby --
-- duncan at grisby.org --
-- http://www.grisby.org --

[evgeni.rojkov]

Hello Duncan,
many thanks for the answer.
Was not omniORB or JavaIDL issue.
Some network problem (now solved) was responsible.
Omniorb.log informations was enough right person cares.
Don't have direct contact so don't have more details.
Many thanks for omniORB,
Eugene


________________________________________
Von: Duncan Grisby [duncan at grisby.org]
Gesendet: Freitag, 18. Juli 2014 16:53
An: Rojkov, Evgeni
Cc: omniORB-list at omniorb-support.com
Betreff: Re: [omniORB] One client call (JavaIDL) creates 2 incoming calls on server (omniORB 4.0.5), both windows

On Thu, 2014-06-26 at 12:58 +0000, evgeni.rojkov at durr.com wrote:

> - One client call (JavaIDL) creates 2 incoming calls on server
> (omniORB 4.0.5).

Sorry for coming to this late...

There's nothing in omniORB that would cause it to duplicate an incoming
call like that. The client must be doing it. You could perhaps use
wireshark or similar to observe what's going on at a network level.

> - This client call fails after 5 minutes(!) with
> org.omg.CORBA.COMM_FAILURE (java.io.IOException: An existing
> connection was forcibly closed by the remote host)

That implies that the client thinks the server closed the connection.

> - Both server calls (answered with about 5K data) get
> giopStream.cc:831(0,NO,COMM_FAILURE_UnMarshalArguments)

That is the normal way that omniORB reports closure of an incoming
connection. It's not directly a sign of a problem. It's only a problem
if the client side doesn't think it has closed the connection.

Can you try to connect to the server with an omniORB client on the same
host as the Java client? That way you'll get consistent logging out of
omniORB, which might help identify what the issue is.

Duncan.

--
-- Duncan Grisby --
-- duncan at grisby.org --
-- http://www.grisby.org --