Using trace() for debugging

Using trace() to debug

The built-in trace() function is the recommended method of viewing variables values for debugging. We also mention the use of print() and explain why using the trace() function is (usually) better.

First a basic example:

As you can see trace() is very simple, it just displays its parameters in the annotation block.

See this blog post for an in depth discussion on how to make the best use of tracepoints.

Tracing an HL7 message [top]

In this example we have created an Out message and we want to check it its contents:

  • When it is created to confirm it is empty

    Note: we did not need to use trace() as clicking on ADT at the end of line 6 will open the same message.

  • After we used mapTree() to copy the Msg to Out, trace() shows that the whole message was copied
  • When we use mapRange() to copy part of Msg to Out2, trace() shows that only the first two segments were copied

Here is the code:

function main(Data)
   local Msg = hl7.parse{vmd = 'demo.vmd', data = Data}
   local Out = hl7.message{vmd = 'demo.vmd', name = Msg.MSH[9][1]:nodeValue()}
   -- the first trace() shows the empty message
   trace(Out)
   -- NOTE: you can also click ADT at the end of line 6 to view this message

   -- Map the all segments from the incoming message to the outgoing message
   Out:mapTree(Msg)
   trace(Out)

   -- However if you only want to see demographic info for patient
   local Out2 = hl7.message{vmd = 'demo.vmd', name = Msg.MSH[9][1]:nodeValue()}
   Out2:mapRange(Msg, 1, 2)
   trace(Out2)  
end

Tracing multiple variables [top]

In this example we created four variables and showed various trace() options:

  • Tracing one or more parameters.
  • Tracing an updated numeric variable.
  • Tracing an updated string variable.

Here is the code:

function main(Data)
   local age     = 10
   local age_str = '10'
   local c       = 'place'
   local d       = 'holder'
   
   -- we can trace one or more parameters
   trace(age)
   trace(age, age_str)
   trace(age, age_str, c)
   trace(age, age_str, c, d)
   
   -- not sure why you would want to do this - but you can
   trace(_, age)
   trace(_,_, age)
   trace(nil, nil, age)
   
   -- imagine that "age_from db" was retrieved from a database
   local age_from_db = 33
   age = age_from_db
   age_str = tostring(age_from_db)
   
   -- show that "age" and age_str were updated
   trace(age, age_str)
   
end

Why not use print() to debug? [top]

The first impression when using trace() and print() is that the results are identical, and it is true that the Annotations that they produce are the same:

However there is one major difference when you run the channel, print() creates a informational Iguana Log entry but trace() does not. So to prevent the Log from being cluttered with debugging information we recommend that you use trace().

I ran 200 sample messages through the channel and the print statement created 200 informational message entries in the log. The last few messages are shown. As you can see this is not desirable behaviour, particularly if you are processing tens of thousands of messages per day.

Note: The Iguana queue is not active in the editor (test mode). So the log messages from print() are only created when the channel is run.

Tip: A better way to create informational messages is to use the Iguana logging functions. These give you control over which type of message you want to create.

  • logDebug : Add a log entry (Debug) with the given text.
  • logError : Add a log entry (Error) with the given text.
  • logInfo : Add a log entry (Info) with the given text.
  • logWarning : Add a log entry (Warning) with the given text.
Tagged: