4 ms·
I also like it when systems go bang spectacularly on a failure, vs silently allowing it. But, related to the Posix thing about reusing fd's, I just ran into th
by prirun 5y ago
I also like it when systems go bang spectacularly on a failure, vs silently allowing it.
But, related to the Posix thing about reusing fd's, I just ran into this a couple of days ago and it took me 6 hours to figure out.
I made a change in HashBackup to interrupt saving a big file if the backup time limit had been reached. Tested it a while, seemed like it worked fine. I was using a 15-second timeout. For whatever reason I tried it with a 5s timeout. This went bang, but in a completely different area of the program responsible for copying backup files to a destination, where it raised an exception "hey, this file was X bytes but I only copied Y". Go look at the source file, it's fine. Look at the destination file, and indeed, it is only Y bytes. Go look at the copy code, it looks fine but obviously isn't, so I start putting all kinds of debug stuff there to check file sizes, do double reads at EOF, ... nothing helps. Then I add an lseek to report the current file position and indeed it is at X, even though only Y bytes have been copied. So I realize that something else has moved this file pointer on me.
To help track that down, I override Python's os.open and os.close and display the pathname and fd so I have a history of who is using what fd's. After going through that with a microscope, I see that the file being backed up is open on fd 6, and when the timeout occurs, it gets closed. Then that fd gets used by the copy function for the source file.
BUT, there is an asynchronous read process used during the backup. It has exception handling if an fd is closed by higher levels and the read thread gets an EBADF error, then resets itself. But there is a race condition: if the fd gets reopened fast enough, the read thread will never see the EBADF error and thinks it is still reading from the file to backup, which it continues to do. Now there are 2 processes reading from the same file and mayhem ensues.
Of course it's ultimately my fault, but we do have at least 32 bits for a file descriptor number. It would be a lot nicer if Posix kept incrementing it instead of using the low numbers and then wrapped around, like Unix PIDs do. And yeah, I realize this would screw up select, dup, etc because of the way they are designed.
- bhawks 5y ago> To help track that down, I override Python's os.open and os.close and display the pathname and fd so I have a history of who is using what fd's. Nice! I'd recommend trying strace to track system calls in the future though. Monkey patching open and close will only catch code using those functions and not any c libraries or very smart people using ctypes. Strace captures every syscall and dumps the parameters and returns.
- mst 5y agoI've used both depending on the situation - I am a huge fan of strace (especially 'strace -f') and have done some truly stupid shit with it. Best example being dealing with a situation where a client's code could only have one connection to a particular external streaming API they were using and the developer in charge of connecting to it was a tad territorial and wouldn't provide me a way to access the data that actually worked for the task I'd been assigned. Solution: strace his process with a -s argument that was larger than any read his process ever did, then backprocess it into the original bytes on the wire, then handle them myself. Yes, this was a horrible hack, but it allowed me to prove the concept of the thing the client wanted building without causing massive political drama that would've been more trouble for everybody involved than it was worth. Ideal for that sort of situation would (for me) likely be trapping the open and close functions and having them emit information to stderr while -also- having strace log to the same stderr so I could see how the two compare - with the caveat that whether it's viable to do that is highly variable depending on context. But as a last comment on strace, I present an old entry from my quotefile: <@mst> actually, I think my first thing to try would be to strace the code <@mst> and try and match up the new value of $! with a failed syscall <@mst> but I mean if strace was a person I'd totally be asking them out to dinner so maybe I'm biased
- Too 5y agoNewer python versions come with what they call audit hooks, which can log events on for example file open. The open function already has such audit built in. https://peps.python.org/pep-0578/ https://peps.python.org/pep-0578/ It can be seen as somewhere in between home made monkey patching and strace. Strace is great, because it shows absolutely everything. But showing everything can also be too much, a pre filtered view is often what you really want. If you want a similar tracing mechanism that spans your whole system I think you could do it with eBPF.
- mst 5y agoI've seen a similarish problem - if I say "the initial bug report was 'why is my application logging to its pid file?'" I imagine you can work out the rest.