Snowball: Board hangs while doing Bluetooth file transfer

[Abhishek Paliwal]

Description:
==========
Trying to send a image file( from gallery app) over Bluetooth to another phone.
File transfer didn't complete and snowball board hangs during file transfer, need to reboot device to use it again.

Serial Logs shows following messages:
-------------------

[ 225.481964] INFO: rcu_preempt detected stalls on CPUs/tasks: { 0} (detected by 1, t=6002 jiffies)
[ 225.490875] Backtrace for cpu 1 (current):
[ 225.494995] [<c001d8a0>] (unwind_backtrace+0x0/0x144) from [<c05e5aec>] (dump_stack+0x20/0x24)
[ 225.503631] [<c05e5aec>] (dump_stack+0x20/0x24) from [<c001aecc>] (smp_send_all_cpu_backtrace+0x70/0xd4)
[ 225.513092] [<c001aecc>] (smp_send_all_cpu_backtrace+0x70/0xd4) from [<c0016678>] (arch_trigger_all_cpu_backtrace+0x18/0x1c)
[ 225.524322] [<c0016678>] (arch_trigger_all_cpu_backtrace+0x18/0x1c) from [<c00982dc>] (__rcu_pending+0x3dc/0x468)
[ 225.534576] [<c00982dc>] (__rcu_pending+0x3dc/0x468) from [<c0099eb4>] (rcu_check_callbacks+0x21c/0x2c8)
[ 225.544067] [<c0099eb4>] (rcu_check_callbacks+0x21c/0x2c8) from [<c0041048>] (update_process_times+0x48/0x78)
[ 225.553985] [<c0041048>] (update_process_times+0x48/0x78) from [<c007b6d4>] (tick_sched_timer+0x98/0xe8)
[ 225.563476] [<c007b6d4>] (tick_sched_timer+0x98/0xe8) from [<c0056668>] (__run_hrtimer+0x94/0x2c8)
[ 225.572448] [<c0056668>] (__run_hrtimer+0x94/0x2c8) from [<c005763c>] (hrtimer_interrupt+0x12c/0x29c)
[ 225.581665] [<c005763c>] (hrtimer_interrupt+0x12c/0x29c) from [<c001bacc>] (twd_handler+0x40/0x54)
[ 225.590637] [<c001bacc>] (twd_handler+0x40/0x54) from [<c00953fc>] (handle_percpu_devid_irq+0xb0/0x1e4)
[ 225.600036] [<c00953fc>] (handle_percpu_devid_irq+0xb0/0x1e4) from [<c00915f8>] (generic_handle_irq+0x3c/0x50)
[ 225.610015] [<c00915f8>] (generic_handle_irq+0x3c/0x50) from [<c0016058>] (handle_IRQ+0x5c/0xbc)
[ 225.618804] [<c0016058>] (handle_IRQ+0x5c/0xbc) from [<c0008544>] (gic_handle_irq+0x34/0xb8)
[ 225.627258] [<c0008544>] (gic_handle_irq+0x34/0xb8) from [<c0014c80>] (__irq_svc+0x40/0x70)
[ 225.635589] Exception stack(0xeaa3fbd0 to 0xeaa3fc18)
[ 225.640655] fbc0: 00000002 00000002 00000008 00000001
[ 225.648834] fbe0: eaa3fc54 c1732ac0 00000000 c1732ac0 00e42000 c1732ac8 00000001 eaa3fc44
[ 225.656982] fc00: 00000001 eaa3fc18 c002627c c00809a0 20000013 ffffffff
[ 225.663604] [<c0014c80>] (__irq_svc+0x40/0x70) from [<c00809a0>] (generic_exec_single+0x84/0xa0)
[ 225.672393] [<c00809a0>] (generic_exec_single+0x84/0xa0) from [<c0080ae4>] (smp_call_function_single+0x128/0x1e0)
[ 225.682647] [<c0080ae4>] (smp_call_function_single+0x128/0x1e0) from [<c0080de0>] (smp_call_function_many+0x244/0x290)
[ 225.693359] [<c0080de0>] (smp_call_function_many+0x244/0x290) from [<c0080e7c>] (smp_call_function+0x50/0x7c)
[ 225.703247] [<c0080e7c>] (smp_call_function+0x50/0x7c) from [<c0080ee0>] (on_each_cpu+0x38/0x78)
[ 225.712066] [<c0080ee0>] (on_each_cpu+0x38/0x78) from [<c00c7b18>] (drain_all_pages+0x28/0x2c)
[ 225.720672] [<c00c7b18>] (drain_all_pages+0x28/0x2c) from [<c00ca188>] (__alloc_pages_nodemask+0x480/0x6f0)
[ 225.730407] [<c00ca188>] (__alloc_pages_nodemask+0x480/0x6f0) from [<c05e76b8>] (cache_alloc_refill+0x2d4/0x520)
[ 225.740600] [<c05e76b8>] (cache_alloc_refill+0x2d4/0x520) from [<c00f45d0>] (kmem_cache_alloc+0xbc/0x16c)
[ 225.750183] [<c00f45d0>] (kmem_cache_alloc+0xbc/0x16c) from [<c00f8690>] (get_empty_filp+0x7c/0x1b8)
[ 225.759307] [<c00f8690>] (get_empty_filp+0x7c/0x1b8) from [<c01057bc>] (path_openat+0x38/0x3b0)
[ 225.768005] [<c01057bc>] (path_openat+0x38/0x3b0) from [<c0105c60>] (do_filp_open+0x3c/0x90)
[ 225.776428] [<c0105c60>] (do_filp_open+0x3c/0x90) from [<c00f63d0>] (do_sys_open+0xec/0x184)
[ 225.784881] [<c00f63d0>] (do_sys_open+0xec/0x184) from [<c00f6494>] (sys_open+0x2c/0x30)
[ 225.792968] [<c00f6494>] (sys_open+0x2c/0x30) from [<c0015080>] (ret_fast_syscall+0x0/0x30)
[ 225.801300]
[ 225.801330] sending IPI to all other CPUs:
[ 405.801940] INFO: rcu_preempt detected stalls on CPUs/tasks: { 0} (detected by 1, t=24034 jiffies)
[ 405.810913] Backtrace for cpu 1 (current):
[ 405.815002] [<c001d8a0>] (unwind_backtrace+0x0/0x144) from [<c05e5aec>] (dump_stack+0x20/0x24)
[ 405.823608] [<c05e5aec>] (dump_stack+0x20/0x24) from [<c001aecc>] (smp_send_all_cpu_backtrace+0x70/0xd4)
[ 405.833099] [<c001aecc>] (smp_send_all_cpu_backtrace+0x70/0xd4) from [<c0016678>] (arch_trigger_all_cpu_backtrace+0x18/0x1c)
[ 405.844329] [<c0016678>] (arch_trigger_all_cpu_backtrace+0x18/0x1c) from [<c00982dc>] (__rcu_pending+0x3dc/0x468)
[ 405.854583] [<c00982dc>] (__rcu_pending+0x3dc/0x468) from [<c0099eb4>] (rcu_check_callbacks+0x21c/0x2c8)
[ 405.864044] [<c0099eb4>] (rcu_check_callbacks+0x21c/0x2c8) from [<c0041048>] (update_process_times+0x48/0x78)
[ 405.873962] [<c0041048>] (update_process_times+0x48/0x78) from [<c007b6d4>] (tick_sched_timer+0x98/0xe8)
[ 405.883453] [<c007b6d4>] (tick_sched_timer+0x98/0xe8) from [<c0056668>] (__run_hrtimer+0x94/0x2c8)
[ 405.892425] [<c0056668>] (__run_hrtimer+0x94/0x2c8) from [<c005763c>] (hrtimer_interrupt+0x12c/0x29c)
[ 405.901641] [<c005763c>] (hrtimer_interrupt+0x12c/0x29c) from [<c001bacc>] (twd_handler+0x40/0x54)
[ 405.910583] [<c001bacc>] (twd_handler+0x40/0x54) from [<c00953fc>] (handle_percpu_devid_irq+0xb0/0x1e4)
[ 405.919982] [<c00953fc>] (handle_percpu_devid_irq+0xb0/0x1e4) from [<c00915f8>] (generic_handle_irq+0x3c/0x50)
[ 405.929992] [<c00915f8>] (generic_handle_irq+0x3c/0x50) from [<c0016058>] (handle_IRQ+0x5c/0xbc)
[ 405.938781] [<c0016058>] (handle_IRQ+0x5c/0xbc) from [<c0008544>] (gic_handle_irq+0x34/0xb8)
[ 405.947204] [<c0008544>] (gic_handle_irq+0x34/0xb8) from [<c0014c80>] (__irq_svc+0x40/0x70)
[ 405.955535] Exception stack(0xeaa3fbd0 to 0xeaa3fc18)
[ 405.960601] fbc0: 00000002 00000002 00000008 00000001
[ 405.968780] fbe0: eaa3fc54 c1732ac0 00000000 c1732ac0 00e42000 c1732ac8 00000001 eaa3fc44
[ 405.976928] fc00: 00000001 eaa3fc18 c002627c c0080998 20000013 ffffffff
[ 405.983551] [<c0014c80>] (__irq_svc+0x40/0x70) from [<c0080998>] (generic_exec_single+0x7c/0xa0)
[ 405.992340] [<c0080998>] (generic_exec_single+0x7c/0xa0) from [<c0080ae4>] (smp_call_function_single+0x128/0x1e0)
[ 406.002593] [<c0080ae4>] (smp_call_function_single+0x128/0x1e0) from [<c0080de0>] (smp_call_function_many+0x244/0x290)
[ 406.013305] [<c0080de0>] (smp_call_function_many+0x244/0x290) from [<c0080e7c>] (smp_call_function+0x50/0x7c)
[ 406.023193] [<c0080e7c>] (smp_call_function+0x50/0x7c) from [<c0080ee0>] (on_each_cpu+0x38/0x78)
[ 406.031982] [<c0080ee0>] (on_each_cpu+0x38/0x78) from [<c00c7b18>] (drain_all_pages+0x28/0x2c)
[ 406.040588] [<c00c7b18>] (drain_all_pages+0x28/0x2c) from [<c00ca188>] (__alloc_pages_nodemask+0x480/0x6f0)
[ 406.050354] [<c00ca188>] (__alloc_pages_nodemask+0x480/0x6f0) from [<c05e76b8>] (cache_alloc_refill+0x2d4/0x520)
[ 406.060516] [<c05e76b8>] (cache_alloc_refill+0x2d4/0x520) from [<c00f45d0>] (kmem_cache_alloc+0xbc/0x16c)
[ 406.070098] [<c00f45d0>] (kmem_cache_alloc+0xbc/0x16c) from [<c00f8690>] (get_empty_filp+0x7c/0x1b8)
[ 406.079223] [<c00f8690>] (get_empty_filp+0x7c/0x1b8) from [<c01057bc>] (path_openat+0x38/0x3b0)
[ 406.087921] [<c01057bc>] (path_openat+0x38/0x3b0) from [<c0105c60>] (do_filp_open+0x3c/0x90)
[ 406.096343] [<c0105c60>] (do_filp_open+0x3c/0x90) from [<c00f63d0>] (do_sys_open+0xec/0x184)
[ 406.104797] [<c00f63d0>] (do_sys_open+0xec/0x184) from [<c00f6494>] (sys_open+0x2c/0x30)
[ 406.112884] [<c00f6494>] (sys_open+0x2c/0x30) from [<c0015080>] (ret_fast_syscall+0x0/0x30)
[ 406.121215]
[ 406.121215] sending IPI to all other CPUs:

IMPACT:
=======
BT file transfer fails.

Reproducible:
===========
2/2

Steps:
=======

1. Bootup snowball device, turn ON Bluetooth, Connect to a commercial phone having BT feature.
2. After pairing is done , open Gallery app(assuming it has some image files , otherwise copy some jpeg images to sd card)
3. Log press an image ->select share option->via Bluetooth->Select paired device ->File transfer should start.
Issue: After around 8% file transfer the snowball board hangs for 30 seconds and then prints the error logs and then hangs completely.

Logs:
======
See attached logs

[Paul Larson (pwlars)]

I'm not sure if this is specific to snowball, or even if it is related to bluetooth. I just hit a backtrace that appears to be the same on a pandaboard after transferring a file over USB and letting it sit idle for a few minutes with an open adb shell connection:
[ 1178.132659] INFO: rcu_preempt detected stalls on CPUs/tasks: { 0} (detected by 1, t=7682 jiffies)
[ 1178.141998] Backtrace for cpu 1 (current):
[ 1178.146331] [<c0019fb4>] (unwind_backtrace+0x0/0xf8) from [<c00183bc>] (smp_send_all_cpu_backtrace+0x5c/0xc0)
[ 1178.156799] [<c00183bc>] (smp_send_all_cpu_backtrace+0x5c/0xc0) from [<c008a7b4>] (__rcu_pending+0x39c/0x418)
[ 1178.167236] [<c008a7b4>] (__rcu_pending+0x39c/0x418) from [<c008b360>] (rcu_check_callbacks+0x194/0x2a4)
[ 1178.177215] [<c008b360>] (rcu_check_callbacks+0x194/0x2a4) from [<c0052dc4>] (update_process_times+0x38/0x4c)
[ 1178.187683] [<c0052dc4>] (update_process_times+0x38/0x4c) from [<c0071804>] (tick_sched_timer+0x88/0xd8)
[ 1178.197662] [<c0071804>] (tick_sched_timer+0x88/0xd8) from [<c0065b14>] (__run_hrtimer+0x7c/0x278)
[ 1178.207092] [<c0065b14>] (__run_hrtimer+0x7c/0x278) from [<c0066900>] (hrtimer_interrupt+0x114/0x2a0)
[ 1178.216796] [<c0066900>] (hrtimer_interrupt+0x114/0x2a0) from [<c0018c14>] (twd_handler+0x30/0x44)
[ 1178.226226] [<c0018c14>] (twd_handler+0x30/0x44) from [<c0086b44>] (handle_percpu_devid_irq+0x90/0x180)
[ 1178.236145] [<c0086b44>] (handle_percpu_devid_irq+0x90/0x180) from [<c0083434>] (generic_handle_irq+0x28/0x3c)
[ 1178.246673] [<c0083434>] (generic_handle_irq+0x28/0x3c) from [<c0014298>] (handle_IRQ+0x4c/0xb0)
[ 1178.255950] [<c0014298>] (handle_IRQ+0x4c/0xb0) from [<c06288f4>] (__irq_svc+0x34/0xac)
[ 1178.264343] [<c06288f4>] (__irq_svc+0x34/0xac) from [<c0628484>] (__raw_spin_lock_irqsave+0x88/0xa8)
[ 1178.273986] [<c0628484>] (__raw_spin_lock_irqsave+0x88/0xa8) from [<bf0141fc>] (st_unregister+0x38/0x144 [st_drv])
[ 1178.284881] [<bf0141fc>] (st_unregister+0x38/0x144 [st_drv]) from [<bf06b04c>] (ti_st_close+0x3c/0x84 [btwilink])
[ 1178.295806] [<bf06b04c>] (ti_st_close+0x3c/0x84 [btwilink]) from [<bf01f84c>] (hci_dev_do_close+0x104/0x1e4 [bluetooth])
[ 1178.307281] [<bf01f84c>] (hci_dev_do_close+0x104/0x1e4 [bluetooth]) from [<bf0202e8>] (hci_dev_close+0x14/0x68 [bluetooth])
[ 1178.319061] [<bf0202e8>] (hci_dev_close+0x14/0x68 [bluetooth]) from [<bf02bfbc>] (hci_sock_ioctl+0x190/0x3cc [bluetooth])
[ 1178.330596] [<bf02bfbc>] (hci_sock_ioctl+0x190/0x3cc [bluetooth]) from [<c04a8b14>] (sock_ioctl+0x70/0x264)
[ 1178.340850] [<c04a8b14>] (sock_ioctl+0x70/0x264) from [<c00e7404>] (do_vfs_ioctl+0x80/0x534)
[ 1178.349731] [<c00e7404>] (do_vfs_ioctl+0x80/0x534) from [<c00e7924>] (sys_ioctl+0x6c/0x7c)
[ 1178.358428] [<c00e7924>] (sys_ioctl+0x6c/0x7c) from [<c00133a0>] (ret_fast_syscall+0x0/0x30)
[ 1178.367309]
[ 1178.367309] sending IPI to all other CPUs:
[ 1358.382690] INFO: rcu_preempt detected stalls on CPUs/tasks: { 0} (detected by 1, t=30754 jiffies)
[ 1358.392120] Backtrace for cpu 1 (current):
[ 1358.396453] [<c0019fb4>] (unwind_backtrace+0x0/0xf8) from [<c00183bc>] (smp_send_all_cpu_backtrace+0x5c/0xc0)
[ 1358.406890] [<c00183bc>] (smp_send_all_cpu_backtrace+0x5c/0xc0) from [<c00...

[Paul Larson (pwlars)]

Sorry, should have mentioned, the panda build I hit this with was https://android-build.linaro.org/builds/~linaro-android/panda-ics-gcc47-tilt-tracking-blob/#build=93

[vishal (vishalbhoj)]

snowball is no more supported.