Кратко: выделенный достаточно мощный сервер, конфигурация УТ 10.3, платформа 8.3.22, MS SQL Server 2019, в базе работает более 40 человек, база весит 34 Гб, более 400 документов продажи в день (плюс другие документы движений товаров).
При проведении документов продажи периодически (какое-то время нормально, потом день/два все плохо, и так по кругу) вываливались ошибки:
- "Конфликт блокировок при выполнении транзакции" - 2 разных вида ("Превышено время ожидания запроса на блокировку" и "Транзакция (идентификатор процесса ...) вызвала взаимоблокировку ресурсов блокировка с другим процессом и стала жертвой взаимоблокировки");
- вылетала база у пользователей с неполными правами.
Решилось созданием плана обслуживания обновлением статистики и очисткой кэша в MS SQL Server Management Studio. Также есть еще 2 других плана, которые выполняются раз в неделю.
Изначально выполнение плана обновления статистики настроил раз в сутки.
Данная проблема не исчезла, периодически появляется. Вернее самой ошибки уже вроде нет про блокировку (хотя база у кассиров вылетает иногда), но периодически проведение документа жутко тормозит.
В итоге план перенастроил на раз в несколько часов, потом ..., потом ... ... . Сейчас план выполняется раз в 30 минут (о Боже!). НО! Периодические зависания никуда не ушли.
Пока писал этот топик, пришла мысль, что возможно это может совпадать с автовыгрузкой на сайт (т.к. остатки выгружаются), но это всего лишь предположение (последний раз смотрел время выполнения регламентного задания выгрузки на сайт и зависаний - время не совпало, разница была минут в 30 между, но еще проверю).
В общем, как можно решить данную проблему?
Пока у меня есть 2 вариант:
- переписать проведение реализации полностью, используя новый метод контроля остатков, как это сделано в новых конфигурациях;
- обрезать базу.
По 1-му варианту - ну очень амбициозная задача + почитал статьи, и понял, что скорее всего не получится, т.к. вроде есть проблема при списании партий по ФИФО (вроде как главное условие использование нового метода, это на момент проведения все данные уже должны быть, не нужно их ниоткуда считывать).
В обще решил следующим способом (мне нужно было максимально быстро решить проблему с зависаниями, без переписывания конфигурации, детальным разбирательством данной проблемы и пр.).
Как правило зависания были про списывании партий товаров. В настройка учета был включен флаг "Списывать партии при проведении документов".
Отключил настройку, и это помогло.
Правда теперь в отчете "Валовая прибыль" будет не совсем актуальная информация, но это не проблема, он нужен нам раз в месяц, поэтому раз в месяц делается восстановление последовательности документов, и все вроде работает как надо.
Вы бы того, тех. журнал там включили, что ли. Ну не хватает данных.
Вы даже не упомянули какие у вас блокировки - автоматические или управляемые.
Поэтому общие соображения:
1. Если у вас нет массовой вставки/удаления, то увеличение частоты обновления статистики ничего не даст.
Не говоря уж о том, что вы также умолчали о том, как у вас установлены такие параметры как AUTO_CREATE_STATISTICS и AUTO_UPDATE_STATISTICS.
2. Постоянный сброс кэша - очень плохая идея с точки зрения производительности.
Это косвенно, заставляя каждый раз перестраивать планы для всех запросов, может дать обратный эффект и вы получите блокировку уже по другой причине.
Надо искать первопричину головной боли.
3. Вариант работает-неработает и то, что все же спрос кэша помогает наводит на мысль, что периодически выполняется запрос с разной селективностью - вот у вас и использование плана запроса из кэша, рассчитанного совсем на другое, дает подобный эффект.
Вывод тут один -смотрите какие запросы у вас выполняются при проведении, с каким планом, и прикиньте, что будет в подобных случаях, если изменится вышеупомянутое.
Почитайте про "Зависание проведения документа при неоптимальных планах запросов из‑за Parameter sniffing в MS SQL", тут была статья - очень похоже на вашу причину.
4. Даже, если п.3 имеет место, напрямую на конфликт блокировок он бы не повлиял,
скорее уж на отмену из-за превышения времени ожидания завершения транзакции.
Хотя, тут уже попадаем на другой ваш вариант - все заработало но меееедленно.
Следовательно - где-то грубая ошибка в коде. А из-за увеличения времени запроса увеличивается и вероятность "не проскочить".
Да и то, что это наблюдается из-под пользователей не с полными правами, возможно также связано с увеличением времени и затронутых объектов из-за RLS, вы, правда, про RLS тоже скромно умолчали.
Проводятся новые и перепроводятся (не раз) уже ранее записанные (вносятся доп. данные позже).
Только проведений/перепроведений реализаций более 600 + другие документы движения остатков.
Уже записанные перепроводятся дольше (очень значительно дольше).
РегистрСведений.СписанныеТовары
Ошибка при вызове метода контекста (Записать): Конфликт блокировок при выполнении транзакции:
Microsoft SQL Server Native Client 11.0: Превышено время ожидания запроса на блокировку.
HRESULT=80040E31, SQLSrvr: SQLSTATE=HYT00, state=33, Severity=10, native=1222, line=1
РегистрСведений.СписанныеТовары
Ошибка при вызове метода контекста (Записать): Конфликт блокировок при выполнении транзакции:
Microsoft SQL Server Native Client 11.0: Превышено время ожидания запроса на блокировку.
HRESULT=80040E31, SQLSrvr: SQLSTATE=HYT00, state=33, Severity=10, native=1222, line=1
Полез в технологический журнал, вот кусок записи (компьютер и пользователь заменен) (в логе уже есть ошибки по взаимоблокировке):
00:34.752000-0,EXCP,6,process=rphost,p:processName=Trade103,OSThread=208832,t:clientID=308636,t:applicationName=1CV8,t:computerName=[Comp],t:connectID=169440,SessionID=560,Usr=[Usr],DBMS=DBMSSQL,DataBase=[Comp]\Trade103,dbpid=59,Exception=DataBaseException,Descr='Конфликт блокировок при выполнении транзакции:
Microsoft SQL Server Native Client 11.0: Транзакция (идентификатор процесса 59) вызвала взаимоблокировку ресурсов блокировка с другим процессом и стала жертвой взаимоблокировки. Запустите транзакцию повторно.
HRESULT=80004005, SQLSrvr: SQLSTATE=40001, state=30, Severity=D, native=1205, line=1
',Context='
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 4606 : ВыполнитьСписание(СтруктураПараметров, ТаблицаСписания, ДокументМоментВремени, Останавливаться, ПроведениеОстановлено);
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 3661 : ЗаписатьДвиженияДокумента(СтруктураПараметров, ТаблицаСписания, Истина);
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 768 : ЗаписатьДвиженияДокументаУпр(СтруктураПараметров, ТаблицаСписания, Замещать);
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 670 : ЗаписатьДвижения(СтруктураПараметров.ДвиженияПартииТоваровНаСкладахУпр,
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 636 : ДвиженияРегистра.Записать(Истина);'
00:34.752001-15827960,DBMSSQL,5,process=rphost,p:processName=Trade103,OSThread=208832,t:clientID=308636,t:applicationName=1CV8,t:computerName=[Comp],t:connectID=169440,SessionID=560,Usr=[Usr],DBMS=DBMSSQL,DataBase=[Comp]\Trade103,Trans=1,dbpid=59,Sql='INS ERT IN TO dbo._AccumRg8581 WITH(SERIALIZABLE) (_Period,_RecorderTRef,_RecorderRRef,_LineNo,_Active,_RecordKind,_Fld8582RRef,_Fld8583RRef,_Fld8584RRef,_Fld8585RRef,_Fld8586_TYPE,_Fld8586_RTRef,_Fld8586_RRRef,_Fld8587RRef,_Fld8588RRef,_Fld8589RRef,_Fld8590,_Fld8591,_Fld8592RRef,_Fld8593,_Fld8594,_Fld8595_TYPE,_Fld8595_RTRef,_Fld8595_RRRef,_Fld8596,_Fld8597) VALUES(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)',Prm='
p_0: 40240704160018
p_1: 0x000000E0
p_2: 0xA8D9AC1F6BF1071311EF39C6BB468B04
p_3: 1N
p_4: TRUE
p_5: 1N
p_6: 0xBB600025111C0EB711DED4EE17677B6B
p_7: 0x831074D43558A2E711E6D9860B48185D
p_8: 0x00000000000000000000000000000000
p_9: 0x00000000000000000000000000000000
p_10: 0x08
p_11: 0x000000BD
p_12: 0xA8D7AC1F6BF1071311EF028AD33D9094
p_13: 0x8F435A1228BDACD2403F1434B4850FC4
p_14: 0x00000000000000000000000000000000
p_15: 0xA79841EBE5E5B977449B6BCED05404A0
p_16: 1N
p_17: 21N
p_18: 0xBD0CAF2D5369CABF40799FE444718DD5
p_19: TRUE
p_20: 1N
p_21: 0x01
p_22: 0x00000000
p_23: 0x00000000000000000000000000000000
p_24: 20010101000000
p_25: 1N
',Context='
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 4606 : ВыполнитьСписание(СтруктураПараметров, ТаблицаСписания, ДокументМоментВремени, Останавливаться, ПроведениеОстановлено);
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 3661 : ЗаписатьДвиженияДокумента(СтруктураПараметров, ТаблицаСписания, Истина);
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 768 : ЗаписатьДвиженияДокументаУпр(СтруктураПараметров, ТаблицаСписания, Замещать);
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 670 : ЗаписатьДвижения(СтруктураПараметров.ДвиженияПартииТоваровНаСкладахУпр,
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 636 : ДвиженияРегистра.Записать(Истина);'
00:34.752004-15827966,SDBL,4,process=rphost,p:processName=Trade103,OSThread=208832,t:clientID=308636,t:applicationName=1CV8,t:computerName=[Comp],t:connectID=169440,SessionID=560,Usr=[Usr],DBMS=DBMSSQL,DataBase=[Comp]\Trade103,Trans=1,Func=insertRecords,tableName=AccumRg8581,Sdbl='
INSERT AccumRg8581 (Period,Recorder,LineNo,Active,RecordKind,Fld8582,Fld8583,Fld8584,Fld8585,Fld8586,Fld8587,Fld8588,Fld8589,Fld8590,Fld8591,Fld8592,Fld8593,Fld8594,Fld8595,Fld8596,Fld8597)
VALUES(
(DATETIME(2024,7,4,16,0,18),224:A8D9AC1F6BF1071311EF39C6BB468B04,1,TRUE,1,72:BB600025111C0EB711DED4EE17677B6B,91:831074D43558A2E711E6D9860B48185D,110:00000000000000000000000000000000,88:00000000000000000000000000000000,189:A8D7AC1F6BF1071311EF028AD33D9094,419:8F435A1228BDACD2403F1434B4850FC4,149:00000000000000000000000000000000,57:A79841EBE5E5B977449B6BCED05404A0,1,21,358:BD0CAF2D5369CABF40799FE444718DD5,TRUE,1,UNDEFINED,DATETIME(1,1,1,0,0,0),1))
',Context='
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 4606 : ВыполнитьСписание(СтруктураПараметров, ТаблицаСписания, ДокументМоментВремени, Останавливаться, ПроведениеОстановлено);
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 3661 : ЗаписатьДвиженияДокумента(СтруктураПараметров, ТаблицаСписания, Истина);
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 768 : ЗаписатьДвиженияДокументаУпр(СтруктураПараметров, ТаблицаСписания, Замещать);
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 670 : ЗаписатьДвижения(СтруктураПараметров.ДвиженияПартииТоваровНаСкладахУпр,
ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль : 636 : ДвиженияРегистра.Записать(Истина);'
00:34.767000-15889836,CALL,3,process=rphost,p:processName=Trade103,OSThread=208832,t:clientID=308636,t:applicationName=1CV8,t:computerName=[Comp],t:connectID=169440,SessionID=560,Usr=[Usr],callWait=0,first=0,Interface=fd7b6cc2-dc8e-11d2-b8d0-008048da0335,IName=IContext_,Method=16,CallID=29475,MName=call,RetExcp='{ОбщийМодуль.УправлениеЗапасамиПартионныйУчет.Модуль(636)}: Ошибка при вызове метода контекста (Записать)
f08d92f8-9eb2-4e19-9dd9-977d907cec2d
Конфликт блокировок при выполнении транзакции:
Microsoft SQL Server Native Client 11.0: Транзакция (идентификатор процесса 59) вызвала взаимоблокировку ресурсов блокировка с другим процессом и стала жертвой взаимоблокировки. Запустите транзакцию повторно.
HRESULT=80004005, SQLSrvr: SQLSTATE=40001, state=30, Severity=D, native=1205, line=1
',Memory=6672,MemoryPeak=1742112,InBytes=0,OutBytes=0,CpuTime=46875
00:34.767002-0,Context,3,process=rphost,p:processName=Trade103,OSThread=208832,t:clientID=308636,t:applicationName=1CV8,t:computerName=[Comp],t:connectID=169440,SessionID=560,Usr=[Usr],Context='
Документ.РеализацияТоваровУслуг.МодульОбъекта : 7247 : ДвиженияПоРегистрам(РежимПроведения, СтруктураШапкиДокумента, ТаблицаПоТоварам, ТаблицаПоСкидкам, ТаблицаПоТаре,
Документ.РеализацияТоваровУслуг.МодульОбъекта : 5704 : УправлениеЗапасамиПартионныйУчет.ДвижениеПартийТоваров(Ссылка, Движения.СписанныеТовары.Выгрузить());'
00:34.767010-0,EXCP,4,process=rphost,p:processName=Trade103,OSThread=208832,t:clientID=308636,t:applicationName=1CV8,t:computerName=[Comp],t:connectID=169440,SessionID=560,Usr=[Usr],DBMS=DBMSSQL,DataBase=[Comp]\Trade103,dbpid=59,Exception=DataBaseException,Descr='Соединение с сервером баз данных разорвано администратором
Выполнение оператора KILL не привело к ошибке СУБД'
00:34.767011-0,EXCPCNTX,0,ClientComputerName=[Comp],ServerComputerName=[Comp],UserName=Морина Мария,ConnectString='Srvr="[Comp]";Ref="Trade103";'
00:34.767012-5,EXCPCNTX,3,SrcName=CALL,process=rphost,p:processName=Trade103,OSThread=208832,t:clientID=308636,t:applicationName=1CV8,t:computerName=[Comp],t:connectID=169440,SessionID=560,Usr=[Usr],callWait=0,first=0
00:34.767013-16139981,EXCPCNTX,3,SrcName=SDBL,process=rphost,p:processName=Trade103,OSThread=208832,t:clientID=308636,t:applicationName=1CV8,t:computerName=[Comp],t:connectID=169440,SessionID=560,Usr=[Usr],DBMS=DBMSSQL,DataBase=[Comp]\Trade103,Trans=0,Func=Transaction
00:34.767014-16139983,EXCPCNTX,2,SrcName=SDBL,process=rphost,p:processName=Trade103,OSThread=208832,t:clientID=308636,t:applicationName=1CV8,t:computerName=[Comp],t:connectID=169440,SessionID=560,Usr=[Usr],DBMS=DBMSSQL,DataBase=[Comp]\Trade103,Trans=0,Func=HoldConnection
00:34.767015-378509992,EXCPCNTX,0,SrcName=CONN,process=rphost,OSThread=107432,t:clientID=308636
00:34.767016-0,EXCP,4,process=rphost,p:processName=Trade103,OSThread=208832,t:clientID=308636,t:applicationName=1CV8,t:computerName=[Comp],t:connectID=169440,SessionID=560,Usr=[Usr],DBMS=DBMSSQL,DataBase=[Comp]\Trade103,Exception=dc31263e-ecbf-41bd-9b3a-7b55897d5fd6,Descr='src\sqlsrvr\src\SQLOperations.cpp(4071):
dc31263e-ecbf-41bd-9b3a-7b55897d5fd6: Соединение с сервером баз данных разорвано администратором
Выполнение оператора KILL не привело к ошибке СУБД'
00:34.767017-16139985,SDBL,3,process=rphost,p:processName=Trade103,OSThread=208832,t:clientID=308636,t:applicationName=1CV8,t:computerName=[Comp],t:connectID=169440,SessionID=560,Usr=[Usr],DBMS=DBMSSQL,DataBase=[Comp]\Trade103,Trans=0,Func=Transaction,Func=RollbackTransaction
00:34.767030-16139999,SDBL,2,process=rphost,p:processName=Trade103,OSThread=208832,t:clientID=308636,t:applicationName=1CV8,t:computerName=[Comp],t:connectID=169440,SessionID=560,Usr=[Usr],DBMS=DBMSSQL,DataBase=[Comp]\Trade103,Trans=0,Func=HoldConnection
Показать
Думаю, из-за настроек журнала данных недостаточно (не все события включены), поэтому включил журнал на все события (все фильтры убрал), чтобы в следующий раз больше информации получить.
Т.к. опыта в разборе проблемы тормозов именно при записи в базу у меня особо нет, какие мои дальнейшие действия?
На вскидку - ежели у вас автоматические блокировки, то похоже накладывается блокировка на изменение при старом (при новом тоже, но позже) механизме контроля отрицательных остатков. Т.е. что-то читаете и 1С автоматом добавляет SELECT .. For Update.
Потом долго что-то делаете в этой же транзакции, держа записи.
В этот момент запускается второй процесс, блокирующий уже другие записи.
И пытается что-то записать в строки, удерживаемые 1-м процессом.
2-ой процесс пытается что-то записать, или повторно прочитать, в строки, удерживаемые 1-м процессом.
Совсем не обязательно в те, что он прочел, чтобы посмотреть остатки.
Получается печальный результат, в т.ч. и по правдивости деталей моего "объяснения", но общий смысл, думаю понятен.
Получается не всегда, а только, если один из процессов не успевает завершиться к моменту старта второго и записи пересекаются.
Причем пересекаться они могут не очевидно, например, просто из-за эскалации блокировок.
Иначе чаще будет, что просто один из процессов будет ждать завершения других и получится ваше "медленно проводится"
Вывод:
Попробуйте сперва ускорить процессы проведения, например, использовать новый механизм контроля отрицательных остатков. Да и вообще посмотрите на скорость отработки кода в механизмах проведения.
Массовое перепроведение документов и регламентные операции на сервере надо проводить во время минимальной загрузки базы.
1. Процесс process1950796f848 делает select из БД Trade103 из двух таблиц (таблиц может больше, но в графе о них ничего нет) dbo._AccumRg8581 и dbo._InfoRg7812
Для того, что бы получить данные из табличек были запрошены и установлены RangeS-S блокировки (разделяемая блокировка диапазона) на индексы _InfoRg7812_ByResource7872_RTRN, _AccumRg8581_ByPeriod_TRN в этих табличках, такая блокировка явилась следствием установленного для БД уровня изоляции isolationlevel=repeatable read
2. В этот момент, процесс process194dade8108 захотел вставить ОДНУ строку в табличку dbo._AccumRg8581 с хинтом WITH(SERIALIZABLE), что бы выполнилось условие SERIALIZABLE, была запрошена RangeI-N блокировка (Блокировка диапазона для вставки, аналог блокировка намерения) на индекс _AccumRg8581_ByPeriod_TRN и такая блокировка была получена, поскольку RangeI-N и RangeS-S являются совместимыми блокировками.
Затем процесс process194dade8108 (тот который делает insert) просит конвертировать свою RangeI-N блокировку в эксклюзивную Х
DataEngin посмотрел (там есть свой алгоритм) на это и прибил процесс, который хотел вставить запись.
Теперь, что делать.
1. Установить у БД read commited snapshot (вроде 1С рекомендует ставить по умолчанию, почему установлен repetable read надо спрашивать у того кто ставил.)
2. Если необходим repetable read, то сделать рефакторинг кода и проставить его там где он необходим.
Если автоматический режим - то в каком-то запросе (при контроле остатков?) отсутствует выражение "ДЛЯ ИЗМЕНЕНИЯ", которое и предназначено для решения таких вот дедлоков... А вообще в 24 году автоматический режим - это странно, переходите в управляемый со снапшотом, там такого не будет.
" использовать новый механизм контроля отрицательных остатков" как советуют выше без упр. режима не выйдет. Да оно и не надо, на старте хотя бы просто нормальный контроль сделать в управляемом режиме..
Ради интереса - в корне какой задан режим совместимости и режим управления блокировкой?
В обще решил следующим способом (мне нужно было максимально быстро решить проблему с зависаниями, без переписывания конфигурации, детальным разбирательством данной проблемы и пр.).
Как правило зависания были про списывании партий товаров. В настройка учета был включен флаг "Списывать партии при проведении документов".
Отключил настройку, и это помогло.
Правда теперь в отчете "Валовая прибыль" будет не совсем актуальная информация, но это не проблема, он нужен нам раз в месяц, поэтому раз в месяц делается восстановление последовательности документов, и все вроде работает как надо.
(13) Возможно отчасти проблема была в том, что висело много отрицательных остатков по партиям (такое бывает).
Я дописывал конфигурацию, чтобы по партиям были минуса (по закупочным ценам), чтобы можно было пользоваться отчетом "Валовая прибыль". Без этого, данные были бы не актуальны.
Почему минуса по партиям даже после восстановления последовательности - я не разбирался, т.к. эту доработку я делал много лет назад, за последовательностью не следили, и получили то что получили.
Возможно их обнуление и помогло бы (обнуление на дату чуть ранее даты проведения документов через документ "Корректировка регистров" по регистру накопления "Партии товаров на складах".