binder: 12682:12687 Release 1 refcount change on invalid ref 1 ret -22
binder: 12682:12687 got transaction to invalid handle
binder: 12682:12687 transaction failed 29201/-22, size 0-8192 line 3005

======================================================
[ INFO: possible circular locking dependency detected ]
4.4.120-gd63fdf6 #28 Not tainted
-------------------------------------------------------
syz-executor2/12723 is trying to acquire lock:
 (&sb->s_type->i_mutex_key#10){+.+.+.}, at: [<ffffffff81463361>] shmem_file_llseek+0xf1/0x240 mm/shmem.c:1816

but task is already holding lock:
 (ashmem_mutex){+.+.+.}, at: [<ffffffff82c62016>] ashmem_llseek+0x56/0x1f0 drivers/staging/android/ashmem.c:330

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

       [<ffffffff8123d7ce>] lock_acquire+0x15e/0x460 kernel/locking/lockdep.c:3592
       [<ffffffff8376a39b>] __mutex_lock_common kernel/locking/mutex.c:521 [inline]
       [<ffffffff8376a39b>] mutex_lock_nested+0xbb/0x850 kernel/locking/mutex.c:621
       [<ffffffff82c61463>] ashmem_mmap+0x53/0x400 drivers/staging/android/ashmem.c:366
       [<ffffffff814b0e4f>] mmap_region+0x94f/0x1250 mm/mmap.c:1664
       [<ffffffff814b1c4d>] do_mmap+0x4fd/0x9d0 mm/mmap.c:1441
       [<ffffffff814700ce>] do_mmap_pgoff include/linux/mm.h:1915 [inline]
       [<ffffffff814700ce>] vm_mmap_pgoff+0x16e/0x1c0 mm/util.c:296
       [<ffffffff814afe1f>] SYSC_mmap_pgoff mm/mmap.c:1491 [inline]
       [<ffffffff814afe1f>] SyS_mmap_pgoff+0x33f/0x560 mm/mmap.c:1449
       [<ffffffff8101beb6>] SYSC_mmap arch/x86/kernel/sys_x86_64.c:95 [inline]
       [<ffffffff8101beb6>] SyS_mmap+0x16/0x20 arch/x86/kernel/sys_x86_64.c:86
       [<ffffffff8377395f>] entry_SYSCALL_64_fastpath+0x1c/0x98

       [<ffffffff8123d7ce>] lock_acquire+0x15e/0x460 kernel/locking/lockdep.c:3592
       [<ffffffff814956ea>] __might_fault+0x14a/0x1d0 mm/memory.c:3810
       [<ffffffff8155ab22>] copy_to_user arch/x86/include/asm/uaccess.h:760 [inline]
       [<ffffffff8155ab22>] filldir+0x162/0x2d0 fs/readdir.c:180
       [<ffffffff8159820e>] dir_emit_dot include/linux/fs.h:3070 [inline]
       [<ffffffff8159820e>] dir_emit_dots include/linux/fs.h:3081 [inline]
       [<ffffffff8159820e>] dcache_readdir+0x11e/0x7b0 fs/libfs.c:150
       [<ffffffff8155a768>] iterate_dir+0x1c8/0x420 fs/readdir.c:42
       [<ffffffff8155b45a>] SYSC_getdents fs/readdir.c:215 [inline]
       [<ffffffff8155b45a>] SyS_getdents+0x14a/0x270 fs/readdir.c:196
       [<ffffffff8377395f>] entry_SYSCALL_64_fastpath+0x1c/0x98

       [<ffffffff8123ab2f>] check_prev_add kernel/locking/lockdep.c:1853 [inline]
       [<ffffffff8123ab2f>] check_prevs_add kernel/locking/lockdep.c:1958 [inline]
       [<ffffffff8123ab2f>] validate_chain kernel/locking/lockdep.c:2144 [inline]
       [<ffffffff8123ab2f>] __lock_acquire+0x371f/0x4b50 kernel/locking/lockdep.c:3213
       [<ffffffff8123d7ce>] lock_acquire+0x15e/0x460 kernel/locking/lockdep.c:3592
       [<ffffffff8376a39b>] __mutex_lock_common kernel/locking/mutex.c:521 [inline]
       [<ffffffff8376a39b>] mutex_lock_nested+0xbb/0x850 kernel/locking/mutex.c:621
       [<ffffffff81463361>] shmem_file_llseek+0xf1/0x240 mm/shmem.c:1816
       [<ffffffff8151c762>] vfs_llseek+0xa2/0xd0 fs/read_write.c:260
       [<ffffffff82c620a7>] ashmem_llseek+0xe7/0x1f0 drivers/staging/android/ashmem.c:342
       [<ffffffff8151e56b>] vfs_llseek fs/read_write.c:260 [inline]
       [<ffffffff8151e56b>] SYSC_lseek fs/read_write.c:285 [inline]
       [<ffffffff8151e56b>] SyS_lseek+0xeb/0x170 fs/read_write.c:276
       [<ffffffff8377395f>] entry_SYSCALL_64_fastpath+0x1c/0x98

other info that might help us debug this:

Chain exists of:
 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(ashmem_mutex);
                               lock(&mm->mmap_sem);
                               lock(ashmem_mutex);
  lock(&sb->s_type->i_mutex_key#10);

 *** DEADLOCK ***

1 lock held by syz-executor2/12723:
 #0:  (ashmem_mutex){+.+.+.}, at: [<ffffffff82c62016>] ashmem_llseek+0x56/0x1f0 drivers/staging/android/ashmem.c:330

stack backtrace:
CPU: 1 PID: 12723 Comm: syz-executor2 Not tainted 4.4.120-gd63fdf6 #28
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
 0000000000000000 74a1b37c41be0607 ffff8800aa157ad8 ffffffff81d0408d
 ffffffff851a0010 ffffffff851a9b50 ffffffff851be7c0 ffff8800b15d38f8
 ffff8800b15d3000 ffff8800aa157b20 ffffffff81233ba1 ffff8800b15d38f8
Call Trace:
 [<ffffffff81d0408d>] __dump_stack lib/dump_stack.c:15 [inline]
 [<ffffffff81d0408d>] dump_stack+0xc1/0x124 lib/dump_stack.c:51
 [<ffffffff81233ba1>] print_circular_bug+0x271/0x310 kernel/locking/lockdep.c:1226
 [<ffffffff8123ab2f>] check_prev_add kernel/locking/lockdep.c:1853 [inline]
 [<ffffffff8123ab2f>] check_prevs_add kernel/locking/lockdep.c:1958 [inline]
 [<ffffffff8123ab2f>] validate_chain kernel/locking/lockdep.c:2144 [inline]
 [<ffffffff8123ab2f>] __lock_acquire+0x371f/0x4b50 kernel/locking/lockdep.c:3213
 [<ffffffff8123d7ce>] lock_acquire+0x15e/0x460 kernel/locking/lockdep.c:3592
 [<ffffffff8376a39b>] __mutex_lock_common kernel/locking/mutex.c:521 [inline]
 [<ffffffff8376a39b>] mutex_lock_nested+0xbb/0x850 kernel/locking/mutex.c:621
 [<ffffffff81463361>] shmem_file_llseek+0xf1/0x240 mm/shmem.c:1816
 [<ffffffff8151c762>] vfs_llseek+0xa2/0xd0 fs/read_write.c:260
 [<ffffffff82c620a7>] ashmem_llseek+0xe7/0x1f0 drivers/staging/android/ashmem.c:342
 [<ffffffff8151e56b>] vfs_llseek fs/read_write.c:260 [inline]
 [<ffffffff8151e56b>] SYSC_lseek fs/read_write.c:285 [inline]
 [<ffffffff8151e56b>] SyS_lseek+0xeb/0x170 fs/read_write.c:276
 [<ffffffff8377395f>] entry_SYSCALL_64_fastpath+0x1c/0x98
binder: undelivered TRANSACTION_ERROR: 29201
check_preemption_disabled: 64 callbacks suppressed
BUG: using __this_cpu_add() in preemptible [00000000] code: syz-executor4/12775
caller is __this_cpu_preempt_check+0x1c/0x20 lib/smp_processor_id.c:62
binder: 12779:12785 IncRefs 0 refcount change on invalid ref 0 ret -22
binder: 12779:12785 BC_CLEAR_DEATH_NOTIFICATION invalid ref 3
binder: 12779:12785 BC_FREE_BUFFER u0000000000000000 no match
audit: type=1400 audit(1521738694.888:201): avc:  denied  { set_context_mgr } for  pid=12779 comm="syz-executor2" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=binder permissive=1
binder: 12779:12788 BC_CLEAR_DEATH_NOTIFICATION invalid ref 3
binder: 12779:12788 BC_FREE_BUFFER u0000000000000000 no match
binder: BINDER_SET_CONTEXT_MGR already set
binder: 12779:12785 ioctl 40046207 0 returned -16
SELinux: unrecognized netlink message: protocol=0 nlmsg_type=51685 sclass=netlink_route_socket
SELinux: unrecognized netlink message: protocol=0 nlmsg_type=51685 sclass=netlink_route_socket
CPU: 1 PID: 12775 Comm: syz-executor4 Not tainted 4.4.120-gd63fdf6 #28
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
 0000000000000000 3eb714a2be69bd42 ffff8801ce4b7638 ffffffff81d0408d
 0000000000000001 ffffffff839fe5a0 ffffffff83cefc20 ffff8800ad326000
 0000000000000003 ffff8801ce4b7678 ffffffff81d63fe4 ffff8801ce52e848
Call Trace:
 [<ffffffff81d0408d>] __dump_stack lib/dump_stack.c:15 [inline]
 [<ffffffff81d0408d>] dump_stack+0xc1/0x124 lib/dump_stack.c:51
 [<ffffffff81d63fe4>] check_preemption_disabled+0x1d4/0x200 lib/smp_processor_id.c:46
 [<ffffffff81d6404c>] __this_cpu_preempt_check+0x1c/0x20 lib/smp_processor_id.c:62
 [<ffffffff8312b439>] tcp_try_coalesce+0x249/0x4d0 net/ipv4/tcp_input.c:4278
 [<ffffffff831335b7>] tcp_queue_rcv+0x127/0x720 net/ipv4/tcp_input.c:4485
 [<ffffffff8314ae8b>] tcp_send_rcvq+0x39b/0x450 net/ipv4/tcp_input.c:4531
 [<ffffffff831220ef>] tcp_sendmsg+0x1e8f/0x2b10 net/ipv4/tcp.c:1134
 [<ffffffff831d7d4c>] inet_sendmsg+0x2bc/0x4c0 net/ipv4/af_inet.c:755
 [<ffffffff82deba6a>] sock_sendmsg_nosec net/socket.c:625 [inline]
 [<ffffffff82deba6a>] sock_sendmsg+0xca/0x110 net/socket.c:635
 [<ffffffff82debcd6>] sock_write_iter+0x226/0x3b0 net/socket.c:834
 [<ffffffff8151e0b8>] do_iter_readv_writev+0x138/0x1e0 fs/read_write.c:664
 [<ffffffff8151f852>] do_readv_writev+0x2d2/0x6e0 fs/read_write.c:808
 [<ffffffff8151fd8b>] vfs_writev+0x7b/0xb0 fs/read_write.c:847
 [<ffffffff81522249>] SYSC_writev fs/read_write.c:880 [inline]
 [<ffffffff81522249>] SyS_writev+0xd9/0x240 fs/read_write.c:872
 [<ffffffff8377395f>] entry_SYSCALL_64_fastpath+0x1c/0x98
SELinux: unrecognized netlink message: protocol=0 nlmsg_type=64282 sclass=netlink_route_socket
binder: 12958:12963 got reply transaction with no transaction stack
binder: 12958:12963 transaction failed 29201/-71, size 88-8 line 2921
binder: 12958:12974 got reply transaction with no transaction stack
binder: 12958:12974 transaction failed 29201/-71, size 88-8 line 2921
audit: type=1400 audit(1521738696.818:202): avc:  denied  { create } for  pid=13094 comm="syz-executor2" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_netfilter_socket permissive=1
audit: type=1400 audit(1521738696.858:203): avc:  denied  { create } for  pid=13094 comm="syz-executor2" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_netfilter_socket permissive=1
audit: type=1400 audit(1521738696.888:205): avc:  denied  { write } for  pid=13094 comm="syz-executor2" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_netfilter_socket permissive=1
audit: type=1400 audit(1521738696.888:204): avc:  denied  { read } for  pid=13094 comm="syz-executor2" path="socket:[28761]" dev="sockfs" ino=28761 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_netfilter_socket permissive=1
audit: type=1400 audit(1521738696.978:206): avc:  denied  { create } for  pid=13111 comm="syz-executor5" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_generic_socket permissive=1
SELinux: unrecognized netlink message: protocol=0 nlmsg_type=0 sclass=netlink_route_socket
SELinux: unrecognized netlink message: protocol=0 nlmsg_type=0 sclass=netlink_route_socket
audit: type=1400 audit(1521738697.058:207): avc:  denied  { create } for  pid=13111 comm="syz-executor5" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_generic_socket permissive=1
SELinux: unrecognized netlink message: protocol=0 nlmsg_type=1685 sclass=netlink_route_socket
SELinux: unrecognized netlink message: protocol=0 nlmsg_type=1685 sclass=netlink_route_socket
audit: type=1400 audit(1521738697.238:208): avc:  denied  { create } for  pid=13171 comm="syz-executor3" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_generic_socket permissive=1
audit: type=1400 audit(1521738697.268:209): avc:  denied  { write } for  pid=13171 comm="syz-executor3" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_generic_socket permissive=1
binder: 13241:13249 transaction failed 29189/-22, size 524328-4611686018427387912 line 3005
binder: 13241:13249 transaction failed 29189/-22, size 524328-4611686018427387912 line 3005
binder: undelivered TRANSACTION_ERROR: 29189
binder: undelivered TRANSACTION_ERROR: 29189
netlink: 16 bytes leftover after parsing attributes in process `syz-executor4'.
netlink: 16 bytes leftover after parsing attributes in process `syz-executor4'.
binder: 13425:13441 tried to acquire reference to desc 0, got 1 instead
binder: 13425:13434 BC_REQUEST_DEATH_NOTIFICATION invalid ref 0
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
audit_printk_skb: 45 callbacks suppressed
audit: type=1400 audit(1521738701.438:226): avc:  denied  { create } for  pid=13963 comm="syz-executor2" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_netfilter_socket permissive=1
audit: type=1400 audit(1521738701.388:225): avc:  denied  { create } for  pid=13963 comm="syz-executor2" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_netfilter_socket permissive=1
audit: type=1400 audit(1521738702.038:227): avc:  denied  { create } for  pid=14092 comm="syz-executor5" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_iscsi_socket permissive=1
audit: type=1400 audit(1521738702.138:228): avc:  denied  { create } for  pid=14092 comm="syz-executor5" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_iscsi_socket permissive=1
audit: type=1400 audit(1521738702.678:229): avc:  denied  { create } for  pid=14231 comm="syz-executor5" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_crypto_socket permissive=1
audit: type=1400 audit(1521738702.698:230): avc:  denied  { set_context_mgr } for  pid=14233 comm="syz-executor4" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=binder permissive=1
binder: 14233:14243 ioctl c0306201 2000a000 returned -11
binder: 14233:14243 ioctl c0306201 2000afd0 returned -14
binder_alloc: binder_alloc_mmap_handler: 14233 20000000-20002000 already mapped failed -16
binder: BINDER_SET_CONTEXT_MGR already set
binder: 14233:14251 ioctl 40046207 0 returned -16
binder: 14233:14251 ioctl c0306201 2000a000 returned -11
binder: 14233:14251 ioctl c0306201 2000afd0 returned -14
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
audit: type=1400 audit(1521738702.828:231): avc:  denied  { create } for  pid=14231 comm="syz-executor5" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_crypto_socket permissive=1
audit: type=1400 audit(1521738703.078:232): avc:  denied  { create } for  pid=14305 comm="syz-executor5" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_generic_socket permissive=1
audit: type=1400 audit(1521738703.128:233): avc:  denied  { create } for  pid=14305 comm="syz-executor5" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_generic_socket permissive=1
audit: type=1400 audit(1521738703.228:234): avc:  denied  { create } for  pid=14349 comm="syz-executor0" scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=netlink_netfilter_socket permissive=1