Sunday, 12 February 2012

Xen Part 5: Dom0 X Instability

After a little time running the Debian dom0, it became clear that something was amiss. Sometimes, when I returned to the PC, I would find it unresponsive. The screen simply refused to come out of power saving mode, or would dump me straight back at the gdm login screen.

However, I was able to SSH into the box, and 'top' showed that my BOINC applications where still alive and well - a sure sign that the problems were limited to X. I could always regain control over the box by restarting Gnome Display Manager:

# /etc/init.d/gdm3 stop && sleep 2 && /etc/init.d/gdm3 start


A tail of /var/log/Xorg.0.log.old showed I was getting a segmentation fault, but didn't give much else to go by. In an effort to discover what the problem was, I decided to debug the X session remotely. 


ace@remote# apt-get install xserver-xorg-core-dbg xserver-xorg-video-intel-dbg gdb
ace@remote# gdb /usr/bin/Xorg $(pidof Xorg)
[...snip...]
(gdb) handle SIGPIPE nostop
(gdb) cont
Program received signal SIGSEGV, Segmentation fault.

0x00007f88988ec775 in outl (port=61440, val=323652) at ../../../../hw/xfree86/common/compiler.h:438



(gdb) bt
#0  0x00007f88988ec775 in outl (port=61440, val=323652) at ../../../../hw/xfree86/common/compiler.h:438
#1  x_outl (port=61440, val=323652) at ../../../../hw/xfree86/int10/helper_exec.c:423
#2  0x00007f88988f3613 in x86emuOp_out_word_DX_AX (op1=<value optimized out>)
    at ../../../../hw/xfree86/int10/../x86emu/ops.c:9847
#3  0x00007f88988ff31c in X86EMU_exec () at ../../../../hw/xfree86/int10/../x86emu/decode.c:122
#4  0x00007f88988eded5 in xf86ExecX86int10 (pInt=0x1810780) at ../../../../hw/xfree86/int10/xf86x86emu.c:40
#5  0x00007f8898b098c9 in VBEDPMSSet (pVbe=0x180e3f0, mode=323652) at ../../../../hw/xfree86/vbe/vbe.c:1072
#6  0x000000000047382f in DPMSSet (client=<value optimized out>, level=<value optimized out>)
    at ../../../../hw/xfree86/common/xf86DPMS.c:167
#7  0x00007f889a636b7f in ProcDPMSForceLevel (client=0xf000) at ../../Xext/dpms.c:188
#8  ProcDPMSDispatch (client=0xf000) at ../../Xext/dpms.c:236

The Xorg server source code can be downloaded from the XOrg Foundation. Looking through the files involved in the stack trace, it seems that the monitor is being restored from power saving mode via DPMS when the segfault occurs. As a test, I tried disabling sleep mode for my monitor, via System -> Preferences -> Power Management -> Put display to sleep when inactive for <Never>. This solved the problem - but that's hardly what I'd call a solution. Best get back to it.

At frame #1, the x86 emulator has already decided to send value 323652 to port 61440 (0xf000). That's probably the port allocated to my onboard graphics card; let's double-check.

$ dmesg | grep 0xf000
[    4.001927] pci 0000:00:02.0: reg 20 io port: [0xf000-0xf03f]
$ lspci | grep 00:02.0
00:02.0 VGA compatible controller: Intel Corporation Sandy Bridge Integrated Graphics Controller (rev 09)

Indeed it is (remember that I'm using my onboard graphics controller for dom0, with the intention of using pci passthrough to dedicate my HD6970 to a domU). So we're using outl to write a long (a 32-bit value) to the 64-bit port at location 0xf000 - 0xf03f, and receiving a segfault. Damn; I was hoping for something a little simpler.

Here's the code in compiler.h (obtained from the Xorg source linked to above) where the segfault is occuring:

static __inline__ void
outl(unsigned short port, unsigned int val)
{
   __asm__ __volatile__("outl %0,%1" : :"a" (val), "d" (port));
}

If the above seems a little unfamiliar to you, you're not alone. That method contains an example of extended inline assembly code. Sandeep has an excellent explanation is his howto guide on inline assembly. A read through of that short howto in its entirely will give you a good understanding of what that line does.

In brief, it executes assembly command "out", with the source operand set to the 32-bit value in C variable $val, and the destination operand set to the value in C variable $port.  "a" and "d" are constraints: they specify that $val should be placed into the eax register and $port should be placed into the edx (well, port is a word value, so dx) register. I'd imagine the resulting AT&T assembly code would look something like this:

movl val,%eax
movw port,%edx
outl %eax,%edx

And the assembly command "out"? That just writes data in the source register to the port provided in the destination register. So far, everything looks fine: we're not really getting to the root of the problem. 

The O'Reilly book Linux Device Drivers, 2nd Edition, mentions in chapter 8 that ioperm or iopl should be called prior to inX/outX calls being made. ioperm can't assign permissions to ports as high as 61440, so it should be using iopl(3) instead to assign permissions to all ports. There is indeed such a call:

$ grep -n -r "iopl(3)" *
hw/xfree86/os-support/linux/lnx_video.c:523:        if (ioperm(0, 1024, 1) || iopl(3)) {

This is in xf86EnableIO(). I checked that it was being called by starting Xorg directly with gdb, and breaking on iopl - it hit. Seemingly another dead end. 

Time to try things for myself.

$ vim outl_test.c
#include <stdio.h>

static __inline__ void
outl(unsigned short port, unsigned int val)
{
   __asm__ __volatile__("outl %0,%1" : :"a" (val), "d" (port));
}

int main() {
  printf("Testing outl\n");
  outl(61140,323652);
  printf("Done\n");
  return 0;
}
$ gcc -O -g -o outl_test outl_test.c
$ gdb ./outl_test
GNU gdb (GDB) 7.0.1-debian
Copyright (C) 2009 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from <stripped>/outl_test...done.
(gdb) run

Starting program: <stripped>/outl_test 
Testing outl
Done

Program exited normally.

(gdb) run
Starting program: <stripped>/outl_test 
Testing outl

Program received signal SIGSEGV, Segmentation fault.
0x00000000004004fc in outl () at outl_test2.c:6
6 outl_test.c: No such file or directory.
in outl_test.c
(gdb)

That's right - this test failed intermittently. It wasn't uncommon to have to run the program 50 times before it segfaulted, or vice versa. The same behaviour was exhibited when running as root. Why did it fail intermittently? 

Well, that isn't really the question... the question is, why did it ever succeed? I should need to request IO port access via iopl(level), otherwise it runs at the default level 0. Odd. I expanded my test case.


#include <stdio.h>

#include <errno.h>


// from <sys/io.h>
extern int iopl (int __level) __THROW;

static int requestPortAccess = 1; // runs iopl(3)
static int clearPortAccess = 0; // runs iopl(0)

static int RUN_TIMES = 1000;
static unsigned short PORT = 61140;
static unsigned int VAL = 323652;

static __inline__ void
outl(unsigned short port, unsigned int val)
{
   __asm__ __volatile__("outl %0,%1" : :"a" (val), "d" (port));
}

int main(int argc, char *argv[]) {
  int i = 1;
  int ret = 0;
  // Handle args (yes it's ugly as heck, but it's 3am and I need my dinner)
  if (argc>1) {
    if (atoi(argv[1]) >=0  && atoi(argv[1]) <=1) {
      requestPortAccess=atoi(argv[1]);
    }
  }
  if (argc>2) {
    if (atoi(argv[2]) >=0  && atoi(argv[2]) <=1) {
      clearPortAccess=atoi(argv[2]);
    }
  }
  if (clearPortAccess > 0) {
    // Simulate forgetting to call iopl(3)
    ret = iopl(0);
    printf("iopl(0) returned %i\n",ret);
  }
  if (requestPortAccess > 0) {
    printf("iopl(3)\n");
    ret = iopl(3);
    printf("iopl(3) returned %i\n", ret);
  }
  if (ret < 0 && errno == ENODEV) {
    printf("No I/O ports found\n");
  } else if (ret < 0) {
    printf("iopl failed to get access to the IO ports, errno: %i\n", errno);
  }
  // Failure can be intermittent, so run plenty of times
  for (;i<=RUN_TIMES;i++) {
    printf("ATTEMPT %i, outl(%i,%i)\n",i,PORT,VAL);
    outl(PORT,VAL);
    printf("Done\n");
  }
  return 0;
}

This allowed for a few more tests. 

1) $ ./outl_test 0 1
2) $ ./outl_test 1 0
3) # ./outl_test 0 1 
4) # ./outl_test 1 0
5) $ ./outl_test 0 0
6) # ./outl_test 0 0

1) iopl(0) as user [outl always segfaulted]
2) iopl(3) as user [outl always segfaulted]
3) iopl(0) as root [outl always segfaulted]
4) iopl(3) as root [outl never segfaulted]
5) no iopl as user [outl intermittently segfaulted]
6) no iopl as root [outl intermittently segfaulted]

The results of tests 1-4 are as one would expect, but the results of tests 5 and 6 don't seem to comply with the spec.  The process should be running with io privilege level 0 by default (== iopl(0)), so outl should always segfault.

And to recap, this occurs only when running with the 2.6.32-5-xen-amd64 with Xen, i.e. in dom0 mode. It doesn't occur when just running 2.6.32-5-xen-amd64 or 2.6.32-5-amd64.

Investigations continue...