Bug 231849

Summary: digikam wakes up 107 times per second (powertop)
Product: [Applications] digikam Reporter: Stefan Fleiter <stefan.fleiter+kdebugs>
Component: Preview-ImageAssignee: Digikam Developers <digikam-bugs-null>
Status: RESOLVED FIXED    
Severity: normal CC: caulier.gilles, marcel.wiesweg, mike, stefan.fleiter+kdebugs
Priority: NOR    
Version: 2.3.0   
Target Milestone: ---   
Platform: Ubuntu   
OS: Linux   
Latest Commit: Version Fixed In: 5.1.0
Sentry Crash Report:
Attachments: strace of digikam running at pid 5292

Description Stefan Fleiter 2010-03-22 23:15:42 UTC
Version:           1.1.0 (using KDE 4.4.1)
OS:                Linux
Installed from:    Ubuntu Packages

digikam wakes up the cpu more than 100 times per second
without any user activity.
There are no special steps to reproduce, simply start digikam.

That makes digikam almost unusable on laptops when running on battery.

I will attach a strace log which shows it does busy waiting
by means of select and poll and does read from a file descriptor (7)
which points to a unix domain socket in spite of the fact that
the matching poll returned with a timeout.

# ls -l /proc/3182/fd/7
lrwx------ 1 me me 64 2010-03-22 22:25 /proc/3182/fd/7 -> socket:[33307]
# lsof | grep 33307
digikam   3182        me    7u     unix 0xffff8800df785200      0t0    33307 socket


Here the powertop output:

# sudo powertop -d
PowerTOP 1.12   (C) 2007, 2008 Intel Corporation 

Collecting data for 15 seconds 


Cn                Avg residency
C0 (cpu running)        (10.9%)
polling           0.0ms ( 0.0%)
C1 mwait          0.0ms ( 0.0%)
C2 mwait          0.1ms ( 0.2%)
C4 mwait          1.8ms (88.9%)
P-states (frequencies)
Turbo Mode     4.3%
  2.21 Ghz     0.0%
  1.60 Ghz     0.1%
  1200 Mhz     0.1%
   800 Mhz    95.5%
Wakeups-from-idle per second : 495.4    interval: 15.0s
no ACPI power usage estimate available
Top causes for wakeups:
  29.7% (232.7)   [Rescheduling interrupts] <kernel IPI>
  16.9% (132.6)   firefox-bin
  13.7% (107.1)   digikam
  12.5% ( 98.1)   [extra timer interrupt]
  10.7% ( 83.9)   [kernel scheduler] Load balancing tick
Comment 1 Stefan Fleiter 2010-03-22 23:20:17 UTC
Created attachment 42191 [details]
strace of digikam running at pid 5292
Comment 2 Stefan Fleiter 2010-03-22 23:48:22 UTC
The pid of digikam changed when capturing the strace output because I had to restart digikam. New pid is 5292.
Comment 3 Marcel Wiesweg 2010-03-24 19:41:56 UTC
#0  __poll (fds=0x7c534b0, nfds=20, timeout=0) at ../sysdeps/unix/sysv/linux/poll.c:69
#1  0x00007fffed27258c in ?? () from /usr/lib64/libglib-2.0.so.0
#2  0x00007fffed2728d0 in g_main_context_iteration () from /usr/lib64/libglib-2.0.so.0
#3  0x00007ffff17cdeb3 in QEventDispatcherGlib::processEvents (this=0xab6500, flags=<value optimized out>)
    at kernel/qeventdispatcher_glib.cpp:412

#0  __poll (fds=0x7fffffffc920, nfds=1, timeout=-1) at ../sysdeps/unix/sysv/linux/poll.c:69          
#1  0x00007fffe8ca191a in ?? () from /usr/lib64/libxcb.so.1                                          
#2  0x00007fffe8ca1e57 in ?? () from /usr/lib64/libxcb.so.1                                          
#3  0x00007fffe8ca2115 in xcb_writev () from /usr/lib64/libxcb.so.1                                  
#4  0x00007fffefb5203a in _XSend () from /usr/lib64/libX11.so.6                                      
#5  0x00007fffefb52561 in _XEventsQueued () from /usr/lib64/libX11.so.6                              
#6  0x00007fffefb3b24b in XEventsQueued () from /usr/lib64/libX11.so.6
#7  0x00007ffff2727747 in x11EventSourcePrepare (s=0xaf3140, timeout=<value optimized out>) at kernel/qguieventdispatcher_glib.cpp:79
#8  0x00007fffed271fca in g_main_context_prepare () from /usr/lib64/libglib-2.0.so.0
#9  0x00007fffed2723a1 in ?? () from /usr/lib64/libglib-2.0.so.0
#10 0x00007fffed2728d0 in g_main_context_iteration () from /usr/lib64/libglib-2.0.so.0
#11 0x00007ffff17cdeb3 in QEventDispatcherGlib::processEvents (this=0xab6500, flags=<value optimized out>)
    at kernel/qeventdispatcher_glib.cpp:412

#0  __poll (fds=0x7fffce984eb0, nfds=1, timeout=333) at ../sysdeps/unix/sysv/linux/poll.c:69          
#1  0x00007fffce98bc4e in ao_alsa_handle_event_thread () from /usr/lib64/xine/plugins/1.27/xineplug_ao_out_alsa.so
#2  0x00007ffff142165d in start_thread (arg=<value optimized out>) at pthread_create.c:297                        
#3  0x00007ffff079f14d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112                               
#4  0x0000000000000000 in ?? ()                                                                                   

I got these three backtraces for poll. So it's either Glib, Xlibs or Xine/Alsa.
Not too much we can do about this.
Comment 4 Stefan Fleiter 2010-03-24 19:55:25 UTC
Thanks for collecting these backtraces.
From my other experiences with those bugs I assume that it might be xine which does this.

If it indeed was xine wouldn't it help to lazy initialize it when it is needed for playing some sound?
That way you could at least look at your photos without wasting energy.
Comment 5 caulier.gilles 2010-03-25 08:19:05 UTC
digiKam use KDE4 Phonon component to play video files, which use Xine as backend...

Gilles Caulier
Comment 6 caulier.gilles 2011-12-12 20:41:31 UTC
Stefan,

This entry still valid using digiKam 2.x ?

Gilles Caulier
Comment 7 Michael G. Hansen 2011-12-13 20:04:39 UTC
Still valid under digikam 2.3 running under KDE 4.7 on debian experimental. powertop reports about 100 wakeups per second.

Michael
Comment 8 Stefan Fleiter 2011-12-13 21:33:38 UTC
With Phonon configured with Gstreamer I have the following numers for wakeups/second:

Before starting digikam: 80-90
With running digikam playing video: 260-270
With running digikam (after playing video): 120-130 (powertop can releate 20 Wakeups/second directly to digikam)
Comment 9 Marcel Wiesweg 2011-12-24 16:54:03 UTC
Does powertop give us any clue (backtrace) from where the wakeups happen?
Comment 10 Stefan Fleiter 2011-12-25 20:18:31 UTC
AFAIK there is no possibility to get a backtrace from powertop.
If you have any information how to get a backtrace please provide a pointer
and I will try to provide it.
Comment 11 caulier.gilles 2011-12-25 20:32:56 UTC
Stefan,

Run digiKam through gdb like this :

http://www.digikam.org/drupal/contrib

Note : Don't forget to install digiKam debug package to see backtrace with GDB

Gilles Caulier
Comment 12 Marcel Wiesweg 2011-12-26 21:41:23 UTC
You made some analysis with a strace output above, at the time still using Xine. Now we all use GStreamer. Can you still pinpoint which of select or poll is the culprit?
Sometime callgrind logs can be (ab)used to find out which method calls which
Comment 13 caulier.gilles 2013-11-25 12:57:11 UTC
This entry still valid using digiKam 3.5.0 ?

Gilles Caulier
Comment 14 caulier.gilles 2014-08-21 21:57:33 UTC
We need a fresh feedback about this entry...

Gilles Caulier
Comment 15 caulier.gilles 2015-06-28 09:41:39 UTC
New digiKam 4.11.0 is available :

https://www.digikam.org/node/740

Can you reproduce the problem with this release ?

Gilles Caulier
Comment 16 caulier.gilles 2015-08-22 06:38:21 UTC
digiKam 4.12.0 is out :

https://www.digikam.org/node/741

We need a fresh feedback using this release please...
Thanks in advance.
Comment 17 caulier.gilles 2016-07-15 12:53:21 UTC
With digiKam 5.0.0, this problem is not reproducible.
I close this file now. Don't hesitate to re-open if necessary.
Gilles Caulier