Bug 254024
|
Description
Adam Jackson
2007-08-23 17:39:15 UTC
Nominating for 5.2. The short summary is the vm86 syscall seems to be stomping register state before returning to userland, which confuses (among other things) the VESA DDC code, so the vesa driver can't ask the monitor about capabilities. Relevant links from the above discussion: https://bugzilla.redhat.com/bugzilla/attachment.cgi?id=158912 http://bugzilla.kernel.org/show_bug.cgi?id=8633 Note that current Rawhide kernels are fine here, due to some churn in the area. This bugzilla has Keywords: Regression. Since no regressions are allowed between releases, it is also being proposed as a blocker for this release. Please resolve ASAP. Moved the Issue Tracker number to this bug from the original. Re: Comment #1: Are you sure that there are Rawhide kernels that are ok? I'd be willing to test one, but I'm not convinced that the problem has actually been fixed. (Perhaps there have been conversations outside the buzilla and other trackers that I've not been privvy to.) (In reply to comment #4) > Re: Comment #1: Are you sure that there are Rawhide kernels that are ok? > I'd be willing to test one, but I'm not convinced that the problem has actually been fixed. Apologies, I'm not actually sure. I had discussed this on IRC with another engineer, who pointed out several changes in do_sys_vm86() that looked likely related. RHEL5 had: if (unlikely(current->audit_context)) audit_syscall_exit(AUDITSC_RESULT(eax), eax); Whereas recentish rawhide has: if (unlikely(current->audit_context)) audit_syscall_exit(AUDITSC_RESULT(0), 0); So the rawhide version is almost certainly touching less register state. Between that and not seeing any reports of this failure on rawhide I probably jumped to conclusions. But yes, testing this on rawhide would be valuable. William,
Currently the patch that #if 0 the audit_ssycall_exit code will not pass
internal code review. So we will need to get a valid patch for RHEL5.2. Having
the results of the rawhide kernel will get us one step closer in getting a fix
into the kernel in the 5.2 timeframe.
Please let us know as soon as you get those results.
Thanks,
Jeff
Created attachment 206251 [details] Attempt to extract syscall exit fix from 2.6.20 kernel Acknowledged. I'd planned on getting back to testing sooner, but got swamped here with some RHEL 5 customer documentation tasks. My friend Chuck and I have tried some testing, and here is where we've gotten to today. One point of clarification: The patch with the #if 0 in it was explicitly not for adoption. It was illustrating the minimal scope of the broken code. A careful reading of our bug report said that we were unsure what the correct fix was, and wanted to assist with the testing of a fix. But, as you ultimately concluded testing with a new kernel was the right next step. Question about a kernel to test with: Up until now I'd let others do testing with beta components. I understand the term "rawhide" refers in a generic way to the bleeding edge beta. But that would be Fedora not RHEL 5, right? Indeed, the 2.6.23 kernel at download.fedora.redhat.com:/pub/fedora/linux/development/i386/os/Packages/ will not install under RHEL 5 without an update to mkinitrd. The newer mkinitrd requires half a dozen lower level libraries to be updated before it will install. This seems like it is mutilating too much of the RHEL 5 environment. Bottom line: Is there a "rawhide" kernel that I can just drop into RHEL 5, or did you indeed mean that I should install Fedora with a 2.6.18 kernel, re-run all my tests to confirm I've got a clean failure, and then try the Fedora 2.6.23 kernel and see if the failure goes away? ---- Trying a rawhide kernel may be moot, however because of some other things we have learned today. Back on December 7, 2006, Jeremy Fitzhardinge checked in some changes to vm86.c that look 100% relevant to our problem. Excerpt from the kernel.org ChangeLog-2.6.20: (http://www.kernel.org/pub/linux/kernel/v2.6/ChangeLog-2.6.20) commit 49d26b6eaa8e970c8cf6e299e6ccba2474191bf5 Author: Jeremy Fitzhardinge <jeremy> Date: Thu Dec 7 02:14:03 2006 +0100 [PATCH] i386: Update sys_vm86 to cope with changed pt_regs and %gs usage sys_vm86 uses a struct kernel_vm86_regs, which is identical to pt_regs, but adds an extra space for all the segment registers. Previously this structure was completely independent, so changes in pt_regs had to be reflected in kernel_vm86_regs. This changes just embeds pt_regs in kernel_vm86_regs, and makes the appropriate changes to vm86.c to deal with the new naming. Also, since %gs is dealt with differently in the kernel, this change adjusts vm86.c to reflect this. While making these changes, I also cleaned up some frankly bizarre code which was added when auditing was added to sys_vm86. Signed-off-by: Jeremy Fitzhardinge <jeremy> Signed-off-by: Andi Kleen <ak> Cc: Chuck Ebbert <76306.1226> Cc: Zachary Amsden <zach> Cc: Jan Beulich <jbeulich> Cc: Andi Kleen <ak> Cc: Al Viro <viro.org.uk> Cc: Jason Baron <jbaron> Cc: Chris Wright <chrisw> Signed-off-by: Andrew Morton <akpm> ---- Chuck and I made an attempt to isolate just the relevant change and test with it. The result was that the EDID transfer always failed. So either Fitzhardinge's amendment to audit_syscall_exit was insufficient, or we didn't take enough of the patch to get correct operation. Indeed our understanding of Fitzhardinge's work is poor, and it is most likely that we incorrectly extracted his cleanup of the audit code. Attached is that trial patch. Chuck and I are evaluating what the right next step would be: To do that Fedora testing path? To re-examine Fitzhardinge's patch and more fully understand his audit fix. To ask Andi Kleen at kernel.org to re-examine our bug report in the context of the Fitzhardinge patch he signed off on in December 2006? What do you recommend as a next step? Owing to the relevance of this patch, is there value to involving Jason Baron of Red Hat who was on the reviewer list of Fitzhardinge's patch? My concern is that we fully enough understand what is going on to clearly demonstrate that the problem is fixed, not just driven underground by code having landed in a different place. Therefore, I see value in getting the minimal correct chunk of Fitzhardinge's changes onto my test bed with minimal other changes. William, Thanks for the detaied feedback. It looks like the patch set you made reference to: http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commitdiff;h=49d26b6eaa8e970c8cf6e299e6ccba2474191bf5 Is part of the 2.6.20 baseline. So you should be able to use our RT Vanilla kernel to test with. Please note this is an _unofficial_ kernel to be use only for testing this issue. You can download the kernel from here: http://people.redhat.com/jburke/kernel-rt-vanilla-2.6.21-39.el5rt.i686.rpm The above kernel should just install ontop of RHEL5. Thanks Jeff Thanks VERY much for that kernel. It made things much easier, and saved us a lot of work. GOOD NEWS: The kernel indeed ran without trouble on the RHEL 5 test system. GREAT NEWS: The problem with EDID transfers through vm86.c appears to be resolved. I ran the X server several times, and each time the EDID fetch was 100% complete. I strongly suspect that Fitzhardinge's patch remedied the problem. Any guess when 2.6.20 or later will make it to public RHEL 5? William, That is good news. So we have a starting point for to backport a fix. Q. Any guess when 2.6.20 or later will make it to public RHEL 5? A. We never do major kernel upgrades in a release. So 2.6.18 is the kernel for the life span of RHEL5. But we will do backports for fixes into the 2.6.18 RHEL kernel. I think the next step is for me to isolate the portions of the patch set that actually fixes the issue. Or come up with an alternative patch. I will get back to you when I have a test kernel. If you don't hear back from me in an acceptable time frame please feel free to ping me on the issue. Thanks, Jeff That sounds like the sensible way forward. hi William, what version of rhel5 kernel are you running? Since we weren't able to reproduce this yet in house, and there have been a number of audit changes, perhaps you can try to reproduce this on the latest rhel5 beta kernel link below. thanks. http://people.redhat.com/dzickus/el5/51.el5/i686/kernel-2.6.18-51.el5.i686.rpm Also, another variable here that might be interesting is wether turning off auditing works around this? you can disable audit by doing: /sbin/chkconfig auditd off and then rebooting. You can verify audit on/off by doing: /sbin/auditctl -s and verifying that enable=0. thanks. Jason, The kernel that we have been working with up to now was 2.6.18-6. I fetched your 2.6.18-51 kernel, and the EDID fetch fails with 100% repeatability for me. (But it *IS* nice to not have to wait for the SATA timeouts. I'm really looking forward to THAT fix showing up in the production kernel asap.) Turning off the audit demon has no effect. The EDID fetch through vm86 still occurrs with 100% repeatability. Though kernel.org, we've been in touch with Jeremy Fitzhardinge in an attempt to craft the minimal effective patch. Alas our second attempt has also been unsuccessful. My current plan is to show the patch I tried to Fitzhardinge and have him tell me how I got it wrong. Grrr! Typo. The kernel that we have been working with is 2.6.18-8. Status update: A couple folks from kernel.org proposed a couple variations on the minimal patch to correct the audit_syscall_exit code. Sadly, none of those candidtate patches worked. I'm pursuing as a next step an integration of the whole pt_regs patch (commit 49d26b6eaa8e970c8cf6e299e6ccba2474191bf5) from kernel.org to see if it has a beneficial effect. William,
When you have time can you please test the following kernel.
http://people.redhat.com/jburke/kernel-2.6.18-53.el5.bz254024.1.i686.rpm
please post the test results.
Thanks in advance,
Jeff
I am sorry to report that, although the kernel seemed to run just fine, the EDID transfer still came back wrong. William, I appreciate you running the test kernels. If you wouldn't mind I have one additional test for you to try when you have time. http://people.redhat.com/jburke/kernel-2.6.18-53.el5.bz254024.3.i686.rpm Again post your results when you can. Thanks in advance, Jeff Alas, still no joy. The EDID transfer still came up all zeros. Here's an observation I tripped over in other testing. I'd updated an RHEL 4 WS system to RHEL 5 Server. (I was seeing what would happen to apps like Open Office across such an update. It wasn't pretty. I opened a trouble ticket. But I digress...) That system had two kernels installed the PAE and the vanilla 2.6.18-8 kernel. The vanilla kernel consistently had bad EDID transfers. but booting the PAE kernel on that setup had consistently good EDID transfers! I'll also note in passing that the EDID transfers are so flaky that RHEL 5 x86_64 gets sufficiently confused that it won't start X at all with the xorg.conf it creates at install time. Let me say this again: I'm booting RHEL 5 i386 and RHEL 5 i86_64 out of different partitions of the same system. I did clean installs from RHEL 5.0 media. But the i386 will actually start X, but the x86_64 wont until I hand tool the config file. This one is probably due to some Xorg app behaving differently in 64 bits. Sheesh! William,
Sorry to rehash this at this point in time but I would like to clear up some
confusion. Your Comment #20 makes me think we have a disconnect. The patch you
posted to the bz in Comment #7 is for i386 the bz is opened for i386. The
kernel-rt-vanilla-2.6.21-39.el5rt.i686.rpm I pointed you at in Comment #8 was
for i686. The git commit from Fitzhardinge's
49d26b6eaa8e970c8cf6e299e6ccba2474191bf5 was for i386. So I have been only
looking at i386.
Please correct any of the following statements below that are not true and
add any additional data you think is relevant.
1.) 2.6.18-8.EL.i686 kernel will start X ... sometimes?
2.) 2.6.18-8.ELPAE.i686 kernel works without issue.
3.) 2.6.18-8.ELxen.i686 kernel unknown
4.) 2.6.18-8.EL.x86_64 kernel fails always.
5.) 2.6.18-8.ELxen.x86_64 kernel unknown.
6.) 2.6.18-53.EL.i686 ?
7.) 2.6.18-53.EL.x86_64 ?
8.) Regardless of kernel. the 3rd party EDID application aways works.
Thanks in advance,
Jeff
Don't panic. The i386 subdirectory is stuff that's built also for the i686 kernel. When I build my test kernel I build the i686 kernel, but it uses code from i386 for vm86.c. I've not run the stand alone read-edid under multiple kernels. I stopped testing with it when I satisfied myself that it aways succeeded whereas X always had a bad EDID fetch under the 2.6.18-8.EL.i686 kernel. Your case #1 above, I'd not say "will start X ... sometimes". X starts, it just has a flaky EDID read that one either can or cannot work around in xorg.conf. I suggest the most correct way to characterize the test is, "Full and correct EDID fetch of BIOS data from the video card." So I'd recast your list as follows: 1.) 2.6.18-8.EL.i686 kernel flaky EDID fetch under X. Fine under get-edid. 2.) 2.6.18-8.ELPAE.i686 kernel apparent 100% reliable EDID fetch under X. 3.) 2.6.18-8.ELxen.i686 kernel unknown 4.) 2.6.18-8.EL.x86_64 kernel flaky EDID fetch under X, but not rigorously tested. (X seems harder to configure under RHEL 5 and 4.5 on the x86_64 platform but that may be unrelated to this bug.) 5.) 2.6.18-8.ELxen.x86_64 kernel unknown. 6.) 2.6.18-53.EL.i686 kernel flaky EDID fetch under X. 7.) 2.6.18-53.EL.x86_64 unknown. In comment #16, I said I'd pursue an attempt to integrate the whole pt_regs patch. I finally got some time and attempted that today. Unfortunately, Fitzhardinge's whole patch is based on the 2.6.20 kernel's definition of struct pt_regs, which has the element: int xgs; which is missing from the 2.6.18 kernel. Alas, I don't know enough about register saving and restoring to have what I would consider a useful suggestion going forward. Perhaps having that extra register in the pt struct is allowing space to save a register that the audit code trashed in 2.6.18? Perhaps the fix to this bug is in some seemingly unrelated region of the 2.6.20 kernel? Jeff: If there are specific things that you've been integrating into the candidate test kernels you've been sending me, I'd be happy to bench check or review them for applicability to this problem. There ARE a couple more radical positions we could take with this issue: 1. Discourage use of vm86.c for EDID transfers, and push for use of the emulator. 2. Encourage use of ATI drivers that use the native register set and abandon the VESA compatibility layer as something that is these days getting insufficient attention. It would be nice if we had a clearer sense of why 2.6.20 works whereas 2.6.18 does not. Is there a 2.6.20 withOUT Fitzhardinge's patch, built for RHE5 that I could test. At least then we'd have a single delta across which to test. William, Ubuntu bug 89853 (https://launchpad.net/ubuntu/+source/xorg/+bug/89853) got solved by an updated vesa driver rpm. xserver-xorg-video-vesa 1.3.0-1ubuntu5 I know in this bug folks could read EDID properly and it might not be the same issue. Still it might be worth to test out new vesa driver once to see if it helps. Few things which are confusing. - RHEL 5 PAE kernel works fine. That means not necessarily vm86() implementation is bad as code base is same. - read-geteid works fine. Why there is an issue with X? I think I should print register states before vm86() call and after and see if there are any registers which have not been restored after the system call. - Jeff mentioned that he backported Jermey's upstream patch to RHEL5 and it did not help. That means issue is probably somewhere else. I am still trying to find out a machine with ATI Radeon 1300 card to see if I can reproduce the issue here. Ubuntu runs with the 2.6.20 kernel these days. That kernel has the entirety of Fitzhardinge's patch, with the additional element in the struct pt_regs. It may be that a new VESA driver fixes the problem. If I get some time, I'll try and compare the new and old VESA driver. However, from what I currently know, I think the problem most likely went away in Ubuntu, not because of a new VESA driver, but because of the 2.6.20 kernel, and that additional element in struct pt_regs. Printing the register state before and after the vm86 call seems precisely the thing to test. Let me see if i can run that test. (In reply to comment #1) > Nominating for 5.2. The short summary is the vm86 syscall seems to be stomping > register state before returning to userland, which confuses (among other things) > the VESA DDC code, so the vesa driver can't ask the monitor about capabilities. Adam, I am running gdb on read-edid and captured the 16bit register states for RHEL5 (-58) and upstream kernel (2.6.24-rc4). Of course read-edid is successful in both the cases. I just wanted to see if vm86() is really stomping over any of the 16 bit registers which can potentially confuse the realmode vesa code. As per the gdb output, it does not look like that vm86()is corrupting any of the 16bit registers. Only registers which seem to be being touched are _null_es (in case of rhel5) and _null_fs(in case of 2.6.24-rc4). But this should not make a difference as 16 bit code is not going to load these segment selectors. Instead it would use es, ds, fs, gs (these are stored in the end in struct vm86_regs.) And looking at register states, actual ds, fs, gs, es seem to be fine even after multiple calls to vm86(). I am going to attach two files. One for 2.6.24-rc4 and one for rhel5(-58). These files contain the output from gdb after the call to vm86(). These have been taken for read_edid utility. Do you have more info regarding what registers are stomped by vm86() at what point of time? Created attachment 289391 [details]
rhel5(.58) gdb output for read-edid
Created attachment 289411 [details]
2.6.24-rc4 gdb output for read-edid
I believe that attempting to re-produce the problem when running the read-edid utility will not be helpful. We ALWAYS get good EDID transfer with the small stand-alone read-edid utility. The failure only occurs when the big, messy X server is run. If you give me instructions how you instrumented either the kernel or the app, I'll reproduce that effort with the X server on my "always fails" test setup. I ran into an interesting problem the moment I upgraded my xserver to 48.26.el5 release. Now if I boot my system, X initializes at 800x600 resolution. If I restart the server it initializes the display at 1024x768. In first case there is no EDID transfer as the the Xorg logs and in second case there is a valid EDID transfer. This problem does not happen always and I could see it only 4 time out of 10-12 reboots. This is not same problem as reported but this looks very similar. I have got Radeon 300 card. I am trying to find a way regarding how to run X under gdb and then debug how vm86 calls are being made. Interesting thing is that this problem happened only after I upgraded my xserver. I am attaching success and failure log. Created attachment 289806 [details]
X logs when server initializes to 800x600 and no EDID data
Created attachment 289807 [details]
X server logs when server initializes with 1024x768 with EDID data
Interesting. I have a couple observations: 1. You're running the Radeon driver now, not the VESA driver. But apparently the Radeon driver now needs a successful EDID transfer to get the video modes. 2. This sort of confirms that the fixup for the failed EDID transfer would not be from an updated VESA driver, since you're not using that driver any more. 3. Sorry that it's not failing hard for you. In the early days, mine didn't get a bad EDID transfer every time either. IMPORTANT: Check the hex dump of the EDID data. You may be getting more failures than you think. Look for that hex dump to sometimes be complete, and sometimes to have zeros in it starting at a random point in the block. THATS the manifestation I see. CONGRATULATIONS! You are in fact seeing the exact failure I see. 4. It looks like the Radeon driver does a poor job of noticing a failed EDID transfer. I think it should actually flag the transfer as unsuccessful instead of magically reporting data or not. In the VESA driver, I fed a patch upstream to test the return value of the version number, and print an error rather than just continuing as if the EDID transfer was successful even if the version number came back with garbage. William, I went little deeper into RADEON driver and found out it is reading EDID data from monitor over I2C/DDC. So RADEON is not making use of int10 and hence vm86 at all on my system. That means EDID trasfer is flaky over I2C too and not just if we are using int10 using vm86(). Well, that would be a different problem altogether. How did you switch drivers (vesa vs fglrx?). I want to forcibly use vesa here instead of readeon and see what does it do in my system. I didn't do anything to explicitly force the VESA driver. I think that, on install, the device ID was not recognized by any other driver, so VESA was set as the default. Presumably xorg.conf gives the device driver as "radeon" or "fglrx" now, and you could change that to "vesa". ok. Now I got vesa driver installed which uses real mode bios calls to get EDID data. I am not seeing any issues on my system. I am also able to use gdb now and print register states before after sys_vm86() calls while retrieving EDID. I can't see any corruption happening. I have collected register states for RHEL5 (.58) kernels and 2.6.24-rc4 kernels. I will be attaching the logs. William, I will prepare an Xorg rpm and send you and also tell you the procedure to how to run gdb. Run Xorg under gdb and see if you can still reproduce the issue. If yes, then it should be able to tell us where does it fail while retrieving EDID and what are the register states. Created attachment 290180 [details]
Register states before and after vm86() calls for 58.el5 kernels
Created attachment 290181 [details]
Register states before and after vm86() calls for 2.6.24-rc4 kernels
William, This is what I did to compile and run my Xorg server and debug with gdb. You might want to do the same to gather some data on your machine. - Download Xorg source rpm from following link. http://people.redhat.com/vgoyal/.xserver-edid-issue/xorg-x11-server-1.1.1-48.26.el5.src.rpm - Install rpm rpm -ivh xorg-x11-server-1.1.1-48.26.el5.src.rpm - Go to /usr/src/redhat/SPECS/ dir and start building the rpm. rpmbuild -bc xorg-x11-server-1.1.1-48.26.el5.src.rpm - Once it start compiling (after applying patches, doing configure etc), you can Ctrl-C the command and move /usr/src/redhat/BUILD/xorg-server-1.1.1 dir to your working dir. - cd xorg-server-1.1.1 and edit "configure" to get rid of "-O2" flag. I want to get rid of optimization otherwise it becomes difficult to work with gdb and source code. - Run ./configure - Run make - Run make install - Now you have built your own Xorg server and installed it. - SSH to target machine from a different machine and run Xorg under gdb gdb --args /usr/bin/Xorg --dumbSched - You can put breakpoint at vbeDoEDID and follow the whole flow from there. First it does vm86 calls for checking if DDC is supported or not. After that it reads the EDID data using vm86 calls. - You can collect register states before and after vm86 calls. vm86() calls exits frequently for various reasons like signals, interrupts etc and it is restarted by 32bit userspace. I suspect in your env it might be exiting for some reason and returning with bad EDID. You shall have to track the control flow in case of success and failure. It's been a VERY long time since I ran the X server under gdb. I needed some clues, and although your
procedure did not work for me, I was able to come up with one that would.
Rather than building the X server the way you told me, I used the X server I'd built, and had been testing
with. I was able to run gdb on that X server by just doing
rpm -ivh xorg-x11-server-debuginfo-1.1.1-48.13.0.2.i386.rpm
which was the debuginfo necessary for the server I was already testing with.
When I tried to run xorg having started gdb as you instructed, I got the error:
Fatal server error:
Unrecognized option: --dumbSched
Program exited with code 01.
but restarting gdb without that argument resulted in an X server starting up and allowing itself
to be tested.
I put the breakpoint in vbeDoEDID
doing "p/x *ptr" didn't work for me, but "info registers" did.
I hit "n" to get up to the call to xf86ExecX86int10(pVbe->pInt10);
I did "info registers" before and after the call.
I have attached the output of this effort for the 2.6.18 kernel that breaks EDID, and the
2.6.21 kernel for which EDID is successful.
In both cases, the contents of the registers seems totally fine.
But in thinking this through, that should be no surprise. The problem is NOT that the registers
get corrupted inside the X server. The problem is that the registers get corrupted INSIDE THE KERNEL
when making the call to the audit subsystem inside the implementation of the int10 code.
When you say that, "it is reading EDID data from monitor over I2C/DDC" is it possible that that stuff
eventually does an int10 call in the kernel to fetch the data?
I call your attention to the simple patch to the 2.6.18 kernel that disables the call to audit from within
the int10 code in the kernel (which is in the original bug from which this bug is cloned):
https://bugzilla.redhat.com/attachment.cgi?id=158912
Although we cannot ship a kernel with that change, when you make that change, EDID transfers
magically become reliable on my system.
Bottom line:
We need to see what the register corruption is INSIDE THE KERNEL IMPLEMENTATION of the vm86 call.
Testing the registers in X will not help.
Any quess how we might instrument things inside the kernel without harming what we're already
doing? Perhaps this is a job for Xen? Can one single step a kernel from within an emulator?
Then again, this all might simply be an MMU race condition which manifested in 2.6.18, and is
back underground in 2.6.20 and later.
Created attachment 290211 [details]
register dump before and after vm86 call in X server. 2.6.18 kernel
Created attachment 290212 [details]
register dump before and after vm86 call in X server. 2.6.21 kernel
(In reply to comment #41) > > When you say that, "it is reading EDID data from monitor over I2C/DDC" is it possible that that stuff > eventually does an int10 call in the kernel to fetch the data? I don't think so. There is I2C protocol which reads the data. AFAIK, real mode bios services are not involved. (int10) > > Any quess how we might instrument things inside the kernel without harming what we're already > doing? Perhaps this is a job for Xen? Can one single step a kernel from within an emulator? > > Then again, this all might simply be an MMU race condition which manifested in 2.6.18, and is > back underground in 2.6.20 and later. Few things. - There are two kind of register states. One is 32bit register state and other is 16bit register state. 32bit register state belongs to the 32bit user space (actual Xorg server code running) and 16bit register state belongs to the real mode BIOS code executing. - 32bit user space, sets the 16bit registers (pInt->cpuRegs) and calls vm86(). This system call sets up various things and then starts executing real mode code. (Remember before doing that it creates the env using 16bit registers). If there is any interrupt, signal etc, real mode code is interrupted and control goes back to 32bit user space. Before returning to user space, kernel also passes the new state of real mode registers back to user space. - 32bit user space makes the vm86() call again with new 16bit register state and it goes on till the real mode code has completed. - If you do just "info registers", then it will give you 32bit register state. Primarily we are not interested in that as if something was wrong with it, user space would have most probably died. - We are interested in 16bit registers. A pointer to 16bit registers is stored in pInt->cpuRegs. - There are different ways of printing this register state depending on which function you are in and where you have put your break point. - You can also put two more break points. One on xf86ExecX86int10() and other on do_vm86(). - You can print real mode registers by using following. (If you are not in vm86_rep()) p/x *(struct vm86_struct*)pInt->cpuRegs - If you have stepped into the function vm86_rep() then you can use p/x *ptr - I think inspecting real mode registers in user space is easier. Even if kernel has corrupted it, we should see it in user space after the call has returned. Remember, vm86() is called thousands of time to finish one EDID retrieval. So you can sample registers in first few invocations and then after the last invocation. If vm86() finished earlier without completing EDID call successfully, we should notice the difference in register states. - I know that by getting rid of audit code, you don't see the problem. I browsed through the audit code quickly and can't find anything which plays around with 16bit register state. Secondly, same audit code is executed in RHEL5 PAE kernel which does not see the problem. So at this point of time it is difficult to conclude anything. Your observations of X using gdb should help though. Hmmmm... Putting a breakpoint in xf86ExecX86int10 tells me that said routine is called RATHER a lot.
You said put another on "do_vm86()" but gdb could not find that routine.
So what I did instead (and I hope this is close enough to what we need to do) was to repeat the
prodedure above (break at vbeDoEDID, and "n" up to the call to xf86ExecX86int10(pVbe->pInt10);
Then I asked to print: *(struct vm86_struct*)pVbe->pInt10->cpuRegs
before and after the call as follows:
(gdb) n
196 xf86ExecX86int10(pVbe->pInt10);
(gdb) p *(struct vm86_struct*)pVbe->pInt10->cpuRegs
$1 = {regs = {ebx = 0, ecx = 486, edx = 0, esi = 0, edi = 8192, ebp = 0,
eax = 79, __null_ds = 0, __null_es = -1069481984, __null_fs = 0,
__null_gs = 0, orig_eax = -1, eip = 1536, cs = 0, __csh = 0,
eflags = 209410, esp = 4096, ss = 256, __ssh = 0, es = 0, __esh = 0,
ds = 64, __dsh = 0, fs = 0, __fsh = 0, gs = 0, __gsh = 0}, flags = 0,
screen_bitmap = 0, cpu_type = 5, int_revectored = {__map = {4294967295,
4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295,
4294967295}}, int21_revectored = {__map = {4294967295, 4294967295,
4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295}}}
(gdb) n
198 if ((pVbe->pInt10->ax & 0xff) != 0x4f) {
(gdb) p *(struct vm86_struct*)pVbe->pInt10->cpuRegs
$2 = {regs = {ebx = 258, ecx = 0, edx = 0, esi = 0, edi = 0, ebp = 0,
eax = 79, __null_ds = 0, __null_es = -1069481984, __null_fs = 0,
__null_gs = 0, orig_eax = -1, eip = 1536, cs = 0, __csh = 0,
eflags = 209410, esp = 4096, ss = 256, __ssh = 0, es = 0, __esh = 0,
ds = 64, __dsh = 0, fs = 0, __fsh = 0, gs = 0, __gsh = 0}, flags = 0,
screen_bitmap = 0, cpu_type = 5, int_revectored = {__map = {4294967295,
4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295,
4294967295}}, int21_revectored = {__map = {4294967295, 4294967295,
4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295}}}
(gdb)
I confirmed that the EDID transfer was bad, and then repeated under the 2.6.21 kernel as follows:
(gdb) n
196 xf86ExecX86int10(pVbe->pInt10);
(gdb) p *(struct vm86_struct*)pVbe->pInt10->cpuRegs
$1 = {regs = {ebx = 0, ecx = 486, edx = 0, esi = 0, edi = 8192, ebp = 0,
eax = 79, __null_ds = 0, __null_es = 0, __null_fs = -1069481984,
__null_gs = 0, orig_eax = -1, eip = 1536, cs = 0, __csh = 0,
eflags = 209410, esp = 4096, ss = 256, __ssh = 0, es = 0, __esh = 0,
ds = 64, __dsh = 0, fs = 0, __fsh = 0, gs = 0, __gsh = 0}, flags = 0,
screen_bitmap = 0, cpu_type = 5, int_revectored = {__map = {4294967295,
4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295,
4294967295}}, int21_revectored = {__map = {4294967295, 4294967295,
4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295}}}
(gdb) n
198 if ((pVbe->pInt10->ax & 0xff) != 0x4f) {
(gdb) p *(struct vm86_struct*)pVbe->pInt10->cpuRegs
$2 = {regs = {ebx = 258, ecx = 0, edx = 0, esi = 0, edi = 0, ebp = 0,
eax = 79, __null_ds = 0, __null_es = 0, __null_fs = -1069481984,
__null_gs = 0, orig_eax = -1, eip = 1536, cs = 0, __csh = 0,
eflags = 209410, esp = 4096, ss = 256, __ssh = 0, es = 0, __esh = 0,
ds = 64, __dsh = 0, fs = 0, __fsh = 0, gs = 0, __gsh = 0}, flags = 0,
screen_bitmap = 0, cpu_type = 5, int_revectored = {__map = {4294967295,
4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295,
4294967295}}, int21_revectored = {__map = {4294967295, 4294967295,
4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295}}}
(gdb)
QUESTION: What do you make of these registers.
(In reply to comment #45) > Hmmmm... Putting a breakpoint in xf86ExecX86int10 tells me that said routine is called RATHER a lot. > You said put another on "do_vm86()" but gdb could not find that routine. You are using a version of Xorg compiled with -O2. I think compiler might have optimized and inlined this function that's why you don't find it. > > So what I did instead (and I hope this is close enough to what we need to do) was to repeat the > prodedure above (break at vbeDoEDID, and "n" up to the call to xf86ExecX86int10(pVbe->pInt10); > > Then I asked to print: *(struct vm86_struct*)pVbe->pInt10->cpuRegs > before and after the call as follows: This is close enough, at least the register state after the call has compledte. > > (gdb) n > 196 xf86ExecX86int10(pVbe->pInt10); > (gdb) p *(struct vm86_struct*)pVbe->pInt10->cpuRegs > $1 = {regs = {ebx = 0, ecx = 486, edx = 0, esi = 0, edi = 8192, ebp = 0, > eax = 79, __null_ds = 0, __null_es = -1069481984, __null_fs = 0, > __null_gs = 0, orig_eax = -1, eip = 1536, cs = 0, __csh = 0, > eflags = 209410, esp = 4096, ss = 256, __ssh = 0, es = 0, __esh = 0, > ds = 64, __dsh = 0, fs = 0, __fsh = 0, gs = 0, __gsh = 0}, flags = 0, > screen_bitmap = 0, cpu_type = 5, int_revectored = {__map = {4294967295, > 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, > 4294967295}}, int21_revectored = {__map = {4294967295, 4294967295, > 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295}}} > (gdb) n > 198 if ((pVbe->pInt10->ax & 0xff) != 0x4f) { > (gdb) p *(struct vm86_struct*)pVbe->pInt10->cpuRegs > $2 = {regs = {ebx = 258, ecx = 0, edx = 0, esi = 0, edi = 0, ebp = 0, > eax = 79, __null_ds = 0, __null_es = -1069481984, __null_fs = 0, > __null_gs = 0, orig_eax = -1, eip = 1536, cs = 0, __csh = 0, > eflags = 209410, esp = 4096, ss = 256, __ssh = 0, es = 0, __esh = 0, > ds = 64, __dsh = 0, fs = 0, __fsh = 0, gs = 0, __gsh = 0}, flags = 0, > screen_bitmap = 0, cpu_type = 5, int_revectored = {__map = {4294967295, > 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, > 4294967295}}, int21_revectored = {__map = {4294967295, 4294967295, > 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295}}} > (gdb) > > I confirmed that the EDID transfer was bad, and then repeated under the 2.6.21 kernel as follows: > > (gdb) n > 196 xf86ExecX86int10(pVbe->pInt10); > (gdb) p *(struct vm86_struct*)pVbe->pInt10->cpuRegs > $1 = {regs = {ebx = 0, ecx = 486, edx = 0, esi = 0, edi = 8192, ebp = 0, > eax = 79, __null_ds = 0, __null_es = 0, __null_fs = -1069481984, > __null_gs = 0, orig_eax = -1, eip = 1536, cs = 0, __csh = 0, > eflags = 209410, esp = 4096, ss = 256, __ssh = 0, es = 0, __esh = 0, > ds = 64, __dsh = 0, fs = 0, __fsh = 0, gs = 0, __gsh = 0}, flags = 0, > screen_bitmap = 0, cpu_type = 5, int_revectored = {__map = {4294967295, > 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, > 4294967295}}, int21_revectored = {__map = {4294967295, 4294967295, > 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295}}} > (gdb) n > 198 if ((pVbe->pInt10->ax & 0xff) != 0x4f) { > (gdb) p *(struct vm86_struct*)pVbe->pInt10->cpuRegs > $2 = {regs = {ebx = 258, ecx = 0, edx = 0, esi = 0, edi = 0, ebp = 0, > eax = 79, __null_ds = 0, __null_es = 0, __null_fs = -1069481984, > __null_gs = 0, orig_eax = -1, eip = 1536, cs = 0, __csh = 0, > eflags = 209410, esp = 4096, ss = 256, __ssh = 0, es = 0, __esh = 0, > ds = 64, __dsh = 0, fs = 0, __fsh = 0, gs = 0, __gsh = 0}, flags = 0, > screen_bitmap = 0, cpu_type = 5, int_revectored = {__map = {4294967295, > 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, > 4294967295}}, int21_revectored = {__map = {4294967295, 4294967295, > 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295}}} > (gdb) > > QUESTION: What do you make of these registers. As per your data, 16bit register states after the last call to vm86() are same both in case of failure (58.el5) and success. With this I would think that vm86() is not doing any register state corruption in el5 kernels. There is no error message also from real mode code. Otherwise some basic checks on eax registers would have failed. Following is the code doing checks. if ((pVbe->pInt10->ax & 0xff) != 0x4f) { xf86DrvMsgVerb(screen,X_INFO,3,"VESA VBE DDC invalid\n"); goto error; } switch (pVbe->pInt10->ax & 0xff00) { case 0x0: xf86DrvMsgVerb(screen,X_INFO,3,"VESA VBE DDC read successfully\n"); tmp = (unsigned char *)xnfalloc(128); memcpy(tmp,page,128); break; case 0x100: xf86DrvMsgVerb(screen,X_INFO,3,"VESA VBE DDC read failed\n"); break; default: xf86DrvMsgVerb(screen,X_INFO,3,"VESA VBE DDC unkown failure %i\n", pVbe->pInt10->ax & 0xff00); break; } William, I have backported the jermey's patch for RHEL5 (58.el5). Can you please apply this patch, rebuild and see if it works fine. If it is too much of trouble, I will build a binary package and send you. Please let me know. I have gone through jermey's patch and can't notice anything which can help. The only other change which I have done in this patch is to set fs and gs to zero before "jmp resume_userspace". I am just trying to cover up the possibility of audit code playing with fs and gs and that creating some problem. Created attachment 290461 [details]
Jermey's vm86 patch backport for RHEL5-58
Your patch succesfully built for me. Alas, the EDID transfer was bad with the resulting kernel. I think this may indeed mean that the fault lies not directly in the vm86 code, but in an un-related area of the kernel that changed at around 2.6.18-20 -- some sort of race condition when filling buffers with data fetched from real mode. (In reply to comment #49) > Your patch succesfully built for me. > Alas, the EDID transfer was bad with the resulting kernel. > > I think this may indeed mean that the fault lies not directly in the vm86 code, but in an un-related > area of the kernel that changed at around 2.6.18-20 -- some sort of race condition when filling buffers > with data fetched from real mode. > Hmm.., Looking at so many zeros in EDID buffer, one of the possibilities is that real mode gave up too early for some reason. I am looking at Xorg code and various exit/error paths but no clue yet. At many exit paths they dump the registers but I think you don't see any additional errors in your Xorg.0.log file. One interesting observation on my sytstem. I was comparing the final exit of read edid and Xorg vm86 call. - get-edid, exits the vm86() loop when control returns userspace because of in interrupt of vector 255. - Xorg exits the vm86() loop upon encountering a "hlt" instruction in real mode code. That's kind of confusing to me. I thought that both the software will exit at the same point after successful completion. But they seem to be taking differnt paths. ... The error checking through all that code is not very good. When I first began working this bug, the X server code ostensibly said that the EDID transfer was successful. Code that could have done basic checking of the contents of the buffer did nothing, and blithely continued to operate on garbage. I submitted an upstream patch to at least error out if the version number of the packet was bad. (That would detect the case of a buffer filled with all zeros.) There may be a checksum embedded in that buffer that could/should be checked, but alas, I was not well enough schooled in the EDID block. Bottom line: The anomaly you find in the two returns may indeed be significant. Perhaps further bench checking will identify where additional error checking code might have detected an abnormal return from real mode. William, Can you please apply the attached patch to xserver, recompile, install and then capture the Xorg logs both in failure and success case. I think this might give us some idea how the control is flowing in terms of how it returns to user space. I have generated the patches for xor-server-1.1.1-48.26.el5 Thanks Vivek Created attachment 290688 [details]
xorg debug patch1
Created attachment 291734 [details]
Log output with the additional debugging output patch.
Vivek, Sorry it took so long for me to comply with your request. Finally I have built an X server with your patch. (Note that I am running an ever so slightly older version: xorg-x11-server 1.1.1-48.13 Your patch went into that version just fine. I believe that there are no differences substantial enough between my version 48.13 and your 48.26 for me to blow away my existing comfy build setup. Attached is the Xorg.0.log output from running that server. What do you make of it? Created attachment 292069 [details]
Debugging output with later kernel and successful EDID transfer
OOPS! I see I didn't read your request carefully enough. Here is Xorg.0.log output from the debugging X server run under the later kernel that gives the successful EDID transfer. I used emacs ediff to make a quick scan for differences. Alas, I can't really detect any, but perhaps your more informed eye will pick something up. Could we do a check in on this bug.
I believe the summary of the situation is:
With the Radeon X1300 card under the VESA X driver, the EDID fetch of video modes from the BIOS is
flaky.
Originally we thought the flakiness was due to incorrect stack discipline when calling auditd from
inside the vbe calls to vm86.
We confirmed that the problem is not present in kernel rev 2.6.20 and later, and attempted back-
porting of likely code from 2.6.20 into 2.6.18.
Unfortunately the delta from 2.6.20 directly related to use of syscall_audit from the vm86 calls inside
vbe.c did not remedy the problem.
So the current situation is that we know there's a problem where the data that comes back from the
EDID read gets corrupted -- some or all of the buffer contains 0s. But we do not see what to back port
from 2.6.20 to end this corruption.
The current recommended work-around is to modify /etc/X11/xorg.conf:
In the"ServerLayout" section add a line:
Option "Int10Backend" "x86emu"
Perhaps all we can do now is to close this bug with WONTFIX because the corruption is too subtle
to identify and back-port.
Can someone re-confirm that this is our shared understanding of the situation, and either:
suggest something else for me to test to see if we've got a new candidate to back port into the
2.6.18 kernel, or
affirm that we should live with the situation as-is and close this bug out.
William, Sorry for not being able to get back to you for so long. Got stuck in other issues. I agree with your viewpoint. Initially it was thought that sys_vm86() system call implementation is wrong in RHEL5 and that is causing this. But at this point it does not look like the case. I have carefully reviewed the code, we have tried back-porting jermey's patch and we have also tried comparing the register states before and after the sys_vm86() call. At this point of time, we don't know what is causing corruption in certain instances. I would think of deferring this issue to 5.3 and till then live with x86emu option. Status update: Neither I nor anyone I've talked to about this bug has an idea where to look for the flaky EDID transfer root cause in the 2.6.18 kernel. It's not present in 2.6.20, but none of the obvious back ports remedied the problem. In the meantime, the radeon driver has made advances, handles the X1300 hardware and many other more recent ATI chips. I have tested this driver under RHEL 5.3 beta and found it to do a good job. It services the hardware and so we don't need to use the VESA driver or the deprecated BIOS interface to the kernel that is responsible for this flaky EDID transfer. We have a serviceable work-around, to use x86-emu, an emerging upstream driver that makes this code path irrelevant, and no insight into how to further debug this problem. I recommend that you CLOSE this bug with status WONTFIX. After speaking with one of the original reporters we have decided to close this BZ out as "WONTFIX". The problem is very elusive and a fix does not appear to be obvious. With the release of RHEL5.3 there will be a suitable and easy work-around for this issue (either via x86-emu and/or the included radeon driver). |