구조화된 로깅으로 디버깅하기

♪ ♪

안녕하세요 저는 네이선입니다 Xcode Debugger UI 팀 엔지니어죠 오늘 소개해 드릴 것은 Xcode 15에 새롭게 추가된 디버그 콘솔입니다

이 세션에서는 디버그 콘솔을 간략히 살펴봅니다 또한 제 앱에서 실제 버그를 진단하여 디버그 콘솔이 얼마나 유용한지 보여 드리죠 그런 다음 LLDB에 적용된 개선 사항을 알아보겠습니다 마지막으로 Apple의 Unified Logging API를 활용해 진단 경험을 개선하는 팁을 공유하죠

그럼 디버그 콘솔의 새로운 기능을 살펴보겠습니다 Backyard Birds 앱을 기기에서 실행했습니다 뒷마당을 관리하고 가상의 새를 돌보는 앱이죠

앱을 실행한 후로 디버그 콘솔에 로그가 많이 채워졌습니다 그런데 콘솔이 각 로그에 제게 익숙한 메타데이터를 접두사로 붙이지 않는군요 대신 개발자가 제게 보여 주려는 기본 메시지에 집중하고 있죠 물론 계속해서 로그 관련 추가 정보를 보고 싶을 수도 있으니 그 기능을 제공하겠습니다 디버그 콘솔 왼쪽 하단의 메타데이터 옵션 버튼을 누르고 지금 가장 필요한 유형을 선택하면 되죠 저는 Type, Library, Subsystem Category를 선택하겠습니다

이걸 활성화하면 콘솔의 각 로그 아래에 메타데이터가 배치됩니다 더 작고 교묘해져서 의도된 출력을 방해하지 않죠 또한 노란색과 빨간색 배경의 로그도 보이는데요 해당 로그는 더 중요하며 저마다 오류와 결함을 나타낸다는 뜻입니다 모든 로그의 메타데이터를 한 번에 보고 싶지 않은 경우 단일 로그의 메타데이터를 콘솔에서 검사할 수 있습니다 해당 로그를 선택하고 스페이스 바를 눌러 빠르게 살펴볼 수 있죠 그러면 사용 가능한 메타데이터를 전부 제공하는 팝업 창이 뜹니다 여기에는 호출 사이트 등의 정보도 포함되어 로그를 처음 전송한 함수의 이름도 나타납니다 추가 메타데이터를 보는 것도 좋지만 새 디버그 콘솔의 진짜 강점은 필터링 기능입니다 콘솔은 중요하지 않은 로그로 가득 차기 십상인데요 Xcode 15에서는 아주 쉽게 필터링할 수 있습니다 이제 콘솔이 복잡하고 토큰화된 필터링을 수행해 가장 관련성 높은 로그를 쉽게 찾을 수 있죠 또한 콘솔에서 필터를 생성하는 방법도 다양합니다

물론 다음과 같이 필터 바에 직접 필터를 입력해도 됩니다

이렇게 하면 자동 완성 팝오버가 나타나 원하는 필터를 입력할 수 있게 도와주죠

또한 필터 메뉴에서 특정 유형 로그에 대한 필터에 빠르게 액세스하여 확인할 유형을 선택할 수 있습니다

마지막으로 필요하거나 불필요한 로그를 우클릭하면 유사한 로그를 숨기거나 보여주는 옵션을 제공합니다 특정 로그 집합을 더 자세히 다루거나 뷰에서 제거할 수 있죠 이렇게요

이러한 필터링 메서드를 통해 빠르고 효율적으로 모든 출력을 정리할 수 있으며 현재 디버깅 요구 사항에 가장 적절한 로그를 찾을 수 있습니다 이번에는 새로운 디버그 콘솔을 사용해 앱에서 실제 문제를 찾고 해결해 보겠습니다 일부 사용자가 프로필을 업데이트한 후 콘텐츠가 저장되지 않는다는 리포트를 보냈는데요 올바른 로깅 사례를 살펴보고 새 디버그 콘솔을 활용하여 버그 원인을 쉽고 빠르게 파악해 봅시다

먼저 탭 막대의 계정을 선택하여 문제를 재현해 보겠습니다 연필을 눌러서 계정을 편집합니다

마지막으로 닉네임을 바꿉니다

이름이 바뀐 것 같지만 페이지에서 나간 뒤 계정을 다시 보면 변경이 적용되지 않았죠 몇 가지 원인이 떠오르는데요 새로운 디버그 콘솔로 그 범위를 좁히고 문제 원인을 찾는 법을 알아봅시다 작업을 수행하는 동안 디버그 콘솔에 다량의 출력이 생성되었습니다 다행히 새 콘솔에서는 로그가 아무리 많아도 괜찮습니다 필터를 설정하여 원하는 로그를 찾을 수 있으니까요 이 경우에는 계정 관리 전용 카테고리가 몇 개 있습니다 여기에 집중하기 위해 프로젝트에서 '계정'이 포함된 모든 카테고리를 필터링합니다 필터 필드에 계정을 입력하고 팝업에서 카테고리 필터를 선택하세요

그러면 코드에서 계정과 관련한 로깅만 남게 됩니다 필터를 설정하면 출력 관리가 훨씬 쉬워지죠 displayName 프로퍼티 설정 요청이 있었음을 몇몇 로그가 보여 주는군요 앱이 제대로 작동하지 않는 원인을 더 자세히 조사해 보죠 코드의 위치가 정확히 기억나지 않는데요 궁금한 로그 위로 마우스를 가져가서 오른쪽 밑의 소스 위치를 선택합니다

그러면 Xcode가 로그 소스로 이동하는데요 이 경우 제가 닉네임 변경을 요청한 곳이죠 소스 코드를 검토해 보니 setDisplayName 함수를 현재 계정에 호출해서 작업을 수행한 것 같군요 계정 정보 업데이트를 담당하는 함수로 이동하여 문제를 자세히 조사해 보겠습니다 코드를 더 검토해 보니 중앙 계정 데이터베이스로 변경 사항을 전송하긴 했지만 로컬 계정 캐시 업데이트를 빠뜨린 것 같네요 데이터베이스를 업데이트한 뒤에는 이렇게 로컬 닉네임을 새로 설정해야 합니다

이메일 주소에서도 같은 버그를 발견했는데요 다행히 같은 방식으로 해결할 수 있습니다

이제 중단점을 설정하여 의심스러운 부분을 확인하고 문제가 해결됐는지 보죠

이번에는 앱을 다시 빌드하고 이전 단계를 재생성하여 이 위치에서 중단하겠습니다 해당 위치에 도달했으니 제 추측이 맞는지 확인해 보죠 계정의 현 상태를 po하고 예상대로 이전 데이터가 나오는지 봅시다

이런, 객체의 주소만 나오네요 왜 그럴까요? 사실 po는 아주 흔히 쓰이지만 제가 실행해야 하는 표현식 유형이 아닙니다 이 클래스에 사용자 지정 디버그 설명을 선언하지 않았기 때문이죠 p만 실행하는 게 나을 듯하니 그렇게 해 보겠습니다

제가 원한 결과입니다 데이터베이스 업데이트만으로 닉네임이 설정되지 않는다는 제 추측이 맞았군요 제가 추가한 줄로 넘어가서 닉네임이 업데이트됐는지 확인해 보죠

좋아요, 업데이트가 문제를 해결했습니다 새들에게 다시 먹이를 줄 수 있겠어요 이번에는 Xcode 15의 LLDB를 살펴봅시다 간단한 LLDB 표현식을 더욱 개선했죠 방금 버그를 해결하면서 적절하지 않은 곳에 po를 사용했는데요 이런 경우 표현식 수행이 더 오래 걸릴 수도 있지만 최악의 경우 프로퍼티의 주소만 반환합니다 저처럼 CustomStringConvertible을 구현하지 않았다면요 답답한 상황이라 더 나은 옵션이 필요했습니다 그래서 프로퍼티에 p를 실행하여 올바른 결과를 얻었죠 하지만 그 외에도 표현식이나 v, vo, 프레임 변수 등 기억해야 하는 다른 커맨드가 많습니다 쉽지 않은 일이죠 그래서 개발자분들을 위해 Do What I Mean Print를 소개합니다 Do What I Mean Print를 쓰면 한 가지 명령으로 코드의 다양한 표현식을 평가해 시간을 절약하는 동시에 가장 빠르게 결과를 반환할 수 있습니다

물론 변수를 검사할 때마다 이렇게 긴 커맨드를 입력할 수는 없죠 그래서 기존의 p 별칭이 Do What I Mean Print를 수행하도록 대체했습니다 대부분의 사용 예에서 간단히 p를 실행하면 되죠 또 변수에 대한 사용자 정의 객체 설명을 프린트하고 싶은 경우에는 선택적 객체 설명 플래그와 함께 Do What I Mean Print 커맨드를 실행해도 됩니다 하지만 이제 기존의 po 별칭도 사용자 지정 객체 설명과 함께 Do What I Mean Print를 수행할 수 있죠 새로운 Do What I Mean Print 함수로 과거에는 여러 가지 커맨드가 필요했던 다양한 표현식의 커맨드를 둘 중 하나만 실행하여 가장 빠르게 원하는 출력을 얻을 수 있습니다 마지막으로 알아볼 것은 로깅을 최대한 활용하는 방법입니다 디버깅 경험을 개선하고 효율적으로 문제를 찾아서 해결할 수 있게요 재현이 어렵거나 사용자 리포트에 의존하는 문제여도 말이죠 먼저 짚고 넘어갈 것은 표준 I/O는 명령행 UI용이고 OSLog는 디버깅용이라는 것입니다 프로그램 실행 중 이벤트 로깅에 프린트를 쓰는 경우는 거의 없죠 OSLog로 엔드 유저에게서 구조화된 로깅을 얻고 디버그 콘솔에서 구조를 유지하는 게 훨씬 낫습니다 지금부터 몇 가지 예제를 통해 표준 I/O에서 OSLog로 변환하는 게 얼마나 쉬운지 알아보죠 간단한 함수에 몇 가지 로깅을 추가해 보겠습니다 실행 중인 작업이나 해당 작업의 결과를 로깅하는 건 좋은 습관이죠 제가 아는 한 가장 좋은 방법으로 그 기능을 추가해 보겠습니다 좋아요, 코드를 따르는 데 유용한 간단한 print문을 몇 개 추가했습니다 이제 이 함수에서 수행 중인 작업을 프린트하고 작업이 끝나면 그 결과도 프린트할 수 있죠 그런데 프로젝트 내 여러 곳에서 실행하다 보니 모든 출력의 출처를 찾기가 어려워졌습니다 그래서 프린트에 마커를 추가해야 했죠 여러분도 그랬을 거예요 하지만 이런 작업은 번거롭습니다 이 많은 추가 출력을 더하니 콘솔이 더욱 복잡해졌죠 추가 작업 없이 메타데이터를 얻는 더 나은 방법이 필요합니다 OSLog가 바로 그런 기능을 제공합니다 이 기능을 업데이트하여 Unified Logging을 활용해 보죠 먼저 OSLog를 프로젝트에 불러와 로그 핸들을 만들 수 있게 해야 합니다 여기서 로그에 표시할 하위 시스템과 카테고리를 정할 수 있죠 디버그 필터링을 돕는 문자열을 쓸 수도 있지만 보통은 하위 시스템의 번들 식별자나 카테고리의 클래스 및 컴포넌트 이름을 씁니다 로거를 생성한 후에는 로거 객체에서 제공된 함수를 호출하여 로그 수준을 지정하고 표시할 메시지를 제공하면 됩니다 이렇게 하면 읽기도 쉽고 장기적으로 코드가 훨씬 적어지죠 이제 코드를 실행하면 콘솔에서 어떻게 보이는지 살펴보죠

로그 두 개를 분리하여 모든 메타데이터의 출처를 검사해 보겠습니다 로그 출력을 보면 출력하고자 한 메시지와 함께 로그에 지정한 추가 메타데이터가 바로 아래에 나타납니다 메타데이터 일부는 메시지나 레벨 등의 초기 로그를 작성한 위치에서 수집됩니다 또 일부는 반복을 저장하는 로그 핸들을 만들 때 수집됐죠 하위 시스템이나 카테고리처럼요 몇몇은 백그라운드에서 처리됐습니다 타임스탬프와 라이브러리 이름 프로세스 ID, 스레드 ID 소스 위치 등이 포함되죠 이 모든 정보는 필요시에는 매우 유용하지만 모든 로그를 프린트할 경우 공간을 많이 차지합니다 다행히 새로운 디버그 콘솔은 원하는 정보만 제공하도록 뷰를 사용자화할 수 있죠 마지막으로 로깅을 최대한 활용하려면 앱을 빌드할 때 다음 사항을 고려하세요 첫째, 반드시 앱의 다양한 요소마다 별도의 로그 핸들을 만들어야 합니다 그래야 기본 메타데이터에 중요한 검색어를 설정하여 앱의 섹션과 관련성 높은 로그를 빠르게 찾을 수 있죠 또한 OSLogStore를 활용하면 앱에 실제로 문제가 발생했을 때 유용한 진단 정보를 수집할 수 있습니다 마지막으로 OSLog는 추적 기능이라는 점을 명심하세요 따라서 Instruments 같은 도구를 사용하여 앱의 복잡한 성능을 분석할 수 있죠 이 예제에서는 로깅 프로파일링 템플릿으로 앱의 성능을 분석합니다 OSLog와 signposts를 사용해서요 오늘 살펴본 내용과 프로그래밍 경험을 개선하는 법을 요약해 보겠습니다 우선 Xcode 15에서 새 디버그 콘솔을 살펴보세요 로깅에 필요한 수많은 개선 사항이 적용됐습니다 또한 코드를 표준 I/O에서 OSLog로 마이그레이션하여 디버그 콘솔의 새로운 기능을 누려 보세요 LLDB의 새 Do What I Mean Print 혹은 p 커맨드도 써 보시고요 이러한 커맨드는 변수 검사를 먼저 수행할 때 사용해야 합니다 또한 Apple의 Unified Logging API에 대한 자세한 내용은 이전 세션인 '로깅을 통한 성능 측정'과 'Swift로 로깅하기'를 참조하세요 즐거운 로깅하세요 시청해 주셔서 감사합니다