8086:27a2 [Dell Latitude D420] 13.04, lag under desktop environments

[Alan Pater]

A while after logging on, the system gets really slow. Menus and window movements take a while to respond, switching windows is slow, etc.

This is a regression, it was not like this using Ubuntu 12.10, it just started on 13.04. Tried different desktops (Unity, GnomeFaillback, Lxde). They all have the same issue.

Testing showed the issue is worsened by the TLP power management package.
TLP was installed in an attempt to resolve issue of fan running constantly.

ProblemType: Bug
DistroRelease: Ubuntu 13.04
Package: linux-image-3.8.0-23-generic 3.8.0-23.34
ProcVersionSignature: Ubuntu 3.8.0-23.34-generic 3.8.11
Uname: Linux 3.8.0-23-generic i686
ApportVersion: 2.9.2-0ubuntu8.1
Architecture: i386
AudioDevicesInUse:
 USER PID ACCESS COMMAND
 /dev/snd/controlC0: alan 2357 F.... pulseaudio
Date: Mon Jun 10 16:35:22 2013
HibernationDevice: RESUME=UUID=08003f81-dc4b-4697-adb9-c4f28291be17
InstallationDate: Installed on 2012-08-17 (297 days ago)
InstallationMedia: Ubuntu 12.10 "Quantal Quetzal" - Alpha i386 (20120724.2)
MachineType: Dell Inc. Latitude D420
MarkForUpload: True
PccardctlIdent:
 Socket 0:
   no product info available
PccardctlStatus:
 Socket 0:
   no card
ProcFB: 0 inteldrmfb
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-3.8.0-23-generic root=UUID=84ceb2d5-8fea-40c7-8d75-337c174735ce ro quiet splash vt.handoff=7
RelatedPackageVersions:
 linux-restricted-modules-3.8.0-23-generic N/A
 linux-backports-modules-3.8.0-23-generic N/A
 linux-firmware 1.106
RfKill:
 0: phy0: Wireless LAN
  Soft blocked: no
  Hard blocked: no
SourcePackage: linux
UpgradeStatus: Upgraded to raring on 2013-05-04 (37 days ago)
dmi.bios.date: 12/18/2006
dmi.bios.vendor: Dell Inc.
dmi.bios.version: A03
dmi.board.name: 0TJ984
dmi.board.vendor: Dell Inc.
dmi.chassis.type: 8
dmi.chassis.vendor: Dell Inc.
dmi.modalias: dmi:bvnDellInc.:bvrA03:bd12/18/2006:svnDellInc.:pnLatitudeD420:pvr:rvnDellInc.:rn0TJ984:rvr:cvnDellInc.:ct8:cvr:
dmi.product.name: Latitude D420
dmi.sys.vendor: Dell Inc.
---
ApportVersion: 2.12.5-0ubuntu2.1
Architecture: i386
AudioDevicesInUse:
 USER PID ACCESS COMMAND
 /dev/snd/controlC0: asp 1592 F.... pulseaudio
DistroRelease: Ubuntu 13.10
HibernationDevice: RESUME=UUID=08003f81-dc4b-4697-adb9-c4f28291be17
InstallationDate: Installed on 2013-12-06 (1 days ago)
InstallationMedia: Ubuntu 13.10 "Saucy Salamander" - Release i386 (20131016.1)
MachineType: Dell Inc. Latitude D420
MarkForUpload: True
Package: linux (not installed)
PccardctlIdent:
 Socket 0:
   no product info available
PccardctlStatus:
 Socket 0:
   no card
ProcFB: 0 inteldrmfb
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-3.11.0-14-generic root=UUID=ecd26c7d-0cb5-446e-a2ca-e4fefc0c0fd0 ro processor.ignore_ppc=1
ProcVersionSignature: Ubuntu 3.11.0-14.21-generic 3.11.7
RelatedPackageVersions:
 linux-restricted-modules-3.11.0-14-generic N/A
 linux-backports-modules-3.11.0-14-generic N/A
 linux-firmware 1.116
RfKill:
 0: phy0: Wireless LAN
  Soft blocked: no
  Hard blocked: no
Tags: saucy
Uname: Linux 3.11.0-14-generic i686
UpgradeStatus: No upgrade log present (probably fresh install)
UserGroups: adm cdrom dip lpadmin plugdev sambashare sudo
dmi.bios.date: 02/02/2008
dmi.bios.vendor: Dell Inc.
dmi.bios.version: A06
dmi.board.name: 0TJ984
dmi.board.vendor: Dell Inc.
dmi.chassis.type: 8
dmi.chassis.vendor: Dell Inc.
dmi.modalias: dmi:bvnDellInc.:bvrA06:bd02/02/2008:svnDellInc.:pnLatitudeD420:pvr:rvnDellInc.:rn0TJ984:rvr:cvnDellInc.:ct8:cvr:
dmi.product.name: Latitude D420
dmi.sys.vendor: Dell Inc.

[Brad Figg (brad-figg)]

This change was made by a bot.

[Joseph Salisbury (jsalisbury)]

Would it be possible for you to test the latest upstream stable kernel? Please test the latest v3.8 stable kernel[0].

If this bug is fixed in the mainline kernel, please add the following tag 'kernel-fixed-upstream'.

If the mainline kernel does not fix this bug, please add the tag: 'kernel-bug-exists-upstream'.

If you are unable to test the mainline kernel, for example it will not boot, please add the tag: 'kernel-unable-to-test-upstream'.
Once testing of the upstream kernel is complete, please mark this bug as "Confirmed".

Thanks in advance.

[0] http://kernel.ubuntu.com/~kernel-ppa/mainline/v3.8.13.2-raring/

[Alan Pater (alan-pater)]

I am now noticing that the 3.9 rc8 kernel does eventually display the same problem, it just takes a lot longer.

[Alan Pater (alan-pater)]

I've now tried 2 mainline kernels.

3.8.13-03081302-generic (v3.8.13.2-raring) dated 07-Jun-2013 is working well so far, no issues.

3.9 rc8 dated 21-Apr-2013 is problematic.

[Alan Pater (alan-pater)]

Also tried 3.10 rc5. That version also has issues.

The version which seems to be working ok is 3.8.13.

[Alan Pater (alan-pater)]

I seem to have hit the bug again using kernel 3.8.13.2. The web site which triggered it is

 http://www.theglobeandmail.com/news/news-video/understanding-rob-fords-relationship-with-to-police/article12559196/

[Joseph Salisbury (jsalisbury)]

So this issue does happen with the 3.8.13 kernel eventually, as well as the 3.9 and 3.10 kernels? If so, we can perform a bisect to identify the commit that introduced this in Raring.

[Alan Pater (alan-pater)]

The flashplugin was recently updated and I can't reproduce the issue. Where can i get the previous version of Flash?

Regardless, a buggy flash plugin should not, I think, affect the whole system. When the issue occured, a complete shutdown was needed to restore sanity. A simple restart did not help.

Once I can load a older flash plugin I can continue to test different kernels. For all I know, older kernels also have the issue, but were not triggered by the flash plugin at that time.

[Alan Pater (alan-pater)]

I can now trigger the problem viewing online video using the current flashplugin 11.2.202.291-0raring1

kernel versions which I have tried the last day or so and which have the problem:

   3.6.11-030611-generic
   3.8.0-25-generic
   3.8.13-03081302-generic

[Alan Pater (alan-pater)]

The latest kernel from saucy still has the problem.

   3.10.0-031000rc7-generic

[Alan Pater (alan-pater)]

Tried a couple of other kernels, but the problem remains.

3.4.50-030450-generic
3.8.0-25-lowlatency

So it looks like the issue has been there all along, but was not being triggered previous to Raring.

For now, I just purged the adobe Flash plugin as it does not really provide critical functionality for me.

[Alan Pater (alan-pater)]

The issue just got triggered by viewing several pdf forms in evince, so it's not just being triggered by flash videos.

[Alan Pater (alan-pater)]

I ran GtkPerf before and after triggering the problem.

Just after starting the computer running

~$ gtkperf -a

       Total time: 10.78

After triggering the issue by playing a movie via Totem, the system bogs down and gtkperf -a gives a result of:

        Total time: 96.63

The attached text file has more details.

[Alan Pater (alan-pater)]

Looks like a UXA versus SNA problem.

   https://wiki.ubuntu.com/X/Testing/IntelSNA

~$ grep "SNA init" /var/log/Xorg.0.log
[ 47.176] (II) intel(0): SNA initialized with gen3 backend

The default is SNA, which is fast, until something goes wrong, then it gets really slow.

If I start with UXA, it is slow from the beginning.

I assume that under 12.10, intel graphics was using UXA, and performance was reasonable.
Under 13.04, UXA is unusable. SNA is fast, but unstable.

[Chris Wilson (ickle)]

Let's start off with the basics: Xorg.0.log, dmesg and a system profile of what is happening when it is slow. And narrow down the complaint, for instance are the measurements you made in parallel with other system activity or after you shut them down?

Also please do try running these tests with a non-OpenGL compositor (i.e. not unity or gnome-shell) to rule out the lack of acceleration from mesa being a limiting factor.

[Alan Pater (alan-pater)]

Ok, triggered issue running Lubuntu.

Ran GtkPerf on a freash startup with no other apps running. Started Firefox, browsed news sites (guardian, bbc). Started Totem, played local video. Started Evince, opened local PDF form which triggered the issue.

Vidoe slows down and gets out of sync with audio. Moving desktop windows around becomes really slow. PDF scrolling is also very slow. Opening other sites in Firfox takes a long long time to load and script heavy pages pop up constant "unresponsive script" warnings.

Shut down Firefox, Totem, Evince. They are slow to respond to clicking on the X.

Ran GtkPerf again. Noticiably slower in everything.

Before, Total time: 8.91
After, Total time: 67.49

Again, this is all under Lubuntu, not Unity or Gnome Shell.

[Alan Pater (alan-pater)]

Perhaps unrelated, but I did find a couple of people having similiar issues:

   http://ubuntuforums.org/showthread.php?t=2147319
   https://bugs.launchpad.net/ubuntu/+source/xserver-xorg-video-intel/+bug/1188874

Though their workarounds did not do anything for me.

[Chris Wilson (ickle)]

That rules out the obvious causes such as GPU hangs. Is that reproduction script as simple as you can make it? i.e. does just loading firefox and browsing a single website enough to bring the system to its knees, or just totem etc?

Can you please 'apt-get install linux-tools xserver-xorg-core-dbg xserver-xorg-video-intel-dbg libpixman-1-0-dbg' (and probably a host more dbg difficult to tell what's going to be required) and then tell me what is consuming the most time in 'sudo perf top'.

Also noting the output of free before/after will be useful.

[Alan Pater (alan-pater)]

Reproducing the issue is somewhat random, so no, there is not a single website that consistently has triggered the problem, at least not since I purged Adobe Flash.

If I have some time later today, I'll re-install flash and the packages you suggest and see if I can reproduce the issue simply.

I have been watching "top" and "free" but have not seen anything unusual there, but will record before and after values for those as well.

[Chris Wilson (ickle)]

So the update-apt-index process is running? (just a quick glance at a normal top) Can you wait until the system is idle (may be upto 5 minutes on some systems) and remeasure?

[Alan Pater (alan-pater)]

Look's that way, doesn't it :-)

I'll retest a bit later, about to head out for the evening ...

[Chris Wilson (ickle)]

Hmm, perf is taking up quite a bit of time to unwind stuff, more that I would expect. But other than libc (likely memcpy/memmove, perhaps apt-get install libc6-dbg and check), the only danger sign is the presence of acpi_os_write.
Can you also look at sudo perf top --sort=dso (and install the dbg packages for the libraries you see there)?

[Chris Wilson (ickle)]

Hmm, perf top -U ?

[Alan Pater (alan-pater)]

This appeared in syslog. Does it mean anything?

Jul 4 16:26:09 loronegro kernel: [12868.528514] Uhhuh. NMI received for unknown reason 30 on CPU 0.
Jul 4 16:26:09 loronegro kernel: [12868.528525] Do you have a strange power saving mode enabled?
Jul 4 16:26:09 loronegro kernel: [12868.528530] Dazed and confused, but trying to continue
Jul 4 16:26:35 loronegro kernel: [12894.500170] Uhhuh. NMI received for unknown reason 30 on CPU 1.
Jul 4 16:26:35 loronegro kernel: [12894.500183] Do you have a strange power saving mode enabled?
Jul 4 16:26:35 loronegro kernel: [12894.500188] Dazed and confused, but trying to continue

and ...

Jul 4 16:43:34 loronegro kernel: [13913.303975] CE: hpet increased min_delta_ns to 20113 nsec
Jul 4 16:45:38 loronegro NetworkManager[1140]: <warn> nl_recvmsgs() error: (-33) Dump inconsistency detected, interrupted
Jul 4 16:52:20 loronegro NetworkManager[1140]: <warn> nl_recvmsgs() error: (-33) Dump inconsistency detected, interrupted

[Chris Wilson (ickle)]

The NMI error is a bug in that kernel's perf (iirc). I still haven't seen anything to suggest a reason for any slowdown. Must be as infuriating for you as it is for me.

Can you please watch top and sudo perf top whilst the system is idle and lightly loaded to learn the expected behaviour, then inspect the system during the slowdown to see what stands out? Just as important an observation would be that no extra CPU time is spent whilst slow.(Given the generation changing cpufreq can have dramatic impact upon the GPU.)

[Alan Pater (alan-pater)]

Chris, does it help knowing that it takes a complete shutdown and eventual restart to clear the issue? Neither a restart or a simple session logoff/logon helps.

I'm still not seeing anything unusual in the log files, top or perf top, but it's likely I'm not looking in the right spot ..

[Chris Wilson (ickle)]

So far I think we've established that it is not a rouge CPU hog that is blocking the system. Having to restart the system rather the session, also lends credence to that it is not a simple userspace or even gfx driver issue.

On the theory that the GPU goes nuts, download and build http://cgit.freedesktop.org/xorg/app/intel-gpu-tools/ (maybe apt-get install intel-gpu-tools if you feel lucky), then run intel_gpu_top. Except for running gtkperf etc, the GPU should be lightly loaded.

On the theory that the CPU goes nuts, apt-get install powertop latencytop, and run the pair of those looking for abnormalities. For powertop, the CPU should be waking up and hitting max frequency when busy and hitting C6+ when idle. latencytop should help identify what is taking time (not necessarily cpu cycles) to complete.

[Alan Pater (alan-pater)]

I'e already run intel_gpu_top and it did not go nuts when triggering the issue, it never went over ~25% then went right back down even though the system was still lagging like crazy.

Let's see what powertop & latencytop show ...

[Alan Pater (alan-pater)]

Triggered by opening a PDF form in Evince.

[Alan Pater (alan-pater)]

Found something interesting using cpufreq-info, cpu frequency gets stuck at lowest level.

On a fresh start:

  available frequency steps: 1.20 GHz, 800 MHz

  current policy: frequency should be within 800 MHz and 1.20 GHz.

After triggering the issue:

  available frequency steps: 1.20 GHz, 800 MHz

  current policy: frequency should be within 800 MHz and 800 MHz.

[Alan Pater (alan-pater)]

Bug #1174169 shows that others have run into the same thing. They mention that battery/AC has something to do with it. My laptop battery is completely dead, all my issues have occurred on AC, though with the dead battery still installed.

[Alan Pater (alan-pater)]

I fixed the cpufreq issue on this laptop. It was exaggerating the issue, but the problem remains.

[Alan Pater (alan-pater)]

No changes. The problem remains. I can't find anything in the logs indicating where the issue might be.

I tried a mainline kernel from http://kernel.ubuntu.com/~kernel-ppa/mainline/drm-intel-next/current/

  ~$ uname -r
       3.10.0-994-generic

No change. Problem remains.

----

Tried starting X in UXA mode instead of SNA.
No change. Problem remains.

---

Not sure where to go next ....

[Chris Wilson (ickle)]

Try with an older kernel, say v3.5. If it turns out to be a difference in kernels, try to find the last known good (and the first known bad) and begin a bisect. The results will be most illuminating.

[Alan Pater (alan-pater)]

Yeah, I've tried a bunch of kernels:

    3.4.50-030450-generic
 3.6.11-030611-generic
    3.8.0-25-generic
    3.8.0-25-lowlatency
 3.8.13-03081302-generic
 3.10.0-031000rc7-generic
 3.10.0-994-generic

I'm sure there was a 3.5. something as well, but I don't have a record of it.

What I find strange is that nothing is showing up in the logs. Any other bug I've come across has always verbalized itself sooner or later.

[Chris Wilson (ickle)]

To clarify, you experience the issue with kernels as far back as 3.4.50? If you can install a 3.2 that would be good to check.

Indeed that it does not present itself in any logs or as an obvious effect, is very worrying. If nothing in the kernel/userspace claims responsibility, then we have to look deeper still - hardware/firmware system management. Or in other words, I am out of ideas.

[Alan Pater (alan-pater)]

Thanks a lot for all your help Chris!

I'm testing all the hw on the machine to see if I can find out more. So far memtest86+, smart, & cpuburn have not turned up anything ...

[Alan Pater (alan-pater)]

Nothing showing up in hardware testing either.

Question. How to identify the cause of the problem being able to survive a reboot but not a shutdown?

[Alan Pater (alan-pater)]

Do all the "Bad" things in this screen mean anything?

[Chris Wilson (ickle)]

Not so "bad", just less than ideal. Though since that hw doesn't support runtime suspend, there isn't anything that can be done. It is certainly not the cause of the spontaneous slowdown. (At least that what's I think, a mere driver author!)

[Alan Pater (alan-pater)]

Ok, I think I am getting closer. I had TLP installed to handle power managment on the laptop. As part of my testing I purged that and the problem went away. Reinstalled TLP and the problem came back.

So it has something to do with how TLP is configuring power management ...

[Chris Wilson (ickle)]

It would be fascinating if you could dig a little into how TLP (what's the actual package called?) works. Being able to identify this in future would help me to help others.

[Alan Pater (alan-pater)]

From the horses mouth: "TLP is a power management tool for Linux. It brings you the benefits of advanced power management without the need to understand every technical detail.

TLP does not replace but enhance the existing power management of your Linux installation. TLP applies it's settings upon system startup and on every change of the power source."

http://linrunner.de/en/tlp/tlp.html

[Alan Pater (alan-pater)]

Another quantifier of the issue can be seen using hdparm.

On a fresh start, hdparm reports:

/dev/sda:
 Timing cached reads: 1740 MB in 2.00 seconds = 870.57 MB/sec
 Timing buffered disk reads: 64 MB in 3.04 seconds = 21.03 MB/sec

After triggering the issue:

/dev/sda1:
 Timing cached reads: 538 MB in 2.00 seconds = 269.10 MB/sec
 Timing buffered disk reads: 64 MB in 3.08 seconds = 20.79 MB/sec

[Chris Wilson (ickle)]

I would suggest going through the TLP configuration option and turning each one on individually to see which causes the slowdown (if it is indeed just one option). If you are really good, you can use a bisect on the config options.

[Alan Pater (alan-pater)]

It seems the TLP was not the main cause after all. I've purged TLP from the system, rebooted multiple times, and the issue still appears, just not as quickly.

[Alan Pater (alan-pater)]

However, given that TLP made it worse, could it be that some power management setting is doing something funky with the system cache as indicated with the hdparm -T result?

What I don't know and can't find to how to see what state the cache or memory are in.

[Alan Pater (alan-pater)]

With the bios update, it takes longer to trigger, but eventually, yes, the system slows down. Videos get out of sync, opening applications, moving windows, menus all get really slow.

~$ sudo dmidecode -s bios-version && sudo dmidecode -s bios-release-date
A06
02/02/2008

In an attempt to quantify, I run hdparm and gtkperf. They both show large losses in performance.

Before:
~$ gtkperf -a
Total time: 12.02

~$ sudo hdparm -tT /dev/sda
 Timing cached reads: 1674 MB in 2.00 seconds = 837.49 MB/sec
 Timing buffered disk reads: 64 MB in 3.11 seconds = 20.57 MB/sec

After:
~$ gtkperf -a
Total time: 40.88

~$ sudo hdparm -tT /dev/sda
 Timing cached reads: 442 MB in 2.00 seconds = 221.04 MB/sec
 Timing buffered disk reads: 62 MB in 3.05 seconds = 20.31 MB/sec

[Alan Pater (alan-pater)]

Yeah, I can try another kernel, but I don't see how that helps to identify the problem. Shouldn't there be some register or log showing what part of the system is getting out of sorts?

PS: After a long shutdown and restart, the problem reappeared within 15 minutes of starting. I noticed this time that the cpu temperature does NOT go up when the system is lagging. When performance is normal, cpu temperature goes up quite a bit.

~$ gtkperf -a
Total time: 108.74 (normal is around 10)

~$ sudo hdparm -tT /dev/sda
 Timing cached reads: 142 MB in 2.02 seconds = 70.45 MB/sec (normal is around 800)
 Timing buffered disk reads: 62 MB in 3.08 seconds = 20.14 MB/sec

[Alan Pater (alan-pater)]

Same problem with the new mainline kernel

-- Fresh start with new kernel --

~$ uname -a
 Linux loronegro 3.11.0-031100rc2-generic #201307211535 SMP Sun Jul 21 19:45:33 UTC 2013 i686 i686 i686 GNU/Linux

~$ gtkperf -a
 Total time: 14.87

~$ sudo hdparm -tT /dev/sda
 Timing cached reads: 1682 MB in 2.00 seconds = 841.29 MB/sec
 Timing buffered disk reads: 64 MB in 3.04 seconds = 21.02 MB/sec

-- After not having done much of anything, a bit of web browsing ---

~$ gtkperf -a
Total time: 68.36

~$ sudo hdparm -tT /dev/sda
 Timing cached reads: 244 MB in 2.01 seconds = 121.54 MB/sec
 Timing buffered disk reads: 64 MB in 3.05 seconds = 20.96 MB/sec

[Alan Pater (alan-pater)]

Worse with a really old kernel: 3.2.48-030248-generic

With that kernel, it only took 5 minutes of light web browsing for the system to totally bog down.

[Alan Pater (alan-pater)]

~$ uname -a
Linux loronegro 3.11.0-031100rc6-generic #201308181835 SMP Sun Aug 18 22:44:53 UTC 2013 i686 i686 i686 GNU/Linux

[Alan Pater (alan-pater)]

The latest updates seem to have triggered the issue, as well as displaying other artifacts. I now get some graphics corruption (attached) and, while watching a (html5) video on youtube (http://www.youtube.com/watch?v=0wp2qhoop9U), the whole system froze and the video audio went into some sort of skip mode.

I've been running in Pavlovian mode, without flash installed and somehow managing to avoid the conditions to trigger the issue, until today, when an update seems have found out how to trigger it all on it's own.

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[Alan Pater (alan-pater)]

apport information

[penalvch (penalvch)]

Alan Peter, sorry on confusingly toggling the (Ubuntu Saucy) task, as the development release is Trusty -> http://cdimage.ubuntu.com/daily-live/current/ . When you test it, please just make a comment on if it's reproducible or not, no need for further apport-collects at this point.