Đôi khi rất khó hiểu đang xảy ra gì với ngoại lệ - nhất là trong app lớn. Tưởng tượng bạn đang làm việc trên code trong project hiện có. Bạn raise ngoại lệ, rồi điều kỳ lạ xảy ra. Có thể ngoại lệ bị nuốt. Có thể biến môi trường bị thay đổi. Có thể ngoại lệ của bạn bị wrap trong ngoại lệ khác.
Tôi sẽ chỉ cho bạn cách đơn giản dùng TracePoints để lấy thêm thông tin về ngoại lệ trong app - ngay cả khi ngoại lệ bị nuốt.
Một ví dụ tiện lợi
Ranh giới giữa controller và view trong Rails là nơi ngoại lệ dường như thách thức logic. Dễ thấy ngay. Chỉ cần raise ngoại lệ trong view và thử rescue nó trong controller. Bạn sẽ thấy KHÔNG THỂ rescue template error từ controller!
# pages_controller.rb def index render rescue # this will never run logger.debug "someone raised the roof" end # index.haml - raise "the roof" 
WTF!?! Tôi tưởng tôi đã rescue này!
Rõ ràng có điều gì đó tricky đang diễn ra. Hãy xem có thể tìm ra không.
Log tất cả ngoại lệ với TracePoint
TracePoints là công cụ introspection mạnh mẽ từ Ruby 2.0. Chúng cho phép định nghĩa callback cho nhiều loại runtime event. Ví dụ, bạn có thể được thông báo khi class được định nghĩa, khi method được gọi hoặc khi ngoại lệ được raise. Xem docs TracePoint cho thêm event.
Hãy bắt đầu bằng cách thêm TracePoint được gọi mỗi khi ngoại lệ được raise và viết tóm tắt vào log.
class PagesController < ApplicationController def index TracePoint.new(:raise) do |tp| # tp.raised_exeption chứa đối tượng ngoại lệ thực tế được raise! logger.debug "#{tp.raised_exception.object_id}: #{tp.raised_exception.class} #{tp.raised_exception.message} ".yellow + tp.raised_exception.backtrace[0].sub(Rails.root.to_s, "").blue end.enable do render end end end Nếu bạn tò mò về phương thức yellow và blue, tôi dùng gem colorize. Nó thêm ANSI color codes vào output.
Khi tôi refresh trang, log trông như screenshot dưới. Một điều thú vị bạn có thể nhận ra là có hai ngoại lệ riêng biệt, và mỗi cái được raise hai lần. Con số dài ở đầu mỗi dòng là object id của Exception. Đó là cách chúng ta biết có hai đối tượng ngoại lệ, không phải bốn.
Log này hiển thị mọi lần dùng raise trong quá trình render
Phương thức nào gây ra raise nào?
Có danh sách event "raise" khá hữu ích. Nhưng sẽ tốt hơn nếu biết phương thức nào gây ra mỗi raise. Một lần nữa, TracePoint đến giải cứu.
TracePoint cho phép thêm handler được gọi mỗi khi method return. Nó đơn giản như event "raise". Trong ví dụ dưới, chúng ta log mọi method return:
TracePoint.trace(:return) do |tp| logger.debug [tp.method_id, tp.lineno, tp.path.sub(Rails.root.to_s, "")].join(" : ").green end Có một vấn đề. Nếu bạn thêm code này vào Rails app, bạn sẽ thấy app ngừng respond request. Có quá nhiều method call trong request Rails đơn giản nhất khiến server timeout trước khi viết hết vào log.
Vì chúng ta chỉ quan tâm method call gây ra exception, hãy sửa code để output hai event "return" đầu tiên xảy ra sau mỗi exception.
class PagesController < ApplicationController def index counter = 0 return_trace = TracePoint.trace(:return) do |tp| logger.debug "\t" + [tp.method_id, tp.lineno, tp.path.sub(Rails.root.to_s, "")].join(" : ").green if (counter += 1) > 3 return_trace.disable counter = 0 end end return_trace.disable # disable tracepoint mặc định TracePoint.new(:raise) do |tp| logger.debug "#{tp.raised_exception.object_id}: #{tp.raised_exception.class} #{tp.raised_exception.message} ".yellow + tp.raised_exception.backtrace[0].sub(Rails.root.to_s, "").blue # "raise" enable "return" tracepoint return_trace.enable end.enable do render end end end Khi tôi refresh browser, thấy các dòng sau được thêm vào log:
Mỗi event "raise" được hiển thị phía trên method gây ra nó
Vì chúng ta chỉ enable "return" TracePoint khi ngoại lệ được raise, event "return" đầu tiên sẽ là từ method raise ngoại lệ.
Chúng ta có thể dùng thông tin này để giải quyết bí ẩn. RuntimeError gốc của chúng ta đang bị chuyển thành ActionView::Template::Error bởi phương thức handle_render_error dòng 310 của template.rb.
Điều hay của kỹ thuật này là nó không liên quan đến Rails. Bạn có thể dùng bất cứ khi nào cần hiểu chi tiết hơn ngoại lệ nào đang được raise và catch dưới đáy.