Примерно так это и выглядит

В этой публикации попробуем понять, как и где Xcode хранит свои логи, что такое SLF0 и как все это читать, а может быть даже понять, и лучше без IDE, так интереснее.

Без лишних предисловий.

Чтобы посмотреть логи сборки проекта или скажем тестов, в обычной, повседневной разработке, мы идем и смотрим последнюю вкладку тулбара Xcode.

Организация лога в целом читаемая, даже есть возможность все это экспортировать в txt формат.

Чтение лога внутри Xcode

Но, все это нам мало подходит для автоматизации сбора метрик, скажем для аккумулирования динамики времени сборки модулей при прогоне job'ы на CI.

Простого пути экспортировать данный лог, в полном объеме для последующей интерпретации конкретных событий нет.

Итак, все логи Xcode собирает и хранит в DerivedData/{ProjectName}/Logs.

Что такое DerivedData

По умолчанию находится по следующему пути:

open ~/Library/Developer/Xcode/DerivedData

Данный путь можно поменять в настройках Xcode:

Настройка путей для DerivedData и архивов

Собственно, DerivedData хранит всю промежуточную информацию (включая логи), а также артефакты, требуемые для оптимизации последующей сборки.

Внутри папки Logs можно встретить множество логов различных стадий, с которыми мы сталкиваемся во время разработки:

Это, собственно, логи (у вас их может быть больше)

Здесь мы можем найти следующие виды файлов:

  • *.xcactivitylog - собственно журнал, который нас будет интересовать далее;

  • *.xcresult - bundle, который хранит сводную информацию. Можно открыть в Xcode и посмотреть журналы в том виде, как если бы мы просто открыли последнюю вкладку тулбара;

  • LogStoreManifest.plist - содержит сводную информацию в читаемом виде о всех xcactivitylog файлах, можно использовать например для отслеживания готовности очередного журнала с логами.

Читаем xcactivitylog

Итак, файл лога представляет собой сжатый gzip журнал, названием служит уникальный идентификатор UUID.

После распаковки получаем журнал, записанный в формате сериализации SLF0.

Пример распакованного журнала в формате SLF0
SLF010#21%IDEActivityLogSection1@0#39"Xcode.IDEActivityLogDomainType.BuildLog25"Build XCActivityLogParser212"eyJ0eXBlIjp7ImJsdWVwcmludFByb3ZpZGVyIjp7fX0sImJsdWVwcmludFByb3ZpZGVyX3Byb3ZpZGVyRmlsZVBhdGhTdHJpbmciOiJcL1VzZXJzXC92b3JvYnlvdlwvRG9jdW1lbnRzXC9YQ0FjdGl2aXR5TG9nUGFyc2VyXC9YQ0FjdGl2aXR5TG9nUGFyc2VyLnhjb2RlcHJvaiJ9cbbac35a7833c541^0000007fc3632d42^1(1@1#27"com.apple.dt.IDE.LogSection16"Prepare packages212"eyJ0eXBlIjp7ImJsdWVwcmludFByb3ZpZGVyIjp7fX0sImJsdWVwcmludFByb3ZpZGVyX3Byb3ZpZGVyRmlsZVBhdGhTdHJpbmciOiJcL1VzZXJzXC92b3JvYnlvdlwvRG9jdW1lbnRzXC9YQ0FjdGl2aXR5TG9nUGFyc2VyXC9YQ0FjdGl2aXR5TG9nUGFyc2VyLnhjb2RlcHJvaiJ9f73bc45a7833c541^4303c95a7833c541^---0#0#0#46"Compile plug-ins and run any prebuild commands--36"52BE500F-D551-461D-975D-BF4B4AA236BF--0"0(0#0#0#---36"2976A337-D8BA-4626-B5F2-41F0F7CB232E--

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

Каждый лог начинается с обязательного хедера SLF0.

Далее последовательность токенов в следующем формате:

<side_value><delimiter><side_value>

<side_value> - опциональное значение, и зависит от конкретного разделителя.

Текущая версия SLF0 поддерживает 7 разделителей, каждый из которых является описанием значения конкретного типа:

# integer

Описывает тип integer, например:

10#

Значение слева: UInt64, собственно само значение токена.

Значение справа: отсутствует.

" string

Описывает тип string, например:

21"IDEActivityLogSection

Значение слева: UInt64, описывает количество символов, которое идет справа от разделителя и является значением строкового токена. В данном случае это значит, что искомым строковым значением является строка справа, состоящая из 21 символа. Подсчет символов ведется в utf-16, и не соответствует дефолтному count у экземпляров типа string, который возвращает количество графем).

Значение справа: строка, состоящая из количества символов, которое находится слева от разделителя.

^ double

Описывает тип double, например:

4fcbedd82b32c541^

Значение слева: представляет собой число с плавающей запятой с прямым порядком байтов, закодированное в шестнадцатеричном формате. Используется в журнале для представления типа timeInterval.

Пример приведения к обычному double из языка swift:

guard let integerValue = UInt64("4fcbedd82b32c541", radix: 16) else { exit(0) }
let double =  Double(bitPattern: integerValue.byteSwapped)
print(double) // 711219121.857767

Значение справа: отсутствует.

- null

Описывает null значение, т.е. значения какого-либо поля у нас просто нет, например:

-

Значение слева: отсутствует.

Значение справа: отсутствует.

( array

Описывает array, указывая количество элементов, которые тот содержит, например:

2(

Значение слева: количество элементов в массиве. Элементами массива являются значения с типом class_instance, о них будет чуть ниже.

Значение справа: отсутствует.

% class_name

Описывает class_name, в SLF0 решающим фактором успеха является порядок всех токенов в журнале, при парсинге их порядок важно соблюсти. Полученная индексация class_name - искомая при парсинге class_instance.

38%IDEActivityLogCommandInvocationSection

Значение слева: здесь все по аналогии с типом string, который описан выше.

Значение справа: название класса.

@ class_instance

Описывает class_instance, т.е. указывает на название класса, исходя из которого должно стать понятно, как интерпретировать все токены, которые будут следовать далее за этим class_instance.

1@

Значение слева: UInt64, собственно само значение токена, указывающее на позицию соответствующего class_name в журнале (требуется, чтобы понять к какому типу относятся токены, которые идут далее).

Значение справа: отсутствует.

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

<header> := SLF0

<integer_delimiter> := #
<double_delimiter> := ^
<null_delimiter> := -
<string_delimiter> := "
<array_delimiter> := (
<class_name_delimiter> := %
<class_instance_delimiter> := @

<delimiter> := <integer_delimiter>|<double_delimiter>|<null_delimiter>|<string_delimiter>|<array_delimiter>|<class_name_delimiter>|<class_instance_delimiter>
<side_value> := <character>|<digit>|<side_value><character>| <side_value><digit>
<value> := [<side_value>]<delimiter>[<side_value>]
<log> := <value>|<log><value>

<all_log> := <header><log>

Единственное, расписывать что такое <digit> и <character> не стал, думаю и так понятно.

Итак, зная все вышеперечисленные синтаксические и семантические правила, попробуем прочитать какой-нибудь конкретный лог (из примера выше), после чтения получаем следующий список токенов, идущих один за одним (использую написанный tokenizer):

Пример полученных токенов xcactivitylog
integer(10)
class_name("IDEActivityLogSection")
class_instance(1)
integer(0)
string("Xcode.IDEActivityLogDomainType.BuildLog")
string("Build XCActivityLogParser")
string("eyJ0eXBlIjp7ImJsdWVwcmludFByb3ZpZGVyIjp7fX0sImJsdWVwcmludFByb3ZpZGVyX3Byb3ZpZGVyRmlsZVBhdGhTdHJpbmciOiJcL1VzZXJzXC92b3JvYnlvdlwvRG9jdW1lbnRzXC9YQ0FjdGl2aXR5TG9nUGFyc2VyXC9YQ0FjdGl2aXR5TG9nUGFyc2VyLnhjb2RlcHJvaiJ9")
double(711389365.529138)
double(63113904000.0)
array(1)
class_instance(1)
integer(1)
string("com.apple.dt.IDE.LogSection")
string("Prepare packages")
string("eyJ0eXBlIjp7ImJsdWVwcmludFByb3ZpZGVyIjp7fX0sImJsdWVwcmludFByb3ZpZGVyX3Byb3ZpZGVyRmlsZVBhdGhTdHJpbmciOiJcL1VzZXJzXC92b3JvYnlvdlwvRG9jdW1lbnRzXC9YQ0FjdGl2aXR5TG9nUGFyc2VyXC9YQ0FjdGl2aXR5TG9nUGFyc2VyLnhjb2RlcHJvaiJ9")
double(711389365.53308)
double(711389365.570412)
null
null
null
integer(0)
integer(0)
integer(0)
string("Compile plug-ins and run any prebuild commands")
null
null
string("52BE500F-D551-461D-975D-BF4B4AA236BF")
null
null
string("")
array(0)
integer(0)
integer(0)
integer(0)
null
null
null
string("2976A337-D8BA-4626-B5F2-41F0F7CB232E")
null
null

На первый взгляд, все очень страшно и не менее понятно, чем было до этого. Однако, попробуем все же разобраться.

Для начала, прошу обратить внимание на имена классов, на самом деле их ограниченное количество, на момент написания статьи:

  • IDEActivityLogSection

  • IDEActivityLogCommandInvocationSection

  • IDEActivityLogUnitTestSection

  • IDEActivityLogMajorGroupSection

  • IDEActivityLogMessage

  • DVTDocumentLocation

  • DVTTextDocumentLocation

При попытке найти информацию о вышеперечисленных типах, становится понятно, что все они описаны в приватном фреймворке IDEFoundation.framework, который является частью Xcode и по умолчанию находится по адресу:

open /Applications/Xcode.app/Contents/Frameworks/IDEFoundation.framework/Versions/A/

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

Ради интереса я покопался с ktool и смог без особого труда получить описание всех классов:

ktool dump --headers /Applications/Xcode.app/Contents/Frameworks/IDEFoundation.framework/Versions/A/IDEFoundation

Приведу в пример IDEActivityLogSection, ради удобства - только его инициализатор, который отражает все нужные нам поля:

-(id)initWithSectionType:(NSInteger)arg0
              domainType:(id)arg1
                   title:(id)arg2
                subtitle:(id)arg3
                location:(id)arg4
               signature:(id)arg5
    timeStartedRecording:(CGFloat)arg6
    timeStoppedRecording:(CGFloat)arg7
             subsections:(id)arg8
                    text:(id)arg9
                messages:(id)arg10
            wasCancelled:(char)arg11
     wasFetchedFromCache:(char)arg12
commandDetailDescription:(id)arg13
              resultCode:(NSInteger)arg14
        uniqueIdentifier:(id)arg15
   localizedResultString:(id)arg16
        xcbuildSignature:(id)arg17

Единственная проблема, что порядок токенов не соответствует порядку, полученному при исследовании фреймворка.

Однако, ребята из тулзы XCLogParser уже все нашли и сопоставили, большое им спасибо, как выглядят все полученные типы с правильным порядком полей, можно посмотреть здесь.

К примеру, итоговые поля с верным порядком для IDEActivityLogSection :

public let sectionType: Int8
public let domainType: String
public let title: String
public let signature: String
public let timeStartedRecording: Double
public var timeStoppedRecording: Double
public var subSections: [IDEActivityLogSection]
public let text: String
public let messages: [IDEActivityLogMessage]
public let wasCancelled: Bool
public let isQuiet: Bool
public var wasFetchedFromCache: Bool
public let subtitle: String
public let location: DVTDocumentLocation
public let commandDetailDesc: String
public let uniqueIdentifier: String
public let localizedResultString: String
public let xcbuildSignature: String

Зная все это, попробуем расшифровать полученные токены:

Первый токен - всегда версия формата сериализации SLF0, в нашем случае 10-я:

integer(10) // Версия SLF0

Далее идет первое объявление имени типа, на которое будут ссылаться токены с типом class_instance:

class_name("IDEActivityLogSection") // Название класса (нужно для понимания, к какому типу относятся поля у class_instance)

Ниже начинается описание первого объекта со значениями его параметров, class_instance(1) указывает, что следующие токены следует интерпретировать как class_name, который указан под соответствующим относительным индексом 1, в нашем случае - IDEActivityLogSection:

class_instance(1) // Указывает, что объект типа IDEActivityLogSection

integer(0) // sectionType
string("Xcode.IDEActivityLogDomainType.BuildLog") // domainType
string("Build XCActivityLogParser") // title
string("eyJ0eXBlIjp7ImJsdWVwcmludFByb3ZpZGVyIjp7fX0sImJsdWVwcmludFByb3ZpZGVyX3Byb3ZpZGVyRmlsZVBhdGhTdHJpbmciOiJcL1VzZXJzXC92b3JvYnlvdlwvRG9jdW1lbnRzXC9YQ0FjdGl2aXR5TG9nUGFyc2VyXC9YQ0FjdGl2aXR5TG9nUGFyc2VyLnhjb2RlcHJvaiJ9") // signature
double(711389365.529138) // timeStartedRecording (TimeInterval)
double(63113904000.0) // timeStoppedRecording (TimeInterval)

Следом идет объявление массива, за которым идет описание его элементов:

array(1) // Массив из одного элемента

class_instance(1) // Элемент массива, также типа IDEActivityLogSection

integer(1) // sectionType
string("com.apple.dt.IDE.LogSection") // domainType
string("Prepare packages") // title
string("eyJ0eXBlIjp7ImJsdWVwcmludFByb3ZpZGVyIjp7fX0sImJsdWVwcmludFByb3ZpZGVyX3Byb3ZpZGVyRmlsZVBhdGhTdHJpbmciOiJcL1VzZXJzXC92b3JvYnlvdlwvRG9jdW1lbnRzXC9YQ0FjdGl2aXR5TG9nUGFyc2VyXC9YQ0FjdGl2aXR5TG9nUGFyc2VyLnhjb2RlcHJvaiJ9")
double(711389365.53308) // timeStartedRecording (TimeInterval)
double(711389365.570412) // timeStoppedRecording (TimeInterval)
null // subSections
null // text
null // messages
integer(0) // wasCancelled
integer(0) // isQuiet
integer(0) // wasFetchedFromCache
string("Compile plug-ins and run any prebuild commands") // subtitle
null // location
null // commandDetailDesc
string("52BE500F-D551-461D-975D-BF4B4AA236BF") // uniqueIdentifier
null // localizedResultString
null // xcbuildSignature

И, напоследок, оставшиеся поля у корневой секции:

string("") // text
array(0) // messages
integer(0) // wasCancelled
integer(0) // isQuiet
integer(0) // wasFetchedFromCache
null // subtitle
null // location
null // commandDetailDesc
string("2976A337-D8BA-4626-B5F2-41F0F7CB232E") // uniqueIdentifier
null // localizedResultString
null // xcbuildSignature

Для удобства понимания, итоговой парсинг журнала, записанным в формате json:

{
   "version": 10,
   "mainSection": {
      "sectionType": 0,
      "domainType": "Xcode.IDEActivityLogDomainType.BuildLog",
      "title": "Build XCActivityLogParser",
      "signature": "eyJ0eXBlIjp7ImJsdWVwcmludFByb3ZpZGVyIjp7fX0sImJsdWVwcmludFByb3ZpZGVyX3Byb3ZpZGVyRmlsZVBhdGhTdHJpbmciOiJcL1VzZXJzXC92b3JvYnlvdlwvRG9jdW1lbnRzXC9YQ0FjdGl2aXR5TG9nUGFyc2VyXC9YQ0FjdGl2aXR5TG9nUGFyc2VyLnhjb2RlcHJvaiJ9",
      "timeStartedRecording": 711389365.529138,
      "timeStoppedRecording": 63113904000.0,
      "subSections": [
         {
            "sectionType": 1,
            "domainType": "com.apple.dt.IDE.LogSection",
            "title": "Prepare packages",
            "signature": "eyJ0eXBlIjp7ImJsdWVwcmludFByb3ZpZGVyIjp7fX0sImJsdWVwcmludFByb3ZpZGVyX3Byb3ZpZGVyRmlsZVBhdGhTdHJpbmciOiJcL1VzZXJzXC92b3JvYnlvdlwvRG9jdW1lbnRzXC9YQ0FjdGl2aXR5TG9nUGFyc2VyXC9YQ0FjdGl2aXR5TG9nUGFyc2VyLnhjb2RlcHJvaiJ9",
            "timeStartedRecording": 711389365.53308,
            "timeStoppedRecording": 711389365.570412,
            "subSections": null,
            "text": null,
            "messages": null,
            "wasCancelled": false,
            "isQuiet": false,
            "wasFetchedFromCache": false,
            "subtitle": "Compile plug-ins and run any prebuild commands",
            "location": null,
            "commandDetailDesc": null,
            "uniqueIdentifier": "52BE500F-D551-461D-975D-BF4B4AA236BF",
            "localizedResultString": null,
            "xcbuildSignature": null
         }
      ],
      "text": "",
      "messages": [],
      "wasCancelled": false,
      "isQuiet": false,
      "wasFetchedFromCache": false,
      "subtitle": null,
      "location": null,
      "commandDetailDesc": null,
      "uniqueIdentifier": "2976A337-D8BA-4626-B5F2-41F0F7CB232E",
      "localizedResultString": null,
      "xcbuildSignature": null
   }
}

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

Спасибо за внимание!

Полезные ссылки:

Подписывайтесь на мои соц. сети: