First, thanks for getting back to me. I appreciate that you guys take the time to help the community like this.
My fiend who owns a Pixel 3 is gathering the info you requested and will reply back. In the meantime, I wanted to point out some findings. This is a snippet from "stune_trace-20190321_192157.log" that I previously provided that captured the problem I am seeing. See below:
Binder:1188_1D-8087 [007] d..2 12046.707148: sched_waking: comm=remote-ui pid=3751 prio=120 target_cpu=003 Binder:1188_1D-8087 [007] d..2 12046.707153: sched_boost_task: comm=remote-ui pid=3751 util=115 margin=454 Binder:1188_1D-8087 [007] d..2 12046.707154: sched_find_best_target: pid=3751 comm=remote-ui prefer_idle=1 start_cpu=4 best_idle=-1 best_active=-1 target=4 Binder:1188_1D-8087 [007] d..2 12046.707155: sched_task_util: pid=3751 comm=remote-ui util=115 prev_cpu=3 next_cpu=4 backup_cpu=-1 target_cpu=4 need_idle=0 fastpath=0 placement_boost=1 rtg_cpu=-1 latency=2344 Binder:1188_1D-8087 [007] d..2 12046.707155: sched_migrate_task: comm=remote-ui pid=3751 prio=120 load=115 orig_cpu=3 dest_cpu=4 Binder:1188_1D-8087 [007] d..4 12046.707164: sched_tune_tasks_update: pid=3751 comm=remote-ui cpu=4 tasks=2 idx=3 boost=50 max_boost=50 Binder:1188_1D-8087 [007] d.h9 12046.707177: sched_boost_cpu: cpu=0 util=26 margin=499 Binder:1188_1D-8087 [007] d.h9 12046.707178: sched_boost_cpu: cpu=1 util=102 margin=0 Binder:1188_1D-8087 [007] d.h9 12046.707179: sched_boost_cpu: cpu=2 util=71 margin=0 Binder:1188_1D-8087 [007] d.h9 12046.707179: sched_boost_cpu: cpu=3 util=32 margin=0 Binder:1188_1D-8087 [007] d.h9 12046.707180: sched_boost_cpu: cpu=4 util=255 margin=384 Binder:1188_1D-8087 [007] d.h9 12046.707180: sched_boost_cpu: cpu=5 util=122 margin=451 Binder:1188_1D-8087 [007] d.h9 12046.707181: sched_boost_cpu: cpu=6 util=158 margin=433 Binder:1188_1D-8087 [007] d.h9 12046.707181: sched_boost_cpu: cpu=7 util=235 margin=394 Binder:1188_1D-8087 [007] d..3 12046.707193: sched_tune_tasks_update: pid=8087 comm=Binder:1188_1D cpu=7 tasks=1 idx=1 boost=0 max_boost=50 Binder:1188_1D-8087 [007] d..2 12046.707195: sched_switch: prev_comm=Binder:1188_1D prev_pid=8087 prev_prio=120 prev_state=S ==> next_comm=RenderThread next_pid=2319 next_prio=120 <...>-2319 [007] d..3 12046.707208: sched_tune_tasks_update: pid=2319 comm=RenderThread cpu=7 tasks=0 idx=1 boost=0 max_boost=50 <...>-2319 [007] d..1 12046.707211: sched_load_balance: cpu=7 state=newly_idle balance=1 group=0x0 busy_nr=2 imbalance=0 flags=0x1 ld_moved=0 bal_int=16 <...>-2319 [007] d..1 12046.707213: sched_load_balance: cpu=7 state=newly_idle balance=1 group=0x0 busy_nr=0 imbalance=0 flags=0x0 ld_moved=0 bal_int=16 <...>-2319 [007] d..2 12046.707215: sched_switch: prev_comm=RenderThread prev_pid=2319 prev_prio=120 prev_state=S ==> next_comm=swapper/7 next_pid=0 next_prio=120 ndroid.systemui-2083 [006] d..4 12046.707224: sched_waking: comm=Binder:1188_1D pid=8087 prio=120 target_cpu=007 ndroid.systemui-2083 [006] d..4 12046.707227: sched_migrate_task: comm=Binder:1188_1D pid=8087 prio=120 load=15 orig_cpu=7 dest_cpu=6 ndroid.systemui-2083 [006] d..5 12046.707232: sched_boost_cpu: cpu=6 util=158 margin=433 ndroid.systemui-2083 [006] d..6 12046.707233: sched_tune_tasks_update: pid=8087 comm=Binder:1188_1D cpu=6 tasks=2 idx=1 boost=0 max_boost=50 ndroid.systemui-2083 [006] d..3 12046.707236: sched_tune_tasks_update: pid=2083 comm=ndroid.systemui cpu=6 tasks=1 idx=1 boost=0 max_boost=50 ndroid.systemui-2083 [006] d..2 12046.707238: sched_switch: prev_comm=ndroid.systemui prev_pid=2083 prev_prio=120 prev_state=S ==> next_comm=Binder:1188_1D next_pid=8087 next_prio=120 Binder:1188_1D-8087 [006] d..2 12046.707270: sched_waking: comm=ndroid.systemui pid=2083 prio=120 target_cpu=006 Binder:1188_1D-8087 [006] d..4 12046.707274: sched_tune_tasks_update: pid=2083 comm=ndroid.systemui cpu=6 tasks=2 idx=1 boost=0 max_boost=50 Binder:1188_1D-8087 [006] d..3 12046.707281: sched_tune_tasks_update: pid=8087 comm=Binder:1188_1D cpu=6 tasks=1 idx=1 boost=0 max_boost=50 Binder:1188_1D-8087 [006] d..2 12046.707283: sched_switch: prev_comm=Binder:1188_1D prev_pid=8087 prev_prio=120 prev_state=S ==> next_comm=ndroid.systemui next_pid=2083 next_prio=120 ndroid.systemui-2083 [006] d..4 12046.707299: sched_waking: comm=Binder:1188_1D pid=8087 prio=120 target_cpu=006 ndroid.systemui-2083 [006] d..6 12046.707302: sched_tune_tasks_update: pid=8087 comm=Binder:1188_1D cpu=6 tasks=2 idx=1 boost=0 max_boost=50 ndroid.systemui-2083 [006] d..3 12046.707304: sched_tune_tasks_update: pid=2083 comm=ndroid.systemui cpu=6 tasks=1 idx=1 boost=0 max_boost=50 ndroid.systemui-2083 [006] d..2 12046.707306: sched_switch: prev_comm=ndroid.systemui prev_pid=2083 prev_prio=120 prev_state=S ==> next_comm=Binder:1188_1D next_pid=8087 next_prio=120 Binder:1188_1D-8087 [006] d..2 12046.707326: sched_waking: comm=ndroid.systemui pid=2083 prio=120 target_cpu=006 Binder:1188_1D-8087 [006] d..4 12046.707330: sched_tune_tasks_update: pid=2083 comm=ndroid.systemui cpu=6 tasks=2 idx=1 boost=0 max_boost=50 Binder:1188_1D-8087 [006] d..3 12046.707336: sched_tune_tasks_update: pid=8087 comm=Binder:1188_1D cpu=6 tasks=1 idx=1 boost=0 max_boost=50 Binder:1188_1D-8087 [006] d..2 12046.707339: sched_switch: prev_comm=Binder:1188_1D prev_pid=8087 prev_prio=120 prev_state=S ==> next_comm=ndroid.systemui next_pid=2083 next_prio=120 surfaceflinger-606 [003] d..1 12046.707383: sched_waking: comm=sfEventThread pid=632 prio=97 target_cpu=002 android.anim-1355 [005] d..4 12046.707401: sched_waking: comm=Binder:606_5 pid=2524 prio=110 target_cpu=007 ndroid.systemui-2083 [006] d..4 12046.707401: sched_waking: comm=Binder:3120_4 pid=3197 prio=120 target_cpu=004 android.anim-1355 [005] d..4 12046.707404: sched_migrate_task: comm=Binder:606_5 pid=2524 prio=110 load=31 orig_cpu=7 dest_cpu=5 <idle>-0 [002] d..2 12046.707405: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=sfEventThread next_pid=632 next_prio=97 ndroid.systemui-2083 [006] d..4 12046.707406: sched_boost_task: comm=Binder:3120_4 pid=3197 util=24 margin=500 ndroid.systemui-2083 [006] d..4 12046.707407: sched_find_best_target: pid=3197 comm=Binder:3120_4 prefer_idle=1 start_cpu=4 best_idle=-1 best_active=-1 target=7 ndroid.systemui-2083 [006] d..4 12046.707407: sched_task_util: pid=3197 comm=Binder:3120_4 util=24 prev_cpu=4 next_cpu=7 backup_cpu=-1 target_cpu=7 need_idle=0 fastpath=0 placement_boost=1 rtg_cpu=-1 latency=2187 ndroid.systemui-2083 [006] d..4 12046.707408: sched_migrate_task: comm=Binder:3120_4 pid=3197 prio=120 load=24 orig_cpu=4 dest_cpu=7 android.anim-1355 [005] d..5 12046.707409: sched_boost_cpu: cpu=5 util=122 margin=451 android.anim-1355 [005] d..5 12046.707410: sched_boost_cpu: cpu=5 util=122 margin=451 android.anim-1355 [005] d..6 12046.707411: sched_tune_tasks_update: pid=2524 comm=Binder:606_5 cpu=5 tasks=2 idx=1 boost=0 max_boost=50 <...>-632 [002] d..2 12046.707412: sched_boost_cpu: cpu=2 util=71 margin=0 ndroid.systemui-2083 [006] d..6 12046.707413: sched_tune_tasks_update: pid=3197 comm=Binder:3120_4 cpu=7 tasks=2 idx=3 boost=50 max_boost=50 android.anim-1355 [005] d..3 12046.707414: sched_tune_tasks_update: pid=1355 comm=android.anim cpu=5 tasks=0 idx=3 boost=50 max_boost=50 android.anim-1355 [005] d..2 12046.707416: sched_switch: prev_comm=android.anim prev_pid=1355 prev_prio=110 prev_state=S ==> next_comm=Binder:606_5 next_pid=2524 next_prio=110 <...>-632 [002] d..1 12046.707418: sched_load_balance: cpu=2 state=newly_idle balance=1 group=0x0 busy_nr=0 imbalance=0 flags=0x0 ld_moved=0 bal_int=8 <idle>-0 [007] d..2 12046.707423: sched_switch: prev_comm=swapper/7 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=Binder:3120_4 next_pid=3197 next_prio=120 <...>-632 [002] d..3 12046.707426: sched_tune_tasks_update: pid=3751 comm=remote-ui cpu=4 tasks=1 idx=3 boost=50 max_boost=50 <...>-632 [002] d..3 12046.707428: sched_migrate_task: comm=remote-ui pid=3751 prio=120 load=115 orig_cpu=4 dest_cpu=2 <...>-632 [002] d..2 12046.707437: sched_boost_cpu: cpu=2 util=175 margin=0 <...>-632 [002] d..3 12046.707439: sched_tune_tasks_update: pid=3751 comm=remote-ui cpu=2 tasks=1 idx=3 boost=50 max_boost=0 <...>-632 [002] d..1 12046.707440: sched_load_balance: cpu=2 state=newly_idle balance=1 group=0xf0 busy_nr=1 imbalance=-31 flags=0x0 ld_moved=1 bal_int=8 <...>-632 [002] d..2 12046.707441: sched_boost_cpu: cpu=2 util=175 margin=424 <...>-632 [002] d..2 12046.707446: sched_switch: prev_comm=sfEventThread prev_pid=632 prev_prio=97 prev_state=S ==> next_comm=remote-ui next_pid=3751 next_prio=120 ndroid.systemui-2083 [006] d..3 12046.707450: sched_waking: comm=InputDispatcher pid=1373 prio=111 target_cpu=007 ndroid.systemui-2083 [006] d..3 12046.707453: sched_boost_task: comm=InputDispatcher pid=1373 util=29 margin=0 ndroid.systemui-2083 [006] d..3 12046.707453: sched_find_best_target: pid=1373 comm=InputDispatcher prefer_idle=1 start_cpu=0 best_idle=-1 best_active=-1 target=7 ndroid.systemui-2083 [006] d..3 12046.707454: sched_task_util: pid=1373 comm=InputDispatcher util=29 prev_cpu=7 next_cpu=7 backup_cpu=-1 target_cpu=7 need_idle=0 fastpath=0 placement_boost=1 rtg_cpu=-1 latency=1615 <...>-3751 [002] d.ha 12046.707467: sched_boost_cpu: cpu=0 util=26 margin=499 <...>-3751 [002] d.ha 12046.707468: sched_boost_cpu: cpu=1 util=102 margin=0 <...>-3751 [002] d.ha 12046.707470: sched_boost_cpu: cpu=2 util=175 margin=424 <...>-3751 [002] d.ha 12046.707471: sched_boost_cpu: cpu=3 util=32 margin=0 <...>-3751 [002] d.ha 12046.707472: sched_boost_cpu: cpu=4 util=152 margin=436 <...>-3751 [002] d.ha 12046.707474: sched_boost_cpu: cpu=5 util=122 margin=0 <...>-3751 [002] d.ha 12046.707475: sched_boost_cpu: cpu=6 util=158 margin=433 <...>-3751 [002] d.ha 12046.707476: sched_boost_cpu: cpu=7 util=235 margin=394
I see the above issue over and over when the problem is occurring. Even when bigs are hardly being utilized. I say that it is a possible bug because for me (OnePlus 6 w/ p3 commits) it will either happen or it won't. For example, I can boot up and during interactions, only bigs are boosted like expected. This will go on for a length of time, maybe a few hours or a couple days. And visa versa, when the issue occurs, there is no middle ground. When this issue occurs, during interactions, both clusters run with a margin 500ish due to a boosted TA running on a small core. This problem will continue to persist till we reboot. The issue doesn't always occur at boot either.
When I looked closer at exactly what boosted TA task is running on a small core, I noticed a pattern. I can see that the TA task is being migrated as soon as it's scheduled. FBT() will pick the right target_cpu (big core) but it will then immediately be migrated to a small core. Every single time, regardless of how loaded bigs are. Remember, when this issue doesn't occur, only bigs will remain boosted until overutilized. This is what I would expect. From what I can tell, it looks like the small core is load balancing when newly_idle. I am trying to gather more data. Unfortunately, I am not very knowledgeable about the ins and outs of load balancing but there is most definitely something going on. For example, in the above example, I dont see why "comm=remote-ui pid=3751" would be migrated to CPU2. It is more utilized than CPU4, and remote-ui is stune boosted.
Once again, thanks for your help. There are a number of members from our community that track your work and this mailing list. Keep up the good work!
Regards, Zachariah