Блокирование потока в методе AddInfoLog()
07.03.2012
Суть проблемы:Если запустить экспорт и сразу же остановить, зависает вся система. Путем разбора полетов было выяснено что блокируется поток внутри метода AddInfoLog(). В итоге завершить остановку экспорта получается невозможно. Для логгирования используется GuiLogListener
Подробности:Ошибка возникает в версии AlfaPlus. Данную версию я еще не публиковал. Допиливаю. В ней реализованы следующие моменты:
- Данные от терминала поступают сначала в очередь. А потом из очереди забираются отдельным Task который очередь мониторит и обрабатывает.
- Данные от монитора очереди поступают в обертку для таблиц, которая поддерживает подписку на данные и отписку от получения данных. В этой таблице своя очередь, которая так же обрабатывается своим Task. На каждую таблицу данных имеем свою обертку и свой Task.
- Методы подписки на таблицу, отписки, и рассылки данных подписчикам реализованы через блокировки. То есть когда происходит подписка, блокируется рассылка данных и отписка от таблиц, и наоборот.
По факту имеем следующую проблему. Когда запустили экспорт StartExport(), в таблицу попадает порция данных и начинает обрабатываться, а затем рассылаться подписчикам. Поскольку процес включения подписки уже успевает закончиться к моменту начала рассылки данных, основной поток переходит к методу остановки экспорта StopExport(). Основной поток переходит к методу отписки от таблицы. В это же время Task этой же таблицы, отвечающий за обработку данных и рассылку по подписчикам, начинает передавать данные в подписчики. И первым делом в методе обработки данных подписчика вызывается запись в лог AddInfoLog(). Вот на этой записи и встает колом поток. А поскольку реализована блокировка при рассылке данных в подписчики, блокировка НЕ освобождается. ОТсюда метод отписки не может получить объект блокировки и тоже встает колом.
Дальнейшие изыскания привели к методу класса GuiLogListener:
Код
protected override void OnWriteMessage(LogMessage message)
{
var listener = _listener ?? _windows.SafeAdd(message.Source, s => _dispatcher.GuiSync(() =>
{
var w = new LogWindow { Title = s.ToString() };
w.Show();
return w;
}));
Action action = () => listener.WriteMessage(message);
if (_dispatcher != null)
_dispatcher.GuiSync(action); // <------ вот тут колом все и встает.
else
action();
}
Если посмотреть где окончательно встает колом поток, то получаем такую картину вызовов:
Код
System.Threading.WaitHandle.WaitOne(System.TimeSpan timeout, bool exitContext)
System.Windows.Threading.DispatcherOperation.DispatcherOperationEvent.WaitOne()
System.Windows.Threading.DispatcherOperation.Wait(System.TimeSpan timeout)
System.Windows.Threading.Dispatcher.InvokeImpl(System.Windows.Threading.DispatcherPriority priority, System.TimeSpan timeout, System.Delegate method, object args, int numArgs)
System.Windows.Threading.Dispatcher.Invoke(System.Delegate method, System.Windows.Threading.DispatcherPriority priority, object[] args)
Ecng.Xaml.XamlHelper.GuiSync(System.Windows.Threading.Dispatcher dispatcher, System.Action action, System.Windows.Threading.DispatcherPriority priority)
Из коннектора никаких выводов не может идти кроме вывода StopExport() и this.AddInfoLog("OnProcessSecurities {0}", data.ToString());
Это проверено. То есть либо конфликт происходит между этими двумя элементами лога или не знаю что сказать. Не понял еще в каком потоке заводится окно логгера. Если в том же что и основное окно тогда все ясно.
Нашел еще один подозрительный поток который связан с логами. Он висит на следующем коде
Код
class AsyncFlushList<TItem> : SynchronizedCollection<TItem>
{...
...
private void Flush(IEnumerable<TItem> items)
{
_isAddRange = true;
try
{
items.ForEach(Add);
}
finally
{
_isAddRange = false;
}
_parent.GuiSync(() => _added(items)); // <---- висим тут.
}
}
Очередь вызовов в общем схожая. Метод ждет освобождения блокировки.