Как я багу по многопоточке фиксил

Підписуйтеся на Telegram-канал «DOU #tech», щоб не пропустити нові технічні статті

Дратути.

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

Дано:
1. Имеем ExecutorService, u know, который выполняет таски
2. Таски могут быть закенселены через отдельный эндпоинт
3. Таска ходит в нашу локальную базу и в отдельный сервис за данными
4. Перед каждым ключевым степом таски написан тот самый

if (Thread.currentThread().isInterrupted()) {
throw new InterruptedException();
}

А теперь кейс:
1. Запускаем тасочку...
2. Ждем пару сек
3. Стопаем
...
А ОНА БЛИН НЕ СТОПАЕТСЯ КАРЛ!

Начинается внутреннее подгорание. В смысле не стопается? Лезем дебажить — докапываемся до TrustedListenableFutureTask и видим что тред то интераптится, даже флаг в фолз стоит!

Ок, получается, что флаг каким-то магическим образом сбросился? Как так.

Лезем в гугл который вежливо напоминает что есть разные методы которые помимо получения текущего флага треда заодно сетает его в false, проще говоря резетит тред(тут по идее должно быть фундаментальное знание которое СОХРАНИЛОСЬ еще с универа но оказывается что ты это, внезапно, забываешь)
Вот один из таких методов это внезапно Thread.interupted(), который под капотом использует Thread.currentThread().isInterrupted(false) что резетит флаг в false. Счастья-здоровья.
Тру дед с дивана прокричит сейчас, что я должен был это знать, а я в свою очередь скажу... да, должен был. Теперь знаю точно. Спасибо.
Самое прикольное, что я про это когда-то давно читал, но с тех пор прошло 4-5 лет. Будем считать, что оправдался.

Штош, получается кто-то юзает Thread.interrupted() или какой-нибудь другой метод.
Ну ок, давайте пробовать дебажить Thread.interrupted().
Странное занятие, учитывая что его юзают куча других тредов, надо же как-то отсеивать их и у Intellij IDEA (боже храни JetBrains) есть возможность ставить кондишин на брикпоинт.
Поставив свечку за их здоровье, я ставлю кондишин по нейму треда который меня интересует. Для этого мне понадобилось дойти до interrupt() в TrustedListanableFuture, ну вы поняли, чисто как макака.
Ловлю кучу говна связанного с jdbc driver поэтому принимаю волевое решение локализовать проблему методом бинарного поиска... вручную.
Комментирую все что связно с jdbc. Пытаюсь воспроизвести — воспроизводится. Дабы убедиться что не показалось — комментирую все что связано с веб-сервисом, оставляю jdbc — все работает как ожидается, тред останавливается.
Вывод: проблема с запросами в сервис. Штош, оставляем закомментированным jdbc, работаем только с вебсервисом и запросами туда. Мы использовали okhttp3 версия 3.8.0

Штош, ставим брикпоинт в Thread.interrupted() и ловим его как и ожидается со стека вызовов okhttp3...
Внезапно, okhttp3 юзает под капотом okio 1.13.0 который в Timeout.throwIfReached() имеет следующую конструкцию:

if (Thread.interrupted()) {
throw InterruptedIOException("interrupted")
}

Ну, тут все православно, скажете вы, обнулили флаг, кинули эксепшен, в чем проблема Санек?
Да вот кинуть то кинули, только он проглатывается выше по стеку, но флаг то уже в фолс стоит...

Если интересно можете подебажить или просто почитать код в стеке вызовов. Лично мне в таком случае проще всего дебажить. Может вы фанат логов, я хз. Но смысл в том, что наверху эксепшен дальше не летит, при этом флаг остался в false.

Вот вам стек

0 = {StackTraceElement@16324} "okio.Timeout.throwIfReached(Timeout.java:144)"

1 = {StackTraceElement@16325} "okio.Okio$2.read(Okio.java:136)"

2 = {StackTraceElement@16326} "okio.AsyncTimeout$2.read(AsyncTimeout.java:237)"

3 = {StackTraceElement@16327} "okio.RealBufferedSource.exhausted(RealBufferedSource.java:56)"

4 = {StackTraceElement@16328} "okhttp3.internal.connection.RealConnection.isHealthy(RealConnection.java:498)"

5 = {StackTraceElement@16329} "okhttp3.internal.connection.StreamAllocation.findHealthyConnection(StreamAllocation.java:133)"

6 = {StackTraceElement@16330} "okhttp3.internal.connection.StreamAllocation.newStream(StreamAllocation.java:100)"

7 = {StackTraceElement@16331} "okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:42)"

8 = {StackTraceElement@16332} "okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92)"

9 = {StackTraceElement@16333} "okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67)"

10 = {StackTraceElement@16334} "okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93)"

11 = {StackTraceElement@16335} "okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92)"

12 = {StackTraceElement@16336} "okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67)"

13 = {StackTraceElement@16337} "okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93)"

14 = {StackTraceElement@16338} "okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92)"

15 = {StackTraceElement@16339} "okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:120)"

16 = {StackTraceElement@16340} "okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92)"

17 = {StackTraceElement@16341} "okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67)"

18 = {StackTraceElement@16342} "okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:185)"

19 = {StackTraceElement@16343} "okhttp3.RealCall.execute(RealCall.java:69)"

Вот тут этот эксепшен перебрасывается:

okio.AsyncTimeout$2.read(AsyncTimeout.java:237)

А тут у нас замечательный кетч который проглатывает эксепшен:

isHealthy:508, RealConnection

 catch (IOException e) {

return false; // Couldn't read; socket is closed.

}

Штош, лезем в мавен репозиторий, обновляем okhttp3 до последней версии (я взял 4.9.1), билдим, дебажим — все работает. Пофиксили получается?

Да, пофиксили и уже в okio 2.8.0 в том же месте есть доп строчка и комментарий:

if (Thread.interrupted()) {

      Thread.currentThread().interrupt() // Retain interrupted status.

      throw InterruptedIOException("interrupted")

 }

Почему не использовать в условии Thread.currentThread().isInterrupted() я так и не понял, но докапываться до парней не будем, мы же не душнилы (наверное).
Но помимо этого там еще и котлин уже везде, да и поменялось все.

Я наверх получаю свой законный InterruptedIOException и не парюсь, могу нормально прервать логику работы таски. Дякую тобі боже!

Кароч хватило обычного обновления либы...

Выводы: кайфовый кейс, люблю в таком копаться потому что не очевидно и приходится напрягать мозги. Да и чувствуешь себя после этого аки Дартаньян!

P.S.: наверняка есть чуваки которые искали бы root cause, u know, по другому, интересно было бы узнать что бы вы делали на моем месте, возможно с использованием каких-то специальных инструментов и тд
Короче буду рад почитать разные варианты размышлений на тему дебагинга. Всем счастья-здоровья.

Ютуб-канал
Телеграм-канал