TECH-4787: switch format to <progname>: message; pass progname throug…

…h in context hash

lib/contextual_logger.rb

@@ -87,9 +87,7 @@ def #{method_name}(arg = nil, **context, &block)
             if arg.nil?
               add(#{log_level}, nil, context, &block)
             elsif block
-              add(#{log_level}, nil, context) do
-                "\#{ContextualLogger.normalize_message(arg)}: \#{ContextualLogger.normalize_message(block.call)}"
-              end
+              add(#{log_level}, nil, context.merge(progname: arg), &block)
             else
               add(#{log_level}, arg, context)
             end
@@ -108,7 +106,11 @@ def add(arg_severity, arg1 = nil, arg2 = nil, **context)   # Ruby will prefer to
         if arg1.nil?
           if block_given?
             message = yield
-            progname = arg2 || @progname
+            if arg2.nil? && context.has_key?(:progname)
+              progname = context[:progname] || @progname
+            else
+              progname = arg2 || @progname
+            end
           else
             message = arg2
             progname = @progname
@@ -138,22 +140,24 @@ def redactor
     end
 
     def format_message(severity, timestamp, progname, message, context: {})
+      normalized_message = ContextualLogger.normalize_message(message)
+      normalized_progname = ContextualLogger.normalize_message(progname) unless progname.nil?
       if @formatter
-        @formatter.call(severity, timestamp, progname, { message: ContextualLogger.normalize_message(message) }.merge!(context))
+        @formatter.call(severity, timestamp, normalized_progname, { message: normalized_message }.merge!(context))
       else
-        "#{basic_json_log_entry(severity, timestamp, progname, message, context: context)}\n"
+        "#{basic_json_log_entry(severity, timestamp, normalized_progname, normalized_message, context: context)}\n"
       end
     end
 
-    def basic_json_log_entry(severity, timestamp, progname, message, context:)
+    def basic_json_log_entry(severity, timestamp, normalized_progname, normalized_message, context:)
       message_hash = {
-        message:   ContextualLogger.normalize_message(message),
+        message: normalized_progname ? "#{normalized_progname}: #{normalized_message}" : normalized_message,
         severity:  severity,
         timestamp: timestamp
       }
-      message_hash[:progname] = progname if progname
+      message_hash[:progname] = normalized_progname if normalized_progname
 
-      # using merge! instead of merge for speed of operation
+      # merge! is faster and OK here since message_hash is still local only to this method
       message_hash.merge!(context).to_json
     end
   end

spec/lib/contextual_logger_spec.rb

@@ -158,7 +158,7 @@ def expect_log_line_to_be_written(log_line)
   context 'with no context' do
     let(:expected_log_hash) do
       {
-        message: 'this is a test',
+        message: 'request: this is a test',
         timestamp: Time.now,
         progname: 'request'
       }
@@ -205,20 +205,11 @@ def expect_log_line_to_be_written(log_line)
       let(:message) { 'request: this is a test' }
 
       it 'handles message block (inline context) with progname' do
-        expect_log_line_to_be_written(expected_log_hash.to_json)
+        expect_log_line_to_be_written(expected_log_hash.merge(progname: 'request').to_json)
         expect(logger.info('request', service: 'test_service') { 'this is a test' }).to eq(true)
       end
     end
 
-    context 'with non-String progname and message' do
-      let(:message) { ':progname: :test' }
-
-      it 'handles message block (inline context) with progname' do
-        expect_log_line_to_be_written(expected_log_hash.to_json)
-        expect(logger.info(:progname, service: 'test_service') { :test }).to eq(true)
-      end
-    end
-
     context "when log level isn't enabled" do
       before { logger.level = Logger::Severity::UNKNOWN }
 
@@ -438,7 +429,7 @@ def expect_log_line_to_be_written(log_line)
 
     it "preserves the Logger interface with non-nil progname & block" do
       expect(logger.add(Logger::Severity::INFO, nil, 'request') { "info message" }).to eq(true)
-      expect(log_stream.string).to match(/\{"message":"info message","severity":"INFO","timestamp":".*","progname":"request"\}/)
+      expect(log_stream.string).to match(/\{"message":"request: info message","severity":"INFO","timestamp":".*","progname":"request"\}/)
     end
 
     it "preserves the Logger interface with nil message & message in progname spot" do