MQQueue.Get()
operation freezes for 5 minutes when getting a message from QueueManager using SSL on .NetCore 3.1. The same code works fine when running on .Net Framework (v4.8) or without SSL on both runtimes.
Details:
- Client: MQ Managed Client from NuGet (IBMMQDotnetClient/v9.1.4)
- Server: docker from tag ibmcom/mq:9.1.4.0-r1 with basic SSL config using
SSLCIPH(ANY_TLS12) SSLCAUTH(OPTIONAL)
- Reproduced on: .Net Core 3.1.2 on Windows and .Net Core 3.1.1 on Linux
- MQ Logs: MqGet-framework48.zip, MqGet-core31.zip
My Findings:
- The attached
MqGet-core31
tells:- The client sends the get message request at 09:15:52.199588
- It receives response with message body almost immediately at 09:15:52.311050
- Then it calls another
MQRcvThread.ReceiveOneTSH()
to finish the get operation. It callsMQTCPConnection.Receive()
and it freeze for 5 minutes to 09:20:52.412669
- Possible reason:
MQTCPConnection
keeps originalsocket
andMQEncryptedSocket
instance wrapping the samesocket
viaSslStream
- The method
MQTCPConnection.Receive()
polls on thesocket
and then it callsMQEncryptedSocket.Read()
- It looks like that data from the
socket
are read bySslStream
inMQEncryptedSocket
before thepoll()
method is called andpoll()
waits for its 5 minutes timeout. Or any other race condition around? - If I put a breakpoint before problematic
poll()
call and delay it for a moment, then it often passess without any delay!
Test Code:
This code finishes in ~2 seconds on .Net Framework, but it needs 5 minutes and ~2 seconds when it is run on .Net Core. (Win or Linux)
// import server's CA
MQConnectionPool.ImportServerCertificateAuthorityIfNotPresent(CertMqTestCa);
Hashtable properties = new Hashtable {
{MQC.HOST_NAME_PROPERTY, Mq1QmSslAnyTls12.Host},
{MQC.PORT_PROPERTY, Mq1QmSslAnyTls12.Port},
{MQC.CHANNEL_PROPERTY, Mq1QmSslAnyTls12.ChannelName},
{MQC.USER_ID_PROPERTY, "admin"},
{MQC.PASSWORD_PROPERTY, "changeit"},
{MQC.CCSID_PROPERTY, 819},
{MQC.SSL_CIPHER_SPEC_PROPERTY, "TLS_RSA_WITH_AES_256_CBC_SHA256"},
{MQC.SSL_CERT_STORE_PROPERTY, "*USER"}
};
MQQueueManager queueManager;
using (new MQCcsidSetter(properties)) {
queueManager = new MQQueueManager(null, properties);
}
string requestText = Guid.NewGuid().ToString();
string queueName = "SV.MqConnectionPoolTest";
// put message - works fine
using (MQQueue queue = queueManager.AccessQueue(queueName, MQC.MQOO_OUTPUT + MQC.MQOO_FAIL_IF_QUIESCING)) {
byte[] requestBytes = Encoding.UTF8.GetBytes(requestText);
MQMessage requestMessage = new MQMessage {Expiry = 3000, Priority = 4, CharacterSet = 1208, MessageType = MQC.MQMT_DATAGRAM};
requestMessage.Write(requestBytes, 0, requestBytes.GetLength(0));
queue.Put(requestMessage, new MQPutMessageOptions());
}
// get message back from the same queue
using (MQQueue queue = queueManager.AccessQueue(queueName, MQC.MQOO_INPUT_AS_Q_DEF + MQC.MQOO_FAIL_IF_QUIESCING)) {
while (true) {
MQMessage msg = new MQMessage();
queue.Get(msg, new MQGetMessageOptions()); // <<= !!!IT IS DELAYED HERE!!!
msg.Seek(0);
string msgContent = msg.ReadString(msg.MessageLength);
if (requestText.Equals(msgContent)) {
break;
}
}
}
Thread Dumps:
- MQ Client Receiver Thread
SocketPal.Poll()
Socket.Poll()
MQTCPConnection.Receive()
MQRcvThread.ReceiveBuffer()
MQRcvThread.ReceiveOneTSH()
MQRcvThread.Run()
ThreadHelper.ThreadStart_Context()
ExecutionContext.RunInternal()
ThreadHelper.ThreadStart()
Waits on Poll()
, but it ends with 5 minute (heartbeat) timeout. Then it goes to this.network.Read()
and immediately gets proper data.
this.socket.SetSocketOption(SocketOptionLevel.Socket, SocketOptionName.ReceiveTimeout, this.timeout);
if (this.socket.Poll(this.timeout * 1000, SelectMode.SelectRead))
{
length2 = this.network.Read(cBuffer, offset1, length1);
- Application Thread
Monitor.Wait()
MQSession.ExchangeTSH()
MQProxyQueue.RequestMessages()
MQProxyQueue.FlushQueue()
MQProxyQueue.ProxyMQGET()
MQFAP.zstMQGET()
MQFAP.MQGET()
MQDestination.Get()
MQDestination.Get()
MqConnectionPoolTest.TestMqDirect()
Waits for entry.Reply
to be filled by receive thread:
while (entry.Reply == null) {
Monitor.Wait((object) entry, this.rmtReqEntMaxPollTime, true);
...
Please, does anybody know a workaround or has a fix?