Трасувальник вводу-виводу в ядрі Linux

Мало хто знає, що в ядрі Linux є незвичайні і дуже корисні інструменти для налагодження і тестування. У цій невеликій статті я хочу поділитися описом трассировщика вводу-виводу.

Введення
Трасувальник вводу-виводу був розроблений в свій час для тестування надійності драйверів (https://landley.net/kdocs/ols/2003/ols2003-pages-524-530.pdf), а пізніше розвинувся в проект реверс инжинирига протоколу програмування відеоплат nVidia для проекту Nouveau. Проте крім цієї мети в процесі розвитку з'явився зручний інструмент не стільки тестування, скільки налагодження драйверів.

Переваги цього методу очевидні — налагоджувальна друк повільна, більш того вносить небажані затримки часу виконання, що часто може призводити до неправильної роботи програми (впевнений, що ви стикалися з таким, що debug версія працює, а release — ні, або навпаки). Недоліки теж є, як-то:
  • ймовірність втрати подій за певних умов (див. нижче)
  • неможливість налагодження шин, для яких вікно завжди присутня, наприклад, ISA
  • трасувальник підтримується лише для архітектур x86, x86_64


Як це працює
Доступ до регістрів заліза досягається шляхом виділення в адресному просторі вікна, всі операції запису або читання в якому транслюються у відповідні команди на шині. Трассировшик впроваджено в функцію
__ioremap()
і буде викликаний відповідно в будь-який момент, коли драйвер запросить виділення вікна.

У підсумку подія запиту вікна і всі подальші звернення до цього вікна будуть записані у внутрішньому балці трассировщика, так як будь-яке звернення буде викликати виключення Page Fault, і ядро змушений його обробляти. Перед записом запит декодується таким чином, щоб виділити операцію (читання або запис), довжину операнда і його значення.

Оскільки можливо стан гонки під час маніпуляцій з прапорами сторінок вікна, можлива втрата подій. Тому трасувальник примусово вимикає всі ядра процесора, крім одного. Включення їх назад не рекомендується.

Приклад використання
Спочатку необхідно у файлі кофигурации ядра включити необхідний модуль з допомогою опції:
CONFIG_MMIOTRACE=y
За замовчуванням трасувальник не активний. Для його активації необхідно виконати наступні команди в консолі:
# Монтуємо debugfs
mount -t debugfs debugfs /sys/kernel/debug
# Активуємо трасувальник
echo mmiotrace > /sys/kernel/debug/tracing/current_tracer
# Перенаправляємо лог файл
cat /sys/kernel/debug/tracing/trace_pipe > mylog.txt &
# Тут ми завантажуємо драйвер, введення-виведення якого хочеться відстежити
...
# Зупиняємо трасувальник
echo nop > /sys/kernel/debug/tracing/current_tracer


Практичний посібник
За основу візьмемо драйвер High Speed UART на SoC від Intel. Виконаємо такі команди:

mount -t debugfs none /sys/kernel/debug/

echo mmiotrace > /sys/kernel/debug/tracing/current_tracer
echo 1 > /sys/kernel/debug/tracing/tracing_on

echo "0000:00:18.1" > "/sys/bus/pci/drivers/intel-lpss/unbind"
echo "0000:00:18.1" > "/sys/bus/pci/drivers/intel-lpss/bind"


Висновок в лог буде виглядати приблизно так:
[ 178.024544] in mmio_trace_init
[ 178.065507] mmiotrace: Disabling non-boot CPUs…
[ 178.080558] Cannot set affinity for irq 169
[ 178.086384] smpboot: CPU 1 now is offline
[ 178.100507] mmiotrace: CPU1 is down.
[ 178.110047] smpboot: CPU 2 now is offline
[ 178.119028] mmiotrace: CPU2 is down.
[ 178.127165] smpboot: CPU 3 now is offline
[ 178.134891] mmiotrace: CPU3 is down.
[ 178.138912] mmiotrace: enabled.
[ 178.147690] in mmio_trace_start
[ 178.151974] mmiotrace: Unmapping ffffc900007ae000.
[ 178.160092] mmiotrace: Unmapping ffffc900007ac000.
[ 178.170893] mmiotrace: Unmapping ffffc900007aa000.
[ 178.178683] mmiotrace: ioremap_*(0x9242e200, 0x100) = ffffc900007dc200
[ 178.186279] mmiotrace: ioremap_*(0x9242e800, 0x800) = ffffc900007de800
[ 178.195682] idma64 idma64.9: Found Intel integrated DMA 64-bit
[ 178.207663] mmiotrace: ioremap_*(0x9242e000, 0x200) = ffffc900007fa000
[ 178.217141] dw-apb-uart.9: ttyS1 at MMIO 0x9242e000 (irq = 5, base_baud = 115200) is a 16550A


Перенаправимо висновок у файл:
cat /sys/kernel/debug/tracing/trace_pipe >/tmp/t &


Файл вже не нульової довжини буде, давайте поглянемо на його вміст:
VERSION 20070824
UNMAP 178.157353 -1 0x0 0
UNMAP 178.165484 -1 0x0 0
UNMAP 178.176279 -1 0x0 0
MAP 178.186036 1 0x9242e200 0xffffc900007dc200 0x100 0x0 0
R 4 178.186064 1 0x9242e2fc 0x11 0x0 0
W 4 178.186067 1 0x9242e204 0x7 0x0 0
W 4 178.186069 1 0x9242e240 0x9242e000 0x0 0
W 4 178.186071 1 0x9242e244 0x0 0x0 0
R 4 178.186125 1 0x9242e200 0x3d090240 0x0 0
R 4 178.186160 1 0x9242e210 0x800 0x0 0
R 4 178.186164 1 0x9242e214 0x800 0x0 0
MAP 178.195481 2 0x9242e800 0xffffc900007de800 0x800 0x0 0
W 4 178.195510 2 0x9242eb98 0x0 0x0 0
W 4 178.195512 2 0x9242eb10 0x300 0x0 0
W 4 178.195515 2 0x9242eb18 0x300 0x0 0
W 4 178.195517 2 0x9242eb20 0x300 0x0 0
W 4 178.195519 2 0x9242eb28 0x300 0x0 0
W 4 178.195521 2 0x9242eb30 0x300 0x0 0
R 4 178.195525 2 0x9242eb98 0x0 0x0 0
MAP 178.216881 3 0x9242e000 0xffffc900007fa000 0x200 0x0 0
R 4 178.216924 1 0x9242e200 0x3d090240 0x0 0
W 4 178.216926 1 0x9242e200 0x3d090241 0x0 0
R 4 178.216931 1 0x9242e200 0x3d090241 0x0 0
W 4 178.216933 1 0x9242e200 0xbd090241 0x0 0
R 4 178.216940 3 0x9242e0f8 0x3331342a 0x0 0
R 4 178.216943 3 0x9242e0f4 0x43f32 0x0 0
W 4 178.229863 3 0x9242e010 0x0 0x0 0


Формат описаний у документації, і в принципі інтуїтивно зрозумілий. Нас цікавлять рядка MAP[ping], R[ead], W[rite], які відповідно визначають адреси вікон вводу-виводу, дані читання з регістра й запису. Оскільки не дуже зручно відстежувати тільки числа, я написав простий парсер, що перетворює адреси в імена регістрів.
R 178.216940 UCV 0x3331342a
R 178.216943 CPR 0x00043f32
W 178.229863 MCR 0x00


Так читати значно зручніше (що не відносяться безпосередньо до регістри UART, як-то DMA і розширення, видалені з виводу, насправді вони присутні у вигляді адрес для подальшої обробки)!

Для перевірки запустимо просту команду
stty -F /dev/ttyS1 921600
.
W 335.706380 FCR 0x01
W 335.706391 FCR 0x07
W 335.706393 FCR 0x00
R 335.706397 LSR 0x60
R 335.706401 RX 0x00
R 335.706405 IIR 0x01
R 335.706408 MSR 0x00
R 335.706413 LSR 0x60
R 335.706417 LSR 0x60
W 335.706419 IER 0x02
R 335.706422 LCR 0x00
R 335.706426 IIR 0x02
W 335.706428 IER 0x00
W 335.706431 IER 0x02
R 335.706435 LCR 0x00
R 335.706440 IIR 0x02
W 335.706442 IER 0x00
W 335.706535 LCR 0x03
W 335.706541 MCR 0x08
W 335.706543 IER 0x02
R 335.706547 LSR 0x60
R 335.706550 IIR 0x02
W 335.706552 IER 0x00
R 335.706561 IIR 0x01
R 335.706565 LSR 0x60
R 335.706568 RX 0x00
R 335.706572 IIR 0x01
R 335.706575 MSR 0x00
W 335.706754 IER 0x05
W 335.706757 LCR 0x93
W 335.706760 DLL 0x0c
W 335.706762 DLM 0x00
W 335.706764 LCR 0x13
W 335.706766 FCR 0x01
W 335.706768 FCR 0x81
W 335.706771 MCR 0x08
W 335.706778 MCR 0x0b
R 335.706850 LSR 0x60
W 335.706918 IER 0x05
W 335.706920 LCR 0x93
W 335.706923 DLL 0x01
W 335.706925 DLM 0x00
W 335.706927 LCR 0x13
W 335.706929 FCR 0x01
W 335.706931 FCR 0x81
W 335.706934 MCR 0x0b
R 335.707047 LSR 0x60
W 335.707071 IER 0x00
R 335.707078 LSR 0x60
W 335.707080 MCR 0x08
W 335.707083 IER 0x00
W 335.707189 MCR 0x00
R 335.707196 LCR 0x13
W 335.707198 LCR 0x13
W 335.707200 FCR 0x01
W 335.707203 FCR 0x07
W 335.707205 FCR 0x00
R 335.707221 RX 0x00
R 335.707268 IIR 0x01


Так ми наочно побачили як програмується UART 8250 в ядрі Linux. Відповідно можна застосовувати в налагодження драйвера пристроїв, коли не зовсім зрозуміло, яким шляхом йде алгоритм, так як залежить від вычитанных даних з пристрою.

Якщо не виходить
Трохи більш детально все описано в документації, до якої має сенс звернутися. Так само зверніть увагу, що в силу своєї реалізації трасувальник може не працювати. Так, зокрема, я виявив регресію в нових ядрах.
Джерело: Хабрахабр

0 коментарів

Тільки зареєстровані та авторизовані користувачі можуть залишати коментарі.