Блокирование потока в методе AddInfoLog()

Нет, используется релизная 4.0.20 4.0 не удастся поддержать. Новый коннектор разве не в дев ветке ра...

2012-03-07T12:52:01Z

Mikhail Sukhov

ra81

Нет, используется релизная 4.0.20

4.0 не удастся поддержать. Новый коннектор разве не в дев ветке разрабатывается?

Вообще да, но я использую релизные либы. В принципе разобрался в чем проблема, благодаря положительному влияюнию Сергея на мою мозговую деятельность. Проблема очевидно была в том что главный поток блокировался, в результате блокировалось окно логгера. В лог нельзя было ничего написать, отсюда блокировался поток обрабатывающий данные. Взаимная блокировка.

Переписал часть классов, использовал спец. коллекции. Убрал не очень хорошо пахнущие блокировки. Код стал лучше и глюкать перестал. Проблему можно закрыть.

Нет, используется релизная 4.0.20 4.0 не удастся поддержать. Новый коннектор разве не в дев ветке ра...

2012-03-07T11:19:29Z

ra81

Нет, используется релизная 4.0.20

4.0 не удастся поддержать. Новый коннектор разве не в дев ветке разрабатывается?

Суть проблемы: Если запустить экспорт и сразу же остановить, зависает вся система. Путем разбора пол...

2012-03-07T11:17:22Z

Mikhail Sukhov

ra81

4.1? Там появился GuiDispatcher, проставляется в GuiLogListener. Его лучше использовать. Он и асинхронен, и быстрее маршалинг делает.

Нет, используется релизная 4.0.20

Суть проблемы: Если запустить экспорт и сразу же остановить, зависает вся система. Путем разбора пол...

2012-03-07T11:03:59Z

ra81

Суть проблемы: Если запустить экспорт и сразу же остановить, зависает вся система. Путем разбора пол...

2012-03-07T09:49:39Z

Суть проблемы:
Если запустить экспорт и сразу же остановить, зависает вся система. Путем разбора полетов было выяснено что блокируется поток внутри метода 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)); // <---- висим тут.
}
}

Очередь вызовов в общем схожая. Метод ждет освобождения блокировки.