Comment 0 for bug 1272438

Revision history for this message
DimanNe (dimanne) wrote :

Steps to reproduce
Login as user1
Login as user2
Press Ctrl+Alt+F7 (to switch to first user)

kwin from second user starts to eat 100% of cpu.

Here is my investigation of what is going on

1) ====== GDB ======
I attached to running (and eating 100% of cpu) kwin, paused ("ctrl+c" command) and run ("continue" command) kwin several times and watched output of info threads command to figure out what thread is eating 100%.
What I got:

(gdb) info threads
  Id Target Id Frame
  3 Thread 0x7fa21ecb6700 (LWP 25128) "QProcessManager" 0x00007fa23f3c8de3 in select () at ../sysdeps/unix/syscall-template.S:81
  2 Thread 0x7fa21c9c6700 (LWP 25131) "kwin" pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
* 1 Thread 0x7fa23fbfe7c0 (LWP 25123) "kwin" 0x00007fa236ea7f84 in __GI___pthread_mutex_lock (mutex=0x2520918) at pthread_mutex_lock.c:54
(gdb) continue

// continue, wait some time, ctrl+c

(gdb) info threads
  Id Target Id Frame
  3 Thread 0x7fa21ecb6700 (LWP 25128) "QProcessManager" 0x00007fa23f3c8de3 in select () at ../sysdeps/unix/syscall-template.S:81
  2 Thread 0x7fa21c9c6700 (LWP 25131) "kwin" pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
* 1 Thread 0x7fa23fbfe7c0 (LWP 25123) "kwin" 0x00007fa23f3d1957 in __libc_recv (fd=9, buf=0x2520974, n=4096, flags=-1, flags@entry=0)
    at ../sysdeps/unix/sysv/linux/x86_64/recv.c:33

// continue, wait some time, ctrl+c

(gdb) info threads
  Id Target Id Frame
  3 Thread 0x7fa21ecb6700 (LWP 25128) "QProcessManager" 0x00007fa23f3c8de3 in select () at ../sysdeps/unix/syscall-template.S:81
  2 Thread 0x7fa21c9c6700 (LWP 25131) "kwin" pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
* 1 Thread 0x7fa23fbfe7c0 (LWP 25123) "kwin" 0x00007fa23f3c8de3 in select () at ../sysdeps/unix/syscall-template.S:81

and so on...

As you can see first thread is really doing something.

Now, when I know thread number I can see backtrace:
First backtrace
[Switching to thread 1 (Thread 0x7fa23fbfe7c0 (LWP 25123))]
#0 0x00007fa238b11303 in ?? () from /usr/lib/x86_64-linux-gnu/libQtGui.so.4
(gdb) backtrace
#0 0x00007fa238b11303 in ?? () from /usr/lib/x86_64-linux-gnu/libQtGui.so.4
#1 0x00007fa2396d05ef in QEventLoop::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#2 0x00007fa2396d08e5 in QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#3 0x00007fa2396d5e5b in QCoreApplication::exec() () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#4 0x00007fa23f719956 in kdemain () from /usr/lib/kde4/libkdeinit/libkdeinit4_kwin.so
#5 0x00007fa23f2f7de5 in __libc_start_main (main=0x4006d0, argc=3, ubp_av=0x7ffffe010848, init=<optimized out>, fini=<optimized out>,
    rtld_fini=<optimized out>, stack_end=0x7ffffe010838) at libc-start.c:260
#6 0x00000000004006fe in _start ()

// continue, wait some time, ctrl+c

And second one (after "continue" and "ctrl+c")
(gdb) backtrace
#0 0x00007fa23f3c8de3 in select () at ../sysdeps/unix/syscall-template.S:81
#1 0x00007fa2396fc33b in qt_safe_select(int, fd_set*, fd_set*, fd_set*, timeval const*) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#2 0x00007fa239701904 in QEventDispatcherUNIXPrivate::doSelect(QFlags<QEventLoop::ProcessEventsFlag>, timeval*) ()
   from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#3 0x00007fa239701d02 in QEventDispatcherUNIX::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) ()
   from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#4 0x00007fa238b112f6 in ?? () from /usr/lib/x86_64-linux-gnu/libQtGui.so.4
#5 0x00007fa2396d05ef in QEventLoop::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#6 0x00007fa2396d08e5 in QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#7 0x00007fa2396d5e5b in QCoreApplication::exec() () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#8 0x00007fa23f719956 in kdemain () from /usr/lib/kde4/libkdeinit/libkdeinit4_kwin.so
#9 0x00007fa23f2f7de5 in __libc_start_main (main=0x4006d0, argc=3, ubp_av=0x7ffffe010848, init=<optimized out>, fini=<optimized out>,
    rtld_fini=<optimized out>, stack_end=0x7ffffe010838) at libc-start.c:260
#10 0x00000000004006fe in _start ()
(gdb)

1) ====== strace ======
Now lets see which syscalls are called, I ran this command
strace -p 25123 -s 1000 -o strace1.txt
And in 1-2 seconds I got file (with 50000 lines) which contains ONLY these messages:

select(29, [4 5 9 10 14 28], [], [], {0, 0}) = 0 (Timeout)
recvfrom(9, 0x2520974, 4096, 0, 0, 0) = -1 EAGAIN (Resource temporarily unavailable)
select(29, [4 5 9 10 14 28], [], [], {0, 0}) = 0 (Timeout)
recvfrom(9, 0x2520974, 4096, 0, 0, 0) = -1 EAGAIN (Resource temporarily unavailable)
select(29, [4 5 9 10 14 28], [], [], {0, 0}) = 0 (Timeout)
recvfrom(9, 0x2520974, 4096, 0, 0, 0) = -1 EAGAIN (Resource temporarily unavailable)
select(29, [4 5 9 10 14 28], [], [], {0, 0}) = 0 (Timeout)
recvfrom(9, 0x2520974, 4096, 0, 0, 0) = -1 EAGAIN (Resource temporarily unavailable)
select(29, [4 5 9 10 14 28], [], [], {0, 0}) = 0 (Timeout)

Notice first argument of recvfrom - 9, this fd we already saw at gdb "info threads":
* 1 Thread 0x7fa23fbfe7c0 (LWP 25123) "kwin" 0x00007fa23f3d1957 in __libc_recv (fd=9, buf=0x2520974, n=4096, flags=-1,

ProblemType: Bug
DistroRelease: Ubuntu 13.10
Package: kde-window-manager 4:4.11.3-0ubuntu0.1
ProcVersionSignature: Ubuntu 3.11.0-15.23-generic 3.11.10
Uname: Linux 3.11.0-15-generic x86_64
NonfreeKernelModules: nvidia
ApportVersion: 2.12.5-0ubuntu2.2
Architecture: amd64
Date: Fri Jan 24 21:20:31 2014
InstallationDate: Installed on 2013-11-11 (74 days ago)
InstallationMedia: Kubuntu 13.10 "Saucy Salamander" - Release amd64 (20131016.1)
MarkForUpload: True
SourcePackage: kde-workspace
UpgradeStatus: No upgrade log present (probably fresh install)