Xamarin Android - 便携式共享库代码运行速度极慢
Xamarin Android - Portable Shared Library Code runs Incredibly Slowly
我正在尝试使用 Xamarin 创建应用程序。我有一个便携式共享库，其中包含一些需要一段时间才能处理的代码。我已经创建了一个使用这个库的控制台应用程序，我也在开发一个 Android 应用程序，它使用与 Xamarin.Android 相同的便携式共享库，但是共享的便携式代码 运行 Android.
上的速度非常慢
编辑：我还尝试将我的代码放在共享项目中，而不是共享库中，以查看它是否可以 运行 以正常速度运行，但没有帮助。
我用秒表计时了一些方法，如下所示：
原创
return p => p.EndsWith(endingString)
带秒表
return (p =>
{
Stopwatch sw = Stopwatch.StartNew();
bool ans = p.EndsWith(endingString);
sw.Stop();
Debug.WriteLine(sw.ElapsedTicks);
return ans;
});
Android 应用程序由于某种原因真的很慢。上面的代码告诉我，只是为了检查一个字符串是否以某些东西结尾，在 Android 上花费了大约 1411 个滴答，而在我的电脑上它只花费了 5 个滴答，这意味着 Android 版本在 [= 上花费了 280 倍以上的滴答47=].
另一种方法在 Android 上花费了 243669 个滴答，在我的计算机上花费了 4561 个滴答，这意味着它花费了 53 倍的滴答。
下面的方法在 Android 上花费了 19847785 次滴答，在我的计算机上花费了 819619 次，慢了 24 倍。我不认为缓慢是由我的代码引起的，但我想提供一些我的代码的示例，以防万一它是由我的代码中的某些东西引起的。
private void InitialiseFrequencyDictionary()
{
if (_frequencyDictionary != null) return;
StreamReader streamReader = EmbeddedResourceGetter.GetFrequencyListStreamReader();
_frequencyDictionary = new Dictionary<string, string>();
string line;
while (!string.IsNullOrEmpty(line = streamReader.ReadLine()))
{
try
{
string[] lineSplit = line.Split(new[] {' '}, 2);
_frequencyDictionary.Add(lineSplit[0], lineSplit[1]);
}
catch { /* ignored */ }
}
}
整个 类 的 public 方法作为一个整体在 Android 上花费了 155524065 个滴答，并花费了 15761 毫秒。它在我的电脑上花费了 2471652 个滴答声和 1152 毫秒，这意味着它在 Android 上比在我的电脑上花费了 63 倍的滴答声和 15 倍的时间。
我知道这些结果并不完全准确，因为我是在不同的设备、不同的 OS 和不同的架构上测试它们，但我不认为这些准确地代表了我和我之间的性能差异电脑和我的 phone 什么的。我的 phone 在 Geekbench 中的单核和多核分数分别为 1219 和 4273，而我的计算机在 Geekbench 中的分数为 3288 和 6978。这意味着我的 phone 最多应该比我的电脑慢 3 倍，而不是 16 倍！
每当此代码在我的 Android 设备上执行时，我都会在 Visual Studio.
的输出部分收到大量来自垃圾收集器（我认为）的消息
01-08 18:48:27.527 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 0.90ms, total 1.08ms, bridge 0.00ms promoted 880K major 880K los 8K
01-08 18:48:30.133 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:30.133 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 0.85ms, total 0.98ms, bridge 0.00ms promoted 880K major 880K los 8K
01-08 18:48:32.760 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:32.760 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 1.81ms, total 2.06ms, bridge 0.00ms promoted 896K major 896K los 8K
01-08 18:48:35.034 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:35.034 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 1.19ms, total 1.37ms, bridge 0.00ms promoted 912K major 912K los 8K
01-08 18:48:37.687 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:37.687 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 0.59ms, total 1.61ms, bridge 0.00ms promoted 912K major 912K los 8K
01-08 18:48:39.298 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.298 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 4.78ms, total 5.13ms, bridge 0.00ms promoted 1248K major 1248K los 296K
01-08 18:48:39.378 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.378 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 7.58ms, total 7.81ms, bridge 0.00ms promoted 2336K major 2336K los 1348K
01-08 18:48:39.459 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.459 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 7.24ms, total 7.46ms, bridge 0.00ms promoted 3488K major 3488K los 2821K
01-08 18:48:39.536 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.536 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 6.13ms, total 6.40ms, bridge 0.00ms promoted 4624K major 4624K los 2821K
01-08 18:48:39.627 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.627 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 8.29ms, total 8.51ms, bridge 0.00ms promoted 5776K major 5776K los 5877K
01-08 18:48:39.705 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.705 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 6.47ms, total 6.68ms, bridge 0.00ms promoted 6832K major 6832K los 5877K
01-08 18:48:39.796 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.796 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 15.16ms, total 16.35ms, bridge 0.00ms promoted 7888K major 7888K los 5877K
01-08 18:48:39.876 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.876 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.47ms, total 5.68ms, bridge 0.00ms promoted 8928K major 8928K los 5877K
01-08 18:48:40.031 I/art ( 9357): Explicit concurrent mark sweep GC freed 6197(237KB) AllocSpace objects, 0(0B) LOS objects, 45% free, 4MB/8MB, paused 1.286ms total 18.093ms
01-08 18:48:40.032 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.06ms sort 0.01ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 7/7/7/1 dfs passes 52/31
01-08 18:48:40.032 D/Mono ( 9357): GC_MAJOR: (Minor allowance) pause 33.66ms, total 36.59ms, bridge 0.00ms major 9968K/0K los 8789K/0K
01-08 18:48:40.110 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.06ms sort 0.01ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.110 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.65ms, total 5.88ms, bridge 0.00ms promoted 11008K major 11008K los 8789K
01-08 18:48:40.190 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.06ms sort 0.01ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.190 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 6.16ms, total 6.37ms, bridge 0.00ms promoted 12032K major 12032K los 8789K
01-08 18:48:40.283 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.06ms sort 0.01ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.283 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 14.61ms, total 17.42ms, bridge 0.00ms promoted 13104K major 13104K los 8789K
01-08 18:48:40.373 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.06ms sort 0.01ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.373 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.86ms, total 6.18ms, bridge 0.00ms promoted 14144K major 14144K los 8789K
01-08 18:48:40.455 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.06ms sort 0.01ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.455 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.82ms, total 6.05ms, bridge 0.00ms promoted 15168K major 15168K los 8789K
01-08 18:48:40.536 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.06ms sort 0.01ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.536 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.51ms, total 5.72ms, bridge 0.00ms promoted 16224K major 16224K los 8789K
01-08 18:48:40.772 I/art ( 9357): Explicit concurrent mark sweep GC freed 338(11KB) AllocSpace objects, 0(0B) LOS objects, 45% free, 4MB/8MB, paused 838us total 17.067ms
01-08 18:48:40.772 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.05ms sort 0.02ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 7/7/7/1 dfs passes 52/31
01-08 18:48:40.773 D/Mono ( 9357): GC_MAJOR: (Minor allowance) pause 74.78ms, total 78.16ms, bridge 0.00ms major 17264K/0K los 18218K/0K
01-08 18:48:40.850 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.05ms sort 0.02ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.850 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.58ms, total 5.81ms, bridge 0.00ms promoted 18304K major 18304K los 18218K
01-08 18:48:40.929 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.05ms sort 0.02ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.929 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.98ms, total 6.53ms, bridge 0.00ms promoted 19344K major 19344K los 18218K
01-08 18:48:41.008 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.05ms sort 0.02ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:41.008 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.53ms, total 5.74ms, bridge 0.00ms promoted 20400K major 20400K los 18218K
01-08 18:48:41.089 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.05ms sort 0.02ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:41.089 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 7.68ms, total 7.74ms, bridge 0.00ms promoted 21440K major 21440K los 18230K
01-08 18:48:41.168 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.05ms sort 0.02ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:41.168 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.56ms, total 5.77ms, bridge 0.00ms promoted 22496K major 22496K los 18230K
01-08 18:48:41.247 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.05ms sort 0.02ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:41.247 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.64ms, total 6.09ms, bridge 0.00ms promoted 23520K major 23520K los 18230K
那么 这种缓慢对于 Xamarin 来说是正常的吗？这是 Xamarin 中的错误，还是我遗漏了什么？这是垃圾收集器造成的吗？
我调查了更多。这个问题不仅在使用 PCL 时存在，而且在 Android 资产中包含单词列表时也存在。
首先我尝试了这样的事情：
public static async Task<Dictionary<string, int>> ReadWordFrequenciesAsync(Stream stream)
{
var freqs = new Dictionary<string, int>();
using (var reader = new StreamReader(stream))
{
string line;
while ((line = await reader.ReadLineAsync().ConfigureAwait(false)) != null)
{
var split = line.Split(' ');
var word = split[0];
var frequency = 0;
if (int.TryParse(split[1], out frequency))
freqs.Add(word, frequency);
line = null;
}
}
return freqs;
}
public static Stream GetWordListFromPcl()
{
var assembly = typeof(WordListReader).GetTypeInfo().Assembly;
return assembly.GetManifestResourceStream("WordList.Content.en.txt");
}
这在我的 PC 上花费了 54 毫秒，在我的 Nexus 5 上花费了大约 8 秒。
修改代码以不将频率解析为 int，如下所示：
public static async Task<Dictionary<string, string>> ReadWordFrequenciesAsync(Stream stream = null)
{
var freqs = new Dictionary<string, string>();
using (var reader = new StreamReader(stream))
{
string line;
while ((line = await reader.ReadLineAsync().ConfigureAwait(false)) != null)
{
var split = line.Split(' ');
var word = split[0];
var frequency = split[1];
freqs.Add(word, frequency);
line = null;
}
}
return freqs;
}
这使得代码在 Nexus 5 上快了 2 秒。
我只是从 Android assets 中尝试了同样的方法，我在其中读取流，例如：
var stream = Assets.Open("en.txt");
这导致读取时间相同。这意味着 PCL 没有错。
我尝试的最后一件事是将整个文件读入内存。像这样：
public static async Task<string> ReadWordFrequenciesStringAsync(Stream stream = null)
{
using (var reader = new StreamReader(stream))
{
return await reader.ReadToEndAsync().ConfigureAwait(false);
}
}
这需要不到一秒钟的时间！
好的，那么结论是什么？我认为 line.Split 方法是错误的！我们可以做什么？
我们可以尝试实现我们自己的拆分器。试过这样的事情：
public static class StringExtensions
{
public static Tuple<string, string> MySplit(this string s, char c)
{
var l = s.Length;
for (var i = 0; i < l; i++)
{
if (s[i] == c)
{
return new Tuple<string, string>(s.Substring(0, i), s.Substring(i + 1));
}
}
return null;
}
}
这节省了整整一秒，同时仍将频率值解析为 int。如果我们使用 string[] 作为 return 值，MySplit 的性能是相同的，所以在那里没有太多收获。
使用不安全代码可能有助于提高此处的性能。但是时间其实不是读取文件，而是解析文件。
我正在尝试使用 Xamarin 创建应用程序。我有一个便携式共享库，其中包含一些需要一段时间才能处理的代码。我已经创建了一个使用这个库的控制台应用程序，我也在开发一个 Android 应用程序，它使用与 Xamarin.Android 相同的便携式共享库，但是共享的便携式代码 运行 Android.
上的速度非常慢编辑：我还尝试将我的代码放在共享项目中，而不是共享库中，以查看它是否可以 运行 以正常速度运行，但没有帮助。
我用秒表计时了一些方法，如下所示：
原创
return p => p.EndsWith(endingString)
带秒表
return (p =>
{
Stopwatch sw = Stopwatch.StartNew();
bool ans = p.EndsWith(endingString);
sw.Stop();
Debug.WriteLine(sw.ElapsedTicks);
return ans;
});
Android 应用程序由于某种原因真的很慢。上面的代码告诉我，只是为了检查一个字符串是否以某些东西结尾，在 Android 上花费了大约 1411 个滴答，而在我的电脑上它只花费了 5 个滴答，这意味着 Android 版本在 [= 上花费了 280 倍以上的滴答47=].
另一种方法在 Android 上花费了 243669 个滴答，在我的计算机上花费了 4561 个滴答，这意味着它花费了 53 倍的滴答。
下面的方法在 Android 上花费了 19847785 次滴答，在我的计算机上花费了 819619 次，慢了 24 倍。我不认为缓慢是由我的代码引起的，但我想提供一些我的代码的示例，以防万一它是由我的代码中的某些东西引起的。
private void InitialiseFrequencyDictionary()
{
if (_frequencyDictionary != null) return;
StreamReader streamReader = EmbeddedResourceGetter.GetFrequencyListStreamReader();
_frequencyDictionary = new Dictionary<string, string>();
string line;
while (!string.IsNullOrEmpty(line = streamReader.ReadLine()))
{
try
{
string[] lineSplit = line.Split(new[] {' '}, 2);
_frequencyDictionary.Add(lineSplit[0], lineSplit[1]);
}
catch { /* ignored */ }
}
}
整个 类 的 public 方法作为一个整体在 Android 上花费了 155524065 个滴答，并花费了 15761 毫秒。它在我的电脑上花费了 2471652 个滴答声和 1152 毫秒，这意味着它在 Android 上比在我的电脑上花费了 63 倍的滴答声和 15 倍的时间。
我知道这些结果并不完全准确，因为我是在不同的设备、不同的 OS 和不同的架构上测试它们，但我不认为这些准确地代表了我和我之间的性能差异电脑和我的 phone 什么的。我的 phone 在 Geekbench 中的单核和多核分数分别为 1219 和 4273，而我的计算机在 Geekbench 中的分数为 3288 和 6978。这意味着我的 phone 最多应该比我的电脑慢 3 倍，而不是 16 倍！
每当此代码在我的 Android 设备上执行时，我都会在 Visual Studio.
的输出部分收到大量来自垃圾收集器（我认为）的消息01-08 18:48:27.527 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 0.90ms, total 1.08ms, bridge 0.00ms promoted 880K major 880K los 8K
01-08 18:48:30.133 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:30.133 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 0.85ms, total 0.98ms, bridge 0.00ms promoted 880K major 880K los 8K
01-08 18:48:32.760 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:32.760 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 1.81ms, total 2.06ms, bridge 0.00ms promoted 896K major 896K los 8K
01-08 18:48:35.034 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:35.034 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 1.19ms, total 1.37ms, bridge 0.00ms promoted 912K major 912K los 8K
01-08 18:48:37.687 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:37.687 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 0.59ms, total 1.61ms, bridge 0.00ms promoted 912K major 912K los 8K
01-08 18:48:39.298 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.298 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 4.78ms, total 5.13ms, bridge 0.00ms promoted 1248K major 1248K los 296K
01-08 18:48:39.378 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.378 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 7.58ms, total 7.81ms, bridge 0.00ms promoted 2336K major 2336K los 1348K
01-08 18:48:39.459 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.459 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 7.24ms, total 7.46ms, bridge 0.00ms promoted 3488K major 3488K los 2821K
01-08 18:48:39.536 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.536 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 6.13ms, total 6.40ms, bridge 0.00ms promoted 4624K major 4624K los 2821K
01-08 18:48:39.627 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.627 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 8.29ms, total 8.51ms, bridge 0.00ms promoted 5776K major 5776K los 5877K
01-08 18:48:39.705 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.705 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 6.47ms, total 6.68ms, bridge 0.00ms promoted 6832K major 6832K los 5877K
01-08 18:48:39.796 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.796 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 15.16ms, total 16.35ms, bridge 0.00ms promoted 7888K major 7888K los 5877K
01-08 18:48:39.876 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 23 num_hash_entries 29 sccs size 29 init 0.00ms df1 0.05ms sort 0.00ms dfs2 0.09ms setup-cb 0.01ms free-data 0.03ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:39.876 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.47ms, total 5.68ms, bridge 0.00ms promoted 8928K major 8928K los 5877K
01-08 18:48:40.031 I/art ( 9357): Explicit concurrent mark sweep GC freed 6197(237KB) AllocSpace objects, 0(0B) LOS objects, 45% free, 4MB/8MB, paused 1.286ms total 18.093ms
01-08 18:48:40.032 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.06ms sort 0.01ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 7/7/7/1 dfs passes 52/31
01-08 18:48:40.032 D/Mono ( 9357): GC_MAJOR: (Minor allowance) pause 33.66ms, total 36.59ms, bridge 0.00ms major 9968K/0K los 8789K/0K
01-08 18:48:40.110 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.06ms sort 0.01ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.110 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.65ms, total 5.88ms, bridge 0.00ms promoted 11008K major 11008K los 8789K
01-08 18:48:40.190 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.06ms sort 0.01ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.190 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 6.16ms, total 6.37ms, bridge 0.00ms promoted 12032K major 12032K los 8789K
01-08 18:48:40.283 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.06ms sort 0.01ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.283 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 14.61ms, total 17.42ms, bridge 0.00ms promoted 13104K major 13104K los 8789K
01-08 18:48:40.373 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.06ms sort 0.01ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.373 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.86ms, total 6.18ms, bridge 0.00ms promoted 14144K major 14144K los 8789K
01-08 18:48:40.455 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.06ms sort 0.01ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.455 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.82ms, total 6.05ms, bridge 0.00ms promoted 15168K major 15168K los 8789K
01-08 18:48:40.536 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.06ms sort 0.01ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.536 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.51ms, total 5.72ms, bridge 0.00ms promoted 16224K major 16224K los 8789K
01-08 18:48:40.772 I/art ( 9357): Explicit concurrent mark sweep GC freed 338(11KB) AllocSpace objects, 0(0B) LOS objects, 45% free, 4MB/8MB, paused 838us total 17.067ms
01-08 18:48:40.772 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.05ms sort 0.02ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 7/7/7/1 dfs passes 52/31
01-08 18:48:40.773 D/Mono ( 9357): GC_MAJOR: (Minor allowance) pause 74.78ms, total 78.16ms, bridge 0.00ms major 17264K/0K los 18218K/0K
01-08 18:48:40.850 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.05ms sort 0.02ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.850 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.58ms, total 5.81ms, bridge 0.00ms promoted 18304K major 18304K los 18218K
01-08 18:48:40.929 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.05ms sort 0.02ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:40.929 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.98ms, total 6.53ms, bridge 0.00ms promoted 19344K major 19344K los 18218K
01-08 18:48:41.008 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.05ms sort 0.02ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:41.008 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.53ms, total 5.74ms, bridge 0.00ms promoted 20400K major 20400K los 18218K
01-08 18:48:41.089 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.05ms sort 0.02ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:41.089 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 7.68ms, total 7.74ms, bridge 0.00ms promoted 21440K major 21440K los 18230K
01-08 18:48:41.168 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.05ms sort 0.02ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:41.168 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.56ms, total 5.77ms, bridge 0.00ms promoted 22496K major 22496K los 18230K
01-08 18:48:41.247 D/Mono ( 9357): GC_OLD_BRIDGE num-objects 21 num_hash_entries 24 sccs size 24 init 0.00ms df1 0.05ms sort 0.02ms dfs2 0.06ms setup-cb 0.01ms free-data 0.02ms links 0/0/0/0 dfs passes 0/0
01-08 18:48:41.247 D/Mono ( 9357): GC_MINOR: (Nursery full) pause 5.64ms, total 6.09ms, bridge 0.00ms promoted 23520K major 23520K los 18230K
那么 这种缓慢对于 Xamarin 来说是正常的吗？这是 Xamarin 中的错误，还是我遗漏了什么？这是垃圾收集器造成的吗？
我调查了更多。这个问题不仅在使用 PCL 时存在，而且在 Android 资产中包含单词列表时也存在。
首先我尝试了这样的事情：
public static async Task<Dictionary<string, int>> ReadWordFrequenciesAsync(Stream stream)
{
var freqs = new Dictionary<string, int>();
using (var reader = new StreamReader(stream))
{
string line;
while ((line = await reader.ReadLineAsync().ConfigureAwait(false)) != null)
{
var split = line.Split(' ');
var word = split[0];
var frequency = 0;
if (int.TryParse(split[1], out frequency))
freqs.Add(word, frequency);
line = null;
}
}
return freqs;
}
public static Stream GetWordListFromPcl()
{
var assembly = typeof(WordListReader).GetTypeInfo().Assembly;
return assembly.GetManifestResourceStream("WordList.Content.en.txt");
}
这在我的 PC 上花费了 54 毫秒，在我的 Nexus 5 上花费了大约 8 秒。
修改代码以不将频率解析为 int，如下所示：
public static async Task<Dictionary<string, string>> ReadWordFrequenciesAsync(Stream stream = null)
{
var freqs = new Dictionary<string, string>();
using (var reader = new StreamReader(stream))
{
string line;
while ((line = await reader.ReadLineAsync().ConfigureAwait(false)) != null)
{
var split = line.Split(' ');
var word = split[0];
var frequency = split[1];
freqs.Add(word, frequency);
line = null;
}
}
return freqs;
}
这使得代码在 Nexus 5 上快了 2 秒。
我只是从 Android assets 中尝试了同样的方法，我在其中读取流，例如：
var stream = Assets.Open("en.txt");
这导致读取时间相同。这意味着 PCL 没有错。
我尝试的最后一件事是将整个文件读入内存。像这样：
public static async Task<string> ReadWordFrequenciesStringAsync(Stream stream = null)
{
using (var reader = new StreamReader(stream))
{
return await reader.ReadToEndAsync().ConfigureAwait(false);
}
}
这需要不到一秒钟的时间！
好的，那么结论是什么？我认为 line.Split 方法是错误的！我们可以做什么？
我们可以尝试实现我们自己的拆分器。试过这样的事情：
public static class StringExtensions
{
public static Tuple<string, string> MySplit(this string s, char c)
{
var l = s.Length;
for (var i = 0; i < l; i++)
{
if (s[i] == c)
{
return new Tuple<string, string>(s.Substring(0, i), s.Substring(i + 1));
}
}
return null;
}
}
这节省了整整一秒，同时仍将频率值解析为 int。如果我们使用 string[] 作为 return 值，MySplit 的性能是相同的，所以在那里没有太多收获。
使用不安全代码可能有助于提高此处的性能。但是时间其实不是读取文件，而是解析文件。