diff --git a/tensorflow/core/BUILD b/tensorflow/core/BUILD index 7120d48c91d..eab44bfca54 100644 --- a/tensorflow/core/BUILD +++ b/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"], diff --git a/tensorflow/core/platform/default/test_benchmark.cc b/tensorflow/core/platform/default/test_benchmark.cc index 0b2287bec30..15c01b52338 100644 --- a/tensorflow/core/platform/default/test_benchmark.cc +++ b/tensorflow/core/platform/default/test_benchmark.cc @@ -15,11 +15,15 @@ limitations under the License. #include "tensorflow/core/platform/test_benchmark.h" +#include +#include + #include #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); + } } } } diff --git a/tensorflow/core/platform/test_benchmark.h b/tensorflow/core/platform/test_benchmark.h index 52bc46384af..4c90cf7f854 100644 --- a/tensorflow/core/platform/test_benchmark.h +++ b/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)); diff --git a/tensorflow/core/util/reporter.cc b/tensorflow/core/util/reporter.cc new file mode 100644 index 00000000000..1fe25afa660 --- /dev/null +++ b/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 diff --git a/tensorflow/core/util/reporter.h b/tensorflow/core/util/reporter.h new file mode 100644 index 00000000000..91b24c3bd85 --- /dev/null +++ b/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 +#include +#include + +#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 log_file_; + BenchmarkEntry benchmark_entry_; + TF_DISALLOW_COPY_AND_ASSIGN(TestReporter); +}; + +} // namespace tensorflow + +#endif // TENSORFLOW_CORE_UTIL_REPORTER_H_ diff --git a/tensorflow/core/util/reporter_test.cc b/tensorflow/core/util/reporter_test.cc new file mode 100644 index 00000000000..555829bc591 --- /dev/null +++ b/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 + +#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 diff --git a/tensorflow/core/util/test_log.proto b/tensorflow/core/util/test_log.proto new file mode 100644 index 00000000000..771a1087c1b --- /dev/null +++ b/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 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 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; +}; diff --git a/tensorflow/tensorflow.bzl b/tensorflow/tensorflow.bzl index 3bfbed993f2..b74f47eb652 100644 --- a/tensorflow/tensorflow.bzl +++ b/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", ]