TMI: printf-style debugging, the only kind there is

[tim]

The subject line is a little misleading, since I actually had an intense gdb session today (at least compared to the usual way in which I use gdb, which is to get a backtrace and then quit).

I got into working on one of those bugs today that's like gambling or playing a video game (two activities I try to avoid as much as possible, since I get paid to debug and don't get paid to gamble or play games :-D). There's always one more strategy you can try and maybe *this* time you'll find the bug... and since sometimes you do find it, the intermittent reinforcement keeps you going until 4 in the morning.

In this case, I was meeting a friend for drinks at 8:30, so that didn't happen... but I haven't found the bug yet and it's taking effort to not just stay up late looking for it some more. I had changed over the comm module to use classes instead of resources, and found a couple bugs that way, as previously described. When I left off to do bug triage, I had just found a dreaded memory leak, and wasn't looking forward to trying to debug that. When I got back into it today, I was able to insert enough print statements (always feels like hitting things with a hammer) to understand that the problem wasn't that rustc itself was leaking memory when trying to compile the comm code -- it was that the compiler itself uses comm and so the stage1 compiler, with my modified library code compiled into it, was leaking memory because of the library code modifications. Also, I figured out that the data structures that were leaking were of type rust_port and circular_buffer -- the former has the latter as a field, so really, it was just rust_port.

With enough print statements, I figured out that there were seven calls to the port_ptr constructor (port_ptr is the class in Rust -- formerly a resource -- that wraps the primitive rust_port type) and seven calls to the port_ptr destructor. Good so far. But there were two additional rust_ports being allocated, and those two weren't being freed; hence the leak. This is strange, since the only way to allocate a rust_port in all the compiler and library code is to call the port function defined in the comm module. And that's really about as far as I got, but from messing around with nm and gdb on the executables and libraries, I developed the hypothesis that the compiler contains inconsistent inlined instances of the port function. Dynamically, there are two calls to port directly from the compiler, and since port is parameterized, port would be monomorphized and thus compiled directly into the compiler. That would introduce an opportunity to have an inlined copy from an out-of-date version of the core library. Then there are seven calls to port from another library function in the task module, meaning that the code for these calls lives in a separate, dynamically linked library (libcore). The seven calls free the created port correctly -- it's just the two calls that are through monomorphized copies of port inside rustc itself that don't free the port properly. I'm wondering whether the code that's responsible for freeing the port is expecting the port to have been created with the new version of port, while it was actually created with the old version of port. I would think this would cause a different error before the memory leak became apparent, but you just never know. Anyway, I haven't confirmed this for sure, but I was trying to put in print statements to find out when I left off. But I'll have to let the suspense build up and leave the answer for another day.

In the meantime, since I do have two laptops, I tried using them both at once today, and working on one laptop while a build ran on the other laptop... I think I was a little more productive than usual that way. I worked on issue 2550, a fix that was easy enough in and of itself, but making it testable turned out to be harder. The original problem was that the test case passes, but triggers a warning; it shouldn't have triggered any warnings. I got it to not trigger the warning, but adding it to the regression test suite was kind of pointless since for run-pass tests, the compiler ignores all warnings. In a test case, you can write something like:

let x: ptr = unsafe::reinterpret_cast(5); //! WARNING This code is bad and you should feel bad

which tells the test runner to expect the warning message "This code is bad and you should feel bad" with a span corresponding to the line let x.... But that only works in compile-fail tests. Furthermore, there's no //! NOWARNING comment to require the absence of a warning. The workaround is to use an attribute that turns warnings into errors -- so that if the warning ever triggers again, the run-pass test will fail and the test runner will report a test failure -- and the attribute should look like:

#[warn(err_non_implicitly_copyable_typarams)]
class C {
...

except the attribute appears to be getting ignored -- somehow, it gets parsed, but then the lint settings get reset to the default. I'll have to go back to that too.

I feel like I spent a lot of time working today without much corresponding satisfaction... but some days are like that.

Comments

[synecdochic]

I have not said yet, which is terribly remiss of me since I subscribed to you like two weeks ago, but allow me to say that I really, really love reading these posts of yours. Not only is it awesome to see other people's workflow, you have a real gift for explaining technical things with just the right amount of detail. (Watch me womanfully restrain from trying to recruit you for DW development or process documentation! heh.) Thank you for writing up your work habits and your thought processes like this; it's been super helpful and interesting.

[tim]

Wow, thank you! I was worried about the amount of detail, and I realize one can never please everyone, but it's still good to know that someone not involved with my project found it to be a useful level of detail.

I've actually wanted to volunteer for DW for the past couple of years, but poor time management skills (and other issues) have always made sure that I never have time for anything coding or coding-like other than paid work... Maybe that will change sometime, but in any case, recruiting me might not take much effort :-)

[synecdochic]

Honestly, some of the detail does go over my head, but that's becasue I'm entirely self-taught (and my skill/understanding is very DW-specific), but that's not at all a reflection on the content, just my understanding! And even the bits that leave me scratching my head don't bore me, because you write engagingly about even the things I don't understand. ;)

Seriously, though, as someone entirely self-taught I slurp up posts like this like a sponge. I love seeing how people's minds work and how they approach problem solving, etc. They are super, super helpful to me.

(As for DW, we are happy to take teeny tiny patches (the smallest patch ever written by a volunteer changed one character *g*) all the way up to the super involved stuff, and we also are thrilled when experienced people hang out in our irc channels and help or encourage the new folk, who are often very uncertain and need a ton of "no! you're doing just fine! really!" at first. Some of our most useful mentoring comes from people who don't write code with us but just hang out in irc, socialize, and answer the "halp what does this mean" from people just starting out. Plus I'd like to think we're pretty fun to hang out with. *g* #dreamwidth on freenode, and we are supremely lurker-friendly. I think some of the people regularly in-channel haven't ever spoken. *g*)

[tim]

1. That's great to know! 2. That's also great to know... and heh, I like the one-character patch.

[synecdochic]

Actually, I checked my records and we have, in fact, had several one-character patches ... and they are cheered and fussed over just as much as the big stuff.

(One of our more experienced devs once observed that he liked coding for us much more than coding for his dayjob, as the dayjob does not come with a cheering section, much less a genuinely enthusiastic one. Since our bug-bot-announcing-all-new-attachments plugin broke we no longer get immediate cheering in irc when a patch goes up, but there is still sufficient YAY going on. *g*)

[tim]

Ha! I have *so* had dayjobs like that. My current dayjob comes with a small but loyal cheering section, and it's really nice. Working on an open-source project for a living is spoiling me -- I'm not sure I'll ever be able to go back to closed-source (and yet jobs like mine are so few and far between that that's a bit worrisome... hopefully not an immediate worry for a long while, though ;-)

[anemone.livejournal.com]

I always find it unsatisfying when building and debugging the test case takes longer than the code change.

[tim]

Yeah, when I'm working on the compiler, extracting out a test case frequently takes longer than just finding the bug... but sometimes it does end up being worth the time to minimize the test case, so it's stressful.