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

Thread 0 Crashed:
0   libobjc.A.dylib                      0x39abcf42 objc_msgSend + 2
1   CoreFoundation                       0x2bfe0c61 __CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER__ + 10
2   CoreFoundation                       0x2bf3c6d5 _CFXNotificationPost + 1782
3   Foundation                           0x2cc6e129 -[NSNotificationCenter postNotificationName:object:userInfo:] + 70
4   Foundation                           0x2cc72c8f -[NSNotificationCenter postNotificationName:object:] + 28
5   UIKit                                0x2f750883 -[UIApplication _performMemoryWarning] + 132
6   libdispatch.dylib                    0x3a0107a7 _dispatch_client_callout + 20
7   libdispatch.dylib                    0x3a021253 _dispatch_source_latch_and_call + 624
8   libdispatch.dylib                    0x3a0122ed _dispatch_source_invoke + 210
9   libdispatch.dylib                    0x3a013e1f _dispatch_main_queue_callback_4CF + 328
10  CoreFoundation                       0x2bfee3b1 __CFRUNLOOP_IS_SERVICING_THE_MAIN_DISPATCH_QUEUE__ + 6
11  CoreFoundation                       0x2bfecab1 __CFRunLoopRun + 1510
12  CoreFoundation                       0x2bf3a3c1 CFRunLoopRunSpecific + 474
13  CoreFoundation                       0x2bf3a1d3 CFRunLoopRunInMode + 104
14  GraphicsServices                     0x332cf0a9 GSEventRunModal + 134
15  UIKit                                0x2f5487b1 UIApplicationMain + 1438
16  xxx                                  0x0015bb81 main (main.m:18)
17  libdyld.dylib                        0x3a030aaf start + 0

По вызову -[UIApplication _performMemoryWarning] понятно, что проблема произошла при обработке memory warning. По всей видимости, какой-то объект подписался на UIApplicationDidReceiveMemoryWarningNotification и забыл отписаться перед своим уничтожением. Но проверка по коду проекта не выявила подозрительных ситуаций — все, кто использовал эту нотификацию, либо были синглтонами, либо более-менее корректно отписывались. На тот момент дело этим и ограничилось, идей для фикса пока что не было.

Затем, когда Apple купила TestFlight, мы перешли на HockeyApp. Они используют крутую крешрепортилку (PLCrashReporter), и в целом работа с крешами там обстояла гораздо лучше (можно еще и свои логи/инфу аттачить при посылке репорта с девайса). Но, возвращаясь к проблеме, в добавок к стеку, приведенному выше, появились еще и такие строчки:

Application Specific Information:
objc_msgSend() selector name: setArchiveData:

Теперь мы знаем, какой селектор посылался умершему объекту. В нашем коде таких методов/свойств не присутствовало, что подтверждало прежний анализ. Соответственно, встает задача найти класс, у которого есть такой селектор. В этом помогают функции obj-c рантайма objc_getClassList (выдает список зарегистрированных классов) и class_copyMethodList (позволяет получить методы экземпляров и самого класса). Пройдясь по всем классам и проверив все их селекторы, я получил единственный вариант — UINibStorage. Это приватный класс, и с помощью свизлинга его методов видим, что он создается и держится UINib'ами. Дальше, опять же с помощью свизлинга и дизассемблирования, выясняем, что UINib подписывается на UIApplicationDidReceiveMemoryWarningNotification, и при ее получении очищает содержимое своего UINibStorage (в т.ч. вызывает setArchiveData) — этот вызов и падает в крешлоге. Отписка от нотификации происходит в деаллоке UINib. Как же получилось, что UINib умер, но при этом получил нотификацию?

Проблема, по всей видимости, возникла из-за того, что мы использовали NSCache для кеширования нибов. При нехватке памяти NSCache очищает свое содержимое в фоновом потоке, т.е. по сути асинхронно с memory warning в главном потоке. Т.о. в фоновом потоке вызывается -[UINib dealloc], в котором тот отписывается от нотификаций, а в главном идет их обработка. Это неправильный и опасный подход к использованию NSNotificationCenter. Вообще говоря, за время работы на проекте нам доводилось фиксить немало багов, связанных с асинхронностью, т.к. там выполняется много асинхронных операций. Одна из частых ошибок, с которой доводилось сталкиваться — отмена или отписывание от чего-либо в деаллоке. Это слишком поздний момент, т.к. объект уже фактически умирает, и если асинхронная операция в этот же момент пытается с ним работать, то это плохо кончится. К сожалению, суровая реальность такова, что не всегда есть хорошее место, где можно было бы отписываться. В случае с UINib понятно, что такого удобного места нет, поэтому сложно упрекнуть за это (скорее тогда стоит упрекать инфраструктуру или NSNotificationCenter).

В качестве решения проблемы я написал тривиальный кеш для хранения нибов. Вообще же, это не первый креш с NSCache. Раньше мне уже доводилось фиксить креш связанный с хранением NSCache в NSCache — так делать тоже не стоит. Но и NSCache я тоже не могу назвать явно виноватым, т.к. он не должен думать, что нельзя послать release объекту в любом фоновом потоке из-за того, что этот release может быть последним, а dealloc делает больше, чем ничего. Пожалуй, эта ситуация из тех, когда понятные и простительные решения дают негативный результат.

Комментарии (4)


  1. kostyl
    05.04.2015 20:03
    +3

    так вы сами виноваты, что используете UI не в главном потоке


    1. PavelTretyakov Автор
      06.04.2015 09:31

      Никакого использования UI из фона в нашем коде не было. Просто объекты UINib кешировались (в главном потоке). А вот NSCache чистит свое содержимое в фоне — отсюда и возникает использование неглавного потока. Но, как я уже написал, обвинять тут NSCache некорректно.


  1. gooddy
    06.04.2015 13:40
    +1

    Что-то не могу придумать для чего понадобилось кешировать UINib


    1. PavelTretyakov Автор
      06.04.2015 21:19

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