[WWDC-2020] Explore logging in Swift

이 글은 WWDC 2020 영상을 정리하여 작성한 글입니다.

원본 영상은 링크를 참고하여 주세요.

Explore logging in Swift 

오늘은 앱에서 디버그 하기 용이하도록 애플에서 제공하는 logging API를 사용하는 방법에 대한 WWDC 세션을 한번 정리해보도록 하겠습니다.

앱을 개발하면서 다양한 버그와 맞딱뜨리게 되는데요. 😬 

새로운 기능을 추가하는 것 이외에도 버그들을 올바르게 수정하는 것 또한 앱을 개발하면서 맡게 되는 중요한 일인 것 같습니다.  이 때 로그는 재현이 어려운 버그들을 찾아내는 유용한 도구라고 할 수 있습니다. 로그는 버그들을 재현할 필요 없이 버그가 발생하기 전 상황들에 대한 흔적들을 제공해 준다고 볼 수 있는데요.

세션에는 실제 재현이 어려운 버그를 이해하고 수정하는데 도움이 되도록 로그를 추가하는 방법을 직접 보여줍니다.

영상에서는 'Fruta' 라는 스무디를 구매하는 앱에서 발생하는 버그 상황을 보여줍니다. 'Fruta'에서는 친구들에게 기프트 카드를 선물해 줄 수 있는 탭이 존재하는데요. 탭에서는 다양한 상품들이 존재하는데 스크롤이 마지막에 도달하면 앱이 서버와 통신하여 더 많은 카드를 로드하기 시작합니다.

만약 로딩중 카드를 선택하게 되면 앱은 로딩과 진행 중인 다른 통신을 중지하게 됩니다. 이러한 상황은 주기적으로 일어날 수 있는데, 이 때 개발자는 새로운 로딩이 종종 실패하는 버그가 발생하고 있다고 설명합니다.

만약 이러한 재현이 어려운 앱에 로깅을 추가하면 추가적으로 제현할 필요 없이 이와 같은 오류를 이해하는데 도움이 될 것 입니다.

Xcode 12 부터 통합된 로깅을 위해 새로운 Swift API가 도입되었습니다. 이 API 를 사용함으로 써 앱에서 발생하는 중요한 이벤트를 기록할 수 있고, 이러한 로그는 운영체제에서 보관이 되므로 장치에서 쉽게 찾을 수 있게 됩니다.

앱에 로그를 남기기 위해서는  세 가지의 간단한 작업이 필요합니다.

먼저 로그 API가 존재하는 'os' 모듈을 import 하고,

'Logger' 라는 인스턴스를 생성합니다. Logger 인스턴스를 생성할 때는  생성자에 'subsystem'과 'category' 값을 전달해 주어야 합니다. 이 값들은 해당 Logger가 기록하는 메세지에 모두 첨부됩니다.  'subsystem'은 기록된 로그에서 앱을 식별하는데 도움이 되는 식별자 이고, 'category'를 통해 앱 내부에 어떤 부분에서 온 메세지인지 구분할 수 있도록 해줍니다.

그 다음 log 메소드를 필요한 위치에 호출하도록 하는 작업입니다. 여기서는 데이터를 서버에서 다운로드할 때마다 로그를 추가하도록 하였습니다.

import os // 1

let logger = Logger(subsystem: "com.example.Fruta", category: "giftcards") // 2

func beginTask(url: URL, handler: (Data) -> Void) {
    launchTask(with: url) {
       handler($0)
    }
    logger.log("Started a task \(taskId)") // 3
}

 

다음과 같이 로그를 사용하여 메세지 내부에 런타임 데이터를 추가할수도 있습니다. 이러한 방식은 일반적으로 런타임 데이터를 체크하기 위해 print 문을 사용하는 것과 비슷하다고 볼 수 있습니다. 이러한 데이터는 로그 메세지에 다양한 형태로 포함이 가능하고, 'CustomStringConvertible' 프로토콜을 준수하는 모든 타입 뿐만아니라 Int 나 Double 같은 숫자를 기록할 수 있습니다. 즉, 로그 메세지에 사용자가 설정한 타입을 추가하려면 'CustomStringConvertible' 프로토콜을 준수해야 합니다.

다만, 런타임 데이터를 로그메세지에 추가할 경우 사용자 개인정보고 표시되지 않도록, 문자열 같이 숫자가 아닌 타입의 경우 로그에서 다시 처리됩니다. 예를 들어, 로그에서 계좌번호와 함께 메세지를 로깅했다면, 출력 로그에서는 계좌번호가 비공개로 수정됩니다.

그러나 민감한 정보가 아닌 데이터일 경우, 이 값을 표기하도록 로그에 전달할 수 있습니다.

앱에서 생성된 로그 메세지를 운영체제에서 압축한 형태로 장치에 저장하고, Mac에서는 'log collect' 명령을 사용하여 해당 로그를 검색할 수 있습니다. 검색하는 방법은 먼저, 장치를 Mac에 연결하고, 터미널에서 다음과 같이 실행합니다.

또한 로그가 필요한 시점을 지정하여 실행할 수 있습니다. 그리고 'output' 옵션을 통해 추출된 로그를 확인할 수 있는 파일 명을 지정할 수 있습니다.

이를 통해 로그를 확인하면 장치 시스템의 모든 프로세스가 기록한 메세지가 포함되어 있는 로그를 확인할 수 있습니다.

세션에서 개발자는 버그가 발생하는 앱 내에 로그를 미리 기록하도록 하였습니다. 서버와 통신을 하는 부분에서 로그를 하도록 하였고, UUID를 포함하도록 하였습니다.

이렇게 기록된 로그에서 Logger 인스턴스를 생성할 때 지정한 'subsystem'을 통해 검색을하여 실패한 task를 찾아냅니다.

그리고 실패한 task ID를 검색하여 어떠한 과정을 겪었는지 확대해 봅니다.

위 과정에서는 앱이 더많은 기프트 카드를 가져오기 위한 작업을 시작하였으나, 네트워크 에러로 인해 작업이 완료되었고, 시간 초과 후 다시 시도하려고 대기하고 있음을 알 수 있습니다. 하지만, 사용자는 기프트 카드에서 어떠한 항목을 선택했고, 이로 인해 활성된 작업을 중지되도록 하였습니다. 하지만 이 시점에는 활성된 작업이 존재하지 않으므로 실패하게 됩니다. 이렇게 버그가 발생한 상황을 살펴보고 개발자는 알맞는 조치를 취할 수 있게 될 것 입니다.

이렇게 'log collect'를 통해 로그를 수집할 수 있습니다. 또한 앱이 실행되는 동안에도 맥이 장치에 연결되어 있다면 Console.app 을 통해 로그를 streaming 할 수도 있습니다. 그리고 Xcode와 연결되어 있다면, Xcode Console에서도 확인할 수 있습니다. 이러한 디버깅은 print 문을 통한 디버깅보다 쉽게 필터링 할 수 있고, 구조화된 출력을 가질 수 있습니다. 

Log Levels

콘솔앱에서는 로그를 탐색할 때 'failure' 메세지가 강조되었다는 것을 볼 수 있는데, 이는 로그 메세지의 level을 fault level로 기록했기 때문입니다. 

이렇게 로깅 API는 메세지의 중요성에 따라 다섯가지 로그 수준을 제공합니다.

• Debug : 디버깅에 유용한 정보를 표시 하는 단계
• Info : 오류 해결에 필수적이진 않지만 유용한 정보를 표시 하는 단계
• Notice(Default) : 문제 해결에 절대적으로 필요한 정보를 표시하는 단계
• Error : 실행 중에 발생하는 오류를 표시하는 단계
• Fault : 결함 수준이 심각한 단계

이러한 단계에서 Error와 Fault 는 각각 노란색, 빨간색으로 강조 표시 됩니다.

실제로 Swift 의 로깅 API는 각각 level에 대한 메서드가 존재합니다. 이러한 level 을 선택하는데 고려해야할 중요한 점은 지속성 입니다. 즉, 로그 메세지를 아카이브하여 나중에 검색할 수 있는 지 여부를 체크해주어야 합니다. 지속되지 않는 로그메세지는 스트리밍 동안에만 확인할 수 있으며, 이러한 지속 여부는 로그 level에 따라 다릅니다. 물론 이러한 지속성은 level에 따라 증가합니다. 

예를 들어  'Debug' level은 앱 실행이 완료 된 후에는 검색을 할 수가 없습니다. 그리고 'Info' level은 'log collect' 명령어를 호출하기 몇 분 전에 생성되는 경우를 제외하고는 대부분 지속되지 않습니다. 그리고 보관되는 메세지 수에는 제한이 있기 때문에 제한을 초과하게 되면 이전 제한을 삭제하고 사용할 수 없게 됩니다. 하지만 'Error' 와 'Fault' 메세지는 보다 더 오래 유지됩니다. 이는 며칠 동안 유지됩니다.

그리고 로그 레벨에 따라 성능에도 영향을 미칩니다. 일반적으로 로그에 대한 오버헤드는 굉장히 낮지만, 덜 중요할수록 빠르고 중요할 수록 느립니다. 

또한 성능 확인에도 로그는 도움을 줄 수 있습니다.

개발자는 앱에서 카드를 불러오는 시간이 너무 느리다고 판단하였고, 어떤 서버를 선택하는지 관련이 있다고 생각하여 이에대한 통계를 수집하는 로깅을 추가하였습니다.

import SwiftUI
import os

let statisticsLogger = Logger(subsystem: "com.example.Fruta", category: "statistics")

// Log statistics about communication with a server.
func logStatistics(taskID: UUID, giftCardID: String, serverID: Int, seconds: Double) {
    statisticsLogger.log("\(taskID) \(giftCardID, align: .left(columns: GiftCard.maxIDLength)) \(serverID) \(seconds, format: .fixed(precision: 2))")
}

 또한 로거에서 식별하기 편하기 위해 align 이나 format을 지정하였습니다. 

그리고 다음의 표를 그대로 복사하여 'Number'에 붙혀 넣으면 테이블의 형태로 볼 수 있습니다.

이러한 방식으로 'format' 이나 'align' 파라미터를 추가하여 데이터 형식을 지정하고 추출되는 데이터의 포맷을 지정할 수 있습니다. 이는 일부이며 Logging API는 많은 포맷 옵션을 제공합니다.

 

지금까지 알아봤던 Logger API 는 iOS 14에서 사용할 수 있습니다. 만약 이전 버전을 대상으로 하는 경우에는 os_log 함수를 통해 사용이 가능합니다.