Speedup llvm-dwarfdump 3.9x

[jankratochvil]

Summary

Currently strace llvm-dwarfdump x.debug >/tmp/file:

ioctl(1, TCGETS, 0x7ffd64d7f340)        = -1 ENOTTY (Inappropriate ioctl for device)
write(1, "           DW_AT_decl_line\t(89)\n"..., 4096) = 4096
ioctl(1, TCGETS, 0x7ffd64d7f400)        = -1 ENOTTY (Inappropriate ioctl for device)
ioctl(1, TCGETS, 0x7ffd64d7f410)        = -1 ENOTTY (Inappropriate ioctl for device)
ioctl(1, TCGETS, 0x7ffd64d7f400)        = -1 ENOTTY (Inappropriate ioctl for device)

After this patch:

write(1, "0000000000001102 \"strlen\")\n     "..., 4096) = 4096
write(1, "site\n                  DW_AT_low"..., 4096) = 4096
write(1, "d53)\n\n0x000e4d4d:       DW_TAG_G"..., 4096) = 4096

The same speedup can be achieved by --color=0 but that is not much convenient.
After this patch it still uses ioctl for printing DWARF parsing errors.
Maybe raw_ostream &OS could be moved into DIDumpOptions DumpOpts which would somehow make this patch more simple, I can investigate it more and change it upon request.
I can also drop this patch if it looks too hacky.

[jhenderson]

Thanks for bringing this up!

I believe llvm-dwarfdump isn't the only thing that prints using colours. I think we need a more general solution than this.

Also, perhaps this should be done by the stream itself - it seems like the stream knows whether or not it supports colours, so should we not just have the stream ignore attempts to use colours if the underlying thing doesn't support them?

[jankratochvil]

In D86406#2232912, @jhenderson wrote:

Also, perhaps this should be done by the stream itself - it seems like the stream knows whether or not it supports colours, so should we not just have the stream ignore attempts to use colours if the underlying thing doesn't support them?

OK, I agree, I will move it there. That should also solve the caching problem.

[JDevlieghere]

If I understand the patch correctly, the speedup is gained by caching the mode instead of trying to recompute it every time we call colorsEnabled()? This seems like a huge speedup for such a small thing, maybe I'm missing something?

In D86406#2232912, @jhenderson wrote:

Also, perhaps this should be done by the stream itself - it seems like the stream knows whether or not it supports colours, so should we not just have the stream ignore attempts to use colours if the underlying thing doesn't support them?

We already disable colors when they're not supported by the stream.

In D86406#2232918, @jankratochvil wrote:

OK, I agree, I will move it there. That should also solve the caching problem.

I don't think we should move it into the stream, if that's what you mean by "there". The color cl::opt is part of WithColor so we should check its value there.

Can we achieve the same thing by resolving the ColorMode to Enable and Disable in the WihtColor constructor?

[jhenderson]

In D86406#2234381, @JDevlieghere wrote:

If I understand the patch correctly, the speedup is gained by caching the mode instead of trying to recompute it every time we call colorsEnabled()? This seems like a huge speedup for such a small thing, maybe I'm missing something?

In D86406#2232912, @jhenderson wrote:

Also, perhaps this should be done by the stream itself - it seems like the stream knows whether or not it supports colours, so should we not just have the stream ignore attempts to use colours if the underlying thing doesn't support them?

We already disable colors when they're not supported by the stream.

Maybe I misunderstood what this bit of the strace output was complaining about then:
ioctl(1, TCGETS, 0x7ffd64d7f340) = -1 ENOTTY (Inappropriate ioctl for device)
(I have never used strace, so was only guessing based on its general appearance). I took it to mean that an attempt was made to change the colour, but failed because files don't support different colours, and that this failure is expensive.

In D86406#2232918, @jankratochvil wrote:

OK, I agree, I will move it there. That should also solve the caching problem.

I don't think we should move it into the stream, if that's what you mean by "there". The color cl::opt is part of WithColor so we should check its value there.

Can we achieve the same thing by resolving the ColorMode to Enable and Disable in the WihtColor constructor?

[jankratochvil]

In D86406#2234381, @JDevlieghere wrote:

If I understand the patch correctly, the speedup is gained by caching the mode instead of trying to recompute it every time we call colorsEnabled()?

Yes.

This seems like a huge speedup for such a small thing, maybe I'm missing something?

Detecting whether fd 1 supports colors means an ioctl() call which is a kernel call. That is several orders of magnitue more expensive than any in-process codeflow and in-process calculations. This is on Linux, I did not check OSX.

I don't think we should move it into the stream, if that's what you mean by "there". The color cl::opt is part of WithColor so we should check its value there.

I plan to make raw_ostream to have auto/on/off mode (default=auto). WithColor's ctor will set the mode of the raw_ostream. raw_ostream will do the expensive ioctl() detection only during first time changing color if raw_ostream has auto mode and raw_ostream will cache the detected value.

(Not yet written, busy with DWZ stuff, thanks for asking.)

Can we achieve the same thing by resolving the ColorMode to Enable and Disable in the WithColor constructor?

No because WithColor is ctored/dtored many times for every DIE. This is what results in so many expensive ioctl()s.

It could be done in WithColor if its Mode is changed to a static member but then that static member would be set according to current raw_ostream and it would be incorrect if WithColor's static member is later used with different raw_ostream.

In D86406#2235331, @jhenderson wrote:

Maybe I misunderstood what this bit of the strace output was complaining about then:
ioctl(1, TCGETS, 0x7ffd64d7f340) = -1 ENOTTY (Inappropriate ioctl for device)
(I have never used strace, so was only guessing based on its general appearance). I took it to mean that an attempt was made to change the colour, but failed because files don't support different colours, and that this failure is expensive.

Expensive is the detection. Color output is just printing some bytes like "\x1B[0;36m".

[joerg]

Can you change raw_fd_ostream::has_colors to memoize the result of FileDescriptorHasColors(FD) instead? That should give most of the performance gain without breaking the abstractions as much.

[jankratochvil]

In D86406#2235959, @joerg wrote:

Can you change raw_fd_ostream::has_colors to memoize the result of FileDescriptorHasColors(FD) instead?

Done, yes, that looks simple and it works. The new code is not thread-safe but other member variables there also are not.

[joerg]

llvm/include/llvm/Support/raw_ostream.h

298

I'd keep the original const in the interface contract and mark HasColors as mutable instead. It's an implementation detail that the field is set lazily and the property itself should be invariant.

[jhenderson]

LGTM, thanks!

llvm/include/llvm/Support/raw_ostream.h

public:
 
   /// This function determines if this stream is connected to a "tty" or
   /// "console" window. That is, the output would be displayed to the user
   /// rather than being put on a pipe or stored in a file.
   virtual bool is_displayed() const { return false; }
 
   /// This function determines if this stream is displayed and supports colors.
   /// The result is unaffected by calls to enable_color().
   virtual bool has_colors() const { return is_displayed(); }
 
   // Enable or disable colors. Once enable_colors(false) is called,
   // changeColor() has no effect until enable_colors(true) is called.
   virtual void enable_colors(bool enable) { ColorEnabled = enable; }
 
   /// Tie this stream to the specified stream. Replaces any existing tied-to
   /// stream. Specifying a nullptr unties the stream.
   void tie(raw_ostream *TieTo) { TiedStream = TieTo; }

 //===----------------------------------------------------------------------===//
 
 /// A raw_ostream that writes to a file descriptor.
 ///
 class raw_fd_ostream : public raw_pwrite_stream {
   int FD;
   bool ShouldClose;
   bool SupportsSeeking = false;
+  mutable Optional<bool> HasColors;
 
 #ifdef _WIN32
   /// True if this fd refers to a Windows console device. Mintty and other
   /// terminal emulators are TTYs, but they are not consoles.
   bool IsWindowsConsole = false;
 #endif
 
   std::error_code EC;

llvm/lib/Support/raw_ostream.cpp

 #endif
 }
 
 bool raw_fd_ostream::is_displayed() const {
   return sys::Process::FileDescriptorIsDisplayed(FD);
 }
 
 bool raw_fd_ostream::has_colors() const {
-  return sys::Process::FileDescriptorHasColors(FD);
+  if (!HasColors)
+    HasColors = sys::Process::FileDescriptorHasColors(FD);
+  return *HasColors;
 }
 
 Expected<sys::fs::FileLocker> raw_fd_ostream::lock() {
   std::error_code EC = sys::fs::lockFile(FD);
   if (!EC)
     return sys::fs::FileLocker(FD);
   return errorCodeToError(EC);
 }