[PATCH] ANDROID: binder: Latelimit binder_debug().

[Tetsuo Handa]

On 2018/07/09 23:29, Tetsuo Handa wrote:
> On 2018/07/09 23:02, Martijn Coenen wrote:
>> On Mon, Jul 9, 2018 at 3:27 PM, Dmitry Vyukov <dvyukov at google.com> wrote:
>>> I know almost nothing about binder. How these debug messages are
>>> enabled?  I don't see anything like CONFIG_BINDER_VERBOSE_DEBUG in the
>>> config:
>>> https://github.com/google/syzkaller/blob/master/dashboard/config/upstream-kasan.config
>>> Also no mentions of binder in sysctl/cmline.
>>> All binder maintainers are in CC already, perhaps they can shed some
>>> light on this.
>>
>> Some are enabled by default here:
>> https://github.com/torvalds/linux/blob/master/drivers/android/binder.c#L138
>>
>> Perhaps we should revise that set then, as it can be quite noisy when
>> lots of processes are dying (which also happens a lot in syzbot
>> tests).
>>
> 
> OK. Then, I think we should consider disabling by default or latelimit printk().
> Repeating hundreds of (or maybe thousands of ?) similar messages is not useful
> (and blocking other threads due to processing flood of printk() is not good).
> 

I don't have benchmark data (I'm not an Android user). But an example log at
https://syzkaller.appspot.com/text?tag=CrashLog&x=12f316fc400000 got
about 13214 messages in 124 seconds (over 100 messages per a second).
Without disabling by default or latelimit printk(), the system shall become unusable.

$ grep binder: log | wc -l
13214
$ head log
[ 1167.389978] binder: 15631:15631 got reply transaction with no transaction stack
[ 1167.391813] binder: 15629:15629 transaction failed 29201/-71, size 0-8 line 2759
[ 1167.399282] binder: 15631:15631 transaction failed 29201/-71, size 0-8 line 2759
[ 1167.399548] binder: undelivered TRANSACTION_ERROR: 29201
[ 1167.419645] binder: 15625:15625 got reply transaction with no transaction stack
[ 1167.427800] binder: 15625:15625 transaction failed 29201/-71, size 0-8 line 2759
[ 1167.461506] binder: 15634:15634 got reply transaction with no transaction stack
[ 1167.469060] binder: 15634:15634 transaction failed 29201/-71, size 0-8 line 2759
[ 1167.472747] binder: 15638:15638 got reply transaction with no transaction stack
[ 1167.477550] binder: 15633:15633 got reply transaction with no transaction stack
$ tail log
[ 1291.131046] binder: 25566:25566 transaction failed 29201/-71, size 0-8 line 2759
[ 1291.140761] binder: 25553:25553 got reply transaction with no transaction stack
[ 1291.151698] binder: 25553:25553 transaction failed 29201/-71, size 0-8 line 2759
[ 1291.182362] binder: 25568:25568 got reply transaction with no transaction stack
[ 1291.183361] binder: undelivered TRANSACTION_ERROR: 29201
[ 1291.189926] binder: 25568:25568 transaction failed 29201/-71, size 0-8 line 2759
[ 1291.204438] binder: 25569:25569 got reply transaction with no transaction stack
[ 1291.211953] binder: 25569:25569 transaction failed 29201/-71, size 0-8 line 2759
[ 1291.213825] binder: 25572:25572 got reply transaction with no transaction stack
[ 1291.227018] binder: 25572:25572 transaction failed 29201/-71, size 0-8 line 2759