【发布时间】:2017-09-17 07:33:35
【问题描述】:
我们注意到一些非常小的 Web 服务调用花费的时间比我们预期的要长得多。我们进行了一些调查并设置了一些计时器,然后我们将其范围缩小到创建 Entity Framework 6 DbContext 的实例。不是查询本身,只是上下文的创建。从那以后,我进行了一些日志记录,以查看创建 DbContext 实例实际需要多长时间,看起来大约是 50 毫秒。
应用程序预热后上下文创建并不慢。应用程序回收后,它会在 2-4ms 开始(这是我们在开发环境中看到的)。上下文创建似乎随着时间的推移而减慢。在接下来的几个小时内,它将爬升到 50-80 毫秒范围并趋于平稳。
我们的上下文是一个相当大的代码优先上下文,包含大约 300 个实体 - 包括一些实体之间的一些非常复杂的关系。我们正在运行 EF 6.1.3。我们正在执行“每个请求一个上下文”,但是对于我们的大多数 Web API 调用,它只执行一两个查询。创建一个耗时 60+ms 的上下文,然后执行一个 1ms 的查询有点令人不满意。我们每分钟大约有 10k 个请求,所以我们不是一个使用率很低的网站。
这是我们所看到的快照。时代在 MS,大跌是一个回收应用程序域的部署。每行是 4 个不同的 Web 服务器之一。请注意,它也不总是同一台服务器。
我确实进行了内存转储以尝试充实正在发生的事情,这是堆统计信息:
00007ffadddd1d60 70821 2266272 System.Reflection.Emit.GenericFieldInfo
00007ffae02e88a8 29885 2390800 System.Linq.Enumerable+WhereSelectListIterator`2[[NewRelic.Agent.Core.WireModels.MetricDataWireModel, NewRelic.Agent.Core],[System.Single, mscorlib]]
00007ffadda7c1a0 1462 2654992 System.Collections.Concurrent.ConcurrentDictionary`2+Node[[System.Object, mscorlib],[System.Object, mscorlib]][]
00007ffadd4eccf8 83298 2715168 System.RuntimeType[]
00007ffadd4e37c8 24667 2762704 System.Reflection.Emit.DynamicMethod
00007ffadd573180 30013 3121352 System.Web.Caching.CacheEntry
00007ffadd2dc5b8 35089 3348512 System.String[]
00007ffadd6734b8 35233 3382368 System.RuntimeMethodInfoStub
00007ffadddbf0a0 24667 3749384 System.Reflection.Emit.DynamicILGenerator
00007ffae04491d8 67611 4327104 System.Data.Entity.Core.Metadata.Edm.MetadataProperty
00007ffadd4edaf0 57264 4581120 System.Signature
00007ffadd4dfa18 204161 4899864 System.RuntimeMethodHandle
00007ffadd4ee2c0 41900 5028000 System.Reflection.RuntimeParameterInfo
00007ffae0c9e990 21560 5346880 System.Data.SqlClient._SqlMetaData
00007ffae0442398 79504 5724288 System.Data.Entity.Core.Metadata.Edm.TypeUsage
00007ffadd432898 88807 8685476 System.Int32[]
00007ffadd433868 9985 9560880 System.Collections.Hashtable+bucket[]
00007ffadd4e3160 92105 10315760 System.Reflection.RuntimeMethodInfo
00007ffadd266668 493622 11846928 System.Object
00007ffadd2dc770 33965 16336068 System.Char[]
00007ffadd26bff8 121618 17335832 System.Object[]
00007ffadd2df8c0 168529 68677312 System.Byte[]
00007ffadd2d4d08 581057 127721734 System.String
0000019cf59e37d0 166894 143731666 Free
Total 5529765 objects
Fragmented blocks larger than 0.5 MB:
Addr Size Followed by
0000019ef63f2140 2.9MB 0000019ef66cfb40 Free
0000019f36614dc8 2.8MB 0000019f368d6670 System.Data.Entity.Core.Query.InternalTrees.SimpleColumnMap[]
0000019f764817f8 0.8MB 0000019f76550768 Free
0000019fb63a9ca8 0.6MB 0000019fb644eb38 System.Data.Entity.Core.Common.Utils.Set`1[[System.Data.Entity.Core.Metadata.Edm.EntitySet, EntityFramework]]
000001a0f6449328 0.7MB 000001a0f64f9b48 System.String
000001a0f65e35e8 0.5MB 000001a0f666e2a0 System.Collections.Hashtable+bucket[]
000001a1764e8ae0 0.7MB 000001a17659d050 System.RuntimeMethodHandle
000001a3b6430fd8 0.8MB 000001a3b6501aa0 Free
000001a4f62c05c8 0.7MB 000001a4f636e8a8 Free
000001a6762e2300 0.6MB 000001a676372c38 System.String
000001a7761b5650 0.6MB 000001a776259598 System.String
000001a8763c4bc0 2.3MB 000001a8766083a8 System.String
000001a876686f48 1.4MB 000001a8767f9178 System.String
000001a9f62adc90 0.7MB 000001a9f63653c0 System.String
000001aa362b8220 0.6MB 000001aa36358798 Free
这似乎是相当多的元数据和类型使用。
我们尝试过的事情:
- 创建一个简单的测试工具来复制。它失败了,我猜是因为我们没有改变流量,或者改变运行的查询类型。只是加载上下文并一遍又一遍地执行几个查询并不会导致时间增加。
- 我们显着减少了上下文,原来是 500 个实体,现在是 300 个。在速度上没有影响。我的猜测是因为我们根本没有使用这 200 个实体。
- (编辑)我们使用 SimpleInjector 来创建我们的“每个请求的上下文”。为了验证它不是 SimpleInjector,我通过 new'in 启动了 Context 的一个实例。同样缓慢的创建时间。
- (编辑)我们有 EF。没有产生任何影响。
我们可以进一步调查什么?我知道 EF 使用的缓存可以用来加快速度。缓存中的内容越多,是否会减慢上下文创建速度?有没有办法准确地查看缓存中的内容以充实其中的任何奇怪的东西?有谁知道我们可以做些什么来加速上下文创建?
更新 - 2017 年 5 月 30 日
我采用了 EF6 源代码并编译了我们自己的版本以坚持一些时间安排。我们运营着一个非常受欢迎的网站,因此收集大量的时间信息很棘手,我没有达到我想要的程度,但基本上我们发现所有的减速都来自this method
public void ForceOSpaceLoadingForKnownEntityTypes()
{
if (!_oSpaceLoadingForced)
{
// Attempting to get o-space data for types that are not mapped is expensive so
// only try to do it once.
_oSpaceLoadingForced = true;
Initialize();
foreach (var set in _genericSets.Values.Union(_nonGenericSets.Values))
{
set.InternalSet.TryInitialize();
}
}
}
foreach 的每次迭代都会命中我们上下文中由 DBSet 定义的每个实体。每次迭代都相对较短,只有 0.1-.3 毫秒,但是当您添加 254 个实体时,我们将其加起来。我们还没有弄清楚为什么它一开始很快就变慢了。
【问题讨论】:
-
DbContext实例创建是您唯一的减慢速度? -
您是否正确处理了上下文?例如使用块?
-
@Alex:Web 应用程序中的每个会话一个上下文?听起来像是一场灾难的邀请。
-
我之前在上一家公司遇到过这种情况。所有操作都是通过带有 odbc 连接的存储过程完成的。我们将 90% 的代码迁移到使用 EF,并且我们在首次启动时看到了相当大的减速。我们对所有事情都有一个背景,这就是我们问题的根源。我们开始将上下文分解为逻辑部分(完成后每个上下文的表不超过 10 个,大多数有 2 或 3 个)。当我们完成时,我们已经解决了问题。
-
我一直在等待更多更新,因为我自己也遇到了同样的事情。分析重负载下的应用程序表示大部分时间(在此方法下)都花在了 Assembly.GetCallingAssembly、ReaderWriterLockSlim.TryEnterReadLock 等。看起来那里有一些浪费的缓存机会,因为一旦编译程序集,类型就不会改变,但我没有通过整个 EF 源代码来完全理解发生了什么,所以我知道什么。 ..
标签: c# asp.net performance entity-framework entity-framework-6