yshui / picom

A lightweight compositor for X11 with animation support
https://picom.app/
Other
4.14k stars 588 forks source link

higher power consumption on experimental backend #341

Open aspieln3r opened 4 years ago

aspieln3r commented 4 years ago

Platform: Arch linux amd64

GPU, drivers, and screen setup: Intel UHD Graphics 620, laptop

picom version: 7.5-3

picom configuration: https://pastebin.com/drbGcGry

Steps of reproduction

run picom with --experimental-backends see iotop picom is frequently on top issue is not present without --experimental-backends

Expected behavior

no changes on io load on both run modes

Current Behavior & Other details

Image of iotop

yshui commented 4 years ago

Why do you think this is problematic? Looks like it's not doing any disk reads or writes.

absolutelynothelix commented 4 years ago

@yshui, take a look at io percentage

i noticed that it really constantly on top but uses only 0.3%, but when performing some actions it jumps to 20-30%. i tried to capture a screenshot and launched maim and io percentage increased to 20%. it also increases when moving/resizing windows. i think it could be a false positive since picom (compositor) is kinda... proxying? a lot of information (textures, windows info's, etc.). but there is no issue without experimental backends, it's a fact.

image

edit: i attached strace to picom and i see a lot of ioctl calls to a video driver (according to command passed to ioctl) and i think it's could be considered as io? but there is a lot of ioctl calls both on experimental and non-experimental backends.

absolutelynothelix commented 4 years ago

ok, i did a little test what old backends do most and what new backends do most. i created two script with only difference:

# old.sh: launch picom with old backends with strace attached and pipe strace output to old.log
# new.sh: launch picom with new backends with strace attached and pipe strace output to new.log
strace picom 2> old.log &
# wait a little till picom initializes
sleep 1
# launch screenshot command  i have bound to prnscr in background which causes io percentage to grow
maim -qsu | xclip -selection clipboard -t image/png &
# wait 5 seconds
sleep 5 
# kill picom
killall picom
# kill maim 
killall maim 

then i analyzed both logs with a quickly written script to see call statistics:

old.log:
getpid  4817
poll    4001
recvmsg 3461
ioctl   3298
writev  2283

new.log:
ioctl   18389
getpid  7291
recvmsg 2569
poll    1817
writev  1172

experimental backends are calling ioctl more often.

hey, i have an idea. we both have intel graphics uhd 620. could this be a driver issue? because ioctl talks to the i915 driver according to command passed to it.

aspieln3r commented 4 years ago

Why do you think this is problematic? Looks like it's not doing any disk reads or writes.

can this cause high power consumption? because I noticed this while trying to find whom to blame for eating my battery and powertop was not helping much with per process power consumption data. It was giving me false data.

yshui commented 4 years ago

@aspieln3r powertop is the best tool for this in my knowledge, if that's not helping you figuring out the power consumption, it is even less likely iotop will.

aspieln3r commented 4 years ago

@yshui see attached powerstat data with and without picom , picom --experimental-backends when total consumption was around 4W, powertop was blaming my mouse for consuming 3W and unplugging mouse didnt make a dent in total consumption and powertop choose to shift blame to backlight. GPU idle stats on powertop reports zero on all fields and GPU ops per sec is zero no matter what. I have seen users reporting similar issues in archlinux forums and probably it is a linux on laptop issue. anyways,

measurements are made while running kitty and picom only, without moving windows or doing any other work.

picom -b

>> sudo powerstat 2 -d 20 -gcz
[sudo] password : 
Running for 460.0 seconds (230 samples at 2.0 second intervals).
Power measurements will start in 20 seconds time.

  Time    User  Nice   Sys  Idle    IO  Run Ctxt/s  IRQ/s Fork Exec Exit  Watts   GPU W
08:36:32   0.2   0.0   0.1  99.7   0.0    2    538    291    0    0    0   4.08    0.62
08:36:34   0.2   0.0   0.1  99.7   0.0    1   1686    798    0    0    0   4.09    0.62
08:36:36   0.1   0.0   0.3  99.7   0.0    1   1692    780    0    0    0   4.12    0.60
08:36:38   0.0   0.0   0.1  99.9   0.0    1    462    266    0    0    0   4.04    0.59
08:36:40   0.0   0.0   0.1  99.9   0.0    1    580    307    0    0    0   4.09    0.58
08:36:42   0.1   0.0   0.3  99.7   0.0    1    564    298    0    0    0   4.16    0.61
08:36:44   0.2   0.0   0.1  99.7   0.0    1    466    316    0    0    0   4.00    0.59
08:36:46   0.1   0.0   0.1  99.8   0.0    1    340    332    0    0    0   3.86    0.56
08:36:48   0.0   0.0   0.0 100.0   0.0    1    274    258    0    0    0   3.86    0.56
08:36:50   0.0   0.0   0.1  99.9   0.0    1    256    203    0    0    0   3.85    0.55
08:36:52   0.1   0.0   0.2  99.7   0.0    1    482    292    1    0    1   4.18    0.61
08:36:54   0.0   0.0   0.1  99.9   0.0    1    306    184    0    0    0   3.85    0.58
08:36:56   0.1   0.0   0.2  99.8   0.0    1    278    172    0    0    0   3.85    0.56
08:36:58   0.0   0.0   0.0 100.0   0.0    1    310    172    0    0    0   3.86    0.56
08:37:00   0.0   0.0   0.0 100.0   0.0    1    354    184    0    0    0   3.95    0.58
08:37:02   0.0   0.0   0.0 100.0   0.0    1    318    180    0    0    0   3.88    0.58
08:37:04   0.1   0.0   0.0  99.9   0.0    1    384    196    0    0    0   3.93    0.59
08:37:06   0.1   0.0   0.1  99.8   0.0    1    270    178    0    0    0   3.88    0.52
08:37:08   0.1   0.0   0.0  99.9   0.0    1    294    176    0    0    0   3.86    0.52
08:37:10   0.0   0.0   0.1  99.9   0.0    1    302    167    0    0    0   3.93    0.53
08:37:12   0.0   0.0   0.0 100.0   0.0    1    290    156    0    0    0   3.87    0.53
08:37:14   0.1   0.0   0.0  99.9   0.0    1    309    172    0    0    0   3.86    0.53
08:37:16   0.1   0.0   0.1  99.9   0.0    1    342    202    0    0    0   3.90    0.54
08:37:18   0.1   0.0   0.0  99.9   0.0    1    262    152    0    0    0   3.87    0.56
08:37:20   0.1   0.0   0.1  99.9   0.0    1    279    154    0    0    0   3.72    0.56
08:37:22   0.2   0.0   0.1  99.6   0.1    1    496    236    0    0    0   4.02    0.58
08:37:24   0.1   0.0   0.1  99.9   0.0    1    304    172    0    0    0   3.72    0.57
08:37:26   0.1   0.0   0.1  99.9   0.0    1    262    147    0    0    0   3.73    0.54
^C-------- ----- ----- ----- ----- ----- ---- ------ ------ ---- ---- ---- ------  ------
 Average   0.1   0.0   0.1  99.9   0.0  1.0  453.6  255.0  0.0  0.0  0.0   3.93    0.57
 GeoMean   0.0   0.0   0.0  99.9   0.0  1.0  387.7  227.5  0.0  0.0  0.0   3.93    0.57
  StdDev   0.1   0.0   0.1   0.1   0.0  0.2  356.1  158.3  0.2  0.0  0.2   0.12    0.03
-------- ----- ----- ----- ----- ----- ---- ------ ------ ---- ---- ---- ------  ------
 Minimum   0.0   0.0   0.0  99.6   0.0  1.0  255.5  147.0  0.0  0.0  0.0   3.72    0.52
 Maximum   0.2   0.0   0.3 100.0   0.1  2.0 1691.5  798.0  1.0  0.0  1.0   4.18    0.62
-------- ----- ----- ----- ----- ----- ---- ------ ------ ---- ---- ---- ------  ------
Summary:
System:   3.93 Watts on average with standard deviation 0.12  
GPU:   0.57 Watts on average with standard deviation 0.03  

C-State    Resident      Count Latency 
C10         96.380%      10626     890
C9           0.004%          7     480
C8           1.876%       3266     200
C7s          0.003%         10     124
C6           0.132%        853      85
C3           0.013%        711      70
C1E          1.296%       3206      10
C1           0.071%        250       2
POLL         0.000%         23       0
C0           0.224%

picom -b --experimental-backends

 >> sudo powerstat 2 -d 40 -gcz     
Running for 440.0 seconds (220 samples at 2.0 second intervals).
Power measurements will start in 40 seconds time.

  Time    User  Nice   Sys  Idle    IO  Run Ctxt/s  IRQ/s Fork Exec Exit  Watts   GPU W
08:40:14   0.1   0.0   0.0  99.9   0.1    1    288    153    0    0    0   8.17    2.46
08:40:16   0.0   0.0   0.0  99.9   0.1    1    308    170    0    0    0   8.27    2.44
08:40:18   0.0   0.0   0.1  99.9   0.0    1    296    168    0    0    0   8.24    2.45
08:40:20   0.1   0.0   0.0  99.8   0.1    1    294    166    0    0    0   8.21    2.41
08:40:22   0.1   0.0   0.1  99.8   0.1    1    310    176    0    0    0   8.30    2.43
08:40:24   0.0   0.0   0.0  99.9   0.1    1    309    165    0    0    0   8.28    2.40
08:40:26   0.0   0.0   0.0 100.0   0.0    1    293    172    0    0    0   8.36    2.45
08:40:28   0.1   0.0   0.0  99.8   0.1    1    340    190    0    0    0   6.91    1.77
08:40:30   0.1   0.0   0.1  99.8   0.1    1    308    176    0    0    0   8.06    2.25
08:40:32   0.0   0.0   0.0  99.9   0.1    1    300    177    0    0    0   8.20    2.24
08:40:34   0.0   0.0   0.0  99.9   0.1    1    298    177    0    0    0   8.30    2.28
08:40:36   0.1   0.0   0.1  99.6   0.2    1    404    212    0    0    0   8.74    2.60
08:40:38   0.1   0.0   0.0  99.8   0.1    1    302    181    0    0    0   8.24    2.28
08:40:40   0.0   0.0   0.0  99.9   0.1    1    386    287    2    0   14   7.99    1.97
08:40:42   0.1   0.0   0.0  99.9   0.0    1    313    181    0    0    0   9.71    4.07
08:40:44   0.0   0.0   0.1  99.7   0.1    1    458    234    0    0    1   8.27    2.31
08:40:46   0.0   0.0   0.2  99.6   0.2    1    338    208    0    0    0   7.50    1.84
08:40:48   0.1   0.0   0.0  99.9   0.0    1    300    184    0    0    0   8.03    2.12
08:40:50   0.1   0.0   0.1  99.6   0.2    1    387    250    1    0    1   8.10    2.19
08:40:52   0.1   0.0   0.1  99.6   0.3    1    354    218    0    0    0   7.64    1.84
08:40:54   0.0   0.0   0.0  99.9   0.1    1    290    165    0    0    0   8.16    2.07
08:40:56   0.1   0.0   0.1  99.7   0.1    1    380    222    3    3    3   7.19    2.12
08:40:58   0.1   0.0   0.0  99.9   0.1    1    308    184    0    0    0   8.29    2.11
08:41:00   0.0   0.0   0.1  99.9   0.1    1    302    195    0    0    0   8.22    1.97
08:41:02   0.1   0.0   0.1  99.7   0.1    1    310    177    0    0    2   5.72    1.62
08:41:04   0.1   0.0   0.0  99.9   0.1    1    340    193    0    0    0   9.78    4.09
08:41:06   0.3   0.0   0.1  99.2   0.4    1    418    212    0    0    0   4.53    0.87
08:41:08   0.1   0.0   0.0  99.7   0.3    1    346    202    0    0    0   6.65    1.93
08:41:10   0.2   0.0   0.1  99.5   0.2    1    360    218    0    0    0   6.42    1.90
08:41:12   0.0   0.0   0.0 100.0   0.0    1    328    198    0    0    2   9.72    4.11
08:41:14   0.1   0.0   0.2  99.3   0.4    1    318    204    0    0    0   4.30    0.81
08:41:16   0.1   0.0   0.1  99.8   0.1    1    323    186    0    0    0   9.72    4.11
08:41:18   0.0   0.0   0.0  99.9   0.1    1    264    157    0    0    0   4.29    0.80
08:41:20   0.0   0.0   0.1  99.9   0.1    1    322    183    0    0    0   9.71    4.14
08:41:22   0.0   0.0   0.0  99.9   0.1    1    306    176    0    0    0   4.20    0.75
08:41:24   0.0   0.0   0.1  99.8   0.1    1    332    182    0    0    0   9.68    4.10
^C-------- ----- ----- ----- ----- ----- ---- ------ ------ ---- ---- ---- ------  ------
 Average   0.1   0.0   0.0  99.8   0.1  1.0  328.7  191.7  0.2  0.1  0.6   7.78    2.34
 GeoMean   0.0   0.0   0.0  99.8   0.0  1.0  326.4  190.0  0.0  0.0  0.0   7.60    2.15
  StdDev   0.1   0.0   0.1   0.2   0.1  0.0   40.9   26.9  0.6  0.5  2.4   1.52    0.92
-------- ----- ----- ----- ----- ----- ---- ------ ------ ---- ---- ---- ------  ------
 Minimum   0.0   0.0   0.0  99.2   0.0  1.0  263.5  153.0  0.0  0.0  0.0   4.20    0.75
 Maximum   0.3   0.0   0.2 100.0   0.4  1.0  458.5  287.0  3.0  3.0 14.0   9.78    4.14
-------- ----- ----- ----- ----- ----- ---- ------ ------ ---- ---- ---- ------  ------
Summary:
System:   7.78 Watts on average with standard deviation 1.52  
GPU:   2.34 Watts on average with standard deviation 0.92  

C-State    Resident      Count Latency 
C10         97.144%      12891     890
C9           0.140%        111     480
C8           1.221%       2316     200
C7s          0.005%         14     124
C6           0.055%        454      85
C3           0.002%        103      70
C1E          1.161%       1544      10
C1           0.000%         10       2
POLL         0.000%          3       0
C0           0.271%

no compositor running

 >> sudo powerstat 2 -d 20 -gcz
Running for 460.0 seconds (230 samples at 2.0 second intervals).
Power measurements will start in 20 seconds time.

  Time    User  Nice   Sys  Idle    IO  Run Ctxt/s  IRQ/s Fork Exec Exit  Watts   GPU W
08:38:02   0.0   0.0   0.0 100.0   0.0    1    271    159    0    0    0   3.84    0.53
08:38:04   0.1   0.0   0.0  99.9   0.0    1    277    150    0    0    0   3.78    0.54
08:38:06   0.0   0.0   0.0 100.0   0.0    1    240    141    0    0    0   3.72    0.54
08:38:08   0.0   0.0   0.0 100.0   0.0    1    247    144    0    0    0   3.73    0.53
08:38:10   0.0   0.0   0.1  99.9   0.0    1    238    140    0    0    0   3.73    0.53
08:38:12   0.0   0.0   0.1  99.9   0.0    1    240    145    0    0    0   3.73    0.54
08:38:14   0.1   0.0   0.0  99.9   0.0    1    246    144    0    0    0   3.73    0.54
08:38:16   0.1   0.0   0.0  99.9   0.0    1    263    146    0    0    0   3.73    0.52
08:38:18   0.0   0.0   0.0 100.0   0.0    1    240    142    0    0    0   3.73    0.51
08:38:20   0.0   0.0   0.0 100.0   0.0    1    240    134    0    0    0   3.71    0.51
08:38:22   0.0   0.0   0.0 100.0   0.0    1    252    148    0    0    0   3.75    0.52
08:38:24   0.0   0.0   0.0 100.0   0.0    1    252    144    0    0    0   3.73    0.50
08:38:26   0.1   0.0   0.0  99.9   0.0    1    236    148    0    0    0   3.72    0.49
08:38:28   0.4   0.0   0.1  99.6   0.0    1    352    182    0    0    0   3.93    0.51
08:38:30   0.0   0.0   0.1  99.9   0.0    1    246    148    0    0    0   3.79    0.54
08:38:32   0.0   0.0   0.0 100.0   0.0    1    241    134    0    0    0   3.72    0.51
08:38:34   0.0   0.0   0.0 100.0   0.0    1    249    150    0    0    0   3.73    0.53
08:38:36   0.0   0.0   0.1  99.9   0.0    1    242    134    0    0    0   3.71    0.53
08:38:38   0.1   0.0   0.0  99.9   0.0    1    244    148    0    0    0   3.72    0.50
08:38:40   0.0   0.0   0.1  99.9   0.0    1    246    141    0    0    0   3.72    0.51
08:38:42   0.1   0.0   0.0  99.9   0.0    1    236    148    0    0    0   3.72    0.52
08:38:44   0.4   0.0   0.6  99.0   0.0    1   2955   1453    0    0    0   3.87    0.53
08:38:46   0.1   0.0   0.0  99.9   0.0    1    244    136    0    0    0   3.72    0.52
08:38:48   0.0   0.0   0.0 100.0   0.0    1    257    138    0    0    0   3.72    0.52
08:38:50   0.1   0.0   0.1  99.9   0.0    1    242    142    0    0    0   3.73    0.52
08:38:52   0.1   0.0   0.0  99.9   0.0    1    288    174    0    0    0   3.78    0.53
08:38:54   0.1   0.0   0.0  99.9   0.0    1    246    176    0    0    0   3.73    0.52
08:38:56   0.0   0.0   0.0 100.0   0.0    1    246    184    0    0    0   3.73    0.50
08:38:58   0.2   0.0   0.0  99.8   0.0    1    286    169    0    0    0   3.79    0.51
08:39:00   0.1   0.0   0.1  99.9   0.0    1    320    196    0    0    0   3.79    0.53
08:39:02   0.0   0.0   0.0 100.0   0.0    1    244    166    0    0    0   3.73    0.51
08:39:04   0.0   0.0   0.0 100.0   0.0    1    255    165    0    0    0   3.74    0.50
08:39:06   0.0   0.0   0.0 100.0   0.0    1    238    156    0    0    0   3.73    0.53
^C-------- ----- ----- ----- ----- ----- ---- ------ ------ ---- ---- ---- ------  ------
 Average   0.0   0.0   0.0  99.9   0.0  1.0  337.0  191.8  0.0  0.0  0.0   3.75    0.52
 GeoMean   0.0   0.0   0.0  99.9   0.0  1.0  273.7  162.3  0.0  0.0  0.0   3.75    0.52
  StdDev   0.1   0.0   0.1   0.2   0.0  0.0  463.5  223.5  0.0  0.0  0.0   0.05    0.01
-------- ----- ----- ----- ----- ----- ---- ------ ------ ---- ---- ---- ------  ------
 Minimum   0.0   0.0   0.0  99.0   0.0  1.0  236.0  134.0  0.0  0.0  0.0   3.71    0.49
 Maximum   0.4   0.0   0.6 100.0   0.0  1.0 2955.0 1453.0  0.0  0.0  0.0   3.93    0.54
-------- ----- ----- ----- ----- ----- ---- ------ ------ ---- ---- ---- ------  ------
Summary:
System:   3.75 Watts on average with standard deviation 0.05  
GPU:   0.52 Watts on average with standard deviation 0.01  

C-State    Resident      Count Latency 
C10         97.890%      10189     890
C9           0.000%          0     480
C8           0.910%       2105     200
C7s          0.000%          0     124
C6           0.105%        858      85
C3           0.004%        265      70
C1E          1.052%       2469      10
C1           0.007%         75       2
POLL         0.000%          8       0
C0           0.032%

As you can see, GPU W and total power consumption jumped while running picom with experimental backends. I think it's safe to conclude that picom experimental backends are causing high power usage

yshui commented 4 years ago

@aspieln3r Thanks for the additional information. Hearing the actual problem that led you to report an issue is much useful for me. I change the title to reflect your real problem.

~Could you post you configuration file? That will help me investigate.~

Edit: sorry, you did post your configuration...

yshui commented 4 years ago

Can you enable/disable these features and see how they affect the power usage?

absolutelynothelix commented 4 years ago

i never thought about power usage caused by picom running in the background... decided to test the thing with maim that i noticed:

nothing happens, picom running in the background, idling for several polls: image

pressed prtsc button which is bound to maim -qsu | xclip -selection clipboard -t image/png, idling with maim running for several polls: image

aspieln3r commented 4 years ago

@mighty9245 can you test using powerstat and see how it goes?

aspieln3r commented 4 years ago

Can you enable/disable these features and see how they affect the power usage?

  • shadow
  • blur
  • use-damage

attaching config with all three disabled : https://pastebin.com/2e9QD8Hd toggling them didn't make any difference.

picom -b:
System:   4.60 Watts on average with standard deviation 0.15  
GPU:   0.56 Watts on average with standard deviation 0.01  

C-State    Resident      Count Latency 
C10         90.235%      12979     890
C9           0.078%         44     480
C8           8.334%       9193     200
C7s          0.009%         16     124
C6           0.171%       1118      85
C3           0.021%        856      70
C1E          0.580%       1365      10
C1           0.053%        384       2
POLL         0.000%          5       0
C0           0.519%
picom -b --experimental-backends
System:   6.85 Watts on average with standard deviation 2.04  
GPU:   2.78 Watts on average with standard deviation 1.04  

C-State    Resident      Count Latency 
C10         90.734%      27683     890
C9           0.010%         37     480
C8           7.936%      19685     200
C7s          0.008%         27     124
C6           0.150%       2189      85
C3           0.021%       1787      70
C1E          0.803%       3606      10
C1           0.057%       2454       2
POLL         0.000%         10       0
C0           0.280%

Result is same when kitty is ran with transparency=1 in fullscreen mode. @yshui small another thing I noticed- when e-damage=false is used instead of use-damage(accidentally) picom didn't report any syntax error.

yshui commented 4 years ago

picom didn't report any syntax error.

picom won't complain about extraneous options set in the config file.

yshui commented 4 years ago

toggling them didn't make any difference.

it did, didn't it? in your previous report, the system uses 7.7W, now it uses 6.9W.

aspieln3r commented 4 years ago

@yshui true.Total is low but this time but std deviation is high. It actually varied from 10w to 4w at times. Change is there for sure but not a significant one like I expected 😕

mmhobi7 commented 4 years ago

I can confidently say that blur causes an increase in power usage. As a heads up I noticed powertop has trouble showing power usage of my GPU.

zerinoid commented 4 years ago
  TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN     IO>     COMMAND
 3174 be/4 zerinol     0.00 B/s    0.00 B/s  0.00 %     50.08 % picom --experimental-backends

io% going as high as 50% with only alacritty and brave running

my config: https://pastebin.com/jEEWYCD6

Ropid commented 4 years ago

Is this problem something that only happens with the Intel driver? On my desktop PC here with an AMD graphics card, I see no IO for picom in iotop. It shows 0% in the IO column. If I press "o" to filter the list, the picom process does not show up in the list, it seems it does no IO at all.