Трассировка пользовательских приложений

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

Структура типа posix_trace_status_info содержит информацию о состоянии активного потока трассировки. Согласно стандарту POSIX-2001, она должна содержать по крайней мере следующие поля.

int posix_stream_status;     
    /* Состояние потока трассировки */ 
int posix_stream_full_status;     
    /* Признак заполненности потока    */
int posix_stream_overrun_status;    
    /* Признак потери информации    */
int posix_stream_flush_status;     
    /* Идет ли в данный момент сброс в журнал */
int posix_stream_flush_error;     
    /* Были ли ошибки при последнем сбросе     */
int posix_log_overrun_status;     
    /* Признак потери информации в журнале     */
int posix_log_full_status;     
    /* Признак заполненности журнала    */

Значение поля posix_stream_status отражает режим, в котором находится поток трассировки:

POSIX_TRACE_RUNNING

Трассировка выполняется, поток принимает события.

POSIX_TRACE_SUSPENDED

Трассировка приостановлена (или не начиналась), поток не принимает события.

Поле posix_stream_full_status отражает состояние заполненности потока. Оно может содержать следующие значения.

POSIX_TRACE_FULL

Пространство в потоке исчерпано.

POSIX_TRACE_NOT_FULL

В потоке есть свободное пространство для событий.

Отметим, что на практике возможны все четыре комбинации значений полей posix_stream_status и posix_stream_full_status. В частности, сочетание POSIX_TRACE_RUNNING и POSIX_TRACE_FULL свидетельствует о том, что трассировка идет, но с потерей информации (новые события записываются на место старых).

Поле posix_stream_overrun_status содержит признак потери информации. Возможные значения:

POSIX_TRACE_OVERRUN

По крайней мере одно событие было потеряно (и, следовательно, не содержится в потоке трассировки ).

POSIX_TRACE_NO_OVERRUN

Ни одно событие не потеряно.

События могут теряться, если они генерируются при заполненном потоке или во время сброса потока трассировки в журнал.

Поле posix_stream_flush_status содержит признак того, что в данный момент происходит сброс потока трассировки в журнал. Возможных значений, разумеется, два.

POSIX_TRACE_FLUSHING

В данный момент происходит сброс потока трассировки в журнал.

POSIX_TRACE_NOT_FLUSHING

В данный момент не происходит сброс потока трассировки в журнал.

В поле posix_stream_flush_error находится нуль, если последний сброс прошел нормально; в противном случае там хранится код первой случившейся при сбросе ошибки (информация о последующих ошибках теряется).

Поле posix_log_overrun_status содержит признак потери информации в журнале с двумя возможными значениями: POSIX_TRACE_OVERRUN и POSIX_TRACE_NO_OVERRUN.

Поле posix_log_full_status служит признаком заполненности журнала. Возможных значений, естественно, два: POSIX_TRACE_FULL и POSIX_TRACE_NOT_FULL.

При создании потока трассировки его атрибуты стандартным для POSIX-2001 образом извлекаются из атрибутного объекта. Стандартом предусмотрены следующие атрибуты:

И для потоков, и для журналов трассировки   правила обработки ситуации заполнения могут сводиться к записи новых событий поверх самых старых (политика POSIX_TRACE_LOOP ) или к приостановке трассировки ( POSIX_TRACE_UNTIL_FULL ). Кроме того, для потоков может быть предусмотрен сброс в журнал с последующей очисткой (политика POSIX_TRACE_FLUSH ), а для для журналов – потенциально неограниченное расширение ( POSIX_TRACE_APPEND ).

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

В заключение раздела еще раз подчеркнем важные достоинства, которыми обладает механизм трассировки.

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

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

Функции для работы с атрибутными объектами потоков трассировки

Согласно стандарту POSIX-2001, система трассировки строится в объектно-ориентированном стиле. Структура большинства используемых объектов скрыта от приложения, поэтому требуется довольно много относительно мелких функций – конструкторов, селекторов, итераторов.

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

Чтобы получить общее представление о функциях трассировки, рассмотрим сначала два верхних уровня описанной иерархии.

Трассирующий процесс управляет ресурсами, ассоциированными с потоками трассировки, а именно:

Трассируемый процесс имеет дело со следующими объектами:

Анализирующий процесс читает:

Перейдем к детальному рассмотрению функций трассировки.

Для создания и уничтожения   атрибутных объектов потоков трассировки служат функции posix_trace_attr_init() и posix_trace_attr_destroy() (см. листинг 8.1).

#include <trace.h>
int posix_trace_attr_init (
    trace_attr_t *attr);
int posix_trace_attr_destroy (
    trace_attr_t *attr);

Функция posix_trace_attr_init() инициализирует атрибутный объект подразумеваемыми значениями для всех атрибутов, используемых реализацией. Отметим, что два атрибута – имя версии системы трассировки и разрешающая способность часов, с помощью которых проставляются временные штампы, – доступны только на чтение.

Нормальным является нулевой результат; при наличии ошибки возвращается ее номер.

Для манипулирования атрибутами, идентифицирующими поток трассировки, служат функции posix_trace_attr_getgenversion(), posix_trace_attr_getname(), posix_trace_attr_setname(), posix_trace_attr_getcreatetime() (см. листинг 8.2).

#include <trace.h>
int posix_trace_attr_getgenversion (
    const trace_attr_t *attr, 
    char *genversion);
int posix_trace_attr_getname (
    const trace_attr_t *attr, 
    char *tracename);
int posix_trace_attr_setname (
    trace_attr_t *attr, const 
    char *tracename);
#include <time.h>
#include <trace.h>
int posix_trace_attr_getcreatetime (
    const trace_attr_t *attr, 
    struct timespec *createtime);

Функции опроса копируют значения соответствующих атрибутов (имя версии системы трассировки, имя и время создания потока трассировки ) из атрибутного объекта, заданного аргументом attr, в символьный массив (длина которого должна быть не меньше TRACE_NAME_MAX ) или в структуру. Функция posix_trace_attr_setname() копирует имя (длина которого не должна превышать TRACE_NAME_MAX ) в противоположном направлении.

Функция posix_trace_attr_getclockres() (см. листинг 8.3) позволяет опросить разрешающую способность часов, с помощью которых проставляются временные штампы.

#include <time.h>
#include <trace.h>
int posix_trace_attr_getclockres (
    const trace_attr_t *attr, 
    struct timespec *resolution);

Поведенческие атрибуты потоков и журналов обслуживаются функциями: posix_trace_attr_getinherited(), posix_trace_attr_setinherited(), posix_trace_attr_getstreamfullpolicy(), posix_trace_attr_setstreamfullpolicy(), posix_trace_attr_getlogfullpolicy(), posix_trace_attr_setlogfullpolicy() (см. листинг 8.4).

#include <trace.h>
int posix_trace_attr_getinherited (
    const trace_attr_t *restrict attr, 
    int *restrict inheritancepolicy);
int posix_trace_attr_setinherited (
    trace_attr_t *attr, 
    int inheritancepolicy);
int posix_trace_attr_getstreamfullpolicy (
    const trace_attr_t *restrict attr, 
    int *restrict streampolicy);
int posix_trace_attr_setstreamfullpolicy (
    trace_attr_t *attr, int streampolicy);
int posix_trace_attr_getlogfullpolicy (
    const trace_attr_t *restrict attr, 
    int *restrict logpolicy);
int posix_trace_attr_setlogfullpolicy (
    trace_attr_t *attr, int logpolicy);

Функции posix_trace_attr_getinherited() и posix_trace_attr_setinherited() позволяют, соответственно, опросить и установить значение атрибута   наследования трассировки порожденными процессами. Если значение этого атрибута равно POSIX_TRACE_INHERITED, то после вызовов fork() и/или spawn() родительский и порожденный процессы будут трассироваться параллельно с использованием общего потока трассировки. Подразумеваемое значение атрибута суть POSIX_TRACE_CLOSE_FOR_CHILD (не трассировать порожденные процессы).

Атрибут, специфицирующий правила обработки ситуации заполнения, и для потоков (функции posix_trace_attr_getstreamfullpolicy() и posix_trace_attr_setstreamfullpolicy() ), и для журналов трассировки (функции posix_trace_attr_getlogfullpolicy() и posix_trace_attr_setlogfullpolicy() ) может принимать следующие значения.

POSIX_TRACE_LOOP

Для потоков – продолжение трассировки с записью новых событий поверх самых старых; для журналов – сброс всех событий из потока также с записью поверх самых старых.

POSIX_TRACE_UNTIL_FULL

Для потоков – приостановка трассировки с генерацией события   POSIX_TRACE_STOP. Реализация обязана возобновить трассировку (с генерацией события   POSIX_TRACE_START ) после очистки потока, но может сделать это и раньше, за счет повторного использования пространства, которое занимали прочитанные события. Для журналов – прекращение сброса (последним в журнал помещается событие   POSIX_TRACE_STOP ). События, которые не поместились в журнал, пропадают.

Для потоков трассировки еще одним возможным значением служит

POSIX_TRACE_FLUSH

Регулярно сбрасывать поток в журнал трассировки; в остальном действовать по правилам POSIX_TRACE_UNTIL_FULL.

Если с потоком ассоциирован журнал, то подразумеваемым значением данного атрибута является POSIX_TRACE_FLUSH ; в противном случае – POSIX_TRACE_LOOP.

Для журналов трассировки описываемый атрибут может принимать значение

POSIX_TRACE_APPEND

Потенциально неограниченное расширение журнала.

Подразумеваемым для журналов является значение POSIX_TRACE_LOOP.

Опросить и/или установить хранящиеся в атрибутном объекте   размеры событий, потоков и журналов можно с помощью функций: posix_trace_attr_getmaxdatasize(), posix_trace_attr_setmaxdatasize(), posix_trace_attr_getmaxsystemeventsize(), posix_trace_attr_getmaxusereventsize(), posix_trace_attr_getstreamsize(), posix_trace_attr_setstreamsize(), posix_trace_attr_getlogsize(), posix_trace_attr_setlogsize() (см. листинг 8.5).

#include <sys/types.h>
#include <trace.h>
int posix_trace_attr_getmaxdatasize (
    const trace_attr_t *restrict attr, 
    size_t *restrict maxdatasize);
int posix_trace_attr_setmaxdatasize (
    trace_attr_t *attr, size_t maxdatasize);
int posix_trace_attr_getmaxsystemeventsize (
    const trace_attr_t *restrict attr, 
    size_t *restrict eventsize);
int posix_trace_attr_getmaxusereventsize (
    const trace_attr_t *restrict attr,
    size_t data_len, size_t *restrict eventsize);
int posix_trace_attr_getstreamsize (
    const trace_attr_t *restrict attr,
    size_t *restrict streamsize);
int posix_trace_attr_setstreamsize (
    trace_attr_t *attr, size_t streamsize);
int posix_trace_attr_getlogsize (
    const trace_attr_t *restrict attr,
    size_t *restrict logsize);
int posix_trace_attr_setlogsize (
    trace_attr_t *attr, size_t logsize);

Функции posix_trace_attr_getmaxdatasize() и posix_trace_attr_setmaxdatasize() позволяют опросить и установить максимальный размер (в байтах) данных, ассоциируемых с пользовательскими событиями. Подразумеваемое значение этого атрибута зависит от реализации.

Функции posix_trace_attr_getmaxsystemeventsize() и posix_trace_attr_getmaxusereventsize() служат для опроса максимального размера   системных и пользовательских событий, соответственно (во втором случае учитывается размер ассоциированных данных, определяемый значением аргумента data_len ).

Функции posix_trace_attr_getstreamsize() и posix_trace_attr_setstreamsize() ведают минимальным объемом памяти, который система трассировки обязана зарезервировать в потоке для хранения событий. Накладные расходы на размещение атрибутов потока, таких как идентифицирующие данные или правила поведения, в эту величину не входят. Пока сумма максимальных размеров событий не превосходит значения данного атрибута, события должны записываться без потери информации.

Функции posix_trace_attr_getlogsize() и posix_trace_attr_setlogsize() обслуживают атрибут   журнала трассировки – максимальный размер, резервируемый для хранения событий. Если правило обработки ситуации заполнения журнала определено как POSIX_TRACE_APPEND, данный атрибут игнорируется.

Функции, обслуживающие жизненный цикл потоков трассировки.

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

Создание потока трассировки осуществляется функциями posix_trace_create() или posix_trace_create_withlog() (см. листинг 8.6).

#include <sys/types.h>
#include <trace.h>
int posix_trace_create (pid_t pid, 
    const trace_attr_t *restrict attr, 
    trace_id_t *restrict trid);
int posix_trace_create_withlog (pid_t pid, 
    const trace_attr_t *restrict attr, int fildes, 
    trace_id_t *restrict trid);

Функция posix_trace_create() создает активный поток, в который будут записываться события   трассировки   целевого процесса с идентификатором pid (при нулевом pid трассируется вызывающий процесс). Ресурсы в потоке отводятся в соответствии со значениями элементов атрибутного объекта, заданного аргументом attr (если attr равен NULL, используются подразумеваемые значения).

Идентификатор созданного потока записывается по указателю trid. Его может использовать только вызывающий процесс.

Фильтр, ассоциированный с новым потоком, пуст.

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

Разумеется, попытки трассировать другие процессы подвержены контролю прав доступа.

Функция posix_trace_create_withlog() делает то же, что и posix_trace_create(), но дополнительно ассоциирует с потоком журнал трассировки, заданный файловым дескриптором fildes.

Сразу после создания потока трассировка считается приостановленной. Чтобы активизировать ее, следует воспользоваться функцией posix_trace_start() ; для последующей приостановки нужно вызвать функцию posix_trace_stop() (см. листинг 8.7).

#include <trace.h>
int posix_trace_start (trace_id_t trid);
int posix_trace_stop (trace_id_t trid);

После вызова posix_trace_start() в поток помещается системное событие   POSIX_TRACE_START, а статус потока получает значение POSIX_TRACE_RUNNING (если трассировка уже шла, вызов posix_trace_start() игнорируется).

После вызова posix_trace_stop() в поток помещается системное событие   POSIX_TRACE_STOP, а статус потока получает значение POSIX_TRACE_SUSPENDED (если трассировка уже была приостановлена, вызов posix_trace_stop() игнорируется).

Если поток трассировки заполнен, вызовы posix_trace_start() и posix_trace_stop() игнорируются.

Функция posix_trace_shutdown() (см. листинг 8.8) завершает трассировку и освобождает ресурсы, ассоциированные с потоком, независимо от того, прочитал ли анализирующий процесс все записанные события.

#include <sys/types.h>
#include <trace.h>
int posix_trace_shutdown (trace_id_t trid);

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

После возврата из posix_trace_shutdown() аргумент trid перестает быть корректным идентификатором потока трассировки.

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

По ходу трассировки   управляющий процесс может инициировать сброс потока в журнал, обратившись к функции posix_trace_flush() (см листинг 8.9).

#include <sys/types.h>
#include <trace.h>
int posix_trace_flush (trace_id_t trid);

Сброс осуществляется с учетом правил обработки ситуации заполнения журнала.

После завершения сброса пространство в потоке трассировки, которое занимали записанные в журнал события, может быть использовано повторно.

Узнать о завершении операции сброса можно, опрашивая статус потока трассировки с помощью функции posix_trace_get_status() (см. листинг 8.10).

#include <trace.h>
int posix_trace_get_status (trace_id_t trid,
    struct posix_trace_status_info 
                               *statusinfo);

Функция обеспечивает согласованность данных, которые записываются в структуру типа posix_trace_status_info по указателю statusinfo. Сразу после завершения вызова признаки переполнения и для потока, и для журнала получают значение POSIX_TRACE_NO_OVERRUN, а в поле posix_stream_flush_error помещается нуль.

Стандартом POSIX-2001 предусмотрен опрос атрибутов потока трассировки. Для этого служит функция posix_trace_get_attr() (см. листинг 8.11).

#include <trace.h>
int posix_trace_get_attr (
    trace_id_t trid, trace_attr_t *attr);

Для возврата значений атрибутов найдено красивое решение – они помещаются в атрибутный объект по указателю attr, откуда могут быть извлечены рассмотренными выше функциями для работы с атрибутными объектами.

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

#include <sys/types.h>
#include <trace.h>
int posix_trace_clear (trace_id_t trid);

Разумеется, после очистки признак заполненности получает значение POSIX_TRACE_NOT_FULL.

Если для журнала предусмотрено неограниченное расширение ( POSIX_TRACE_APPEND ), эффект от вызова posix_trace_clear() не специфицирован.

При опросе и установке фильтров   событий   трассировки (функции posix_trace_get_filter() и posix_trace_set_filter(), см. листинг 8.13) применяется апробированная в других частях стандарта POSIX-2001 схема работы с множествами, основанная на функциях: posix_trace_eventset_empty(), posix_trace_eventset_fill(), posix_trace_eventset_add(), posix_trace_eventset_del(), posix_trace_eventset_ismember() (см. листинг 8.14).

#include <trace.h>
int posix_trace_get_filter (
    trace_id_t trid, trace_event_set_t *set);
int posix_trace_set_filter (trace_id_t trid, 
    const trace_event_set_t *set, int how);

#include <trace.h>
int posix_trace_eventset_empty (
    trace_event_set_t *set);
int posix_trace_eventset_fill (
    trace_event_set_t *set, int what);
int posix_trace_eventset_add (
    trace_event_id_t event_id, 
    trace_event_set_t *set);
int posix_trace_eventset_del (
    trace_event_id_t event_id, 
    trace_event_set_t *set);
int posix_trace_eventset_ismember (
    trace_event_id_t event_id, 
    const trace_event_set_t *restrict set, 
    int *restrict ismember);

Когда вызывается функция posix_trace_set_filter(), в поток трассировки помещается событие   POSIX_TRACE_FILTER с указанием старого и нового фильтров. Аргумент how, определяющий, как меняется фильтр, может принимать следующие значения.

POSIX_TRACE_SET_EVENTSET

Новое значение фильтра задается аргументом set.

POSIX_TRACE_ADD_EVENTSET

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

POSIX_TRACE_SUB_EVENTSET

Новое значение фильтра вычисляется как разность текущего значения и множества, заданного аргументом set.

Вероятно, функции для работы с множествами событий трассировки не нуждаются в пространном описании. Аргумент event_id задает тип события. Функция posix_trace_eventset_empty()  создает пустое множество событий. Функция posix_trace_eventset_fill() помещает в создаваемое множество события, определяемые аргументом what, который может принимать следующие значения.

POSIX_TRACE_WOPID_EVENTS

Все зависящие от реализации системные события, не ассоциированные с каким-либо процессом.

POSIX_TRACE_SYSTEM_EVENTS

Все зависящие от реализации системные события.

POSIX_TRACE_ALL_EVENTS

Все события ( системные и пользовательские ).

Для функций posix_trace_eventset_add() и posix_trace_eventset_del() добавление уже присутствующего или, соответственно, удаление отсутствующего типа не считается ошибкой.

Функция posix_trace_eventset_ismember() помещает по указателю ismember ненулевое значение, если тип event_id принадлежит множеству, заданному аргументом set.

Как и (почти) везде в системе трассировки, нормальным для описанных функций является нулевой результат.

Играющие техническую роль функции posix_trace_trid_eventid_open(), posix_trace_eventid_get_name() и posix_trace_eventid_equal() (см. листинг 8.15), обслуживают идентификаторы типов событий, рассматриваемые как абстрактные объекты.

#include <trace.h>
int posix_trace_trid_eventid_open (
    trace_id_t trid, 
    const char *restrict event_name, 
    trace_event_id_t *restrict event);

int posix_trace_eventid_get_name (
    trace_id_t trid, 
    trace_event_id_t event, 
    char *event_name);

int posix_trace_eventid_equal (
    trace_id_t trid, 
    trace_event_id_t event1, 
    trace_event_id_t event2);

Функция posix_trace_trid_eventid_open() ассоциирует с именем event_name, длина которого не должна превышать значения конфигурационной константы TRACE_EVENT_NAME_MAX, уникальный для потока трассировки, заданного аргументом trid, идентификатор типа событий и записывает его по указателю event. При повторном вызове posix_trace_trid_eventid_open() с тем же именем возвращается ранее созданный идентификатор. При попытке превысить максимально допустимое для процесса количество типов   пользовательских событий TRACE_USER_EVENT_MAX возвращается предопределенный идентификатор POSIX_TRACE_UNNAMED_USEREVENT.

Функция posix_trace_eventid_get_name() записывает в массив event_name   имя события, ассоциированное с типом, заданным аргументом event.

Сравнить два идентификатора типов из одного потока трассировки можно посредством функции posix_trace_eventid_equal(), возвращающей в случае равенства результат, отличный от нуля.

Функции posix_trace_eventtypelist_getnext_id() и posix_trace_eventtypelist_rewind() (см. листинг 8.16) позволяют обрабатывать совокупность идентификаторов типов событий, присутствующих в заданном потоке трассировки.

#include <trace.h>
int posix_trace_eventtypelist_getnext_id (
    trace_id_t trid, 
    trace_event_id_t *restrict event, 
    int *restrict unavailable);
int posix_trace_eventtypelist_rewind (trace_id_t trid);

Функция posix_trace_eventtypelist_getnext_id() является итератором. При первом обращении она записывает по указателю event первый идентификатор типа. При каждом следующем вызове туда же помещается очередной идентификатор. Пока перебор идентификаторов не закончен, по указателю unavailable записывается нулевое значение.

Функция posix_trace_eventtypelist_rewind() позволяет вернуться к началу перебора.

Приведем пример программы, выясняющей подразумеваемые значения атрибутов   потока трассировки (см. листинг 8.17).

/* * * * * * * * * * * * * * * * * * * * * * * */
/* Программа выясняет подразумеваемые значения */
/* атрибутов потока трассировки                */
/* * * * * * * * * * * * * * * * * * * * * * * */

#include <sys/types.h>
#include <stdio.h>
#include <trace.h>
#include <time.h>
#include <limits.h>
#include <errno.h>

int main (void) {
    trace_attr_t attr;                 /* Атрибутный объект потока */
    trace_id_t trid;                 /* Идентификатор потока */
    char trbuf [TRACE_NAME_MAX];    /* Буфер для имен */
    struct timespec tms;             /* Структура для времен */
    char dtbuf [LINE_MAX];             /* Буфер для данных о времени */
    int res;                         /* Целочисленные результаты    */
    size_t mdatsz;                     /* Максимальный размер данных */
if ((errno = posix_trace_create (0, NULL, trid)) != 0) {
        perror ("POSIX_TRACE_CREATE");
        return (errno);
    }

    if ((errno = posix_trace_get_attr (trid, attr)) != 0) {
        perror ("POSIX_TRACE_GET_ATTR");
        return (errno);
    }

    if ((errno = posix_trace_attr_getgenversion (attr, 
            trbuf)) != 0) {
        perror ("POSIX_TRACE_ATTR_GETGENVERSION");
        return (errno);
    }
    printf ("Версия системы трассировки: %s\n", trbuf);

    if ((errno = posix_trace_attr_getname 
            (attr, trbuf)) != 0) {
        perror ("POSIX_TRACE_ATTR_GETNAME");
        return (errno);
    }
    printf ("Имя потока трассировки: %s\n", trbuf);

    if ((errno = posix_trace_attr_getcreatetime 
            (attr, tms)) != 0) {
        perror ("POSIX_TRACE_ATTR_GETCREATETIME");
        return (errno);
    }
    (void) strftime (dtbuf, sizeof (dtbuf), "%c", 
        localtime (tms.tv_sec));
    printf ("Время создания потока трассировки: %s\n", dtbuf);

    if ((errno = posix_trace_attr_getclockres 
            (attr, tms)) != 0) {
        perror ("POSIX_TRACE_ATTR_GETCLOCKRES");
        return (errno);
    }
    printf ("Разрешающая способность часов потока "
                "трассировки: %ld нсек\n", tms.tv_nsec);

    if ((errno = posix_trace_attr_getstreamfullpolicy 
            (attr, res)) != 0) {
        perror ("POSIX_TRACE_ATTR_GETSTREAMFULLPOLICY");
        return (errno);
    }
    printf ("Правило обработки ситуации заполнения потока: ");
    switch (res) {
        case POSIX_TRACE_LOOP:
            printf ("POSIX_TRACE_LOOP\n");
            break;
        case POSIX_TRACE_UNTIL_FULL:
            printf ("POSIX_TRACE_UNTIL_FULL\n");
            break;
        case POSIX_TRACE_FLUSH:
            printf ("POSIX_TRACE_FLUSH\n");
            break;
        default:
            printf ("неизвестно\n");
    }

    if ((errno = posix_trace_attr_getlogfullpolicy 
            (attr, res)) != 0) {
        perror ("POSIX_TRACE_ATTR_GETLOGFULLPOLICY");
        return (errno);
    }
    printf ("Правило обработки ситуации заполнения "
                "журнала трассировки: ");
    switch (res) {
        case POSIX_TRACE_LOOP:
            printf ("POSIX_TRACE_LOOP\n");
            break;
        case POSIX_TRACE_UNTIL_FULL:
            printf ("POSIX_TRACE_UNTIL_FULL\n");
            break;
        case POSIX_TRACE_APPEND:
            printf ("POSIX_TRACE_APPEND\n");
            break;
        default:
            printf ("неизвестно\n");
    }

    if ((errno = posix_trace_attr_getmaxdatasize 
            (attr, mdatsz)) != 0) {
        perror ("POSIX_TRACE_ATTR_GETMAXDATASIZE");
        return (errno);
    }
    printf ("Максимальный размер данных в пользовательском "
                "событии: %d\n", mdatsz);

    if ((errno = posix_trace_attr_getmaxusereventsize 
            (attr, mdatsz, mdatsz)) != 0) {
        perror ("POSIX_TRACE_ATTR_GETMAXUSEREVENTSIZE");
        return (errno);
    }
    printf ("Максимальный размер пользовательского события: "
                "%d\n", mdatsz);

    if ((errno = posix_trace_attr_getmaxsystemeventsize 
            (attr, mdatsz)) != 0) {
        perror ("POSIX_TRACE_ATTR_GETMAXSYSTEMEVENTSIZE");
        return (errno);
    }
    printf ("Максимальный размер системного события: "
                "%d\n", mdatsz);

    if ((errno = posix_trace_attr_getstreamsize 
            (attr, mdatsz)) != 0) {
        perror ("POSIX_TRACE_ATTR_GETSTREAMSIZE");
        return (errno);
    }
    printf ("Размер потока трассировки: %d\n", mdatsz);

    return 0;
}

Обратим внимание на использование конфигурационной константы TRACE_NAME_MAX для задания размера буфера имен.

При запуске этой программы под управлением операционной системы реального времени oc2000 могут быть получены следующие результаты (см. листинг 8.18).

Версия системы трассировки: 2.17
  Имя потока трассировки: trace
  Время создания потока трассировки: Пн 19 АПР 2004 11:54:07
  Разрешающая способность часов потока трассировки: 41904 нсек
  Правило обработки ситуации заполнения потока: POSIX_TRACE_UNTIL_FULL
  Правило обработки ситуации заполнения журнала трассировки: POSIX_TRACE_LOOP
  Максимальный размер данных в пользовательском событии: 100
  Максимальный размер пользовательского события: 128
  Максимальный размер системного события: 84
  Размер потока трассировки: 409600

Отметим нестандартность конфигурации системы применительно к обработке ситуации заполнения потока: POSIX-2001 предусматривает, что подразумеваемыми (в зависимости от наличия журнала) могут быть лишь значения POSIX_TRACE_LOOP или POSIX_TRACE_FLUSH, но не POSIX_TRACE_UNTIL_FULL.

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

Функции для работы с событиями

От рассмотрения средств, доступных трассирующему процессу, мы переходим к функциям, используемым для оборудования трассируемых пользовательских приложений. Таких функций две: 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);

Вызов функции 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);

Функция 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);

Функция 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;
}

Отметим, что в качестве данных, ассоциированных с пользовательскими событиями, выступают целые числа – номера философов (по одному на событие, см. вызовы 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.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;
}

Результаты трассировки сводятся к многократному повторению фрагмента, показанного на в дополнительной литературе).

Помещенные в поток трассировки события с мьютексом 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
        . . .

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