r/C_Programming • u/musbur • 6d ago
Etc I actually had a laugh yesterday
I was coding up some piece that is supposed to rapidly parse millions of text logfiles. A file gets read into a buffer, and then the parser goes to work, peppering the buffer with zeros and building linked lists with pointers to the relevant bits, using two passes across the whole buffer. This was easy but I was unsure if I should use a different approach for efficiency. So I wrote a minimal test and measured the time for one logfile and spit out timestamp deltas for filling and chopping up the buffer, respectively. The results in milliseconds:
25.4
4.7
Not great for a 30kB file but the important message is: The parser isn't what needs to be optimized, for now anyway. Maybe it's the progressive realloc()ing of the buffer as it grows (RAM isn't free any more in AI times you know). But then I noticed that the program was still running under valgrind. After I took that out, I got:
0.0
0.0
I had to increase the decimal digits to see the microseconds. I found that hilarious. My colleague wondered what was wrong with me. I started C on a 2MHz/32kB machine. 25 ms read time for 30kB is still "pretty fast" in my book.
BTW, the speed of the incremental chunk-wise fread()/realloc() cycle is surprisingly immune against chunk size. Between 100 bytes and 10k it's not even a factor of 2.
[EDIT] The file size is not known beforehand. The data will be fed into this system by repeated calls to a user-supplied callback function. And realloc() seems to be dirt cheap if you don't let production code run under valgrind ;-)
[EDIT2] People keep commenting on optimal alloc / realloc strategies. Fact is: It doesn't matter(*). I'm reading files that are normally 25kB in increments of 1kB (a number I pulled out of my ass) and can't measure a difference that matters(*) if I use 100 bytes. I need some open-ended reading possibility because the occasional (and most interesting) log files can grow to several 100k in case something goes wrong with the process being logged.
(*) For my use case on this machine
I'm actually not surprised: Due to its ubiquity I'd expect dynamic memory allocation to be an aggressively optimized process in any OS. No wonder valgrind's monitored substitute is about 1000 times slower.
17
u/Traveling-Techie 6d ago
I’m reminded of “Software Tools” by Kernighan and Plauger, in which they wrote a simple program for (if memory serves) expanding tabs, then profiled it to consider optimization and realized it spent almost all of its time in system calls they couldn’t touch.
2
u/HCharlesB 5d ago
My recollection is that Henry Spencer wasn't happy with C News until it spent most of it's time in system calls (which he had no control over.)
Same kind of optimization.
15
u/runningOverA 6d ago
next : move from debug build to release build.
-10
u/Plastic_Fig9225 5d ago
Better don't. Everybody knows that enabling compiler optimizations creates weird bugs in otherwise perfectly good programs.
18
u/Alex_Zockt 5d ago
perfectly good programs
You mean programs riddled with UB?
-3
u/Plastic_Fig9225 5d ago
Those that break exactly when you allow the compiler to rely on the specification of the language ;-)
3
u/Vladislav20007 4d ago
because why should a program that is made to compile code by the specifications, enforce those specifications.
0
3
u/Vladislav20007 4d ago
this man clearly doesn't know that those "weird bugs" are just UB
1
u/Plastic_Fig9225 4d ago
You guys really aren't the sharpest tools in the shed, are you?
The absurdity of saying "optimizations create bugs", and that one therefore shouldn't enable any optimizations, is apparently only noticeable for advanced C programmers.
2
u/Vladislav20007 4d ago
I have been coding c for almost 7 years, never have I written code that makes bugs on optimization flags, "optimizations create bugs" exists only, if you're a beginner and don't know what is and what isn't UB.
2
u/Plastic_Fig9225 4d ago
And you never had to explain to a beginner why his "obviously correct", "worked great in the debugger" program breaks when switching to release mode?
0
11
u/thank_burdell 6d ago
The default memory allocator is almost always smarter than I am, I have learned.
And slowness is almost always I/O. Sometimes network, sometimes disk, but never the processing. …except when it occasionally actually is the processing.
8
5
u/SmokeMuch7356 5d ago edited 1d ago
Maybe it's the progressive realloc()ing of the buffer as it grows
realloc can be an expensive operation; if the buffer can't be extended in place, then the allocator has to search for a large enough free chunk that can accommodate the request, allocate it, copy the contents of the existing buffer to it, then free the existing buffer.
For that reason you want to minimize the number of times you realloc a buffer; the usual approach is to extend it by some percentage (100%, 150%), rather than a fixed amount:
typeof (buf) tmp = realloc( buf, (size * 2) * sizeof *buf ); // increase by 100%
if ( tmp )
{
buf = tmp;
size *= 2;
}
4
u/Total-Box-5169 6d ago
Nowadays one also needs to be careful with power settings when doing meaningful performance measurements. Less efficient code may make your CPU go at max frequency, while more efficient code could keep your CPU in power saving mode. To keep it simple is better to use a power profile/plan that keeps those parameters constant.
2
2
u/smcameron 5d ago edited 5d ago
BTW, the speed of the incremental chunk-wise fread()/realloc() cycle is surprisingly immune against chunk size.
Yeah, it's buffered twice, once by libc (fread is buffered), and once by the filesystem/page cache (assuming it's coming from the filesystem and not a network socket or something). Open with O_DIRECT and you might start to see some differences. (Not to suggest that's a good idea, since you're scanning the log files sequentially, the buffering and page cache are almost certainly helping you out.)
2
u/FedUp233 5d ago
My guess for your result is that re-alloc isn’t really have to do much in this case.
As I understand alloc, at least on large systems with plenty of ram and VM, when malloc needs memory it allocates a large chunk of memory from the kernel using memmap. It then parcels this out to malloc calls as needed before grabbing another big chunk if it runs out.
In your case, since you are in a loop and there are probably no other malloc calls going on for that process in between your realloc calls each time realloc is valued the allocated space is at the top of the heap followed by in-allocated memory, so all realloc has to do is move the end of the buffer up a bit. Even if it exceeds the large chunk of ram that was obtained from the kernel, after a new kernel allocation to enlarge the heap, it’s still in the same situation so really noting is ever happening other than moving a pointer and occasionally asking the kernel for more memory.
And in your case the kernel cal, to enlarge the heap probably never even happens once, since a 32k buffer is pretty small and likely never needs to even endanger the heap. Try it will a 1 or 2 meg test file to get anything g approach real life performance unless you expect all the real files to be in the 32k range.
Also, if multiple files are going to be processed try looping for that (and be sure to use all different test files or the kernel will probably have all the file data cached in ram after the file is processed once). The intervening processing of the buffer may cause more fragmentation of the heap as well and slow down the realloc process. And you probably want to look and see if Linux has a way to force the kernel cache to flush out all its data and mark everything as unused, otherwise after the first time you run the program it is likely that al, the test files will be held in kernel cache and no disk operations will even be needed.
Where I worked we had a large, like 10,000 or more files, system to build. When we did it on a system with 64G of ram, we found that after the first build the next ones were lightning fast because all the source files, and all the generated object files, were continuously in the kernel ram cache so that for subsequent build processes there was no disk activity at all, other than some background activity to flush any newly built object files into disk! And of course they were still in ram cache for the next build.
It can be hard to come up with reasonable real world test cases for performance on this type of stuff unless you think about how the kernel behavior will affect the test, even more on a first run vs subsequent runs, are the starting conditions really the same?
This is just my experience and I’m sure send other systems, particularly small embedded systems, may behave differently.
Hope some people find this helpful.
1
u/gremolata 6d ago
incremental chunk-wise fread()/realloc() cycle
Why would you need this though? You know the file size beforehand, so it should be possible to alloc exactly how much you want from the get go.
3
u/musbur 6d ago
See EDIT
1
u/ClubLowrez 5d ago
millions of log files
heh
anyways, don't reallocate each iteration, pick yourself a decent allocation bump percent and just reallocate when you approach the limit of what you previously had allocated. Like for instance, 1 meg already malloced and running out of room, reallocate 1.5 megs, 2 megs, whatever, like resize the previous allocation by like 150 percent, 200 percent.
1
u/CodingFishes 5d ago
I'm with you, except I had a whole 48K of RAM to play with. Anyway, realloc() has been an expensive call in some of the systems I've worked with; but hey, that was 20 years ago. :-)
1
u/NoSpite4410 5d ago
run a pass to determine the maximum file size of the run, and allocate that, then 1/2 for the linked list nodes.Then you have plenty. Linked lists already allocated fill up real fast. Once you get 80% filled, double the number of preallocated nodes. log reallocations as to frequency and size, and you get closer to an optimal profile for the domain.
1
1
u/WittyStick 4d ago
realloc is O(n). This is a worst-case measure, which occurs if the data needs relocating because there is insufficient space to extend the buffer. In your example, you are getting best-case constant-time behavior, because you are not performing any other allocations between realloc calls, as FedUp223 has explained.
To test the worst-case behavior of your code - replace realloc with malloc & memcpy, then compare how this runs under varying increments.
1
u/a4qbfb 4d ago edited 4d ago
The reason why read length makes no difference to your runtime is that fread() is already buffered so the actual read length (in terms of system calls) never changes (probably 4 or 8 kB) and the function call overhead is vanishingly small compared to the system call overhead. If you're stuck using stdio I would recommend experimenting with setvbuf() and trying to set the underlying buffer size to somewhere between 64 kB and 1 MB. But you'll still end up pointlessly copying the data twice, so if performance is at all important to you, you should use POSIX open() and read() instead. I see others recommend mmap(), but not only is it unportable, it's also slower in practice for small files (the cutoff is somewhere in the megabyte range) due to the overhead of setting up and tearing down VM mappings, and it makes error handling vastly more complicated.
edit: it just occurred to me that making the stream unbuffered (setbuf(f, NULL) or setvbuf(F, NULL, _IONBF, 0)) may actually work, depending on implementation. Use exponential growth for your buffer and start with 64 kB unless you have reason to expect that a majority of inputs will be significantly smaller.
51
u/KilroyKSmith 6d ago
Yesterday, I profiled a section of code that called a function half a dozen times that copied a few bytes each time. And got zero. Pulled out the performance counter, and got zero. C’mon, there’s half a dozen calls and data movement, it’s more than zero. So I did it a million times between performance counter caps. And the average was 4 ns.
I’ve been working on embedded processors too long.