1

最近有一个问题真的很挑战我,我已经浪费了将近 15 天来找出根本原因。但不幸的是,到目前为止还没有运气。

以下是详细信息,

作为我们在应用程序中向客户提供的功能的一部分,客户可以排队作业列表并让它在后台运行,并在他们排队的作业完成后让客户知道。

每个作业都应该执行 ~100K mdx 查询以完成并获得成功结果。但在幕后,我们的引擎将这 10 万个查询分成更小的块,并为每个块创建具有较少查询量的作业。在这种情况下,小型作业正在处理 1000 个查询。有了这个粗略的数字,我可以看出引擎正在创造 100 个额外的工作。然后我们的引擎开始一一执行这些小块。

并且在每个作业执行中,它都会在以下代码中运行 RunAndParseQueryResult 方法。

class Snippet
{
    public static void RunAndParseQueryResult()
    {
        DataTable result = new DataTable();
        IDbConnection conn = ConnectionFactory.CreateConnection();
        conn.Open();
        foreach (string mdxQuery in queryList)
        {
              ExecuteMdxQuery(IDbConnection connection, DataTable result, string mdxQuery)
        }
        conn.Close();
        conn.Dispose();
    }

    private void ExecuteMdxQuery(IDbConnection connection, DataTable result, string mdxQuery)
    {
        var conn = connection as AdomdConnection;
        Trace.TraceInformation("Log 1");
        if (conn != null)
        {
            Trace.TraceInformation("Log 2");
            using (AdomdCommand command = new AdomdCommand(mdxFile.Mdx, conn) { CommandTimeout = 5000 })
            {
                Trace.TraceInformation("Log 3");
                using (AdomdDataAdapter adapter = new AdomdDataAdapter(command))
                {
                    Trace.TraceInformation("Log 4");
                    try
                    {
                        DataTable dt = new DataTable();
                        Trace.TraceInformation("Log 5");
                        dt.BeginLoadData();
                        Trace.TraceInformation("Log 6");
                        adapter.Fill(dt);
                        Trace.TraceInformation("Log 7");
                        dt.EndLoadData();
                        Trace.TraceInformation("Log 8");

                        if (dt.Rows.Any())
                        {
                            Trace.TraceInformation("Log 9");
                            ParseQueryResult(result, mdxFile, dt);
                            Trace.TraceInformation("Log 10");
                        }
                    }
                    catch (Exception exception)
                    {
                        Trace.TraceInformation("Log 11");
                        throw;
                    }
                }
            }
        }
        else
        {
            throw new Exception("Given cube connection can not be casted to AdoMdConnection");
        }
    }
}

如您所见,RunAndParseQueryResult 方法打开连接并将其与 mdxQuery 循环变量一起传递给 ExecuteMdxQuery 方法。

在 ExecuteMdxQuery 方法中,几乎在每一行之后,我都使用 Trace.TraceInformation 方法放置了一个日志。

发生的事情是在某些迭代 ExecuteMdxQuery 方法停止在

 adapter.Fill(dt);

方法。我通过查看日志来解决这个问题。因为如果它成功执行,我会看到像“Log 7”这样的日志,或者如果它执行失败,我应该能够看到“Log 11”。但是这些行似乎都没有运行。

当我手动运行查询时,它工作正常。该查询绝对不是长时间运行的查询,即使它是,我们已经指定了超时 5000 秒

AdomdCommand command = new AdomdCommand(mdxFile.Mdx, conn) { CommandTimeout = 5000 }

代码,它假设正常抛出 TimeOutException。但事实并非如此。

任何意见为什么会这样?

先感谢您。

4

1 回答 1

1

经过大量的努力和长时间的耐心,我们在微软支持的帮助下了解了这个问题的根本原因。

最后,问题原来与 AdoMD.Net 中的 CommandTimeout 属性行为有关。

在网络故障的情况下,CommandTimeout 设置无法按预期工作。

为了确定问题,我们必须在应用程序挂起并且不再执行查询时创建客户端应用程序的转储。

使用 WinDbg 工具,我们发现,在发生挂起时,应用程序正在等待 System.Net 命名空间下的某些方法。以下是我们从转储文件中得到的堆栈跟踪。

a15e18d548 7ffa07f306fa [InlinedCallFrame: 000000a15e18d548] System.Net.UnsafeNclNativeMethods+OSSOCK.recv(IntPtr, Byte*, Int32, System.Net.Sockets.SocketFlags)
a15e18d548 7ff99b7757af [InlinedCallFrame: 000000a15e18d548] System.Net.UnsafeNclNativeMethods+OSSOCK.recv(IntPtr, Byte*, Int32, System.Net.Sockets.SocketFlags)
a15e18d520 7ff99b7757af DomainBoundILStubClass.IL_STUB_PInvoke(IntPtr, Byte*, Int32, System.Net.Sockets.SocketFlags)
a15e18d5f0 7ff99b7761be System.Net.Sockets.Socket.Receive(Byte[], Int32, Int32, System.Net.Sockets.SocketFlags, System.Net.Sockets.SocketError ByRef)
a15e18d690 7ff99b775d35 System.Net.Sockets.NetworkStream.Read(Byte[], Int32, Int32)
a15e18d710 7ff99b775be9 System.Net.FixedSizeReader.ReadPacket(Byte[], Int32, Int32)
a15e18d760 7ff99b782839 System.Net.Security._SslStream.StartFrameHeader(Byte[], Int32, Int32, System.Net.AsyncProtocolRequest)
a15e18d7d0 7ff99b78237a System.Net.Security._SslStream.StartReading(Byte[], Int32, Int32, System.Net.AsyncProtocolRequest)
a15e18d850 7ff99b781fab System.Net.Security._SslStream.ProcessRead(Byte[], Int32, Int32, System.Net.AsyncProtocolRequest)
a15e18d8d0 7ff99b781d6e System.Net.TlsStream.Read(Byte[], Int32, Int32)
a15e18d960 7ff99b781c93 System.Net.PooledStream.Read(Byte[], Int32, Int32)
a15e18d990 7ff99b781499 System.Net.Connection.SyncRead(System.Net.HttpWebRequest, Boolean, Boolean)
a15e18da20 7ff99b76d694 System.Net.ConnectStream.WriteHeaders(Boolean)
a15e18dad0 7ff99b76bb44 System.Net.HttpWebRequest.EndSubmitRequest()
a15e18db20 7ff99b762e58 System.Net.Connection.SubmitRequest(System.Net.HttpWebRequest, Boolean)
a15e18dbb0 7ff99b76120e System.Net.ServicePoint.SubmitRequest(System.Net.HttpWebRequest, System.String)
a15e18dc20 7ff99b60eda4 System.Net.HttpWebRequest.SubmitRequest(System.Net.ServicePoint)
a15e18dc80 7ff99b60ded1 System.Net.HttpWebRequest.GetResponse()
a15e18dd30 7ff99d474f7c Microsoft.AnalysisServices.AdomdClient.HttpStream.GetResponseStream()
a15e18de20 7ff99d474ac0 Microsoft.AnalysisServices.AdomdClient.HttpStream.GetResponseDataType()
a15e18de90 7ff99d4743cc Microsoft.AnalysisServices.AdomdClient.CompressedStream.GetResponseDataType()
a15e18def0 7ff99d470745 Microsoft.AnalysisServices.AdomdClient.XmlaClient.EndRequest()
a15e18df70 7ff99d4702f7 Microsoft.AnalysisServices.AdomdClient.XmlaClient.SendMessage(Boolean, Boolean, Boolean)
a15e18dfe0 7ff99d558f0a Microsoft.AnalysisServices.AdomdClient.XmlaClient.ExecuteStatement(System.String, System.Collections.IDictionary, System.Collections.IDictionary, System.Data.IDataParameterCollection, Boolean)
a15e18e040 7ff99d558037 Microsoft.AnalysisServices.AdomdClient.AdomdConnection+XmlaClientProvider.Microsoft.AnalysisServices.AdomdClient.IExecuteProvider.ExecuteTabular(System.Data.CommandBehavior, Microsoft.AnalysisServices.AdomdClient.ICommandContentProvider, Microsoft.AnalysisServices.AdomdClient.AdomdPropertyCollection, System.Data.IDataParameterCollection)
a15e18e0e0 7ff99d557b28 Microsoft.AnalysisServices.AdomdClient.AdomdCommand.ExecuteReader(System.Data.CommandBehavior)

正如您从堆栈跟踪中看到的那样,在 Receive 方法中发生了挂起

System.Net.Sockets.Socket

命名空间。

在此之后,我们决定在分析服务和客户端应用程序端捕获网络跟踪。当我们在两端捕获跟踪时,有趣的是,挂起问题不再发生。然后我们只捕获了 SSAS 服务器上的网络跟踪。

NetMon 跟踪屏幕截图

从上面的截图可以看出,SSAS 尝试重新发送响应 9 次,最后超时并断开 TCP 通信。

这导致我们认为客户端有时会丢失网络连接。当客户端尝试重新建立网络连接时,SSAS 端已经准备好结果,并且 SSAS 正在尝试将结果传输到客户端。从网络跟踪中可以看出,在我的示例中它尝试了 9 次。最后它放弃了更多的尝试。发生的事情是,在这 9 次试用期间,如果客户端重新建立网络连接,那么一切都按预期进行,但是如果客户端在重试结束后建立连接,那么客户端会继续等待,尽管服务器已经尝试过回复客户。此时,作为客户端,我们希望它至少尊重 CommandTimeout 属性。并在达到 CommandTimeout 时使执行失败。但它不这样做。

作为一种解决方法,我们意识到,还有另一个连接字符串属性

Timeout:指定客户端库在生成错误之前等待命令完成的时间(以秒为单位)。关联

当我们在网络故障的情况下设置超时时,正在发生连接超时,因此查询执行失败。客户端永远不会挂起。虽然,在命令超时的情况下,我们不希望出现连接丢失,但这是我们在产品团队修复 CommandTimout 属性行为之前所拥有的。

谢谢你。

于 2016-12-19T21:30:43.770 回答