====================================================== [ INFO: possible circular locking dependency detected ] 4.4.120-gd63fdf6 #29 Not tainted ------------------------------------------------------- syz-executor2/13545 is trying to acquire lock: (&sb->s_type->i_mutex_key#10){+.+.+.}, at: [ 81.947030] binder: 13558:13559 transaction failed 29189/-22, size 24-8 line 3005 binder: BINDER_SET_CONTEXT_MGR already set binder: 13558:13559 ioctl 40046207 0 returned -16 binder: 13558:13560 transaction failed 29189/-22, size 24-8 line 3005 binder: undelivered TRANSACTION_ERROR: 29189 binder: undelivered TRANSACTION_ERROR: 29189 [] shmem_file_llseek+0xf1/0x240 mm/shmem.c:1816 but task is already holding lock: (ashmem_mutex){+.+.+.}, at: [] 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: [] lock_acquire+0x15e/0x460 kernel/locking/lockdep.c:3592 [] __mutex_lock_common kernel/locking/mutex.c:521 [inline] [] mutex_lock_nested+0xbb/0x850 kernel/locking/mutex.c:621 [] ashmem_mmap+0x53/0x400 drivers/staging/android/ashmem.c:366 [] mmap_region+0x94f/0x1250 mm/mmap.c:1664 [] do_mmap+0x4fd/0x9d0 mm/mmap.c:1441 [] do_mmap_pgoff include/linux/mm.h:1915 [inline] [] vm_mmap_pgoff+0x16e/0x1c0 mm/util.c:296 [] SYSC_mmap_pgoff mm/mmap.c:1491 [inline] [] SyS_mmap_pgoff+0x33f/0x560 mm/mmap.c:1449 [] do_syscall_32_irqs_on arch/x86/entry/common.c:392 [inline] [] do_fast_syscall_32+0x321/0x8a0 arch/x86/entry/common.c:459 [] sysenter_flags_fixed+0xd/0x17 [] lock_acquire+0x15e/0x460 kernel/locking/lockdep.c:3592 [] __might_fault+0x14a/0x1d0 mm/memory.c:3810 [] copy_to_user arch/x86/include/asm/uaccess.h:760 [inline] [] filldir+0x162/0x2d0 fs/readdir.c:180 [] dir_emit_dot include/linux/fs.h:3070 [inline] [] dir_emit_dots include/linux/fs.h:3081 [inline] [] dcache_readdir+0x11e/0x7b0 fs/libfs.c:150 [] iterate_dir+0x1c8/0x420 fs/readdir.c:42 [] SYSC_getdents fs/readdir.c:215 [inline] [] SyS_getdents+0x14a/0x270 fs/readdir.c:196 [] entry_SYSCALL_64_fastpath+0x1c/0x98 [] check_prev_add kernel/locking/lockdep.c:1853 [inline] [] check_prevs_add kernel/locking/lockdep.c:1958 [inline] [] validate_chain kernel/locking/lockdep.c:2144 [inline] [] __lock_acquire+0x371f/0x4b50 kernel/locking/lockdep.c:3213 [] lock_acquire+0x15e/0x460 kernel/locking/lockdep.c:3592 [] __mutex_lock_common kernel/locking/mutex.c:521 [inline] [] mutex_lock_nested+0xbb/0x850 kernel/locking/mutex.c:621 [] shmem_file_llseek+0xf1/0x240 mm/shmem.c:1816 [] vfs_llseek+0xa2/0xd0 fs/read_write.c:260 [] ashmem_llseek+0xe7/0x1f0 drivers/staging/android/ashmem.c:342 [] vfs_llseek fs/read_write.c:260 [inline] [] SYSC_lseek fs/read_write.c:285 [inline] [] SyS_lseek fs/read_write.c:276 [inline] [] C_SYSC_lseek fs/read_write.c:297 [inline] [] compat_SyS_lseek+0xeb/0x170 fs/read_write.c:295 [] do_syscall_32_irqs_on arch/x86/entry/common.c:392 [inline] [] do_fast_syscall_32+0x321/0x8a0 arch/x86/entry/common.c:459 Buffer I/O error on dev loop2, logical block 0, lost async page write [] sysenter_flags_fixed+0xd/0x17 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/13545: #0: (ashmem_mutex){+.+.+.}, at: [] ashmem_llseek+0x56/0x1f0 drivers/staging/android/ashmem.c:330 stack backtrace: CPU: 1 PID: 13545 Comm: syz-executor2 Not tainted 4.4.120-gd63fdf6 #29 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 0000000000000000 7c6bd5737404129c ffff8801c4df7a58 ffffffff81d0408d ffffffff8519fe60 ffffffff851a99a0 ffffffff851becd0 ffff8801c38a68f8 ffff8801c38a6000 ffff8801c4df7aa0 ffffffff81233ba1 ffff8801c38a68f8 Call Trace: [] __dump_stack lib/dump_stack.c:15 [inline] [] dump_stack+0xc1/0x124 lib/dump_stack.c:51 [] print_circular_bug+0x271/0x310 kernel/locking/lockdep.c:1226 [] check_prev_add kernel/locking/lockdep.c:1853 [inline] [] check_prevs_add kernel/locking/lockdep.c:1958 [inline] [] validate_chain kernel/locking/lockdep.c:2144 [inline] [] __lock_acquire+0x371f/0x4b50 kernel/locking/lockdep.c:3213 [] lock_acquire+0x15e/0x460 kernel/locking/lockdep.c:3592 [] __mutex_lock_common kernel/locking/mutex.c:521 [inline] [] mutex_lock_nested+0xbb/0x850 kernel/locking/mutex.c:621 [] shmem_file_llseek+0xf1/0x240 mm/shmem.c:1816 [] vfs_llseek+0xa2/0xd0 fs/read_write.c:260 [] ashmem_llseek+0xe7/0x1f0 drivers/staging/android/ashmem.c:342 [] vfs_llseek fs/read_write.c:260 [inline] [] SYSC_lseek fs/read_write.c:285 [inline] [] SyS_lseek fs/read_write.c:276 [inline] [] C_SYSC_lseek fs/read_write.c:297 [inline] [] compat_SyS_lseek+0xeb/0x170 fs/read_write.c:295 [] do_syscall_32_irqs_on arch/x86/entry/common.c:392 [inline] [] do_fast_syscall_32+0x321/0x8a0 arch/x86/entry/common.c:459 [] sysenter_flags_fixed+0xd/0x17 audit_printk_skb: 15 callbacks suppressed audit: type=1400 audit(1521582285.612:102): avc: denied { create } for pid=13642 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_crypto_socket permissive=1 audit: type=1400 audit(1521582285.542:101): avc: denied { create } for pid=13642 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_crypto_socket permissive=1 binder: 13855:13857 got transaction to invalid handle binder: 13855:13857 transaction failed 29201/-22, size 48-24 line 3005 binder: 13855:13863 got transaction to invalid handle binder: 13855:13863 transaction failed 29201/-22, size 48-24 line 3005 audit: type=1400 audit(1521582287.112:103): avc: denied { create } for pid=13982 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_generic_socket permissive=1 audit: type=1400 audit(1521582287.152:104): avc: denied { create } for pid=13982 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_generic_socket permissive=1 audit: type=1326 audit(1521582287.762:105): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 pid=14127 comm="syz-executor1" exe="/root/syz-executor1" sig=31 arch=40000003 syscall=240 compat=1 ip=0xf776dba9 code=0x0 audit: type=1400 audit(1521582287.882:106): avc: denied { create } for pid=14158 comm="syz-executor1" 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(1521582287.922:107): avc: denied { getopt } for pid=14158 comm="syz-executor1" 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(1521582287.972:108): avc: denied { write } for pid=14158 comm="syz-executor1" path="socket:[28445]" dev="sockfs" ino=28445 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(1521582288.022:109): avc: denied { create } for pid=14158 comm="syz-executor1" 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(1521582288.022:110): avc: denied { write } for pid=14158 comm="syz-executor1" 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 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=12421 sclass=netlink_route_socket binder: 14305:14312 ioctl 4b6d 0 returned -22 binder: 14305:14312 BC_REQUEST_DEATH_NOTIFICATION invalid ref 4 binder: 14305:14312 ERROR: BC_REGISTER_LOOPER called without request binder: 14305:14332 ioctl 4b6d 0 returned -22 binder: 14305:14312 Release 1 refcount change on invalid ref 4 ret -22 binder: 14305:14312 ERROR: BC_REGISTER_LOOPER called without request binder: 14305:14332 BC_REQUEST_DEATH_NOTIFICATION invalid ref 4 binder: 14305:14332 ERROR: BC_REGISTER_LOOPER called without request binder: 14305:14312 BC_DEAD_BINDER_DONE 0000000000000003 not found binder: 14305:14332 Release 1 refcount change on invalid ref 4 ret -22 binder: 14305:14332 ERROR: BC_REGISTER_LOOPER called without request binder: 14305:14332 BC_DEAD_BINDER_DONE 0000000000000003 not found sd 0:0:1:0: [sg0] tag#48 FAILED Result: hostbyte=DID_ABORT driverbyte=DRIVER_OK sd 0:0:1:0: [sg0] tag#48 CDB: Test Unit Ready sd 0:0:1:0: [sg0] tag#48 CDB[00]: 00 05 00 20 4a 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#48 CDB[10]: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#48 CDB[20]: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#48 CDB[30]: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#48 CDB[40]: 2e 2f 66 69 6c 65 30 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#48 CDB[50]: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#48 CDB[60]: 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#175 FAILED Result: hostbyte=DID_ABORT driverbyte=DRIVER_OK sd 0:0:1:0: [sg0] tag#175 CDB: Test Unit Ready sd 0:0:1:0: [sg0] tag#175 CDB[00]: 00 05 00 20 4a 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#175 CDB[10]: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#175 CDB[20]: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#175 CDB[30]: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#175 CDB[40]: 2e 2f 66 69 6c 65 30 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#175 CDB[50]: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#175 CDB[60]: 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#48 FAILED Result: hostbyte=DID_ABORT driverbyte=DRIVER_OK sd 0:0:1:0: [sg0] tag#48 CDB: Test Unit Ready sd 0:0:1:0: [sg0] tag#48 CDB[00]: 00 05 00 20 4a 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#48 CDB[10]: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#48 CDB[20]: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#48 CDB[30]: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#48 CDB[40]: 2e 2f 66 69 6c 65 30 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#48 CDB[50]: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 sd 0:0:1:0: [sg0] tag#48 CDB[60]: 00 00 00 00 00 device syz_tun entered promiscuous mode device syz_tun left promiscuous mode audit_printk_skb: 82 callbacks suppressed audit: type=1400 audit(1521582290.682:139): avc: denied { create } for pid=14752 comm="syz-executor1" 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(1521582290.652:138): avc: denied { create } for pid=14752 comm="syz-executor1" 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(1521582290.702:140): avc: denied { write } for pid=14752 comm="syz-executor1" path="socket:[29987]" dev="sockfs" ino=29987 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(1521582290.702:141): avc: denied { write } for pid=14752 comm="syz-executor1" 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 netlink: 3 bytes leftover after parsing attributes in process `syz-executor1'. netlink: 11 bytes leftover after parsing attributes in process `syz-executor1'. audit: type=1400 audit(1521582290.702:142): avc: denied { create } for pid=14752 comm="syz-executor1" 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(1521582290.762:143): avc: denied { write } for pid=14752 comm="syz-executor1" 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 netlink: 12 bytes leftover after parsing attributes in process `syz-executor1'. audit: type=1400 audit(1521582290.762:144): avc: denied { create } for pid=14752 comm="syz-executor1" 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(1521582290.762:145): avc: denied { write } for pid=14752 comm="syz-executor1" path="socket:[30001]" dev="sockfs" ino=30001 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 netlink: 3 bytes leftover after parsing attributes in process `syz-executor1'. audit: type=1400 audit(1521582290.762:146): avc: denied { read } for pid=14752 comm="syz-executor1" 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 device bridge0 entered promiscuous mode keychord: Insufficient bytes present for keycount 55 keychord: Insufficient bytes present for keycount 55 audit: type=1400 audit(1521582291.902:147): avc: denied { create } for pid=14970 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_netfilter_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 binder: 15054:15059 ioctl c0306201 20000080 returned -14 TCP: request_sock_TCP: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. binder: BINDER_SET_CONTEXT_MGR already set binder: 15054:15059 ioctl 40046207 0 returned -16 binder: 15054:15078 ioctl c0306201 20000080 returned -14 TCP: request_sock_TCP: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. TCP: request_sock_TCP: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. TCP: request_sock_TCP: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. TCP: request_sock_TCP: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. TCP: request_sock_TCP: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. TCP: request_sock_TCP: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. TCP: request_sock_TCP: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. TCP: request_sock_TCP: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. TCP: request_sock_TCP: Possible SYN flooding on port 20002. Sending cookies. Check SNMP counters. binder: 15433:15436 BC_DEAD_BINDER_DONE 0000000000000000 not found binder: 15433:15436 BC_DEAD_BINDER_DONE 0000000000000000 not found