Содержание файла трассировки
При работе сервера репликации может создаваться файл трассировки, который, в зависимости от выбранного уровня трассировки, содержит информацию о работе сервера репликации. Уровень трассировки задается с помощью ключа -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
Сообщения файла трассировки:
| Сообщение | Описание | |
|---|---|---|
Startreplicationserver
| Старт | |
Tracelevel4
| Уровень трассировки – 4 | |
Serviceflagis:0
| Сервер репликации запускается не как сервис (для Windows). Если запускается как сервис – будет указано значение 1 | |
Usenodetabfile'Z:\Linter\bin\nodetab'
| Указано, какой конкретно файл с описанием серверов будет использоваться | |
Begindeleteolddata
| Начался процесс очистки служебных таблиц от устаревшей информации | |
Enddeleteolddata
| Процесс закончен | |
Begindownloadreplicationrules
| Начался процесс скачивания информации о правилах репликации | |
Enddownloadreplicationrules-3OK
| Процесс закончен, найдено три правила | |
Begindownloadreplicationtables
| Начался процесс скачивания информации о структуре таблиц, предназначенных к репликации | |
Enddownloadreplicationtables-3OK
| Процесс закончен, найдено три таблицы | |
StartmainRCVprocess
| Запускается процесс приема данных. В префиксе указан id процесса и номер нити (p1068,t1012) | |
StartSNDprocessfornode'ORACLE'
| Запускается процесс передачи данных. В префиксе указан id процесса и номер нити (p1068,t1044). Этот процесс будет производить рассылку данных на сервер ORACLE | |
StartSNDprocessfornode'SERV100'
| Запускается процесс передачи данных. В префиксе указан id процесса и номер нити (p1068,t992). Этот процесс будет производить рассылку данных на сервер SERV100. Всего запущено два процесса рассылки, значит три правила репликации созданы для рассылки на два сервера | |
Openspecialchannel(Logaddr355:213034)
| Открывается интерфейс к БД источнику данных. Адрес начала потока данных в системном журнале – файл 355 смещение в файле 213034 | |
Startfindandrecoveryaccumulatedrecords
| Запускается процесс получения данных, измененных во время того, как сервер репликации был остановлен | |
Unknownservername:"ORACLE"
| Сообщение процесса рассылки с номером нити 1044 (это видно из префикса). Сервер ORACLE не найден в файле nodetab, эту ошибку должен устранить администратор | |
errorsendingtonetwork:10057
| Тот же процесс сообщает об ошибке при попытке отослать данные | |
Endrecoveryaccumulatedrecords- 0foundandrecoveringnow
| Закончен процесс получения данных, измененных во время того, как сервер репликации был остановлен, таких данных не обнаружено | |
CurrentLreplserverpid=1068
| ID процесса репликации – 1068 | |
Waitdatamodestarted
| Начало ожидания изменения данных |
При изменении данных в таблицах, предназначенных для репликации, может появиться подобный фрагмент:
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 уже есть запись с таким первичным ключом. Эта коллизия должна разрешаться администратором.