Format the passed message on Message initialization

Since we can not guarantee that a user-supplied formatter is side-effect
free, a delayed formatting might result in unexpected results. An
example of such a formatter is the one used by
ActiveSupport::TaggedLogging.

lib/rackstash/message.rb

@@ -19,6 +19,11 @@ module Rackstash
 
     attr_reader :message
 
+    alias as_json message
+    # Messages are implicitly conversible to Strings
+    alias to_s message
+    alias to_str message
+
     attr_reader :severity
 
     attr_reader :progname
@@ -28,34 +33,26 @@ module Rackstash
     attr_reader :formatter
 
     def initialize(
-      msg,
+      message,
       severity: UNKNOWN,
       time: Time.now.utc.freeze,
       progname: PROGNAME,
       formatter: RAW_FORMATTER
     )
-      @message = dup_freeze(msg)
-
       @severity = Integer(severity)
       @severity = 0 if @severity < 0
 
       @time = dup_freeze(time)
       @progname = dup_freeze(progname)
       @formatter = formatter
+
+      @message = cleanup @formatter.call(severity_label, @time, @progname, message)
     end
 
     def severity_label
       SEVERITY_LABEL[@severity] || SEVERITY_LABEL.last
     end
 
-    def to_s
-      cleanup @formatter.call(severity_label, @time, @progname, @message)
-    end
-
-    alias as_json to_s
-    # Messages are implicitly conversible to Strings
-    alias to_str to_s
-
     def to_json
       as_json.to_json
     end

spec/rackstash/message_spec.rb

@@ -6,35 +6,99 @@
 require 'spec_helper'
 
 require 'digest'
+require 'json'
 require 'rackstash/message'
 
 describe Rackstash::Message do
-  describe '#message' do
+  describe '#initialize' do
-    it 'dups the message string' do
+    it 'immediately formats the message' do
-      str = 'a message'.encode(Encoding::ASCII_8BIT)
+      severity = 0
-      message = Rackstash::Message.new(str)
+      time = Time.now
+      progname = 'ProgramName'
+      message = 'Hello World'
 
-      expect(message.message).to eql str
+      formatter = double('formatter')
-      expect(message.message).not_to equal str
+      expect(formatter).to receive(:call)
-      expect(message.message.encoding).to eql Encoding::ASCII_8BIT
+        .with('DEBUG', time, progname, message)
+
+      message = Rackstash::Message.new(
+        message,
+        severity: severity,
+        time: time,
+        progname: progname,
+        formatter: formatter
+      )
+    end
+
+    it 'cleans the message' do
+      messages = [
+        ["First\r\nSecond",         "First\nSecond"],
+        ["First\r\nSecond\n\r",     "First\nSecond\n\n"],
+        ["Foo\r\n\rBar",            "Foo\n\nBar"],
+        ["\r \tWord\n\nPhrase\n",   "\n \tWord\n\nPhrase\n"],
+        ["\e[31mRED TEXT\e[0m",     'RED TEXT']
+      ]
+
+      messages.each do |msg, clean|
+        message = Rackstash::Message.new(msg)
+        expect(message.message).to eql clean
         expect(message.message).to be_frozen
       end
+    end
+
+    it 'encodes the message as UTF-8' do
+      utf8_str = 'Dönerstraße'
+      latin_str = utf8_str.encode(Encoding::ISO8859_9)
+      expect(latin_str.encoding).to eql Encoding::ISO8859_9
+
+      message = Rackstash::Message.new(latin_str)
+      expect(message.message).to eql utf8_str
+      expect(message.message.encoding).to eql Encoding::UTF_8
+    end
+
+    it 'does not raise an error on incompatible encodings' do
+      binary = Digest::SHA256.digest('string')
+      message = Rackstash::Message.new(binary)
+
+      expect(message.message).to include '<27>'
+      expect(message.message.encoding).to eql Encoding::UTF_8
+    end
 
     it 'accepts non-string objects' do
-      exception = StandardError.new('An error')
+      message = Rackstash::Message.new(StandardError.new('An error'))
-      message = Rackstash::Message.new(exception)
+      expect(message.message).to eql '#<StandardError: An error>'
+      expect(message.message).to be_frozen
 
-      expect(message.message).to eq exception
+      message = Rackstash::Message.new(:symbol)
+      expect(message.message).to eql ':symbol'
+      expect(message.message).to be_frozen
     end
 
-    it 'attempts to dup non-frozen objects' do
+    it 'dups and freezes all messages' do
-      rational = Rational(2, 3)
+      str = 'hello'
-      expect(rational).to_not be_frozen
+      expect(str.encoding).to eql Encoding::UTF_8
 
-      message = Rackstash::Message.new(rational)
+      message = Rackstash::Message.new(str)
+      expect(message.message).to be_frozen
+      expect(message.message).not_to equal str
+      expect(message.message).to eql str
+    end
+  end
 
-      expect(message.message).to_not be_frozen
+  describe '#message' do
-      expect(message.message).to equal rational
+    it 'is aliased to to_str' do
+      message = Rackstash::Message.new('hello world')
+      expect(message.to_s).to eql 'hello world'
+    end
+
+    it 'is aliased to to_str' do
+      message = Rackstash::Message.new('hello world')
+      expect(message.to_str).to eql 'hello world'
+    end
+
+    it 'is aliased to as_json' do
+      message = Rackstash::Message.new('hello world')
+      expect(message.as_json).to eql 'hello world'
     end
   end
 
@@ -117,88 +181,11 @@ describe Rackstash::Message do
     end
   end
 
-  describe '#to_s' do
-    it 'formats the message' do
-      severity = 0
-      time = Time.now
-      progname = 'ProgramName'
-      message = 'Hello World'
-
-      formatter = double('formatter')
-      expect(formatter).to receive(:call)
-        .with('DEBUG', time, progname, message)
-        .and_return('Formatted Message')
-
-      message = Rackstash::Message.new(
-        message,
-        severity: severity,
-        time: time,
-        progname: progname,
-        formatter: formatter
-      )
-
-      expect(message.to_s).to eql 'Formatted Message'
-    end
-
-    it 'cleans the message' do
-      messages = [
-        ["First\r\nSecond",         "First\nSecond"],
-        ["First\r\nSecond\n\r",     "First\nSecond\n\n"],
-        ["Foo\r\n\rBar",            "Foo\n\nBar"],
-        ["\r \tWord\n\nPhrase\n",   "\n \tWord\n\nPhrase\n"],
-        ["\e[31mRED TEXT\e[0m",     'RED TEXT']
-      ]
-
-      messages.each do |msg, clean|
-        message = Rackstash::Message.new(msg)
-        expect(message.to_s).to eql clean
-      end
-    end
-
-    it 'encodes the message as UTF-8' do
-      utf8_str = 'Dönerstraße'
-      latin_str = utf8_str.encode(Encoding::ISO8859_9)
-      expect(latin_str.encoding).to eql Encoding::ISO8859_9
-
-      message = Rackstash::Message.new(latin_str)
-      expect(message.to_s).to eql utf8_str
-      expect(message.to_s.encoding).to eql Encoding::UTF_8
-    end
-
-    it 'does not raise an error on incompatible encodings' do
-      binary = Digest::SHA256.digest('string')
-      message = Rackstash::Message.new(binary)
-
-      expect(message.to_s).to include '<27>'
-      expect(message.to_s.encoding).to eql Encoding::UTF_8
-    end
-
-    it 'accepts non-string objects' do
-      message = Rackstash::Message.new(StandardError.new('An error'))
-      expect(message.to_s).to eql '#<StandardError: An error>'
-
-      message = Rackstash::Message.new(:symbol)
-      expect(message.to_s).to eql ':symbol'
-    end
-
-    it 'is aliased to to_str' do
-      message = Rackstash::Message.new('hello world')
-      expect(message.to_str).to eql 'hello world'
-    end
-
-    it 'is aliased to as_json' do
-      message = Rackstash::Message.new('hello world')
-      expect(message.as_json).to eql 'hello world'
-    end
-  end
 
+  describe '#to_json' do
     it 'formats the message as JSON' do
       message = Rackstash::Message.new('hello world')
-    as_json = 'hello world'
+      expect(message.to_json).to eql '"hello world"'
-
+    end
-    expect(message).to receive(:as_json).and_return(as_json)
-    expect(as_json).to receive(:to_json).and_return('"json string"')
-
-    expect(message.to_json).to eql '"json string"'
   end
 end