Я выполняю некоторую трассировку различных функций ядра и системных вызовов и устанавливаю между ними шаблоны, которые можно использовать для определенного профилирования производительности.
Одна вещь, которую я заметил, это то, что иногда, даже в моем простом тестированииприложение, которое раскручивает несколько потоков, которые играют с некоторыми мьютексами, я не получал бы никаких вызовов на kretprobe__sys_futex, но я получал бы много на kprobe__sys_futex.
Я предполагал, что это произошло, например, из-за потокаЗвонил в sys_futex, и засыпал или, возможно, завершал, но на самом деле я вижу, как одни и те же процессы вызывают sys_futex несколько раз подряд, а зонд возврата никогда ничего не замечал.
Затем я предположил, что проблема была вкак я фильтровал вызовы на kprobe__sys_futex, поэтому я сделал минимальный пример, используя BCC / eBPF для проверки этого:
#! /usr/bin/env python
from bcc import BPF
b = BPF(text="""
BPF_HASH(call_count, int, int);
int kprobe__sys_futex() {
int zero = 0;
call_count.lookup_or_init(&zero, &zero);
bpf_trace_printk("futex start\\n");
call_count.increment(zero);
return 0;
}
int kretprobe__sys_futex() {
int zero = 0;
int *val_p = call_count.lookup(&zero);
if (val_p != NULL) {
int val = *val_p;
val--;
call_count.update(&zero, &val);
bpf_trace_printk("futex calls with no return: %d\\n", val);
} else { bpf_trace_printk("unexpected futex return\\n"); }
return 0;
}
""")
b.trace_print()
Я заметил, что во всех видах приложений (хорошим примером является mysql-сервер,который выполняет обычные операции futex даже в режиме ожидания - по крайней мере, на моем компьютере), многие (часто 10+) futex start s печатаются раньшесообщение от датчика возврата.
Вот пример трассировки вышеупомянутой программы, которую я оставил запущенной на пару минут, пока писал этот пост:
... hundreds of lines of much the same as below
gdbus-612 [001] .... 211229.997665: 0x00000001: futex start
NetworkManager-541 [001] .... 211229.997667: 0x00000001: futex start
gdbus-612 [001] .... 211229.997670: 0x00000001: futex start
mysqld-697 [001] .... 211230.789205: 0x00000001: futex start
mysqld-697 [001] .... 211230.789227: 0x00000001: futex start
mysqld-703 [001] .... 211230.789251: 0x00000001: futex start
mysqld-703 [001] .... 211230.789253: 0x00000001: futex start
mysqld-704 [001] d... 211230.789258: 0x00000001: futex calls with no return: 3994
mysqld-704 [001] .... 211230.789259: 0x00000001: futex start
mysqld-704 [001] d... 211230.789260: 0x00000001: futex calls with no return: 3994
mysqld-704 [001] .... 211230.789272: 0x00000001: futex start
mysqld-713 [000] .... 211231.037016: 0x00000001: futex start
mysqld-713 [000] .... 211231.037036: 0x00000001: futex start
vmstats-895 [000] .... 211231.464867: 0x00000001: futex start
mysqld-697 [001] .... 211231.790738: 0x00000001: futex start
mysqld-697 [001] .... 211231.790784: 0x00000001: futex start
mysqld-703 [001] .... 211231.790796: 0x00000001: futex start
mysqld-703 [001] .... 211231.790799: 0x00000001: futex start
mysqld-704 [001] d... 211231.790809: 0x00000001: futex calls with no return: 4001
mysqld-704 [001] .... 211231.790812: 0x00000001: futex start
mysqld-704 [001] d... 211231.790814: 0x00000001: futex calls with no return: 4001
Как видите,Например, pid 697, по-видимому, четыре раза вызывал sys_futex, не возвращаясь только по этой маленькой трассировке.
Я не думаю, что это условие гонки в коде eBPF, потому что если вы отключите печатьДля операторов и только для периодической печати счетчик обычно ограничен несколькими нулями для sys_write, что происходит на величины чаще, чем sys_futex (по крайней мере, при нагрузке на мою систему), поэтому я ожидаю, что любые условия гонки будут усугублены, а не решены.
Я использую Kernel 4.15.0-43-generic на Ubuntu 18.04 LTS, который находится в VirtualBox.
Рад предоставить вам еще какой-нибудь контекст, который может быть полезен!
В списке рассылки IOVisor есть тема, которая имеет отношение: https://lists.iovisor.org/g/iovisor-dev/topic/29702757