Thread was being aborted
От: MadHuman Россия  
Дата: 22.02.18 06:27
Оценка: 64 (1)
Всем привет!

Иногда (раз в месяц, но в последнее время пару дней подряд было), в сервисном процессе .Net возникает ошибка ThreadAbortException (сообщение Thread was being aborted). Судя по описанию в MSDN — такая ошибка возможна если потоку явно сказали Abort, но в нашем коде такого нет (используемые библиотеки также можно исключить). Почему тогда возникает??? очень странно.
Ещё из деталей: во всех случаях, ошибка случалась в разных местах нашего кода, который выполнялся из Task-и. Также в такие моменты много Task могло быть запущено и высокая CPU нагрузка. Но если таким образом оборванную работу затем перезапустить, то ок, то есть дело не в самой выполняемой таской процедуре.
В стэк трэйсе ничего интересного (наш код), который вдруг в произвольном месте прерывается с такой ошибкой.
Хостом является IIS, и это происходит при старте веб-приложения, запускаются таски чтоб асинхронно выполнялась определённая инициализация, но не нужная сразу. В течении последующей работы такого небывает.
Это точно не выгрузка домена (тк домен только поднялся и остальные стартовавшие таски продолжают работу).
Это точно не в процессе обработки хттп-запроса, т.е. не из-за возможных редиректов.

Кто-нибудь сталкивался с похожей проблемой? Куда копать?...

upd — ответ нашёлся
дело оказалось в следующем.
до запуска плановой асинхронной инициализации, успевал прилетать хттп-реквест и инициализация шла синхронно в потоке этого реквеста.
запрос был на асинхронный контроллер (mvc3), который имел аттрибут AsyncTimeout.
тк инициализация шла долго, то таймаут проходил и asp.net видимо абортил рабочий поток реквеста (о чем в евент-логе виндовс и было сообщение секунда в секунду совпавшее с уже нашим логом об ошибке).
Отредактировано 22.02.2018 14:57 MadHuman . Предыдущая версия . Еще …
Отредактировано 22.02.2018 8:33 MadHuman . Предыдущая версия .
Re: Thread was being aborted
От: Sinix  
Дата: 22.02.18 07:19
Оценка:
Здравствуйте, MadHuman, Вы писали:

MH>Кто-нибудь сталкивался с похожей проблемой? Куда копать?...


Самая вероятная причина — это выгрузка домена или завершение процесса, т.е. в лог только следствие попадает.

Менее вероятные — хост (iis) разбушевался, вот этот и этот (выстреливает в реквесте) подарки от bcl.

Можно сделать ход конём, загоняем все сборки в ilspy, смотрим, кто дёргает методы Thread.Abort().
Re[2]: Thread was being aborted
От: MadHuman Россия  
Дата: 22.02.18 08:42
Оценка:
Здравствуйте, Sinix, Вы писали:

Спасибо, за идеи!

S>Самая вероятная причина — это выгрузка домена или завершение процесса, т.е. в лог только следствие попадает.

Это точно не выгрузка домена. Хостом является IIS, и обычно это происходит при старте веб-приложения, запускаются таски чтоб асинхронно выполнялась определённая инициализация, но не нужная сразу. В течении последующей работы такого небывает.
Не выгрузка домена, тк так падает только какая-нибудь одна инициализация, остальные успешно проходят.

S>Менее вероятные — хост (iis) разбушевался, вот этот и этот (выстреливает в реквесте) подарки от bcl.


Это происходит не в процессе обработки хттп-запроса, т.е. возможный редирект (и "подарок от bcl") тут не причем.

(дополнил стартовый пост этой информацией).
Re: Thread was being aborted
От: Sharov Россия  
Дата: 22.02.18 10:05
Оценка:
Здравствуйте, MadHuman, Вы писали:

MH>используемые библиотеки также можно исключить


Откуда такая уверенность?
Кодом людям нужно помогать!
Re[2]: Thread was being aborted
От: MadHuman Россия  
Дата: 22.02.18 10:50
Оценка:
Здравствуйте, Sharov, Вы писали:

S>Здравствуйте, MadHuman, Вы писали:


MH>>используемые библиотеки также можно исключить


S>Откуда такая уверенность?


при инициализации веб-приложения и собственно при работе наших процедур инициализации, они не используются (кроме bcl конечно).
используются уже при работе, сильно позже.
теоретически конечно возможно, что в каком-нибудь class-constructor-e в них мог бы быть Thread.Abort, но кто ж в здравом уме такое делать будет)
ну и под микроскопом их рассмотрели, нет в них Thread.Abort.
Re[3]: Thread was being aborted
От: Sinix  
Дата: 22.02.18 12:09
Оценка:
Здравствуйте, MadHuman, Вы писали:

MH>Это точно не выгрузка домена. Хостом является IIS

С этого и надо было начинать

См эту ссылку
https://haacked.com/archive/2011/10/16/the-dangers-of-implementing-recurring-background-tasks-in-asp-net.aspx/

Навешиваем логгинг на unhandled exception & domain unload events, если ничего не найдено — проверяем стэк, возможно исключение всё-таки апи выбросило.
Нет — см предыдущий совет про ilspy и thread.Abort().
Как вариант, можно поймать через etw trace, но надо мануалы искать.
https://blogs.msdn.microsoft.com/tess/2008/11/06/troubleshooting-appdomain-restarts-and-other-issues-with-etw-tracing/ для начала.

UPD, да, в аппуле IIS других приложений нет случаем?
Отредактировано 22.02.2018 12:10 Sinix . Предыдущая версия .
Re[4]: Thread was being aborted
От: MadHuman Россия  
Дата: 22.02.18 12:54
Оценка:
Здравствуйте, Sinix, Вы писали:

S>См эту ссылку

S>https://haacked.com/archive/2011/10/16/the-dangers-of-implementing-recurring-background-tasks-in-asp-net.aspx/

S>Навешиваем логгинг на unhandled exception & domain unload events,

если аборт происходит только в одном потоке, а остальные остаются и завершаются другие асинхронные инициализации (это видно по нашим логам), и собственно всё работает нормально (кроме тех мест которые рассчитывали на абортнутую инициализацию), это же однозначно говорит о том что AppDomain не был грохнут, верно?

S>если ничего не найдено — проверяем стэк, возможно исключение всё-таки апи выбросило.

не совсем понятно, что там можно увидеть, в нашем случае стэк-трэйс заканчивался на одной из ничем не примечательных наших функций.
в которой ну никак не может быть ошибки. т.е. как раз похоже на настоящий трэд аборт, когда ран-тайм практически в произвольном месте прерывает нормальную работу с такой ошибкой.


S>Нет — см предыдущий совет про ilspy и thread.Abort().

в нашем коде 100% нет.
внешние библиотеки на этом этапе ещё не используются, значит не могут быть причиной такого, верно?

S>Как вариант, можно поймать через etw trace, но надо мануалы искать.

S>https://blogs.msdn.microsoft.com/tess/2008/11/06/troubleshooting-appdomain-restarts-and-other-issues-with-etw-tracing/ для начала.
это ещё не раскурил, но спасибо.


S>UPD, да, в аппуле IIS других приложений нет случаем?

нет. всё происходит на отдельном VDS с Win2008 r2 web, это единственный аппул.
настроено так, чтоб аппул рекуклился раз в сутки, собственно при старте такая хрень иногда (редко) и случается.
в течении дня всё ок, никогда подобного не фиксировалось.

всё таки как-то связано с работой процедур инициализации, тк при абортах стэк-трэйсы только в них.

бывают ли какие другие причины (кроме явного вызова кем-то Thread.Abort) когда рант-тайм исходя из каких-то своих соображений абортит поток?..
Re[5]: Thread was being aborted
От: Sinix  
Дата: 22.02.18 13:56
Оценка: 10 (1)
Здравствуйте, MadHuman, Вы писали:

S>>Навешиваем логгинг на unhandled exception & domain unload events,

MH>если аборт происходит только в одном потоке, а остальные остаются и завершаются другие асинхронные инициализации (это видно по нашим логам), и собственно всё работает нормально (кроме тех мест которые рассчитывали на абортнутую инициализацию), это же однозначно говорит о том что AppDomain не был грохнут, верно?

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

MH>бывают ли какие другие причины (кроме явного вызова кем-то Thread.Abort) когда рант-тайм исходя из каких-то своих соображений абортит поток?..

Да. Пока больше всего похоже вот на это
https://stackoverflow.com/questions/4347870/how-can-i-find-out-why-my-thread-is-being-stopped-in-asp-net

И ещё вариации на ту же тему:
https://stackoverflow.com/questions/23483091/why-asp-net-kills-my-background-thread.
https://stackoverflow.com/a/21045242

Я бы посмотрел логи IIS + проверил, что никакие модули IIS типа wcf-хоста не вмешиваются.
Re[6]: Thread was being aborted
От: MadHuman Россия  
Дата: 22.02.18 14:29
Оценка: 55 (2)
Здравствуйте, Sinix, Вы писали:


MH>>бывают ли какие другие причины (кроме явного вызова кем-то Thread.Abort) когда рант-тайм исходя из каких-то своих соображений абортит поток?..

S>Да. Пока больше всего похоже вот на это
S>https://stackoverflow.com/questions/4347870/how-can-i-find-out-why-my-thread-is-being-stopped-in-asp-net
не наш случай. там причина — рекуклинг аппула спустя период бездействия.

S>Я бы посмотрел логи IIS + проверил, что никакие модули IIS типа wcf-хоста не вмешиваются.

вот это помогло, вроде же очевидно, но не заглянул

дело оказалось в следующем.
до запуска плановой асинхронной инициализации, успевал прилетать хттп-реквест и инициализация шла синхронно в потоке этого реквеста.
запрос был на асинхронный контроллер (mvc3), который имел аттрибут AsyncTimeout.
тк инициализация шла долго, то таймаут проходил и asp.net видимо абортил рабочий поток реквеста (о чем в евент-логе и было сообщение секунда в секунду совпавшее с уже нашим логом об ошибке).

спасибо
Re[7]: Thread was being aborted
От: Sinix  
Дата: 22.02.18 15:13
Оценка:
Здравствуйте, MadHuman, Вы писали:

MH>дело оказалось в следующем.

MH>до запуска плановой асинхронной инициализации, успевал прилетать хттп-реквест и инициализация шла синхронно в потоке этого реквеста.

Отлично, что нашлось Вообще, с iis-ом очень много неочевидных и слабо документированных вещей и отбрасывать версии сходу не стоит, сам кучу раз натыкался. Свои логи и логи ииса спасают, да.
Re[8]: Thread was being aborted
От: MadHuman Россия  
Дата: 22.02.18 15:54
Оценка:
Здравствуйте, Sinix, Вы писали:


S>Вообще, с iis-ом очень много неочевидных и слабо документированных вещей и отбрасывать версии сходу не стоит, сам кучу раз натыкался. Свои логи и логи ииса спасают, да.


на моём опыте (года 4 поддерживаю веб-сервис), загадок с иис-ом было относительно мало. иис на удивление хорошо себя зарекомендовал как веб-сервер и сюрпризов я даже не припомню с ним.
из хороших фич, нравится что если вдруг крэш рабочего процесса случается (всегда было по нашей вине, в основном из-за стэковерфлоу), то иис сам рестартует. реально полезно.
одно из самых неприятных было — раньше когда апппул собирался рестартовать, то из приложения никак об этом было не узнать, чтоб выполнить нужные финализационные действия. но сейчас уже есть способ для этого.
 
Подождите ...
Wait...
Пока на собственное сообщение не было ответов, его можно удалить.