Thursday, May 20, 2010

Are C++ iostreams really slow?

In the C++ world, one often hears the statement “iostreams are slow, you should use printf instead”. Is this true?

It is possible that this story results from abuse of endl. Beginner's C++ books often recommend endl over '\n' for writing a newline. The observable result is often the same, but endl results in extra overhead: it flushes the stream. This results in a system call, slowing things down while often unnecessary.

Using my newly written TimedSection class, I tested whether the story is actually true, or just a myth. I tried three methods of printing:

  • cout with endl for line endings
  • cout with '\n' for line endings
  • printf (also with '\n' for line endings, so no forced flushing)

Each of these was tested in the following scenarios:

  • printing an empty line
  • printing a line containing a string literal
  • printing a line containing a string variable, a string literal, and an integer variable

All strings used were 20 characters long; I figured this would be a typical average length for printing messages. Newline characters were absorbed into string constants wherever possible.

Each of these was run 10 million times, redirecting the output to /dev/null. The testing machine is an Intel i7 920, running Ubuntu 10.4, Linux 2.6.32 and gcc 4.4.3.

Here are the results:

cout with only endl                     1461.310252 ms
cout with only '\n'                      343.080217 ms
printf with only '\n'                     90.295948 ms
cout with string constant and endl      1892.975381 ms
cout with string constant and '\n'       416.123446 ms
printf with string constant and '\n'     472.073070 ms
cout with some stuff and endl           3496.489748 ms
cout with some stuff and '\n'           2638.272046 ms
printf with some stuff and '\n'         2520.318314 ms

Surprise! Yes, for printing newlines, printf greatly outperforms cout. We can also see the huge slowdown of using endl inappropriately, something which is clearly to be avoided.

However, even for printing a moderately-sized string constant, cout outperforms printf. This effect becomes more pronounced as the string gets longer, probably because printf has to do more processing per character.

Finally, for some slightly more complicated formatting, the difference is quite small. For longer string constants, it becomes even smaller.

We can conclude that iostreams are definitely not always slower than C-style printf. It depends on the particular use, and as the formatting becomes more complicated, the difference drops to zero. Part of the myth may be ascribed to inappropriate use of endl; maybe another part is due to unoptimized implementations of the standard library. Either way: myth busted.

Update: For the curious, here is the full source code. You may need to link with -lrt to get clock_gettime.

#include <stdio.h>
#include <iostream>
#include <ctime>

class TimedSection {
    char const *d_name;
    timespec d_start;
    public:
        TimedSection(char const *name) :
            d_name(name)
        {
            clock_gettime(CLOCK_REALTIME, &d_start);
        }
        ~TimedSection() {
            timespec end;
            clock_gettime(CLOCK_REALTIME, &end);
            double duration = 1e3 * (end.tv_sec - d_start.tv_sec) +
                              1e-6 * (end.tv_nsec - d_start.tv_nsec);
            std::cerr << d_name << '\t' << std::fixed << duration << " ms\n"; 
        }
};

int main() {
    const int iters = 10000000;
    char const *text = "01234567890123456789";
    {
        TimedSection s("cout with only endl");
        for (int i = 0; i < iters; ++i)
            std::cout << std::endl;
    }
    {
        TimedSection s("cout with only '\\n'");
        for (int i = 0; i < iters; ++i)
            std::cout << '\n';
    }
    {
        TimedSection s("printf with only '\\n'");
        for (int i = 0; i < iters; ++i)
            printf("\n");
    }
    {
        TimedSection s("cout with string constant and endl");
        for (int i = 0; i < iters; ++i)
            std::cout << "01234567890123456789" << std::endl;
    }
    {
        TimedSection s("cout with string constant and '\\n'");
        for (int i = 0; i < iters; ++i)
            std::cout << "01234567890123456789\n";
    }
    {
        TimedSection s("printf with string constant and '\\n'");
        for (int i = 0; i < iters; ++i)
            printf("01234567890123456789\n");
    }
    {
        TimedSection s("cout with some stuff and endl");
        for (int i = 0; i < iters; ++i)
            std::cout << text << "01234567890123456789" << i << std::endl;
    }
    {
        TimedSection s("cout with some stuff and '\\n'");
        for (int i = 0; i < iters; ++i)
            std::cout << text << "01234567890123456789" << i << '\n';
    }
    {
        TimedSection s("printf with some stuff and '\\n'");
        for (int i = 0; i < iters; ++i)
            printf("%s01234567890123456789%i\n", text, i);
    }
}

10 comments:

Anonymous said...

"myth busted"? Maybe if you provide the source code for your tests. And specified compile flags you used ;)

Mark IJbema said...

Still, from your number i'd deduce that the best way to be sure that it's quite fast is using printf. In certain cases cout is a bit faster, but in other ones printf is way slower. Right?

Thomas ten Cate said...

@Anonymous: I updated with the full source code and compile flags.

@Mark IJbema: I assume you mean "... cout is way slower." However, those cases are pathological; who'd want to print ten million newlines? In common cases, however, the speed difference is so small that we are better off using cout, gaining type-safety and (often) readability. (I know, there are cases where printf is more readable…)

flux said...

Of course, there is not much formatting going on.

{
TimedSection s("cout number formatting");
for (int i = 0; i < iters; ++i)
std::cout << std::setfill('0') << std::setw(2) << i << " "
<< std::setfill(' ') << std::setw(4) << i << "\n";
}
{
TimedSection s("printf number formatting");
for (int i = 0; i < iters; ++i)
printf("%02d %4d\n", i, i);
}

These give me a results 3.7 seconds and 3.1 seconds. (With g++ and -O2; with default optimization level the numbers were 4.1 and 3.0.)

In practice, though, I don't care. But while printf isn't type safe nor extensible, it sure is more compact..

Nicola Bonelli said...

What compiler options did you use to make the test? Optimizations matter for streams, probably more than for printf...

Thomas ten Cate said...

@Nicola Bonelli: Yes, compile flags matter. Ignoring the endl cases (which are pathologically slow), on my system...

-O0 makes the first printf blazing fast (WTF?!). For the other cases, cout is slightly slower, but the difference is negligible.

-O1 makes cout slightly faster than printf in all cases.

-O2 makes cout a little bit faster compared to -O1; printf remains about the same.

-O3 gives nearly the same results as -O2.

Nicola Bonelli said...
This comment has been removed by the author.
Nicola Bonelli said...

Streams are template, the code is compiled with the application, that explains why the optimization flags matter. The code of printf, instead, is a builtin function of the gcc comper unless you pass -fno-builtin option, in which case the glbc library function is used.

Nicola Bonelli said...

It would be nice if you could post also the performance of boost::format, as well as the performance of my c++0x print (available here: http://code.google.com/p/nicola-bonelli-repo/source/browse/trunk/codes.cpp0x/print.hpp) :-)

Anonymous said...

Must keep knowledge of Matt Wilson's Fast Format alive -

http://www.fastformat.org/performance.html