-
After 15+ years, we've made a big change: Android Forums is now Early Bird Club. Learn more here.
Root [KERNEL] Quattrimus Kernel
- Thread starter tdm
- Start date
-
- Tags
- lg spectrum
tdm
Android Expert
I am testing a better method right now: turn off the power to the wlan radio when suspending and turn it back on when resuming. This is obviously not how suspend/resume is meant to operate but I don't have a spec sheet or hardware diagnostics to work from. But it seems to be working well, and doesn't seem to have any side effects. If it continues to work for the next couple hours and actually saves battery, I'll toss it out there.
tdm
Android Expert
Okay I posted v1.2 with an attempt at fixing the WiFi deep sleep bug.
This does prevent WiFi interrupts from waking the device, but I'm not entirely sure whether the WiFi chip is actually in low power mode.
Give it a shot and let me know if you see better battery life. Actual numbers for percent drain per hour when idle would be helpful. I don't know what the ideal drain is but I'm guessing somewhere between 2% and 4%.
This does prevent WiFi interrupts from waking the device, but I'm not entirely sure whether the WiFi chip is actually in low power mode.
Give it a shot and let me know if you see better battery life. Actual numbers for percent drain per hour when idle would be helpful. I don't know what the ideal drain is but I'm guessing somewhere between 2% and 4%.
tdm
Android Expert
The thought occurred to me that perhaps I'm going about this the wrong way.
There was a fair amount of changes in the kernel between 4.1.x (CM10/AOKP41) and 4.2.x (CM10.1/AOKP42). The kernel was updated from 3.0.8 to 3.0.31 and many CAF patches were added in.
So here's the big question I have: did 4.1.x have the battery drain issue due to WiFi? If not, I should be able to find the offending code by looking at the 4.1.x -> 4.2.x changes.
There was a fair amount of changes in the kernel between 4.1.x (CM10/AOKP41) and 4.2.x (CM10.1/AOKP42). The kernel was updated from 3.0.8 to 3.0.31 and many CAF patches were added in.
So here's the big question I have: did 4.1.x have the battery drain issue due to WiFi? If not, I should be able to find the offending code by looking at the 4.1.x -> 4.2.x changes.
)
MrB206
Android Expert
Ditto. I keep a nandroid of it because it performed so we'll on my phone.
tdm
Android Expert
This is a very interesting log. I'm not sure which issue caused the reboot lol. But generally the first error you see is the one that caused the chain reaction. So it seems the vdd issue really needs to be solved. I'll try to look at that in the next few days.
Here are details for the curious...
I see the failure to set vdd:
Code:
[10275.792083] msm_spm_set_vdd: cpu 1 failed, remaining timeout 50us, vlevel 0xa8
[10275.798522] saw_set_voltage: 8901_s1: msm_spm_set_vdd failed -5
[10275.804656] decrease_vdd: vdd_sc (cpu1) decrease failed (-5)
[10275.810485] cpufreq: cpu1 init at 1674000 switching to 1512000Then I see some additional failures:
Code:
[10280.982116] ===pm8xxx_tz_get_temp_pm8058_adc: failed to adc wait for completion!===
[10280.989257] Pmic 8058 xoadc spurious interrupt detected
[10280.994049] ============== batt temp adc read fail so default temp ===============
[10302.149963] binder: 656:668 transaction failed 29189, size 120-0
[10302.155517] binder: 656:668 transaction failed 29189, size 120-0
[10302.161102] binder: 656:668 transaction failed 29189, size 120-0
[10302.167480] binder: 656:668 transaction failed 29189, size 120-0
[10313.542114] ===batt_read_adc: failed to adc wait for completion!===
[10313.547485] Pmic 8058 xoadc spurious interrupt detected
[10313.552642] ============== batt temp adc read fail so default temp ===============
[10316.562164] ===batt_read_adc: failed to adc wait for completion!===
[10316.567474] Pmic 8058 xoadc spurious interrupt detected
[10316.572753] ============== batt temp adc read fail so default temp ===============
[10333.992126] ===pm8xxx_tz_get_temp_pm8058_adc: failed to adc wait for completion!===
[10333.998901] Pmic 8058 xoadc spurious interrupt detected
[10334.004089] ============== batt temp adc read fail so default temp ===============Finally, there is an RCU stall:
Code:
[10335.842071] INFO: rcu_preempt_state detected stalls on CPUs/tasks: { 1} (detected by 0, t=6002 ji
ffies)
[10335.850494] Backtrace for cpu 0 (current):
[10335.854614] [<c010c5bc>] (unwind_backtrace+0x0/0x11c) from [<c010a9cc>] (smp_send_all_cpu_backtra
ce+0x5c/0xc0)
[10335.864654] [<c010a9cc>] (smp_send_all_cpu_backtrace+0x5c/0xc0) from [<c020d7bc>] (__rcu_pending+
0x3c0/0x544)
[10335.874542] [<c020d7bc>] (__rcu_pending+0x3c0/0x544) from [<c020f20c>] (rcu_check_callbacks+0x124
/0x158)
[10335.884002] [<c020f20c>] (rcu_check_callbacks+0x124/0x158) from [<c01cc354>] (update_process_time
s+0x38/0x68)
[10335.893890] [<c01cc354>] (update_process_times+0x38/0x68) from [<c01ed738>] (tick_sched_timer+0x9
4/0x254)
[10335.903442] [<c01ed738>] (tick_sched_timer+0x94/0x254) from [<c01e2244>] (__run_hrtimer+0x1dc/0x3
30)
[10335.912536] [<c01e2244>] (__run_hrtimer+0x1dc/0x330) from [<c01e306c>] (hrtimer_interrupt+0x154/0
x2c0)
[10335.921783] [<c01e306c>] (hrtimer_interrupt+0x154/0x2c0) from [<c0116c6c>] (msm_timer_interrupt+0
x18/0x20)
[10335.931457] [<c0116c6c>] (msm_timer_interrupt+0x18/0x20) from [<c020a578>] (handle_percpu_devid_i
rq+0x110/0x1d0)
[10335.941619] [<c020a578>] (handle_percpu_devid_irq+0x110/0x1d0) from [<c02060d4>] (generic_handle_
irq+0x30/0x44)
[10335.951690] [<c02060d4>] (generic_handle_irq+0x30/0x44) from [<c0106800>] (handle_IRQ+0x7c/0xc0)
[10335.960479] [<c0106800>] (handle_IRQ+0x7c/0xc0) from [<c01003a4>] (gic_handle_irq+0x70/0x9c)
[10335.968902] [<c01003a4>] (gic_handle_irq+0x70/0x9c) from [<c08339d4>] (__irq_svc+0x54/0x80)
[10335.977142] Exception stack(0xc0c01f28 to 0xc0c01f70)
[10335.982238] 1f20: 00000000 00000000 00000001 00000000 c9c92288 000026dc
[10335.990417] 1f40: c084e01c c0c2d5a0 00000000 510f02d2 00000000 00000000 09c40000 c0c01f70
[10335.998504] 1f60: c0835c90 c0173ec4 60000013 ffffffff
[10336.003601] [<c08339d4>] (__irq_svc+0x54/0x80) from [<c0173ec4>] (msm_cpuidle_enter+0x64/0x74)
[10336.012145] [<c0173ec4>] (msm_cpuidle_enter+0x64/0x74) from [<c061205c>] (cpuidle_idle_call+0x1e4
/0x380)
[10336.021667] [<c061205c>] (cpuidle_idle_call+0x1e4/0x380) from [<c0106db0>] (cpu_idle+0x84/0xe8)
[10336.030334] [<c0106db0>] (cpu_idle+0x84/0xe8) from [<c08124f8>] (rest_init+0xd4/0xf8)
[10336.038146] [<c08124f8>] (rest_init+0xd4/0xf8) from [<c00088a8>] (start_kernel+0x2ac/0x308)
[10336.046478] unwind: Unknown symbol address c00088a8
[10336.051300] unwind: Index not found c00088a8
[10336.055541]
[10336.055541] sending IPI to all other CPUs:
[10355.962097] INFO: rcu_bh_state detected stalls on CPUs/tasks: { 1} (detected by 0, t=6002 jiffies)
[10355.970123] Backtrace for cpu 0 (current):
[10355.974182] [<c010c5bc>] (unwind_backtrace+0x0/0x11c) from [<c010a9cc>] (smp_send_all_cpu_backtrace+0x5c/0xc0)
[10355.984222] [<c010a9cc>] (smp_send_all_cpu_backtrace+0x5c/0xc0) from [<c020d7bc>] (__rcu_pending+0x3c0/0x544)
[10355.994110] [<c020d7bc>] (__rcu_pending+0x3c0/0x544) from [<c020f1f0>] (rcu_check_callbacks+0x108/0x158)
[10356.003570] [<c020f1f0>] (rcu_check_callbacks+0x108/0x158) from [<c01cc354>] (update_process_times+0x38/0x68)
[10356.013397] [<c01cc354>] (update_process_times+0x38/0x68) from [<c01ed738>] (tick_sched_timer+0x94/0x254)
[10356.023010] [<c01ed738>] (tick_sched_timer+0x94/0x254) from [<c01e2244>] (__run_hrtimer+0x1dc/0x330)
[10356.032135] [<c01e2244>] (__run_hrtimer+0x1dc/0x330) from [<c01e306c>] (hrtimer_interrupt+0x154/0x2c0)
[10356.041412] [<c01e306c>] (hrtimer_interrupt+0x154/0x2c0) from [<c0116c6c>] (msm_timer_interrupt+0x18/0x20)
[10356.051055] [<c0116c6c>] (msm_timer_interrupt+0x18/0x20) from [<c020a578>] (handle_percpu_devid_irq+0x110/0x1d0)
[10356.061218] [<c020a578>] (handle_percpu_devid_irq+0x110/0x1d0) from [<c02060d4>] (generic_handle_irq+0x30/0x44)
[10356.071289] [<c02060d4>] (generic_handle_irq+0x30/0x44) from [<c0106800>] (handle_IRQ+0x7c/0xc0)
[10356.079986] [<c0106800>] (handle_IRQ+0x7c/0xc0) from [<c01003a4>] (gic_handle_irq+0x70/0x9c)
[10356.088470] [<c01003a4>] (gic_handle_irq+0x70/0x9c) from [<c08339d4>] (__irq_svc+0x54/0x80)
[10356.096801] Exception stack(0xd5f5fda8 to 0xd5f5fdf0)
[10356.101776] fda0: 00000002 00000002 00000002 00000001 d5f5fe1c 00000001
[10356.109985] fdc0: c9c9c1e0 c9c9c1e0 00000000 137e137f 137e137f 00000001 00000002 d5f5fdf0
[10356.118133] fde0: c011539c c01f3a9c 20000013 ffffffff
[10356.123138] [<c08339d4>] (__irq_svc+0x54/0x80) from [<c01f3a9c>] (generic_exec_single+0xf4/0x104)
[10356.132049] [<c01f3a9c>] (generic_exec_single+0xf4/0x104) from [<c01f3c1c>] (smp_call_function_single+0x170/0x1c8)
[10356.142364] [<c01f3c1c>] (smp_call_function_single+0x170/0x1c8) from [<c01f3fa8>] (smp_call_function+0x44/0x6c)
[10356.152435] [<c01f3fa8>] (smp_call_function+0x44/0x6c) from [<c0114408>] (__new_context+0x104/0x17c)
[10356.161560] [<c0114408>] (__new_context+0x104/0x17c) from [<c0276428>] (flush_old_exec+0x67c/0x890)
[10356.170532] [<c0276428>] (flush_old_exec+0x67c/0x890) from [<c02b8e00>] (load_elf_binary+0x2d4/0x123c)
[10356.179870] [<c02b8e00>] (load_elf_binary+0x2d4/0x123c) from [<c0275418>] (search_binary_handler+0x19c/0x450)
[10356.189758] [<c0275418>] (search_binary_handler+0x19c/0x450) from [<c0276f98>] (do_execve+0x15c/0x264)
[10356.199066] [<c0276f98>] (do_execve+0x15c/0x264) from [<c0109124>] (sys_execve+0x34/0x54)
[10356.207214] [<c0109124>] (sys_execve+0x34/0x54) from [<c0105900>] (ret_fast_syscall+0x0/0x30)
[10356.215728]
[10356.215728] sending IPI to all other CPUs:tdm
Android Expert
I'm getting about 4% drain per hour on my P930 with this kernel. That's two reports of reasonable battery drain, so I think it's safe to say it works.
However, this solution is really a hack. I'm looking at the changes between 4.1.x and 4.2.x to find the root cause of the issue.
I'm also looking into faster charging and reducing kernel log chatter.
I might play with undervolt and gpu clock. Don't expect much more overclock though. This phone gets plenty warm at 1674mhz and I don't want to be responsible for melted phones.
However, this solution is really a hack. I'm looking at the changes between 4.1.x and 4.2.x to find the root cause of the issue.
I'm also looking into faster charging and reducing kernel log chatter.
I might play with undervolt and gpu clock. Don't expect much more overclock though. This phone gets plenty warm at 1674mhz and I don't want to be responsible for melted phones.
tdm
Android Expert
Oh yeah .. almost forgot. The next two culprits for waking from deep sleep are power-supply and alarm-rtc. I will try to see if it's possible to reduce the power-supply wakeup frequency -- maybe cut it in half. alarm-rtc is probably a general purpose alarm mechanism used by many things, including apps that schedule callbacks (eg. email sync). So that's probably not something that can be changed.
I tried this last night, Battery life was looking good but after a scheduled reboot the wifi would no longer connect to my access point. Rebooted the phone again and it still wouldn't connect. Finally re-flashed triggerhappy kernel and it connected fine.
Logcat just showed it associating with the AP and then immediately getting:
I/wpa_supplicant(6408): wlan0: CTRL-EVENT-DISCONNECTED bssid=c0:c1:c0:XX:XX:XX reason=0
Logcat just showed it associating with the AP and then immediately getting:
I/wpa_supplicant(6408): wlan0: CTRL-EVENT-DISCONNECTED bssid=c0:c1:c0:XX:XX:XX reason=0
tdm
Android Expert
Logs for battery drain are probably not useful. The kernel is far too chatty... it won't keep a long enough time window in the log buffer. That's one reason I want to reduce the chatter.
tdm
Android Expert
It seems that even on 4.1 (Quattrimus CM 10 v1.0), wlan is still waking the phone, and the same culprit is behind it: wlan_oob_irq(). So it seems that even on 4.1 the wifi is not sleeping properly. I don't really have any clue (yet) why this makes the battery drain faster in 4.2.
So I'm diving into the wifi sleep issue deeper. Right now I'm using my Spectrum with CM 10.0 to see if I can get the wifi chip to sleep properly.
Also... earlier this morning I was still under the theory that the kernel changes for 4.2 were causing this issue. So I got a 4.2 kernel compiled with only the CM changes (video driver updates etc.) but not the update to 3.0.31. This was intended to isolate which of the two was causing the issue. It was surprisingly easy to do, as the two are entirely orthogonal and don't touch the same files at all. It should be just as easy to make a 3.0.31 kernel for 4.1 by pulling back the other set of changes. I'll keep those under my hat for now, in case they might be useful in the future.
So I'm diving into the wifi sleep issue deeper. Right now I'm using my Spectrum with CM 10.0 to see if I can get the wifi chip to sleep properly.
Also... earlier this morning I was still under the theory that the kernel changes for 4.2 were causing this issue. So I got a 4.2 kernel compiled with only the CM changes (video driver updates etc.) but not the update to 3.0.31. This was intended to isolate which of the two was causing the issue. It was surprisingly easy to do, as the two are entirely orthogonal and don't touch the same files at all. It should be just as easy to make a 3.0.31 kernel for 4.1 by pulling back the other set of changes. I'll keep those under my hat for now, in case they might be useful in the future.
ortrigger
Android Expert
Have you tried using the kernel repo from CM instead or your quattrimus one? I haven't noticed any sleep issues with it like you're seeing here whether it be my kernel or the stock one.
EDIT: Maybe you should try diff'ing your specific changes with the stock kernel. That may shed some additional light on what is causing this.
tdm
Android Expert
What ROM are you running? This only seems to affect 4.2 based ROMs for some reason. But as I mentioned both 4.1 and 4.2 seem to wake frequently due to the oob IRQ. So there are really two issues:
1. Why is 4.2 affected so badly?
2. What are the oob irqs and why are they not disabled in sleep?
I still have bad WiFi drain on CM10.1, back to using DS battery saver but still have to plug in twice a day usually, but I also use it pretty much non-stop. I'd say the stock CM10.1 kernel has the same/ similar problem.
tdm
Android Expert
Well perhaps you have a different issue then. I have been getting over 50% deep sleep with light to moderate usage today. Which still doesn't translate to a full day of battery but it's getting close.... maybe 10 to 12 hours of usage.
tdm
Android Expert
Basically what happens on both CM10 and CM10.1 is that the wlan_wake lock keeps waking up the phone from deep sleep all the time. I haven't seen it get more than a few seconds of uninterrupted deep sleep.
Hmm ... it would be interesting to see if this same issue affects stock ZV7. Does anyone have ZV7 and want to see how often wlan_wake wakes up the phone?
Basically you're looking for lines like this in the kernel log:
Wakeup wake lock: wlan_wake
My hack/fix is to turn off wlan power and the oob irq when entering sleep and turn them back on when exiting sleep. Which means that it doesn't matter what the wifi sleep policy is set to, it will be turned off during sleep and it's not going to be interrupting sleep. That is, you'll never see the wlan_wake as the wakeup wake lock again.
The actual diff looks like this (unpolished but hey, it's a hack):
Code:
+++ b/drivers/net/wireless/bcmdhd_b1/src/dhd/sys/dhd_linux.c
@@ -526,6 +526,7 @@ static int dhd_wl_host_event(dhd_info_t *dhd, int *ifidx, void *pktdata,
wl_event_msg_t *event_ptr, void **data_ptr);
#if (LINUX_VERSION_CODE >= KERNEL_VERSION(2, 6, 27)) && defined(CONFIG_PM_SLEEP)
+extern void bcmsdh_set_irq(int flag);
static int dhd_sleep_pm_callback(struct notifier_block *nfb, unsigned long action, void *ignored)
{
int ret = NOTIFY_DONE;
@@ -534,13 +535,21 @@ static int dhd_sleep_pm_callback(struct notifier_block *nfb, unsigned long actio
#if 1 //(LINUX_VERSION_CODE <= KERNEL_VERSION(2, 6, 39))
switch (action) {
case PM_HIBERNATION_PREPARE:
+ printk(KERN_INFO "dhd_sleep_pm_callback: action=PM_HIBERNATION_PREPARE\n");
case PM_SUSPEND_PREPARE:
+ printk(KERN_INFO "dhd_sleep_pm_callback: action=PM_SUSPEND_PREPARE\n");
dhd_mmc_suspend = TRUE;
+ bcmsdh_oob_intr_set(0);
+ dhd_customer_gpio_wlan_ctrl(WLAN_POWER_OFF);
ret = NOTIFY_OK;
break;
case PM_POST_HIBERNATION:
+ printk(KERN_INFO "dhd_sleep_pm_callback: action=PM_POST_HIBERNATION\n");
case PM_POST_SUSPEND:
+ printk(KERN_INFO "dhd_sleep_pm_callback: action=PM_POST_SUSPEND\n");
dhd_mmc_suspend = FALSE;
+ dhd_customer_gpio_wlan_ctrl(WLAN_POWER_ON);
+ bcmsdh_oob_intr_set(1);
ret = NOTIFY_OK;
break;
}And I've found this to be useful also:
Code:
diff --git a/kernel/power/wakelock.c b/kernel/power/wakelock.c
index 2583856..ebcfd19 100644
--- a/kernel/power/wakelock.c
+++ b/kernel/power/wakelock.c
@@ -350,9 +350,15 @@ static void suspend(struct work_struct *work)
entry_event_num = current_event_num;
suspend_sys_sync_queue();
- if (debug_mask & DEBUG_SUSPEND)
- pr_info("suspend: enter suspend\n");
getnstimeofday(&ts_entry);
+ if (debug_mask & DEBUG_EXIT_SUSPEND) { /* XXX: don't want to enable DEBUG_SUSPEND */
+ struct rtc_time tm;
+ rtc_time_to_tm(ts_entry.tv_sec, &tm);
+ pr_info("suspend: enter suspend "
+ "(%d-%02d-%02d %02d:%02d:%02d.%09lu UTC)\n",
+ tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday,
+ tm.tm_hour, tm.tm_min, tm.tm_sec, ts_exit.tv_nsec);
+ }
ret = pm_suspend(requested_suspend_state);
getnstimeofday(&ts_exit);
@@ -493,8 +499,10 @@ static void wake_lock_internal(
BUG_ON(!(lock->flags & WAKE_LOCK_INITIALIZED));
#ifdef CONFIG_WAKELOCK_STAT
if (type == WAKE_LOCK_SUSPEND && wait_for_wakeup) {
- if (debug_mask & DEBUG_WAKEUP)
+ if (debug_mask & DEBUG_WAKEUP) {
pr_info("wakeup wake lock: %s\n", lock->name);
+ dump_stack();
+ }
wait_for_wakeup = 0;
lock->stat.wakeup_count++;
}