[WWDC 2018] Measuring Performance Using Logging

WWDC 2018 Measuring Performance Using Logging 를 정리한 포스트입니다.

더 자세한 내용을 원하시면 위 링크를 참조하시길 바랍니다.

 

 

Introducing Signposts

 

 

Logging

 

let logHandle = OSLog(subsystem: "com.example.widget", category: "Setup")
os_log(.info, log: logHandle, "Hello, %{public}s!", world)

 

Signposts

WWDC 2016에 새로운 로깅 시스템이 도입되었습니다
효율성과 프라이버시를 염두에 두고 디버깅 할 수 있도록 구축합니다.
성능 활용 사례 및 개발자 도구와의 통합을 위해 구축합니다.

 

Logging Apple Document

 

 

Measuring Intervals with Signposts

인터페이스의 특정 부분을 새로 고치는 데 걸리는 시간을 측정하고 하는 예제를 살펴보죠!
(첫번째 이미지는 로드가 되었고 두, 세번째 이미지를 로드하고 있습니다.)

 

 

os signpost 함수 호출를 하면 시작과 끝을 두 시점의 이벤트를 서로 연관시킬 수 있습니다. 

 

 

 

import os.signpost
let refreshLog = OSLog(subsystem: "com.example.your-app", category: "RefreshOperations")
for element in panel.elements {
	os_signpost(.begin, log: refreshLog, name: "Fetch Asset")
	fetchAsset(for: element)
	os_signpost(.end, log: refreshLog, name: "Fetch Asset")
}

 

Category는 관련 작업을 그룹화하거나 관련 Signpost을 그룹화하는 데 사용됩니다.

 

위 코드를 실행하면 아래 그림과 같이 타임 라인이 생성됩니다.

(b == begin, e == end)

 

 

Measuring Asynchronous Intervals

비동기인 경우는 아래와 같이 호출됩니다. 

 

 

 

Signpost IDs

이름이 같고 동일한 OSLog에 기록되는 signpost를 구별하는 데 사용하는 식별자입니다.

 

let spid = OSSignpostID(log: refreshLog)
os_signpost(.begin, log: refreshLog, name: "Fetch Asset", signpostID: spid)
os_signpost(.end, log: refreshLog, name: "Fetch Asset", signpostID: spid) 

 

object: 를 추가할 수 있습니다.

제공된 개체를 사용하여 지정된 로그에 기록하는 signpost과 signpost 사이에서 고유 한 signpost 식별자를 만듭니다.

제공된 개체로 식별되기 때문에 signpost ID를 보관할 필요가 없습니다.

 

let spid = OSSignpostID(log: refreshLog)
let spid = OSSignpostID(log: refreshLog, object: element) 

 

SignpostIDs 타임라인

 

 

Adding Metadata to Signposts

signpost과 함께 추가 정보, 추가 성능 관련 정보를 전달할 수 있습니다.

 

Custom Metadata in Signpost Arguments

 

os_signpost(.begin, log: log, 
name: "Compute Physics", "for particle")  // 1

os_signpost(.begin, log: log, 
name: "Compute Physics",  "%d %d %d %d",  x1, y1, x2, y2)  // 2

os_signpost(.begin, log: log, 
name: "Compute Physics", "%{public}s %.1f %.1f %.2f %.1f %.1f", description, x1, y1, m, x2, y2)  // 3, 4

 

1. "for particle" 라는 String literal 를 추가 정보로 전달할 수 있습니다.

2. OSLog format 형식으로 전달할 수 있습니다.

3. 부동소수점을 전달할 수 있습니다.

4. "${public}"  동적 문자열을 전달할 수 있습니다. 

 

 

Adding Independent Events

.begin .end 뿐만 아니라 .event 로 사용자 정의 시점을 추가할 수 있습니다. 

 

 

 

os_signpost(.event, log: log, name: "Fetch Asset",
"Fetched first chunk, size %u", size)

os_signpost(.event, log: log, name: "Swipe",
 "For action 0x%x", actionCode) 

 

Event: Connected to service

Event: Fetched first chunk

해당 간격의 해당 시간 동안 특정 간격의 상태 또는 진행 상황을 여러 번 업데이트 할 수 있습니다.

 

 

 

Conditionally Enabling Signposts

.disabled 로 signpost 를 비활성화 시킬 수 있습니다. 

 

let refreshLog: OSLog
if ProcessInfo.processInfo.environment.keys.contains("SIGNPOSTS_FOR_REFRESH") {
 refreshLog = OSLog(subsystem: "com.example.your-app", category: "RefreshOperations")
} else {
 refreshLog = .disabled
}

 

특정 로그 핸들의 signpostsEnabled 켜져 있는지 확인할 수 있습니다.

 

if refreshLog.signpostsEnabled {
 let information = copyDescription()
 os_signpost(..., information)
} 

 

 

Demo

Sample Project 는 여기에서 다운받을 수 있습니다.

 

Xcode > Product > Profile

Profile 로 실행되면 아래 창이 뜹니다. 

"Blank" 를 선택합니다. 

 

 

우측에 "+" 버튼을 누르고 os_signpost 를 추가합니다.

 

 

 

빨간 네모 박스 녹화를 누르면 앱이 실행되면서 Profiling 이 실행됩니다.

 

 

 

let networking = OSLog(subsystem: "com.captech.blog-ios12-performance", category: "networking")
        os_signpost(
            OSSignpostType.begin,
            log: SignpostLog.networking,
            name: "Background Image",
            signpostID: OSSignpostID(log: SignpostLog.networking, object: self.imageLoader), "Image name:%{pulbic}@", article.title
        )

 

Category: "networking" 

Name: "Background Image"

Duration: Event 활동 시간

"%{public}@" 는 어떤걸 의미하는지 잘 모르겠습니다. 

 

Zoom: Option + Scroll 

 

 

마무리 

자동화 프로세스를 구축하는데 Performance 측정은 많은 도움이 될 것 같습니다.

마구잡이로 Log 코드를 추가하는 것이 아니라 전략적으로 Log 를 추가하면 

"일관성있는"  성능 측정에 많은 도움이 될 것 같습니다.

 

 

참조: 

https://developer.apple.com/videos/play/wwdc2018/405