Module: TraceView::API::Logging

Defined in:
lib/traceview/api/logging.rb

Overview

This modules provides the X-Trace logging facilities.

Instance Method Summary collapse

Instance Method Details

#log(layer, label, opts = {}) ⇒ Object

Public: Report an event in an active trace.

Arguments

  • layer - The layer the reported event belongs to

  • label - The label for the reported event. See API documentation for reserved labels and usage.

  • opts - A hash containing key/value pairs that will be reported along with this event (optional).

Example

TraceView::API.log('logical_layer', 'entry')
TraceView::API.log('logical_layer', 'info', { :list_length => 20 })
TraceView::API.log('logical_layer', 'exit')

Returns nothing.



33
34
35
36
37
 
# File 'lib/traceview/api/logging.rb', line 33

def log(layer, label, opts = {})
  return unless TraceView.loaded

  log_event(layer, label, TraceView::Context.createEvent, opts)
end

#log_end(layer, opts = {}) ⇒ Object

Public: Report an exit event and potentially clear the tracing context.

Attributes

  • layer - The layer the reported event belongs to

  • opts - A hash containing key/value pairs that will be reported along with this event (optional).

Example

TraceView::API.log_end(:layer_name, { :id => @user.id })

Returns an xtrace metadata string



151
152
153
154
155
156
157
158
 
# File 'lib/traceview/api/logging.rb', line 151

def log_end(layer, opts = {})
  return unless TraceView.loaded

  log_event(layer, :exit, TraceView::Context.createEvent, opts)
  xtrace = TraceView::Context.toString
  TraceView::Context.clear unless TraceView.has_incoming_context?
  xtrace
end

#log_entry(layer, kvs = {}, op = nil) ⇒ Object

Public: Log an entry event

A helper method to create and log an entry event

Attributes

  • layer - The layer the reported event belongs to

  • kvs - A hash containing key/value pairs that will be reported along with this event (optional).

  • op - To identify the current operation being traced. Used to avoid double tracing recursive calls.

Example

TraceView::API.log_entry(:layer_name, { :id => @user.id })

Returns an xtrace metadata string



176
177
178
179
180
181
 
# File 'lib/traceview/api/logging.rb', line 176

def log_entry(layer, kvs = {}, op = nil)
  return unless TraceView.loaded

  TraceView.layer_op = op.to_sym if op
  log_event(layer, :entry, TraceView::Context.createEvent, kvs)
end

#log_event(layer, label, event, opts = {}) ⇒ Object

Internal: Report an event.

Attributes

  • layer - The layer the reported event belongs to

  • label - The label for the reported event. See API documentation for reserved labels and usage.

  • event - The pre-existing TraceView context event. See TraceView::Context.createEvent

  • opts - A hash containing key/value pairs that will be reported along with this event (optional).

Example

entry = TraceView::Context.createEvent
TraceView::API.log_event(:layer_name, 'entry',  entry_event, { :id => @user.id })

exit_event = TraceView::Context.createEvent
exit_event.addEdge(entry.getMetadata)
TraceView::API.log_event(:layer_name, 'exit',  exit_event, { :id => @user.id })



246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
 
# File 'lib/traceview/api/logging.rb', line 246

def log_event(layer, label, event, opts = {})
  return unless TraceView.loaded

  event.addInfo(TV_STR_LAYER, layer.to_s.freeze) if layer
  event.addInfo(TV_STR_LABEL, label.to_s.freeze)

  TraceView.layer = layer.to_sym if label == :entry
  TraceView.layer = nil          if label == :exit

  opts.each do |k, v|
    value = nil

    next unless valid_key? k

    if [Integer, Float, Fixnum, NilClass, String].include?(v.class)
      value = v
    elsif v.class == Set
      value = v.to_a.to_s
    else
      value = v.to_s if v.respond_to?(:to_s)
    end

    begin
      event.addInfo(k.to_s, value)
    rescue ArgumentError => e
      TraceView.logger.debug "[TraceView/debug] Couldn't add event KV: #{k} => #{v.class}"
      TraceView.logger.debug "[TraceView/debug] #{e.message}"
    end
  end if !opts.nil? && opts.any?

  TraceView::Reporter.sendReport(event)
end

#log_exception(layer, exn, kvs = {}) ⇒ Object

Public: Report an exception.

Arguments

  • layer - The layer the reported event belongs to

  • exn - The exception to report

  • kvs - Custom params if you want to log extra information

Example

begin
  my_iffy_method
rescue Exception => e
  TraceView::API.log_exception('rails', e, { user: user_id })
  raise
end

Returns nothing.



58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
 
# File 'lib/traceview/api/logging.rb', line 58

def log_exception(layer, exn, kvs = {})
  return if !TraceView.loaded || exn.instance_variable_get(:@oboe_logged)

  unless exn
    TV.logger.debug '[traceview/debug] log_exception called with nil exception'
    return
  end

  kvs.merge!(:ErrorClass => exn.class.name,
             :ErrorMsg => exn.message,
             :Backtrace => exn.backtrace.join("\r\n"))

  exn.instance_variable_set(:@oboe_logged, true)
  log(layer, :error, kvs)
end

#log_exit(layer, kvs = {}, op = nil) ⇒ Object

Public: Log an exit event

A helper method to create and log an exit event

Attributes

  • layer - The layer the reported event belongs to

  • kvs - A hash containing key/value pairs that will be reported along with this event (optional).

  • op - To identify the current operation being traced. Used to avoid double tracing recursive calls.

Example

TraceView::API.log_exit(:layer_name, { :id => @user.id })

Returns an xtrace metadata string



220
221
222
223
224
225
 
# File 'lib/traceview/api/logging.rb', line 220

def log_exit(layer, kvs = {}, op = nil)
  return unless TraceView.loaded

  TraceView.layer_op = nil if op
  log_event(layer, :exit, TraceView::Context.createEvent, kvs)
end

#log_info(layer, kvs = {}) ⇒ Object

Public: Log an info event

A helper method to create and log an info event

Attributes

  • layer - The layer the reported event belongs to

  • kvs - A hash containing key/value pairs that will be reported along with this event (optional).

Example

TraceView::API.log_info(:layer_name, { :id => @user.id })

Returns an xtrace metadata string



198
199
200
201
202
 
# File 'lib/traceview/api/logging.rb', line 198

def log_info(layer, kvs = {})
  return unless TraceView.loaded

  log_event(layer, :info, TraceView::Context.createEvent, kvs)
end

#log_start(layer, xtrace = nil, opts = {}) ⇒ Object

Public: Decide whether or not to start a trace, and report an event appropriately.

Attributes

  • layer - The layer the reported event belongs to

  • xtrace - An xtrace metadata string, or nil. Used for cross-application tracing.

  • opts - A hash containing key/value pairs that will be reported along with this event (optional).

Example

TraceView::API.log_start(:layer_name, nil, { :id => @user.id })



88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
 
# File 'lib/traceview/api/logging.rb', line 88

def log_start(layer, xtrace = nil, opts = {})
  return if !TraceView.loaded || (opts.key?(:URL) && ::TraceView::Util.static_asset?(opts[:URL]))

  # For entry only layers (DelayedJob workers, Sidekiq workers), auto-set the tracing mode
  # Don't do this if tracing mode is already :always or :never
  if TraceView.through? && TraceView.entry_layer?(layer)
    TraceView.logger.debug "[traceview/debug] Detected #{layer}: auto-configuring tracing mode"
    TraceView::Config[:tracing_mode] = :always
  end

  # Used by JRuby/Java webservers such as Tomcat
  TraceView::Context.fromString(xtrace) if TraceView.pickup_context?(xtrace)

  if TraceView.tracing?
    # Pre-existing context.  Either we inherited context from an
    # incoming X-Trace request header or under JRuby, Joboe started
    # tracing before the JRuby code was called (e.g. Tomcat)
    TraceView.is_continued_trace = true

    if TraceView.has_xtrace_header
      opts[:TraceOrigin] = :continued_header
    elsif TraceView.has_incoming_context
      opts[:TraceOrigin] = :continued_context
    else
      opts[:TraceOrigin] = :continued
    end

    log_entry(layer, opts)

  elsif opts.key?('Force')
    # Forced tracing: used by __Init reporting
    opts[:TraceOrigin] = :forced
    log_event(layer, :entry, TraceView::Context.startTrace, opts)

  elsif TraceView.sample?(opts.merge(:layer => layer, :xtrace => xtrace))
    # Probablistic tracing of a subset of requests based off of
    # sample rate and sample source
    opts[:SampleRate]        = TraceView.sample_rate
    opts[:SampleSource]      = TraceView.sample_source

    if TraceView.through? && opts.key?('X-TV-Meta')
      opts[:TraceOrigin]       = :avw_sampled
    else
      opts[:TraceOrigin]       = :always_sampled
    end

    log_event(layer, :entry, TraceView::Context.startTrace, opts)
  end
end