Автор: vasek
Способы нестандартной отладки/трассировки Х-ов, unit-ов systemd, udev, модулей
Иногда возникают ситуации, в которых при решении проблем не хватает информации, точнее логов journal и Xorg не достаточно, а как получить дополнительно не понятно.
Отдельной подборки материалов на данную тематику, где бы все это было в одном месте, нет … да, в принципе, и нагуглить это не просто.
Вот и решил описать некоторые способы добычи этой информации.
1. Начало
Начнем с самого простого udev, который имеет конфигурационный файл /etc/udev/udev.conf, в котором есть одна строчка
#udev_log=infoudev_log=debugjournalctl -b | grep -i udev #или по другому. 2. Отладка unit systemd
2.1 Стандартный простой способ
Имеется стандартный простой способ для увеличения логирования отдельного системного unit,
находящегося в директории /usr/lib/systemd/system/ - необходимо добавить опцию -d (от слова debug) в строке запуска юнита.
Например, для /usr/lib/systemd/system/bluetooth.service имеем
cat /usr/lib/systemd/system/bluetooth.service | grep ExecStart
ExecStart=/usr/lib/bluetooth/bluetoothd
ExecStart=/usr/lib/bluetooth/bluetoothd -dsystemctl daemon-reload # при необходимости и restart сервиса2.2. Применение strace
Для этого способа используем следующий запуск unit, например, имеем
cat /usr/lib/systemd/system/systemd-vconsole-setup.service | grep ExecStart
ExecStart=/usr/lib/systemd/systemd-vconsole-setup
ExecStart=/usr/bin/strace -f -tt -o /run/%N.strace /lib/systemd/systemd-vconsole-setupИ не забываем systemctl daemon-reload (при необходимости и restart сервиса)
PS- Разумеется можно редактировать тот же сервис в другой стандартной директории /etc/systemd/system/ и не забываем потом вернуть все обратно ...
3. Xorg
Xorg - здесь имеется несколько способов - и простые и сложные. Простые приводят к простому увеличению логирования от которого мало толку,
а потому их не описываю. Приведу не стандартный способ трассировки с использованием strace.
Если используется DM, то лучше его временно отключить и использовать .xinitrc (то есть startx).
Загружаемся в текстовую консоль (Х-ы не запускаем), меняем файл **/etc/X11/xinit/xserverrc**, например, приводим к виду (изменив на нужное)
cat /etc/X11/xinit/xserverrc
#!/bin/sh
#exec /usr/bin/X -nolisten tcp "$@"
exec /usr/bin/strace -f -T -o /home/vasek/strace_X.log /usr/bin/X -nolisten tcp "$@"которая позволяет посмотреть как долго выполняется каждый системный вызов. Название лога на Ваше усмотрение.
Сохраняем и стартуем Х-ы - не пугаемся, время загрузки увеличится, **НО сразу после загрузки убиваем (выходим) Х-ы** и приводим файл /etc/X11/xinit/xserverrc к нормальному виду,
точнее возвращаем все на место (Х-ы нужно убить, так как они запущены через strace, убить которй не получится - вообщем проще убить Х-ы и вернуться в текстовую консоль)
cat /etc/X11/xinit/xserverrc
#!/bin/sh
exec /usr/bin/X -nolisten tcp "$@"
Снова загружаем Х-ы и анализируем **файл strace_X.log**, в котором в конце каждой строки будет указано время выполнения системного вызова, типа такого
9218 openat(AT_FDCWD, "/proc/9232/cmdline", O_RDONLY) = 27 <0.000027>
9218 read(27, "tilix\0", 4097) = 6 <0.000019>
9218 close(27) = 0 <0.000015>
Повторюсь, использование опций strace зависит от обстоятельств расследования.
При желании вместо strace можно использовать более мощный комбайн - sysdig, но работать с ним сложнее.
4. Драйвера/модули
И в конце привожу, как можно получить информацию в случае проблем с драйверами/модулями - обычно возникает при выходе из suspend/hibernate … иногда и при загрузке.
Способ заключается в передаче параметра ядра **initcall_debug** при загрузке, в результате чего в dmesg будет сохранена информация каждого initcall,
который используется для инициализации статически связанных драйверов ядра и подсистем, и будет возможность получить информацию о времени загрузки этих драйверов/модулей.
Вообщем, прописываем параметр initcall_debug, лучше прямо при загрузке, перейдя в консоль Grub (нажимаем e в меню Grub) и загружаемся.
В логах будут строки о загрузке модулей, они разбросаны, искать их тяжело, но для одного модуля, например, ath3k можно посмотреть так
dmesg | grep ath3k
[ 12.594842] calling ath3k_driver_init+0x0/0x1000 [ath3k] @ 326
[ 13.101284] usbcore: registered new interface driver ath3k
[ 13.101298] initcall ath3k_driver_init+0x0/0x1000 [ath3k] returned 0 after 23011 usecs
Но в одной статье приведена интересная команда для вытаскивания этой информации из dmesg
dmesg -s 128000 | grep "initcall" | sed "s/\(.*\)after\(.*\)/\2 \1/g" | sort -n0 usecs [ 0.971675] initcall vga_arb_device_init+0x0/0x25e returned 0
0 usecs [ 0.971686] initcall cn_init+0x0/0xe0 returned 0
0 usecs [ 0.971697] initcall pm860x_i2c_init+0x0/0x30 returned 0
………….
13 usecs [ 11.832572] initcall init_soundcore+0x0/0x1000 [soundcore] returned 0
14 usecs [ 1.175133] initcall pid_namespaces_init+0x0/0x40 returned 0
14 usecs [ 1.289965] initcall dw_pci_driver_init+0x0/0x1a returned 0
14 usecs [ 1.344490] initcall clk_debug_init+0x0/0x116 returned 0
14 usecs [ 1.509541] initcall serio_init+0x0/0x1000 [serio] returned 0
15 usecs [ 1.177037] initcall zs_init+0x0/0x77 returned 0
... и так далее …
Рекомендуют увеличить размер буфера журнала printk, чтобы избежать переполнения буфера журнала.
Правда я с таким не сталкивался.
Дополнение
Уточнение в части информативности Xorg - конечно, не совсем удобно редактировать файл /etc/X11/xinit/xserverrc, чтобы прописать запуск strace,
а затем убивать Х-ы …. намного удобнее ничего этого не делать, а просто из текстовой консоли запустить sysdig, а затем startx …,
то есть загружаемся в текстовую консоль и далее ...
# sysdig -w ~/sysdig.log$ pidof sysdig
28360
# kill 28360
$ pidof sysdig
… пусто …
Посмотрим на созданный лог и его объем
$ du -m ~/sysdig.log
**18** /home/vasek/sysdig.log
Анализируя данный файл можно получить любую информацию, но для этого нужно знать как это делать, то есть нужно изучать sysdig.
В принципе sysdig можно успешно использовать и в работающей системе, чтобы найти возможные проблемы. https://habr.com/ru/company/selectel/blog/222839/ для начального ознакомления с sysdig