Merge pull request #22 from polysics/feature/better_error_handling

Better SIPp error handling
mojolingo · Sep 10, 2013 · 7210a4b · 7210a4b
2 parents 6f3cdcc + 4132d1e
commit 7210a4b
Show file tree

Hide file tree

Showing 3 changed files with 132 additions and 43 deletions.
diff --git a/.gitignore b/.gitignore
@@ -3,3 +3,4 @@
 *.gem
 /spec/reports/
 Gemfile.lock
+.ruby-gemset
diff --git a/lib/sippy_cup/runner.rb b/lib/sippy_cup/runner.rb
@@ -47,7 +47,6 @@ def prepare_command
       end
       command << " -inf #{@options[:scenario_variables]}" if @options[:scenario_variables]
       command << " #{@options[:destination]}"
-      command << " > /dev/null 2>&1" unless @options[:full_sipp_output]
       command
     end
 
@@ -58,17 +57,43 @@ def prepare_command
     # @raises SippyCup::NoCallsProcessed when SIPp exit normally, but has processed no calls
     # @raises SippyCup::FatalError when SIPp encounters a fatal failure
     # @raises SippyCup::FatalSocketBindingError when SIPp fails to bind to the specified socket
+    # @raises SippyCup::SippGenericError when SIPp encounters another type of error
     #
     # @return Boolean true if execution succeeded without any failed calls, false otherwise
     #
     def run
       command = prepare_command
       @logger.info "Preparing to run SIPp command: #{command}"
 
-      @sipp_pid = spawn command
+      rd, wr = IO.pipe
+
+      output_options = {
+        err: wr
+      }
+
+      output_options[:out] = '/dev/null' unless @options[:full_sipp_output]
+
+      stderr_buffer = String.new
+
+      t = Thread.new do
+        begin
+          wr.close
+          loop do
+            buffer = rd.readpartial(1024).strip
+            stderr_buffer += buffer
+            $stderr << buffer unless @options[:full_sipp_output]
+          end
+        rescue IOError
+          #no-op, just breaking the loop
+        end
+      end
+
+      @sipp_pid = spawn command, output_options
       sipp_result = Process.wait2 @sipp_pid.to_i
 
-      final_result = process_exit_status sipp_result
+      rd.close
+
+      final_result = process_exit_status sipp_result, stderr_buffer
 
       if final_result
         @logger.info "Test completed successfully!"
@@ -90,21 +115,23 @@ def stop
       Process.kill "KILL", @sipp_pid if @sipp_pid
     end
 
-    def process_exit_status(process_status)
+    def process_exit_status(process_status, error_message = nil)
       exit_code = process_status[1].exitstatus
       case exit_code
+      when 0
+        return true
       when 1
         false
       when 97
-        raise SippyCup::ExitOnInternalCommand
+        raise SippyCup::ExitOnInternalCommand, error_message
       when 99
-        raise SippyCup::NoCallsProcessed
-      when -1
-        raise SippyCup::FatalError
-      when -2
-        raise SippyCup::FatalSocketBindingError
+        raise SippyCup::NoCallsProcessed, error_message
+      when 255
+        raise SippyCup::FatalError, error_message
+      when 254
+        raise SippyCup::FatalSocketBindingError, error_message
       else
-        true
+        raise SippyCup::SippGenericError, error_message
       end
     end
   end
@@ -115,4 +142,5 @@ class ExitOnInternalCommand < Error; end # 97
   class NoCallsProcessed < Error; end # 99
   class FatalError < Error; end # -1
   class FatalSocketBindingError < Error; end # -2
+  class SippGenericError < Error; end # 255 and undocumented errors
 end
diff --git a/spec/sippy_cup/runner_spec.rb b/spec/sippy_cup/runner_spec.rb
@@ -11,7 +11,7 @@
       it 'should raise an error when the system call fails' do
         subject.logger.stub :info
         subject.should_receive(:prepare_command).and_return command
-        subject.should_receive(:spawn).with(command).and_raise(Errno::ENOENT)
+        subject.should_receive(:spawn).with(command, an_instance_of(Hash)).and_raise(Errno::ENOENT)
         Process.stub :wait2
         subject.stub :process_exit_status
         lambda {subject.run}.should raise_error Errno::ENOENT
@@ -20,7 +20,7 @@
       it 'should not raise an error when the system call is successful' do
         subject.logger.stub :info
         subject.should_receive(:prepare_command).and_return command
-        subject.should_receive(:spawn).with(command).and_return pid
+        subject.should_receive(:spawn).with(command, an_instance_of(Hash)).and_return pid
         Process.stub :wait2
         subject.stub :process_exit_status
         lambda {subject.run}.should_not raise_error
@@ -36,7 +36,7 @@
       it 'should display the path to the csv file when one is specified' do
         subject.logger.should_receive(:info).twice
         subject.should_receive(:prepare_command).and_return command
-        subject.should_receive(:spawn).with(command).and_return pid
+        subject.should_receive(:spawn).with(command, an_instance_of(Hash)).and_return pid
         Process.stub :wait2
         subject.stub :process_exit_status
         subject.logger.should_receive(:info).with "Statistics logged at #{File.expand_path settings[:stats_file]}"
@@ -54,7 +54,7 @@
         subject.logger.should_receive(:info).ordered.with(/Preparing to run SIPp command/)
         subject.logger.should_receive(:info).ordered.with(/Test completed successfully/)
         subject.should_receive(:prepare_command).and_return command
-        subject.should_receive(:spawn).with(command).and_return pid
+        subject.should_receive(:spawn).with(command, an_instance_of(Hash)).and_return pid
         Process.stub :wait2
         subject.stub :process_exit_status
         subject.run
@@ -71,27 +71,50 @@
       it 'should use CSV into the test run' do
         subject.logger.should_receive(:info).ordered.with(/Preparing to run SIPp command/)
         subject.logger.should_receive(:info).ordered.with(/Test completed successfully/)
-        subject.should_receive(:spawn).with(/\-inf \/path\/to\/csv/)
+        subject.should_receive(:spawn).with(/\-inf \/path\/to\/csv/, an_instance_of(Hash))
         Process.stub :wait2
         subject.stub :process_exit_status
         subject.run
       end
     end
 
-    context "Evaluating SIPp exit code" do
+    context "capturing STDOUT/STDERR output" do
+      let(:error_string) { "Some error" }
+      let(:exit_code) { 128 }
+      let(:command) { "sh -c 'echo \"#{error_string}\" 1>&2; exit #{exit_code}'" }
       let(:settings) { Hash.new }
-      let(:command) { "sudo sipp -i 127.0.0.1" }
-      let(:pid) { '1234' }
-
       subject { SippyCup::Runner.new settings }
 
-      it 'should return false when the SIPp exit code is 1 and log appropriately' do
-        subject.logger.stub :info
-        subject.should_receive(:prepare_command).and_return command
-        subject.should_receive(:spawn).with(command).and_return pid
-        Process.should_receive(:wait2).and_return([nil, double(exitstatus: 1)])
-        subject.logger.should_receive(:info).ordered.with(/Test completed successfully but some calls failed./)
-        subject.run.should == false
+      it "should raise a SippyCup::SippGenericError with the correct error message" do
+        quietly do
+          subject.logger.stub :info
+          subject.should_receive(:prepare_command).and_return command
+          expect { subject.run }.to raise_error SippyCup::SippGenericError, error_string
+        end
+      end
+
+      context "with :full_sipp_output enabled" do
+        let(:settings) { Hash.new full_sipp_output: true }
+
+        def capture_stderr(&block)
+          original_stderr = $stderr
+          $stderr = fake = StringIO.new
+          begin
+            yield
+          ensure
+            $stderr = original_stderr
+          end
+          fake.string
+        end
+
+        it "sends the message to stderr" do
+          subject.logger.stub :info
+          subject.should_receive(:prepare_command).and_return command
+          stderr = capture_stderr do
+            expect { subject.run }.to raise_error
+          end
+          stderr.should == error_string
+        end
       end
     end
 
@@ -129,51 +152,88 @@
     end
   end
 
-  describe '#process_exit_status' do
+  describe 'SIPp exit status handling' do
+    let(:settings) { Hash.new }
+    let(:error_string) { "Some error" }
+    let(:exit_code) { 255 }
+    let(:command) { "sh -c 'echo \"#{error_string}\" 1>&2; exit #{exit_code}'" }
     let(:settings) { Hash.new }
-    let(:process_status) { [nil, double(exitstatus: exitstatus)] }
 
     subject { SippyCup::Runner.new settings }
 
+    before do
+      subject.logger.stub :info
+      subject.should_receive(:prepare_command).and_return command
+    end
+
     context "with normal operation" do
-      let(:exitstatus) { 0 }
+      let(:exit_code) { 0 }
       it "should not raise anything if SIPp returns 0" do
-        expect {subject.process_exit_status(process_status)}.to_not raise_error
+        quietly do
+          expect {subject.run}.to_not raise_error
+        end
       end
     end
 
     context "with at least one call failure" do
-      let(:exitstatus) { 1 }
+      let(:exit_code) { 1 }
       it "should return false if SIPp returns 1" do
-        subject.process_exit_status(process_status).should == false
+        quietly do
+          subject.logger.should_receive(:info).ordered.with(/Test completed successfully but some calls failed./)
+          subject.run.should == false
+        end
       end
     end
 
     context "with an exit from inside SIPp" do
-      let(:exitstatus) { 97 }
+      let(:exit_code) { 97 }
       it "should raise a ExitOnInternalCommand error if SIPp returns 97" do
-        expect {subject.process_exit_status(process_status)}.to raise_error SippyCup::ExitOnInternalCommand
+        quietly do
+          expect {subject.run}.to raise_error SippyCup::ExitOnInternalCommand, error_string
+        end
       end
     end
 
     context "with no calls processed" do
-      let(:exitstatus) { 99 }
+      let(:exit_code) { 99 }
       it "should raise a NoCallsProcessed error if SIPp returns 99" do
-        expect {subject.process_exit_status(process_status)}.to raise_error SippyCup::NoCallsProcessed
+        quietly do
+          expect {subject.run}.to raise_error SippyCup::NoCallsProcessed, error_string
+        end
       end
     end
 
     context "with a fatal error" do
-      let(:exitstatus) { -1 }
-      it "should raise a FatalError error if SIPp returns -1" do
-        expect {subject.process_exit_status(process_status)}.to raise_error SippyCup::FatalError
+      let(:exit_code) { 255 }
+      it "should raise a FatalError error if SIPp returns 255" do
+        quietly do
+          expect {subject.run}.to raise_error SippyCup::FatalError, error_string
+        end
       end
     end
 
     context "with a socket binding fatal error" do
-      let(:exitstatus) { -2 }
-      it "should raise a FatalSocketBindingError error if SIPp returns -2" do
-        expect {subject.process_exit_status(process_status)}.to raise_error SippyCup::FatalSocketBindingError
+      let(:exit_code) { 254 }
+      it "should raise a FatalSocketBindingError error if SIPp returns 254" do
+        quietly do
+          expect {subject.run}.to raise_error SippyCup::FatalSocketBindingError, error_string
+        end
+      end
+    end
+
+    context "with a generic undocumented fatal error" do
+      let(:exit_code) { 128 }
+      let(:error_message) { 'Some error occurred' }
+      it "should raise a SippGenericError error if SIPp returns 255" do
+        quietly do
+          expect {subject.run}.to raise_error SippyCup::SippGenericError, error_string
+        end
+      end
+
+      it "should raise a SippGenericError error with the appropriate message" do
+        quietly do
+          expect {subject.run}.to raise_error SippyCup::SippGenericError, error_string
+        end
       end
     end
   end