spec/lib/sysloggable/logger_spec.rb in sysloggable-0.2.0 vs spec/lib/sysloggable/logger_spec.rb in sysloggable-0.2.1

@@ -1,10 +1,11 @@
 require "spec_helper"
 
 describe Sysloggable::Logger do
   let(:syslogger) { spy("syslogger") }
-  subject(:logger) { described_class.new(ident: "test_ident") }
+  let(:options) { {ident: "test_ident"} }
+  subject(:logger) { described_class.new(options) }
 
   before do
     Sysloggable::Container.stub('lib.syslogger', syslogger)
   end
 
@@ -17,26 +18,54 @@
 
       logger.send(severity_name, "msg")
     end
   end
 
-  it "counts duration" do
-    Timecop.freeze(Time.now.utc)
+  context 'duration' do
+    context 'when normal task' do
+      it "counts duration" do
+        Timecop.freeze(Time.now.utc)
 
-    expect(syslogger).to receive(:add).
-      with(described_class::SEVERITIES[:info],
-           "severity=INFO service=test_ident operation= duration=10.0 message=msg")
+        expect(syslogger).to receive(:add).
+          with(described_class::SEVERITIES[:info],
+               "severity=INFO service=test_ident operation= duration=9.524 message=msg")
 
-    logger.info("msg") do
-      Timecop.freeze(Time.now.utc + 10)
+        logger.info("msg") do
+          Timecop.freeze(Time.now.utc + 9.523531)
+        end
+
+        Timecop.return
+      end
     end
 
-    Timecop.return
+    context 'when very quick task' do
+      it "counts duration" do
+        expect(syslogger).to receive(:add).
+          with(described_class::SEVERITIES[:info],
+               "severity=INFO service=test_ident operation= duration=0.0 message=msg")
+
+        logger.info("msg") do
+          # no-op
+        end
+      end
+    end
   end
 
   context 'when ident is invalid' do
     subject(:logger) { described_class.new(ident: '22222' * 5) }
     it 'raises error' do
       expect{ logger.info('msg') }.to raise_error(ArgumentError)
+    end
+  end
+
+  context "custom separator" do
+    let(:options) { {ident: "test_ident", separator: " | "} }
+
+    it do
+      expect(syslogger).to receive(:add).
+        with(described_class::SEVERITIES[:info],
+             "severity=INFO | service=test_ident | operation= | duration=0 | message=msg")
+
+      logger.info("msg")
     end
   end
 end