Pedigree: Progress Update & Python Debugging Post-Mortem

My last post on this blog covered off the work so far on memory mapped files. There has been quite a bit of progress since then in this area:

  • Memory mapped file cleanup works as expected. Programs can remove their memory mappings at runtime, and this will be successful – including ‘punching holes’ in mappings.
  • Remapping an area with different permissions is now possible. The dynamic linker uses this to map memory as required for the type of segment it is loading – for example, executable, or writeable. This means it is no longer possible to execute data as code on Pedigree on systems which support this.
  • Anonymous memory maps are mapped to a single zeroed page, copy-on-write. Programs that never write to an anonymous memory map are therefore significantly lighter in physical memory.
  • The virtual address space available for memory maps on 64-bit builds of Pedigree is now significantly larger.

Other significant changes since the last post include:

  • Implemented a VGA text-mode VT100 emulator and necessary fallbacks for a system that does not have the ability to support a graphics mode for Pedigree. This significantly improves the experience.
  • Psuedo-terminal support has improved substantially, such that the ‘Dropbear’ SSH server runs and accepts numerous connections, without nasty error messages.
  • POSIX job control is functional.
  • I have successfully used Pedigree on my old eee PC with a USB Mass Storage device as the root filesystem; writing files on Pedigree using Vim and reading them on a Linux system.
  • The build system now uses GCC 4.8.2 and Binutils 2.24.
  • Pedigree is now only 64-bit when targeting x86 hardware, in order to reduce development complexity and to acknowledge the fact that very few modern systems are 32-bit-only anymore.

Of particular interest has been the switch to 64-bit-only when targeting x86. The following is a post-mortem from a particularly interesting side-effect of this.

Python has been a supported port in Pedigree for quite a while. Python entered the tree proper in 2009, version 2.5. The process of and lessons learned while building Python for Pedigree led to the creation of the Porting Python page on the wiki. Suffice it to say, this is a port that has great significance to the project. Our build system (SCons) also uses Python, so it is critical to support Python in order to achieve the goal of building Pedigree on Pedigree. Recently I noticed that Python was consistently hitting a segmentation fault during its startup. Noting that this is probably not a great state for the Python port to be in, I decided to take a closer look.

All code is from Python 2.7.3.

The problem lies in moving from 32-bit to 64-bit; I am sure by now many readers will have identified precisely what the problem is, or will do so within the first paragraph or two of reading. Read on and find out if you are correct! 🙂

The first order of business was to get an idea as to where the problem was taking place. I rebuilt Python making sure that `-fno-omit-frame-pointer was in the build flags, so the Pedigree kernel debugger could do a trivial backtrace for me. I removed the code that only enters the kernel debugger when a kernel thread crashes (normally, it makes more sense for a SIGSEGV to be sent to the faulting process – but I needed more debugging flexibility to fix this). I managed to get a backtrace and discovered that the process was crashing within the _PySys_Init function.

With a disassembly of the Python binary in hand, and the source code available, I quickly identified that the problem line was:

PyDict_SetItemString(sysdict, "__displayhook__", PyDict_GetItemString(sysdict, "displayhook"));

Okay, so it turns out that somehow, the sys module’s dictionary of attributes, methods, and documentation is returning a ‘not found’. This is bad! The question is, why is the lookup failing?

I ended up having to trace through the source with breakpoints and disassembly, which took a good 5-6 man-hours to complete. I reached a point where I could no longer isolate the issue and it was at this point I realised I needed something a bit heavier than Pedigree’s builtin debugging tools. The QEMU emulator provides a GDB stub, which is perfect for debugging this kind of thing.

I also reached the conclusion to use GDB after a number of test runs where I ended up inspecting the raw contents of RAM to decipher the problem at hand – while this is helpful for learning a lot about how Python data structures work and how they look, it is nowhere near a sustainable solution for debugging a problem like this.

I linked a local GDB up to the Python binary, with a .gdbinit file that made sure to transform the file paths the binary held within it so GDB could show me source references while running. The file looks a little like this:

file images/local/applications/python2.7
target remote localhost:1234
directory /find/source/in/misc/src/Python-2.7.3
set substitute-path /path/to/builds/build-python27-2.7.3/build/.. /real/path/to/misc/src/Python-2.7.3
set filename-display absolute
set disassemble-next-line on
break *0x4fcd42

The breakpoint on the final line is set to the line of code shown above.

The key to the .gdbinit file is that it essentially specifies a list of GDB commands to run before GDB is interactive. This saves a huge amount of time when doing the same general debug process repeatedly. So the stage is set, the actors are ready!

Up comes Pedigree, up comes GDB, everything is connected and functioning correctly. QEMU hits the breakpoint address and hands off control to GDB. At this point, I am able to print the value of various variables in scope and start tracing. First of all, I check the sysdict dictionary to make sure it actually has items…

> print sysdict.ma_used

(number greater than zero)

Okay, so there’s items in the dictionary. Excellent. I’ll confess at this point I became a little bit excited – I hadn’t used GDB with QEMU before, and I hadn’t realised that it would be exactly the same as debugging any other userspace application. The entire toolset is at my fingertips.

So I trace, stepping through function after function, nested deeply. Fortunately GDB has the finish command – which basically continues execution until the current function is about to return. Many functions included things like allocating memory, interning strings, and creating Python objects. Jumping to the end and seeing each of these functions completed successfully indicated the issue was not in any of these particular areas of the Python source tree.

Finally, after much stepping and moving through the call tree, I ended up at the PyDict_GetItem function. Excellent – I know I’m close now!

I’ll confess, as soon as I saw the source dump for this function I had a bit of an a-ha moment; the first line of the function is:

long hash;

From my previous memory dumping and traversing the Python codebase, I happened to have an awareness that dictionary objects use the type Py_ssize_t for their hashes. This is defined as ssize_t normally, which is fine on most systems. I had a hunch at this point, but I continued stepping – I wanted conclusive evidence before I left the GDB session and identified a fix.

The next few steps essentially involved tracing until finding something along the lines of:

if (ep->me_hash == hash) {

Okay, GDB, do your best!

> print ep->me_hash
> print hash

Oh dear.

I aborted the GDB session here, closed QEMU, and ran a quick test to see what the actual size of Pedigree’s ssize_t on 64-bit is… and discovered that it is in fact only 4 bytes (where size_t is 8 bytes). Of course, a long on 64-bit is a full 8-byte integer. Matching the hash would be a true fluke; the dictionary lookup could never succeed.

The problem has now been fixed and Python now runs perfectly well on 64-bit systems. Python checks the size of size_t in its configure script but not the signed variant; nor should it need to – the two types should be the same size. Even so, PyObject_Hash returns a long; there is a comment to this effect in Python’s dictobject.h:

/* Cached hash code of me_key.  Note that hash codes are C longs.
 * We have to use Py_ssize_t instead because dict_popitem() abuses
 * me_hash to hold a search finger.
Py_ssize_t me_hash;

I have not yet checked whether this is resolved in newer Python.

It’s nice to be able to run Python code again in Pedigree. 🙂

Leave a Comment

Fill in your details below or click an icon to log in: Logo

You are commenting using your account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s