Содержание файла трассировки

При работе сервера репликации может создаваться файл трассировки, который, в зависимости от выбранного уровня трассировки, содержит информацию о работе сервера репликации. Уровень трассировки задается с помощью ключа -log < число >, где < число > – уровень трассировки:

Число Описание
0 Нет трассировки, файл не создается
1 Минимальная трассировка, выдаются основные сообщения и сообщения об ошибках
2 Выдаются сообщения о предупреждениях
3 Выдаются информационные сообщения
4 Подробная трассировка

При перезапуске сервера репликации файл не удаляется, запись происходит в конец файла.

При запуске сервера репликации в файл пишется заголовок (если трассировка разрешена):

-------------- Mon Oct 28 13:21:57 2002 --------------

В заголовке содержится дата и время старта сервера репликации.

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

Mon.dd hh24:mi:ss.tt

затем номер процесса (pid) и номер нити (thread), которая произвела запись. В ОС UNIX номер нити равен номеру процесса, вот часть типичного файла трассировки:

-------------- Mon Oct 28 13:21:57 2002 --------------
Oct.28 13:21:57.36,p1068,t104: Start replication server
Oct.28 13:21:57.36,p1068,t104: Trace level 4
Oct.28 13:21:57.36,p1068,t104: Service flag is: 0
Oct.28 13:21:57.40,p1068,t104: Use nodetab file 'Z:\Linter\bin\nodetab'
Oct.28 13:21:57.90,p1068,t104: Begin delete old data
Oct.28 13:21:57.96,p1068,t104: End delete old data
Oct.28 13:21:57.96,p1068,t104: Begin download replication rules
Oct.28 13:21:58.22,p1068,t104: End download replication rules - 3 OK
Oct.28 13:21:58.27,p1068,t104: Begin download replication tables
Oct.28 13:21:58.58,p1068,t104: End download replication tables - 3 OK
Oct.28 13:21:58.61,p1068,t1012: Start main RCV process
Oct.28 13:21:58.68,p1068,t1044: Start SND process for node 'ORACLE'
Oct.28 13:21:58.68,p1068,t992: Start SND process for node 'SERV100'
Oct.28 13:21:58.68,p1068,t104: Open special channel (Log addr 355:213034)
Oct.28 13:21:58.69,p1068,t1056: Start find and recovery accumulated records.
Oct.28 13:21:58.70,p1068,t1044: Unknown server name: "ORACLE"
Oct.28 13:21:58.70,p1068,t1044: error sending to network: 10057
Oct.28 13:21:58.75,p1068,t1056: End recovery accumulated records - 0 found and recovering now.
Oct.28 13:21:59.19,p1068,t104: Current Lreplserver pid=1068
Oct.28 13:21:59.19,p1068,t104: Wait data mode started

Сообщения файла трассировки:

Сообщение Описание
Start replication server  Старт
Trace level 4  Уровень трассировки – 4
Service flag is: 0  Сервер репликации запускается не как сервис (для Windows). Если запускается как сервис – будет указано значение 1
Use nodetab file 'Z:\Linter\bin\nodetab'  Указано, какой конкретно файл с описанием серверов будет использоваться
Begin delete old data  Начался процесс очистки служебных таблиц от устаревшей информации
End delete old data  Процесс закончен
Begin download replication rules  Начался процесс скачивания информации о правилах репликации
End download replication rules - 3 OK  Процесс закончен, найдено три правила
Begin download replication tables  Начался процесс скачивания информации о структуре таблиц, предназначенных к репликации
End download replication tables - 3 OK  Процесс закончен, найдено три таблицы
Start main RCV process  Запускается процесс приема данных. В префиксе указан id процесса и номер нити (p1068,t1012)
Start SND process for node 'ORACLE'  Запускается процесс передачи данных. В префиксе указан id процесса и номер нити (p1068,t1044). Этот процесс будет производить рассылку данных на сервер ORACLE
Start SND process for node 'SERV100'  Запускается процесс передачи данных. В префиксе указан id процесса и номер нити (p1068,t992). Этот процесс будет производить рассылку данных на сервер SERV100. Всего запущено два процесса рассылки, значит три правила репликации созданы для рассылки на два сервера
Open special channel (Log addr 355:213034)  Открывается интерфейс к БД источнику данных. Адрес начала потока данных в системном журнале – файл 355 смещение в файле 213034
Start find and recovery accumulated records  Запускается процесс получения данных, измененных во время того, как сервер репликации был остановлен
Unknown server name: "ORACLE"  Сообщение процесса рассылки с номером нити 1044 (это видно из префикса). Сервер ORACLE не найден в файле nodetab, эту ошибку должен устранить администратор
error sending to network: 10057  Тот же процесс сообщает об ошибке при попытке отослать данные
End recovery accumulated records - 0 found and recovering now  Закончен процесс получения данных, измененных во время того, как сервер репликации был остановлен, таких данных не обнаружено
Current Lreplserver pid=1068  ID процесса репликации – 1068
Wait data mode started  Начало ожидания изменения данных

При изменении данных в таблицах, предназначенных для репликации, может появиться подобный фрагмент:

Oct.28 13:22:26.26,p1068,t104: Insert record (Tr=302900)
Oct.28 13:22:26.26,p1068,t104: Insert complete
Oct.28 13:22:26.27,p1068,t104: Commit (Tr=302900)
Oct.28 13:22:26.27,p1068,t104: Commit complete
Oct.28 13:22:26.27,p1068,t104: Insert record (Tr=302901)
Oct.28 13:22:26.27,p1068,t104: Insert complete
Oct.28 13:22:26.27,p1068,t104: Commit (Tr=302901)
Oct.28 13:22:26.27,p1068,t104: Commit complete
Oct.28 13:22:26.27,p1068,t104: Insert record (Tr=302902)
Oct.28 13:22:26.27,p1068,t104: Insert complete
Oct.28 13:22:26.27,p1068,t104: Commit (Tr=302902)
Oct.28 13:22:26.27,p1068,t104: Commit complete
Oct.28 13:22:26.27,p1068,t104: Start appends 6 records

Здесь в базу данных были вставлены три записи, при этом было три транзакции (302900, 302901, 302902), в последней строке данные заносятся в служебные таблицы, которые использует процесс рассылки данных.

На стороне БД приемника в файле трассировки может появиться следующее:

Oct.28 13:22:29.09,p776,t1256: Processing transaction 302900 (pid=1256)
Oct.28 13:22:29.22,p776,t1256: Attention! (err#903): cbl[    ,DEMO1,3],"INSERT INTO "T1" VALUES(10,'10.10.2000:20:20:20.20');"
Oct.28 13:22:29.23,p776,t1256: Replication error:  -- Error 903

При выполнении транзакции 302900 произошла ошибка и выдана следующая информация:

  • (err#903) – ЛИНТЕР вернул код завершения 903 (повторное значение для первичного или уникального ключа);

  • cbl[ ,DEMO1,3] – ошибка произошла при выполнении команды интерфейса нижнего уровня СУБД ЛИНТЕР (call-интерфейса) типа ' ' по каналу номер 3, открытому к базе данных DEMO1;

  • "INSERT INTO "T1" VALUES(10,'10.10.2000:20:20:20.20');" – SQL-текст команды.

Здесь оказалось, что в таблице T1 уже есть запись с таким первичным ключом. Эта коллизия должна разрешаться администратором.