18938 Passing the error log around

toolset/benchmark/benchmarker.py

@@ -517,12 +517,12 @@ class Benchmarker:
               Error: Port {port} is not available before start {name}
             ---------------------------------------------------------
             """.format(name=test.name, port=str(test.port))) )
-          out.flush()
+          err.flush()
           return
 
-        result = test.start(out)
+        result = test.start(out, err)
         if result != 0: 
-          test.stop(out)
+          test.stop(out, err)
           time.sleep(5)
           err.write( "ERROR: Problem starting {name}\n".format(name=test.name) )
           err.write( textwrap.dedent("""
@@ -544,8 +544,9 @@ class Benchmarker:
           Verifying URLs for {name}
         -----------------------------------------------------
         """.format(name=test.name)) )
-        test.verify_urls(out)
+        test.verify_urls(out, err)
         out.flush()
+        err.flush()
 
         ##########################
         # Benchmark this test
@@ -557,7 +558,9 @@ class Benchmarker:
             -----------------------------------------------------
             """.format(name=test.name)) )
           out.flush()
-          test.benchmark(out)
+          test.benchmark(out, err)
+          out.flush()
+          err.flush()
 
         ##########################
         # Stop this test
@@ -568,7 +571,9 @@ class Benchmarker:
         -----------------------------------------------------
         """.format(name=test.name)) )
         out.flush()
-        test.stop(out)
+        test.stop(out, err)
+        out.flush()
+        err.flush()
         time.sleep(5)
 
         if self.__is_port_bound(test.port):
@@ -578,7 +583,7 @@ class Benchmarker:
               Error: Port {port} was not released by stop {name}
             -----------------------------------------------------
             """.format(name=test.name, port=str(test.port))) )
-          out.flush()
+          err.flush()
           return
 
         out.write( textwrap.dedent("""
@@ -602,34 +607,36 @@ class Benchmarker:
         self.__write_intermediate_results(test.name,time.strftime("%Y%m%d%H%M%S", time.localtime()))
       except (OSError, IOError, subprocess.CalledProcessError):
         self.__write_intermediate_results(test.name,"<setup.py> raised an exception")
-        out.write( textwrap.dedent("""
+        err.write( textwrap.dedent("""
         -----------------------------------------------------
           Subprocess Error {name}
         -----------------------------------------------------
         """.format(name=test.name)) )
-        out.flush()
+        err.flush()
         try:
-          test.stop(out)
+          test.stop(out, err)
         except (subprocess.CalledProcessError):
           self.__write_intermediate_results(test.name,"<setup.py>#stop() raised an error")
-          out.write( textwrap.dedent("""
+          err.write( textwrap.dedent("""
           -----------------------------------------------------
             Subprocess Error: Test .stop() raised exception {name}
           -----------------------------------------------------
           """.format(name=test.name)) )
-          out.flush()
+          err.flush()
       except (KeyboardInterrupt, SystemExit):
         test.stop(out)
-        out.write( """
+        err.write( """
         -----------------------------------------------------
           Cleaning up....
         -----------------------------------------------------
         """ )
-        out.flush()
-        out.close()
+        err.flush()
         self.__finish()
         sys.exit()
 
+      out.close()
+      err.close()
+
   ############################################################
   # End __run_tests
   ############################################################

toolset/benchmark/framework_test.py

@@ -104,7 +104,7 @@ class FrameworkTest:
   # start(benchmarker)
   # Start the test using it's setup file
   ############################################################
-  def start(self, out):
+  def start(self, out, err):
     return self.setup_module.start(self.benchmarker, out)
   ############################################################
   # End start
@@ -114,7 +114,7 @@ class FrameworkTest:
   # stop(benchmarker)
   # Stops the test using it's setup file
   ############################################################
-  def stop(self, out):
+  def stop(self, out, err):
     return self.setup_module.stop(out)
   ############################################################
   # End stop
@@ -127,13 +127,13 @@ class FrameworkTest:
   # For each url, a flag will be set on this object for whether
   # or not it passed
   ############################################################
-  def verify_urls(self, out):
+  def verify_urls(self, out, err):
     # JSON
     try:
       out.write( "VERIFYING JSON (" + self.json_url + ") ...\n" )
       out.flush()
       url = self.benchmarker.generate_url(self.json_url, self.port)
-      self.__curl_url(url, out)
+      self.__curl_url(url, out, err)
       self.json_url_passed = True
     except (AttributeError, subprocess.CalledProcessError) as e:
       self.json_url_passed = False
@@ -143,7 +143,7 @@ class FrameworkTest:
       out.write( "VERIFYING DB (" + self.db_url + ") ...\n" )
       out.flush()
       url = self.benchmarker.generate_url(self.db_url, self.port)
-      self.__curl_url(url, out)
+      self.__curl_url(url, out, err)
       self.db_url_passed = True
     except (AttributeError, subprocess.CalledProcessError) as e:
       self.db_url_passed = False
@@ -153,7 +153,7 @@ class FrameworkTest:
       out.write( "VERIFYING Query (" + self.query_url + "2) ...\n" )
       out.flush()
       url = self.benchmarker.generate_url(self.query_url + "2", self.port)
-      self.__curl_url(url, out)
+      self.__curl_url(url, out, err)
       self.query_url_passed = True
     except (AttributeError, subprocess.CalledProcessError) as e:
       self.query_url_passed = False
@@ -163,7 +163,7 @@ class FrameworkTest:
       out.write( "VERIFYING Fortune (" + self.fortune_url + ") ...\n" )
       out.flush()
       url = self.benchmarker.generate_url(self.fortune_url, self.port)
-      self.__curl_url(url, out)
+      self.__curl_url(url, out, err)
       self.fortune_url_passed = True
     except (AttributeError, subprocess.CalledProcessError) as e:
       self.fortune_url_passed = False
@@ -173,7 +173,7 @@ class FrameworkTest:
       out.write( "VERIFYING Update (" + self.update_url + "2) ...\n" )
       out.flush()
       url = self.benchmarker.generate_url(self.update_url + "2", self.port)
-      self.__curl_url(url, out)
+      self.__curl_url(url, out, err)
       self.update_url_passed = True
     except (AttributeError, subprocess.CalledProcessError) as e:
       self.update_url_passed = False
@@ -183,7 +183,7 @@ class FrameworkTest:
       out.write( "VERIFYING Plaintext (" + self.plaintext_url + ") ...\n" )
       out.flush()
       url = self.benchmarker.generate_url(self.plaintext_url, self.port)
-      self.__curl_url(url, out)
+      self.__curl_url(url, out, err)
       self.plaintext_url_passed = True
     except (AttributeError, subprocess.CalledProcessError) as e:
       self.plaintext_url_passed = False
@@ -223,14 +223,14 @@ class FrameworkTest:
   # Runs the benchmark for each type of test that it implements
   # JSON/DB/Query.
   ############################################################
-  def benchmark(self, out):
+  def benchmark(self, out, err):
     # JSON
     try:
       if self.json_url_passed and (self.benchmarker.type == "all" or self.benchmarker.type == "json"):
         out.write("BENCHMARKING JSON ... ") 
         out.flush()
         remote_script = self.__generate_concurrency_script(self.json_url, self.port, self.accept_json)
-        self.__run_benchmark(remote_script, self.benchmarker.output_file(self.name, 'json'))
+        self.__run_benchmark(remote_script, self.benchmarker.output_file(self.name, 'json'), err)
         results = self.__parse_test('json')
         self.benchmarker.report_results(framework=self, test="json", results=results['results'])
         out.write( "Complete\n" )
@@ -244,7 +244,7 @@ class FrameworkTest:
         out.write("BENCHMARKING DB ... ") 
         out.flush()
         remote_script = self.__generate_concurrency_script(self.db_url, self.port, self.accept_json)
-        self.__run_benchmark(remote_script, self.benchmarker.output_file(self.name, 'db'))
+        self.__run_benchmark(remote_script, self.benchmarker.output_file(self.name, 'db'), err)
         results = self.__parse_test('db')
         self.benchmarker.report_results(framework=self, test="db", results=results['results'])
         out.write( "Complete\n" )
@@ -258,7 +258,7 @@ class FrameworkTest:
         out.write("BENCHMARKING Query ... ")
         out.flush()
         remote_script = self.__generate_query_script(self.query_url, self.port, self.accept_json)
-        self.__run_benchmark(remote_script, self.benchmarker.output_file(self.name, 'query'))
+        self.__run_benchmark(remote_script, self.benchmarker.output_file(self.name, 'query'), err)
         results = self.__parse_test('query')
         self.benchmarker.report_results(framework=self, test="query", results=results['results'])
         out.write( "Complete\n" )
@@ -273,7 +273,7 @@ class FrameworkTest:
         out.write("BENCHMARKING Fortune ... ") 
         out.flush()
         remote_script = self.__generate_concurrency_script(self.fortune_url, self.port, self.accept_html)
-        self.__run_benchmark(remote_script, self.benchmarker.output_file(self.name, 'fortune'))
+        self.__run_benchmark(remote_script, self.benchmarker.output_file(self.name, 'fortune'), err)
         results = self.__parse_test('fortune')
         self.benchmarker.report_results(framework=self, test="fortune", results=results['results'])
         out.write( "Complete\n" )
@@ -288,12 +288,13 @@ class FrameworkTest:
         out.write("BENCHMARKING Update ... ") 
         out.flush()
         remote_script = self.__generate_query_script(self.update_url, self.port, self.accept_json)
-        self.__run_benchmark(remote_script, self.benchmarker.output_file(self.name, 'update'))
+        self.__run_benchmark(remote_script, self.benchmarker.output_file(self.name, 'update'), err)
         results = self.__parse_test('update')
         self.benchmarker.report_results(framework=self, test="update", results=results['results'])
         out.write( "Complete\n" )
         out.flush()
     except AttributeError:
+      # TODO - this needs to report some logging
       traceback.print_exc()
       pass
 
@@ -303,7 +304,7 @@ class FrameworkTest:
         out.write("BENCHMARKING Plaintext ... ")
         out.flush()
         remote_script = self.__generate_concurrency_script(self.plaintext_url, self.port, self.accept_plaintext, wrk_command="wrk-pipeline", intervals=[256,1024,4096,16384], pipeline="--pipeline 16")
-        self.__run_benchmark(remote_script, self.benchmarker.output_file(self.name, 'plaintext'))
+        self.__run_benchmark(remote_script, self.benchmarker.output_file(self.name, 'plaintext'), err)
         results = self.__parse_test('plaintext')
         self.benchmarker.report_results(framework=self, test="plaintext", results=results['results'])
         out.write( "Complete\n" )
@@ -456,11 +457,12 @@ class FrameworkTest:
   # template that uses weighttp to run the test. All the results
   # outputed to the output_file.
   ############################################################
-  def __run_benchmark(self, script, output_file):
+  def __run_benchmark(self, script, output_file, err):
     with open(output_file, 'w') as raw_file:
 	  
-      p = subprocess.Popen(self.benchmarker.client_ssh_string.split(" "), stdin=subprocess.PIPE, stdout=raw_file, stderr=raw_file)
+      p = subprocess.Popen(self.benchmarker.client_ssh_string.split(" "), stdin=subprocess.PIPE, stdout=raw_file, stderr=err)
       p.communicate(script)
+      err.flush()
   ############################################################
   # End __run_benchmark
   ############################################################
@@ -516,14 +518,15 @@ class FrameworkTest:
   # Dump HTTP response and headers. Throw exception if there
   # is an HTTP error.
   ############################################################
-  def __curl_url(self, url, out):
+  def __curl_url(self, url, out, err):
     # Use -i to output response with headers.
     # Don't use -f so that the HTTP response code is ignored.
     # Use --stderr - to redirect stderr to stdout so we get
     # error output for sure in stdout.
     # Use -sS to hide progress bar, but show errors.
-    subprocess.check_call(["curl", "-i", "--stderr", "-", "-sS", url], stderr=out, stdout=out)
+    subprocess.check_call(["curl", "-i", "-", "-sS", url], stderr=err, stdout=out)
     out.flush()
+    err.flush()
     # HTTP output may not end in a newline, so add that here.
     out.write( "\n" )
     out.flush()
@@ -534,8 +537,9 @@ class FrameworkTest:
     # uses check_output() instead of check_call() so that we can
     # ignore the HTTP response because we already output that in
     # the first curl invocation.
-    subprocess.check_output(["curl", "-fsS", url], stderr=out)
+    subprocess.check_output(["curl", "-fsS", url], stderr=err)
     out.flush()
+    err.flush()
     # HTTP output may not end in a newline, so add that here.
     out.write( "\n" )
     out.flush()