spandex-project / spandex

A platform agnostic tracing library
MIT License
333 stars 53 forks source link

Guard clauses for trace and span macros #130

Closed GregMefford closed 3 years ago

GregMefford commented 3 years ago

While updating one of our apps from Spandex 2.4.4 to 3.0.3, we hit an issue where it was crashing at runtime where it hadn't before. We traced it down to these new Spandex error logs that weren't using inspect and were failing to encode a keyword list of opts as a string, because at some earlier point, we had moved from using Decorators to using the Tracer macros and made a mistake in the conversion:

From:

@decorate trace(name: "somename", service: "someservice")
def some_function do
  :noop
end

To:

def some_function do
  Tracer.trace(name: "somename", service: "someservice") do
    :noop
  end
end

Instead of:

def some_function do
  Tracer.trace("somename", service: "someservice") do
    :noop
  end
end

The bug here was subtle: rather than passing in a name and opts, we're accidentally passing in our opts as the name, with the optional opts being defaulted to []. Normally, that would have caused some other crash elsewhere when trying to use that name as a string, but in this case, we also had decorated this code as a trace when it should have been a span, so the only thing that was happening is the Logger.error message warning us that we already had an active trace, which we hadn't noticed yet and it wasn't causing a crash until the code was introduced to log the name.

So anyway, with this change I am using inspect to protect those particular log messages against runtime exceptions and also adding guard clauses, which should be reasonably safe because the macro itself runs at compile time, so it generates a compiler error like the following if you're trying to call it wrong like we were:

== Compilation error in file lib/my_service/my_module.ex ==
** (FunctionClauseError) no function clause matching in MyService.Tracer."MACRO-trace"/4    

    The following arguments were given to MyService.Tracer."MACRO-trace"/4:

        # 1                      
        #Macro.Env<...>

        # 2                                        
        [name: "somename", service: "someservice"]                                                          

        # 3                            
        []

        # 4                             
        [do: :noop]            

    lib/my_service/tracer.ex:3: MyService.Tracer."MACRO-trace"/4
    expanding macro: Spandex.Test.Support.OtherTracer.trace/2                       
    lib/my_service/my_module.ex:2: MyService.MyModule.some_function/0

IMO, this is better than actually putting a guard clause on Spandex.trace because that would crash at runtime instead of compile time. Doing it this way means that when someone upgrades, the compiler will point them directly at the problem so they can fix it before they deploy new code. That being said, should this be considered a non-breaking change, because it will only require a code change if they're already calling the macro incorrectly? 🤔