Added TestReporter and test / benchmark reporting tools.

These tools are meant to allow recording of benchmark & unit test
structured output to pbtxt files in a directory only when the
environment variable TEST_REPORT_FILE_PREFIX is set.  For now,
only saving of C++  microbenchmark output is supported.
Change: 115518303

tensorflow/core/BUILD

@@ -145,11 +145,13 @@ cc_library(
     testonly = 1,
     srcs = [
         "platform/test.cc",
+        "util/reporter.cc",
     ] + tf_additional_test_srcs(),
     hdrs = [
         "lib/core/status_test_util.h",
         "platform/test.h",
         "platform/test_benchmark.h",
+        "util/reporter.h",
     ],
     copts = tf_copts(),
     linkopts = ["-lm"],

tensorflow/core/platform/default/test_benchmark.cc

@@ -15,11 +15,15 @@ limitations under the License.
 
 #include "tensorflow/core/platform/test_benchmark.h"
 
+#include <cstdio>
+#include <cstdlib>
+
 #include <vector>
 #include "tensorflow/core/lib/strings/str_util.h"
 #include "tensorflow/core/platform/env.h"
 #include "tensorflow/core/platform/logging.h"
 #include "tensorflow/core/platform/regexp.h"
+#include "tensorflow/core/util/reporter.h"
 
 namespace tensorflow {
 namespace testing {
@@ -112,6 +116,24 @@ void Benchmark::Run(const char* pattern) {
       }
       printf("%-*s %10.0f %10d\t%s\n", width, name.c_str(),
              seconds * 1e9 / iters, iters, full_label.c_str());
+
+      TestReporter reporter(name);
+      Status s = reporter.Initialize();
+      if (!s.ok()) {
+        LOG(ERROR) << s.ToString();
+        exit(EXIT_FAILURE);
+      }
+      s = reporter.Benchmark(iters, 0.0, seconds,
+                             items_processed * 1e-6 / seconds);
+      if (!s.ok()) {
+        LOG(ERROR) << s.ToString();
+        exit(EXIT_FAILURE);
+      }
+      s = reporter.Close();
+      if (!s.ok()) {
+        LOG(ERROR) << s.ToString();
+        exit(EXIT_FAILURE);
+      }
     }
   }
 }

tensorflow/core/platform/test_benchmark.h

@@ -39,8 +39,11 @@ namespace tensorflow {
 namespace testing {
 
 #if defined(PLATFORM_GOOGLE)
+
 using ::testing::Benchmark;
+
 #else
+
 class Benchmark {
  public:
   Benchmark(const char* name, void (*fn)(int));

tensorflow/core/util/reporter.cc

@@ -0,0 +1,75 @@
+/* Copyright 2016 Google Inc. All Rights Reserved.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+==============================================================================*/
+
+#include "tensorflow/core/util/reporter.h"
+
+#include "tensorflow/core/lib/core/errors.h"
+#include "tensorflow/core/lib/strings/str_util.h"
+#include "tensorflow/core/platform/mutex.h"
+
+namespace tensorflow {
+
+TestReporter::TestReporter(const string& fname, const string& test_name)
+    : closed_(true), fname_(fname), test_name_(test_name) {}
+
+Status TestReporter::Close() {
+  if (closed_) return Status::OK();
+
+  string entry_string;
+  if (!protobuf::TextFormat::PrintToString(benchmark_entry_, &entry_string)) {
+    return errors::Internal("Could not serialize to string: ",
+                            benchmark_entry_.DebugString());
+  }
+
+  TF_RETURN_IF_ERROR(log_file_->Append(entry_string));
+  benchmark_entry_.Clear();
+
+  closed_ = true;
+
+  return log_file_->Close();
+}
+
+Status TestReporter::Benchmark(int64 iters, double cpu_time, double wall_time,
+                               double throughput) {
+  if (closed_) return Status::OK();
+  benchmark_entry_.set_iters(iters);
+  benchmark_entry_.set_cpu_time(cpu_time);
+  benchmark_entry_.set_wall_time(wall_time);
+  benchmark_entry_.set_throughput(throughput);
+  return Status::OK();
+}
+
+Status TestReporter::Initialize() {
+  if (fname_.empty()) {
+    return Status::OK();
+  }
+  string mangled_fname = strings::StrCat(
+      fname_, str_util::Join(str_util::Split(test_name_, '/'), "__"));
+  Env* env = Env::Default();
+  if (env->FileExists(mangled_fname)) {
+    return errors::InvalidArgument("Cannot create TestReporter, file exists: ",
+                                   mangled_fname);
+  }
+  WritableFile* log_file;
+  TF_RETURN_IF_ERROR(env->NewWritableFile(mangled_fname, &log_file));
+  log_file_.reset(log_file);
+  TF_RETURN_IF_ERROR(log_file->Flush());
+
+  benchmark_entry_.set_name(test_name_);
+  closed_ = false;
+  return Status::OK();
+}
+
+}  // namespace tensorflow

tensorflow/core/util/reporter.h

@@ -0,0 +1,94 @@
+/* Copyright 2016 Google Inc. All Rights Reserved.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+==============================================================================*/
+
+#ifndef TENSORFLOW_CORE_UTIL_REPORTER_H_
+#define TENSORFLOW_CORE_UTIL_REPORTER_H_
+
+#include <memory>
+#include <string>
+#include <unordered_set>
+
+#include "tensorflow/core/platform/env.h"
+#include "tensorflow/core/platform/macros.h"
+#include "tensorflow/core/platform/mutex.h"
+#include "tensorflow/core/platform/types.h"
+#include "tensorflow/core/util/test_log.pb.h"
+
+namespace tensorflow {
+
+// The TestReporter writes test / benchmark output to text Protobuf files
+// when the environment variable "TEST_REPORT_FILE_PREFIX" is defined.
+//
+// If this environment variable is not defined, no logging is performed.
+//
+// The intended use is via the following 4 lines:
+//
+//  TestReporter reporter(test_name);
+//  TF_CHECK_OK(reporter.Initialize()));
+//  TF_CHECK_OK(reporter.Benchmark(iters, cpu_time, wall_time, throughput));
+//  TF_CHECK_OK(reporter.Close());
+//
+// For example, if the environment variable
+//   TEST_REPORT_FILE_PREFIX="/tmp/run_"
+// is set, and test_name is "BM_Foo/1/2", then a BenchmarkEntry pbtxt
+// is written to file:
+//   /tmp/run_BM_Foo__1__2
+//
+class TestReporter {
+ public:
+  static constexpr const char* kTestReporterEnv = "TEST_REPORT_FILE_PREFIX";
+
+  // Create a TestReporter with the test name 'test_name'.
+  explicit TestReporter(const string& test_name)
+      : TestReporter(GetLogEnv(), test_name) {}
+
+  // Provide a prefix filename, mostly used for testing this class.
+  TestReporter(const string& fname, const string& test_name);
+
+  // Initialize the TestReporter.  If the reporting env flag is set,
+  // try to create the reporting file.  Fails if the file already exists.
+  Status Initialize();
+
+  // Finalize the report.  If the reporting env flag is set,
+  // flush the reporting file and close it.
+  // Once Close is called, no other methods should be called other
+  // than Close and the destructor.
+  Status Close();
+
+  // Set the report to be a Benchmark and log the given parameters.
+  // Only does something if the reporting env flag is set.
+  // Does not guarantee the report is written.  Use Close() to
+  // enforce I/O operations.
+  Status Benchmark(int64 iters, double cpu_time, double wall_time,
+                   double throughput);
+
+  ~TestReporter() { Close(); }  // Autoclose in destructor.
+
+ private:
+  static string GetLogEnv() {
+    const char* fname_ptr = std::getenv(kTestReporterEnv);
+    return (fname_ptr != nullptr) ? fname_ptr : "";
+  }
+  bool closed_;
+  string fname_;
+  string test_name_;
+  std::unique_ptr<WritableFile> log_file_;
+  BenchmarkEntry benchmark_entry_;
+  TF_DISALLOW_COPY_AND_ASSIGN(TestReporter);
+};
+
+}  // namespace tensorflow
+
+#endif  // TENSORFLOW_CORE_UTIL_REPORTER_H_

tensorflow/core/util/reporter_test.cc

@@ -0,0 +1,117 @@
+/* Copyright 2015 Google Inc. All Rights Reserved.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+==============================================================================*/
+
+#define _XOPEN_SOURCE  // for setenv, unsetenv
+#include <cstdlib>
+
+#include "tensorflow/core/util/reporter.h"
+
+#include "tensorflow/core/lib/core/status_test_util.h"
+#include "tensorflow/core/lib/strings/str_util.h"
+#include "tensorflow/core/lib/strings/strcat.h"
+#include "tensorflow/core/platform/protobuf.h"
+#include "tensorflow/core/platform/test.h"
+
+namespace tensorflow {
+namespace {
+
+// Tests of all the error paths in log_reader.cc follow:
+static void ExpectHasSubstr(StringPiece s, StringPiece expected) {
+  EXPECT_TRUE(StringPiece(s).contains(expected)) << s << " does not contain "
+                                                 << expected;
+}
+
+TEST(TestReporter, NoLogging) {
+  TestReporter test_reporter("b1");
+  TF_EXPECT_OK(test_reporter.Initialize());
+  TF_EXPECT_OK(test_reporter.Close());
+}
+
+TEST(TestReporter, UsesEnv) {
+  const char* old_env = std::getenv(TestReporter::kTestReporterEnv);
+
+  // Set a file we can't possibly create, check for failure
+  setenv(TestReporter::kTestReporterEnv, "/cant/find/me:!", 1);
+  CHECK_EQ(string(std::getenv(TestReporter::kTestReporterEnv)),
+           string("/cant/find/me:!"));
+  TestReporter test_reporter("b1");
+  Status s = test_reporter.Initialize();
+  ExpectHasSubstr(s.ToString(), "open failed for /cant/find/me");
+
+  // Remove the env variable, no logging is performed
+  unsetenv(TestReporter::kTestReporterEnv);
+  CHECK_EQ(std::getenv(TestReporter::kTestReporterEnv), nullptr);
+  TestReporter test_reporter_empty("b1");
+  s = test_reporter_empty.Initialize();
+  TF_EXPECT_OK(s);
+  s = test_reporter_empty.Close();
+  TF_EXPECT_OK(s);
+
+  if (old_env == nullptr) {
+    unsetenv(TestReporter::kTestReporterEnv);
+  } else {
+    setenv(TestReporter::kTestReporterEnv, old_env, 1);
+  }
+}
+
+TEST(TestReporter, CreateTwiceFails) {
+  {
+    TestReporter test_reporter(
+        strings::StrCat(testing::TmpDir(), "/test_reporter_dupe"), "t1");
+    TF_EXPECT_OK(test_reporter.Initialize());
+  }
+  {
+    TestReporter test_reporter(
+        strings::StrCat(testing::TmpDir(), "/test_reporter_dupe"), "t2");
+    Status s = test_reporter.Initialize();
+    ExpectHasSubstr(s.ToString(), "file exists:");
+  }
+}
+
+TEST(TestReporter, CreateCloseCreateAgainSkipsSecond) {
+  TestReporter test_reporter(
+      strings::StrCat(testing::TmpDir(), "/test_reporter_create_close"), "t1");
+  TF_EXPECT_OK(test_reporter.Initialize());
+  TF_EXPECT_OK(test_reporter.Close());
+  TF_EXPECT_OK(test_reporter.Benchmark(1, 1.0, 2.0, 3.0));  // No-op, closed
+  TF_EXPECT_OK(test_reporter.Close());                      // No-op, closed
+  Status s = test_reporter.Initialize();  // Try to reinitialize
+  ExpectHasSubstr(s.ToString(), "file exists:");
+}
+
+TEST(TestReporter, Benchmark) {
+  string fname =
+      strings::StrCat(testing::TmpDir(), "/test_reporter_benchmarks_");
+  TestReporter test_reporter(fname, "b1/2/3");
+  TF_EXPECT_OK(test_reporter.Initialize());
+  TF_EXPECT_OK(test_reporter.Benchmark(1, 1.0, 2.0, 3.0));
+  TF_EXPECT_OK(test_reporter.Close());
+
+  string expected_fname = strings::StrCat(fname, "b1__2__3");
+  string read;
+  TF_EXPECT_OK(ReadFileToString(Env::Default(), expected_fname, &read));
+
+  BenchmarkEntry benchmark_entry;
+  EXPECT_TRUE(protobuf::TextFormat::ParseFromString(read, &benchmark_entry));
+
+  EXPECT_EQ(benchmark_entry.name(), "b1/2/3");
+  EXPECT_EQ(benchmark_entry.iters(), 1);
+  EXPECT_EQ(benchmark_entry.cpu_time(), 1.0);
+  EXPECT_EQ(benchmark_entry.wall_time(), 2.0);
+  EXPECT_EQ(benchmark_entry.throughput(), 3.0);
+}
+
+}  // namespace
+}  // namespace tensorflow

tensorflow/core/util/test_log.proto

@@ -0,0 +1,147 @@
+// Protocol messages for describing the results of benchmarks and unit tests.
+syntax = "proto3";
+
+import "google/protobuf/any.proto";
+
+// option cc_enable_arenas = true;
+option java_outer_classname = "TestLogProtos";
+option java_multiple_files = true;
+option java_package = "org.tensorflow.util.testlog";
+
+package tensorflow;
+
+message EntryValue {
+  oneof kind {
+    double double_value = 1;
+    string string_value = 2;
+  }
+};
+
+// Each unit test or benchmark in a test or benchmark run provides
+// some set of information.  Here we provide some reasonable keys
+// one would expect to see, with optional key/value pairs for things
+// we haven't considered.
+//
+// This BenchmarkEntry should be emitted by each unit test or benchmark
+// reporter.
+message BenchmarkEntry {
+  // The name of the specific benchmark or test
+  // (e.g. BM_AdjustContrast_gpu_B_W_H)
+  string name = 1;
+
+  // If a benchmark, how many iterations it was run for
+  int64 iters = 2;
+
+  // Total cpu time used for all iterations (in seconds)
+  double cpu_time = 3;
+
+  // Total wall time used for all iterations (in seconds)
+  double wall_time = 4;
+
+  // Throughput (in MB/s)
+  double throughput = 5;
+
+  // Generic map from result key to value.
+  map<string, EntryValue> extras = 6;
+};
+
+message BenchmarkEntries {
+  repeated BenchmarkEntry entry = 1;
+}
+
+message BuildConfiguration {
+  string mode = 1;             // opt, dbg, etc
+  repeated string config = 2;  // asan, cuda, etc
+  repeated string copts = 3;   // -mavx, etc.
+};
+
+message CommitId {
+  oneof kind {
+    int64 changelist = 1;
+    string hash = 2;
+  }
+};
+
+message CPUInfo {
+  // How fast are these cpus?
+  double mhz_per_cpu = 1;
+
+  // Additional cpu information. For example,
+  // Intel Ivybridge with HyperThreading (24 cores) dL1:32KB dL2:256KB dL3:30MB
+  string cpu_info = 2;
+
+  // What kind of cpu scaling is enabled on the host.
+  // Examples include "performance", "ondemand", "conservative", "mixed".
+  string cpu_governor = 3;
+
+  // Cache sizes (in bytes), e.g. "L2": 262144 (for 256KB)
+  map<string, int64> cache_size = 4;
+};
+
+message GPUInfo {
+  string model = 1;  // e.g. "Tesla K40c"
+  string uuid = 2;   // Final entry in output of "nvidia-smi -L"
+};
+
+message PlatformInfo {
+  string bits = 1;       // e.g. '64bit'
+  string linkage = 2;    // e.g. 'ELF'
+  string machine = 3;    // e.g. 'i386'
+  string processor = 4;  // e.g. 'amdk6'  (the real processor name)
+  string release = 5;    // e.g. '3.13.0-76-generic'
+  string system = 6;     // e.g. 'Linux'
+  string version = 7;    // e.g. '#120-Ubuntu SMP Mon Jan 18 15:59:10 UTC 2016'
+};
+
+message MachineConfiguration {
+  // Host name of machine that ran the benchmark.
+  string hostname = 1;
+
+  // Additional platform information.
+  PlatformInfo platform_info = 2;
+
+  // CPU Information.
+  CPUInfo cpu_info = 3;
+
+  // Other devices that are attached and relevant (e.g. GPUInfo).
+  repeated google.protobuf.Any device_info = 4;
+};
+
+// Run-specific items such as arguments to the test / benchmark.
+message RunConfiguration {
+  repeated string arguments = 1;
+}
+
+// The output of one benchmark / test run.  Each run contains a list of
+// tests or benchmarks, stored as BenchmarkEntry messages.
+//
+// This message should be emitted by the reporter (which runs the
+// test / BM in a subprocess and then reads the emitted BenchmarkEntry messages;
+// usually from a serialized json file, finally collecting them along
+// with additional information about the test run.
+message TestResults {
+  // The target of the run, e.g.:
+  //  //tensorflow/core:kernels_adjust_contrast_op_benchmark_test
+  string target = 1;
+
+  // The list of tests or benchmarks in this run.
+  BenchmarkEntries entries = 2;
+
+  // The configuration of the build (compiled opt? with cuda? any copts?)
+  BuildConfiguration build_configuration = 3;
+
+  // The commit id (git hash or changelist)
+  CommitId commit_id = 4;
+
+  // The time the run started (in seconds of UTC time since Unix epoch)
+  int64 start_time = 5;
+
+  // The amount of time the total run took (wall time in seconds)
+  double run_time = 6;
+
+  // Machine-specific parameters (Platform and CPU info)
+  MachineConfiguration machine_configuration = 7;
+
+  // Run-specific parameters (arguments, etc)
+  RunConfiguration run_configuration = 8;
+};

tensorflow/tensorflow.bzl

@@ -9,6 +9,7 @@ load("//tensorflow/core:platform/default/build_config_root.bzl",
 # List of proto files for android builds
 def tf_android_core_proto_sources():
     return [
+        "//google/protobuf",  # any.proto
         "//tensorflow/core:example/example.proto",
         "//tensorflow/core:example/feature.proto",
         "//tensorflow/core:framework/allocation_description.proto",
@@ -29,7 +30,8 @@ def tf_android_core_proto_sources():
         "//tensorflow/core:framework/versions.proto",
         "//tensorflow/core:lib/core/error_codes.proto",
         "//tensorflow/core:protobuf/saver.proto",
-        "//tensorflow/core:util/saved_tensor_slice.proto"
+        "//tensorflow/core:util/saved_tensor_slice.proto",
+        "//tensorflow/core:util/test_log.proto",
   ]