调试慢ContentResolver的查询，调用及QUOT花费大量的时间;上下文切换＆QUOT; [英] Debugging slow ContentResolver query calls spending lots of time in "context switch"

问题描述

偶尔Android系统调用，如<一个href=\"http://developer.android.com/reference/android/content/ContentResolver.html#query(android.net.Uri%2C%20java.lang.String%5B%5D%2C%20java.lang.String%2C%20java.lang.String%5B%5D%2C%20java.lang.String)\"相对=nofollow> ContentResolver.query（...），可以比平时长1000倍倍，例如〜10秒一个电话，可能正常完成〜10毫秒。我的问题是如何识别这样的情况下，明白为什么它的发生和解决问题。

下面的例子是一个检索Android系统的用户配置文件。在我的Nexus 6一般需要约10毫秒做到这一点。旧设备数量也同样快。偶尔尽管它可以20+秒。使用traceview，它表明，几乎所有的时间都花在上下文切换：

我的设备有异常〜7000联系人。对于用户配置那我请求，结果是只有一行。它的使用要求 Uri.withAppendedPath（Profile.CONTENT_URI，Data.CONTENT_DIRECTORY） - 我presume将是一个共同的，优化的案例。目前，该查询主线程，这可能是复杂的东西上完成......在Android文档提到，你应该在一个单独的线程做异步查询。我会迁移到，在未来，但我怀疑，是事业的，因为它是pviously工作的罚款$ P $。

另一个令人惊奇的因素是奇怪的一致性。我在应用多个查询。对于运行的序列中，用户配置文件将始终如一地慢然后开始再次快速是，我不能重现该问题。同样，其他联系查询不属于用户配置文件，将快速，然后变得缓慢。在过去的六个月中，所有查询都很快通过Nexus 5和Nexus 6的设备 - 这只是出现在最后一周

。

查询：

 开放的URI = Uri.withAppendedPath（Profile.CONTENT_URI，Data.CONTENT_DIRECTORY）
Log.d（TAGgetOwner：+ uri.toString（））;
光标CUR = mResolver.query（
    URI，
    投影，// 6列
    空值，
    空值，
    Data.IS_PRIMARY +DESC）;
Log.d（TAG，getOwner：查询计数 - + cur.getCount（））;
 

日志输出：

  //注意18的日志条目之间秒的差距
19：20：33.134 D / ConnectActivity：getOwner：URI：内容：//com.android.contacts/profile/data
19：20：51.779 D / ConnectActivity：getOwner：查询计数 -  1
 

我仍然觉得这种行为令人吃惊，不明白为什么它会发生。

解决方案

调试和改进（最后两个是专门为慢上下文切换）的水平：

1. 查询改进：查询URI，投影尺寸和列索引缓存<一个href=\"http://stackoverflow.com/questions/12109391/getting-name-and-email-from-contact-list-is-very-slow\">more详细信息


2. 查询过滤：通过更好的滤波降低了查询结果的大小


3. 异步：查询速度慢不应该阻塞UI线程，使用


4. 观察日志：各地放缓看它是否有任何线索的原木的更多详细信息


5. Traceview ：以标识呼叫花费时间


6. 上下文切换：解释

查询改进和过滤

在mosts情况下，查询权乌里，降低了投影和缓存列索引的列数是主要的改进：<一href=\"http://stackoverflow.com/questions/12109391/getting-name-and-email-from-contact-list-is-very-slow\">Getting名称和联系人列表的电子邮件是非常缓慢的

这例子是从用户配置文件获取的名称：

 光标CUR = mResolver.query（
    //乌里只会返回用户配置文件，而不是一切接触
    Uri.withAppendedPath（Profile.CONTENT_URI，Data.CONTENT_DIRECTORY）
    //投影只有2列，以减少返回的数据
    新的String [] {
            Data.MIMETYPE，
            ContactsContract.Data.DISPLAY_NAME};
    //筛选特定的MIME类型相匹配，以减少结果的大小
    Data.MIMETYPE +=？，
    //筛选特定的MIME类型相匹配，以减少结果的大小
    新的String [] {} StructuredName.CONTENT_ITEM_TYPE，
    //没有排序可以提高性能
    空值）;
 

异步

建议使用的 Android文档 CursorLoader ：

的为了清楚起见，在本节调用ContentResolver.query（以下简称UI线程。在实际code在code段），但是，你应该做的查询上异步。一个单独的线程来做到这一点的方法之一是使用CursorLoader类，它进行更详细的装载机指南中描述另外，code的线仅是片段;他们不显示完整的应用程序<。 / EM>

观察日志

您应该看看周围很多放缓到两个量化它，看它是否有唯一线索的原因。 ContentResolver.query（...）调用往往需要10-100毫秒，该范围内的任何地方都可能如上述，但相当预期得到改善。在范围1-10秒，这可以通过一个上下文切换到其它进程造成的。当发生上下文切换，ART（在是Android 5.0默认运行时），将输出指示采取它的上下文切换和时间日志行：

Traceview

Android的 traceview 的可用于识别时间被消耗。基本用法是包你想分析的方法如下：

  Debug.startMethodTracing（跟踪名称）;
// code个人资料
Debug.stopMethodTracing（）;
 

接下来从设备（我相信这是默认的路径）拉日志

  ADB拉/storage/emulated/legacy/dmtrace.trace
 

Android设备监控可以用来打开文件和查看。从Android的Studio中，选择工具 - > Android的 - > Android设备监控，然后打开该文件。通常是有帮助的重新排列的已包含实时和已包含CPU时间列到最左边。这表明通过一种方法所花费的时间（和它的孩子们的方法）两种CPU时间和实时（其中还包括阻止未与应用程序的CPU时间来衡量IO电话 - 的more详细信息）。最可疑的条目，其中已包含实时大大超过在已包含CPU时间即可。这意味着，意味着该方法花了很长时间，但在你的code没有做太多，所以它必须被封锁的应用程序之外的东西。

您可以看到一个列表的方法和每个时间。在0（顶层）启动单击三角形看到孩子并打开。每个孩子都会列出，你可以在traceview用找对方法和其他地方看着自己的孩子，通过层次递减的方法数。寻找情况下的已包含实时 >> 已包含CPU时间后，你会经常发现其结尾（上下文切换）。这是长阻塞事件的放慢您的进程。

上下文切换

描述：

在计算，上下文切换是存储和恢复的过程或线程的状态（上下文）以使执行可以从同一点在以后的时间重新开始的过程。这使得多个进程共享一个CPU和是一个多任务操作系统的一个基本特征。什么构成的上下文是由处理器和操作系统来确定。的

在Android的情况下，这表明操作系统已经选择了preserve您的应用程序的状态，从CPU中取出，以便它可以执行其他程序。当上下文切换结束后，该过程可以在CPU和恢复执行被恢复

Occasionally Android system calls, such as ContentResolver.query(...), can take 1000x times longer than normal, for example ~10 seconds for a single call that might normally complete in ~10 milliseconds. My question is how to identify cases like this, understand why it's happening and resolve the problem.

The example below is retrieving the "user profile" on an Android system. On my Nexus 6 it normally takes ~10 milliseconds to do this. Older devices were similarly quick. Occasionally though it can 20+ seconds. Using traceview, it shows that virtually all the time is spent in "context switch":

My device unusually has ~7,000 contacts. For the "user profile" that I'm requesting, the result is only a single row. It's requested using Uri.withAppendedPath(Profile.CONTENT_URI, Data.CONTENT_DIRECTORY) - which I presume would be a common, optimized case. At the moment, the queries are done on the main thread, which may be complicating things... the Android documentation mentions that "you should do queries asynchronously on a separate thread". I will migrate to that in the future but I'm skeptical of that being the cause as it was working fine previously.

Another surprising factor is the strange consistency. I have multiple queries in the app. For a sequence of runs, the "user profile" will be consistently slow then start being fast again and I can't reproduce the issue. Likewise other contact queries that aren't the user profile, will be fast and then become slow. For the past six months, all the queries have been fast through the Nexus 5 and Nexus 6 devices - this only appeared in the last week.

The query:

Uri uri = Uri.withAppendedPath(Profile.CONTENT_URI, Data.CONTENT_DIRECTORY),
Log.d(TAG, "getOwner: " + uri.toString());
Cursor cur = mResolver.query(
    uri,
    PROJECTION,  // 6 columns
    null,
    null,
    Data.IS_PRIMARY + " DESC");
Log.d(TAG, "getOwner: query count -  " + cur.getCount());

Log Output:

// NOTE 18 second gap between log entries
19:20:33.134 D/ConnectActivity﹕ getOwner: URI: content://com.android.contacts/profile/data
19:20:51.779 D/ConnectActivity﹕ getOwner: query count -  1

I still find this behaviour surprising and don't understand why it occurs.

解决方案

Levels of debugging and improvements (the last two are specifically for slow "context switch"):

1. Query Improvements: query Uri, Projection size and column indices caching more details
2. Query Filtering: reduce size of the query result through better filtering
3. Asynchronous: slow queries shouldn't block the UI thread, use
4. Observe Logs: around the slowdown to see if it has any clues more details on logs
5. Traceview: to identify where the call is spending time
6. Context Switch: explanation

Query Improvements & Filtering

In mosts cases, querying the right Uri, reducing the number of columns in the projection and caching column indices are the primary improvements: Getting name and email from contact list is very slow

This example is for obtaining the name from the user profile:

Cursor cur = mResolver.query(
    // Uri will only return user profile rather than everything in contacts
    Uri.withAppendedPath(Profile.CONTENT_URI, Data.CONTENT_DIRECTORY),
    // Projection only has 2 columns to reduce the data returned
    new String[] {
            Data.MIMETYPE,
            ContactsContract.Data.DISPLAY_NAME};
    // Filter matches on specific mimetype to reduce result size
    Data.MIMETYPE + "=?",
    // Filter matches on specific mimetype to reduce result size
    new String[]{StructuredName.CONTENT_ITEM_TYPE},
    // No sorting may improve performance
    null);

Asynchronous

The Android Documentation suggests using a CursorLoader:

For the sake of clarity, the code snippets in this section call ContentResolver.query() on the "UI thread"". In actual code, however, you should do queries asynchronously on a separate thread. One way to do this is to use the CursorLoader class, which is described in more detail in the Loaders guide. Also, the lines of code are snippets only; they don't show a complete application.

Observe Logs

You should look at lot around the slowdown to both quantify it and see if it has only clues to the cause. ContentResolver.query(...) calls often take 10-100 milliseconds and anything within that range may be improved as above but is fairly expected. In the range 1-10 seconds, this may be caused by a context switch to other processes. When the context switch occurs, ART (default Runtime in Android 5.0), will output a log line indicating the context switch and the time taken for it:

Traceview

Android's traceview can be used to identify where time is being spent. The basic usage is to wrap the method you wish to profile as follows:

Debug.startMethodTracing("trace-name");
// Code to profile
Debug.stopMethodTracing();

Next pull the logs from the device (I believe this is the default path):

adb pull /storage/emulated/legacy/dmtrace.trace

Android Device Monitor can be used to open the file and view. From Android Studio, select Tools -> Android -> Android Device Monitor, then open the file. Often it is helpful to rearrange the Incl Real Time and Incl Cpu Time columns to the far left. These show the time taken by a method (and it's children methods) both as cpu time and real time (which also including blocking IO calls that aren't measured with cpu time in the app process - more details). The most suspicious entries are where Incl Real Time vastly exceeds the Incl Cpu Time. That means that means the method took a long time but didn't do much in your code, so it must have been blocked by something outside of the app process.

You can see that a list methods and the time for each. Starting at "0 (top level)" click the triangle to see the "children" and open that. Each child will list a method number that you can use to find the method elsewhere in traceview and looks at their children, descending through the hierarchy. Looking for cases where Incl Real Time >> Incl Cpu Time, you will often find it ends with "(context switch)". This is the long blocking event that's slowing down your process.

Context Switch

Wikipedia description:

In computing, a context switch is the process of storing and restoring the state (context) of a process or thread so that execution can be resumed from the same point at a later time. This enables multiple processes to share a single CPU and is an essential feature of a multitasking operating system. What constitutes the context is determined by the processor and the operating system.

In the case of Android, this indicates the OS has chosen to preserve the state of your app, remove it from the CPU so that it can execute another process. When the context switch is over, the process may be reinstated on the CPU and resume execution.

这篇关于调试慢ContentResolver的查询，调用及QUOT花费大量的时间;上下文切换＆QUOT;的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！