Re: binder stress testing

[Dmitry Vyukov]

On Fri, May 17, 2019 at 5:36 PM Todd Kjos <tkjos@xxxxxxxxxx> wrote:
>
> From: Dmitry Vyukov <dvyukov@xxxxxxxxxx>
> Date: Fri, May 17, 2019 at 3:26 AM
> To: Greg Kroah-Hartman, Arve HjÃnnevÃg, Todd Kjos, Martijn Coenen,
> Joel Fernandes, Christian Brauner, open list:ANDROID DRIVERS, LKML
> Cc: syzkaller
>
> > Hi,
> >
> > I have 2 questions re drivers/android/binder.c stress testing.
> >
> > 1. Are there any docs on the kernel interface? Or some examples on how
> > to use it and reference syscall sequences to make it do something
> > meaningful?
> > I hopefully figured out struct layouts and offsets of objects thing,
> > but I still can't figure out handles, pointers, nodes, pointer to
> > nodes... pointer to data (?), references, cookies and where does one
> > get valid values for these.
>
> The kernel interface is not well documented since it isn't intended to
> be used apart from libbinder. The best example for your purposes is
> probably the binderDriverInterfaceTest which you can find at
> https://android.googlesource.com/platform/frameworks/native/+/refs/heads/master/libs/binder/tests/binderDriverInterfaceTest.cpp.
>
> The libbinder source is at
> https://android.googlesource.com/platform/frameworks/native/+/refs/heads/master/libs/binder.
>
> >
> > 2. In my tests any transaction breaks binder device until the next reboot.
> > If I open binder device twice, mmap, set context and then the process
> > dies, then everything it released fine, in particular the context
> > (context_mgr_node gone). So the device is ready for a next test:
> >
> > [   40.247970][ T6239] binder: binder_open: 6238:6239
> > [   40.250819][ T6239] binder: 6238:6239 node 1 u0000000000000000
> > c0000000000000000 created
> > [   40.253365][ T6239] binder: binder_mmap: 6238 200a0000-200a2000 (8
> > K) vma f9 pagep 8000000000000025
> > [   40.256454][ T6239] binder: binder_open: 6238:6239
> > [   40.259604][ T6239] binder: binder_mmap: 6238 200c0000-200c2000 (8
> > K) vma f9 pagep 8000000000000025
> > [   40.271526][ T6238] binder: 6238 close vm area 200a0000-200a2000 (8
> > K) vma 180200d9 pagep 8000000000000025
> > [   40.273113][ T6238] binder: 6238 close vm area 200c0000-200c2000 (8
> > K) vma 180200d9 pagep 8000000000000025
> > [   40.275058][   T17] binder: binder_flush: 6238 woke 0 threads
> > [   40.275997][   T17] binder: binder_flush: 6238 woke 0 threads
> > [   40.276968][   T17] binder: binder_deferred_release: 6238 threads
> > 0, nodes 0 (ref 0), refs 0, active transactions 0
> > [   40.278626][   T17] binder: binder_deferred_release: 6238
> > context_mgr_node gone
> > [   40.279756][   T17] binder: binder_deferred_release: 6238 threads
> > 1, nodes 1 (ref 0), refs 0, active transactions 0
> >
> >
> > However, if I also send a transaction between these fd's, then
> > context_mgr_node is not released:
> >
> > [  783.851403][ T6167] binder: binder_open: 6166:6167
> > [  783.858801][ T6167] binder: 6166:6167 node 1 u0000000000000000
> > c0000000000000000 created
> > [  783.862458][ T6167] binder: binder_mmap: 6166 200a0000-200a2000 (8
> > K) vma f9 pagep 8000000000000025
> > [  783.865777][ T6167] binder: binder_open: 6166:6167
> > [  783.867892][ T6167] binder: binder_mmap: 6166 200c0000-200c2000 (8
> > K) vma f9 pagep 8000000000000025
> > [  783.870810][ T6167] binder: 6166:6167 write 76 at 0000000020000180,
> > read 0 at 0000000020000300
> > [  783.872211][ T6167] binder: 6166:6167 BC_TRANSACTION 2 -> 6166 -
> > node 1, data 0000000020000200-00000000200002c0 size 88-24-16
> > [  783.873819][ T6167] binder: 6166:6167 node 3 u0000000000000000
> > c0000000000000000 created
> > [  783.875032][ T6167] binder: 6166 new ref 4 desc 1 for node 3
> > [  783.875860][ T6167] binder:         node 3 u0000000000000000 -> ref 4 desc 1
> > [  783.876868][ T6167] binder: 6166:6167 wrote 76 of 76, read return 0 of 0
> > [  783.886714][ T6167] binder: 6166 close vm area 200a0000-200a2000 (8
> > K) vma 180200d9 pagep 8000000000000025
> > [  783.888161][ T6167] binder: 6166 close vm area 200c0000-200c2000 (8
> > K) vma 180200d9 pagep 8000000000000025
> > [  783.890134][   T27] binder: binder_flush: 6166 woke 0 threads
> > [  783.891036][   T27] binder: binder_flush: 6166 woke 0 threads
> > [  783.892027][ T2903] binder: release 6166:6167 transaction 2 out, still active
> > [  783.893097][ T2903] binder: unexpected work type, 4, not freed
> > [  783.893947][ T2903] binder: undelivered TRANSACTION_COMPLETE
> > [  783.894849][ T2903] binder: node 3 now dead, refs 1, death 0
> > [  783.895717][ T2903] binder: binder_deferred_release: 6166 threads
> > 1, nodes 1 (ref 1), refs 0, active transactions 1
> >
> >
> > And all subsequent tests will fail because "BINDER_SET_CONTEXT_MGR
> > already set" presumably to the now unrecoverably dead process:
> >
> > [  831.085174][ T6191] binder: binder_open: 6190:6191
> > [  831.087450][ T6191] binder: BINDER_SET_CONTEXT_MGR already set
> > [  831.088910][ T6191] binder: 6190:6191 ioctl 4018620d 200000c0 returned -16
> > [  831.090626][ T6191] binder: binder_mmap: 6190 200a0000-200a2000 (8
> > K) vma f9 pagep 8000000000000025
> > [  831.092783][ T6191] binder: binder_open: 6190:6191
> > [  831.094076][ T6191] binder: binder_mmap: 6190 200c0000-200c2000 (8
> > K) vma f9 pagep 8000000000000025
> > [  831.096218][ T6191] binder: 6190:6191 write 76 at 0000000020000180,
> > read 0 at 0000000020000300
> > [  831.097606][ T6191] binder: 6190:6191 BC_TRANSACTION 5 -> 6166 -
> > node 1, data 0000000020000200-00000000200002c0 size 88-24-16
> > [  831.099251][ T6191] binder_alloc: 6166: binder_alloc_buf, no vma
> > [  831.100433][ T6191] binder: 6190:6191 transaction failed 29189/-3,
> > size 88-24 line 3157
> > [  831.101559][ T6191] binder: 6190:6191 wrote 76 of 76, read return 0 of 0
> > [  831.110317][ T6191] binder: 6190 close vm area 200a0000-200a2000 (8
> > K) vma 180200d9 pagep 8000000000000025
> > [  831.111752][ T6191] binder: 6190 close vm area 200c0000-200c2000 (8
> > K) vma 180200d9 pagep 8000000000000025
> > [  831.113266][ T3344] binder: binder_flush: 6190 woke 0 threads
> > [  831.114147][ T3344] binder: binder_flush: 6190 woke 0 threads
> > [  831.115087][ T3344] binder: undelivered TRANSACTION_ERROR: 29189
> > [  831.115991][ T3344] binder: binder_deferred_release: 6190 threads
> > 1, nodes 0 (ref 0), refs 0, active transactions 0
> > [  831.117525][ T3344] binder: binder_deferred_release: 6190 threads
> > 1, nodes 0 (ref 0), refs 0, active transactions 0
> >
> >
> > The question is: if processes that opened the device and ever mapped
> > it are now completely gone, should it reset the original state when
> > context can be bound again? Is it a bug in binder that it does not? If
> > so, is there some kind of temp work-around for this?
>
> If all the processes that opened the device are gone, everything
> should be cleaned up and leave binder in a useable state. When the
> device is in this state, can you dump out
> /sys/debug/kernel/binder/state and send it to me?


Here it is:


binder state:
dead nodes:
  node 3: u0000000000000000 c0000000000000000 hs 0 hw 0 ls 0 lw 0 is 1
iw 1 tr 1 proc 6193
proc 6193
context binder0
  thread 6194: l 00 need_return 1 tr 0
  node 1: u0000000000000000 c0000000000000000 hs 1 hw 1 ls 2 lw 1 is 0 iw 0 tr 1
  ref 4: desc 1 dead node 3 s 1 w 0 d 00000000e77aea3b
  buffer 2: 00000000b2301cfa size 88:24:16 active
  pending transaction 2: 00000000b1591166 from 0:0 to 6193:0 code 0
flags 0 pri 0 r1 node 1 size 88:24 data 00000000b2301cfa



Kernel also said:

[  197.049702][   T12] binder: release 6193:6194 transaction 2 out, still active
[  197.050803][   T12] binder: unexpected work type, 4, not freed
[  197.051658][   T12] binder: undelivered TRANSACTION_COMPLETE

Not sure why there is something unexpected. I don't try to fuzz it or
something at this point. Just run a basic test.
Here is the test, it's in syzkaller notation, but hopefully you can
get overall idea:

r0 = syz_open_dev$binder(&AUTO='/dev/binder#\x00', 0x0, 0x2)
ioctl$BINDER_SET_CONTEXT_MGR_EXT(r0, AUTO, &AUTO={AUTO, 0x100, 0x0, 0x0})
mmap$binder(&(0x7f00000a0000), 0x2000, 0x1, 0x11, r0, 0x0)
r1 = syz_open_dev$binder(&AUTO='/dev/binder#\x00', 0x0, 0x2)
mmap$binder(&(0x7f00000c0000), 0x2000, 0x1, 0x11, r1, 0x0)
ioctl$BINDER_WRITE_READ(r1, AUTO, &AUTO={AUTO, AUTO,
&AUTO=[@transaction_sg={AUTO, {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0,
AUTO, AUTO, &AUTO={@flat=@binder={AUTO, 0x0, 0x0, 0x0}, @fd={AUTO,
AUTO, r0, AUTO, 0x0}, @ptr={AUTO, 0x0, &AUTO=""/10, AUTO, 0x0, 0x0}},
&AUTO={AUTO, AUTO, AUTO}}, 0x10}], AUTO, AUTO, &AUTO})