Changing logging behavior to only write to $STDOUT by default (#39)

* Added new `log` option to `Loba.ts` and `Loba.val` to override and also write to Rails.logger (when available)
* Output will always be sent to $STDOUT even if `log` option is set to `true`
* Updated specs, docs, and CHANGELOG to reflect new behavior
* Restructured specs for `Loba::Internal::Platform`
* Updated specs to use more inline mocking, esp., for `Loba::Internal::Platform`

.rubocop.yml

@@ -14,6 +14,9 @@ Layout/LineLength:
 Metrics/BlockLength:
   Max: 25
 
+Style/DoubleNegation:
+  Enabled: false
+
 Style/FrozenStringLiteralComment:
   Enabled: true
   EnforcedStyle: never

CHANGELOG.md

@@ -7,13 +7,16 @@ and, as of version 0.3.0 and later, this project adheres to [Semantic Versioning
 
 ## [Unreleased]
 
-## [2.0.0] - 2023-07-04
+## [2.0.0] - 2023-07-07
 ### Added
+- `Loba.ts`: `log` option to allow logging to Rails.logger (ignored if unavailable)
+- `Loba.val`: `log` option to allow logging to Rails.logger (ignored if unavailable)
 - SECURITY.md to specify security policy
 
 ### Changed
 - Dropped support for Ruby prior to 3.0.6
-- Changed output to always write to STDOUT even if Rails is present (in which case it will also log)
+- Changed output to always write to STDOUT (regardless whether Rails is present)
+- Changed to only write to Rails.logger (when present) when `log` option is set to `true`
 - Updated YARD documentation for improved completeness
 
 ## [1.2.1] - 2021-09-05

lib/loba.rb

@@ -13,6 +13,8 @@ module Loba
   # help with quick, minimalist profiling.
   # @param production [Boolean] set to true if this timestamp notice is
   #   to be recorded when running in :production environment
+  # @param log [Boolean] when false, will not write to Rails.logger if present;
+  #   when true, will write to Rails.logger if present
   # @return [NilClass] nil
   # @example Basic use
   #   def hello
@@ -24,15 +26,20 @@ module Loba
   #     Loba.ts production: true # Loba.ts is a shorthand alias for Loba.timestamp
   #   end
   #   #=> [TIMESTAMP] #=0001, diff=0.000463, at=1451615389.505411, in=/path/to/file.rb:2:in 'hello'
-  def timestamp(production: false)
+  # @example Forced to output to log (if Rails.logger present) in addition to $STDOUT
+  #   def hello
+  #     Loba.timestamp log: true
+  #   end
+  #   #=> [TIMESTAMP] #=0001, diff=0.000463, at=1451615389.505411, in=/path/to/file.rb:2:in 'hello'
+  def timestamp(production: false, log: false) # rubocop:disable Metrics/AbcSize, Metrics/MethodLength
     return unless Internal::Platform.logging_ok?(production)
 
-    # produce timestamp notice
-    @loba_logger ||= Internal::Platform.logger
+    # NOTE: while tempting, memoizing loba_logger can lead to surprises if Rails presence isn't constant
+    loba_logger = Internal::Platform.logger
 
     begin
       stats = Internal::TimeKeeper.instance.ping
-      @loba_logger.call(
+      loba_logger.call(
         # 60: light_black / grey
         "#{Rainbow('[TIMESTAMP]').black.bg(60)}" \
         "#{Rainbow(' #=').yellow.bg(:default)}" \
@@ -41,18 +48,19 @@ def timestamp(production: false)
         "#{format('%.6f', stats[:change])}" \
         "#{Rainbow(', at=').yellow}" \
         "#{format('%.6f', stats[:now].round(6).to_f)}" \
-        "#{Rainbow("    \t(in #{caller(1..1).first})").color(60)}" # warning: nested interpolation
+        "#{Rainbow("    \t(in #{caller(1..1).first})").color(60)}", # warning: nested interpolation
+        !!log
       )
     rescue StandardError => e
-      @loba_logger.call Rainbow("[TIMESTAMP] #=FAIL, in=#{caller(1..1).first}, err=#{e}").red
+      loba_logger.call Rainbow("[TIMESTAMP] #=FAIL, in=#{caller(1..1).first}, err=#{e}").red
     end
 
     nil
   end
   module_function :timestamp
 
   # Shorthand alias for Loba.timestamp.
-  # @!method ts(production: false)
+  # @!method ts(production: false, log: false)
   alias ts timestamp
   module_function :ts
 
@@ -66,6 +74,8 @@ def timestamp(production: false)
   #   content being evaluated; otherwise, false
   # @param production [Boolean] set to true if this timestamp notice is
   #   to be recorded when running in :production environment
+  # @param log [Boolean] when false, will not write to Rails.logger if present;
+  #   when true, will write to Rails.logger if present
   # @return [NilClass] nil
   # @example Using Symbol as argument
   #   class HelloWorld
@@ -97,33 +107,36 @@ def timestamp(production: false)
   #   HelloWorld.new.hello("Charlie")
   #   #=> [HelloWorld#hello] Name: Charlie        (at /path/to/file/hello_world.rb:3:in `hello')
   #   #=> Hello, Charlie!
-  def value(argument, label: nil, inspect: true, production: false)
+  def value(argument, label: nil, inspect: true, production: false, log: false) # rubocop:disable Metrics/AbcSize, Metrics/MethodLength
     return nil unless Internal::Platform.logging_ok?(production)
 
-    @loba_logger ||= Internal::Platform.logger
-
     text = Internal::Value.phrases(
       argument: (argument.nil? ? :nil : argument),
       label: label,
       inspect: inspect,
       depth_offset: 1
     )
-    @loba_logger.call(
+
+    Internal::Platform.logger.call(
+      # NOTE: while tempting, memoizing Internal::Platform.logger can lead to surprises
+      #   if Rails presence isn't constant
+      #
       # warning: nested interpolation below (slight help to performance)
       # 60: light_black
       # 62: light_green
       "#{Rainbow("#{text[:tag]} ").green.bg(:default)}" \
       "#{Rainbow("#{text[:label]} ").color(62)}" \
       "#{text[:value]}" \
-      "#{Rainbow("    \t(in #{text[:line]})").color(60)}"
+      "#{Rainbow("    \t(in #{text[:line]})").color(60)}",
+      !!log
     )
 
     nil
   end
   module_function :value
 
   # Shorthand alias for Loba.value.
-  # @!method val(argument, label: nil, inspect: true, production: false)
+  # @!method val(argument, label: nil, inspect: true, production: false, log: false)
   alias val value
   module_function :val
 end

lib/loba/internal/platform.rb

@@ -22,13 +22,23 @@ def logging_ok?(force_true = false)
           end
         end
 
-        # Provides logging mechanism appropriate in the application
+        # Provides logging mechanism appropriate in the application.
+        #
+        # Returned lambda takes 2 arguments:
+        #   * arg [String] value to be output (and potentially logged)
+        #   * force_log [Boolean] when false (default), never logs to Rails.logger;
+        #       when true, logs to Rails.logger if present
         # @return [Lambda] procedure for logging output
         def logger
           if rails? && Rails.logger.present?
-            ->(arg) { puts arg; Rails.logger.debug arg }
+            lambda do |arg, force_log = false|
+              puts arg
+              return unless force_log
+
+              Rails.logger.debug arg
+            end
           else
-            ->(arg) { puts arg }
+            ->(arg, _force_log = false) { puts arg }
           end
         end
       end

readme/ts.md

@@ -34,7 +34,8 @@ where
 ##### Options
 
 The following keyword argument may be specified when calling:
-*   `production`: `true` if this value notice is enabled when running in :production environment (see ["Environment Notes"](README.md#environment-notes)) \[_default: `false`_\]
+*   `production`: true if this timestamp notice is to be enabled when running in :production environment (see ["Environment Notes"](README.md#environment-notes)) \[_default: `false`_\]
+*   `log`: `true` true if output is to be sent to both $STDOUT and to the Rails.logger (when availabe)
 
 ###### Examples using options
 ```ruby
@@ -43,3 +44,15 @@ Loba.ts production: true
 ```ruby
 Loba.ts(production: true)
 ```
+```ruby
+Loba.ts log: true
+```
+```ruby
+Loba.ts(log: true)
+```
+```ruby
+Loba.ts production: true, log: true # may result in double logging
+```
+```ruby
+Loba.ts(production: true, log: true # may result in double logging)
+```

readme/val.md

@@ -109,7 +109,8 @@ Notes:
 The following options may be provided via keywords:
 *   `label`: give a string to explicitly provide a label to use in the notice (see sample above) \[_default: attempts to infer a label from the first argument]_\]
 *   `inspect`: true if this value notice is to use #inspect against the content being evaluated; occasionally, `inspect: false` can give a more useful result \[_default: `true`_\]
-*   `production`: true if this value notice is enabled when running in :production environment (see ["Environment Notes"](README.md#environment-notes)) \[_default: `false`_\]
+*   `production`: true if this value notice is to be enabled when running in :production environment (see ["Environment Notes"](README.md#environment-notes)) \[_default: `false`_\]
+*   `log`: `true` true if output is to be sent to both $STDOUT and to the Rails.logger (when availabe)
 
 ###### Example 5: Using special options
 ```ruby
@@ -118,3 +119,6 @@ Loba.val name, label: "Name:", inspect: false
 ```ruby
 Loba.val :name, production: true
 ```
+```ruby
+Loba.val :name, label: "Name:", log: true
+```