4 ms·

I know you probably can't share details, but would be curious to hear a little more color around these two situations.

marcan_42 5y ago
Honestly, it's not that sensitive (at least without service details; plus this was over 7 years ago). I think the lawyers won't send me a nastygram for this much detail: The kernel panic one started when I got pinged by a downstream team that we somehow delivered garbage data (valid-looking but entirely the wrong schema) to them, and that broke everything. Tracing things back up the chain, I found out that the source machine had had a kernel panic. Turns out that ended up with file metadata flushed to disk, but not file data. The unwritten sectors happened to contain data from a different process that was in the right file format, but had the wrong payloads, and since the file format was garbage-tolerant and self-synchronizing, the processing from that point on cleaned it up into data that looked completely valid... but was just from entirely the wrong place. All that happened automatically upon reboot from the panic. I was able to quite conclusively prove that this is what had happened by observing the data offsets logged to debug logs, and noting that the funkiness happened on filesystem block boundaries, and also aligned time-wise with the kernel panic, and a process that matched the schema of the data that ended up delivered had been running simultaneously on the same machine. This was all from just one instance of the fault, forensically debugged; we never reproduced it. The conclusion was basically "working as intended"... that is, this is apparently a thing that can happen given the filesystem mount mode in use (which was chosen for performance), so I think in the end they introduced some sanity checks on the data shape as a stop-gap. I think this was all soon deprecated and replaced with a system that didn't use local disk at all anyway, so there wasn't much point in introducing a big refactor to eliminate this rare failure mode at that point, but it's interesting that it did have security implications (it was just rare and not directly triggerable). It was very satisfying being able to trace down exactly what had happened (and the team lead sent this one off to me specifically due to my reputation for working this kind of stuff out... :) ). The other one had to do with Google's NIHed gzip implementation, because of course they have one. We had found data mismatches between output computed over identical input in two different data centers (for redundancy/cross-checking), but it always went away if we tried again. This happened once a petabyte or so, give or take (I'll let you guess how often that was in terms of days, at Google scale). Digging through the error logs, I found that the mismatch was an offset mismatch, not a data mismatch. These files had gzip-compressed data blocks. Investigating the data was tricky because we weren't allowed to copy parts of it to workstations due to privacy reasons, but doing some contortions to work in the cloud I found out that the logical data was equivalent, but the compressed data was one or two bytes larger in one of the files, hence shifting the offset of the next block. Eventually I managed to grab one of the problem-causing uncompressed data blocks, build a test case for the gzip compressor with exactly the same flags used in production, and I had the idea of running it under valgrind... and that's when it screamed. Turns out the gzip compressor used a ring buffer of history to perform searches for compression, and for performance reasons the lookups weren't always wrapped, but rather there was a chunk of the ring buffer duplicated at the end. This was calculated to never exceed how much the pointer could fall off the end of the buffer. But, on top of that, the reads used unaligned 32-bit reads, again for performance reasons. And so you could end up with the pointer less than 4 bytes from the end of the buffer padding area, reading 1 to 3 bytes of random RAM after that. The way the compressor worked, if the data was bad it wouldn't break the compression, but it could compress a bit less. And so, the chances of both the read falling off the end of the buffer and happening to be one that would've improved compression were tiny, and that's how we ended up with the rarity. We never saw crashes due to the OOB read, but I think I heard some other team had been having actual segfaults (I guess the page after the buffer was unmapped for them) and this fix resolved them. I think we had the problem going on sporadically for a few months before I got sick of it (and I'd managed to rule out the obvious "it's a RAM bit flip / bad CPU / something" things you tend blame rare random failures on at that kind of scale) and spent a couple evenings figuring it out.
- tegansnyder 5y ago
  This was an absolute joy to read. Isn't it fun how many years later we remember stuff like this? The thrill of hunting down a complex issue, peeling away layer after layer to find the solution. Thanks for sharing.

Honestly, it's not that sensitive (at least without service details; plus this was over 7 years ago). I think the lawyers won't send me a nastygram for this much detail: The kernel panic one started when I got pinged by a downstream team that we somehow delivered garbage data (valid-looking but entirely the wrong schema) to them, and that broke everything. Tracing things back up the chain, I found out that the source machine had had a kernel panic. Turns out that ended up with file metadata flushed to disk, but not file data. The unwritten sectors happened to contain data from a different process that was in the right file format, but had the wrong payloads, and since the file format was garbage-tolerant and self-synchronizing, the processing from that point on cleaned it up into data that looked completely valid... but was just from entirely the wrong place. All that happened automatically upon reboot from the panic. I was able to quite conclusively prove that this is what had happened by observing the data offsets logged to debug logs, and noting that the funkiness happened on filesystem block boundaries, and also aligned time-wise with the kernel panic, and a process that matched the schema of the data that ended up delivered had been running simultaneously on the same machine. This was all from just one instance of the fault, forensically debugged; we never reproduced it. The conclusion was basically "working as intended"... that is, this is apparently a thing that can happen given the filesystem mount mode in use (which was chosen for performance), so I think in the end they introduced some sanity checks on the data shape as a stop-gap. I think this was all soon deprecated and replaced with a system that didn't use local disk at all anyway, so there wasn't much point in introducing a big refactor to eliminate this rare failure mode at that point, but it's interesting that it did have security implications (it was just rare and not directly triggerable). It was very satisfying being able to trace down exactly what had happened (and the team lead sent this one off to me specifically due to my reputation for working this kind of stuff out... :) ). The other one had to do with Google's NIHed gzip implementation, because of course they have one. We had found data mismatches between output computed over identical input in two different data centers (for redundancy/cross-checking), but it always went away if we tried again. This happened once a petabyte or so, give or take (I'll let you guess how often that was in terms of days, at Google scale). Digging through the error logs, I found that the mismatch was an offset mismatch, not a data mismatch. These files had gzip-compressed data blocks. Investigating the data was tricky because we weren't allowed to copy parts of it to workstations due to privacy reasons, but doing some contortions to work in the cloud I found out that the logical data was equivalent, but the compressed data was one or two bytes larger in one of the files, hence shifting the offset of the next block. Eventually I managed to grab one of the problem-causing uncompressed data blocks, build a test case for the gzip compressor with exactly the same flags used in production, and I had the idea of running it under valgrind... and that's when it screamed. Turns out the gzip compressor used a ring buffer of history to perform searches for compression, and for performance reasons the lookups weren't always wrapped, but rather there was a chunk of the ring buffer duplicated at the end. This was calculated to never exceed how much the pointer could fall off the end of the buffer. But, on top of that, the reads used unaligned 32-bit reads, again for performance reasons. And so you could end up with the pointer less than 4 bytes from the end of the buffer padding area, reading 1 to 3 bytes of random RAM after that. The way the compressor worked, if the data was bad it wouldn't break the compression, but it could compress a bit less. And so, the chances of both the read falling off the end of the buffer and happening to be one that would've improved compression were tiny, and that's how we ended up with the rarity. We never saw crashes due to the OOB read, but I think I heard some other team had been having actual segfaults (I guess the page after the buffer was unmapped for them) and this fix resolved them. I think we had the problem going on sporadically for a few months before I got sick of it (and I'd managed to rule out the obvious "it's a RAM bit flip / bad CPU / something" things you tend blame rare random failures on at that kind of scale) and spent a couple evenings figuring it out.

tegansnyder 5y ago
This was an absolute joy to read. Isn't it fun how many years later we remember stuff like this? The thrill of hunting down a complex issue, peeling away layer after layer to find the solution. Thanks for sharing.