I had a hard time Googling a solution to this particular woe. Alas the exact string “unresolved overloaded function type” doesn’t give anything useful with “boost::bind” and “boost:mem_fn“. This is the typical sort error message from g++:

foo.cpp:18: error: no matching function for call to
    'bind(<unresolved overloaded function type>,
        const boost::reference_wrapper<FooMaster>, boost::arg<1> (&)())'

I’ve generated this using a rather contrived example based on the use pattern that was causing my woe:

#include <iostream>
#include <boost/bind.hpp>

class FooMaster {
public:
    void foo(std::string &s) {
        std::cout << "foo(s=" << s << ")" << std::endl;
    }

    void foo(int x) {
        std::cout << "foo(x=" << x << ")" << std::endl;
    }
};  
    
int main(int argc, char **argv) {
    FooMaster fm;
    boost::bind(&FooMaster::foo, boost::ref(fm), _1)(10);
    return 0;
}

The problem is obvious of course, it is exactly as the compiler is telling you. Mr compiler has no idea which “foo” you’re talking about. “But Mr Compiler, it is obvious!” You say. “I’m not passing it a bloody string!” Sometimes you just have to understand that Mr Compiler isn’t you and needs a little hand-holding.

The issue clearly boils down to FooMaster having two methods that match &FooMaster::foo. This signature, used to instantiate the bind template, doesn’t take into account the arguments, so which foo are we taling about?! Alas, as obvious as the problem was I didn’t find the solution so obvious. I just don’t cut it as a C++ guy sometimes. I’d given up on the problem in fact, but then I stumbled on a solution while looking into some other problem I had. It was one of those “oh, duh!” moments really, I was looking at some code that assigned a member function pointer. The type specification for such a thing includes the argument types! So here’s a modified main that uses one extra step in order to explain what we want to the compiler:

int main(int argc, char **argv) {
    FooMaster fm;
    // Create a variable of the desired function signature type and assign
    // using desired member function.  This will resolve the correct
    // function thanks to the signature including the argument types.
    void (FooMaster::*fn)(int) = &FooMaster::foo;
    // Now pass the function variable to the template method so that it knows
    // exactly which function we mean.
    boost::bind(fn, boost::ref(fm), _1)(10);
    return 0;
}

All you have to do is give Mr Compiler a little bit of a helping hand…

Joy!

While I did get around to my one-extention-at-a-time testing of Firefox slowness I still haven’t got around to writing more about it. My, rough, observations are the following:

1. The longer Firefox is running the slower everything gets. As much as I’d love to turn my computer off every night and start afresh every morning the fact is that the best I can do really is put it into suspend, without wasting time every morning (I work at home and maintain a lot of state on my computer.) Another solution would be to stop-start firefox every now and then since it’ll reload my last set of open tabs/windows on starting, I really shouldn’t have to do that though, and it leads to point 2…
2. More tabs seems to mean more slowness. I tend to be tab-happy, like my 20-desktop(+tabs) spaces of state I find keeping stuff open in the browser to be simpler than worrying about “saving tabsets” and bookmarking everything (and trying to work out one end of the “history” from the other is just not going to work.) To this end I tend to have 2 or three browser windows open at a time with up to three rows of tabs in each. The slowness isn’t Firefox hitting swap so must be something else (Firefox memory use seems to grow linearly with number of tabs open, fair enough I guess since memory is cheap these days.) Maybe a plugin or extension, I haven’t tried the incremental-plugin/extension-addition + tab-growth experiment.
3. The “SwitchProxy Tool” extension does seem to cause slowness. I’m confounded as to why it should be so!
4. The “Google Browser Sync” extension also causes slowness. Again, I have no idea why, but it does a pretty complicated job.

That’s all I have to report. And AFAIC “problem solved!” “How so?!” You ask? Simple: I’ve mostly stopped using Firefox. Over the last few weeks I’ve been making a gradual switch to Opera. Oh no! It’s closed-source evilware! shrug It is:

1. Faster (oh, so much faster!), more responsive when I have 50 tabs open in three windows.
2. No longer encumbered with that annoying ad panel.
3. Now equipped (in the current beta) with native browser-sync functionality. This is nice since Google Browser Sync has become, for me, the most important Firefox feature. That said, I don’t know how “trusted” the Opera browser sync is and it certainly doesn’t seem to be as comprehensive as the Google offering. I expect Opera sync will be expanded in time.
4. No more of a memory hog than Firefox (as far as I can see, but I haven’t tested this exhaustively.)
5. Binary packaged for every distro I use and there’s an apt repository (though without Ubuntu dists, my sources.list line on Ubuntu gutsy is for Debian testing.)

On the downsides:

1. Has occasional problems with Flash, which require a browser restart but luckily Opera comes back up with all my windows and tabs rather quickly. Yes, in an ideal world there’d be no flash, wank, wank. Flash is a “fact of life” as far as the web goes these days, and IMO it gives us some useful things that would XHTML/CSS can’t. This particular problem is my most pressing issue with Opera at the moment.
2. No less of a memory hog than Firefox. This is based on occasional glances at top while running both, not any proper testing!
3. Much less of a CPU hog than Firefox but still pretty bad at idle sometimes. However this is mostly the fault of websites to some degree, it just seems that Opera keeps a tighter hold on not letting a site’s javascript get out of hand. For example, having smh.com.au open in Firefox really bogs it down, while Opera remains responsive (albeit at a constant ~10% CPU usage on my desktop.) It should be noted that the smh.com.au site runs some particularly disgusting javascript.
4. Hitting sites that “don’t work in Opera” is more common than “don’t work in Firefox”, but the Web’s become pretty good in this regard these days so this is fairly rare.

It should be noted that I’m using a beta version of Opera (on Ubuntu Gutsy.)

There are things I haven’t tried or worked out with Opera yet. Namely:

1. What’s on offer as far as equivalents to the Firebug and Web Developer Firefox extensions. I haven’t had to do any HTML/CSS debugging for a while.
2. AdBlock Plus equivalent? I think there might be one out there, but I have to admit I’m not hunting since I’ve kind of fallen out of love with auto-updated ad blocking, it was blocking things I wanted to see sometimes. Opera does have a “content block” feature and I use it to block out particularly bad ads and ad-iframes (anything I see that is large, or overtly bright, or animated.)

I haven’t spent much time looking into equivalent Opera functionality as I have everything I need for day-to-day browsing “out of the box.” However, I just found “Opera equivalents to Firefox extensions” and “Opera equivalents to Firefox extensions II” which look like a pretty good starting point!

In conclusion: I’m converted to Opera. It has it’s downsides, but so does Firefox and my feeling at the moment is that Firefox is more annoying than Opera.

It was that time again, time to go out to a great restaurant as a “make up” dinner because I’d had to bugger off somewhere and leave Kat alone a for a week. Such creatures become unhappy when left to fend for themselves for too long. Exactly where to eat is always the problem, there are so many interesting restaurants in London. I juggled around a few names I remembered and tried to find somewhere that definitely had Squirrel on the menu at the moment, but no luck there. So, something different at least? We normally do very Italian style food so how about French? A couple of names came to mind and on the back of seeing a lot of good reviews it was Coq d’Argent we chose.

Coq d’Argent can be found on the roof of N° 1 Poultry, convenient for “City” folk (like Kat, who works only a 2 minute wander down the road.) Poultry/Coq is just the first witty pun. “Argent”, it seems, can be taken in two meanings: one being “money” (we’re in the banking district after all), and the other, from heraldry, “silver” (pretty much the same link to the City there I guess). So, the “Silver Rooster” on N° 1 Poultry in the financial district. Ho ho. Anyway, enough randomness, we’re in this for the food.

Entrée

Coq is a very French restaurant, complete with all the stereotypical French dishes. This left me with a bit of a conundrum when it can to the entrée, only two?! So we picked three. Kat had the cuisses de grenouille, which is frog’s legs to you and me. While I ordered the terrine de foie gras au jambon fumé, which doesn’t need translation I think! Then to share we had another dish that really speaks for its self: douzaine d’escargots.

Frogs legs, foie gras, and snails— could we try any harder?

Timbale de cuisses de grenouille au vermouth, Avruga caviar et crème d’épinards.
(Frog legs and vermouth timbale with spinach cream and Avruga caviar.)
The timbale came with an escort of three little legs, nuggets of meat in a very light crispy batter complete with little bones sticking out. The legs were succulent and, I guess, a little like dark-meat on chicken. The timbale was delicately flavoured, so as to not overwhelm the leg meat it contained. The spinach cream (or: creamed spinach) and caviar topped off the whole dish well. Avruga caviar is actually a fancy name for a caviar made with herring roe, and my assessment of it was that it was rather good! (However have a look at that link to learn about the true nature of this “caviar”.)

Terrine de foie gras au jambon fumé, poire aigre-doux, purée de pruneaux.
(Foie gras and smoked ham terrine, pickled pears, prune compote and sherry vinegar caramel.)
Ah, foie gras, I don’t know how much the goose suffered but it was all worth it. A good rich terrine this and a reasonably sized slice (for this day and age.) The “pickled pears” barely rated a mention, coming in about 10 pieces about 3mm to a side. Personally, I’d have preferred a few neat slices. That said, they’re really just there to lead some sharpness to cut the thick richosity of the terrine and the prune compote came in a good dollop alongside a drizzle of the “vinegar caramel” (think darkened sugar syrup) that lent it’s own edge. I enjoyed every mouthful, even the ones Kat ate.

Douzaine d’escargots de Bourgogne au beurre d’ail et tomates.
(Twelve snails baked in garlic and tomato butter.)
Straight out of the French language textbook! (I studied French for three years in school, but somehow didn’t learn a thing.) There’s always the snail horror stories you hear: “chewy little lumps of garlic flavoured rubber.” I’m glad to say we didn’t have such an experience, the dark little bodies of our snails, tucked delicately into their shells, were succulent and melt-in-the mouth tender. I’m not sure what to compare them to actually. And you can’t go wrong with garlicy butter, especially when there’s bread nearby.

Main Course

That wraps up the first course, and what a beginning! I’d had some difficulty choosing my main course and ordering three really wasn’t going to be an option. Wanting something with a bit of meat to it I went for the filet de sanglier, wild boar. Kat eyed the fish for a while before actually choosing agneau rôti à la provençale which was actually agneau de pré-salé, or salt-marsh lamb. This, despite the “salt” and related seaside environment, really isn’t quite fish. Right after the entrée I popped along to the bathroom and found the mains already on the table when I returned! A tad too speedy for my tastes I have to say, it must have been less than ten minutes between clearing firsts and laying out the seconds. Agneau rôti à la provençale, jus au romarin.
(Salt marsh lamb with mini ratatouille, soft mash, pesto, anchovy fritter, black olives and rosemary jus.)
Kat’s main was a sizable serving, with three decent pieces of lamb (including a cutlet). The presentation was an amusing construction whereby an encircling wall of mash, dotted with olives and pesto, had been built around the core constituents of the dish and filled with a shallow pool of jus. That was the pinnacle of presentation for the evening, though every dish came with a strong dose of the art. (Something I have only a marginal respect for.) I found the anchovy fritter an unusual and maybe too cheffy device, essentially packaging for a condiment. However, this was a good solid dish and the lamb pink and juicy. This “salt marsh” lamb is talked up a lot but from the little I tasted and from Kat’s words I don’t think we recognised anything really special about this lamb. Don’t get me wrong though, it was very good lamb, I’m just not sure if it was amazingly, wonderfully good. I will have to endeavour to get myself a leg or shoulder of it for a more complete assessment.

Filet de sanglier sauce grand veneur, purée de marron et panais rôti.
(Wild boar fillet wrapped in pancetta with chestnut purée, roasted parsnip and grand veneur sauce.)
Three small medallions of fillet made this a much less substantial meal that Kat’s, but sufficient. Being served with one tiny, lonely baked onion (it’s not listed, so it’s a bonus I guess), and a couple of skinny sticks of parsnip certainly doesn’t bulk it out enough for those who measure enjoyment by volume! A good thing I fit less in and have a smaller appetite these days then! The chestnut purée was an excellent wetting agent for the plate, not something I’ve had before but something I’ve got to add to my repertoire. Now the sauce is a bit of an enigma, I tasted it and immediately recognised chocolate and Kat agrees. If I’d thought to review the menu and seen “grand veneur” I’d have asked about it, but Kat said she saw mention of chocolate on the menu and I left it at that. The problem is that the online menu (which I used as reference for the names in this entry) says it is a grand veneur sauce. This is, essentially, a rather complicated stock reduction (a poivrade) thickened with blood and finished with redcurrant jelly and cream. There was certainly no hint of anything cream-like in the sauce with my meal! I suspect the answer to this puzzle is that the menu of the night was slightly different to what they have online, which is a fairly common occurrence (restaurant menus tend to be “live” documents.)

OK, I’ve written far too much about this dish now and not even approached the point yet… how was it? Good, the possibly-chocolate sauce and chestnut purée were a highlight and I’ve got to keep them in mind when I tackle game meats in future. But not brilliant, the “wild boar” lacked the sort of strong flavour I hoped for and what flavour it had was hard to find behind the flavour absorbed from the pancetta. Aside from my persnicketiness in regard to flavours the dish added up to something enjoyable, the boar tender and the sauces unusual and flavourful (maybe a little sweet, there I go again.)

Along with our mains we had a small rocket and parmesan salad, dressed with a good balsamico and, refershingly, lemon juice. The acidity in the salad worked well complimenting the flavours in my main.

Dessert

There was certainly room for dessert! Given the non-overzealous serving sizes, the small amount of bread (a good thing), and our choice to order only a very small salad as an extra. Kat went straight for the Catalan crème brûlée, which was an excellent and very rich rendition of this all time favourite. I debated whether or not to have one with poached rhubarb or something much richer and chocolaty. I don’t normally go for chocolate desserts so decided to give it a go for a change and had the “Warm bitter chocolate and marmalade sabayon tart with orange ice sorbet.” It beat Kat’s dessert on richness, twice over at least! The tart filling was akin to a warm version of my richest chocolate mousse and the crust thin and crumbly, this balanced very well with the frigid tang of the sorbet. If anything the tart could have been just a little smaller.

The Rest

I didn’t have any wine with this meal, sticking to just water. I was glad to note that their still water was UK sourced and not imported from some ridiculous location. It was also supposedly “carbon neutral”, however they work that out. I almost always stick to tap water these days, water from Fiji? People are idiots. Anyway, the water was good and a little less uncomfortable.

Kat had a glass of Chianti, it was very good, you’d hope so at £11.50 for 125ml.

We dared espresso, and that was nothing special. I don’t really like espresso in France (based only on experience in Provence and Corsica) but it is very consistent and the coffee in Coq was authentic in that sense. Certainly better than the “English standard”, but then so is cow manure. (One day I might get off my old espresso high-horse, or maybe I’ll just move to Italy and shut up.)

The End

The service was great, not in-your-face as is all too common in the fancier restaurants. Pretty much a case of being there only when you want it but also always when you want it. In a rare act I actually rounded up the bill a bit on top of the auto-service-charge of 12.5%.

In the end the bill was £132.75, including the 12.5% “discretionary service charge”. That includes all the dishes mentioned above with £11.50 for a glass of wine, £3.75 for 750ml of water, and £5.00 for two espressos. Now that I scan over the bill I have to end the evening on a bit of a bum note, they charged me for a very random thing I never had! £6.75 for a “Chivas Regal”, at that price it can’t have been a very good one anyway so I’m glad I didn’t have it. How the bloody hell that ended up on there I don’t know, oh well maybe I’ll learn the lesson to check bills more carefully in future. Bit of a bummer, but £6.75 isn’t worth too much upset and I have to accept part fault for not checking the bill as I should. (And I extra-tipped these incompetents! That’s totally unfair, from experience I know how easily these mistakes can creep in and don’t go in for the conspiracy theories.)

Overall, in our experience of “known” London restaurants, we’re rating this as our second-best meal to-date. (FYI, third is “The Providores”, which I never wrote about, and first is the “Neal Street Restaurant,” now sadly no more.) We’re likely to try Coq again in the summer, since there’s a huge and well presented outdoor space on top of the building (the space inside the circle and the wings on both sized of the orange roof in this zoomed-in version of the map link above.) It looks like a beautiful spot for a classy summer lunch or dinner.

Oh, we booked through the “D&D London” website again, worked out fine.

Quite some time ago a friend of mine at work supplied us with a magical vim binding that generated safe header guards. (And copyright/licence/doxygen preamble too!) The idea is that it automatically inserts the matching (#ifndef, #define, #endif) triplet and uses a guard that incorporates the file name and a suitably long random number. (The random number is what makes it “safe”, for example what if you have a “UTIL_H” but another library you’re using also has a “UTIL_H“?)

Today I went to use the trusty old insert-guard key-binding and I see: “shell returned 127“. The problem was a simple one, the vim binding called on a script written by yet another colleague. I had copied my usual .vimrc over but not the required script so the guard failed. Since I’m easily distracted I decided to work out a way to generate the guards that wouldn’t do this to me again, rather than just scp the script onto the system! I ended up with this:

" function to insert a C/C++ header file guard
function! s:InsertGuard()
  let randlen = 7
  let randnum = system("xxd -c " . randlen * 2 . " -l " . randlen . " -p /dev/urandom")
  let randnum = strpart(randnum, 0, randlen * 2)
  let fname = expand("%")
  let lastslash = strridx(fname, "/")
  if lastslash >= 0
    let fname = strpart(fname, lastslash+1)
  endif
  let fname = substitute(fname, "[^a-zA-Z0-9]", "_", "g")
  let randid = toupper(fname . "_" . randnum)
  exec 'norm O#ifndef ' . randid
  exec 'norm o#define ' . randid
  let origin = getpos('.')
  exec '$norm o#endif /* ' . randid . ' */'
  norm o
  -norm O
  call setpos('.', origin)
  norm w
endfunction

" keymap Ctrl-g to the InsertGuard function
map <silent> <C-g> :call <SID>InsertGuard()<CR>

It is still dependent on an external command, but if vim is installed then xxd is pretty likely to be around! (Since xxd is part of the vim toolset.) I wonder if it could be shorter? I didn’t find an obvious equivalent to “basename” in vim, I suspect there might be an alternative variable to ‘%‘ that gives what I want.

An example of what it generates when you’re editing “src/util.h” and hit Ctrl-h:

#ifndef UTIL_H_668A545328A5CC
#define UTIL_H_668A545328A5CC

<existing file content>

#endif /* UTIL_H_668A545328A5CC */

Introduction

Man it was hard to find information on debugging 2.6 kernel issues, maybe my Google skills need honing. Recently I was parachuted into a customer site on a support-or-die mission. The problem: kernel-space. My problem: not much kernel-space experience. A week of little sleep, much reading, and some learning. In the end the problem was rooted out and the crack team of kernel monkeys back at base blew it out of the water. Hooray!

This is the first in a trilogy of entries I intend to write. This one discusses a specific example of an “Oops” in detail, giving a line-by-line description of everything the oops tells you. Well, almost everything, some details go too deep to cover in something this introductory… to drill all the way down could take a whole textbook.

The second entry goes into relating the oops to the original code, I might call it “tracing assembly”. The third entry will delve into a session of debugging with ‘kdb’.

Now the first two entries will certainly happen as almost all the material was written during my work trip. (Joyful hours of trains, flights, and just plain waiting at stations and airports.) I won’t make any promises about the ‘kdb’ entry though, since I’ve written nothing for it and would need to spend quite a bit of time generating examples and traces.

Important items of note:

• An IA32/i386 architecture/kernel is assumed, the oops code is platform dependant.
• The oops examined here comes from a 2.6.16 kernel.
• Sometimes file paths are given, these are relative to the root of a Linux 2.6.16 source tree.
• This entry deals with a specific oops for a specific error case and doesn’t discuss much beyond the specific example.
• There’s no guarantee, as far as I know, that the oops format won’t change at some time.

Finally, a disclaimer: I am not a kernel developer. In fact I learnt a couple of new things just writing these two entries. No doubt there are important facts I’ve missed or not rated highly enough. Maybe it is even possible that I’ve got something plain wrong (if so please correct me via the comments or email).

Oops!

Let us start where these things usually start, a kernel oops:

kernel: Unable to handle kernel paging request at virtual address 68230a7d
kernel: printing eip:
kernel: c0143742
kernel: *pde = 00000000
kernel: Oops: 0000 [#1]
kernel: SMP 
kernel: Modules linked in: monkey_pkt_eater nfnetlink_queue xt_condition
    iptable_ips edd ide_cd ip_nat_ftp ip_conntrack_ftp ipt_REDIRECT xt_tcpudp
    ipt_addrtype ebtable_nat ebtables ip_nat_mms ip_nat_pptp ip_nat_irc
    iptable_nat ip_conntrack_mms ip_conntrack_pptp ip_conntrack_irc af_packet
    ipt_logmark ipt_CONFIRMED ipt_confirmed ipt_owner ipt_REJECT sr_mod cdrom
    usb_storage evdev microcode parport_pc ppdev parport xt_state xt_NOTRACK
    iptable_raw iptable_filter ip_conntrack_netlink ip_nat ipt_LOG ip_conntrack
    ip_tables x_tables nfnetlink_log nfnetlink monkey e1000 capability
    commoncap loop sg ahci libata sd_mod scsi_mod
kernel: CPU:    0
kernel: EIP:    0060:[<c0143742>]    Tainted: PF     VLI
kernel: EFLAGS: 00210202   (2.6.16.43-54.5-smp #1) 
kernel: EIP is at put_page+0x2/0x40
kernel: eax: 68230a7d   ebx: 00000001   ecx: f1057680   edx: 68230a7d
kernel: esi: f6fe7600   edi: fe089b98   ebp: f64d3c14   esp: f64d3bbc
kernel: ds: 007b   es: 007b   ss: 0068
kernel: Process snort_inline (pid: 6298, threadinfo=f64d2000 task=dff3fa70)
kernel: Stack: <0>c02a8b4a f6fe7600 f1057020 c02a88d8 000004cd f9de0fdd c7af5000 f7802b60 
kernel: 0000c7af fe73e860 f64d3c48 f64d3c48 e7e19834 f64d3c34 f5b54cc0 00000000 
kernel: 00000001 c02c7adf 00200282 d94bd4cc f64d3c48 f4429a40 f64d3c40 f9dd912a 
kernel: Call Trace:
kernel: [<c02a8b4a>] skb_release_data+0x8a/0xa0
kernel: [<c02a88d8>] kfree_skbmem+0x8/0x80
kernel: [<f9de0fdd>] mkyDestroyPacket+0x9d/0x260 [monkey_pkt_eater]
kernel: [<c02c7adf>] ip_local_deliver_finish+0xef/0x270
kernel: [<f9dd912a>] mkyIpqPostHandler+0xda/0x140 [monkey_pkt_eater]
kernel: [<c02c79f0>] ip_local_deliver_finish+0x0/0x270
kernel: [<f8e9e182>] find_dequeue_entry+0x82/0x90 [nfnetlink_queue]
kernel: [<f8e9e1ab>] issue_verdict+0x1b/0x50 [nfnetlink_queue]
kernel: [<f8e9f5af>] nfqnl_recv_verdict+0x1ff/0x330 [nfnetlink_queue]
kernel: [<c0308730>] schedule+0x350/0xdd0
kernel: [<f887940e>] nfnetlink_rcv_msg+0x16e/0x200 [nfnetlink]
kernel: [<f8879542>] nfnetlink_rcv+0xa2/0x169 [nfnetlink]
kernel: [<c02beecd>] netlink_unicast+0x16d/0x250
kernel: [<c02bf462>] netlink_data_ready+0x12/0x50
kernel: [<c02be2d1>] netlink_sendskb+0x21/0x40
kernel: [<c02bfacd>] netlink_sendmsg+0x27d/0x320
kernel: [<c0116c88>] __wake_up+0x38/0x50
kernel: [<c02a2b2e>] sock_sendmsg+0xae/0xe0
kernel: [<c012f4c0>] autoremove_wake_function+0x0/0x50
kernel: [<c012f4c0>] autoremove_wake_function+0x0/0x50
kernel: [<f90caa7f>] monkey_chan_queue_append+0x15f/0x170 [monkey]
kernel: [<c02a9e4a>] verify_iovec+0x2a/0x90
kernel: [<c02a306d>] sys_sendmsg+0x15d/0x270
kernel: [<c02a3f86>] sys_recvfrom+0x116/0x140
kernel: [<f90557c0>] e1000_clean_rx_irq+0x0/0x3d0 [e1000]
kernel: [<f9053b0e>] e1000_clean+0x53e/0x780 [e1000]
kernel: [<f90c7780>] mkyGetState+0x20/0x30 [monkey]
kernel: [<f9ddbc90>] packet_writer+0x2e0/0xd50 [monkey_pkt_eater]
kernel: [<c02a453f>] sys_socketcall+0x24f/0x280
kernel: [<c013a5b0>] __do_IRQ+0xc0/0x110
kernel: [<c0102d3f>] sysenter_past_esp+0x54/0x75
kernel: Code: c0 8b 01 01 c2 83 fa 10 89 11 7f 05 83 fa f0 7d 0d f0 01 15 fc 8f
    40 c0 c7 01 00 00 00 00 c3 8d 76 00 8d bc 27 00 00 00 00 89 c2 <8b> 00 f6
    c4 40 75 1e 8b 42 04 40 74 1f f0 83 42 04 ff 0f 98 c0 

(This oops has had some timestamp details removed and has been wrapped for neatness. Also, some “proprietary symbols” have been renamed, let us just say: beware the monkey.)

Tackling the oops

Let me first say: Thanks to the Internet containing cruft from all ages you’ll find many references to ksymoops when researching kernel oopses. Stop now! Maybe add a “-ksymoops” to your search query, though this may remove several good links. It really is a battle against accumulated information. The ksymoops tool was useful for dealing with Linux 2.4 oopses, but in 2.6 it’s work is done at oops-time and ksymoops is useless. If you’re dealing with 2.6 forget about ksymoops.

On with the oops. It tells us quite a lot about what was going on when the it occurred, we have the stack, the call path, the content of registers, and more. On inspection much of this is pretty straight forward to someone familiar with Linux, C programming, and Intel CPUs and assembly (be aware of GAS). It’s probably very hard going for someone who hasn’t done any work at that sort of level, but difficulty is just a good opportunity to learn! Right? However, like me, you don’t need to be a hard-core kernel hacker (I’m not even soft-core, I’d barely earn a PG rating) to get an idea of what’s going on.

Line by line

kernel: Unable to handle kernel paging request at virtual address 68230a7d

The core problem, and an oft-seen one, think of this as the “segfault” of the kernel. In actual fact both userspace nd kernelspace memory access violations come from the same place (MMU) and are handled by the same code. Generation of the oops text starting with this line has it’s origins in do_page_fault in the arch/i386/mm/fault.c code file. Think of that path as “i386 memory manager faults”. (“faults” covers a bunch of conditions, not just access violations.)

In short: something in the kernel has tried to use an address that doesn’t work, and that address was: 0x68230a7d.

kernel: printing eip:
kernel: c0143742
kernel: *pde = 00000000

Eip! It sounds like a small rodent’s cry of distress. It’s actually the “Extended Instruction Pointer”, which is the CPU register containing the address in memory of the instruction being executed. Thinking back to computer architecture classes you might be more familiar with this as the “Program Counter”. This tells us that at the time of the invalid paging request the instruction at address 0xc0143742 was being executed. A most useful bit of information that we’ll return to several times.

The “PDE” is the “Page Directory Entry”, and I’m not going to pursue that further. Try this article by Robert Collins, published in DDJ back in ’96, for more information: Understanding 4M Page Size Extensions on the Pentium Processor.

There’s a seriously large amount of information behind this that is worth reading up on. For starters try Google mixing “Linux Kernel” with a variety of things like “virtual memory”, “paging”, “mmu”, … From my bookshelf I’d recommend Chapter 2 of Understanding the Linux Kernel. That book is fairly bent towards Intel, I don’t have a book that covers deeper Intel specifics and can only recommend you make use of Google.

kernel: Oops: 0000 [#1]
kernel: SMP 

Now we’ve jumped to output generated by the die function in arch/i386/kernel/traps.c.

The first number is actually the error_code value passed to do_page_fault printed in hex. The interpretation for this is:

 *  bit 0 == 0 means no page found, 1 means protection fault
 *  bit 1 == 0 means read, 1 means write
 *  bit 2 == 0 means kernel, 1 means user-mode

So 0000 means “no page found” on “read” in “kernel” mode. This checks out with what we already know, consistency is good.

The number in the square brackets is the oops count. It is the number of times this die function has been called since boot, counting from 1. Usually you only want to worry about the first oops that you find. Everything after that point could be a side-effect of earlier kernel badness. If you’re working past the first oops then anything I have written here will be old news to you.

Yeah, and it is an SMP kernel. Other strings that may appear here are PREEMPT, and DEBUG_PAGEALLOC. After this the somewhat mis-named show_registers function found in arch/i386/kernel/traps.c is called and the rest of the oops text is generated in or below this call.

kernel: Modules linked in: monkey_pkt_eater nfnetlink_queue xt_condition
    ...

This output is generated by a call to print_modules (kernel/modules.c) by show_registers. Usually one of these will be the culprit for your problem, module code tends to be less stable than core kernel code, especially proprietary modules!

kernel: CPU:    0

This message is coming from CPU 0. Obvious enough?

kernel: EIP:    0060:[<c0143742>]    Tainted: PF     VLI

Eip! Again. The value 0060 comes from the CS register, let’s ignore it. (Sorry!) After that we have the EIP address 0xc0143742 shown again. Now “Tainted“, sounds nasty doesn’t it? There are six single-char codes here, and they’re generated by the print_tainted function in kernel/panic.c. The codes represent a bunch of undesirable, yet legal, things that might have been done to the kernel. The first code either ‘P‘ or ‘G‘, if the former then a non-GPL module has been loaded (as is the case here). If you have a ‘P‘ then don’t expect much support from kernel.org developers, unless the problem is obviously not related to non-kosher kernel modules. You’ll either want to work out the problem yourself, reproduce the problem without the proprietary module loaded, or get help from the vendor responsible for said module.

I’ll take a short-cut now and rip the comment from print_tainted to give the full list of flags:

 *  'P' - Proprietary module has been loaded.
 *  'F' - Module has been forcibly loaded.
 *  'S' - SMP with CPUs not designed for SMP.
 *  'R' - User forced a module unload.
 *  'M' - Machine had a machine check experience.
 *  'B' - System has hit bad_page.

The alternative character to all except ‘P‘ is a blank space (i.e. flag is unset). In our oops we also have an ‘F‘ because one of the custom modules loaded is missing symbol version information. The ‘F‘ flag can come into the mix for a variety of reasons it seems, the canonical one being that `insmod -f` was used to load it. None of the other “taints” are flagged in my example so I’m not going detail them. (See the bottom of Documentation/oops-tracing.txt for information.)

One last note on “taint”: Once a kernel is tainted it stays tainted. I.e. if you load a propriety module it taints the kernel and the ‘P‘ taint flag remains even if you unload it. You could think of it as an “from here on in all bets are off” state.

After the taint flags we have “VLI” and I don’t have a clue what this signifies. This is hard-coded in the i386 traps.c file, since it isn’t variable within the architecture I’ll dismiss it as unimportant!

kernel: EFLAGS: 00210202   (2.6.16.43-54.5-smp #1) 

This line first gives the CPU’s EFLAGS register, this register stores all the usual flags like “carry” as well as a bunch of less familiar flags (see link for more detail). After the flags, in brackets, is the version string identifying the kernel that generated the oops.

kernel: EIP is at put_page+0x2/0x40

Eip! Yet again, but now with some more useful information. The symbol attached to the code into which EIP is pointing along with EIP’s offset from the symbol (0x02) and the size of the code associated with the symbol (0x40, distance between the put_page symbol and the next marked symbol).

kernel: eax: 68230a7d   ebx: 00000001   ecx: f1057680   edx: 68230a7d
kernel: esi: f6fe7600   edi: fe089b98   ebp: f64d3c14   esp: f64d3bbc
kernel: ds: 007b   es: 007b   ss: 0068

Now we finally get the actual named purpose of the print_registers function: a dump of the content some CPU registers. It’s worth noting at this point that %edx and %eax both contain our dodgey address.

kernel: Process snort_inline (pid: 6298, threadinfo=f64d2000 task=dff3fa70)

Information about the current “process” being run on the CPU including pointers to the process’s thread and task structures. There will always be some process, but it may or may not be directly related to the error that caused the oops. When you’re debugging don’t jump to conclusions without good reason, keep following the trail of the oops.

kernel: Stack: <0>c02a8b4a f6fe7600 f1057020 c02a88d8 000004cd f9de0fdd c7af5000 f7802b60 
kernel: 0000c7af fe73e860 f64d3c48 f64d3c48 e7e19834 f64d3c34 f5b54cc0 00000000 
kernel: 00000001 c02c7adf 00200282 d94bd4cc f64d3c48 f4429a40 f64d3c40 f9dd912a 

The stack. Simply each word starting at %esp (stack pointer) and continuing
to the base of he stack or for kstack_depth_to_print words, a limit
configurable at kernel compile time. Some values in the stack can be related
to the next part of the oops, the “Call Trace“. Essentially, starting with the
at %esp the call chain is traced:

kernel: Call Trace:
kernel: [<c02a8b4a>] skb_release_data+0x8a/0xa0
kernel: [<c02a88d8>] kfree_skbmem+0x8/0x80
kernel: [<f9de0fdd>] mkyDestroyPacket+0x9d/0x260 [monkey_pkt_eater]
kernel: [<c02c7adf>] ip_local_deliver_finish+0xef/0x270
kernel: [<f9dd912a>] mkyIpqPostHandler+0xda/0x140 [monkey_pkt_eater]
kernel: [<c02c79f0>] ip_local_deliver_finish+0x0/0x270
kernel: [<f8e9e182>] find_dequeue_entry+0x82/0x90 [nfnetlink_queue]
kernel: [<f8e9e1ab>] issue_verdict+0x1b/0x50 [nfnetlink_queue]
kernel: [<f8e9f5af>] nfqnl_recv_verdict+0x1ff/0x330 [nfnetlink_queue]
kernel: [<c0308730>] schedule+0x350/0xdd0
kernel: [<f887940e>] nfnetlink_rcv_msg+0x16e/0x200 [nfnetlink]
kernel: [<f8879542>] nfnetlink_rcv+0xa2/0x169 [nfnetlink]
kernel: [<c02beecd>] netlink_unicast+0x16d/0x250
kernel: [<c02bf462>] netlink_data_ready+0x12/0x50
kernel: [<c02be2d1>] netlink_sendskb+0x21/0x40
kernel: [<c02bfacd>] netlink_sendmsg+0x27d/0x320
kernel: [<c0116c88>] __wake_up+0x38/0x50
kernel: [<c02a2b2e>] sock_sendmsg+0xae/0xe0
kernel: [<c012f4c0>] autoremove_wake_function+0x0/0x50
kernel: [<c012f4c0>] autoremove_wake_function+0x0/0x50
kernel: [<f90caa7f>] monkey_chan_queue_append+0x15f/0x170 [monkey]
kernel: [<c02a9e4a>] verify_iovec+0x2a/0x90
kernel: [<c02a306d>] sys_sendmsg+0x15d/0x270
kernel: [<c02a3f86>] sys_recvfrom+0x116/0x140
kernel: [<f90557c0>] e1000_clean_rx_irq+0x0/0x3d0 [e1000]
kernel: [<f9053b0e>] e1000_clean+0x53e/0x780 [e1000]
kernel: [<f90c7780>] mkyGetState+0x20/0x30 [monkey]
kernel: [<f9ddbc90>] packet_writer+0x2e0/0xd50 [monkey_pkt_eater]
kernel: [<c02a453f>] sys_socketcall+0x24f/0x280
kernel: [<c013a5b0>] __do_IRQ+0xc0/0x110
kernel: [<c0102d3f>] sysenter_past_esp+0x54/0x75

Think of this as analogous to “bt” in gdb, it is generated by show_trace_log_lvl in arch/i386/kernel/traps.c. But be aware that it can be broken, what if your bug involved mucking up data on the stack?

What we know at this point is that the put_page where our problem occured was called by skb_release_data (aha! networking code!), which in turn was called by kfree_skbmem, and that by mkyDestroyPacket. That last item, from the monkey_pkt_eater module comes from our propriety code. Our suspicion is that we have, for some reason, given some bad data to kfree_skbmem.

kernel: Code: c0 8b 01 01 c2 83 fa 10 89 11 7f 05 83 fa f0 7d 0d f0 01 15 fc 8f
    40 c0 c7 01 00 00 00 00 c3 8d 76 00 8d bc 27 00 00 00 00 89 c2 <8b> 00 f6
    c4 40 75 1e 8b 42 04 40 74 1f f0 83 42 04 ff 0f 98 c0 

Personally I find this the most exciting part of the oops. A sequence of hex values, joy! But what is the “Code:“? Quite simple really. The kernel takes the value of EIP, subtracts 43 then prints out 64 bytes from that point, marking the byte at EIP with <..>. I.e. it is a hexdump of the section of machine code being run at the time the oops occurred. And this means we can disassemble.

But it might not be so straight forward as we’d like. That “-43” means the hex-dump could start anywhere, maybe right in the middle of an instruction. So I suggest either removing everything prior to EIP (remove everything before <8b>) or starting at the symbol address that EIP maps into. The latter option is only going to work if the offset from the symbol is less than 43, in our case we’re lucky because in put_page+0x2/0x40 we’re given that the offset is only 2 bytes, so we can safely cut the code down to this:

    89 c2 <8b> 00 f6 c4 40 75 1e 8b 42 04 40 74 1f f0 83 42 04 ff 0f 98 c0 

Now we can employ trusty xxd to reverse the hex to a binary file:

:; echo '89 c2 8b 00 f6 c4 40 75 1e 8b 42 04 40 74 1f f0 83 42 04 ff 0f 98 c0' | 
    sed 's/[^0-9a-f]//g;s/^/0: /' |  
    xxd -r  -c 256 > code.bin

What do we do with this code.bin file? Our next friendly tool is objdump, which won’t accept data from STDIN or using <(...), thus the temporary code.bin file rather than a pipe. With objdump we do and get this:

:; objdump -b binary -m i386 -D code.bin 

code.bin:     file format binary

Disassembly of section .data:

0000000000000000 <.data>:
   0:   89 c2                   mov    %eax,%edx
   2:   8b 00                   mov    (%eax),%eax
   4:   f6 c4 40                test   $0x40,%ah
   7:   75 1e                   jne    0x27
   9:   8b 42 04                mov    0x4(%edx),%eax
   c:   40                      inc    %eax
   d:   74 1f                   je     0x2e
   f:   f0 83 42 04 ff          lock addl $0xffffffff,0x4(%edx)
  14:   0f 98 c0                sets   %al

Some really hard-core people familiar with machine code read it like assembly, and can easily work out the instruction sequence prior to put_page too. But if that was you then you wouldn’t be reading this I think.

What we know now is that the oops occurred in the assembly above at offset 2, at “mov (%eax),%eax“. Which is moving the word at the address stored in %eax into %eax. We can surmise that our invalid address is stored in %eax, and looking further up the oops, at the register dump, we see that the value in %eax is 0x68230a7d and that is the bad address that the very first line of the oops gives us. We now know the exact problem, but it isn’t really any use to use without some context isn’t it?

Thinking a little further, we know that offset 0 in the assembly code above is the entry point of the put_page function so the only code belonging to the function prior to where the error occurs is “mov %eax,%edx“. Logically it seems that an argument to the put_page function was provided in %edx (which the register dump shows also contains 0x68230a7d), and that this argument provides the bad address.

At this point we still don’t have any useful context and really need to start looking at a more complete picture of the code involved. That’s the subject of the next entry in this series.

[With some amusement I note that during the week I was dealing with the problem that prompted me to write this stuff the topic of “decoding oopses” became somewhat popular on LKML! Heh, great timing. This renders my own efforts somewhat redundant, oh well.]