Отладка через печать

Наиболее общей техникой отладки является мониторинг, который в прикладном программировании осуществляется вызовом в соответствующих местах printf. При отладке кода ядра вы можете достичь той же цели с помощью printk.

printk

Мы использовали функцию printk в предыдущих главах с упрощающим предположением, что она работает как printf. Теперь пришло время познакомиться с некоторыми отличиями.

Одним из отличий является то, что printk позволяет классифицировать сообщения в зависимости от их серьёзности, связывая разные уровни логирования (loglevels) или приоритеты, с сообщениями. Вы обычно указываете уровень логирования макросом. Например, KERN_INFO, который мы видели предшествующим чему-либо в приведённых раннее вызовах печати, является одним из возможных уровней логирования сообщений. Макрос уровня логирования заменяется на строку, которая объединяется с текстом сообщения во время компиляции; вот почему в следующих примерах нет запятой между приоритетом и строкой форматирования. Вот два примера команд printk, отладочное сообщение и критическое сообщение:

printk(KERN_DEBUG "Here I am: %s:%i\n", __FILE__, __LINE__);

printk(KERN_CRIT "I'm trashed; giving up on %p\n", ptr);

Есть восемь возможных строк уровня логирования, определённых в заголовке <linux/kernel.h>; мы перечисляем их в порядке убывания серьёзности:

KERN_EMERG

Используется для аварийных сообщений, как правило, тем, которые предшествуют катастрофе.

KERN_ALERT

Ситуации, требующей немедленных действий.

KERN_CRIT

Критические условия, часто связанные с серьёзными аппаратными или программными сбоями.

KERN_ERR

Используется, чтобы сообщить об ошибочных условиях; драйверы устройств часто используют KERN_ERR для сообщения об аппаратных проблемах.

KERN_WARNING

Предупреждения о проблемных ситуациях, которые сами по себе не создают серьёзных проблем с системой.

KERN_NOTICE

Ситуации, которые являются нормальными, но всё же достойны внимания. Различные обстоятельства, относящиеся к безопасности, сообщаются с этим уровнем.

KERN_INFO

Информационные сообщения. Многие драйверы печатают информацию об оборудовании, которую они находят во время запуска с этим уровнем.

KERN_DEBUG

Используется для отладочных сообщений.

Каждая строка (в макроподстановках) представляет собой целое число в угловых скобках. Целые числа в диапазоне от 0 до 7, чем меньше величина, тем больше приоритет.

Вызов printk без заданного приоритета использует DEFAULT_MESSAGE_LOGLEVEL, определённый в kernel/printk.c как целое число. В ядре версии 2.6.10, DEFAULT_MESSAGE_LOGLEVEL является KERN_WARNING, но это, как известно, менялось в прошлом.

На основании уровня логирования ядро может печатать сообщения в текущей консоли, будь то текстовый терминал, последовательный порт, или параллельный принтер. Если приоритет меньше целой переменной console_loglevel, сообщение будет доставлено на консоль по одной строке за раз (не посылается ничего, пока не получен завершающий символ "новая строка"). Если в системе работают и klogd и syslogd, сообщения ядра добавляются в /var/log/messages (или другой, в зависимости от вашей конфигурации syslogd), независимо от console_loglevel. Если klogd не работает, сообщение не дойдёт до пространства пользователя, пока вы не прочитаете /proc/kmsg (что часто проще всего сделать командой dmesg). При использовании klogd вы должны помнить, что он не сохраняет одинаковые следующие друг за другом строки; он сохраняет только первую такую линию, а позднее - количество полученных повторов.

Переменная console_loglevel инициализируется с DEFAULT_CONSOLE_LOGLEVEL и может быть изменена с помощью системного вызова sys_syslog. Один из способов изменить это - задать значение ключом -c при вызове klogd, как указано в справке klogd. Обратите внимание, что для изменения текущего значения, вы должны сначала убить klogd, а затем перезапустить его с опцией -c. Кроме того, вы можете написать программу для изменения уровня логирования консоли. Вы найдёте вариант такой программы в misc-progs/setlevel.c в исходных файлах, находящихся на FTP сайте O'Reilly. Новый уровень определяется как целое число между 1 и 8, включительно. Если он установлен в 1, консоли достигают только сообщения уровня 0 (KERN_EMERG), если он установлен в 8, отображаются все сообщения, включая отладочные.

Также можно читать и модифицировать уровень логирования консоли с помощью текстового файла /proc/sys/kernel/printk. Файл содержит четыре целых величины: текущий уровень логирования, уровень по умолчанию для сообщений, которые не имеют явно заданного уровня логирования, минимально разрешённый уровень логирования и уровень логирования по умолчанию во время загрузки. Запись одного значения в этот файл изменяет текущий уровень логирования на это значение; так, например, вы можете распорядиться, чтобы все сообщения ядра появлялись в консоли, простым вводом:

# echo 8 > /proc/sys/kernel/printk

Сейчас должно быть понятно, почему пример hello.c имел маркеры KERN_ALERT; они применялись для уверенности, что сообщение появится в консоли.

Перенаправление сообщений консоли

Linux обеспечивает определённую гибкость в политиках консольного логирования, позволяя отправлять сообщения на заданную виртуальную консоль (если ваша консоль живёт на текстовом экране). По умолчанию, "консолью" является текущий виртуальный терминал. Чтобы выбрать для приёма сообщений другой виртуальный терминал, вы можете на любом консольном устройстве вызвать ioctl(TIOCLINUX). Следующая программа, setconsole, может быть использована для выбора консоли, получающей сообщения ядра; она должна быть запущена суперпользователем и находиться в каталоге misc-progs.

Ниже приводится программа в полном объёме. Вы должны вызывать её с одним аргументом, указывающим номер консоли, которая будет получать сообщения.

int main(int argc, char **argv)

{

    char bytes[2] = {11,0}; /* 11 - номер команды TIOCLINUX */

    if (argc==2) bytes[1] = atoi(argv[1]); /* выбранная консоль */

    else {

        fprintf(stderr, "%s: need a single arg\n",argv[0]); exit(1);

    }

    if (ioctl(STDIN_FILENO, TIOCLINUX, bytes)<0) { /* использовать stdin */

        fprintf(stderr,"%s: ioctl(stdin, TIOCLINUX): %s\n",

        argv[0], strerror(errno));

        exit(1);

    }

    exit(0);

}

setconsole использует специальную команду ioctl TIOCLINUX, которая реализует особые функции Linux. Для использования TIOCLINUX вы передаёте аргумент, который является указателем на массив байтов. Первый байт массива является числом, которое определяет запрошенную подкоманду, а следующий байт зависит от подкоманды. В setconsole используется подкоманда 11, а следующий байт (хранимый в bytes[1]) идентифицирует виртуальную консоль. Полное описание TIOCLINUX может быть найдено в исходных текстах ядра в drivers/char/tty_io.c.

Как получить сообщения из лога

Функция printk записывает сообщения в круговой буфер размером __LOG_BUF_LEN байт: значение от 4 Кб до 1 Мб выбирается при конфигурации ядра. Эта функция затем будит любой процесс, который ожидает сообщений, то есть любой процесс, который является заснувшим при вызове системного вызова syslog или при чтении /proc/kmsg. Эти два интерфейса движка логирования почти эквивалентны, но учтите, что чтение /proc/kmsg забирает данные из буфера журнала, а системный вызов syslog может произвольно возвращать данные протокола, оставляя их для других процессов. В общем, чтение файла /proc проще и является поведением по умолчанию для klogd. Чтобы взглянуть на содержание буфера без сброса его на диск, может быть использована команда dmesg; на деле команда возвращает в stdout всё содержимое буфера, независимо от того, читался ли он до этого.

Если вам случится читать сообщения ядра вручную, после остановки klogd, вы увидите, что файл /proc выглядит как FIFO, в котором читатель блокируется, ожидая данных. Очевидно, что нельзя прочитать сообщения таким образом, если klogd или другой процесс уже читает эти же данные, так как вы будете соперничать.

Если круговой буфер заполнится, printk вернётся в начало и начнёт добавлять новые данные с начала буфера, перезаписывая старые данные. Таким образом, процесс протоколирования теряет старые данные. Эта проблема незначительна по сравнению с преимуществами использования кругового буфера. Например, циклический буфер позволяет системе работать даже без процесса протоколирования, минимизируя потерю памяти и перезаписывая старые данные, которые никто не прочитает. Ещё одна особенность подхода Linux для обмена сообщениями, это то, что printk может быть вызвана из любого места, даже из обработчика прерываний, без ограничения на размер распечатываемых данных. Единственным недостатком является возможность потери некоторых данных.

Если процесс klogd запущен, он получает сообщения ядра и передаёт их syslogd, который, в свою очередь, проверяет /etc/syslog.conf, чтобы выяснить, как с ними поступать. syslogd делает различия между сообщениями в соответствии с видом приложения и приоритетом; допустимые значения видов и приоритетов определены в заголовочном файле <sys/syslog.h>. Сообщения ядра протоколируются со значением типа LOG_KERN и соответствующим ему приоритетом, используемым в printk (например, LOG_ERR используется для сообщений KERN_ERR). Если klogd не работает, данные остаются в круговом буфере, пока кто-то не прочитает их или буфер не переполнится. Если вы хотите избежать затирания системного лога мониторинговыми сообщениями от вашего драйвера, вы можете либо указать опцию -f (файл) для klogd, чтобы поручить ему сохранять сообщения в заданный файл, или изменить /etc/syslog.conf в соответствии с вашими требованиями. Ещё одна возможность использовать метод решения "в лоб": убить klogd и многословно печатать сообщения на неиспользуемых виртуальных терминалах (* Например, используйте setlevel 8; setconsole 10, чтобы установить терминал 10 для отображения сообщений.) или дать команду cat /proc/kmsg из неиспользуемого xterm.

Включение и выключение сообщений

На ранних этапах разработки драйвера printk может оказать существенную помощь при отладке и тестировании нового кода. С другой стороны, когда вы официально опубликуете драйвер, вы должны удалить или, по крайней мере, отключить такую печать. К сожалению, вы, вероятно, обнаружите, что как только вы подумаете, что сообщения вам больше не нужны и удалите их, вы добавите новую функцию в драйвер (или кто-то найдёт ошибку) и вы захотите вернуть обратно по крайней мере одно сообщение. Есть несколько путей решения обоих вопросов: глобально разрешать или запрещать отладочные сообщения, и включать или выключать отдельные сообщения.

Здесь мы покажем один из способов кодирования вызовов printk так, что вы сможете включать и выключать их индивидуально или глобально; техника зависит от определения макроса, который разрешает вызов printk (или printf), когда вы хотите, чтобы:

•Каждый оператор печати мог быть включен или отключен удалением или добавлением одной буквы к имени макроса.

•Все сообщения могли быть отключены сразу изменением значения переменной CFLAGS перед компиляцией.

•Такое же управление печатью могло бы быть использовано и в коде ядра и в коде пользовательского уровня, так что драйвер и тестовые программы могли бы управляться одним способом относительно дополнительных сообщений.

Эти возможности реализует следующий фрагмент кода, взятый прямо из заголовка scull.h:

#undef PDEBUG /* уберём определение на всякий случай */

#ifdef SCULL_DEBUG

# ifdef __KERNEL__

    /* используется, если включена отладка и пространство ядра */

# define PDEBUG(fmt, args...) printk( KERN_DEBUG "scull: " fmt, ## args)

# else

    /* используется для пользовательского пространства */

# define PDEBUG(fmt, args...) fprintf(stderr, fmt, ## args)

# endif

#else

# define PDEBUG(fmt, args...) /* не отлаживаемся: ничего */

#endif

#undef PDEBUGG

#define PDEBUGG(fmt, args...) /* ничего: это пустышка */

Символ PDEBUG определяется или не определяется, в зависимости от того, определён ли SCULL_DEBUG, и отображает информацию в форме, подходящей для той среды, где выполняется код: он использует вызов ядра printk в пространстве ядра и вызов fprintf библиотеки libc для стандартных ошибок при работе в пространстве пользователя. Символ PDEBUGG, наоборот, ничего не делает; он может быть использован, чтобы просто "закомментировать" строчки с печатью, не удаляя их полностью.

Чтобы упростить процесс ещё больше, добавьте в ваш Makefile следующие строчки:

# Закомментируйте/раскомментируйте следующие строки, чтобы запретить/разрешить отладку

DEBUG = y

# Добавить ваш флаг отладки (или нет) к CFLAGS

ifeq ($(DEBUG),y)

 DEBFLAGS = -O -g -DSCULL_DEBUG # опция "-O" необходима для раскрытия встраиваемых определений

else

 DEBFLAGS = -O2

endif

CFLAGS += $(DEBFLAGS)

Показанные в данном разделе макросы зависят от расширения ANSI Си препроцессора в gcc, который поддерживает макросы с переменным числом аргументов. Эта зависимость gcc не должна быть проблемой, потому что ядро в любом случае сильно зависит от особенностей gcc. Кроме того, Makefile зависит от версии утилиты GNU make; раз ядро уже зависит от GNU make, эта зависимость не является проблемой.

Если вы знакомы с препроцессором Си, вы можете расширить данные определения для реализации концепции "уровень отладки", определяя различные уровни и задавая целые значения (или битовые маски) для каждого уровня, чтобы задать, насколько подробными они должны быть. Но каждый драйвер имеет свои особенности и потребности мониторинга. Искусство хорошего программирования проявляется в выборе лучшего компромисса между гибкостью и эффективностью, и мы не можем сказать, что лучше для вас. Помните, что условия препроцессора (также как и постоянные выражения в коде) выполняются во время компиляции, и требуется перекомпиляция для включения или выключения сообщений. Возможной альтернативой является использование условий языка Си, которые будут выполнены во время выполнения программы и, следовательно, позволят вам включат и выключать сообщения во время исполнения программы. Это хорошая возможность, но она требует дополнительной обработки каждый раз при выполнении кода, который может повлиять на производительность, даже если сообщения будут отключены. Иногда такая производительность является неприемлемой.

Макросы, показанные в этом разделе, зарекомендовали себя полезным во многих ситуациях, с единственным недостатком, требующим перекомпиляцию модулей после любого изменения их сообщений.

Ограничение скорости

Если вы не будете осторожны, то можете получить сгенерированные вами тысяч сообщений printk, переполняющие консоль и, возможно, переполненный файл системного лога. При использовании медленного консольного устройства (например, последовательного порта), чрезмерный поток сообщений также может замедлить работу системы или просто сделать её не отвечающей. Может быть очень трудно получить управление, когда с системой что-то не так, когда консоль безостановочно извергает данные. Поэтому вы должны быть очень осторожны с тем, что вы печатаете, особенно в выпущенных версиях драйверов и особенно после завершения инициализации. Обычно, выпущенный код никогда не должен ничего печатать во время нормальной эксплуатации; печатный вывод должен быть индикацией исключительной ситуации, требующей внимания.

С другой стороны, вы можете захотеть выдать сообщение, если устройство, которым вы управляете, перестаёт работать. Но вы должны быть осторожны, чтобы не переусердствовать в этом. Неумный процесс, который продолжается вечно при встрече с проблемами, может генерировать тысяч попыток в секунду; если ваш драйвер печатает сообщение "моё устройство повреждено" каждый раз, он может создать огромное количество вывода и, возможно, подвесить процессор, если консольное устройство медленное - нет прерываний, которые могут быть использованы для управления консолью, даже если это последовательный порт или строчный принтер.

Во многих случаях лучшим поведением является установка флага говорящего: "я уже жаловался на это", а не печать любых дальнейших сообщений после установки флага. Хотя, с другой стороны, есть резон и в посылке периодического сообщения "устройство по-прежнему сломано". Ядро предлагает функцию, которая может быть полезна в таких случаях:

int printk_ratelimit(void);

Эта функция должна быть вызвана перед печатью сообщения, если вы считаете, что оно может повторяться часто. Если функция возвращает ненулевое значение, идите дальше и печатайте сообщение, в противном случае пропустите его. Таким образом, типичные вызовы выглядят следующим образом:

if (printk_ratelimit( ))

    printk(KERN_NOTICE "The printer is still on fire\n");

printk_ratelimit работает, отслеживая как много сообщений отправляются на консоль. Когда уровень вывода превышает порог, printk_ratelimit начинает возвращать 0 и вызывает пропуск сообщений.

Поведение printk_ratelimit можно настроить, изменяя /proc/sys/kernel/printk_ratelimit (количество секунд ожидания до повторного включения сообщений) и /proc/sys/kernel/printk_ratelimit_burst (количество сообщений, принимаемых до начала ограничения).

Печать номеров устройств

Иногда при печати сообщение от драйвера необходимо будет напечатать номер устройства, связанный с интересующим оборудованием. Не очень трудно печатать старшие и младшие номера, но в интересах обеспечения совместимости ядро предоставляет для этой цели несколько полезных макросов (определённых в <linux/kdev_t.h>):

int print_dev_t(char *buffer, dev_t dev);

char *format_dev_t(char *buffer, dev_t dev);

Оба макроса кодируют номер устройства в данный буфер; отличие лишь в том, что print_dev_t возвращает количество напечатанных символов, а format_dev_t возвращает буфер, поэтому он может быть использован в качестве параметра при вызове printk напрямую, хотя надо помнить, что printk не сбросит данные на диск, пока не получит символ перевода строки. Буфер должен быть достаточно большим, чтобы содержать номер устройства; учитывая, что 64-х разрядные номера устройств являются определённо возможными в будущих версиях ядра, следует иметь буфер длиной, по крайней мере, 20 байт.