Created attachment 138431 [details]
A photo of some of the kernel spew.
On my Fedora 27 Thinkpad T430, I have been unable to boot any of the 4.15.x kernels (4.14.18 and previous work just fine). The kernel crashes at the initial kms only 3s into the boot, before any logging to disk happens, making this one hard to provide information on. Adding "nomodeset" to the boot lets the boot process go further: but as soon as a buffer flush tries to write to the system disk, it hangs (so again, no syslog info beyond a string of ^@'s). kdump doesn't help: that needs to write to disk, and this bug seems to be taking out that ability as it flails.
Complicating matters further is that the screen's backlight is turned off at the start of the kms (in a normal boot it comes back on later), rendering console messages hard to read. Luckily, I found out that with an external monitor, it will eventually (a minute or two later) light up, resulting in the attached screenshot which points to the i915 driver.
The initial bug was posted at Fedora's bugzilla:
and they redirected me here (delayed by travel, sorry).
I see this Ubuntu bug, which shares a similar backtrace:
although my crash is not dependent on an external monitor.
Another similar backtrace is on your site here:
but that one doesn't seem fatal.
Ideas? bios update to the laptop didn't change anything. xorg update didn't change anything.
F27 is now on xorg-x11-drv-intel-2.99.917-31-20171025. All 4.15.x kernels they've put out do the same thing, the latest being 4.15.12-301
Thanks in advance - this has been bugging me for months, and all my usual debugging techniques have been stymied!
HI, can you try with latest drm-tip (https://cgit.freedesktop.org/drm-tip and please add drm.debug=14 module parameter, and attach dmesg from boot to reproducing the problem. Thanks.
Will try. Am not optimistic we'll get much, however, as the crash occurs before syslogd can write anything.
Created attachment 138444 [details]
dmesg from initial boot into single user mode
Created attachment 138445 [details]
dmesg from boot into runlevel 3 after ntfs filesystems removed
Created attachment 138446 [details]
dmesg including logging after X started
same boot as dmesg-booted.tx, but with some additional logging after X was started.
ok, boot success! First try fell into single user mode due to ntfs filesystems the drm-tip kernel didn't like. (the first dmesg attachement).
Commenting those out from fstab got me into runlevel three (the second dmesg attachment). X started just fine (I command line that using startx), additional debugging logs are appended (the 3rd dmesg file).
Note that it didn't crash, so these logs, as happy as I am to get them, don't illuminate the problem (although they surely have lots of info about the intel chip in the system with the problem!). Potential reasons include: Maybe 4.16 fixed the problem; or maybe the drm-tip kernel doesn't include some offending but of code running in the Fedora kernel (eg, it obviously doesn't have ntfs support enabled).
Narrowed down the possibilities: just fished the 4.16.0-rc7 rpms for f28 out of koji: same crash, same lack of any entries into /var/log/messages whilst doing so. So, the problem isn't fixed in the newer kernel: it them must be something that's in the Fedora kernel and not in the drm-tip kernel.
Ideas for how to narrow this down?
Jani, any advice here?
[ 3.562059] bbswitch: loading out-of-tree module taints kernel.
[ 3.562266] bbswitch: version 0.8
[ 3.562272] bbswitch: Found integrated VGA device 0000:00:02.0: \_SB_.PCI0.VID_
[ 3.562278] bbswitch: Found discrete VGA device 0000:01:00.0: \_SB_.PCI0.PEG_.VID_
[ 3.562286] ACPI Warning: \_SB.PCI0.PEG.VID._DSM: Argument #4 type mismatch - Found [Buffer], ACPI requires [Package] (20180105/nsarguments-100)
[ 3.562634] bbswitch: detected an Optimus _DSM function
[ 3.562644] pci 0000:01:00.0: enabling device (0000 -> 0003)
[ 3.562676] bbswitch: Succesfully loaded. Discrete card 0000:01:00.0 is on
Can you disable the discrete card and run without out-of-tree stuff?
Good idea Jani!
Removed bumblebee and the proprietary nvidia driver. This didn't fix things, but it did allow me to go further before things locked up. Including actual system logging!
Attached a dmesg output I got before things fell over. Upon booting, it seems the nouveau driver kms fails, then it falls over to i915. You can see nouveau initializing around 2.2 seconds in the log, then timing out at around 16 seconds. The first actual kernel crashes come later, starting with ieee80211 complaints. I was able to dmesg to a logfile and scp it away before things really unraveled. Hitting ctl-alt-del (all on console) induces a hard hang.
blacklisting nouveau and rebuilding the initfs, it's back to the original problem of not even booting happily. Disabling the discrete card in bios does not change this behavior. The tail of its problems again shows up eventually on my second monitor, looking similar to the initial attachments where drm_atomic_helper is timing out. Wait... as I type this it eventually got to single user mode, second dmesg dump retrieved before it hang (again on ctl-alt-del). But, dumping that to a text file didn't make it to disk, the crash didn't flush the disk write buffer :(
Created attachment 139108 [details]
dmesg from boot with nouveau instead of proprietary driver.
Slight correction - my first attempt to boot with discrete graphics enabled was foiled by there being a second bios setting that tries to autoset the graphics cards, despite me having just manually set it. REALLY forcing discrete graphics off got me back to the exact same "hang, doesn't write to syslog, but I could take a photo of it" problem as started this thread. Same kernel dump about ironlake and drm.
... and, to close the loop: 4.14.18 continues to work great (well, without bumblebee now, because it's uninstalled), as does windows 7 (dual-booted).
(In reply to Alec Habig from comment #11)
> Created attachment 139108 [details]
> dmesg from boot with nouveau instead of proprietary driver.
Please add drm.debug=14 module parameter to get detailed debugging, and get the dmesg again. The attached dmesg doesn't seem to have anything out of the ordinary in graphics, the only warns come from wifi.
ok. First, a note that yesterday and today's test were with kernel-4.15.17-300.fc27.x86_64
Couldn't get past a few seconds into the boot (the original failure mode) till I remembered that I'd taken the nouveau modules out of the initfs yesterday. Put it back, booted with drm.debug-14.
It certainly seems that without nouveau taking the hit for whatever goes wrong in the initial kms, things are toast. nouveau times out, hands off to i915, which finishes the kms. However, if there's no nouveau in the kernel, i915 fails the initial mode swich entirely.
Anyway, this boot went clear to runlevel 3 with no errors this time, so I logged on console as root, saved a dmesg (attached). Then exit'd from root's bash.... and things hung. A bit later these errors came to console:
pr 26 14:47:24 entropy kernel: [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out
Apr 26 14:47:24 entropy kernel: [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:47:pipe B] flip_done timed out
after which I leaned on the power switch to shut down.
Since it didn't go down cleanly, "journalctl -b -1" can't count its instances correctly. But, things did go to /var/log/messages this time, so the complete /var/log/messages for that session is also attached. To sync the two different time series, the dmesg ends around 14:44:44 in messages.
Created attachment 139146 [details]
dmesg from drm.debug=14 clean boot (which then hung after this log was copied...)
Created attachment 139147 [details]
/var/log/messages from that corresponding session, including an unfortunately sparse record of the actual hang. Last line in the dmesg corresponds to 14:44:44 in this full log.
There are similar issues seen on many bugs eg. on IVB: https://bugs.freedesktop.org/show_bug.cgi?id=104573.
Ville, any idea for those?
(In reply to Jani Saarinen from comment #18)
> There are similar issues seen on many bugs eg. on IVB:
> Ville, any idea for those?
Nothing similar about that AFAICT.
I also don't see an actual crash or hang here anyway. Sure, the display may be toast, but per the logs systemd gracefully shuts down on power button press. Can you ssh into the machine?
Finally, the Optimus stuff have always been a pain. Life suddenly feels too short when debugging issues with them. I know it sucks for you as a user, but please understand that they're really hard for us too. We only have control over one piece of the puzzle, without much clues of the whole.
sshing in let me continue to work on shell in the ssh session, after the console hung upon exiting. dmesg reports continued "flip timeout" errors as kms flails.
"shutdown -r now" at this point, although booting the ssh session promptly as expected, takes a few minutes to complete, seems to be waiting for the kms errors to complete. This clean boot did allow me to get a journalctl log of the whole process (will attach that).
I understand that optimus is a nasty mess. But, frustratingly, things work just fine with the fedora 4.14.* series, and just fine with your debugging tree kernel. As a user I suppose I can always go back to the bad old days of hand installing kernels rather than just loading them from the yum repository. Last time I did that regularly was going on 20 years ago :)
The fact that the errors happen with either fedora's 4.15.* tree or their 4.16 devel tree is telling us that something in the deltas they apply to their kernel build is the source of the problem. I suppose at this point, I go back to the original fedora bugzilla and put the ball back in their court? bisecting their configs and patches sounds like the next (tedious) step.
Before I go, though: what are these "flip timeout" errors? If I had to guess, any number of things horribly wrong in there could make the i915 module get into a funny state that eventually throws this error: but any insight as I move forward would be appreciated.
Created attachment 139175 [details]
full journalctl -b -1 -l dump obtained after being able to issue a clean reboot via sssh.
I just asked the Fedora bugzilla about what patches they're putting on to their rpms, and they suggested:
It's probably the opposite, there is something in the Free Desktop tree that
hasn't yet made it into Linus' tree. If you can narrow down which patch it is
we can bring it into Fedora.
Alec, any updates from you on this?
No update since the Fedora suggestion above.
How different is your development tree from the main kernel release?
Jani, like to comment or add something to https://01.org/linuxgraphics/gfx-docs/maintainer-tools/drm-intel.html?
Interesting development here. I decided to try the latest drm-tip (4.17.0-rc4) and see what happens. It died: but looking at it harder, it seems my working drm-tip (4.16.0-rc7) had a much simpler .config file. I think the difference is I compiled the new one as root, which picked up all the config settings from my currently running fedora 4.14 kernel, while doing it as a normal user for 4.16 did not.
Anyway - copying over the 4.16 .config into the 4.17 build area, and being conservative with all the new config optins the 4.17 build presents, it does boot again: although it does spend 30+seconds at the boot flailing: before succeeding rather than failing.
So: something in fedora's kernel config is triggering my problem. So I can try bisecting kernel options till I find the specific troublemaker. There are a lot of them though.
But: it's not just that. Hopefully the additional debugging info in the 4.17 dmesg (attached) offer clues. You can see the drm module having problems: I do not know the severity of the problems, just that it did the same "spend 30-odd seconds early in the boot timing out" problem as it does when it fails,even though it then succeeds (with a simpler .config).
Created attachment 139469 [details]
dmesg from a successful boot with drm-tip 4.17.0-rc4, and a simpler .config.
Per logs you have selftests enabled:
[ 0.377402] drm_mm: Testing DRM range manger (struct drm_mm), with random_seed=0x9292e37 max_iterations=8192 max_prime=128
[ 0.377756] drm_mm: igt_sanitycheck - ok!
[ 0.377962] igt_debug 0x0000000000000000-0x0000000000000200: 512: free
[ 0.377963] igt_debug 0x0000000000000200-0x0000000000000600: 1024: used
[ 0.377963] igt_debug 0x0000000000000600-0x0000000000000a00: 1024: free
[ 0.377964] igt_debug 0x0000000000000a00-0x0000000000000e00: 1024: used
[ 0.377965] igt_debug 0x0000000000000e00-0x0000000000001000: 512: free
[ 0.377966] igt_debug total: 4096, used 2048 free 2048
Yes, that self-test thing was the delay early in boot with the simply-configured drm-tip kernel. Thanks!
Working on testing various kernel configs to see which combination is the lethal one. This will take a while... (although less now that it boots faster :)
I don't know if this will help, but I have an old Centrino i5 mobile running 4.18.1 as a media pc and if I connect an external monitor and boot I get a hard crash of the PC. I managed to get a complete dmesg just before the hang.
This PC is intel only, not dual video.
I'm using this PC at the moment, on the external monitor which works fine if I plug it in after X has started.
I'll try to keep tabs on this thread.
This is a Gentoo install.
Alec, do you still have the boot failure?
I do: even with the current Fedora Kernel (4.17.19) and the latest Lenovo BIOS (which got updated recently, presumably for spectre mitigation). Just verified this when booting this morning (accidentally chose the wrong kernel in grub).
I have made little progress on narrowing down which kernel features cause the problem when enabled. Your vanilla testing kernel works, the same version of the fedora configured kernel does not. But there's a lot of parameter space to search, each "tweak/compile/boot/fail" iteration takes an hour, and this is the laptop I use for actual work. So slow progress :(
So since last week, kernel-4.18.7-100.fc27.x86_64 came out on the Fedora updates repo. Tried it just now in the process of looking at the next batch of options differences... and it didn't crash! And all the other drivers I need on this laptop are enabled (which wasn't the case with your drm-tip kernel).
Typing at you now in an X session while running the new kernel and its video modules.
Sometimes bigger numbers really are better :)
Will go read release notes and changelogs to see if there are clues to what might have changed (for the good this time), and update this bug for future reference if there's news.
ok, all's not wine and roses. When exiting X, it goes into the same style lockup as used to happen on boot. Which includes crashing so hard that often times (but not all the time) the BIOS can't find the boot disk after the next power cycle.
At least the bug moving further back in the chain means I can do some work, and investigate a running system. Thank goodness I didn't uninstall the (still happily working) kernel-4.14.18-300.fc27.x86_64
(In reply to Alec Habig from comment #36)
> ok, all's not wine and roses. When exiting X, it goes into the same style
> lockup as used to happen on boot. Which includes crashing so hard that
> often times (but not all the time) the BIOS can't find the boot disk after
> the next power cycle.
> At least the bug moving further back in the chain means I can do some work,
> and investigate a running system. Thank goodness I didn't uninstall the
> (still happily working) kernel-4.14.18-300.fc27.x86_64
Alec, sorry for the delay...
Do you have the dmesg from boot? Attached logs are old. Have you verified wtih latest drm-tip? Please attach the latest dmesg from boot with kernel parameters drm.debug=0x1e log_buf_len=4M.
Sorry for the long silence. Going has been slow: it takes a while to do a tweak/test/reboot/hang cycle. Especially since the disk controller gets munged upon the bug happening, even persisting across a power cycle (!) about 50% of the time (I have no idea how such a thing is even possible). And, this device is my "get work done" laptop, using the 4.14 kernel which is perfectly happy.
Anyway: tried a different approach. Threw in a spare disk, and tried a clean install of F29 and Kubuntu 18.04.1, in case cruft was to blame.
F29 installed from dvd... but the kernel installed to disk didn't boot once the first install pass finished.
Kubuntu's install dvd wouldn't even boot past the spinny "it's starting to boot" graphics screen.
In both cases, since things are "graphical boot" and "quiet", there's no feedback as to exactly what went wrong, and the system hangs too hard to switch to a different vtty, but it felt the same as the hangs described above.
Trying with the latest/last F27 kernel (yes, it's EOL now) 4.18.19-100, tried all permutations of integrated, discrete, and optimus bios settings, excluding nouveau drivers, and the nvidia proprietary blob. Sometimes it can get a clean boot - but then the sata controller goes out to lunch as soon as a write cache flush happens. Which makes me think the kms problem which started this thread is a symptom rather than the problem, just the one which usually triggers first. This is consistent with the problems getting log traces of the problems described above, because a lunched sata controller can't log errors.
Went back to drm-tip. See that it's kernel 5.0 now, cool.
This minimally configured kernel continues to work. I've enabled the extra features needed to run the laptop, no problems.
So: the bug is at the very least triggered by one of the (myriad) of enabled kernel options in the distro stock kernels. It feels to me like the old days of unprotected flat memory space where you could POKE random values into random addresses and watch the system fall apart: with the initial kms call being the most sensitive to it, and things unravel into thrashing the disk controller.
Parameter space is too vast for me to find the culprit with intermittent effort and a logging system that's often the first victim of the bug. So, I'm ready to punt, documenting this here in case someone else with more clues googles it is the only remaining thing I can do.
Time to just return to the 1990's and compile my own kernel :( At least git now makes tracking updates easier than it used to be in the Bad Old Days.
Just accidentally booted into fedora's 4.20.13-200.fc29.x86_64 (have been happily running the drm-tip)... and it worked!
Will try reading changelogs to get some clues.
nuts. Going to 4.20.15-200.fc29.x86_64 failed again... and backing up to 4.20.13-200 also failed. Tricked by a race condition into thinking that that version actually worked? Bad interaction with some other update applied since? Dunno.
drm-tip (now at 5.1-rc3) continues to work.
Fedora 29 is now at 5.0.5-200... yep, same problems as always.
Nothing in the changelogs lights me up as an obvious thing, but there's a lot there and I'm not a kernel expert.
At least I can compile my own from drm-tip's clean tree and get work done.
drm-tip works, nothing in dmesg to indicate failure. Pretty much the only way to get progress is to get a bisect result.
Alec, any updates here? Did you get any chance to bisect the results?
Priority is updated as the issue isn't in drmtip.
Bisecting is a manual process, since it's some option (or combination thereof) enabled in Fedora's .config that's the problem rather than a bad commit which git can help with.
You're right in that it's not drm-tip itself. In fact, while the original weirdness manifested itself in drm, it also trashed the disk controller. In the last couple stock fedora kernels (5.1.6 and 5.1.8), the problem has shifted to the keyboard controller (or maye it's usb, haven't disentabled it). So something in there is stomping on things it shouldn't, and for the longest time, that was the video driver.
Since I'm now pretty certain it's not your bug, closing this one is fine: I'll keep poking at it till I solve it, or until I finally upgrade this T430, whichever comes first :)
Closing this issue as NOTOUTBUG.