akpaevj / OneSTools.EventLog

Библиотеки и готовые инструменты для чтения и экспорта журнала регистрации 1С в ClickHouse и ElasticSearch
MIT License
129 stars 46 forks source link

Дубли в логах #46

Open ibragimovrs opened 2 years ago

ibragimovrs commented 2 years ago

При перезапуске службы он одни и теже данные перезаливает но уже под другим ID (т.к. служба плохо работает добавил таск в шедулер который раз в час ребутит службу), Нужно хранить данные о последних удачных загрузках локально а не в самом эластике и при старте бежать за инфой к себе а на сторону которая может выдать не актуальные сведения. Отпишитесь может у кого есть фиксы? автор похоже забросил проект.

akpaevj commented 2 years ago

Автор не забросил, а временно приостановил вообще всю деятельность на github'е=) В БД хранится позиция события в файле. Не могу пока придумать какой-то случай, при котором может произойти повторная загрузка

ibragimovrs commented 2 years ago

:) image

при таких показателях Elastic? cлужба частенько просто ничего не исполняет, а точнее ничего не экспортирует и в лог файл не пишет, в C# нуб, пытаюсь найти причину но пока ищу нашёл решение именно в рестарте службы, именно после таких рестартов (раз в час) начало такое сыпаться (не всегда) Missing replica shards - это не индексы ЖР (по ним всё зелено) там кто-то пул реквест сделал может его стянуть и попробовать?

ibragimovrs commented 2 years ago

Убрал рестартер. Сбоев после запуска небыло, логи писались без останова. При этом дубли остались. Смотрю в фале log он читает один и тот же файл по нескольку раз (2, 3, 4). Почему так? "Separation": "H" image

1rV1N-git commented 2 years ago

Экспортер пеерчитывает логи если

Самый просто способ сменить имя у текущего индекса (reindex) и залить логи в чистый индекс.

https://github.com/akpaevj/OneSTools.EventLog/issues/21

ibragimovrs commented 2 years ago

Экспортер пеерчитывает логи если

  • в документе в эластике с самым большим id есть поле fileName и если служба не находит такой файл в папке с логами. тогда он будет перечитывать всё

Самый просто способ сменить имя у текущего индекса (reindex) и залить логи в чистый индекс.

21

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

deevil commented 1 year ago

С учетом фикса от @JohnyDeath баг все равно есть. Не связан с ребутом. Связь пока однозначно не понял. Условно как я понял по логу: в 00:00 ридер переключается на новый файл, а потом обратно переключается на старый и начинает его вычитку, параллельно переключившись на новый файл. Насчет повторных ридеров на 100% не уверен - так как на сервере есть несколько СУБД и запущено в режиме менеджера. Добавил в вывод лога путь - чтобы видней было какой базы касается...

2023-10-14 00:00:00.796 Information EventLogExporter - Reader started reading 20231014000000.lgp 2023-10-14 00:00:01.730 Information EventLogExporter - Reader started reading 20231013000000.lgp 2023-10-14 00:00:02.333 Debug CH 20000 items 1C_DB 2023-10-14 00:00:02.802 Debug CH 20000 items 1C_DB 2023-10-14 00:00:03.221 Debug CH 20000 items 1C_DB 2023-10-14 00:00:03.670 Debug CH 20000 items 1C_DB 2023-10-14 00:00:04.104 Debug CH 20000 items 1C_DB 2023-10-14 00:00:04.540 Debug CH 20000 items 1C_DB 2023-10-14 00:00:05.107 Debug CH 20000 items 1C_DB 2023-10-14 00:00:05.512 Debug CH 20000 items 1C_DB 2023-10-14 00:00:05.625 Information EventLogExporter - Reader started reading 20231014000000.lgp 2023-10-14 00:00:05.755 Information EventLogExporter - Reader started reading 20231014000000.lgp 2023-10-14 00:00:05.998 Debug CH 20000 items 1C_DB 2023-10-14 00:00:06.452 Debug CH 20000 items 1C_DB 2023-10-14 00:00:06.874 Debug CH 20000 items 1C_DB 2023-10-14 00:00:07.314 Debug CH 20000 items 1C_DB 2023-10-14 00:00:07.666 Information EventLogExporter - Reader started reading 20231014000000.lgp 2023-10-14 00:00:07.709 Debug CH 20000 items 1C_DB 2023-10-14 00:00:08.196 Debug CH 20000 items 1C_DB 2023-10-14 00:00:08.609 Debug CH 20000 items 1C_DB 2023-10-14 00:00:09.038 Debug CH 20000 items 1C_DB 2023-10-14 00:00:09.480 Debug CH 20000 items 1C_DB 2023-10-14 00:00:09.886 Debug CH 20000 items 1C_DB 2023-10-14 00:00:10.355 Debug CH 20000 items 1C_DB ......................................................... 2023-10-14 00:00:47.938 Debug CH 20000 items 1C_DB 2023-10-14 00:00:48.348 Debug CH 20000 items 1C_DB 2023-10-14 00:00:48.864 Debug CH 20000 items 1C_DB 2023-10-14 00:00:49.317 Debug CH 20000 items 1C_DB 2023-10-14 00:00:50.379 Debug CH 7361 items 1C_DB 2023-10-14 00:00:51.329 Debug CH 10 items 1C_DB 2023-10-14 00:00:52.330 Debug CH 16 items 1C_DB 2023-10-14 00:00:53.343 Debug CH 11 items 1C_DB 2023-10-14 00:00:54.356 Debug CH 13 items 1C_DB 2023-10-14 00:00:55.377 Debug CH 13 items 1C_DB 2023-10-14 00:00:56.389 Debug CH 13 items 1C_DB 2023-10-14 00:00:57.391 Debug CH 8 items 1C_DB 2023-10-14 00:00:58.396 Debug CH 11 items 1C_DB 2023-10-14 00:00:59.408 Debug CH 15 items 1C_DB 2023-10-14 00:01:00.410 Debug CH 8 items 1C_DB 2023-10-14 00:01:01.416 Debug CH 11 items 1C_DB 2023-10-14 00:01:02.423 Debug CH 13 items 1C_DB 2023-10-14 00:01:03.429 Debug CH 15 items 1C_DB 2023-10-14 00:01:13.538 Debug CH 11 items 1C_DB 2023-10-14 00:01:14.548 Debug CH 8 items 1C_DB

deevil commented 1 year ago

Отчасти объяснение в том что похоже старый файл меняется в догонок уже созданному новому (асинхронность записи?)...

image

JohnyDeath commented 1 year ago

Да, я тоже замечал не переключение на новые журналы даже с моим патчем. Но практически сразу сервер 1С переехал на новую более быструю машину. Там еще ни разу этого бага не обнаружил. Не знаю с чем связано. Воспроизвести на новом железе не получается

deevil commented 1 year ago

@JohnyDeath А на проде комит https://github.com/akpaevj/OneSTools.EventLog/commit/88e113d66d8fce71ccf4174fa621ef134fafb142 используется?

Думаю он фиксит эту проблему - но опосредованно...

JohnyDeath commented 1 year ago

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

deevil commented 1 year ago

Думаю вопрос в Windows и его работе с файлами. У меня вчера вообще по какой-то причине lgp файл предыдущего дня изменен через 44 минуты после полуночи. И по мониторингу сервер не был перегружен.

Костыльный вариант подготовил. Логика такая: при начале чтения нового файла лога из базы вытягивается EndPosition и если EndPosition записи меньше этого значения - то запись пропускается.

Минуса 2:

  1. Он проходит весь файл пока не дойдет до изменения.
  2. Id получается не последовательным.

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

deevil commented 1 year ago

Добавил фикс (костыльный) чтобы id не увеличивался (по факту при пропуске записи - он уменьшается на 1) Сделал чтобы при смене файла данные записывались в БД (из-за этого при переключении обратно на новый файл создавались дубли уже в новом). Добавил в лог информацию о пропущенных и т.д.

Костыли все таки есть:

  1. Все также проходит весь старый файл - но на 2х миллионах записей - это занимает порядка 30 секунд.
  2. Все таки хотелось бы чтобы при переключении на старый файл он продолжал читать с EndPosition - но пока не представляю как это сделать "красиво"

В целом 2 дня тестов - пока полет нормальный... Доделаю другие фиксы и выложу релиз/бинарники у себя...