Andre's Blog
Perfection is when there is nothing left to take away
std::wstringstream vs. swprintf

A few days ago a developer asked me if we intend to replace all archaic printf-style calls within the project with modern, object-oriented string stream equivalents. I heard this sentiment many times over the years, often substantiated by the fact that buffered stream operations are faster than frequent parsing of the format string. Let's test this theory and format a simple string in a loop using both methods.

Both code fragments were compiled using Visual C++ in release mode, with all optimizations set to a maximum level.

DWORD stime;
int slen, max_count = 1000000ul;
wchar_t buffer[256];
std::wstring s;
stime = GetTickCount();
for(int i = 0; i < max_count; i++) {
	slen = swprintf(buffer, 255, L"Temperature:% 4.3f\n", 
			(double) 123.456789);
	s.assign(buffer, slen);
}
printf("elapsed (sptrintf): %0.3f sec\n", (GetTickCount()-stime)/1000.);

The swprintf loop completed in 2.141 seconds.

DWORD stime;
int max_count = 1000000ul;
std::wstringstream strm;
const std::wstring empty;
stime = GetTickCount();
for(int i = 0; i < max_count; i++) {
	strm.str(empty);
	strm << L"Temperature:" << 
		std::setiosflags(std::ios::right) << 
		std::setfill(L' ') << 
		std::setw(8) << 
		std::setprecision(6) << 
		(double) 123.456789 << std::endl;
	s = strm.str();
}
printf("elapsed (stream): %0.3f sec\n", (GetTickCount()-stime)/1000.);

However, the string stream loop took 7.359 seconds to complete. What a difference!

In order to find out why string streams took so long, I ran this test in a profiler and quickly found that most time was spent in the new "secure" function  sprintf_s (see Microsoft: More steam, more noise - let the world think we are moving! for details) and then, on top of that, the code used a mutex to make sure the stream is thread-safe (std::basic_ostream::sentry). Finally, the formatted number was output using the current locale to make sure it is formatted according to the locale rules, which also took a bit of time.

Since sprintf_s was a Microsoft's invention, I wanted to see how much difference would there be if I compiled this test using GCC 4.1.2. I ran the test on my Linux machine and the difference was still there, even though it was much more modest than in the Microsoft's case - the swprintf loop took 8 seconds to complete, while the string stream loop finished in 14 seconds.

On top of performance concerns, I also find stream-based output much less descriptive than the good old printf-style formatting. Along these lines, I find it rather interesting that the king of OO languages, Java, struggled for a few years concatenating strings until, finally, formatted output was introduced in Java about three years ago. It's just one of those things that makes life of a developer much easier!

December 3rd, 2009

I ran a few more tests at Billy's request. I had to modify the code from the comment because it was not assigning the output string within the loop, which was a part of the test. I also have to note that the new code is unfair to printf because a single format string may be used with multiple arguments.

Nevertheless, I re-ran the tests described above to make sure I'm getting the same results for the tests described above, and then tested this code:

stime = GetTickCount();

strm << std::setiosflags(std::ios::right) << 
	std::setfill(L' ') << 
	std::setw(8) << 
	std::setprecision(6);

for(int i = 0; i < max_count; i++) {
	strm.str(empty);
	strm << L"Temperature:" << (double) 123.456789 << std::endl;
	s = strm.str();
}
printf("%S", s.c_str());

printf("elapsed (stream 2): %0.3f sec\n", (GetTickCount()-stime)/1000.);

The running time of this test was similar to the initial result, just slightly faster at 7.188 seconds, which is expected, since all of the calls taken out of the loop merely set numeric data members within the stream.

I also got curious how much did it cost to populate the STL string in these tests, so I took the assignment of s out of the loop and ran the tests again. Interestingly enough, the running time of the first test calling string::assign didn't change much from the initial test and was at 2.047 seconds. The second and third tests, however, took just a bit more than half the initial time at 4.688 and 4.546 seconds, respectively.

The reason for this is that once string s has been created, the storage allocated in the first assignment was reused in all subsequent calls. Contrary to this, stream string was always created as a temporary and then copied into s, adding a couple of seconds to the overall running time.

Comments:
Posted Thu Dec 3 15:26:23 EST 2009 by Billy O'Neal

A good hunk of that too is that you're setting the format flags over and over again at each iteration. One of the nice things about the iostream library is that it lets you set a flag once and forget about it. You're also paying for construction of a wstringstream object every time in the loop.

I'd be curious to see how this performs instead:

DWORD stime;

int max_count = 1000000ul;

std::wstringstream strm;

stime = GetTickCount();

strm << std::setiosflags(std::ios::right) << 

std::setfill(L' ') << 

std::setw(8) << 

std::setprecision(6);

for(int i = 0; i < max_count; i++) {

strm.str.clear();

strm << L"Temperature:" << (double) 123.456789 << std::endl;

}

printf("elapsed (stream): %0.3f sec\n", (GetTickCount()-stime)/1000.);

Name:

Comment: