Refactored: Extract log to Components

docs/GettingStarted.md

@@ -1567,7 +1567,6 @@ Available options are:
  - `port`: set the port the trace agent is listening on.
  - `env`: set the environment. Rails users may set it to `Rails.env` to use their application settings.
  - `tags`: set global tags that should be applied to all spans. Defaults to an empty hash
- - `log`: defines a custom logger.
  - `partial_flush`: set to `true` to enable partial trace flushing (for long running traces.) Disabled by default. *Experimental.*
 
 #### Custom logging
@@ -1576,15 +1575,16 @@ By default, all logs are processed by the default Ruby logger. When using Rails,
 
 Datadog client log messages are marked with `[ddtrace]` so you should be able to isolate them from other messages.
 
-Additionally, it is possible to override the default logger and replace it by a custom one. This is done using the `log` attribute of the tracer.
+Additionally, it is possible to override the default logger and replace it by a custom one. This is done using the `log` setting.
 
 ```ruby
-f = File.new("my-custom.log", "w+")           # Log messages should go there
+f = File.new("my-custom.log", "w+") # Log messages should go there
 Datadog.configure do |c|
-  c.tracer log: Logger.new(f)                 # Overriding the default tracer
+  c.log = Logger.new(f) # Overriding the default logger
+  c.log.level = ::Logger::INFO
 end
 
-Datadog::Logger.log.info { "this is typically called by tracing code" }
+Datadog.log.info { "this is typically called by tracing code" }
 ```
 
 ### Environment and tags

lib/ddtrace/buffer.rb

@@ -83,15 +83,15 @@ def measure_accept(trace)
       @buffer_accepted += 1
       @buffer_accepted_lengths += trace.length
     rescue StandardError => e
-      Datadog::Logger.log.debug("Failed to measure queue accept. Cause: #{e.message} Source: #{e.backtrace.first}")
+      Datadog.log.debug("Failed to measure queue accept. Cause: #{e.message} Source: #{e.backtrace.first}")
     end
 
     def measure_drop(trace)
       @buffer_dropped += 1
       @buffer_spans -= trace.length
       @buffer_accepted_lengths -= trace.length
     rescue StandardError => e
-      Datadog::Logger.log.debug("Failed to measure queue drop. Cause: #{e.message} Source: #{e.backtrace.first}")
+      Datadog.log.debug("Failed to measure queue drop. Cause: #{e.message} Source: #{e.backtrace.first}")
     end
 
     def measure_pop(traces)
@@ -113,7 +113,7 @@ def measure_pop(traces)
       @buffer_dropped = 0
       @buffer_spans = 0
     rescue StandardError => e
-      Datadog::Logger.log.debug("Failed to measure queue. Cause: #{e.message} Source: #{e.backtrace.first}")
+      Datadog.log.debug("Failed to measure queue. Cause: #{e.message} Source: #{e.backtrace.first}")
     end
   end
 end

lib/ddtrace/configuration.rb

@@ -31,6 +31,7 @@ def configure(target = configuration, opts = {})
     def_delegators \
       :components,
       :health_metrics,
+      :log,
       :runtime_metrics,
       :tracer
 
@@ -45,13 +46,16 @@ def rebuild_components!(configuration)
       new_components = Components.new(configuration)
 
       # Teardown old components if they exist
-      teardown_components!(@components, new_components) if instance_variable_defined?(:@components)
+      teardown_old_components!(@components, new_components) if instance_variable_defined?(:@components)
 
       # Activate new components
       @components = new_components
     end
 
-    def teardown_components!(old, current)
+    def teardown_old_components!(old, current)
+      # Shutdown the old logger, unless it's still being used.
+      # old.log.close unless old.log == current.log
+
       # Shutdown the old tracer, unless it's still being used.
       # (e.g. a custom tracer instance passed in.)
       old.tracer.shutdown! unless old.tracer == current.tracer

lib/ddtrace/configuration/components.rb

@@ -1,3 +1,5 @@
+require 'ddtrace/diagnostics/health'
+require 'ddtrace/logger'
 require 'ddtrace/tracer'
 
 module Datadog
@@ -6,6 +8,9 @@ module Configuration
     # rubocop:disable Metrics/LineLength
     class Components
       def initialize(settings)
+        # Logger
+        @log = build_log(settings)
+
         # Tracer
         @tracer = build_tracer(settings)
 
@@ -18,6 +23,7 @@ def initialize(settings)
 
       attr_reader \
         :health_metrics,
+        :log,
         :tracer
 
       def runtime_metrics
@@ -26,6 +32,13 @@ def runtime_metrics
 
       private
 
+      def build_log(settings)
+        log = settings.log.instance || Datadog::Logger.new(STDOUT)
+        log.level = settings.diagnostics.debug ? ::Logger::DEBUG : settings.log.level
+
+        log
+      end
+
       def build_tracer(settings)
         # If a custom tracer has been provided, use it instead.
         # Ignore all other options (they should already be configured.)

lib/ddtrace/configuration/settings.rb

@@ -1,13 +1,11 @@
+require 'logger'
 require 'ddtrace/configuration/base'
 
 require 'ddtrace/ext/analytics'
 require 'ddtrace/ext/distributed'
 require 'ddtrace/ext/runtime'
 require 'ddtrace/ext/sampling'
 
-require 'ddtrace/diagnostics/health'
-require 'ddtrace/logger'
-
 module Datadog
   module Configuration
     # Global configuration settings for the trace library.
@@ -34,6 +32,8 @@ class Settings
       end
 
       settings :diagnostics do
+        option :debug, default: false
+
         settings :health_metrics do
           option :enabled do |o|
             o.default { env_to_bool(Datadog::Ext::Diagnostics::Health::Metrics::ENV_ENABLED, false) }
@@ -73,6 +73,19 @@ class Settings
         o.lazy
       end
 
+      settings :log do
+        option :instance do |o|
+          o.setter { |value, old_value| value.is_a?(::Logger) ? value : old_value }
+          o.on_set { |value| set_option(:level, value.level) unless value.nil? }
+        end
+
+        option :level, default: ::Logger::WARN
+      end
+
+      def log=(log)
+        get_option(:log).instance = log
+      end
+
       option :report_hostname do |o|
         o.default { env_to_bool(Ext::NET::ENV_REPORT_HOSTNAME, false) }
         o.lazy
@@ -180,7 +193,7 @@ def tracer(options = nil)
 
         if options.key?(:log)
           # TODO: Raise deprecation warning
-          Datadog::Logger.log = options.delete(:log)
+          get_option(:log).instance = options.delete(:log)
         end
 
         if options.key?(:tags)
@@ -195,7 +208,7 @@ def tracer(options = nil)
 
         if options.key?(:debug)
           # TODO: Raise deprecation warning
-          Datadog::Logger.debug_logging = options.delete(:debug)
+          get_option(:diagnostics).debug = options.delete(:debug)
         end
 
         if options.key?(:partial_flush)

lib/ddtrace/context.rb

@@ -95,7 +95,7 @@ def add_span(span)
         if @max_length > 0 && @trace.length >= @max_length
           # Detach the span from any context, it's being dropped and ignored.
           span.context = nil
-          Datadog::Logger.log.debug("context full, ignoring span #{span.name}")
+          Datadog.log.debug("context full, ignoring span #{span.name}")
 
           # If overflow has already occurred, don't send this metric.
           # Prevents metrics spam if buffer repeatedly overflows for the same trace.
@@ -124,13 +124,13 @@ def close_span(span)
         set_current_span(span.parent)
         return if span.tracer.nil?
         if span.parent.nil? && !all_spans_finished?
-          if Datadog::Logger.debug_logging
+          if Datadog.configuration.diagnostics.debug
             opened_spans = @trace.length - @finished_spans
-            Datadog::Logger.log.debug("root span #{span.name} closed but has #{opened_spans} unfinished spans:")
+            Datadog.log.debug("root span #{span.name} closed but has #{opened_spans} unfinished spans:")
           end
 
           @trace.reject(&:finished?).group_by(&:name).each do |unfinished_span_name, unfinished_spans|
-            Datadog::Logger.log.debug("unfinished span: #{unfinished_spans.first}") if Datadog::Logger.debug_logging
+            Datadog.log.debug("unfinished span: #{unfinished_spans.first}") if Datadog.configuration.diagnostics.debug
             Datadog.health_metrics.error_unfinished_spans(
               unfinished_spans.length,
               tags: ["name:#{unfinished_span_name}"]

lib/ddtrace/context_flush.rb

@@ -58,7 +58,7 @@ def finished_spans(context)
         if trace[0]
           context.annotate_for_flush!(trace[0])
         else
-          Datadog::Logger.log.debug('Tried to retrieve trace from context, but got nothing. ' \
+          Datadog.log.debug('Tried to retrieve trace from context, but got nothing. ' \
             "Is there another consumer for this context? #{context.trace_id}")
         end
 

lib/ddtrace/contrib/action_cable/instrumentation.rb

@@ -18,7 +18,7 @@ def on_open
                 rack_request_span = env[Datadog::Contrib::Rack::TraceMiddleware::RACK_REQUEST_SPAN]
                 rack_request_span.resource = span.resource if rack_request_span
               rescue StandardError => e
-                Datadog::Logger.log.error("Error preparing span for ActionCable::Connection: #{e}")
+                Datadog.log.error("Error preparing span for ActionCable::Connection: #{e}")
               end
 
               super

lib/ddtrace/contrib/action_pack/action_controller/instrumentation.rb

@@ -24,7 +24,7 @@ def start_processing(payload)
             tracing_context = payload.fetch(:tracing_context)
             tracing_context[:dd_request_span] = span
           rescue StandardError => e
-            Datadog::Logger.log.error(e.message)
+            Datadog.log.error(e.message)
           end
 
           def finish_processing(payload)
@@ -71,7 +71,7 @@ def finish_processing(payload)
               span.finish
             end
           rescue StandardError => e
-            Datadog::Logger.log.error(e.message)
+            Datadog.log.error(e.message)
           end
 
           def exception_controller?(payload)

lib/ddtrace/contrib/action_view/events/render_partial.rb

@@ -36,7 +36,7 @@ def process(span, _event, _id, payload)
 
             record_exception(span, payload)
           rescue StandardError => e
-            Datadog::Logger.log.debug(e.message)
+            Datadog.log.debug(e.message)
           end
         end
       end

lib/ddtrace/contrib/action_view/events/render_template.rb

@@ -39,7 +39,7 @@ def process(span, _event, _id, payload)
 
             record_exception(span, payload)
           rescue StandardError => e
-            Datadog::Logger.log.debug(e.message)
+            Datadog.log.debug(e.message)
           end
         end
       end

lib/ddtrace/contrib/action_view/instrumentation/partial_renderer.rb

@@ -21,7 +21,7 @@ def render_partial(*args)
 
               datadog_render_partial(template)
             rescue StandardError => e
-              Datadog::Logger.log.debug(e.message)
+              Datadog.log.debug(e.message)
             end
 
             # execute the original function anyway

lib/ddtrace/contrib/action_view/instrumentation/template_renderer.rb

@@ -54,7 +54,7 @@ def render_template_with_datadog(*args)
                     # Measure service stats
                     Contrib::Analytics.set_measured(active_datadog_span)
                   rescue StandardError => e
-                    Datadog::Logger.log.debug(e.message)
+                    Datadog.log.debug(e.message)
                   end
 
                   # execute the original function anyway
@@ -103,7 +103,7 @@ def render_template(*args)
 
                 datadog_render_template(template, layout_name)
               rescue StandardError => e
-                Datadog::Logger.log.debug(e.message)
+                Datadog.log.debug(e.message)
               end
 
               # execute the original function anyway

lib/ddtrace/contrib/action_view/patcher.rb

@@ -38,7 +38,7 @@ def patch_renderer
             ::ActionView::Rendering.send(:prepend, Instrumentation::TemplateRenderer::Rails30)
             ::ActionView::Partials::PartialRenderer.send(:prepend, Instrumentation::PartialRenderer::RailsLessThan4)
           else
-            Datadog::Logger.log.debug('Expected Template/Partial classes not found; template rendering disabled')
+            Datadog.log.debug('Expected Template/Partial classes not found; template rendering disabled')
           end
         end
       end

lib/ddtrace/contrib/active_record/events/instantiation.rb

@@ -51,7 +51,7 @@ def process(span, event, _id, payload)
             span.set_tag(Ext::TAG_INSTANTIATION_CLASS_NAME, payload.fetch(:class_name))
             span.set_tag(Ext::TAG_INSTANTIATION_RECORD_COUNT, payload.fetch(:record_count))
           rescue StandardError => e
-            Datadog::Logger.log.debug(e.message)
+            Datadog.log.debug(e.message)
           end
         end
       end

lib/ddtrace/contrib/active_record/events/sql.rb

@@ -55,7 +55,7 @@ def process(span, event, _id, payload)
             span.set_tag(Datadog::Ext::NET::TARGET_HOST, config[:host]) if config[:host]
             span.set_tag(Datadog::Ext::NET::TARGET_PORT, config[:port]) if config[:port]
           rescue StandardError => e
-            Datadog::Logger.log.debug(e.message)
+            Datadog.log.debug(e.message)
           end
         end
       end

lib/ddtrace/contrib/active_support/cache/instrumentation.rb

@@ -31,7 +31,7 @@ def start_trace_cache(payload)
             span.resource = payload.fetch(:action)
             tracing_context[:dd_cache_span] = span
           rescue StandardError => e
-            Datadog::Logger.log.debug(e.message)
+            Datadog.log.debug(e.message)
           end
 
           def finish_trace_cache(payload)
@@ -56,7 +56,7 @@ def finish_trace_cache(payload)
               span.finish
             end
           rescue StandardError => e
-            Datadog::Logger.log.debug(e.message)
+            Datadog.log.debug(e.message)
           end
 
           # Defines instrumentation for ActiveSupport cache reading

lib/ddtrace/contrib/active_support/notifications/subscription.rb

@@ -114,7 +114,7 @@ def initialize(&block)
             def run(span, name, id, payload)
               run!(span, name, id, payload)
             rescue StandardError => e
-              Datadog::Logger.log.debug("ActiveSupport::Notifications handler for '#{name}' failed: #{e.message}")
+              Datadog.log.debug("ActiveSupport::Notifications handler for '#{name}' failed: #{e.message}")
             end
 
             def run!(*args)
@@ -139,7 +139,7 @@ def run(event, key, *args)
                 begin
                   callback.call(event, key, *args)
                 rescue StandardError => e
-                  Datadog::Logger.log.debug(
+                  Datadog.log.debug(
                     "ActiveSupport::Notifications '#{key}' callback for '#{event}' failed: #{e.message}"
                   )
                 end

lib/ddtrace/contrib/dalli/patcher.rb

@@ -57,7 +57,7 @@ def service_name=(service_name)
 
           def log_deprecation_warning(method_name)
             do_once(method_name) do
-              Datadog::Logger.log.warn("#{method_name}:#{DEPRECATION_WARNING}")
+              Datadog.log.warn("#{method_name}:#{DEPRECATION_WARNING}")
             end
           end
         end

lib/ddtrace/contrib/dalli/quantize.rb

@@ -13,7 +13,7 @@ def format_command(operation, args)
           command = Utils.utf8_encode(command, binary: true, placeholder: placeholder)
           Utils.truncate(command, Ext::QUANTIZE_MAX_CMD_LENGTH)
         rescue => e
-          Logger.log.debug("Error sanitizing Dalli operation: #{e}")
+          Datadog.log.debug("Error sanitizing Dalli operation: #{e}")
           placeholder
         end
       end

lib/ddtrace/contrib/elasticsearch/patcher.rb

@@ -97,7 +97,7 @@ def perform_request(*args)
                   quantized_url = Datadog::Contrib::Elasticsearch::Quantize.format_url(url)
                   span.resource = "#{method} #{quantized_url}"
                 rescue StandardError => e
-                  Datadog::Logger.log.error(e.message)
+                  Datadog.log.error(e.message)
                 ensure
                   # the call is still executed
                   response = perform_request_without_datadog(*args)

lib/ddtrace/contrib/excon/middleware.rb

@@ -34,7 +34,7 @@ def request_call(datum)
               end
             end
           rescue StandardError => e
-            Datadog::Logger.log.debug(e.message)
+            Datadog.log.debug(e.message)
           end
 
           @stack.request_call(datum)
@@ -137,7 +137,7 @@ def handle_response(datum)
             end
           end
         rescue StandardError => e
-          Datadog::Logger.log.debug(e.message)
+          Datadog.log.debug(e.message)
         end
 
         def propagate!(span, datum)