Логирование и профилирование в микроконтроллерах

[zHz00]

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

Хотя программа и крутится на микроконтроллере, вспомогательные задачи, которые надо решать, остаются теми же, что для программ большого компьютера. Две из таких задач -- логирование и профилирование.

(читать дальше)

Логирование -- запись куда-либо событий, происходящих в программе. Во многом логирование и отладочная печать -- это одно и то же. После (или во время) выполнения программы лог можно изучить. Это помогает отладке.
Профилирование (кода) -- выяснение, какой участок программы сколько времени выполняется.

Для решения первой задачи на компьютере существует такая вещь, как файловая система. Мы можем в любой момент открыть файл, чиркануть туда пару строк и закрыть.
Для решения второй задачи есть целые системы (названий которых я, правда, не знаю, однако знаю, что в последних версиях вижуал студии профилировщик входит в комплект поставки).

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

На микроконтроллере наши ресурсы крайне ограничены. Можно выдавать лог через какой-нибудь UART, но их мало, а передача данных будет медленной. Контроллер медленный сам по себе, поэтому потеря времени на логирование и, тем более, на профилирование -- это плохо.

Поэтому лог надо вести в оперативной памяти. Естественно, чем меньше памяти, тем беднее будут возможности по логированию. Итак, вам понадобится:
-- свободная память, чем больше, тем лучше. Для комфортной работы нужно 20-40 KiB. Но у некоторых контроллеров ВСЕГО 40 KiB.
-- таймер, который будет заведовать метками времени.

Об'являем глобальный массив:

#define LOG_SIZE 10000//в каком-нибудь хэдере
volatile int log[LOG_SIZE];
volatile int log_idx=0;

volatile нужно, чтобы не было эксцессов с кэшированием памяти, оптимизацией компилятора и пр. Это слово означает, что чтение и запись в указанные области памяти каждый раз надо производить "начисто", даже если кажется, что можно как-то срезать путь.

Таймер настраиваем так, чтобы он выдавал по одному тику каждую миллисекунду. Это достаточно удобно для наблюдения.

В каждом модуле, где будет осуществляться запись в лог, надо написать:

extern volatile int log[LOG_SIZE];
extern volatile int log_idx=0;

(очевидно, что LOG_SIZE виден не будет; надо включить хэдер, где он определён)

А для записи событий использовать следующую функцию, к примеру:

void log(int type)
{
	log[log_idx]=type*100000+get_timer();//get_timer() выдаёт время в миллисекундах
	log_idx++;
	if(log_idx>=LOG_SIZE)
		log_idx=0;
}

Теперь у нас в старших разрядах будет тип события, а в младших -- метка времени (например, 77001427 -- код события 77, 1427 миллисекунд от последнего переполнения таймера). Данный пример рассчитан на таймер, который будет переполняться не реже, чем раз в сто секунд. В противном случае младшие разряды начнут "наползать" на старшие, где тип события. Если вам нужно больше, то вместо 100000 можно поставить что-нибудь более крутое, например, 1000000.

Очевидно, что всё это действует при отображении данных в десятичной системе. Если у вас вывод только в шестнадцатеричной, придётся немного переделать.

Как этим пользоваться, я думаю, очевидно. Но всё равно напишу:

1. Во всех местах, где происходит что-то интересное, вызываем функцию log(), в качестве аргумента указывая уникальный код места вызова (тип события). Коды придётся придумать самим.
2. Останавливаем процессор (желательно интерактивным отладчиком) и смотрим в память по адресу log. Там будет лог. При этом он будет относительно читабельным (если вы все типы событий запишете на бумажку).

Аналогичным образом можно гнать в этот лог значения переменных, причём без всяких кодов событий, если мы точно знаем, что и когда записываем. Например, так:

void log_data(int value)
{
	log[log_idx]=value;
	log_idx++;
	if(log_idx>=LOG_SIZE)
		log_idx=0;
}
//в месте вызова
//...
	int c=25,d=35;
	log(15);
	log_data(c);
	log_data(d);
//...

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

Это всё будет нормально работать, к сожалению, только на крутых 32-битных контроллерах. Что делать на 8 и 16-разрядных, не знаю. Может быть, писать коды событий и метки времени по очереди?

Comments

[CD_Eater]

Ээээ....
Если у МК есть 40 Кбайт ОЗУ, то у него точно есть всякие там жтаги и прочие интерфейсы для in-circuit emulation, как раз предназначенные для наблюдения жизни МК в реальном времени


так и вспоминается хохма: "Javasсript, небось, алертами дебажили?"

[zHz00]

CD_Eater, жтаги и свд есть, конечно. А вот про in-curcuit emultaion прошу рассказать поподробнее.

[zHz00]

Особенно интересно прочитать про работу в реальном времени со сбором данных, а не в пошаговом.

[roadischosen]

Лучше объявить массив и его индекс рядом с самими функциями логирования, а вот extern-объявления вынести в заголовочный файл, который будет включаться

"в каждом модуле, где будет осуществляться запись в лог"

.