[llvm-dev] Why is printing an Instruction so slow?

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
7 messages Options
Reply | Threaded
Open this post in threaded view
|

[llvm-dev] Why is printing an Instruction so slow?

Aaron Smith via llvm-dev
Hi all,

When writing my custom passes, I often emit log messages to llvm::errs() like so:

llvm::errs() << "Could not handle instruction: " << *Inst << std::endl;

where Inst is a pointer to an Instruction.

I've profiled my code and found that this way of printing an Instruction takes a very long time: indeed, it is the bottleneck of my pass. 

Of course, I could always switch these log messages off for production runs, but during development and debugging, I'd like to have them on to make debugging much easier.

Is there a faster way to print an Instruction?

Thanks,
Steve

_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev
Reply | Threaded
Open this post in threaded view
|

Re: [llvm-dev] Why is printing an Instruction so slow?

Aaron Smith via llvm-dev
Hi Steve:

llvm::errs() is unbuffered, so that might explain it.  Could you try llvm::outs() instead and see if that helps.

hth...
don

On Mon, Oct 5, 2015 at 11:17 AM, Stephen Thomas via llvm-dev <[hidden email]> wrote:
Hi all,

When writing my custom passes, I often emit log messages to llvm::errs() like so:

llvm::errs() << "Could not handle instruction: " << *Inst << std::endl;

where Inst is a pointer to an Instruction.

I've profiled my code and found that this way of printing an Instruction takes a very long time: indeed, it is the bottleneck of my pass. 

Of course, I could always switch these log messages off for production runs, but during development and debugging, I'd like to have them on to make debugging much easier.

Is there a faster way to print an Instruction?

Thanks,
Steve

_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev



_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev
Reply | Threaded
Open this post in threaded view
|

Re: [llvm-dev] Why is printing an Instruction so slow?

Aaron Smith via llvm-dev
Using `llvm::outs()` will only be noticeably faster if `std::endl;` is replaced with `'\n'` or similar, since `std::endl;` will cause a flush as well - it may be little better, but for buffering to work well, you wan't a few thousand characters in the buffer, not just a few dozen.

--
Mats

On 5 October 2015 at 17:05, don hinton via llvm-dev <[hidden email]> wrote:
Hi Steve:

llvm::errs() is unbuffered, so that might explain it.  Could you try llvm::outs() instead and see if that helps.

hth...
don

On Mon, Oct 5, 2015 at 11:17 AM, Stephen Thomas via llvm-dev <[hidden email]> wrote:
Hi all,

When writing my custom passes, I often emit log messages to llvm::errs() like so:

llvm::errs() << "Could not handle instruction: " << *Inst << std::endl;

where Inst is a pointer to an Instruction.

I've profiled my code and found that this way of printing an Instruction takes a very long time: indeed, it is the bottleneck of my pass. 

Of course, I could always switch these log messages off for production runs, but during development and debugging, I'd like to have them on to make debugging much easier.

Is there a faster way to print an Instruction?

Thanks,
Steve

_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev



_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev



_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev
Reply | Threaded
Open this post in threaded view
|

Re: [llvm-dev] Why is printing an Instruction so slow?

Aaron Smith via llvm-dev
In reply to this post by Aaron Smith via llvm-dev
Instruction printing is usually slow because it uses SlotNumbering, which is a whole function analysis to determine what numbers to use for unnamed values.

If printing is part of your critical path, you can use 'Value::print(raw_ostream&, ModuleSlotTracker&)' instead of operator<<. I believe it will help you do the analysis once and print many instructions.

On Mon, Oct 5, 2015 at 8:17 AM, Stephen Thomas via llvm-dev <[hidden email]> wrote:
Hi all,

When writing my custom passes, I often emit log messages to llvm::errs() like so:

llvm::errs() << "Could not handle instruction: " << *Inst << std::endl;

where Inst is a pointer to an Instruction.

I've profiled my code and found that this way of printing an Instruction takes a very long time: indeed, it is the bottleneck of my pass. 

Of course, I could always switch these log messages off for production runs, but during development and debugging, I'd like to have them on to make debugging much easier.

Is there a faster way to print an Instruction?

Thanks,
Steve

_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev



_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev
Reply | Threaded
Open this post in threaded view
|

Re: [llvm-dev] Why is printing an Instruction so slow?

Aaron Smith via llvm-dev


On Mon, Oct 5, 2015 at 12:36 PM, Reid Kleckner <[hidden email]> wrote:
Instruction printing is usually slow because it uses SlotNumbering, which is a whole function analysis to determine what numbers to use for unnamed values.

If printing is part of your critical path, you can use 'Value::print(raw_ostream&, ModuleSlotTracker&)' instead of operator<<. I believe it will help you do the analysis once and print many instructions.

Reid,

Thanks for the tip. I don't see a `Value::print()` function with that signature. I only see `Value::print(raw_ostream&)` (from http://llvm.org/docs/doxygen/html/classllvm_1_1Value.html). I'm using 3.6. Is this a 3.7 thing?

Cheers,
Steve

 

On Mon, Oct 5, 2015 at 8:17 AM, Stephen Thomas via llvm-dev <[hidden email]> wrote:
Hi all,

When writing my custom passes, I often emit log messages to llvm::errs() like so:

llvm::errs() << "Could not handle instruction: " << *Inst << std::endl;

where Inst is a pointer to an Instruction.

I've profiled my code and found that this way of printing an Instruction takes a very long time: indeed, it is the bottleneck of my pass. 

Of course, I could always switch these log messages off for production runs, but during development and debugging, I'd like to have them on to make debugging much easier.

Is there a faster way to print an Instruction?

Thanks,
Steve

_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev




_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev
Reply | Threaded
Open this post in threaded view
|

Re: [llvm-dev] Why is printing an Instruction so slow?

Aaron Smith via llvm-dev
In reply to this post by Aaron Smith via llvm-dev

On Mon, Oct 5, 2015 at 12:05 PM, don hinton <[hidden email]> wrote:
Hi Steve:

llvm::errs() is unbuffered, so that might explain it.  Could you try llvm::outs() instead and see if that helps.

Don,

Nice tip. Switching to llvm::outs() saved about 15% for me. Not a golden bullet, but still nothing to sneeze at. Printing instructions still remains the bottleneck for my pass.

I'm curious how llvm-dis is able to write out so much IR text is so little time.

Thanks,
Steve
 

hth...
don

On Mon, Oct 5, 2015 at 11:17 AM, Stephen Thomas via llvm-dev <[hidden email]> wrote:
Hi all,

When writing my custom passes, I often emit log messages to llvm::errs() like so:

llvm::errs() << "Could not handle instruction: " << *Inst << std::endl;

where Inst is a pointer to an Instruction.

I've profiled my code and found that this way of printing an Instruction takes a very long time: indeed, it is the bottleneck of my pass. 

Of course, I could always switch these log messages off for production runs, but during development and debugging, I'd like to have them on to make debugging much easier.

Is there a faster way to print an Instruction?

Thanks,
Steve

_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev




_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev
Reply | Threaded
Open this post in threaded view
|

Re: [llvm-dev] Why is printing an Instruction so slow?

Aaron Smith via llvm-dev
In reply to this post by Aaron Smith via llvm-dev


On Mon, Oct 5, 2015 at 9:36 AM, Reid Kleckner via llvm-dev <[hidden email]> wrote:
Instruction printing is usually slow because it uses SlotNumbering, which is a whole function analysis to determine what numbers to use for unnamed values.

If printing is part of your critical path, you can use 'Value::print(raw_ostream&, ModuleSlotTracker&)' instead of operator<<. I believe it will help you do the analysis once and print many instructions.

It is still linear in the number of types in the module. (I recently tried to reduce llvm-diff's O((module size)^2) complexity by using ModuleSlotTracker but it still was quadratic even when using moduleslottracker)

-- Sean Silva
 

On Mon, Oct 5, 2015 at 8:17 AM, Stephen Thomas via llvm-dev <[hidden email]> wrote:
Hi all,

When writing my custom passes, I often emit log messages to llvm::errs() like so:

llvm::errs() << "Could not handle instruction: " << *Inst << std::endl;

where Inst is a pointer to an Instruction.

I've profiled my code and found that this way of printing an Instruction takes a very long time: indeed, it is the bottleneck of my pass. 

Of course, I could always switch these log messages off for production runs, but during development and debugging, I'd like to have them on to make debugging much easier.

Is there a faster way to print an Instruction?

Thanks,
Steve

_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev



_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev



_______________________________________________
LLVM Developers mailing list
[hidden email]
http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev