Использование кольцевого буфера предоставляет определенные преимущества. Так как одновременные операции чтения и записи в кольцевом буфере выполняются достаточно просто, то функцию printk() можно использовать даже из контекста прерывания. Более того, это позволяет просто организовать управление системными сообщениями. Если сообщений оказывается очень много, то новые сообщения просто затирают старые. Если возникает проблема, которая проявляется в генерации большого количества сообщений, то буфер сообщений просто начинает переписывать себя вместо того, чтобы бесконтрольно занимать память. Единственный недостаток кольцевого буфера — возможность потерять сообщения, что не такая уж и большая плата за ту устойчивость, которую такое решение предоставляет.
Демоны syslogd и klogd
В стандартной системе Linux для извлечения сообщений ядра из буфера используется специальный демон пространства пользователя klogd, который направляет эти сообщения в файл журнала системных сообщений. Для чтения системных сообщений программа klogd может считывать данные из файла /proc/kmsg, или использовать системный вызов syslog(). По умолчанию используется подход на основе файловой системы /proc. Если сообщений нет, то демон klogd блокируется на операции чтения, пока не поступит новое сообщение. Когда приходит новое сообщение, демон возвращается к выполнению, считывает сообщения и обрабатывает их. По умолчанию сообщения отправляются демону syslogd.
Демон syslogd добавляет полученные сообщения в конец файла журнала, по умолчанию — /var/log/messages. Имя соответствующего файла можно настроить в конфигурационном файле /etc/syslog.conf.
Изменить уровень вывода сообщений на консоль (console loglevel) можно при старте демона klogd с помощью флага -с.
Замечание относительно функции printk() и разработки ядра
Когда впервые начинают разрабатывать код ядра, то скорее всего очень часто приходится заменять функцию printf() на функцию printk(). Это нормально, потому что нельзя не принимать во внимание многолетний опыт по написанию пользовательских программ и использовании функции printf(). Следует надеяться, что повторение таких ошибок не будет продолжаться долго, потому что повторяющиеся ошибки компоновщика начнут быстро надоедать.
Однажды вдруг окажется, что вы поймали себя на том, что начали использовать функцию printk() вместо функции printf() в пользовательских программах. Когда для вас этот день наконец наступит, то можно сказать, что вы стали настоящим хакером и специалистом по разработке кода ядра.
Сообщения Oops
Сообщения oops — обычный для ядра способ сообщить пользователю, что произошло что-то нехорошее. Так как ядро управляет всей системой, то оно не может само себя исправить, или завершить, как это возможно для программ пространства пользователя, когда они делают что-то не так. Вместо этого, ядро выводит сообщение oops. Такое сообщение включает вывод информации об ошибке на консоль, вывод дампа содержимого всех регистров и вывод обратной трассировки вызовов функций (back trace). Сбои в работе ядра трудно обработать, поэтому ядро должно "пролезть'' через многие дыры, чтобы вывести сообщение oops и выполнить за собой все необходимые действия по очистке. Часто после выдачи сообщения oops ядро находится в несогласованном состоянии. Например, в момент возникновения ситуации, в которой выдается сообщение oops, ядро может находится в процессе обработки важных данных. В этот момент может удерживаться блокировка, или выполняться сеанс взаимодействия с оборудованием. Ядро должно аккуратно отойти от текущего состояния и попытаться восстановить контроль над системой. Во многих случаях это невозможно. Если ситуация, в которой выдается сообщение oops, возникает в контексте прерывания, то ядро не может продолжать работу и переходит в состояние паники. Состояние паники проявляется в полной остановке системы. Если oops возникает в холостой задаче (idle task, идентификатор pid равен нулю), или при выполнении процесса init (идентификатор pid равен единице), то ядро также переходит в состояние паники, потому что ядро не может продолжать выполнение без этих важных процессов. Однако, если oops возникает при выполнении любого другого процесса, то ядро завершает этот процесс и продолжает работу.
Сообщение oops может выдаваться по многим причинам, включая недопустимый доступ к памяти (memory access violation) и выполнение недопустимой машинной команды. Как разработчику ядра, вам придется иметь дело с сообщениями oops и далее, несомненно, быть причиной их появления.
Ниже показано сообщение oops для машины аппаратной платформы PPC, которое возникло и обработчике таймера для сетевого интерфейсного адаптера tulip.
Oops: Exception in kernel mode, sig: 4
Unable to handle kernel NULL pointer dereference at virtual address 00000001
NIP: C013A7F0 LR: C013A7F0 SP:C0685E00 REGS: c0905d10 TRAP: 0700
Not tainted
MSR: 00089037 EE: 1 PR: 0 FP: 0 ME: 1 IR/DR: 11
TASK=c0712530[0] swapper Last syscalclass="underline" 120
GPR00: C013A7C0 C0295E00 C0231530 0000002F 00000001 C0380CB8 C0291B80 C02D0000
GPR08: 000012AD 00000000 00000000 C0292AA0 4020A088 00000000 00000000 00000000
GPR16: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
GPR24: 00000000 00000005 00000000 00001032 C3F7C000 00000032 FFFFFFFF C3F7C1C0
Call trace:
[c013ab30] tulip_timer+0x128/0x1c4
[c0020744] run_timer_softirq+0x10c/0x164
[c001b864] do_softirq+0x88/0x104
[c0007e80] timer_interrupt+0x284/0x298
[c00033c4] ret_from_except+0x0/0x34
[c0007b84] default_idle+0x20/0x60
[c0007bf8] cpu_idle+0x34/0x38
[c0003ae8] rest_init+0x24/0x34
У пользователей ПК может вызвать удивление количество регистров процессора (32 — огромное число!). Сообщение oops для аппаратной платформы x86, которые возможно вам более знакомы, имеют несколько более простой вид. Тем не менее, важная информация идентична для всех аппаратных платформ: содержимое всех регистров и обратная трассировка.
Обратная трассировка показывает точную последовательность вызовов функций, которая привела к проблеме. В данном случае можно точно определить, что случилось: машина выполняла холостое задание — холостой цикл: вызов функции cpu_idle(), из которой циклически вызывается функция default_idle(). Поступило прерывание от системного таймера, в котором вызываются обработчики таймеров ядра. Среди них вызывается обработчик таймера — функция tulip_timer(), в которой выполнено разыменование указателя со значением NULL. Можно даже воспользоваться значением смещения (числа вроде 0х128/0х1с4, которые указаны справа от имени функции) для точного нахождения команды, в которой возникла ошибка.
Содержимое регистров точно также полезно, хотя и используется не так часто. Вместе с дизассемблированным кодом функции содержимое регистров может помочь восстановить точную последовательность событий, которая привела к проблеме. Если значение в некотором регистре не соответствует ожидаемому, то это может пролить некоторый свет на корень проблемы. В данном случае можно проверить, какие регистры содержат значение NULL (все разряды нулевые) и определить, какая из переменных функции содержит не то значение. В ситуациях, похожих на данную, скорее всего причина — конкуренция за ресурс (race) и скорее всего между таймером и другой частью сетевого адаптера. Отладка состояний конкуренции за ресурсы — всегда серьезная задача.