RCF & Unix domain Socket between versions RCF-2.0.0.2685 and RCF-2.0.1.100

[pedro]

Hello,

I'm using RCF and when I upgrade RCF from RCF-2.0.0.2685 to RCF-2.0.1.100 my application has problems working. It uses Unix Domain Sockets (UnixLocalEndpoint).

It seems that one side sends data but the other side never receives it and falls in timeout.

I'ts quite hard to debug because I didn't write in the first place. Do you have any hints on what changes might have caused this between these two version? Even in the latest version of RCF (3) it doesn't work.

Thank you.

[pedro]

Enabling the logs I Can see this:

Line 939: EXTERNAL/Src/RCF/ThreadPool.cpp(618): [Thread: 503297792][Time: 3151] ThreadPool - thread terminating. [Args: getThreadName()=RCF Server, ]
Line 2979: EXTERNAL/Src/RCF/ThreadPool.cpp(618): [Thread: 503297792][Time: 12552] ThreadPool - thread terminating. [Args: getThreadName()=RCF Server, ]
Line 5029: EXTERNAL/Src/RCF/RcfServer.cpp(252): [Thread: 503297792][Time: 22671] RcfServer - adding service. [Args: typeid(*servicePtr).name()=N3RCF24UnixLocalServerTransportE, ]
Line 5030: EXTERNAL/Src/RCF/RcfServer.cpp(252): [Thread: 503297792][Time: 22671] RcfServer - adding service. [Args: typeid(*servicePtr).name()=N3RCF13FilterServiceE, ]
Line 5031: EXTERNAL/Src/RCF/RcfServer.cpp(252): [Thread: 503297792][Time: 22671] RcfServer - adding service. [Args: typeid(*servicePtr).name()=N3RCF15PingBackServiceE, ]
Line 5032: EXTERNAL/Src/RCF/RcfServer.cpp(252): [Thread: 503297792][Time: 22671] RcfServer - adding service. [Args: typeid(*servicePtr).name()=N3RCF21SessionTimeoutServiceE, ]
Line 5033: EXTERNAL/Src/RCF/RcfServer.cpp(252): [Thread: 503297792][Time: 22671] RcfServer - adding service. [Args: typeid(*servicePtr).name()=N3RCF25CallbackConnectionServiceE, ]
Line 5034: EXTERNAL/Src/RCF/RcfServer.cpp(1305): [Thread: 503297792][Time: 22671] RcfServer - exposing static binding. [Args: name=I_CreateCallbackConnection, ]
Line 5035: EXTERNAL/Src/RCF/RcfServer.cpp(252): [Thread: 503297792][Time: 22671] RcfServer - adding service. [Args: typeid(*servicePtr).name()=N3RCF19ServerObjectServiceE, ]
Line 5036: EXTERNAL/Src/RCF/RcfServer.cpp(252): [Thread: 503297792][Time: 22671] RcfServer - adding service. [Args: typeid(*servicePtr).name()=N3RCF17PublishingServiceE, ]
Line 5037: EXTERNAL/Src/RCF/RcfServer.cpp(1305): [Thread: 503297792][Time: 22671] RcfServer - exposing static binding. [Args: name=I_RequestSubscription, ]
Line 5038: EXTERNAL/Src/RCF/RcfServer.cpp(252): [Thread: 503297792][Time: 22671] RcfServer - adding service. [Args: typeid(*servicePtr).name()=N3RCF19SubscriptionServiceE, ]
Line 5039: EXTERNAL/Src/RCF/RcfServer.cpp(252): [Thread: 503297792][Time: 22671] RcfServer - adding service. [Args: typeid(*servicePtr).name()=N3RCF27SessionObjectFactoryServiceE, ]
Line 5048: EXTERNAL/Src/RCF/RcfServer.cpp(1305): [Thread: 503297792][Time: 22672] RcfServer - exposing static binding. [Args: name=I_SessionObjectFactory, ]
Line 5050: EXTERNAL/Src/RCF/RcfServer.cpp(252): [Thread: 503297792][Time: 22672] RcfServer - adding service. [Args: typeid(*servicePtr).name()=N3RCF20ObjectFactoryServiceE, ]
Line 5052: EXTERNAL/Src/RCF/RcfServer.cpp(1305): [Thread: 503297792][Time: 22672] RcfServer - exposing static binding. [Args: name=I_ObjectFactory, ]
Line 5055: EXTERNAL/Src/RCF/UnixLocalServerTransport.cpp(122): [Thread: 503297792][Time: 22672] UnixLocalSessionState - calling async_accept().
Line 5056: EXTERNAL/Src/RCF/UnixLocalServerTransport.cpp(256): [Thread: 503297792][Time: 22672] UnixLocalServerTransport - listening on local socket. [Args: mFileName=/tmp/.Application/CYSN_uYKEaY, ]
Line 5057: EXTERNAL/Src/RCF/RcfServer.cpp(1305): [Thread: 503297792][Time: 22672] RcfServer - exposing static binding. [Args: name=I_RequestTransportFilters, ]
Line 5072: EXTERNAL/Src/RCF/RcfServer.cpp(394): [Thread: 503297792][Time: 22676] RcfServer - starting service. [Args: typeid(*servicePtr).name()=N3RCF24UnixLocalServerTransportE, ]
Line 5073: EXTERNAL/Src/RCF/RcfServer.cpp(394): [Thread: 503297792][Time: 22677] RcfServer - starting service. [Args: typeid(*servicePtr).name()=N3RCF13FilterServiceE, ]
Line 5074: EXTERNAL/Src/RCF/RcfServer.cpp(394): [Thread: 503297792][Time: 22677] RcfServer - starting service. [Args: typeid(*servicePtr).name()=N3RCF15PingBackServiceE, ]
Line 5075: EXTERNAL/Src/RCF/RcfServer.cpp(394): [Thread: 503297792][Time: 22677] RcfServer - starting service. [Args: typeid(*servicePtr).name()=N3RCF21SessionTimeoutServiceE, ]
Line 5076: EXTERNAL/Src/RCF/RcfServer.cpp(394): [Thread: 503297792][Time: 22677] RcfServer - starting service. [Args: typeid(*servicePtr).name()=N3RCF25CallbackConnectionServiceE, ]
Line 5077: EXTERNAL/Src/RCF/RcfServer.cpp(394): [Thread: 503297792][Time: 22677] RcfServer - starting service. [Args: typeid(*servicePtr).name()=N3RCF19ServerObjectServiceE, ]
Line 5078: EXTERNAL/Src/RCF/RcfServer.cpp(394): [Thread: 503297792][Time: 22677] RcfServer - starting service. [Args: typeid(*servicePtr).name()=N3RCF17PublishingServiceE, ]
Line 5079: EXTERNAL/Src/RCF/RcfServer.cpp(394): [Thread: 503297792][Time: 22677] RcfServer - starting service. [Args: typeid(*servicePtr).name()=N3RCF19SubscriptionServiceE, ]
Line 5080: EXTERNAL/Src/RCF/RcfServer.cpp(394): [Thread: 503297792][Time: 22677] RcfServer - starting service. [Args: typeid(*servicePtr).name()=N3RCF27SessionObjectFactoryServiceE, ]
Line 5081: EXTERNAL/Src/RCF/RcfServer.cpp(394): [Thread: 503297792][Time: 22677] RcfServer - starting service. [Args: typeid(*servicePtr).name()=N3RCF20ObjectFactoryServiceE, ]
Line 5096: EXTERNAL/(Include)/RCF/Future.hpp(245): [Thread: 503297792][Time: 22683] RcfClient - begin remote call. I_CYSRCF::iCYS_SendNotify(). Fnid: 2. Type: R4
Line 5097: EXTERNAL/Src/RCF/Future.cpp(105): [Thread: 503297792][Time: 22683] RcfClient - sending synchronous request. [Args: mpClientStub=0x7f8b04001080, mpClientStub->mRequest=(r.mToken = ( id = 0 ))(r.mSubInterface = I_CYSRCF)(r.mFnId = 2)(r.mSerializationProtocol = 1)(r.mMarshalingProtocol = 1)(r.mOneway = 0)(r.mClose = 0)(r.mService = I_CYSRCF)(r.mRuntimeVersion = 12)(r.mPingBackIntervalMs = 0)(r.mArchiveVersion = 0), ]
Line 5098: EXTERNAL/Src/RCF/Marshal.cpp(185): [Thread: 503297792][Time: 22683] RcfClient - connect to server. [Args: this=0x7f8b04001080, endpoint=Named pipe endpoint "/tmp/.Application/CYS", mConnectTimeoutMs=2000, ]
Line 5099: EXTERNAL/Src/RCF/ConnectionOrientedClientTransport.cpp(352): [Thread: 503297792][Time: 22683] ConnectionOrientedClientTransport - initiating timed send operation. [Args: lengthByteBuffers(data)=6603, totalTimeoutMs=10000, ]
Line 5100: EXTERNAL/Src/RCF/ConnectionOrientedClientTransport.cpp(619): [Thread: 503297792][Time: 22683] ConnectionOrientedClientTransport - initiating write. [Args: lengthByteBuffers(byteBuffers)=6603, ]
Line 5101: EXTERNAL/Src/RCF/BsdClientTransport.cpp(322): [Thread: 503297792][Time: 22683] BsdClientTransport - initiating send on socket. [Args: lengthByteBuffers(byteBuffers)=6603, ]
Line 5102: EXTERNAL/Src/RCF/ConnectionOrientedClientTransport.cpp(610): [Thread: 503297792][Time: 22683] ConnectionOrientedClientTransport - initiating read. [Args: bytesToRead=4, ]
Line 5103: EXTERNAL/Src/RCF/BsdClientTransport.cpp(208): [Thread: 503297792][Time: 22683] BsdClientTransport - initiating read from socket. [Args: byteBuffer.getLength()=4, bytesToRead=4, ]
Line 5236: EXTERNAL/Src/RCF/ConnectionOrientedClientTransport.cpp(260): [Thread: 503297792][Time: 32688] RCF exception thrown. Error message: Remote call timeout exceeded. No response from peer.
Line 5237: EXTERNAL/Src/RCF/ClientStub.cpp(543): [Thread: 503297792][Time: 32712] RcfClient - disconnecting from server. [Args: this=0x7f8b04001080, endpoint=Named pipe endpoint "/tmp/.Application/CYS", ]
Line 5238: EXTERNAL/(Include)/RCF/Future.hpp(252): [Thread: 503297792][Time: 32712] RcfClient - end remote call. I_CYSRCF::iCYS_SendNotify(). Fnid: 2. Type: R4
Line 5239: EXTERNAL/Src/RCF/RcfServer.cpp(409): [Thread: 503297792][Time: 32713] RcfServer - stopping service. [Args: typeid(*servicePtr).name()=N3RCF20ObjectFactoryServiceE, ]
Line 5240: EXTERNAL/Src/RCF/RcfServer.cpp(409): [Thread: 503297792][Time: 32713] RcfServer - stopping service. [Args: typeid(*servicePtr).name()=N3RCF27SessionObjectFactoryServiceE, ]
Line 5241: EXTERNAL/Src/RCF/RcfServer.cpp(409): [Thread: 503297792][Time: 32713] RcfServer - stopping service. [Args: typeid(*servicePtr).name()=N3RCF19SubscriptionServiceE, ]
Line 5242: EXTERNAL/Src/RCF/RcfServer.cpp(409): [Thread: 503297792][Time: 32713] RcfServer - stopping service. [Args: typeid(*servicePtr).name()=N3RCF17PublishingServiceE, ]
Line 5243: EXTERNAL/Src/RCF/RcfServer.cpp(409): [Thread: 503297792][Time: 32713] RcfServer - stopping service. [Args: typeid(*servicePtr).name()=N3RCF19ServerObjectServiceE, ]
Line 5244: EXTERNAL/Src/RCF/RcfServer.cpp(409): [Thread: 503297792][Time: 32713] RcfServer - stopping service. [Args: typeid(*servicePtr).name()=N3RCF25CallbackConnectionServiceE, ]
Line 5245: EXTERNAL/Src/RCF/RcfServer.cpp(409): [Thread: 503297792][Time: 32713] RcfServer - stopping service. [Args: typeid(*servicePtr).name()=N3RCF21SessionTimeoutServiceE, ]
Line 5246: EXTERNAL/Src/RCF/RcfServer.cpp(409): [Thread: 503297792][Time: 32713] RcfServer - stopping service. [Args: typeid(*servicePtr).name()=N3RCF15PingBackServiceE, ]
Line 5247: EXTERNAL/Src/RCF/RcfServer.cpp(409): [Thread: 503297792][Time: 32713] RcfServer - stopping service. [Args: typeid(*servicePtr).name()=N3RCF13FilterServiceE, ]
Line 5248: EXTERNAL/Src/RCF/RcfServer.cpp(409): [Thread: 503297792][Time: 32713] RcfServer - stopping service. [Args: typeid(*servicePtr).name()=N3RCF24UnixLocalServerTransportE, ]
Line 5250: EXTERNAL/Src/RCF/AsioServerTransport.cpp(298): [Thread: 503297792][Time: 32713] AsioSessionState - destructor. [Args: mState=1, mSessionPtr.get()=0x7f8b04006ca0, mSessionPtr->mDisableIo=1, ]
Line 5251: EXTERNAL/Src/RCF/ClientStub.cpp(543): [Thread: 503297792][Time: 32713] RcfClient - disconnecting from server. [Args: this=0x7f8b04001080, endpoint=Named pipe endpoint "/tmp/.Application/CYS", ]
Line 5252: EXTERNAL/Src/RCF/ClientStub.cpp(543): [Thread: 503297792][Time: 32713] RcfClient - disconnecting from server. [Args: this=0x7f8b04001080, endpoint=Named pipe endpoint "/tmp/.Application/CYS", ]


And looking at the release note I see that version RCF-2.0.1.100 has this :
Publish/subscribe - published messages are now sent asynchronously and concurrently on all subscriber connections.

Could it come from this ?

[pedro]

I've switched to RCF::TcpEndpoint, and I have exactly the same error.

[pedro]

It comes from the publisher/subscriber part. But I can't tell why it was working before and not now.

I am now pretty sure this is the cause =>"Publish/subscribe - published messages are now sent asynchronously and concurrently on all subscriber connections."

It's hard to know what change cause this behaviour. Is there a compile flag to use the old behaviour to confirm my understanding of the problem?

[jarl]

Hi,

Sorry for the late response. I'm currently traveling and have unreliable internet access.

The change to asynchronous I/O for pub/sub is probably what's causing the exception you're getting. Can you try configuring a thread pool for the RcfServer that is doing the publishing? I don't have the code available to me at the moment but there should be a RcfServer::setThreadPool() function that you can use to configure a thread pool with multiple threads. The extra threads are needed to make the async publishing mechanism work.

[pedro]

Hello,

Don't worry for the late response, I was just afraid to never get a response
It works on the version RCF-2.0.1.100. I will try on the last one (3.0) to see if it works too. Not depending on boost would be great ^^
And if it works we will buy the upgrade !

I'll come back to tell you if it works.

Thanks again.

[pedro]

Works on version 3 too.

[jarl]

OK, glad it's working.