Đọc một bản ghi Time Profiler mà không cần đoán

Mười lần đầu mở Time Profiler, tôi nhìn cái cây lời gọi, thấy start_wqthread chiếm 94%, gật gù, rồi đóng lại. Nó là một công cụ đáng sợ chủ yếu vì khung nhìn mặc định gần như vô dụng.

Bốn thiết lập và một thói quen đã biến nó thành thứ tôi với tới đầu tiên.

Bốn ô đánh dấu

Trong phần tùy chọn Call Tree ở đáy cửa sổ:

• Separate by Thread — bật. Nếu không thì công việc trên luồng chính và công việc chạy nền bị cộng gộp, và con số bạn quan tâm (luồng chính có bận không?) bị chôn mất.
• Invert Call Tree — bật, để bắt đầu. Nó đưa những hàm thật sự tiêu tốn thời gian lên trên cùng, thay vì bắt bạn lần từ main đi xuống.
• Hide System Libraries — bật. Đây là cái quan trọng nhất. Nó gỡ bỏ mọi khung không phải code của bạn, thường co một cái cây 40 tầng lại thành thứ đọc được.
• Flatten Recursion — bật nếu bạn có đệ quy, tắt nếu không.

Với bốn cái đó, phần trên của cây đảo ngược là một bảng xếp hạng các hàm của bạn theo thời gian tiêu tốn trong chúng. Đó mới là báo cáo bạn thật sự muốn.

Đọc self time, đừng đọc total

Cột quan trọng là self weight — thời gian tiêu tốn trong chính các lệnh của hàm đó, không tính các hàm nó gọi. Total weight nói cho bạn biết viewDidLoad chiếm 80% thời gian khởi động, điều đó đúng và vô dụng. Self weight nói cho bạn biết hàm cụ thể nào đang đốt chu kỳ CPU.

Quy trình tôi dùng:

1. Đảo cây, ẩn thư viện hệ thống, sắp xếp theo self weight.
2. Nhìn năm mục đầu. Thời gian nằm ở đó.
3. Bỏ đảo cây rồi bung từ main xuống để xem ai đã gọi cái thứ đắt đỏ ấy, vì cách chữa thường nằm ở chỗ gọi chứ không nằm trong hàm.

Bước thứ ba mới thường là chỗ có được cái nhìn thật sự. Một hàm mất 200ms là một vấn đề; một hàm mất 2ms bị gọi một trăm lần từ một vòng lặp đáng lẽ chỉ chạy một lần là một vấn đề khác với một cách chữa tốt hơn nhiều.

Lấy mẫu nghĩa là nó nói dối về những thứ ngắn

Mặc định Time Profiler lấy mẫu ngăn xếp mỗi mili giây. Điều đó có hai hệ quả khiến người ta vấp.

Bất cứ thứ gì ngắn hơn khoảng lấy mẫu đều có thể không xuất hiện. Một hàm chạy trong 100µs chỉ hiện ra nếu nó chạy đủ thường xuyên để bị bắt gặp. Vắng mặt khỏi bản ghi không phải bằng chứng cho sự nhanh.

Các phần trăm là của thời gian thực tế, không phải thời gian CPU. Một luồng đang chặn chờ một lời gọi mạng hay một cái khóa thì vẫn bị lấy mẫu, và cái khung nó đang chặn ở đó vẫn tích lũy trọng số. Đó là lý do việc chờ đợi trông giống như đang làm việc.

Luôn đo trên bản Release

Bản Debug tắt các tối ưu. Nghĩa là không nội tuyến, không chuyên biệt hóa generic, có những lời gọi retain và release lẽ ra đã bị lược bỏ, và có những phép kiểm tra biên lẽ ra đã bị gỡ đi.

Kết quả không phải “y hệt nhưng chậm hơn”. Nó là một hình dạng hiệu năng khác, và đã hai lần tôi tối ưu một thứ trong bản Debug mà hóa ra chẳng tốn gì trong bản Release. Hãy đo đúng cấu hình bạn phát hành.

Điều tương tự áp dụng cho thiết bị. Simulator chạy trên CPU của máy Mac, thứ nhanh hơn điện thoại vài lần và có đặc tính bộ nhớ hoàn toàn khác. Một bản ghi từ simulator nói cho bạn về cái máy Mac của bạn.

Thói quen còn quan trọng hơn công cụ

Hãy lấy một bản ghi trước khi bạn sửa bất cứ thứ gì, và lưu nó lại.

Nghe thì hiển nhiên mà tôi đã không làm suốt nhiều năm. Không có đường cơ sở thì bạn không biết thay đổi của mình có giúp ích không, và cám dỗ tuyên bố chiến thắng thì cực lớn, vì ứng dụng “cảm giác” nhanh hơn sau một buổi chiều làm việc. Đã hai lần, một thay đổi mà tôi chắc mẩm hóa ra trung tính, và tôi chỉ biết được vì có bản ghi trước đó để so.

Instruments cho phép mở hai bản ghi cạnh nhau. Hãy dùng nó.

Nó tìm ra gì trong trường hợp của tôi

Chuyện cụ thể khiến tôi phải học tử tế công cụ này: một màn hình danh sách mất khoảng 900ms mới hiện ra, thứ tôi vẫn đinh ninh là do độ trễ mạng.

Cây đảo ngược với thư viện hệ thống bị ẩn đưa DateFormatter.string(from:) lên đầu với 61% self weight. Tôi đang tạo một bộ định dạng bên trong một map trên phản hồi, mỗi dòng một cái, mà việc khởi tạo DateFormatter thì nổi tiếng đắt đỏ — nó nạp dữ liệu locale mỗi lần.

// trước: mỗi dòng một bộ định dạng
items.map { ItemViewModel(date: DateFormatter().string(from: $0.date), …) }

// sau: một bộ định dạng, dùng lại
let formatter = DateFormatter()
formatter.dateStyle = .medium
items.map { ItemViewModel(date: formatter.string(from: $0.date), …) }

Từ 900ms xuống 140ms, chỉ nhờ chuyển một dòng ra khỏi một closure. Tôi đã chẳng bao giờ đoán ra — tôi vốn đã sẵn sàng thêm phân trang và một lớp cache để chữa một vấn đề không tồn tại.

Đó mới thật sự là lập luận cho công cụ này. Không phải việc đo hiệu năng làm bạn tối ưu nhanh hơn, mà là nó ngăn bạn tối ưu hoàn toàn nhầm chỗ.