[llvm-objdump][NFC] Make the PrettyPrinter::printInst() output buffered

[seiya]

Summary

Every time PrettyPrinter::printInst is called, stdout is flushed and it makes llvm-objdump slow. This patches adds a string
buffer to prevent stdout from being flushed.

Benchmark results (./llvm-objdump-master: without this patch, ./bin/llvm-objcopy: with this patch):

$ hyperfine --warmup 10 './llvm-objdump-master -d ./bin/llvm-objcopy' './bin/llvm-objdump -d ./bin/llvm-objcopy'
Benchmark #1: ./llvm-objdump-master -d ./bin/llvm-objcopy
  Time (mean ± σ):      2.230 s ±  0.050 s    [User: 1.533 s, System: 0.682 s]
  Range (min … max):    2.115 s …  2.278 s    10 runs

Benchmark #2: ./bin/llvm-objdump -d ./bin/llvm-objcopy
  Time (mean ± σ):     386.4 ms ±  13.0 ms    [User: 376.6 ms, System: 6.1 ms]
  Range (min … max):   366.1 ms … 407.0 ms    10 runs

Summary
  './bin/llvm-objdump -d ./bin/llvm-objcopy' ran
    5.77 ± 0.23 times faster than './llvm-objdump-master -d ./bin/llvm-objcopy'

[jhenderson]

I've added a few more reviewers for visibility.

My initial thought was "why not just delete the "flush"" from printInst, but I see that it's there for a "good" reason, looking at PrettyPrinter. I can't help but feel that a better solution would be to fix formatted_raw_ostream so that the indentation only gets added after any already-written content. Assuming that's not viable (e.g. it's intentional behaviour), I think what you have written works. @seiya, what are your thoughts on the formatted_raw_ostream implementation? Can it be sensibly changed?

[seiya]

In D64969#1593100, @jhenderson wrote:

I've added a few more reviewers for visibility.

My initial thought was "why not just delete the "flush"" from printInst, but I see that it's there for a "good" reason, looking at PrettyPrinter. I can't help but feel that a better solution would be to fix formatted_raw_ostream so that the indentation only gets added after any already-written content. Assuming that's not viable (e.g. it's intentional behaviour), I think what you have written works. @seiya, what are your thoughts on the formatted_raw_ostream implementation? Can it be sensibly changed?

First I thought that it is not straightforward to update the position (what FOS.getColumn() returns) in formatted_raw_stream without flushing because it's done in its write_impl.

However, now I realized that it's trivial: add new method formatted_raw_ostream::updatePositionByBufferedString() (I couldn't come up with a good name) method, which reads the buffered string and updates the position by doing ComputePosition(getBufferStart(), GetNumBytesInBuffer()); .

I haven't tried this, but with this method, we no longer need to add a string buffer like this current patch. What do you think on this approach?

[jhenderson]

In D64969#1593267, @seiya wrote:

In D64969#1593100, @jhenderson wrote:

I've added a few more reviewers for visibility.

My initial thought was "why not just delete the "flush"" from printInst, but I see that it's there for a "good" reason, looking at PrettyPrinter. I can't help but feel that a better solution would be to fix formatted_raw_ostream so that the indentation only gets added after any already-written content. Assuming that's not viable (e.g. it's intentional behaviour), I think what you have written works. @seiya, what are your thoughts on the formatted_raw_ostream implementation? Can it be sensibly changed?

First I thought that it is not straightforward to update the position (what FOS.getColumn() returns) in formatted_raw_stream without flushing because it's done in its write_impl.

However, now I realized that it's trivial: add new method formatted_raw_ostream::updatePositionByBufferedString() (I couldn't come up with a good name) method, which reads the buffered string and updates the position by doing ComputePosition(getBufferStart(), GetNumBytesInBuffer()); .

I haven't tried this, but with this method, we no longer need to add a string buffer like this current patch. What do you think on this approach?

It's hard to envisage this without seeing a patch with it in. Could you create a separate patch to this one, with your alternative proposal in, so that I and others can compare and contrast the two options, please?

[seiya]

In D64969#1593271, @jhenderson wrote:

In D64969#1593267, @seiya wrote:

In D64969#1593100, @jhenderson wrote:

I've added a few more reviewers for visibility.

My initial thought was "why not just delete the "flush"" from printInst, but I see that it's there for a "good" reason, looking at PrettyPrinter. I can't help but feel that a better solution would be to fix formatted_raw_ostream so that the indentation only gets added after any already-written content. Assuming that's not viable (e.g. it's intentional behaviour), I think what you have written works. @seiya, what are your thoughts on the formatted_raw_ostream implementation? Can it be sensibly changed?

First I thought that it is not straightforward to update the position (what FOS.getColumn() returns) in formatted_raw_stream without flushing because it's done in its write_impl.

However, now I realized that it's trivial: add new method formatted_raw_ostream::updatePositionByBufferedString() (I couldn't come up with a good name) method, which reads the buffered string and updates the position by doing ComputePosition(getBufferStart(), GetNumBytesInBuffer()); .

I haven't tried this, but with this method, we no longer need to add a string buffer like this current patch. What do you think on this approach?

It's hard to envisage this without seeing a patch with it in. Could you create a separate patch to this one, with your alternative proposal in, so that I and others can compare and contrast the two options, please?

I had a look at formatted_raw_ostream, but the idea I proposed in a comment is not effective and this current patch would be better. Here's why:

formatted_raw_ostream takes a raw_ostream (outs() in this context) and tracks the current column/line position. Since formatted_raw_ostream itself is buffered, it flushes and makes the wrapped stream ( outs()) unbuffered in the constructor, and restore its buffering settings in the destructor [1].

To prevent outs() from being flushed, I tried making formatted_raw_ostream unbuffered and keeping outs() buffered, however, outs() is unbuffered if it's tty (line buffering is not implemented and it is stated that "it's' not worth the complexity" [2]). That is, what we need to do is implementing line buffering for stdout (this patch implements a sort of it by InstString).

I think this patch is a simple workaround for this, but working on making outs() line-buffered instead may be better. What do you think which way sounds better?

Personally I redirect the output of llvm-objdump to a pipe (e.g., llvm-objdump foo | less) so we can just ignore such case (stdout is tty), btw.

[1]: https://github.com/llvm/llvm-project/blob/2946cd701067404b99c39fb29dc9c74bd7193eb3/llvm/include/llvm/Support/FormattedStream.h#L83
[2]: https://github.com/llvm/llvm-project/blob/49a3ad21d6034eb20f99f228dbebcc5f65a748d8/llvm/lib/Support/raw_ostream.cpp#L773

[MaskRay]

Nice finding!

[1]: https://github.com/llvm/llvm-project/blob/2946cd701067404b99c39fb29dc9c74bd7193eb3/llvm/include/llvm/Support/FormattedStream.h#L83

I think the 4x (line buffered vs unbuffered) slowdown can be explained by your first link. The formatted_raw_ostream ctor resets the underlying stream (outs()) to unbuffered. There are several solutions to the problem. Given formatted_raw_ostream FOS(OS); is only used once in PrettyPrinter and can be easily replaced, I suggest deleting it and tracking the column manually.

[seiya]

In D64969#1595098, @MaskRay wrote:

Nice finding!

[1]: https://github.com/llvm/llvm-project/blob/2946cd701067404b99c39fb29dc9c74bd7193eb3/llvm/include/llvm/Support/FormattedStream.h#L83

I think the 4x (line buffered vs unbuffered) slowdown can be explained by your first link. The formatted_raw_ostream ctor resets the underlying stream (outs()) to unbuffered. There are several solutions to the problem. Given formatted_raw_ostream FOS(OS); is only used once in PrettyPrinter and can be easily replaced, I suggest deleting it and tracking the column manually.

Tracking the column manually sounds good idea to me. I'll try that!

[seiya]

• Track the column manually to remove formatted_raw_ostream.

[seiya]

Simply removing formatted_raw_ostream makes llvm-objdump faster as I expected:

$ hyperfine --warmup 10 './llvm-objdump-master -d ./bin/llvm-objcopy' './bin/llvm-objdump -d ./bin/llvm-objcopy'
Benchmark #1: ./llvm-objdump-master -d ./bin/llvm-objcopy
  Time (mean ± σ):      2.230 s ±  0.050 s    [User: 1.533 s, System: 0.682 s]
  Range (min … max):    2.115 s …  2.278 s    10 runs

Benchmark #2: ./bin/llvm-objdump -d ./bin/llvm-objcopy
  Time (mean ± σ):     386.4 ms ±  13.0 ms    [User: 376.6 ms, System: 6.1 ms]
  Range (min … max):   366.1 ms … 407.0 ms    10 runs

Summary
  './bin/llvm-objdump -d ./bin/llvm-objcopy' ran
    5.77 ± 0.23 times faster than './llvm-objdump-master -d ./bin/llvm-objcopy'

[MaskRay]

Apologize I added formatted_raw_ostream and I didn't read its ctor carefully...

Benchmark #2: ./bin/llvm-objdump -d ./bin/llvm-objcopy
Time (mean ± σ): 386.4 ms ± 13.0 ms [User: 376.6 ms, System: 6.1 ms]
Range (min … max): 366.1 ms … 407.0 ms 10 runs

Please remember updating the description before you commit. The benchmark has been updated.

[seiya]

In D64969#1598506, @MaskRay wrote:

Apologize I added formatted_raw_ostream and I didn't read its ctor carefully...

Benchmark #2: ./bin/llvm-objdump -d ./bin/llvm-objcopy
Time (mean ± σ): 386.4 ms ± 13.0 ms [User: 376.6 ms, System: 6.1 ms]
Range (min … max): 366.1 ms … 407.0 ms 10 runs

Please remember updating the description before you commit. The benchmark has been updated.

Don't apologize! This was a good opportunity for me to work on the performance issue and was just interesting :D

[jhenderson]

LGTM too.

llvm/trunk/tools/llvm-objdump/llvm-objdump.cpp

virtual void printInst(MCInstPrinter &IP, const MCInst *MI,
                          ArrayRef<uint8_t> Bytes,
                          object::SectionedAddress Address, raw_ostream &OS,
                          StringRef Annot, MCSubtargetInfo const &STI,
                          SourcePrinter *SP,
                          std::vector<RelocationRef> *Rels = nullptr) {
     if (SP && (PrintSource || PrintLines))
       SP->printSourceLine(OS, Address);
 
-    {
-      formatted_raw_ostream FOS(OS);
-      if (!NoLeadingAddr)
-        FOS << format("%8" PRIx64 ":", Address.Address);
-      if (!NoShowRawInsn) {
-        FOS << ' ';
-        dumpBytes(Bytes, FOS);
-      }
-      FOS.flush();
-      // The output of printInst starts with a tab. Print some spaces so that
-      // the tab has 1 column and advances to the target tab stop.
-      unsigned TabStop = NoShowRawInsn ? 16 : 40;
-      unsigned Column = FOS.getColumn();
-      FOS.indent(Column < TabStop - 1 ? TabStop - 1 - Column : 7 - Column % 8);
-
-      // The dtor calls flush() to ensure the indent comes before printInst().
-    }
+    size_t Start = OS.tell();
+      OS << format("%8" PRIx64 ":", Address.Address);
+      OS << ' ';
+      dumpBytes(Bytes, OS);
+
+    unsigned Column = OS.tell() - Start;
+    OS.indent(Column < TabStop - 1 ? TabStop - 1 - Column : 7 - Column % 8);
 
     if (MI)
       IP.printInst(MI, OS, "", STI);
     else
       OS << "\t<unknown>";
   }
 };
 PrettyPrinter PrettyPrinterInst;