Расследовать такие ошибки самостоятельно сложно, но иногда все-таки можно, об этом и будет данная статья.
С чего начать?
Первое что необходимо сделать, это настроить технологический журнал (ТЖ).
Если кто не знает что это за зверь, то вам сюда.
Даже если у вас все хорошо, или вы думаете что у вас все хорошо, то все равно рекомендуется настроить сбор логов. Зачем?
Есть 2 причины:
1. Если вдруг проблемы возникнут, то у вас уже будут все данные для расследования.
2. Возможно, что проблемы у вас уже есть, например процессы «падают» раз в 2-3 месяца, но вы об этом просто не знаете, т.к. пользователям легче перезапустится и продолжить работу, чем связываться с программистами.
Файл настроек ТЖ, тот который logcfg.xml, должен выглядеть следующим образом:
Теперь давайте разберемся с тем, что здесь написано.
Во второй строке мы включаем запись дампа, т.е. в случае краха одного из процессов дамп будет записан в каталог «c:v82dumps» и при необходимости поможет разработчикам платформы найти причину ошибки.
Дамп образуется только в случае падения одного из процессов, т.е. если в каталоге damps появятся файлы, это значит, что у вас есть проблемы со стабильностью.
В третьей строке мы включаем запись логов ТЖ, как не трудно догадаться, логи будут записываться в каталог «c:v82logs» и храниться 48 часов.
Событие EXCP пишется в случае возникновения исключения, и нужно что бы узнать какой код выполнялся в момент ошибки.
События PROC и ADMIN могут пригодиться разработчикам платформы для расследования.
Что делать, если появится дамп?
Допустим в каталоге dumps появился файл rphost_8.2.18.102_7c938235_20131025162441_3348.mdmp
Имя дампа строится по следующему шаблону:
ИмяПроцесса_Релиз_АдресОшибки_ГГГГММДДЧЧММСС_PIDПроцесса.mdmp
ГГГГММДДЧЧММСС – это дата и время падения, в нашем примере это 2013.10.25 16:24:41
Обычно каждая ошибка, из-за которой происходит падение, имеет свой уникальный АдресОшибки.
Т.е. если у двух дампов одинаковый процесс, релиз и адрес ошибки, то скорее всего причина падения одна и та же.
Из названия дампа, мы знаем точное время падения, теперь необходимо выяснить, что происходило в это время в системе, и здесь нам помогут логи ТЖ.
ТЖ пишется в отдельный каталог для каждого процесса, имя каталога формируется по шаблону ИмяПроцесса_PIDПроцесса.
Имя файла лога формируется по следующему шаблону ГГММДДЧЧ.log
Что бы узнать, что привело к падению, находим каталог с логами покинувшего нас процесса. Мы легко это можем сделать т.к. в имени файла дампа есть имя и PID процесса.
В данном случае нам нужен каталог rphost_3348.
Теперь в указанном каталоге нужно найти тот лог, в который писалась информация в момент падения. Опять же берем время падения из имени дампа, и таким образом находим файл лога 13102516.log
Открываем файл лога и ищем строку rphost_8.2.18.102_7c938235_20131025162441_3348
В моем случае в логе написано следующее:
0,EXCP,3,process=rphost,p:processName=Test,t:clientID=2,t:applicationName=1CV8C,t:computerName=AND-SERVER,t:connectID=196,SessionID=4,AppID=1CV8C,OSException=rphost_8.2.18.102_7c938235_20131025162441_3348,Context=’Форма.Вызов : ВнешняяОбработка.ВнешняяОбработка1.Форма.Форма.Модуль.Крах
Форма.Форма.Форма : 5 : Крах();
Форма.Форма.Форма : 5 : Крах();
Форма.Форма.Форма : 5 : Крах();
Форма.Форма.Форма : 5 : Крах();
Форма.Форма.Форма : 5 : Крах();
…
EXCP – это событие означает, что в системе возникло какое-либо исключение, далее через запятую перечислены свойства этого события, перечислим основные из них.
Process – имя процесса, где возникло исключение
processName – имя информационной базы
applicationName – клиент с которого пришел вызов, приведший к падению, в данном случае это тонкий клиент
computerName – имя компьютера, на котором был запущен клиент
Context – код, который выполнялся в момент падения, это самое важное для нас событие.
С помощью контекста иногда (но реже чем хотелось бы) удается понять причину ошибки.
В моем случае причина падения очевидна, это бесконечная рекурсия.
Данный пример конечно слишком простой и достаточно редко встречается в реальной жизни, хотя иногда бывает.
Рассмотрим другой пример
В версии 8.2.13 есть одна очень популярная ошибка при работе с объектом «СистемнаяИнформация»
Контекст ТЖ выглядит примерно так:
Context=’Инфо = Новый СистемнаяИнформация;
Текст = «Версия 1С » + Инфо.ВерсияПриложения;’
На первый взгляд ничего криминального здесь нет, но надо помнить, что 1С это многопользовательская система, и объекты должны быть спроектированы с учетом параллельности работы пользователей, как раз здесь часто и ошибаются разработчики платформы.
Причем ошибки, возникающие в момент одновременного обращения к объекту нескольких пользователей, встречаются достаточно часто, и если у вас уже образовалось несколько дампов, и при этом в контексте фигурирует один и тот же объект (в данном примере СистемнаяИнформация), то скорее всего это как раз тот случай.
Обход проблемы очень прост, нужно просто закомментировать обращение к объекту. В данном случае это не проблема, т.к. обычно без системной информации вполне можно обойтись.
Что делать, если понять причину падения по логам самостоятельно не удается?
Вы конечно можете обратиться в тех. поддержку 1С, но это, мягко говоря, не самый быстрый способ 🙂
Есть и более быстрый вариант, все что требуется, это разместить на партнерском форуме пост с описанием вашей проблемы, и желательно сразу дать ссылку на архив с дампом и логами либо прикрепить его к сообщению.
Если вы не работаете во франчайзи и у вас нет доступа на партнерский форум, то наверняка у вас есть друзья или знакомые, которые там работают.
Это намного более быстрый способ, чем обращение через тех. поддержку или решение проблемы методом научного тыка.
На партнерском форуме на ваши вопросы отвечают не только специалисты, которые возможно уже сталкивались с такой проблемой, но и сами разработчики платформы.
При обращении на форум, обязательно указывайте следующую информацию:
- Ссылки на архив с дампом и логами для скачивания
- Версию и разрядность серверной ОС
- Разрядность сервера 1С
- Количество серверов в кластере
- Количество запущенных рабочих процессов на сервере 1С
- Версию используемой СУБД
Related Posts
Восстановление последовательности документов при закрытии месяца в Бухгалтерия 3.0 не завершается
Заполнение табличных частей
Формирование сводных актов выполненных работ
Ввод поступления в переработку на основании передачи сырья (между организациями)- Конспект по установке сервера 1С на linux
Получение имени компьютера и его IP локально и в терминале
… и следить за ним, не отрывая глаз 🙂 у нас при наших объёмах технологический журнал может сначала работать спокойно полдня, а потом резко (меньше, чем за час) съесть всё место на диске (100+ ГБ), что не только не даст ответа на вопрос, что рухнуло, но и порушит всё остальное. Перепробовали разные настройки — ничего нас не спасает пока что.
В среднем процессы падают 3-4 раза в неделю. Платформа 8.2.18.82, сервер 64х.
(1) baton_pk, а если обновить сервер на более позднюю версию? Ну а вдруг там все исправили )))
(2) Famza,
С такими надеждами мы обновлялись предыдущие два раза.
(1) baton_pk, Такой неравномерный рост файлов ТЖ, скорее всего, вызван спецификой работы Ваших пользователей. Ищите, что «особенное» происходит в периоды такого роста ТЖ. Для этого можно, например, настроить лог только части событий.
(4) kapustinag,
Я не спорю. Пишу лишь о том, что в нашем случае на это надо выделить целого человека на хороший промежуток времени, чего наша компания позволить себе не может. С наскоку одолеть не получается, настроек перепробовали довольно много. Пока что для нас целесообразней плюнуть на всё это — ну вылетает 3-4 раза за неделю один процесс из 8 — это ладно, а порушить экспериментами сразу весь сервер пару раз в неделю — это плохой вариант.
(1) baton_pk,
ТЖ может расти только по одной причине, у вас включена регистрация кучи событий, большинство из которых вам скорее всего не нужны.
Сделайте logcfg таким как написано в статье, тогда ТЖ не будет расти, т.к. эти события возникают редко.
После очередного падения пришлите мне собранные логи, возможно удастся что-то найти.
(6)
Пробовали весной такой лог. Никакой закономерности: процесс может рухнуть и без единого EXCP, процесс может быть повально завален EXCP (у нас тучи конфликтов блокировок), раздувать лог, занимать место, но работать всю неделю без сбоев.
Попробую на неделе — может, Вы увидите в этих логах больше, чем мы.
(7) baton_pk,
Ок, только присылайте логи всех процессов, а не только упавшего.
(8) само собой.
Я один такой?
А куда это — сюда? На сколько я понимаю, там ссылочка должна быть?
(10) Tedman,
Да должна быть ссылка, вот такая
Позвольте мне вставить 5 копеек, когда мы сделали сервис хранения логов ТЖ (по событиям EXCP), то выяснились удивительные вещи:
1) не все ошибки — ошибки, многие были либо предупреждающими сообщениями, либо вообще «информационном мусором», например частое сообщение про «разделитель»
2) мы сделали фильтр по «откидываю» уже после первой загрузки тех сообщений, которые «бестолковые», это существенно повысило читаемость реальных проблем
3) ввели классификацию по важности — это позволяет не переключать внимание на «ненужное»
4) смотрим графики динамики изменения количества — это иногда дает больше информации, чем сама ошибка
5) отдельное внимание уделяем сообщениям, где есть упоминание имени файла дампа
(12) Gilev.Vyacheslav,
1 — именно поэтому я и написал в статье, что данное событие возникает при наличии исключения, а не при наличии ошибки. Исключение может возникать и в штатном режиме и никак не указывать на ошибку.
Надеюсь что в будущем эту ситуацию исправят, и сделают дополнительные события которые позволят более точно идентифицировать проблемы.
P.S.
И да, я подозревал что и здесь вы не упустите шанса попиарить свои разработки -)
(13) кажется, что здесь дан бесплатный полезный совет, коллега поделился опытом. Да и пиар — это вовсе не зло 🙂
(14) Evil Beaver,
Да я и не злюсь, просто удивляюсь этакой вездесущности 🙂
Кстати сам рекомендую пользоваться сервисами Вячаслава, благо они пока бесплатные.
(15) стараюсь всеми силами сохранить сервисы бесплатными (ошибки платформы, это не то, на чем надо зарабатывать имхо), единственное, что мы уже точно решили сделать платным — это старые архивы, данные набегают уже десятками террабайт
Про «уникальный АдресОшибки». Если правильно понимаю, на самом деле это адрес смещения в рабочем процессе, где возникло исключение. Но есть хоть и маленькая вероятность, но все же что причины исключения могут быть разными. В разных версиях платформы у одной и той же ошибки эти смещения могут меняться. Но это я так, скорее «поумничать». Мне вот сейчас идея пришла сделать классификатор этих смещений, но нужна коллективная помощь в заполнении интерпретаций. Сами в одиночку не осилю.
(16) Gilev.Vyacheslav,
Именно поэтому я и написал что если процесс, версия и адрес одинаковые, тогда это скорее всего одна и та же ошибка, исключения бывают но это редкость.
Идея хорошая, в 1С такой классификатор есть, знали бы вы какого труда мне стоило его заполнить 🙂
Но файла этого у меня к сожалению нет, а если бы и был, то не уверен что было бы законно его публиковать в открытом доступе.
Согласен, но ситуация со стабильностью к сожалению оставляет желать лучшего, особенно в больших системах.
Вам не хуже меня известно, что иногда запускаются целые проекты не с целью ускорения, а с целью стабилизации системы. Проект с Enter яркий тому пример.
Если бы 1С публиковало такой же классификатор дампов, как публикует номера ошибок, это был бы большой плюс к карме, и возможно baton_pk сразу бы увидел решение или обход своей проблемы.
Полезная статья.
Отдельное спасибо за название и картинку )))
Спасибо, полезно. Попробуем.
Это просто гейзенбаг какой-то! После включения журнала ни один процесс до сих пор внепланово не рухнул!
(21) baton_pk,
Знает что за ним наблюдают -)
(21) baton_pk, это хорошее имеет свойство заканчиваться, а плохое никогда само просто так не уходит, терпение мой друг, терпение…
Спасибо большое, хотя так хочется надеяться, что не пригодится 🙂
(22) (23) Gilev.Vyacheslav,
Одно ваше присутствие заставляет наш сервак пахать без перебоев уже третью неделю!
А если серьёзно, отключили за пару дней до этого один из наших злосчастных сделанных на скорую руку самописных COM-обменов — видимо, дело было в нём. Надо будет запустить его обратно после сдачи отчётности 🙂
(25) baton_pk,
Действительно очень может быть из за COM-обмена.
Уже сейчас можете посмотреть если что-то похожее в списке ошибок для вашего релиза.
(26)
насколько я слежу за ошибками, проблемы с COM у них вечны.
Я рекомендую следующую стратегию использования техножурнала в случае, если он очень сильно растет. Сначала включаете запись только события EXCP и EXCPCNTX и накапливаете статистику по ним. Это обычно очень небольшой объем данных. Затем на основе анализа накопленных событий EXCP включаете и другие события в зависимости от типа исключения и ваших знаний о платформе, но при этом вы включаете узкую фильтрацию по свойствам этих событий, используя информацию из событий EXCP (например по имени пользователя, длительности, базе и т.д.).
Но признаюсь, что такой подход требует определенного опыта и даже в этом случае иногда оказывается неэффективен.
(27) baton_pk, Многие проблемы удалось избежать добавив пользователей в группу «Пользователь DCOM». К сожалению, не все проблемы решены.
(29) gorodok11,
у нас все COM-обмены работают в фоновых заданиях на сервере, служба сервера 1С работает под локальным админом, под клиентами COM-обменов нет.
Таки рухнуло! Притом довольно жестоко — файлы с дампами забили всё свободное место (~80 ГБ).
Дампы пришлось убить, но ничего страшного — после перезапуска тут же снова рухнуло и дало ещё чуток дампов.
Полезу, посмотрю, чего там в журналах интересного.
(31) baton_pk,
Выкладывайте сюда, тоже посмотрим
(32)
0800 — тех.журнал до 08.00, я его запаковал и прибил. и дампы прибил — место надо было чистить
0950 — тех.журнал на текущий момент. есть дампы
по свежему журналу можно смотреть только файлы с 8-м часом, в 9, когда я отключил в одной из баз все-все-все COM-обмены, всё стало тихо.
В текстовом файле «бортовой журнал». Там выдержки из техжурнала и хронология падения процессов.
Попробую изменить настройку
Показать
и через полчасика запустить один из обменов
(34) baton_pk,
Настройка не отображается, лучше сделать скрин
По крайней мере удалось локализовать проблему, теперь известна причина
В принципе с этим уже можно обращаться на партнерский форум.
(35)
Есть такая беда — если в комментариях к публикации, то не отображаются, а если на форуме, всё в порядке:
Ну, процентов на 99 мы и так грешили именно на COM-обмены 🙂
Дык надо сейчас как-то это обойти 🙂 Негоже, чтобы обмены стояли целый день.
Запустил с клиента COM-обмен, процесс рухнул. Удалил из лога всё, что было ДО запуска, лог прикладываю.
Лог только упавшего процесса.
А нельзя отказаться от СОМ обменов? С точки зрения интеграции это самый большой костыль который можно представить. Если нужна онлайновость, то веб-сервисы как раз то, что надо.
(37) dmitry-gr,
Веб-сервисы ещё делать надо 🙂 Это уже должно начальство решать. Моя смертная задача — решать возникшую проблему с существующими обменами. Но, да, COM-обмены — ещё то зло и надо от них уходить. С другой стороны, трудозатраты на перекраивание системы под веб-сервисы сильно превышают трудозатраты на периодические костыли при падениях.
Хотя может после нынешнего падения всё изменится. Первый раз так, что сижу уже четвёртый час и даже зацепок нет, какую заплатку и куда поставить!
(38) baton_pk,
У вас что полный тех. журнал пишется?
Зачем вам запросы и вызовы сервера, так никакого места на дисках не хватит.
По логам тут мало что видно к сожалению, т.к. это как раз тот случай когда контекста нет.
Все же я вам советую задать вопрос на форуме, возможно это уже известная проблема.
(39)
Там фильтр на одну базу и на COM-Соединения.
Всё оказалось банально просто: в выгрузке появился документ, которым с лохматых времён никто не пользовался и который пытается провестись и выдаёт ошибки. Опять же вернулись к пресловутому «Сообщить» под внешним соединением. Вот только если в первые разы я это отлавливал по тех.журналу, то сегодня пришлось работать методом тыка. Убрал из выгрузки данный вид документа и попёрло: 15 минут, полёт нормальный.
(41) baton_pk,
Поздравляю с успешно решенной проблемой 🙂
(42)
Это не решение, это обход.
Ну в вашем случае обход это единственно возможное решение -)
Если не считать переход на версию где эта ошибка исправлена.
(41) Можно подробнее про это «Сообщить»?
(45) tormozit,
в первый раз на это чудо я наткнулся в таком виде:
50:43.4032-0,EXCP,1,process=1cv8,Usr=Робот-ОбменУТ,OSException=1cv8_8.2.17.169_7735e45c_20130305135043_7112,Context=’
Обработка.УниверсальныйОбменДаннымиXML.МодульОбъекта : 12363 : ЗаписатьВПротоколВыполнения(«Начало загрузки: » + ТекущаяДатаСеанса(), , Ложь, , , Истина);
Обработка.УниверсальныйОбменДаннымиXML.МодульОбъекта : 1526 : СообщитьПользователю(ИтоговаяСтрокаДляЗаписи);
Обработка.УниверсальныйОбменДаннымиXML.МодульОбъекта : 14266 : Сообщение.Сообщить();’
50:43.4033-0,EXCPCNTX,0,ClientComputerName=SRV1C,ServerComputerName=SRV1C,UserName=Робот-ОбменУТ,ConnectString=’Srvr=»srv1c:1641″;Ref=»upp_rs»;’,Context=’
Обработка.УниверсальныйОбменДаннымиXML.МодульОбъекта : 12363 : ЗаписатьВПротоколВыполнения(«Начало загрузки: » + ТекущаяДатаСеанса(), , Ложь, , , Истина);
Обработка.УниверсальныйОбменДаннымиXML.МодульОбъекта : 1526 : СообщитьПользователю(ИтоговаяСтрокаДляЗаписи);
Обработка.УниверсальныйОбменДаннымиXML.МодульОбъекта : 14266 : Сообщение.Сообщить();’
50:43.4034-3,EXCPCNTX,0,SrcName=SCALL,OSThread=9488,process=1cv8,Usr=Робот-ОбменУТ,ClientID=4,Interface=90b77326-8e4a-4195-b980-d758277d1f03,Method=0,Context=’
Обработка.УниверсальныйОбменДаннымиXML.МодульОбъекта : 12363 : ЗаписатьВПротоколВыполнения(«Начало загрузки: » + ТекущаяДатаСеанса(), , Ложь, , , Истина);
Обработка.УниверсальныйОбменДаннымиXML.МодульОбъекта : 1526 : СообщитьПользователю(ИтоговаяСтрокаДляЗаписи);
Обработка.УниверсальныйОбменДаннымиXML.МодульОбъекта : 14266 : Сообщение.Сообщить();’
50:48.3331-0,EXCP,1,process=1cv8,Usr=Робот-ОбменУТ,DumpFile=C:Program Files (x86)1cv82conf\1cv8_8.2.17.169_7735e45c_20130305135043_7112.mdmp,Context=’
Обработка.УниверсальныйОбменДаннымиXML.МодульОбъекта : 12363 : ЗаписатьВПротоколВыполнения(«Начало загрузки: » + ТекущаяДатаСеанса(), , Ложь, , , Истина);
Обработка.УниверсальныйОбменДаннымиXML.МодульОбъекта : 1526 : СообщитьПользователю(ИтоговаяСтрокаДляЗаписи);
Обработка.УниверсальныйОбменДаннымиXML.МодульОбъекта : 14266 : Сообщение.Сообщить();’
Показать
В основном проблемы возникают, когда при COM-обмене пытаемся провести документ и этот документ пытается нам чего-то сказать. В частности, когда не может провестись.
Попробую смоделировать ошибку и вышлю более подробные сведения.
Спасибо, Андрей! Статья на все времена — до скончания платформы 1С.
Вот только одно замечание: т.к. мы не собираемся анализировать дамп в отладчике (у нас ведь нет файлов .pdb с отладочной информацией), то надо использовать тип дампа «минимальный» — от дампа мы хотим получить только номер упавшего процесса.
Т.е. вместо <dump create=»true» location=»бла-блаdumps» type=»3″/>
используйте <dump create=»true» location=»бла-блаdumps» type=»0″/>
Значение type=»0″ указано для платформы 8.3.16, подробнее смотреть «Рук-во админа. Приложение 3»
3.21.2.5. Элемент <dump>
(47)
Если вы не собираетесь отправлять дапм в тех. поддержку, тогда да, достаточно и минимального. Но как правило дампы отправляются в 1С, а там требуют именно полные дампы для анализа.
Почему надо использовать тип дампа «минимальный» ? — содержимое дампа нам «до фонаря», из имени файла дампа получим имя модуля, время падения, адрес в памяти, номер (PID) упавшего процесса.
цитирую пункт «3.21.2.5. Элемент <dump>»
Атрибут «type» (применяется только для ОС Windows)
Тип дампа, произвольная комбинация приведенных ниже флажков (т.е. это битовая маска), представленная в десятичной или шестнадцатеричной системе. Значение атрибута «type» получается сложением значений, указанных ниже. Представление в шестнадцатеричной системе должно начинаться с символа ‘x’, например, x0002.
Доступны следующие значения:
0 (x0000) ‑ минимальный;
1 (x0001) ‑ дополнительный сегмент данных;
2 (x0002) ‑ содержимое всей памяти процесса;
4 (x0004) ‑ данные хэндлов;
8 (x0008) ‑ оставить в дампе только информацию, необходимую для восстановления стеков вызовов;
16 (x0010) ‑ если стек содержит ссылки на память модулей, то добавить флажок флаг 64 (0x0040);
32 (x0020) ‑ включить в дамп память из-под выгруженных модулей;
64 (x0040) ‑ включить в дамп память, на которую есть ссылки;
128 (x0080) ‑ добавить в дамп подробную информацию о файлах модулей;
256 (x0100) ‑ добавить в дамп локальные данные потоков;
512 (x0200) ‑ включение в дамп памяти из всего доступного виртуального адресного пространства.
конец цитаты из доки.
Включение в тип значения «2 (x0002) ‑ содержимое всей памяти процесса» резко увеличивает размер файла дампа.
(49) использовать нужно тот тип, который решает вашу задачу, о чем и сказано в ответе (48).
(50)
Андрей слишком обобщает — анализировать содержимое дампа могут только сотрудники 1С, если вы решаете проблему краха процессов платформы 1С и собираете дампы и ТЖ под руководством службы техн.поддержки 1С, то мои замечания не важны абс-но, они написаны для тех, кто точно не будет обращаться в ТП 1С, а будет пытаться самостоятельно анализировать ТЖ — не так уж это сложно, хотя требует хороших навыков и «быстрого» (т.е. который не «тормозит») ума. Для избежания ситуации исчерпания дискового места файлами дампов, я бы даже сделал виндовое задание, которое по расписанию выполняло: 1) сохранить в текстовом файле список файлов дампов 2) удалить те дампы, которые на 1-м шаге были записаны в файл протокола.
(51)
Вы молодец )))