3

This one's baffled me. I have Ubuntu 14.04, 3 days ago (2014-20-10) it started slowing down.

I've reproduced it by opening gedit and then closing gedit, when the issue is active it hits roughly 2 seconds to close an empty file, whilst without the issue this is always instant - affects everything else in a similar manner.

top reports no unusual activity when the freeze occurs, htop the same, iotop the same as well.

The issue only arises after 30 minutes of uptime, I can guarantee that at 29mins of uptime I could not reproduce it, at 31 minutes of uptime I could reproduce this consistently (using above method, no apps started other than terminal and htop) and managed to repeat this 4 or 5 times (by shutting down, booting up and waiting half hour - which was enjoyable).

The issue persists even after reboots but can be reset by shutting down and powering back up, what part of Ubuntu holds state after reboots but not shutdowns?

Relevant logs for this period are syslog, auth.log and Xorg.0.log (by examining contents of /var/log for time modified in specified range)

syslog:

Oct 22 17:21:36 raiden NetworkManager[1102]: <warn> nl_recvmsgs() error: (-33) Dump inconsistency detected, interrupted
Oct 22 17:39:01 raiden CRON[3284]: (root) CMD (  [ -x /usr/lib/php5/maxlifetime ] && [ -x /usr/lib/php5/sessionclean ] && [ -d /var/lib/php5 ] && /usr/lib/php5/sessionclean /var/lib/php5 $(/usr/lib/php5/maxlifetime))
Oct 22 18:09:01 raiden CRON[3370]: (root) CMD (  [ -x /usr/lib/php5/maxlifetime ] && [ -x /usr/lib/php5/sessionclean ] && [ -d /var/lib/php5 ] && /usr/lib/php5/sessionclean /var/lib/php5 $(/usr/lib/php5/maxlifetime))

authlog:

Oct 22 17:39:01 raiden CRON[3283]: pam_unix(cron:session): session opened for user root by (uid=0)
Oct 22 17:39:01 raiden CRON[3283]: pam_unix(cron:session): session closed for user root
Oct 22 18:09:01 raiden CRON[3369]: pam_unix(cron:session): session opened for user root by (uid=0)
Oct 22 18:09:01 raiden CRON[3369]: pam_unix(cron:session): session closed for user root
Oct 22 18:17:01 raiden CRON[3495]: pam_unix(cron:session): session opened for user root by (uid=0)
Oct 22 18:17:01 raiden CRON[3495]: pam_unix(cron:session): session closed for user root

Xorg.0.log: (probably me just waking computer back up)

[  3466.727] (II) intel(0): switch to mode 1366x768@60.0 on LVDS1 using pipe 0, position (0, 900), rotation normal, reflection none
[  3466.880] (II) intel(0): switch to mode 1600x900@60.0 on VGA1 using pipe 1, position (0, 0), rotation normal, reflection none

None of those indicate anything bad and subsequent steps to reproduce the issue indicate no changes to the logs so these were most likely just innocent logs.

I presume there's 3 possible sources of this problem:

Software install: I installed something dodgy

I did:

  • history | grep apt-get' - no installs in that time period
  • Looked at synaptic package manager history - nothing in that time period
  • Software centre history - last update was several weeks before (there was a dependency issue so I hadn't done any updates in a while)
  • I installed Skype for Ubuntu around that time period but there's no indication it's caused by Skype (removed it anyway)

Cron job going wrong

Checked cronjobs in crontab, /etc/cron.d /etc/cron.daily and hourly nothing indicating it's something in there only a PHP cron job occurs every 30 minutes but if it were cron it would do it at certain points around the clock not 30 minutes after startup.

Analysing new processes that have been started between non-slowdown state and slowdown state suggest no new processes are started, (first test this showed up a kworker thread but this is likely to just be a coincidence). I presume this must mean it's either an existing process that triggered it or something else.

Malware

Due to it's elusiveness and the mysterious 30 min absence of the issue (30 minutes seems like a human-chosen amount of time) I began to think it could be some kind of malware however unlikely it could be (hadn't done an update for a while and have a few open ports). So ran rkhunter (rootkit finder) but nothing untoward was found.

Other things I've tried:

  • Unticking certain compiz components - no change
  • Restarting compiz - no change
  • Unticking all compiz components - no change (except for me wrestling to get the computer usable again)
  • Playing various musical instruments whilst waiting for uptime to get to 30 minutes and then watching the results of top and htop for any suspicious changes - nothing odd

Has anyone had anything similar to this happen to them or could point me in the right direction if you do I'll hit the up vote button repeatedly on your answer (I'll make sure it's an odd number)

  • So there was error with network manager in syslog that you posted. Try sudo service network-manager stop and wait those 30 mins or so and see if issue persists. If not - something is going on with network-manager. You said it also happens on boot and network manager is one of those services that actually start on boot – Sergiy Kolodyazhnyy Oct 23 '14 at 19:16
  • Thanks for the help, I've shut down the network manager as per your suggestion but to no avail, I did this when the issue was active. It's also worth noting that when I reproduced the issue again that log message wasn't there so it's possible it may not be that. – alex.p Oct 23 '14 at 19:37
  • Have you tried booting into another kernel ? – Sergiy Kolodyazhnyy Oct 23 '14 at 20:13
  • Nope that's a good call, I've booted into 3.13.0.36 was 3.13.0.37, I'll see what happens in half hour – alex.p Oct 23 '14 at 20:31
  • Same issue with older kernel – alex.p Oct 23 '14 at 20:57
1

There are some ways to configure cron to run a job 30 minutes after startup. Jenkins does that by hashing the function and using H/30 * * * * for example. It could also be a thread sleeping for 30 minutes and spawning a silent cpu killer process.

Some ideas there :

Did you try htop as root? Some processes may be invisible, I've seen this on Debian especially.

Did you try to logout / log back in when the issue occurs? Could be the window manager or a session problem.

If logout/login does not work, you can try to restart your session manager. I think it's lightdm by default so sudo service lightdm restart should do it.

| improve this answer | |
  • Thanks for the suggestions, logging in and out unfortunately retains the issue when it's occuring (post 30 mins after power up). Even rebooting will still cause the slowdown (don't have to wait 30 mins after a reboot), I'll try htop as root that's a good one I'll have to give it half hour. Yep it's lightdm, I'll give that a try as well. – alex.p Oct 23 '14 at 20:27
  • Tried rebooting lightdm but it just went to black screen so had to do a reboot. htop with root doesn't have anything interesting going on as well, when I'm doing nothing the cpu is pretty much at 0.1 - 0.5% cpu so it looks fine at idle, compiz seems to be the most demanding process but I've tried disabling compiz to no effect. – alex.p Oct 23 '14 at 21:49
  • All right, probably that you lost lightdm because it respawned in a different tty. Try ctrl + alt + F7 through F12 you should find it back. F1 to F6 are consoles and F7-F12 are graphical. Retry that I think it's worth it. After that you can try to kill lightdm with service lightdm stop, log in as root in tty1 and try to put ps aux in a file before, another file after and diff them to see if there is any unwanted process. So run ps aux > ps1.txt just before the slowdown, ps aux > ps2.txt and diff ps1.txt ps2.txt after the slowdown. Post the output to pastebin and link here. – Johnride Oct 23 '14 at 22:14
  • Ok well you've taught me something new there, didn't know those shortcuts corresponded to different ttys, thanks. This link pastebin.com/iLAAehGB shows the ps -aux diff between uptimes of 29m40s and 30m10s, so it should be guaranteed to be in the range of the issue occuring. I'm going to try and replicate the issue again and do another diff to see if the diffs have anything in common with the diff above. – alex.p Oct 24 '14 at 10:09
  • Oh yeah forgot to mention I tried shutting down light dm and then going back to the right graphical tty as you suggested but that still had the slowdown occurring unfortunately. – alex.p Oct 24 '14 at 10:22
0

This was caused by SMART data being enabled for the drive in question.

Disabling SMART data solved this :

sudo smartctl --smart=off /dev/sda

Presumably it kept rerunning some kind of internal self-test 30 minutes after the disk spun up and got into a loop; as this was at the hardware layer the rest of the computer was unaware of it going on hence I could see no process in particular responsible for IO blocking and no processes hogging resources.

| improve this answer | |

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.