More data.
It appears that a single remote call is getting split into three distinct writes, each of which gets an index. The final index is what is included in the response. The next remote call then fails with an index mismatch:
Code: Select all
19:31:53.607 - RCF/include/RCF/Future.hpp(245): [Thread: 13468][Time: 2948] RcfClient - begin remote call. I_CDEngine::reserveEngine(). Fnid: 1. Type: R7
19:31:53.607 - rcf/src/rcf/Future.cpp(105): [Thread: 13468][Time: 2948] RcfClient - sending synchronous request. [Args: mpClientStub=167BA288, mpClientStub->mRequest=(r.mToken = ( id = 0 ))(r.mSubInterface = I_CDEngine)(r.mFnId = 1)(r.mSerializationProtocol = 1)(r.mMarshalingProtocol = 1)(r.mOneway = 0)(r.mClose = 0)(r.mService = I_CDEngine)(r.mRuntimeVersion = 12)(r.mPingBackIntervalMs = 0)(r.mArchiveVersion = 0), ]
19:31:53.607 - rcf/src/rcf/ConnectedClientTransport.cpp(362): [Thread: 13468][Time: 2948] ConnectionOrientedClientTransport - initiating timed send operation. [Args: lengthByteBuffers(data)=620, totalTimeoutMs=10000, ]
19:31:53.607 - rcf/src/rcf/ConnectedClientTransport.cpp(619): [Thread: 13468][Time: 2948] ConnectionOrientedClientTransport - initiating write. [Args: lengthByteBuffers(byteBuffers)=620, ]
19:31:53.607 - rcf/src/rcf/HttpFrameFilter.cpp(786): [Thread: 13468][Time: 2948] Sending HTTP message. [Args: this=167BB3A0, frameLen=482, "\n" + httpMessageHeader=
POST / HTTP/1.1
Host: 192.168.119.35:9999
Accept: */*
Connection: Keep-Alive
X-RCFSessionId: cf554273-4d19-4fa6-941c-9a11099a05dc
X-RCFSessionIndex: 9
Content-Length: 302
, ]
19:31:53.607 - rcf/src/rcf/BsdClientTransport.cpp(320): [Thread: 13468][Time: 2948] BsdClientTransport - initiating send on socket. [Args: lengthByteBuffers(byteBuffers)=482, ]
19:31:53.607 - rcf/src/rcf/ConnectedClientTransport.cpp(619): [Thread: 13468][Time: 2948] ConnectionOrientedClientTransport - initiating write. [Args: lengthByteBuffers(byteBuffers)=347, ]
19:31:53.607 - rcf/src/rcf/HttpFrameFilter.cpp(786): [Thread: 13468][Time: 2948] Sending HTTP message. [Args: this=167BB3A0, frameLen=467, "\n" + httpMessageHeader=
POST / HTTP/1.1
Host: 192.168.119.35:9999
Accept: */*
Connection: Keep-Alive
X-RCFSessionId: cf554273-4d19-4fa6-941c-9a11099a05dc
X-RCFSessionIndex: 10
Content-Length: 286
, ]
19:31:53.607 - rcf/src/rcf/BsdClientTransport.cpp(320): [Thread: 13468][Time: 2948] BsdClientTransport - initiating send on socket. [Args: lengthByteBuffers(byteBuffers)=467, ]
19:31:53.607 - rcf/src/rcf/ConnectedClientTransport.cpp(619): [Thread: 13468][Time: 2948] ConnectionOrientedClientTransport - initiating write. [Args: lengthByteBuffers(byteBuffers)=90, ]
19:31:53.607 - rcf/src/rcf/HttpFrameFilter.cpp(786): [Thread: 13468][Time: 2948] Sending HTTP message. [Args: this=167BB3A0, frameLen=300, "\n" + httpMessageHeader=
POST / HTTP/1.1
Host: 192.168.119.35:9999
Accept: */*
Connection: Keep-Alive
X-RCFSessionId: cf554273-4d19-4fa6-941c-9a11099a05dc
X-RCFSessionIndex: 11
Content-Length: 119
, ]
19:31:53.607 - rcf/src/rcf/BsdClientTransport.cpp(320): [Thread: 13468][Time: 2948] BsdClientTransport - initiating send on socket. [Args: lengthByteBuffers(byteBuffers)=300, ]
19:31:53.607 - rcf/src/rcf/ConnectedClientTransport.cpp(610): [Thread: 13468][Time: 2948] ConnectionOrientedClientTransport - initiating read. [Args: bytesToRead=4, ]
19:31:53.607 - rcf/src/rcf/BsdClientTransport.cpp(208): [Thread: 13468][Time: 2948] BsdClientTransport - initiating read from socket. [Args: byteBuffer.getLength()=1024, bytesToRead=1024, ]
19:31:53.744 - rcf/src/rcf/HttpFrameFilter.cpp(424): [Thread: 13468][Time: 3089] Received HTTP message [Args: this=167BB3A0, mHttpMessage.mFrameLen=0, "\n" + mHttpMessage.mHttpMessageHeader=
HTTP/1.1 200 OK
X-RCFSessionId: cf554273-4d19-4fa6-941c-9a11099a05dc
X-RCFSessionIndex: 11
Content-Length: 108
Connection: Keep-Alive
, ]
19:31:53.744 - rcf/src/rcf/ConnectedClientTransport.cpp(610): [Thread: 13468][Time: 3089] ConnectionOrientedClientTransport - initiating read. [Args: bytesToRead=75, ]
19:31:53.744 - rcf/src/rcf/Marshal.cpp(593): [Thread: 13468][Time: 3089] RcfClient - received response. [Args: this=167BA288, response=(r.mException = 0)(r.mError = 0), ]
19:31:53.744 - RCF/include/RCF/Future.hpp(252): [Thread: 13468][Time: 3089] RcfClient - end remote call. I_CDEngine::reserveEngine(). Fnid: 1. Type: R7
19:31:53.744 - RCF/include/RCF/Future.hpp(245): [Thread: 13468][Time: 3089] RcfClient - begin remote call. I_CDEngine::addRAL(). Fnid: 19. Type: V4
19:31:53.745 - rcf/src/rcf/Future.cpp(105): [Thread: 13468][Time: 3089] RcfClient - sending synchronous request. [Args: mpClientStub=167BA288, mpClientStub->mRequest=(r.mToken = ( id = 0 ))(r.mSubInterface = I_CDEngine)(r.mFnId = 19)(r.mSerializationProtocol = 1)(r.mMarshalingProtocol = 1)(r.mOneway = 0)(r.mClose = 0)(r.mService = I_CDEngine)(r.mRuntimeVersion = 12)(r.mPingBackIntervalMs = 0)(r.mArchiveVersion = 0), ]
19:31:53.745 - rcf/src/rcf/ConnectedClientTransport.cpp(362): [Thread: 13468][Time: 3089] ConnectionOrientedClientTransport - initiating timed send operation. [Args: lengthByteBuffers(data)=212, totalTimeoutMs=10000, ]
19:31:53.745 - rcf/src/rcf/ConnectedClientTransport.cpp(619): [Thread: 13468][Time: 3089] ConnectionOrientedClientTransport - initiating write. [Args: lengthByteBuffers(byteBuffers)=212, ]
19:31:53.745 - rcf/src/rcf/HttpFrameFilter.cpp(786): [Thread: 13468][Time: 3089] Sending HTTP message. [Args: this=167BB3A0, frameLen=422, "\n" + httpMessageHeader=
POST / HTTP/1.1
Host: 192.168.119.35:9999
Accept: */*
Connection: Keep-Alive
X-RCFSessionId: cf554273-4d19-4fa6-941c-9a11099a05dc
X-RCFSessionIndex: 12
Content-Length: 241
, ]
19:31:53.745 - rcf/src/rcf/BsdClientTransport.cpp(320): [Thread: 13468][Time: 3089] BsdClientTransport - initiating send on socket. [Args: lengthByteBuffers(byteBuffers)=422, ]
19:31:53.745 - rcf/src/rcf/ConnectedClientTransport.cpp(610): [Thread: 13468][Time: 3089] ConnectionOrientedClientTransport - initiating read. [Args: bytesToRead=4, ]
19:31:53.745 - rcf/src/rcf/BsdClientTransport.cpp(208): [Thread: 13468][Time: 3089] BsdClientTransport - initiating read from socket. [Args: byteBuffer.getLength()=1024, bytesToRead=1024, ]
19:31:53.745 - rcf/src/rcf/HttpFrameFilter.cpp(424): [Thread: 13468][Time: 3089] Received HTTP message [Args: this=167BB3A0, mHttpMessage.mFrameLen=0, "\n" + mHttpMessage.mHttpMessageHeader=
HTTP/1.1 400 Bad Request
X-RCFError: HTTP session index mismatch on request. Expected index: 10 . Actual index: 12 .
Content-Length: 0
, ]
19:31:53.745 - rcf/src/rcf/HttpFrameFilter.cpp(468): [Thread: 13468][Time: 3089] RCF exception thrown. Error message: HTTP tunnel error. HTTP session index mismatch on request. Expected index: 10 . Actual index: 12 .
19:31:53.745 - rcf/src/rcf/ClientStub.cpp(447): [Thread: 13468][Time: 3089] RcfClient - disconnecting from server. [Args: this=167BA288, endpoint=http://192.168.119.35:9999, ]
19:31:53.745 - rcf/src/rcf/ClientStub.cpp(447): [Thread: 13468][Time: 3089] RcfClient - disconnecting from server. [Args: this=167BA288, endpoint=http://192.168.119.35:9999, ]
19:31:53.746 - RCF/include/RCF/Future.hpp(252): [Thread: 13468][Time: 3089] RcfClient - end remote call. I_CDEngine::addRAL(). Fnid: 19. Type: V4