commit fa02c9d460b300c26849b453c430297df46ce904
author David Brazdil <dbrazdil@google.com> Wed Mar 30 09:41:02 2016 +0100
committer David Brazdil <dbrazdil@google.com> Wed Mar 30 10:30:49 2016 +0100
tree 8dd8e2cc5f181bbcf41fa8d79da182fa974b906c
parent a923025e08e61fd2ff26e3d60c26e9db29637736

ART: Flush ostream less frequently in GraphVisualizer

We have seen Checker tests timing out on debug-GC configurations after
having switched to Optimizing because its GraphVisualizer makes too
many syscalls which the configuration keeps track of.

This patch replaces std::endl with "\n" across GraphVisualizer so as
to not flush the stream after every line of output.

Bug: 27826765
Change-Id: I5e3f1e92f8a84f36d324d56945e2d420b2d36a5d

compiler/optimizing/graph_visualizer.cc

diff --git a/compiler/optimizing/graph_visualizer.cc b/compiler/optimizing/graph_visualizer.cc
index 4b5b919..b3eff14 100644
--- a/compiler/optimizing/graph_visualizer.cc
+++ b/compiler/optimizing/graph_visualizer.cc
@@ -178,41 +178,47 @@
                       : nullptr),
         indent_(0) {}
 
+  void Flush() {
+    // We use "\n" instead of std::endl to avoid implicit flushing which
+    // generates too many syscalls during debug-GC tests (b/27826765).
+    output_ << std::flush;
+  }
+
   void StartTag(const char* name) {
     AddIndent();
-    output_ << "begin_" << name << std::endl;
+    output_ << "begin_" << name << "\n";
     indent_++;
   }
 
   void EndTag(const char* name) {
     indent_--;
     AddIndent();
-    output_ << "end_" << name << std::endl;
+    output_ << "end_" << name << "\n";
   }
 
   void PrintProperty(const char* name, const char* property) {
     AddIndent();
-    output_ << name << " \"" << property << "\"" << std::endl;
+    output_ << name << " \"" << property << "\"\n";
   }
 
   void PrintProperty(const char* name, const char* property, int id) {
     AddIndent();
-    output_ << name << " \"" << property << id << "\"" << std::endl;
+    output_ << name << " \"" << property << id << "\"\n";
   }
 
   void PrintEmptyProperty(const char* name) {
     AddIndent();
-    output_ << name << std::endl;
+    output_ << name << "\n";
   }
 
   void PrintTime(const char* name) {
     AddIndent();
-    output_ << name << " " << time(nullptr) << std::endl;
+    output_ << name << " " << time(nullptr) << "\n";
   }
 
   void PrintInt(const char* name, int value) {
     AddIndent();
-    output_ << name << " " << value << std::endl;
+    output_ << name << " " << value << "\n";
   }
 
   void AddIndent() {
@@ -249,7 +255,7 @@
     if (block->IsEntryBlock() && (disasm_info_ != nullptr)) {
       output_ << " \"" << kDisassemblyBlockFrameEntry << "\" ";
     }
-    output_<< std::endl;
+    output_<< "\n";
   }
 
   void PrintSuccessors(HBasicBlock* block) {
@@ -258,7 +264,7 @@
     for (HBasicBlock* successor : block->GetNormalSuccessors()) {
       output_ << " \"B" << successor->GetBlockId() << "\" ";
     }
-    output_<< std::endl;
+    output_<< "\n";
   }
 
   void PrintExceptionHandlers(HBasicBlock* block) {
@@ -272,7 +278,7 @@
         !disasm_info_->GetSlowPathIntervals().empty()) {
       output_ << " \"" << kDisassemblyBlockSlowPaths << "\" ";
     }
-    output_<< std::endl;
+    output_<< "\n";
   }
 
   void DumpLocation(std::ostream& stream, const Location& location) {
@@ -588,7 +594,7 @@
       auto it = disasm_info_->GetInstructionIntervals().find(instruction);
       if (it != disasm_info_->GetInstructionIntervals().end()
           && it->second.start != it->second.end) {
-        output_ << std::endl;
+        output_ << "\n";
         disassembler_->Disassemble(output_, it->second.start, it->second.end);
       }
     }
@@ -608,7 +614,7 @@
       output_ << bci << " " << num_uses << " "
               << GetTypeId(instruction->GetType()) << instruction->GetId() << " ";
       PrintInstruction(instruction);
-      output_ << " " << kEndInstructionMarker << std::endl;
+      output_ << " " << kEndInstructionMarker << "\n";
     }
   }
 
@@ -652,10 +658,10 @@
     output_ << "    0 0 disasm " << kDisassemblyBlockFrameEntry << " ";
     GeneratedCodeInterval frame_entry = disasm_info_->GetFrameEntryInterval();
     if (frame_entry.start != frame_entry.end) {
-      output_ << std::endl;
+      output_ << "\n";
       disassembler_->Disassemble(output_, frame_entry.start, frame_entry.end);
     }
-    output_ << kEndInstructionMarker << std::endl;
+    output_ << kEndInstructionMarker << "\n";
     DumpEndOfDisassemblyBlock();
   }
 
@@ -671,9 +677,9 @@
         GetGraph()->HasExitBlock() ? GetGraph()->GetExitBlock()->GetBlockId() : -1,
         -1);
     for (SlowPathCodeInfo info : disasm_info_->GetSlowPathIntervals()) {
-      output_ << "    0 0 disasm " << info.slow_path->GetDescription() << std::endl;
+      output_ << "    0 0 disasm " << info.slow_path->GetDescription() << "\n";
       disassembler_->Disassemble(output_, info.code_interval.start, info.code_interval.end);
-      output_ << kEndInstructionMarker << std::endl;
+      output_ << kEndInstructionMarker << "\n";
     }
     DumpEndOfDisassemblyBlock();
   }
@@ -694,6 +700,7 @@
       DumpDisassemblyBlockForSlowPaths();
     }
     EndTag("cfg");
+    Flush();
   }
 
   void VisitBasicBlock(HBasicBlock* block) OVERRIDE {
@@ -733,7 +740,7 @@
       for (HInputIterator inputs(instruction); !inputs.Done(); inputs.Advance()) {
         output_ << inputs.Current()->GetId() << " ";
       }
-      output_ << "]" << std::endl;
+      output_ << "]\n";
     }
     EndTag("locals");
     EndTag("states");
@@ -775,6 +782,7 @@
   printer.PrintProperty("method", method_name);
   printer.PrintTime("date");
   printer.EndTag("compilation");
+  printer.Flush();
 }
 
 void HGraphVisualizer::DumpGraph(const char* pass_name,