asp.net-mvc-3 - Glimpse HUD 和 SQL 选项卡中的数据库查询计数之间存在差异

Question

这个问题涉及 Glimpse.MVC3 和 Glimpse.EF5 包。我正在尝试调试旧 MVC3 站点上的性能问题。根据 Glimpse 的 HUD，特定的 GET 请求总共 28 毫秒有 12 个查询 - 但是当我展开以打开主面板并单击SQL 选项卡，它显示总共 10.41ms 仅有 6 个查询。顶部的计数显示为 6，当我计算它列出的查询时，有 6 个。当我看到编写的代码时，这也是有意义的。 (无论哪种方式，我都可以看到太多的延迟加载，需要修复。)

Glimpse 没有迹象表明相同的 6 个查询被执行了两次(当我看到 HUD 显示的数字是面板的两倍时，我的大脑就会想到这一点)。

此外，HUD 显示 0 个 Ajax 请求，但历史记录部分实际上显示 1 (这绝对是准确的)。

您知道为什么会出现差异吗？ (请记住，我更关心查询的差异。)

编辑 - 根据请求从文件中获取 JSON:

glimpse_sql:
{
  data:
  {
    "SQL Statistics":
    [
      {
        connectionCount: 6
        queryCount: 6
        transactionCount: 0
        queryExecutionTime: 6.91
        connectionOpenTime: 116.08
      }
    ]
    Queries:
    [
      [
        Commands per Connection
        Duration
      ]

hud:
  {
    sql:
    {
      data:
      {
        queryCount: 12
        connectionCount: 12
        transactionCount: 0
        queryExecutionTime: 41.87
        connectionOpenTime: 242.96
      }
      name: sql
    }

编辑 2 - 查询

"Queries":[["Commands per Connection","Duration"],

[[["Transaction Start","Ordinal","Command","Parameters","Records","Duration","Offset","Async","Transaction End","Errors"],[null,"1","SELECT TOP (2) \r\n[Extent1].[TrxnID] AS [TrxnID], \r\n[Extent1].[StartTime] AS [StartTime], \r\n[Extent1].[Lane] AS [Lane], \r\n[Extent1].[EmployeeID] AS [EmployeeID], \r\n[Extent1].[OptionsCompleted] AS [OptionsCompleted], \r\n[Extent1].[StoreID] AS [StoreID], \r\n[Extent1].[NoVehicleTireCheck] AS [NoVehicleTireCheck], \r\nFROM [Activity].[Trxn] AS [Extent1]\r\nWHERE [Extent1].[TrxnID] = 353 /* @p__linq__0 */",[["Name","Value","Type","Size"],["@p__linq__0",353,"Int32",0]],1,1.12,76.67,false,null,null,""]],5.85],

[[["Transaction Start","Ordinal","Command","Parameters","Records","Duration","Offset","Async","Transaction End","Errors"],[null,"1","SELECT \r\n[Extent1].[TrxnID] AS [TrxnID], \r\n[Extent1].[CustomerID] AS [CustomerID], \r\n[Extent1].[FirstName] AS [FirstName], \r\n[Extent1].[LastName] AS [LastName], \r\n[Extent1].[RewardAccountID] AS [RewardAccountID], \r\n[Extent1].[CustomerEmail] AS [CustomerEmail], \r\n[Extent1].[HomePhone] AS [HomePhone]\r\nFROM [Activity].[Trxn_Customers] AS [Extent1]\r\nWHERE [Extent1].[TrxnID] = 353 /* @EntityKeyValue1 */",[["Name","Value","Type","Size"],["@EntityKeyValue1",353,"Int32",0]],0,1.18,102.7,false,null,null,""]],21.7],

[[["Transaction Start","Ordinal","Command","Parameters","Records","Duration","Offset","Async","Transaction End","Errors"],[null,"1","SELECT \r\n[Extent1].[TrxnID] AS [TrxnID], \r\n[Extent1].[VehicleID] AS [VehicleID], \r\n[Extent1].[VehicleVIN] AS [VehicleVIN], \r\n[Extent1].[VehicleOdometer] AS [VehicleOdometer], \r\n[Extent1].[VehicleEngineID] AS [VehicleEngineID], \r\n[Extent1].[VehicleMakeID] AS [VehicleMakeID], \r\n[Extent1].[ModelYear] AS [ModelYear]\r\nFROM [Activity].[Trxn_Vehicles] AS [Extent1]\r\nWHERE [Extent1].[TrxnID] = 353 /* @EntityKeyValue1 */",[["Name","Value","Type","Size"],["@EntityKeyValue1",353,"Int32",0]],0,1.26,2301.56,false,null,null,""]],27.72],

[[["Transaction Start","Ordinal","Command","Parameters","Records","Duration","Offset","Async","Transaction End","Errors"],[null,"1","SELECT \r\n[Extent1].[TrxnID] AS [TrxnID], \r\n[Extent1].[SecondaryVehicleID] AS [SecondaryVehicleID], \r\n[Extent1].[SecondaryVehicleVIN] AS [SecondaryVehicleVIN], \r\n[Extent1].[SecondaryVehicleTypeID] AS [SecondaryVehicleTypeID], \r\n FROM [Activity].[Trxn_SecondaryVehicles] AS [Extent1]\r\n WHERE [Extent1].[TrxnID] = 353 /* @EntityKeyValue1 */",[["Name","Value","Type","Size"],["@EntityKeyValue1",353,"Int32",0]],0,1.15,2325.95,false,null,null,""]],23.15],

[[["Transaction Start","Ordinal","Command","Parameters","Records","Duration","Offset","Async","Transaction End","Errors"],[null,"1","SELECT \r\n[Extent1].[TrxnServiceID] AS [TrxnServiceID], \r\n[Extent1].[TrxnID] AS [TrxnID], \r\n[Extent1].[PackageID] AS [PackageID], \r\n[Extent1].[PartID] AS [PartID], \r\n[Extent1].[Qty] AS [Qty]\r\nFROM [Activity].[Trxn_Services] AS [Extent1]\r\nWHERE [Extent1].[TrxnID] = 353 /* @EntityKeyValue1 */",[["Name","Value","Type","Size"],["@EntityKeyValue1",353,"Int32",0]],0,1.02,2342.92,false,null,null,""]],15.74],

[[["Transaction Start","Ordinal","Command","Parameters","Records","Duration","Offset","Async","Transaction End","Errors"],[null,"1","SELECT \r\n[Extent1].[TrxnNoteID] AS [TrxnNoteID], \r\n[Extent1].[TrxnID] AS [TrxnID], \r\n[Extent1].[NoteText] AS [NoteText], \r\n[Extent1].[NoteNumber] AS [NoteNumber], \r\n[Extent1].[SendToInvoice] AS [SendToInvoice]\r\nFROM [Activity].[Trxn_Notes] AS [Extent1]\r\nWHERE [Extent1].[TrxnID] = 353 /* @EntityKeyValue1 */",[["Name","Value","Type","Size"],["@EntityKeyValue1",353,"Int32",0]],0,1.19,4689.34,false,null,null,""]],21.92]

]},"name":"SQL"}

Answer 1

嗯，我明白了。但首先，请查看出现问题所需的确切使用场景。

使用场景
仅当您执行以下操作时才会出现此问题:
A。为上下文启用延迟加载。
b.将您的 EF 模型直接传递给 View ，并且不要使用 View 模型(无论如何，这都不是一个好的实践，但正是此遗留代码所做的)。

我学到了什么
1) 事实证明，HUD 显示的较高数量的查询是正确的 - SQL Server Profiler 揭示了这一点。

2) Glimpse 本身似乎正在触发额外的查询。当我打开“元数据”选项卡时，它似乎以某种方式访问​​导航属性，从而导致延迟加载。如果我关闭 Glimpse，或保持 Glimpse 打开但禁用“元数据”选项卡，则不会发生额外的查询。

说明
我花了一段时间才弄清楚这一点，因为我搜索了代码并构建了一个测试场景来隔离问题。在其中，我检索了一条记录，之后没有触及任何导航属性。通过它，我确信我的代码中没有访问任何导航属性来导致它 - 但应用程序仍然生成所有这些额外的查询，并且我完全困惑在哪里 他们来自。

我最终放弃了解决这个问题，禁用了上下文的延迟加载(这可以防止额外的调用)，但随后在导航属性之一上抛出了 NullReferenceException 。我已经急切地加载了这个特定的导航属性，所以我更困惑为什么它是空的。在该导航属性上设置断点，我发现它被击中两次 - 一次是在我调用它时(当时它不为空)，但随后是第二次之后 em> 我的View/Razor代码已经编译完成了，它又神秘地被击中了。 调用堆栈似乎指向它来自 Glimpse。果然，我能够继续处理异常并加载页面(没有错误或丢失数据)，但 Glimpse 在引用该属性的“元数据”选项卡。我将两个和两个放在一起，尝试打开/关闭 Glimpse，然后禁用“元数据”选项卡。无论哪种情况，额外的查询都会停止，并且在 Glimpse 打开但元数据选项卡禁用的情况下，HUD 和 SQL 选项卡查询计数匹配。问题解决了。

现在要澄清的是，我并不是说这是我前面提到的性能问题的原因 - 当性能问题开始时，Glimpse 甚至没有安装，据我所知，Glimpse 在 Release模式下默认是关闭的。性能问题是由代码中发生的一些明显的延迟加载引起的。 但是，当我修复了代码中发生的延迟加载时，HUD 选项卡中的查询计数并没有减少太多，并且性能也没有增加 - 现在这是有道理的。 对于我从代码中删除的每个延迟加载查询，Glimpse 都会通过访问“元数据”选项卡的导航属性在幕后生成一个查询。

底线/TLDR:禁用“Glimpse Metadata”选项卡可以解决我的问题。减少了查询次数并提高了 Debug模式下的性能，并且 Glimpse 的 HUD 与其 SQL 选项卡之间的查询次数没有差异。