Почему данные ThreadStatic неожиданно распределяются между потоками?

У меня есть инфраструктура ведения журнала, которую я написал, которая имеет возможность отслеживать «контекст ведения журнала». У него есть подключаемая структура стратегии, однако я чаще всего использую вариант ThreadStatic, который отслеживает контекст в переменной [ThreadStatic] . Я пытался решить проблему с ведением журнала в многопоточном рабочем процессе. Цель состоит в том, чтобы все записи журнала для всех вызовов всех методов и классов, которые совместно используют общий поток, регистрировали одну и ту же контекстную информацию. Поскольку каждый поток теоретически должен получать свою собственную переменную ThreadStatic, идея казалась простой.

public class ThreadStaticLoggingContextStrategy: ILoggingContextStrategy
{
    public ThreadStaticLoggingContextStrategy()
    {
        Debug.WriteLine("[INITIALIZE] A new instance of 'ThreadStaticLoggingContextStrategy' has been created.");
    }

    [ThreadStatic] private LoggingContext _context;

    public LoggingContext GetLoggingContext()
    {
        if (_context == null)
            _context = new LoggingContext();

        return _context;
    }
}

На самом деле кажется, что данные ThreadStatic на самом деле ОБМЕНАЮТСЯ между потоками. Это противоречит всему, что я понимаю о многопоточности. Мне было трудно понять, в чем проблема, пока я не добавил дополнительную запись в журнал, которая отслеживала, когда каждый поток очищал контекст потока (все потоки выполняются в основном цикле ... в начале, если необходимые сообщения получен, контекст инициализируется, а в конце предложения finally - его сброс.) Следующее ведение журнала СОГЛАСНО:

[2011-12-15 16: 27: 21,233] [DEBUG] [TPI.LTI.Eventing.GroupCreatedNotificationHandler: TPI.LTI.Provisioning.Handlers.GroupCreatedNotificationHandler.WORKDEVELOPMENT.1_Thread: 324]: (ContextId = 184e82dd-152b-4bb5-a2c6-3e05b2365c04; TransactionId = 1a11130e-e8dd-4fa1-9107-3b46dcb4ffd6; HandlerName = GroupCreatedNotificationHandler; HandlerId = WORKDEVELOPMENT.1) Отправка события для инструмента '0967e031-398f-437d-8949-2a17fe844df0' на http://tpidev.pearsoncmg.com/tpi/lti/service/event ...

[2011-12-15 16: 27: 21,259] [DEBUG] [TPI.LTI.Facades.LTIFacade: TPI.LTI.Provisioning.Handlers.GroupCreatedNotificationHandler.WORKDEVELOPMENT.1_Thread: 299]: (ContextId = 184e82dd-152b-4bb5-a2c6-3e05b2365c04; TransactionId = 1a11130e-e8dd-4fa1-9107-3b46dcb4ffd6; HandlerName = GroupCreatedNotificationHandler; HandlerId = WORKDEVELOPMENT.1) Получение экземпляра инструмента LTI для инструмента идентификатор экземпляра 0967e031-398f-437d-8949-2a17fe844df0:

[2011-12-15 16: 27: 21,318] [DEBUG] [TPI.LTI.Facades.LTIFacade: TPI.LTI.Provisioning.Handlers.GroupCreatedNotificationHandler.WORKDEVELOPMENT.1_Thread: 299]: (ContextId = 184e82dd-152b-4bb5-a2c6-3e05b2365c04; TransactionId = 1a11130e-e8dd-4fa1-9107-3b46dcb4ffd6; HandlerName = GroupCreatedNotificationHandler; HandlerId = WORKDEVELOPMENT.1) Найден экземпляр инструмента LTI для экземпляра инструмента. руководство 0967e031-398f-437d-8949-2a17fe844df0.

[2011-12-15 16: 27: 21,352] [DEBUG] [TPI.LTI.Facades.TPIFacade: TPI.LTI.Provisioning.Handlers.GroupCreatedNotificationHandler.WORKDEVELOPMENT.1_Thread: 299]: (ContextId = 184e82dd-152b-4bb5-a2c6-3e05b2365c04; TransactionId = 1a11130e-e8dd-4fa1-9107-3b46dcb4ffd6; HandlerName = GroupCreatedNotificationHandler; HandlerId = WORKDEVELOPMENT.1) Публикация события в TPI по адресу 'http: //tpidev.pearsoncmg.com/tpi/lti/service/event' ...

[2011-12-15 16: 27: 21,428] [DEBUG] [TPI.LTI.Eventing.GroupCreatedNotificationHandler: TPI.LTI.Provisioning.Handlers.GroupCreatedNotificationHandler.WORKDEVELOPMENT.2_Thread: 301]: [LOG] Сброс контекста ведения журнала !!

[2011-12-15 16: 27: 21,442] [DEBUG] [TPI.LTI.Eventing.GroupCreatedNotificationHandler: TPI.LTI.Provisioning.Handlers.GroupCreatedNotificationHandler.WORKDEVELOPMENT.2_Thread: 299]: в очереди нет ожидающих сообщений. Обработчик GroupCreatedNotificationHandler.WORKDEVELOPMENT.2 является ожидание ...

[2011-12-15 16: 27: 22,282] [DEBUG] [TPI.LTI.Facades.TPIFacade: TPI.LTI.Provisioning.Handlers.GroupCreatedNotificationHandler.WORKDEVELOPMENT.1_Thread: 301]: событие опубликовано в TPI.

[2011-12-15 16: 27: 22,283] [DEBUG] [TPI.LTI.Eventing.GroupCreatedNotificationHandler: TPI.LTI.Provisioning.Handlers.GroupCreatedNotificationHandler.WORKDEVELOPMENT.1_Thread: 301]: Получен ответ от провайдера:

Вы можете видеть, что в данном конкретном случае есть два потока, 1_Thread и 2_Thread. Я выделил курсивом контекстные данные, которые должны быть включены в начало КАЖДОЙ записи журнала для 1_Thread. Я выделил жирным шрифтом точку в 2_Thread, где сбрасывается контекст ведения журнала.После этого вся контекстная информация 1_Thread отсутствует. На данный момент в десятках тестов контекстная информация для всех потоков теряется после того, как контекст ведения журнала сбрасывается в другом.

Могу ли я неправильно понять ThreadStatic? Я пишу код на C # с 2001 года и никогда раньше не сталкивался с подобным поведением. Кажется, есть новый класс ThreadLocal в.NET 4, однако я не уверен, что это просто внутреннее использование ThreadStatic и, следовательно, будет иметь ту же проблему, или если он будет работать по-другому (и, надеюсь, более надежно). Любое понимание этой проблемы будет ОЧЕНЬ ЦЕННО! Спасибо!

5
задан jrista 15 December 2011 в 23:39
поделиться