Опубликован: 06.12.2004 | Доступ: свободный | Студентов: 1180 / 143 | Оценка: 4.76 / 4.29 | Длительность: 20:58:00
ISBN: 978-5-9556-0021-5
Тема: Программирование
Специальности: Программист, Архитектор программного обеспечения
Теги:
Лекция 8:
Трассировка пользовательских приложений
Функции для работы с событиями
От рассмотрения средств, доступных трассирующему процессу, мы переходим к функциям, используемым для оборудования трассируемых пользовательских приложений. Таких функций две: posix_trace_event() и posix_trace_eventid_open() (см. листинг 8.19).
#include <sys/types.h>
#include <trace.h>
void posix_trace_event (
trace_event_id_t event_id,
const void *restrict data_ptr,
size_t data_len);
int posix_trace_eventid_open (
const char *restrict event_name,
trace_event_id_t *restrict event_id);
Листинг
8.19.
Описание функций для оборудования трассируемых пользовательских приложений.
Вызов функции posix_trace_event() создает точку трассировки, при попадании в которую генерируется пользовательское событие с идентификатором типа event_id и ассоциированными данными, специфицированными аргументами data_ptr (адрес буфера) и data_len (размер буфера). Если трассировка идет и события заданного типа не задерживаются фильтром, соответствующая информация будет записана в потоки, созданные ранее для трассировки вызывающего процесса. В противном случае вызов posix_trace_event() игнорируется.
Функция posix_trace_eventid_open(), ассоциирующая имя события с идентификатором типа, по сути аналогична posix_trace_trid_eventid_open(), только поток задается неявно (как поток, куда идет трассировка вызывающего процесса). Очевидно, подобная функция необходима для формирования аргумента event_id перед вызовами posix_trace_event().
Что касается анализирующего процесса, то обычно он в первую очередь открывает ранее записанный журнал трассировки, обращаясь к функции posix_trace_open(), а, обработав, закрывает его с помощью функции posix_trace_close(), быть может, в промежутке позиционируясь на начало журнала посредством функции posix_trace_rewind() (см. листинг 8.20).
#include <trace.h>
int posix_trace_open (
int fildes, trace_id_t *trid);
int posix_trace_close (trace_id_t trid);
int posix_trace_rewind (trace_id_t trid);
Листинг
8.20.
Описание функций для работы с журналами трассировки.
Функция posix_trace_open(), отправляясь от файлового дескриптора журнала трассировки fildes, открытого на чтение, создает поток трассировки и записывает его идентификатор по указателю trid. С помощью этого идентификатора анализирующий процесс может опрашивать атрибуты и статус потока и, главное, читать из него события, вызывая функцию posix_trace_getnext_event() (см. листинг 8.21).
#include <sys/types.h>
#include *lt;trace.h>
int posix_trace_getnext_event (
trace_id_t trid,
struct posix_trace_event_info
*restrict event,
void *restrict data_ptr,
size_t num_bytes,
size_t *restrict data_len,
int *restrict unavailable);
int posix_trace_timedgetnext_event (
trace_id_t trid,
struct posix_trace_event_info
*restrict event,
void *restrict data_ptr,
size_t num_bytes,
size_t *restrict data_len,
int *restrict unavailable,
const struct timespec *restrict abstime);
int posix_trace_trygetnext_event (
trace_id_t trid,
struct posix_trace_event_info
*restrict event,
void *restrict data_ptr,
size_t num_bytes,
size_t *restrict data_len,
int *restrict unavailable);
Листинг
8.21.
Описание функций чтения событий трассировки.
Функция posix_trace_getnext_event() выдает очередное событие из потока трассировки, который может быть как предварительно записанным в журнале, так и активным (в последнем случае анализирующий процесс должен совпадать с трассирующим). События выдаются в порядке их генерации, то есть от самого старого к самому новому.
Информация о событии помещается в структуру типа posix_trace_event_info, на которую указывает аргумент event. Данные, ассоциированные с событием, записываются в буфер с адресом data_ptr и длиной num_bytes ; по указателю data_len размещается число записанных в буфер байт данных. Наконец, в случае успешного чтения по указателю unavailable помещается нулевое значение.
Если аргумент trid идентифицирует активный поток трассировки, вызов posix_trace_getnext_event() блокируется при отсутствии непрочитанных событий.
Функции posix_trace_timedgetnext_event() и posix_trace_trygetnext_event() применимы только к активным потокам трассировки. При отсутствии непрочитанных событий первая блокируется, но с контролем длительности ожидания (до наступления заданного абсолютного момента времени), а вторая немедленно завершится, записав по указателю unavailable ненулевое значение.
В качестве иллюстрации применения описанных выше средств рассмотрим трассировку обеда философов (см. листинг 8.22). Мы не будем приводить весь исходный текст, а перечислим лишь изменения в трассируемой части программы и полностью приведем новую функцию main(), в которой сосредоточены управление трассировкой и анализ сгенерированных событий.
/* * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * */
/* Многопотоковый вариант обеда философов с использованием */
/* сигналов реального времени и таймера для контроля */
/* длительности обеда как пример применения средств трассировки */
/* * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * */
. . .
#include <trace.h>
. . .
/* Идентификаторы генерируемых пользовательских событий */
static trace_event_id_t pev1; /* Заявка на захват вилок */
static trace_event_id_t pev2; /* Захват вилок */
static trace_event_id_t pev3; /* Освобождение вилок */
. . .
/* * * * * * * * * * * * * * * * * * * * * * */
/* Попытка выполнить заявку на захват вилок */
/* от философа номер no, если она есть */
/* * * * * * * * * * * * * * * * * * * * * * */
static void fork_lock (int no) {
. . .
phil_req [no – 1] = 0;
/* Сгенерируем событие – захват вилок */
posix_trace_event (pev2, &no, sizeof (no));
. . .
}
/* * * * * * * * * * * * * * * * * * * * * * * * * * * * * * */
/* Стартовая функция потока, обслуживающего заявки на захват */
/* и освобождение вилок. Заявка передается в виде значения, */
/* ассоциированного с сигналом signo. Значение no > 0 */
/* запрашивает захват вилок для философа с номером no, */
/* no < 0 – освобождение философа -no */
/* * * * * * * * * * * * * * * * * * * * * * * * * * * * * * */
void *start_waiter (void *signo) {
int no; /* Номер философа, приславшего заявку */
. . .
/* Заявка на захват вилок. */
/* Запомним ее ... */
phil_req [no – 1] = 1;
/* Сгенерируем событие – заявка на захват вилок ... */
posix_trace_event (pev1, &no, sizeof (no));
/* ... и попробуем выполнить заявку */
fork_lock (no);
} else {
/* Освобождение вилок */
no = -no;
fork_busy [no – 1] = fork_busy [no % QPH] = 0;
/* Сгенерируем событие – освобождение вилок */
posix_trace_event (pev3, &no, sizeof (no));
. . .
}
/* * * * * * * * * * * * * */
/* Организация обеда */
/* (бывшая функция main()) */
/* * * * * * * * * * * * * */
void *dinorg (void *dummy) {
. . .
return (NULL);
}
/* * * * * * * * * * * * * * * * */
/* Управление трассировкой, */
/* выборка и распечатка событий */
/* * * * * * * * * * * * * * * * */
int main (void) {
trace_id_t trid; /* Идентификатор потока трассировки */
trace_event_set_t fltr; /* Множество фильтруемых событий */
pthread_t pt_dinorg; /* Идентификатор потока управления, */
/* ведающего организацией обеда */
/* Информация о событии */
struct posix_trace_event_info evinf;
size_t datsz; /* Размер данных в событии */
/* Буфер для имени события */
char evnam [TRACE_EVENT_NAME_MAX];
int evdat [BUFSIZ]; /* Данные "вилочных" событий */
int res; /* Целочисленные результаты */
if ((errno = posix_trace_create (0, NULL, &trid)) != 0) {
perror ("POSIX_TRACE_CREATE");
return (errno);
}
/* Установим фильтр на все системные события ... */
(void) posix_trace_eventset_fill (&fltr,
POSIX_TRACE_SYSTEM_EVENTS);
/* ... и удалим из него события с сигналами */
(void) posix_trace_eventset_del (traceSigGeneration, &fltr);
(void) posix_trace_eventset_del (traceSigDelivery, &fltr);
(void) posix_trace_eventset_del (traceSigCatchFunc, &fltr);
if ((errno = posix_trace_set_filter (trid, &fltr,
POSIX_TRACE_SET_EVENTSET)) != 0) {
perror ("POSIX_TRACE_SET_FILTER");
return (errno);
}
/* Зарегистрируем три типа пользовательских событий */
if (((errno = posix_trace_eventid_open (
"Заявка на вилки философа", &pev1)) != 0) ||
((errno = posix_trace_eventid_open (
"Захват вилок философа", &pev2)) != 0) ||
((errno = posix_trace_eventid_open (
"Освобождение вилок философа", &pev3)) != 0)) {
perror ("POSIX_TRACE_TRID_EVENTID_OPEN");
return (errno);
}
/* Активизируем трассировку */
if ((errno = posix_trace_start (trid)) != 0) {
perror ("POSIX_TRACE_START");
return (errno);
}
/* Организуем обед */
if ((errno = pthread_create (&pt_dinorg, NULL, dinorg,
NULL)) != 0) {
perror ("PTHREAD_CREATE-dinorg");
return (errno);
}
/* Дождемся завершения обеда */
(void) pthread_join (pt_dinorg, NULL);
/* Остановим трассировку */
if ((errno = posix_trace_stop (trid)) != 0) {
perror ("POSIX_TRACE_STOP");
return (errno);
}
/* Прочитаем и распечатаем сгенерированные события */
printf ("Помещенные в поток трассировки события "
"с вилками:\n");
while (posix_trace_getnext_event (trid, &evinf, &evdat,
sizeof (evdat), &datsz, &res), res == 0) {
if (evinf.posix_event_id == traceSigGeneration) {
printf ("Потоком %p порожден сигнал с номером %d "
"и значением %d " "для потока %p\n",
(void *) evdat [0], evdat [2], evdat [3],
(void *) evdat [5]);
else if (evinf.posix_event_id == traceSigDelivery) {
printf ("Потоку %p доставлен сигнал с номером %d "
"и значением %d\n", (void *) evdat [0],
evdat [1], evdat [2]);
} else if (evinf.posix_event_id == traceSigCatchFunc) {
printf ("В контексте потока %p вызван обработчик "
"сигнала с номером %d " "и значением %d\n",
(void *) evdat [0], evdat [1], evdat [2]);
} else if (posix_trace_eventid_get_name (trid,
evinf.posix_event_id, evnam) == 0) {
printf (" %s %d\n", evnam, evdat [0]);
}
}
return 0;
}
Листинг
8.22.
Фрагмент исходного текста программы обеда философов с трассировкой.
Отметим, что в качестве данных, ассоциированных с пользовательскими событиями, выступают целые числа – номера философов (по одному на событие, см. вызовы posix_trace_event() ).
Отметим также стиль формирования фильтра системных событий. Сначала в фильтрующее множество включаются все системные события (вызов posix_trace_eventset_fill(), а затем из него удаляются типы событий, представляющих интерес (вызовы posix_trace_eventset_del() ).
Если интересоваться системными событиями, то исходный текст управляющей и анализирующей частей неизбежно получается зависящим от целевой платформы. Приведенный вариант программы ориентирован на операционную систему реального времени oc2000. В этой связи обратим внимание на идентификаторы типов системных событий ( traceSigGeneration, traceSigDelivery, traceSigCatchFunc ) и на структуру ассоциированных с событиями данных ( evdat [0], evdat [2], evdat [5] и т.п.), вообще говоря, свою для каждого типа.
Фрагмент возможных результатов трассировки обеда двух философов показан на листинге 8.23.
Помещенные в поток трассировки события с вилками:
Потоком 0xf10b34 порожден сигнал с номером 24 и значением 1 для потока 0xf14d54
Потоку 0xf14d54 доставлен сигнал с номером 24 и значением 1
Заявка на вилки философа 1
Захват вилок философа 1
Потоком 0xf14d54 порожден сигнал с номером 2 и значением 0 для потока 0xf10b34
Потоку 0xf10b34 доставлен сигнал с номером 2 и значением 0
В контексте потока 0xf10b34 вызван обработчик сигнала с номером 2 и значением 0
Потоком 0xf0c914 порожден сигнал с номером 24 и значением 2 для потока 0xf14d54
Потоку 0xf14d54 доставлен сигнал с номером 24 и значением 2
Потоком 0xf10b34 порожден сигнал с номером 24 и значением -1 для потока 0xf14d54
Потоку 0xf14d54 доставлен сигнал с номером 24 и значением -1
Заявка на вилки философа 2
Освобождение вилок философа 1
. . .
Листинг
8.23.
Фрагмент возможных результатов трассировки обеда двух философов на операционной платформе oc2000.
Трассировка – по-настоящему полезный инструмент в ситуациях, когда многопотоковая программа по непонятным причинам ведет себя не так, как хотелось бы. Рассмотрим пример, предложенный автору Н.В. Шмыревым (см. листинг 8.24). Пусть имеется критический интервал, вход в который охраняется мьютексом. Один поток управления пытается захватывать этот мьютекс с ожиданием, другой – без ожидания, с паузами между попытками (должен же мьютекс когда-нибудь освободиться?). Выясняется, что второму потоку не удается войти в критический интервал. Почему?
Чтобы получить ответ на этот вопрос, уместно воспользоваться трассировкой системных событий, связанных с мьютексами.
/* * * * * * * * * * * * * * * * * * * * * * * * * * * * * */
/* Трассировка системных событий, связанных с мьютексами. */
/* Демонстрируется, что один поток управления */
/* не дает второму захватить мьютекс */
/* * * * * * * * * * * * * * * * * * * * * * * * * * * * * */
#include <stdio.h>
#include <pthread.h>
#include <time.h>
#include <trace.h>
#include <errno.h>
enum {
TimeFirstThreadCritical,
TimeFirstThreadNonCritical,
TimeSecondThreadInit,
TimeSecondThreadWait,
TimeSecondThreadCritical,
TimeSecondThreadNonCritical,
TimeTest,
TIME_SIZE
};
/* Массив задержек всех видов */
static struct timespec my_times [TIME_SIZE];
/* Мьютекс, охраняющий вход в критический интервал */
static pthread_mutex_t my_mutex = PTHREAD_MUTEX_INITIALIZER;
/* * * * * * * * * * * * * * * */
/* Заполнение массива задержек */
/* * * * * * * * * * * * * * * */
void init_times (void) {
struct timespec resolution;
int i;
for (i = 0; i < TIME_SIZE; i++) {
my_times [i].tv_sec = 0;
my_times [i].tv_nsec = 0;
}
if (clock_getres (CLOCK_REALTIME, &resolution) != 0) {
perror ("CLOCK_GETRES");
resolution.tv_nsec = 20000000;
}
my_times [TimeFirstThreadCritical].tv_nsec = resolution.tv_nsec * 3;
my_times [TimeFirstThreadNonCritical].tv_nsec = resolution.tv_nsec * 7;
my_times [TimeSecondThreadInit].tv_nsec = resolution.tv_nsec * 2;
my_times [TimeSecondThreadWait].tv_nsec = resolution.tv_nsec * 10;
my_times [TimeSecondThreadCritical].tv_nsec = resolution.tv_nsec * 4;
my_times [TimeSecondThreadNonCritical].tv_nsec = resolution.tv_nsec * 8;
my_times [TimeTest].tv_sec = 3;
}
/* * * * * * * * * * * * * * * * * */
/* Поток, монополизирующий мьютекс */
/* * * * * * * * * * * * * * * * * */
void *tf1 (void *dummy) {
while (1) {
if ((errno = pthread_mutex_lock (&my_mutex)) != 0) {
perror ("PTHREAD_MUTEX_LOCK");
return ((void *) errno);
}
/* Критический интервал */
if (nanosleep (&my_times [TimeFirstThreadCritical],
NULL) != 0) {
perror ("NANOSLEEP-1-1");
return ((void *) errno);
}
if ((errno = pthread_mutex_unlock (&my_mutex)) != 0) {
perror ("PTHREAD_MUTEX_UNLOCK");
return ((void *) errno);
}
/* Действия вне критического интервала */
if (nanosleep (&my_times [TimeFirstThreadNonCritical],
NULL) != 0) {
perror ("NANOSLEEP-1-2");
return ((void *) errno);
}
}
return (NULL);
}
/* * * * * * * * * * * * * * * * * * * * * * * * * */
/* Поток, безуспешно пытающийся захватить мьютекс */
/* * * * * * * * * * * * * * * * * * * * * * * * * */
void *tf2 (void *dummy) {
/* Подготовительные действия */
if (nanosleep (&my_times [TimeSecondThreadInit],
NULL) != 0) {
perror ("NANOSLEEP-2-1");
return ((void *) errno);
}
while (1) {
if (pthread_mutex_trylock (&my_mutex) != 0) {
/* Ожидание освобождения мьютекса */
if (nanosleep (&my_times [TimeSecondThreadWait],
NULL) != 0) {
perror ("NANOSLEEP-2-2");
return ((void *) errno);
}
} else {
/* Критический интервал */
if (nanosleep (&my_times [TimeSecondThreadCritical],
NULL) != 0) {
perror ("NANOSLEEP-2-3");
return ((void *) errno);
}
if ((errno = pthread_mutex_unlock (&my_mutex)) != 0) {
perror ("PTHREAD_MUTEX_UNLOCK");
return ((void *) errno);
}
/* Действия вне критического интервала */
if (nanosleep (&my_times
[TimeSecondThreadNonCritical], NULL) != 0) {
perror ("NANOSLEEP-2-4");
return ((void *) errno);
}
}
}
return (NULL);
}
/* * * * * * * * * * * * * * * * */
/* Создание потоков управления, */
/* управление трассировкой, */
/* выборка и распечатка событий */
/* * * * * * * * * * * * * * * * */
int main (void) {
pthread_t pt1, pt2; /* Идентификаторы потоков управления */
trace_id_t trid; /* Идентификатор потока трассировки */
trace_event_set_t fltr; /* Множество фильтруемых событий */
/* Информация о событии */
struct posix_trace_event_info evinf;
size_t datsz; /* Размер данных в событии */
void *evdat [BUFSIZ]; /* Данные событий */
int res; /* Целочисленные результаты */
if ((errno = posix_trace_create (0, NULL, &trid)) != 0) {
perror ("POSIX_TRACE_CREATE");
return (errno);
}
/* Установим фильтр на системные события, */
/* не связанные с захватом мьютексов */
(void) posix_trace_eventset_fill (&fltr,
POSIX_TRACE_SYSTEM_EVENTS);
(void) posix_trace_eventset_del (traceMutexLock, &fltr);
(void) posix_trace_eventset_del (traceMutexTryLock,
&fltr);
(void) posix_trace_eventset_del (traceMutexUnlock, &fltr);
if ((errno = posix_trace_set_filter (trid, &fltr,
POSIX_TRACE_SET_EVENTSET)) != 0) {
perror ("POSIX_TRACE_SET_FILTER");
return (errno);
}
/* Заполним массив задержек */
init_times ();
/* Активизируем трассировку */
if ((errno = posix_trace_start (trid)) != 0) {
perror ("POSIX_TRACE_START");
return (errno);
}
/* Создадим потоки управления, конкурирующие за мьютекс */
(void) pthread_create (&pt1, NULL, tf1, NULL);
(void) pthread_create (&pt2, NULL, tf2, NULL);
/* Дадим созданным потокам повыполняться */
(void) nanosleep (&my_times [TimeTest], NULL);
/* Терминируем потоки управления */
(void) pthread_cancel (pt2);
(void) pthread_cancel (pt1);
/* Дождемся завершения */
(void) pthread_join (pt1, NULL);
(void) pthread_join (pt2, NULL);
/* Остановим трассировку */
if ((errno = posix_trace_stop (trid)) != 0) {
perror ("POSIX_TRACE_STOP");
return (errno);
}
printf ("Помещенные в поток трассировки события "
"с мьютексом %p:\n", &mamp;y_mutex);
while (posix_trace_getnext_event (trid, &evinf, &evdat,
sizeof (evdat), &datsz, &res), res == 0) {
/* Нас интересуют только операции с мьютексом */
/* my_mutex */
if (evdat [3] != &my_mutex) {
continue;
}
if (evinf.posix_event_id == traceMutexLock) {
printf ("%ld сек. %ld нсек. Попытка захвата "
"мьютекса:\n" "код ошибки %d, поток %p, "
"владелец %p\n",
evinf.posix_timestamp.tv_sec,
evinf.posix_timestamp.tv_nsec,
(int) evdat [0], evinf.posix_thread_id,
evdat [4]);
} else if (evinf.posix_event_id == traceMutexTryLock) {
printf ("%ld сек. %ld нсек. Попытка захвата без "
"ожидания мьютекса:\n" "код ошибки %d, "
"поток %p, владелец %p\n",
evinf.posix_timestamp.tv_sec,
evinf.posix_timestamp.tv_nsec,
(int) evdat [0], evinf.posix_thread_id,
evdat [4]);
} else if (evinf.posix_event_id == traceMutexUnlock) {
printf ("%ld сек. %ld нсек. Освобождение "
"мьютекса:\n" "код ошибки %d, поток %p\n",
evinf.posix_timestamp.tv_sec,
evinf.posix_timestamp.tv_nsec,
(int) evdat [0], evinf.posix_thread_id);
}
}
return 0;
}
Листинг
8.24.
Программа, демонстрирующая трассировку системных событий, связанных с мьютексами, на операционной платформе oc2000.
Результаты трассировки сводятся к многократному повторению фрагмента, показанного на листинге 8.25. Второй поток управления не может попасть в критический интервал, потому что мьютекс оказывается захваченным первым потоком. Разумеется, величины задержек в приведенном примере подобраны так, чтобы длительность пауз между попытками входа в критический интервал второго потока управления была кратна периоду выполнения первого потока (что вполне может иметь место и в реальном приложении реального времени). Абстрактная надежда на то, что "все проходит" и мьютекс должен когда-нибудь освободиться, надо только набраться терпения и подождать, может и не сбыться. На подобные проблемы указывал еще Э. Дейкстра в своих первых работах по синхронизации параллельных процессов (см. [ 2 ] в дополнительной литературе).
Помещенные в поток трассировки события с мьютексом 0xf34dcc
. . .
18 сек. 200100569 нсек.
Попытка захвата мьютекса: код ошибки 0, поток 0xf18f74, владелец 0xf18f74 18 сек. 240099731 нсек.
Попытка захвата без ожидания мьютекса: код ошибки 6, поток 0xf14d54, владелец 0xf18f74 18 сек. 260103084 нсек.
Освобождение мьютекса: код ошибки 0, поток 0xf18f74 18 сек. 400098893 нсек.
Попытка захвата мьютекса: код ошибки 0, поток 0xf18f74, владелец 0xf18f74 18 сек. 440100569 нсек.
Попытка захвата без ожидания мьютекса: код ошибки 6, поток 0xf14d54, владелец 0xf18f74 18 сек. 460102246 нсек.
Освобождение мьютекса: код ошибки 0, поток 0xf18f74
. . .
Листинг
8.25.
Фрагмент возможных результатов трассировки системных событий, связанных с мьютексами, на операционной платформе oc2000.
Из результатов трассировки видно, что большую часть времени мьютекс свободен, что он освободится всего через две сотых секунды после того, как второй поток управления сделает очередную неудачную попытку захвата, но ...
