我有一个线程写入原子变量,第二个线程在其上旋转。我从写入到检测到变化的时间。
我发现延迟高达 80,000,其中许多延迟在 20,000 到 40,000 之间。这应该需要约 350 个周期。线程被固定,我使用获取-释放语义等。
代码:https://godbolt.org/z/ETM1YnTrb并粘贴在下面。如果有人能证实我的观察,我们将不胜感激。
为了进行调查,我重点关注了热旋转 while 循环:
while(true)
{
if(_trigger.load(std::memory_order_acquire)) [[unlikely]]
{
const uint64_t read_ts = rdtscp();
}
操作系统是否重新调度了旋转线程?或者,线程是否仍在旋转,但没有看到
_trigger
的值?
我在每次循环迭代时获取时间戳并保存到数组中。在高延迟时,我打印写入时间戳、读取时间戳和循环迭代时间戳。
while(true)
{
// Take a timestamp here and store to an array/circular buffer
if(_trigger.load(std::memory_order_acquire)) [[unlikely]]
{
const uint64_t read_ts = GetNow();
const uint64_t latency = read_ts - write_ts;
if(latency > N)
{
// print write ts
// loop iteration timestamps
// print read ts
}
我观察到写入和读取之间有数百次循环迭代:
write_ts 392525979198029
iteration (37898) loop_ts 392525979198029
.
.
.
iteration (37932) loop_ts 392525979198029
iteration (37933) loop_ts 392525979198029
.
iteration (38500) loop_ts 392525979198029
.
iteration (38545) loop_ts 392525979198029
read_ts 392525979221689
core_id (1) write -> read (23660) loop -> read (196) soft (0) hard (0) vol (0) invol (0) sig (0) kernel_us (0)
因此,读取线程不会被重新安排,除非它发生在最终循环 ts 之后和读取 ts 之前。
while(true)
{
const uint64_t loop_ts = GetNow();
// Delay starts here
if(_trigger.load(std::memory_order_acquire)) [[unlikely]]
{
// delay ends here
const uint64_t read_ts = GetNow();
上面显示旋转线程从最终循环时间戳到达到读取时间戳花了 23,000 个周期?!
我添加了一个宏来切换
getrusage()
来测量上下文切换,虽然偶尔会发生一些情况,但很多时候发生这种情况时并没有上下文切换。我还添加了一个宏来在 tsc 和纳秒/计时之间切换。
我认为有三种可能性?
我的 CPU 是 Intel Xeon W-1370P @ 3.60GHz。它有 1 个插槽、8 个核心、16 个超线程。我相信核心 0-7 映射到核心 8 到 15,所以我使用 1 和 6 进行了测试。
如果我取消定义 rusage (和纳秒)并运行
perf
我得到:
sudo perf stat -B --delay=1000 ./my_app
所以我不认为这与上下文切换有关?
有谁知道这是怎么回事吗?
Ubuntu 22.04
内核是:
6.5.0-14-generic
编译器是 Clang 16,带有
-O3 -march=native -mprefer-vector-width=128
完整代码:
#include <cstdint>
#include <iostream>
#include <thread>
#include <x86intrin.h>
#include <atomic>
#include <array>
#include <chrono>
#include <sys/resource.h>
//#define USE_RUSAGE
//#define USE_NANOSECONDS
using TimePoint = std::chrono::high_resolution_clock::time_point;
uint64_t GetNow();
uint64_t rdtscp();
void set_thread_affinity(const int8_t core_id);
void check_latency(int core_id, uint64_t ts_1, uint64_t ts_2);
static const size_t WRITE_THREAD_CPU_ID_AFFINITY = 6;
static const size_t READ_THREAD_CPU_ID_AFFINITY = 1;
alignas(64) std::atomic<bool> _trigger{false};
int _core_id;
std::array<uint64_t, 65536> _loop_ts;
alignas(64) std::atomic<uint64_t> _write_ts;
void hot_spin()
{
set_thread_affinity(READ_THREAD_CPU_ID_AFFINITY);
#ifdef USE_RUSAGE
struct rusage usage_1;
getrusage(RUSAGE_THREAD, &usage_1);
#endif
uint16_t loop_count{0};
while(true)
{
const uint64_t loop_start = GetNow();
_loop_ts[loop_count] = loop_start;
if(_trigger.load(std::memory_order_acquire)) [[unlikely]]
{
const uint64_t read_ts = GetNow();
const uint64_t latency = read_ts - _write_ts.load(std::memory_order_acquire);
#ifdef USE_RUSAGE
struct rusage usage_2;
getrusage(RUSAGE_THREAD, &usage_2);
#endif
if(latency >= 20'000 && latency <= 100'000'000)
{
std::cout << "write_ts " << _write_ts << std::endl;
for(size_t i = 0; i < _loop_ts.size(); ++i)
{
if(_loop_ts[i] >= _write_ts)
{
std::cout << "iteration (" << i << ") loop_ts " << _write_ts << std::endl;
}
}
std::cout << "read_ts " << read_ts << std::endl;
#ifdef USE_RUSAGE
const uint64_t vol_cs = usage_2.ru_nvcsw - usage_1.ru_nvcsw;
const uint64_t invol_cs = usage_2.ru_nivcsw - usage_1.ru_nivcsw;
const uint64_t soft = usage_2.ru_minflt - usage_1.ru_minflt;
const uint64_t hard = usage_2.ru_majflt - usage_1.ru_majflt;
printf("core_id (%d) write -> read (%lu) loop -> read (%lu) soft (%lu) hard (%lu) vol (%lu) invol (%lu) sig (%ld) kernel_us (%ld)\n", _core_id, latency, read_ts - loop_start, soft, hard, vol_cs, invol_cs, usage_2.ru_nsignals - usage_1.ru_nsignals, usage_2.ru_stime.tv_usec - usage_1.ru_stime.tv_usec);
#else
printf("core_id (%d) write -> read (%lu) loop -> read (%lu)\n", _core_id, latency, read_ts - loop_start);
#endif
}
#ifdef USE_RUSAGE
usage_1 = usage_2;
#endif
_trigger = false;
}
++loop_count;
}
}
void write()
{
const uint64_t write_ts = GetNow();
_write_ts.store(write_ts, std::memory_order_release);
_trigger.store(true, std::memory_order_release);
}
void waitUntilPtrReset()
{
while(_trigger){}
}
int main()
{
set_thread_affinity(WRITE_THREAD_CPU_ID_AFFINITY);
std::thread t(&hot_spin);
t.detach();
while(true)
{
write();
waitUntilPtrReset();
}
return 0;
}
#ifdef USE_NANOSECONDS
uint64_t GetNow()
{
const TimePoint now = chrono::high_resolution_clock::now();
const auto tmp_1 = std::chrono::time_point_cast<std::chrono::nanoseconds>(now);
const auto tmp_2 = tmp_1.time_since_epoch();
return tmp_2.count();
}
#else
uint64_t GetNow()
{
return rdtscp();
}
uint64_t rdtscp()
{
uint32_t lo, hi;
__asm__ __volatile__("rdtscp" : "=a" (lo), "=d" (hi) : : "%rcx");
return (((uint64_t)hi << 32) | lo);
}
#endif
inline void set_thread_affinity(const int8_t core_id)
{
cpu_set_t mask;
CPU_ZERO(&mask);
CPU_SET(core_id, &mask);
const int this_process = 0;
const int result = sched_setaffinity(this_process, sizeof(mask), &mask);
if(result != 0)
{
std::abort();
}
}
正如评论中所讨论的,这很可能只是中断处理程序导致其中一个核心偶尔出现延迟峰值,与实际的线程间通信无关。
通常,您应该因为中断等原因而丢弃微基准测试中的异常值。 (如果您不禁用 Turbo,CPU 频率转换可能会在新电压稳定时暂停时钟几微秒。)
我可以在我的桌面上重现它(i7-6700k Arch GNU/Linux,内核 6.5)。当我按下键盘按键时,终端上的喷涌率似乎更高,但如果我把手拿开几秒钟,就会稳定下来。 (不是零,而是更低的中断率)。敲击更多按键和另一次输出爆发之间似乎存在相关性。移动鼠标时没有那么强烈;也许 IRQ 处理程序与运行这些线程的两个内核位于不同的内核上。
IRQ 处理程序不算作上下文切换。在 Spectre/Meltdown 和 KPTI 的其他原因之前,页表不会改变。对于 KPTI,它只是在同一进程的页表的 with-kernel-mappings 与 without-kernel-mappings 版本之间进行更改。 Linux 的每核心
current
变量不会改变。 (需要调度并需要上下文切换的中断处理程序的下半部分。但本地计时器中断不需要下半部分。此外,下半部分可能会在不同的内核上运行。 )
要在本地计时器中断每秒触发 100x 或 1000x 的情况下运行进程,您需要一个配置有 CONFIG_NO_HZ_FULL=y
(
https://docs.kernel.org/timers/no_hz.html) 的内核。文档称通常不建议这样做,因为启用/禁用定期引发中断的计时器会增加比在大多数工作负载中节省的开销更多的开销。 大概您需要
isolcpus
或其他东西来引导设备驱动程序中断远离您所固定的内核。
中断可以持续那么久?!启用 Spectre 和 MDS 缓解措施后,当然可以。刷新分支预测和内部微架构缓冲区的微代码可能需要大量时间,30k 周期似乎是合理的。