catch-up after a brief hiatus.

Yikes, almost a month since I last posted.
In that time, I’ve spent pretty much all my time heads down chasing memory corruption bugs in Trinity, and whacking a bunch of smaller issues as I came across them. Some of the bugs I’ve been chasing have taken a while to reproduce, so I’ve deliberately held off on changing too much at once this last few weeks, choosing instead to dribble changes in a few commits at a time, just to be sure things weren’t actually getting worse. Every time I thought I’d finally killed the last bug, I’d do another run for a few hours, and then see the same corrupted structures. Incredibly frustrating. After a process of elimination (I found a hundred places where the bug wasn’t), I think I’ve finally zeroed in on the problematic code, in the functions that generate random filenames.
I pretty much gutted that code today, which should remove both the bug, and a bunch of unnecessary operations that never found any kernel bugs anyway. I’m glad I spent the time to chase this down, because the next bunch of features I plan to implement leverage this code quite heavily, and would have only caused even more headache later on.

The one plus side of chasing this bug the last month or so has been all the added debugging code I’ve come up with. Some of it has been committed for re-use later, while some of the more intrusive debug features (like storing backtraces for every locking operation) I opted not to commit, but will keep the diff around in case it comes in handy again sometime.

Spent the afternoon clearing out my working tree by committing all the clean-up patches I’ve done while doing this work. Some of them were a little tangled and needed separating into multiple commits). Next, removing some lingering code that hasn’t really done anything useful for a while.

I’ve been hesitant to start on the newer features until things calmed down, but that should hopefully be pretty close.

Transferring maintainership of x86info.

On Mon Feb 26 2001, I committed the version of x86info. 13 years later I’m pretty much done with it.
Despite a surge of activity back in February, when I reached a new record monthly commit count record, it’s been a project I’ve had little time for over the last few years. Luckily, someone has stepped up to take over. Going forward, Nick Black will be maintaining it here.

I might still manage the occasional commit, but I won’t be feeling guilty about neglecting it any more.

An unfinished splinter project that I started a while back x86utils was intended to be a replacement for x86info of sorts, by moving it to multiple small utilities rather than the one monolithic blob that x86info is. I’m undecided if I’ll continue to work on this, especially given my time commitments to Trinity and related projects.

Daily log June 16th 2014

Catch up from the last week or so.
Spent a lot of time turning a bunch of code in trinity inside out. After splitting the logging code into “render” and “write out buffer”, I had a bunch of small bugs to nail down. While chasing those I kept occasionally hitting some strange bug where occasionally the list of pids would get corrupted. Two weeks on, and I’m still no closer to figuring out the exact cause, but I’ve got a lot more clues (mostly by now knowing what it _isn’t_ due to a lot of code rewriting).
Some of that rewriting has been on my mind for a while, the shared ‘shm’ structure between all processes was growing to the point that I was having trouble remembering why certain variables were shared there rather than just be globals in main, inherited at fork time. So I moved a bunch of variables from the shm to another structure named ‘childdata’, of which there are an array of ptrs to in the shm.

Some of the code then looked a little convoluted with references that used to be shm->data being replaced with shm->children[childno].data, which I remedied by having each child instantiate a ‘this_child’ var when it starts up, allowing this_child->data to point to the right thing.

All of this code churn served in part to refresh my memory on how some of this worked, hoping that I’d stumble across the random scribble that occasionally happens. I also added a bunch of code to things like dump backtraces, which has been handy for turning up 1-2 unrelated bugs.

On Friday afternoon I discovered that the bug only shows up if MALLOC_PERTURB_ is set. Which is curious, because the struct in question that gets scribbled over is never free()’d. It’s allocated once at startup, and inherited in each child when it fork()’s.

Debugging continues..

Daily log June 2nd 2014

Spent the day making some progress on trinity’s “dump buffers after we detect tainted kernel” code, before hitting a roadblock. It’s possible for a fuzzing child process to allocate a buffer to create (for eg) a mangled filename. Because this allocation is local to the child, attempts to reconstruct what it pointed to from the dumping process will fail.
I spent a while thinking about this before starting on a pretty severe rewrite of how the existing logging code works. Instead of just writing the description of what is in the registers to stdout/logs, it now writes it to a buffer, which can be referenced directly by any of the other processes. A lot of the output code actually looks a lot easier to read as an unintended consequence.
No doubt I’ve introduced a bunch of bugs in the process, which I’ll spend time trying to get on top of tomorrow.

Daily log May 27th 2014

Spent much of the day getting on top of the inevitable email backlog.
Later started cleaning up some of the code in trinity that dumps out syscall parameters to tty/log files.
One of the problems that has come up with trinity is that many people run it with logging disabled, because it’s much faster when you’re not constantly spewing to files, or scrolling text. This unfortunately leads to situations where we get an oops and we have no idea what actually happened. We have some information that we could dump in that case, which we aren’t right now.
So I’ve been spending time lately working towards a ‘post-mortem dump’ feature. The two pieces missing are 1. moving the logging functions away from being special cased to be called from within a child process, so that they can just chew on a syscall record. (This work is now almost done), and 2. maintain a ringbuffer of these records per child. (Not a huge amount of work once everything else is in place).

Hopefully I’ll have this implemented soon, and then I can get back on track with some of the more interesting fuzzing ideas I’ve had for improving.

Daily log May 22nd 2014

Found another hugepage VM bug.
This one VM_BUG_ON_PAGE(PageTail(page), page). The filemap.c bug has gone into hiding since last weekend. Annoying.

On the trinity list, Michael Ellerman reported a couple bugs that looked like memory corruption since my changes yesterday to make fd registration more dynamic. So I started the day trying out -fsanitize=address without much success. (I had fixed a number of bugs recently using it). However, reading the gcc man page, I found out about -fsanitize=undefined, which I was previously unaware of. This is new in gcc 4.9, so ships with Fedora rawhide, but my test box is running F20. Luckily, clang has supported it even longer.

So I spent a while fixing up a bunch of silly bugs, like (1<<31) where it should have been (1UL<<31) and some not so obvious alignment bugs. A dozen or so fixes for bugs that had been there for years. Sadly though, nothing that explained the corruption Michael has been seeing. I spent some more time looking over yesterdays changes without success. Annoying that I don’t see the corruption when I run it.

Decided not to take on anything too ambitious for the rest of the day given I’m getting an early start on the long weekend, by taking off tomorrow. Hopefully when I return with fresh eyes on Tuesday I’ll have some idea of what I can do to reproduce the bug.

Daily log May 21st 2014

Fell out of the habit of blogging regularly again.
Recap: Took Monday off, to deal with fallout from a flooded apartment that happened at 2am Sunday night. Not fun in the least.

Despite this, I’ve found time to do a bunch of trinity work this last week. Biggest highlight being todays work gutting the generation of file descriptors on startup, moving it away from a nasty tangled mess of goto’s and special cases to something more manageable, involving dynamic registration. The code is a lot more readable now, and hopefully as a result more maintainable.

This work will continue over the next few days, extending to the filename cache code. For a while, I’ve felt that maintaining one single filename cache of /dev, /sys & /proc wasn’t so great, so I’ll be moving that to also be a list of caches.

Eventually, the network socket code also needs the same kind of attention, moving it away from a single array of sockets, to per-protocol buckets. But that’s pretty low down my list right now.

Asides from the work mentioned above, lots of commits changing code around to use syscallrecord structs to make things clearer, and making sure functions get passed the parameters they need rather than have them recomputing them.

Daily log May 13th 2014

After yesterdays Trinity release, not too much fallout. Michael Ellerman reported a situation that causes the watchdog to hang indefinitely after the main process has exited. Hopefully this won’t affect too many people. It should now be fixed in the git tree anyway. Doesn’t seem worth doing another point release over right now.

Thomas Gleixner finally got to the bottom of the futex bugs that Trinity has been hitting for a while.

The only other kernel bugs I’m still seeing over and over are the filemap.c:202 BUG_ON, and a perf bug that has been around for a while.

Sasha seems to be hitting a ton of VM related issues on linux-next. Hopefully some of that stuff gets straightened out before the next merge window.