我正在寻找最快的方法来弹出大量数据。我遇到了一个非常奇怪的效果:将循环变量从unsigned更改为uint64_t,使我的电脑性能下降了50%。
基准
#include <iostream>
#include <chrono>
#include <x86intrin.h>
int main(int argc, char* argv[]) {
using namespace std;
if (argc != 2) {
cerr << "usage: array_size in MB" << endl;
return -1;
}
uint64_t size = atol(argv[1])<<20;
uint64_t* buffer = new uint64_t[size/8];
char* charbuffer = reinterpret_cast<char*>(buffer);
for (unsigned i=0; i<size; ++i)
charbuffer[i] = rand()%256;
uint64_t count,duration;
chrono::time_point<chrono::system_clock> startP,endP;
{
startP = chrono::system_clock::now();
count = 0;
for( unsigned k = 0; k < 10000; k++){
// Tight unrolled loop with unsigned
for (unsigned i=0; i<size/8; i+=4) {
count += _mm_popcnt_u64(buffer[i]);
count += _mm_popcnt_u64(buffer[i+1]);
count += _mm_popcnt_u64(buffer[i+2]);
count += _mm_popcnt_u64(buffer[i+3]);
}
}
endP = chrono::system_clock::now();
duration = chrono::duration_cast<std::chrono::nanoseconds>(endP-startP).count();
cout << "unsigned\t" << count << '\t' << (duration/1.0E9) << " sec \t"
<< (10000.0*size)/(duration) << " GB/s" << endl;
}
{
startP = chrono::system_clock::now();
count=0;
for( unsigned k = 0; k < 10000; k++){
// Tight unrolled loop with uint64_t
for (uint64_t i=0;i<size/8;i+=4) {
count += _mm_popcnt_u64(buffer[i]);
count += _mm_popcnt_u64(buffer[i+1]);
count += _mm_popcnt_u64(buffer[i+2]);
count += _mm_popcnt_u64(buffer[i+3]);
}
}
endP = chrono::system_clock::now();
duration = chrono::duration_cast<std::chrono::nanoseconds>(endP-startP).count();
cout << "uint64_t\t" << count << '\t' << (duration/1.0E9) << " sec \t"
<< (10000.0*size)/(duration) << " GB/s" << endl;
}
free(charbuffer);
}
如您所见,我们创建了一个随机数据缓冲区,大小为x兆字节,其中x是从命令行读取的。然后,我们遍历缓冲区,并使用x86 popcount内在的展开版本来执行popcount。为了得到更精确的结果,我们做了10000次popcount。我们为教皇计时。在大写情况下,内部循环变量是无符号的,在小写情况下,内循环变量是uint64_t。我认为这应该没有什么区别,但事实恰恰相反。
(绝对疯狂的)结果
我这样编译它(g++版本:Ubuntu 4.8.2-19ubuntu1):
g++ -O3 -march=native -std=c++11 test.cpp -o test
以下是我的Haswell Core i7-4770K CPU在3.50 GHz下运行测试1(因此1 MB随机数据)的结果:
无符号41959360000 0.401554秒26.113 GB/suint64_t 41959360000 0.759822秒13.8003 GB/s
如您所见,uint64_t版本的吞吐量仅为未签名版本的一半!问题似乎是生成了不同的程序集,但为什么?首先,我想到了一个编译器错误,所以我尝试了clang++(Ubuntu clang版本3.4-1ubuntu3):
clang++ -O3 -march=native -std=c++11 teest.cpp -o test
结果:测试1
无符号41959360000 0.398293秒26.3267 GB/suint64_t 41959360000 0.680954秒15.3986 GB/s
所以,这几乎是相同的结果,仍然很奇怪。但现在它变得超级奇怪。我将从输入读取的缓冲区大小替换为常量1,因此我更改:
uint64_t size = atol(argv[1]) << 20;
to
uint64_t size = 1 << 20;
因此,编译器现在知道编译时的缓冲区大小。也许它可以添加一些优化!以下是g++的数字:
无符号41959360000 0.509156秒20.5944 GB/suint64_t 41959360000 0.508673秒20.6139 GB/s
现在,两个版本的速度都一样快。然而,未签名的变得更慢了!它从26 GB/s下降到20 GB/s,因此用常量值替换非常量会导致非优化。说真的,我不知道这里发生了什么!但现在,要用新版本发出叮当声:
无符号41959360000 0.677009秒15.4884 GB/suint64_t 41959360000 0.676909秒15.4906 GB/s
等等,什么?现在,两个版本都降到了15GB/s的速度。因此,用常量值替换非常量甚至会导致Clang在这两种情况下的代码变慢!
我请一位拥有Ivy Bridge CPU的同事来编译我的基准测试。他得到了类似的结果,所以似乎不是哈斯韦尔。因为两个编译器在这里产生了奇怪的结果,所以它似乎也不是编译器错误。我们这里没有AMD CPU,所以我们只能使用Intel进行测试。
请再疯狂一点!
以第一个示例(带有atol(argv[1])的示例)为例,在变量之前放置一个静态变量,即:
static uint64_t size=atol(argv[1])<<20;
以下是我在g++中的结果:
无符号41959360000 0.396728秒26.4306 GB/suint64_t 41959360000 0.509484秒20.5811 GB/s
是的,又是另一种选择。我们仍然拥有u32的快速26GB/s,但我们设法获得了u64,至少从13GB/s到20GB/s版本!在我同事的电脑上,u64版本比u32版本更快,取得了最快的成绩。遗憾的是,这只适用于g++,clang++似乎不关心静态。
我的问题
你能解释一下这些结果吗?特别是:
u32和u64之间怎么会有这样的区别?用恒定缓冲区大小替换非常量如何触发更少的优化代码?静态关键字的插入如何使u64循环更快?甚至比我同事电脑上的原始代码还要快!
我知道优化是一个棘手的领域,然而,我从来没有想过这样的小变化会导致执行时间的100%差异,并且像恒定缓冲区大小这样的小因素会再次完全混合结果。当然,我总是希望有一个能够弹出26GB/s的版本。我能想到的唯一可靠的方法是复制粘贴本例的程序集并使用内联程序集。这是我摆脱那些似乎热衷于小改动的编译器的唯一方法。你怎么认为?有没有其他方法可以可靠地获得性能最高的代码?
拆卸
以下是各种结果的分解:
g++/u32/non const bufsize的26 GB/s版本:
0x400af8:
lea 0x1(%rdx),%eax
popcnt (%rbx,%rax,8),%r9
lea 0x2(%rdx),%edi
popcnt (%rbx,%rcx,8),%rax
lea 0x3(%rdx),%esi
add %r9,%rax
popcnt (%rbx,%rdi,8),%rcx
add $0x4,%edx
add %rcx,%rax
popcnt (%rbx,%rsi,8),%rcx
add %rcx,%rax
mov %edx,%ecx
add %rax,%r14
cmp %rbp,%rcx
jb 0x400af8
g++/u64/non-const bufsize的13 GB/s版本:
0x400c00:
popcnt 0x8(%rbx,%rdx,8),%rcx
popcnt (%rbx,%rdx,8),%rax
add %rcx,%rax
popcnt 0x10(%rbx,%rdx,8),%rcx
add %rcx,%rax
popcnt 0x18(%rbx,%rdx,8),%rcx
add $0x4,%rdx
add %rcx,%rax
add %rax,%r12
cmp %rbp,%rdx
jb 0x400c00
clang++/u64/non-const bufsize的15 GB/s版本:
0x400e50:
popcnt (%r15,%rcx,8),%rdx
add %rbx,%rdx
popcnt 0x8(%r15,%rcx,8),%rsi
add %rdx,%rsi
popcnt 0x10(%r15,%rcx,8),%rdx
add %rsi,%rdx
popcnt 0x18(%r15,%rcx,8),%rbx
add %rdx,%rbx
add $0x4,%rcx
cmp %rbp,%rcx
jb 0x400e50
g++/u32&u64/const bufsize的20 GB/s版本:
0x400a68:
popcnt (%rbx,%rdx,1),%rax
popcnt 0x8(%rbx,%rdx,1),%rcx
add %rax,%rcx
popcnt 0x10(%rbx,%rdx,1),%rax
add %rax,%rcx
popcnt 0x18(%rbx,%rdx,1),%rsi
add $0x20,%rdx
add %rsi,%rcx
add %rcx,%rbp
cmp $0x100000,%rdx
jne 0x400a68
clang++/u32&u64/const bufsize的15 GB/s版本:
0x400dd0:
popcnt (%r14,%rcx,8),%rdx
add %rbx,%rdx
popcnt 0x8(%r14,%rcx,8),%rsi
add %rdx,%rsi
popcnt 0x10(%r14,%rcx,8),%rdx
add %rsi,%rdx
popcnt 0x18(%r14,%rcx,8),%rbx
add %rdx,%rbx
add $0x4,%rcx
cmp $0x20000,%rcx
jb 0x400dd0
有趣的是,最快(26 GB/s)的版本也是最长的!这似乎是唯一使用lea的解决方案。一些版本使用jb跳转,其他版本使用jne。但除此之外,所有版本似乎都具有可比性。我不知道100%的性能差距可能来自何处,但我不太擅长破译汇编。最慢的(13 GB/s)版本看起来甚至非常短而且很好。有人能解释一下吗?
经验教训
无论这个问题的答案是什么;我已经了解到,在真正的热循环中,每一个细节都很重要,即使是看起来与热代码没有任何关联的细节。我从未想过循环变量使用什么类型,但正如您所看到的那样,这样一个微小的更改可以产生100%的差异!即使缓冲区的存储类型也会产生巨大的差异,正如我们在大小变量前面插入静态关键字所看到的那样!将来,当编写对系统性能至关重要的非常紧凑和热循环时,我将始终在各种编译器上测试各种替代方案。
有趣的是,尽管我已经展开了四次循环,但性能差异仍然很大。因此,即使展开,仍可能会受到重大性能偏差的影响。很有趣。
首先,尝试估计峰值性能-检查https://www.intel.com/content/dam/www/public/us/en/documents/manuals/64-ia-32-architectures-optimization-manual.pdf特别是附录C。
在您的案例中,表C-10显示POPCNT指令的延迟=3个时钟,吞吐量=1个时钟。吞吐量以时钟为单位显示最大速率(如果是popcnt64,则乘以核心频率和8字节以获得最佳带宽数)。
现在检查编译器做了什么,并总结循环中所有其他指令的吞吐量。这将为生成的代码提供最佳可能的估计。
最后,看看循环中指令之间的数据依赖性,因为它们将强制延迟大而不是吞吐量,所以将单次迭代的指令拆分到数据流链上,计算它们之间的延迟,然后天真地从中获取最大值。考虑到数据流的依赖性,它将给出粗略的估计。
然而,在您的情况下,只要以正确的方式编写代码就可以消除所有这些复杂性。不要累加到同一个计数变量,只需累加到不同的变量(如count0、count1、…count8),并在最后将它们相加。或者甚至创建一个计数数组[8]并累积到其元素中——也许,它甚至会被矢量化,您将获得更好的吞吐量。
P.S.,永远不要运行基准测试一秒钟,先预热核心,然后运行循环至少10秒或更好的100秒。否则,您将在硬件中测试电源管理固件和DVFS实现:)
P.P.S.我听到了关于基准测试应该运行多长时间的无尽争论。最聪明的人甚至会问为什么10秒不是11秒或12秒。我应该承认这在理论上很有趣。在实践中,您只需连续运行基准测试100次并记录偏差。这很有趣。大多数人都会更改源代码,并在这之后运行测试台一次,以获取新的性能记录。做正确的事情。
还不相信?只需通过assp1r1n3使用高于C版本的基准测试(https://stackoverflow.com/a/37026212/9706746)在重试循环中尝试100而不是10000。
我的7960X显示,RETRY=100:
计数:203182300已用时间:0.008385秒速度:12.505379 GB/s
计数:203182300已用时间:0.011063秒速度:9.478225 GB/s
计数:203182300已用时间:0.011188秒速度:9.372327 GB/s
计数:203182300已用时间:0.010393秒速度:10.089252 GB/s
计数:203182300已用时间:0.009076秒速度:11.553283 GB/s
RETRY=10000时:
计数:20318230000已用时间:0.661791秒速度:15.844519 GB/s
计数:20318230000已用时间:0.665422秒速度:15.758060 GB/s
计数:20318230000已用时间:0.660983秒速度:15.863888 GB/s
计数:20318230000已用时间:0.665337秒速度:15.760073 GB/s
计数:20318230000已用时间:0.662138秒速度:15.836215 GB/s
每分钟。最后,关于“接受的答案”和其他错误;-)
让我们用assp1r1n3的答案——他有2.5Ghz的核心。POPCNT有1个时钟输出,他的代码使用64位POPCNT。因此,对于他的设置,数学是2.5Ghz*1时钟*8字节=20GB/s。他看到的是25Gb/s,可能是由于涡轮增压到3Ghz左右。
因此,请访问ark.intel.com并查找i7-4870HQ:https://ark.intel.com/products/83504/Intel-Core-i7-4870HQ-Processor-6M-Cache-up-to-3-70-GHz-?q=i7-4870小时
该内核可以运行到3.7Ghz,其硬件的实际最大速率为29.6GB/s。那么,另一个4GB/s在哪里?也许,它花费在每个迭代中的循环逻辑和其他周围代码上。
现在,这种错误依赖关系在哪里?硬件几乎以峰值速率运行。也许我的数学不好,有时会这样:)
P.P.P.P.S.仍然有人认为硬件错误是罪魁祸首,所以我遵循建议,创建了内联asm示例,见下文。
在我的7960X上,第一个版本(单输出到cnt0)以11MB/s的速度运行,第二个版本(输出到cnt0、cnt1、cnt2和cnt3)的速度为33MB/s。有人会说——瞧!这是输出依赖性。
好吧,也许,我的观点是这样写代码是没有意义的,这不是输出依赖性问题,而是愚蠢的代码生成。我们不是在测试硬件,而是在编写代码以释放最大性能。你可以期待HW OOO应该重命名并隐藏这些“输出依赖项”,但只要做正确的事情,你就永远不会面临任何谜团。
uint64_t builtin_popcnt1a(const uint64_t* buf, size_t len)
{
uint64_t cnt0, cnt1, cnt2, cnt3;
cnt0 = cnt1 = cnt2 = cnt3 = 0;
uint64_t val = buf[0];
#if 0
__asm__ __volatile__ (
"1:\n\t"
"popcnt %2, %1\n\t"
"popcnt %2, %1\n\t"
"popcnt %2, %1\n\t"
"popcnt %2, %1\n\t"
"subq $4, %0\n\t"
"jnz 1b\n\t"
: "+q" (len), "=q" (cnt0)
: "q" (val)
:
);
#else
__asm__ __volatile__ (
"1:\n\t"
"popcnt %5, %1\n\t"
"popcnt %5, %2\n\t"
"popcnt %5, %3\n\t"
"popcnt %5, %4\n\t"
"subq $4, %0\n\t"
"jnz 1b\n\t"
: "+q" (len), "=q" (cnt0), "=q" (cnt1), "=q" (cnt2), "=q" (cnt3)
: "q" (val)
:
);
#endif
return cnt0;
}
缺点:虚假数据依赖性(编译器甚至不知道)
在Sandy/Ivy Bridge和Haswell处理器上,指令:
popcnt src, dest
似乎对目标寄存器dest有错误的依赖性。即使该指令只向其写入数据,该指令仍将等待dest就绪后再执行。这种错误的依赖性(现在)被Intel记录为勘误表HSD146(Haswell)和SKL029(Skylake)
Skylake为lzcnt和tzcnt修复了此问题。Cannon Lake(和Ice Lake)为popcnt修复了这个问题。bsf/bsr具有真正的输出依赖性:对于输入=0,输出未修改。(但无法利用内部函数的优势——只有AMD记录了它,编译器不会公开它。)
(是的,这些指令都在同一个执行单元上运行)。
这种依赖性不仅仅支持单个循环迭代中的4个popcnt。它可以跨循环迭代,使得处理器无法并行化不同的循环迭代。
无符号vs.uint64_t和其他调整不会直接影响问题。但它们会影响将寄存器分配给变量的寄存器分配器。
在您的案例中,速度是由于寄存器分配器决定执行的操作而导致的(错误)依赖链的直接结果。
13 GB/s有一个链:popcnt add popcnt popcnt→ 下一次迭代15 GB/s有一个链:popcnt add popcnt add→ 下一次迭代20 GB/s有一条链:popcnt popcnt→ 下一次迭代26 GB/s有一条链:popcnt popcnt→ 下一次迭代
20 GB/s和26 GB/s之间的差异似乎是间接寻址的一个小瑕疵。无论哪种方式,一旦达到这个速度,处理器就会开始遇到其他瓶颈。
为了测试这一点,我使用了内联程序集来绕过编译器,得到我想要的程序集。我还拆分了count变量,以打破可能会干扰基准测试的所有其他依赖关系。
以下是结果:
Sandy Bridge Xeon@3.5 GHz:(可在底部找到完整的测试代码)
GCC 4.6.3:g++popcnt.cpp-std=c++0x-O3-save temps-march=本地Ubuntu 12
不同寄存器:18.6195 GB/s
.L4:
movq (%rbx,%rax,8), %r8
movq 8(%rbx,%rax,8), %r9
movq 16(%rbx,%rax,8), %r10
movq 24(%rbx,%rax,8), %r11
addq $4, %rax
popcnt %r8, %r8
add %r8, %rdx
popcnt %r9, %r9
add %r9, %rcx
popcnt %r10, %r10
add %r10, %rdi
popcnt %r11, %r11
add %r11, %rsi
cmpq $131072, %rax
jne .L4
相同寄存器:8.49272 GB/s
.L9:
movq (%rbx,%rdx,8), %r9
movq 8(%rbx,%rdx,8), %r10
movq 16(%rbx,%rdx,8), %r11
movq 24(%rbx,%rdx,8), %rbp
addq $4, %rdx
# This time reuse "rax" for all the popcnts.
popcnt %r9, %rax
add %rax, %rcx
popcnt %r10, %rax
add %rax, %rsi
popcnt %r11, %rax
add %rax, %r8
popcnt %rbp, %rax
add %rax, %rdi
cmpq $131072, %rdx
jne .L9
断链的相同寄存器:17.8869 GB/s
.L14:
movq (%rbx,%rdx,8), %r9
movq 8(%rbx,%rdx,8), %r10
movq 16(%rbx,%rdx,8), %r11
movq 24(%rbx,%rdx,8), %rbp
addq $4, %rdx
# Reuse "rax" for all the popcnts.
xor %rax, %rax # Break the cross-iteration dependency by zeroing "rax".
popcnt %r9, %rax
add %rax, %rcx
popcnt %r10, %rax
add %rax, %rsi
popcnt %r11, %rax
add %rax, %r8
popcnt %rbp, %rax
add %rax, %rdi
cmpq $131072, %rdx
jne .L14
那么编译器出了什么问题?
GCC和Visual Studio似乎都没有意识到popcnt有这样一个错误的依赖关系。然而,这些错误的依赖关系并不罕见。这只是编译器是否意识到的问题。
popcnt并不是最常用的指令。因此,一个主要的编译器可能会漏掉这样的内容,这并不奇怪。似乎也没有任何文档提到这个问题。如果英特尔不披露,那么在有人偶然发现之前,外界不会知道。
(更新:从4.9.2版开始,GCC意识到这种错误依赖性,并在启用优化时生成代码来补偿它。其他供应商的主要编译器,包括Clang、MSVC,甚至英特尔自己的ICC,都还没有意识到这种微体系结构错误,不会发出补偿它的代码。)
为什么CPU有这样的错误依赖性?
我们可以推测:它与bsf/bsr运行在同一个执行单元上,后者确实具有输出依赖性。(POPCNT是如何在硬件中实现的?)。对于这些指令,英特尔将input=0的整数结果记录为“undefined”(ZF=1),但英特尔硬件实际上提供了更有力的保证,以避免损坏旧软件:未修改输出。AMD记录了这种行为。
大概是不方便让这个执行单元的一些uop依赖于输出,但其他的不依赖于输出。
AMD处理器似乎没有这种错误的依赖性。
完整的测试代码如下:
#include <iostream>
#include <chrono>
#include <x86intrin.h>
int main(int argc, char* argv[]) {
using namespace std;
uint64_t size=1<<20;
uint64_t* buffer = new uint64_t[size/8];
char* charbuffer=reinterpret_cast<char*>(buffer);
for (unsigned i=0;i<size;++i) charbuffer[i]=rand()%256;
uint64_t count,duration;
chrono::time_point<chrono::system_clock> startP,endP;
{
uint64_t c0 = 0;
uint64_t c1 = 0;
uint64_t c2 = 0;
uint64_t c3 = 0;
startP = chrono::system_clock::now();
for( unsigned k = 0; k < 10000; k++){
for (uint64_t i=0;i<size/8;i+=4) {
uint64_t r0 = buffer[i + 0];
uint64_t r1 = buffer[i + 1];
uint64_t r2 = buffer[i + 2];
uint64_t r3 = buffer[i + 3];
__asm__(
"popcnt %4, %4 \n\t"
"add %4, %0 \n\t"
"popcnt %5, %5 \n\t"
"add %5, %1 \n\t"
"popcnt %6, %6 \n\t"
"add %6, %2 \n\t"
"popcnt %7, %7 \n\t"
"add %7, %3 \n\t"
: "+r" (c0), "+r" (c1), "+r" (c2), "+r" (c3)
: "r" (r0), "r" (r1), "r" (r2), "r" (r3)
);
}
}
count = c0 + c1 + c2 + c3;
endP = chrono::system_clock::now();
duration=chrono::duration_cast<std::chrono::nanoseconds>(endP-startP).count();
cout << "No Chain\t" << count << '\t' << (duration/1.0E9) << " sec \t"
<< (10000.0*size)/(duration) << " GB/s" << endl;
}
{
uint64_t c0 = 0;
uint64_t c1 = 0;
uint64_t c2 = 0;
uint64_t c3 = 0;
startP = chrono::system_clock::now();
for( unsigned k = 0; k < 10000; k++){
for (uint64_t i=0;i<size/8;i+=4) {
uint64_t r0 = buffer[i + 0];
uint64_t r1 = buffer[i + 1];
uint64_t r2 = buffer[i + 2];
uint64_t r3 = buffer[i + 3];
__asm__(
"popcnt %4, %%rax \n\t"
"add %%rax, %0 \n\t"
"popcnt %5, %%rax \n\t"
"add %%rax, %1 \n\t"
"popcnt %6, %%rax \n\t"
"add %%rax, %2 \n\t"
"popcnt %7, %%rax \n\t"
"add %%rax, %3 \n\t"
: "+r" (c0), "+r" (c1), "+r" (c2), "+r" (c3)
: "r" (r0), "r" (r1), "r" (r2), "r" (r3)
: "rax"
);
}
}
count = c0 + c1 + c2 + c3;
endP = chrono::system_clock::now();
duration=chrono::duration_cast<std::chrono::nanoseconds>(endP-startP).count();
cout << "Chain 4 \t" << count << '\t' << (duration/1.0E9) << " sec \t"
<< (10000.0*size)/(duration) << " GB/s" << endl;
}
{
uint64_t c0 = 0;
uint64_t c1 = 0;
uint64_t c2 = 0;
uint64_t c3 = 0;
startP = chrono::system_clock::now();
for( unsigned k = 0; k < 10000; k++){
for (uint64_t i=0;i<size/8;i+=4) {
uint64_t r0 = buffer[i + 0];
uint64_t r1 = buffer[i + 1];
uint64_t r2 = buffer[i + 2];
uint64_t r3 = buffer[i + 3];
__asm__(
"xor %%rax, %%rax \n\t" // <--- Break the chain.
"popcnt %4, %%rax \n\t"
"add %%rax, %0 \n\t"
"popcnt %5, %%rax \n\t"
"add %%rax, %1 \n\t"
"popcnt %6, %%rax \n\t"
"add %%rax, %2 \n\t"
"popcnt %7, %%rax \n\t"
"add %%rax, %3 \n\t"
: "+r" (c0), "+r" (c1), "+r" (c2), "+r" (c3)
: "r" (r0), "r" (r1), "r" (r2), "r" (r3)
: "rax"
);
}
}
count = c0 + c1 + c2 + c3;
endP = chrono::system_clock::now();
duration=chrono::duration_cast<std::chrono::nanoseconds>(endP-startP).count();
cout << "Broken Chain\t" << count << '\t' << (duration/1.0E9) << " sec \t"
<< (10000.0*size)/(duration) << " GB/s" << endl;
}
free(charbuffer);
}
同样有趣的基准可以在这里找到:http://pastebin.com/kbzgL8si该基准会改变(false)依赖链中popcnt的数量。
False Chain 0: 41959360000 0.57748 sec 18.1578 GB/s
False Chain 1: 41959360000 0.585398 sec 17.9122 GB/s
False Chain 2: 41959360000 0.645483 sec 16.2448 GB/s
False Chain 3: 41959360000 0.929718 sec 11.2784 GB/s
False Chain 4: 41959360000 1.23572 sec 8.48557 GB/s