Uploaded image for project: 'RHEL'
  1. RHEL
  2. RHEL-19081

[regression] BUG: KASAN: use-after-free in __lock_acquire+0x16d6/0x18b0

    • kernel-5.14.0-406.el9
    • Yes
    • Low
    • Regression
    • rhel-sst-filesystems
    • ssg_filesystems_storage_and_HA
    • 18
    • 20
    • 3
    • QE ack
    • False
    • Hide

      None

      Show
      None
    • None
    • None
    • None

      What were you trying to do that didn't work?

      Encountered the following BUG when running nfs regression test on kernel-5.14.0-397.el9, which seems to be introduced by RHEL-7936.

      [  536.401401] NFSD: Using UMH upcall client tracking operations. 
      [  536.401410] NFSD: starting 90-second grace period (net f0000000) 
      [  536.474614] svc: failed to register nfsdv3 RPC service (errno 512). 
      [  536.475334] svc: failed to register nfsaclv3 RPC service (errno 512). 
      [  536.482922] ================================================================== 
      [  536.482930] BUG: KASAN: use-after-free in __lock_acquire+0x16d6/0x18b0 
      [  536.483002] Read of size 8 at addr ffff88800697b428 by task rpc.nfsd/14509 
      [  536.483005]  
      [  536.483020] CPU: 0 PID: 14509 Comm: rpc.nfsd Kdump: loaded Not tainted 5.14.0-397.el9.x86_64+debug #1 
      [  536.483024] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011 
      [  536.483032] Call Trace: 
      [  536.483045]  <TASK> 
      [  536.483048]  dump_stack_lvl+0x57/0x81 
      [  536.483095]  print_address_description.constprop.0+0x87/0x293 
      [  536.483117]  print_report+0x132/0x21c 
      [  536.483122]  ? kasan_addr_to_slab+0x9/0xa0 
      [  536.483150]  ? __lock_acquire+0x16d6/0x18b0 
      [  536.483153]  kasan_report+0xd2/0x210 
      [  536.483157]  ? __lock_acquire+0x16d6/0x18b0 
      [  536.483162]  __lock_acquire+0x16d6/0x18b0 
      [  536.483168]  lock_acquire+0x1da/0x640 
      [  536.483171]  ? svc_xprt_names+0x39/0x290 [sunrpc] 
      [  536.483461]  ? find_held_lock+0x33/0x120 
      [  536.483470]  ? __pfx_lock_acquire+0x10/0x10 
      [  536.483473]  ? __lock_release+0x4c1/0xa00 
      [  536.483477]  ? __pfx___lock_release+0x10/0x10 
      [  536.483480]  ? __pfx___lock_release+0x10/0x10 
      [  536.483484]  _raw_spin_lock_bh+0x39/0x80 
      [  536.483499]  ? svc_xprt_names+0x39/0x290 [sunrpc] 
      [  536.483582]  svc_xprt_names+0x39/0x290 [sunrpc] 
      [  536.483665]  ? net_generic+0xa0/0x1c0 [nfsd] 
      [  536.483919]  write_ports+0x1b6/0x260 [nfsd] 
      [  536.483986]  ? __pfx_write_ports+0x10/0x10 [nfsd] 
      [  536.484045]  nfsctl_transaction_write+0xaf/0x110 [nfsd] 
      [  536.484104]  nfsctl_transaction_read+0x5f/0xa0 [nfsd] 
      [  536.484164]  vfs_read+0x18d/0xa30 
      [  536.484182]  ? kvm_sched_clock_read+0x14/0x30 
      [  536.484199]  ? sched_clock_cpu+0x15/0x1b0 
      [  536.484210]  ? __pfx_vfs_read+0x10/0x10 
      [  536.484214]  ? __lock_release+0x4c1/0xa00 
      [  536.484217]  ? __pfx___lock_release+0x10/0x10 
      [  536.484219]  ? __pfx_lock_acquire+0x10/0x10 
      [  536.484221]  ? __pfx_do_sys_openat2+0x10/0x10 
      [  536.484230]  ? __fget_light+0x51/0x240 
      [  536.484243]  ksys_read+0xf9/0x1d0 
      [  536.484246]  ? __pfx_ksys_read+0x10/0x10 
      [  536.484248]  ? ktime_get_coarse_real_ts64+0x130/0x170 
      [  536.484277]  do_syscall_64+0x5c/0x90 
      [  536.484290]  ? lockdep_hardirqs_on+0x79/0x100 
      [  536.484295]  ? do_syscall_64+0x69/0x90 
      [  536.484299]  ? do_syscall_64+0x69/0x90 
      [  536.484302]  ? lockdep_hardirqs_on+0x79/0x100 
      [  536.484305]  ? do_syscall_64+0x69/0x90 
      [  536.484308]  ? do_syscall_64+0x69/0x90 
      [  536.484311]  ? lockdep_hardirqs_on+0x79/0x100 
      [  536.484314]  ? do_syscall_64+0x69/0x90 
      [  536.484317]  ? asm_exc_page_fault+0x22/0x30 
      [  536.484331]  ? lockdep_hardirqs_on+0x79/0x100 
      [  536.484334]  entry_SYSCALL_64_after_hwframe+0x72/0xdc 
      [  536.484337] RIP: 0033:0x7fe40d33ec62 
      [  536.484520] Code: c0 e9 b2 fe ff ff 50 48 8d 3d 3a 0b 08 00 e8 c5 e7 01 00 0f 1f 44 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 0f 05 <48> 3d 00 f0 ff ff 77 56 c3 0f 1f 44 00 00 48 83 ec 28 48 89 54 24 
      [  536.484523] RSP: 002b:00007fff58c72b78 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 
      [  536.484537] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fe40d33ec62 
      [  536.484540] RDX: 0000000000000080 RSI: 0000563366e3ac20 RDI: 0000000000000003 
      [  536.484542] RBP: 0000000000000003 R08: 1999999999999999 R09: 0000000000000000 
      [  536.484544] R10: 0000000000000000 R11: 0000000000000246 R12: 0000563366e372a6 
      [  536.484546] R13: 0000563366e37262 R14: 00007fff58c72c40 R15: 00000000ffffffff 
      [  536.484552]  </TASK> 
      [  536.484554]  
      [  536.484554] Allocated by task 14504: 
      [  536.484562]  kasan_save_stack+0x1e/0x40 
      [  536.484567]  kasan_set_track+0x21/0x30 
      [  536.484569]  __kasan_kmalloc+0x7b/0x90 
      [  536.484571]  __svc_create+0x53/0x9c0 [sunrpc] 
      [  536.484651]  svc_create_pooled+0x9b/0x530 [sunrpc] 
      [  536.484722]  nfsd_create_serv+0x123/0x420 [nfsd] 
      [  536.484783]  __write_ports_addfd+0x17d/0x620 [nfsd] 
      [  536.484841]  write_ports+0x1eb/0x260 [nfsd] 
      [  536.484899]  nfsctl_transaction_write+0xaf/0x110 [nfsd] 
      [  536.484961]  vfs_write+0x260/0xe50 
      [  536.484964]  ksys_write+0xf9/0x1d0 
      [  536.484966]  do_syscall_64+0x5c/0x90 
      [  536.484969]  entry_SYSCALL_64_after_hwframe+0x72/0xdc 
      [  536.484972]  
      [  536.484973] Freed by task 14504: 
      [  536.484974]  kasan_save_stack+0x1e/0x40 
      [  536.484976]  kasan_set_track+0x21/0x30 
      [  536.484978]  kasan_save_free_info+0x2a/0x50 
      [  536.484982]  ____kasan_slab_free+0x14c/0x1b0 
      [  536.484984]  slab_free_freelist_hook+0x11d/0x1d0 
      [  536.484988]  __kmem_cache_free+0xba/0x2c0 
      [  536.484990]  __write_ports_addfd+0x508/0x620 [nfsd] 
      [  536.485048]  write_ports+0x1eb/0x260 [nfsd] 
      [  536.485105]  nfsctl_transaction_write+0xaf/0x110 [nfsd] 
      [  536.485166]  vfs_write+0x260/0xe50 
      [  536.485168]  ksys_write+0xf9/0x1d0 
      [  536.485171]  do_syscall_64+0x5c/0x90 
      [  536.485173]  entry_SYSCALL_64_after_hwframe+0x72/0xdc 
      [  536.485176]  
      [  536.485177] The buggy address belongs to the object at ffff88800697b400 
      [  536.485177]  which belongs to the cache kmalloc-512 of size 512 
      [  536.485179] The buggy address is located 40 bytes inside of 
      [  536.485179]  512-byte region [ffff88800697b400, ffff88800697b600) 
      [  536.485182]  
      [  536.485183] The buggy address belongs to the physical page: 
      [  536.485188] page:0000000002f55b5d refcount:1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x6978 
      [  536.485201] head:0000000002f55b5d order:3 compound_mapcount:0 nr_pages_mapped:0 pincount:0 
      [  536.485203] flags: 0xfffffc0010200(slab|head|node=0|zone=1|lastcpupid=0x1fffff) 
      [  536.485218] raw: 000fffffc0010200 0000000000000000 dead000000000001 ffff888001042c80 
      [  536.485223] raw: 0000000000000000 0000000080200020 00000001ffffffff 0000000000000000 
      [  536.485227] page dumped because: kasan: bad access detected 
      [  536.485228]  
      [  536.485229] Memory state around the buggy address: 
      [  536.485231]  ffff88800697b300: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc 
      [  536.485233]  ffff88800697b380: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc 
      [  536.485235] >ffff88800697b400: fa fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb 
      [  536.485236]                                   ^ 
      [  536.485238]  ffff88800697b480: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb 
      [  536.485240]  ffff88800697b500: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb 
      [  536.485241] ================================================================== 
      [  536.485246] Disabling lock debugging due to kernel taint 
      [  536.495453] ------------[ cut here ]------------ 
      [  536.495458] refcount_t: addition on 0; use-after-free. 
      [  536.495586] WARNING: CPU: 4 PID: 14509 at lib/refcount.c:25 refcount_warn_saturate+0xee/0x150 
      [  536.495623] Modules linked in: rpcrdma rdma_cm iw_cm ib_cm ib_core nfsd nfs_acl rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver nfs lockd grace fscache netfs rfkill sunrpc snd_hda_codec_generic ledtrig_audio intel_rapl_msr snd_hda_intel snd_intel_dspcfg snd_intel_sdw_acpi snd_hda_codec snd_hda_core qxl snd_hwdep drm_ttm_helper intel_rapl_common ttm snd_pcm drm_kms_helper snd_timer syscopyarea snd sysfillrect soundcore pcspkr virtio_balloon sysimgblt i2c_piix4 joydev drm fuse xfs libcrc32c sd_mod t10_pi sg ata_generic ata_piix crct10dif_pclmul crc32_pclmul crc32c_intel libata 8139too virtio_console ghash_clmulni_intel 8139cp mii serio_raw dm_mirror dm_region_hash dm_log dm_mod 
      [  536.495780] CPU: 4 PID: 14509 Comm: rpc.nfsd Kdump: loaded Tainted: G    B             -------  ---  5.14.0-397.el9.x86_64+debug #1 
      [  536.495785] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011 
      [  536.495788] RIP: 0010:refcount_warn_saturate+0xee/0x150 
      [  536.495793] Code: 38 52 55 03 01 e8 32 e8 0a ff 0f 0b eb 91 80 3d 2b 52 55 03 00 75 88 48 c7 c7 60 5e 14 a7 c6 05 1b 52 55 03 01 e8 12 e8 0a ff <0f> 0b e9 6e ff ff ff 80 3d 0a 52 55 03 00 0f 85 61 ff ff ff 48 c7 
      [  536.495796] RSP: 0018:ffffc90001cdfac8 EFLAGS: 00010296 
      [  536.495801] RAX: 0000000000000000 RBX: ffff88800697b458 RCX: 0000000000000000 
      [  536.495807] RDX: 0000000000000002 RSI: 0000000000000004 RDI: 0000000000000001 
      [  536.495810] RBP: 0000000000000002 R08: 0000000000000001 R09: ffff888072fefd2b 
      [  536.495812] R10: ffffed100e5fdfa5 R11: 0000000000000001 R12: 0000000000000000 
      [  536.495814] R13: ffffffffac819540 R14: ffff888060563300 R15: 0000000000000004 
      [  536.495816] FS:  00007fe40d549740(0000) GS:ffff888072e00000(0000) knlGS:0000000000000000 
      [  536.495822] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033 
      [  536.495824] CR2: 00007fff58d5a080 CR3: 0000000039416005 CR4: 00000000003706e0 
      [  536.495827] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 
      [  536.495828] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 
      [  536.495830] Call Trace: 
      [  536.495833]  <TASK> 
      [  536.495835]  ? show_trace_log_lvl+0x1c4/0x2df 
      [  536.495854]  ? show_trace_log_lvl+0x1c4/0x2df 
      [  536.495861]  ? nfsd_create_serv+0x3ce/0x420 [nfsd] 
      [  536.495983]  ? refcount_warn_saturate+0xee/0x150 
      [  536.495987]  ? __warn+0xca/0x1d0 
      [  536.496004]  ? irq_work_queue+0xb/0x50 
      [  536.496027]  ? refcount_warn_saturate+0xee/0x150 
      [  536.496031]  ? report_bug+0x1ef/0x370 
      [  536.496043]  ? handle_bug+0x3c/0x70 
      [  536.496049]  ? exc_invalid_op+0x14/0x50 
      [  536.496053]  ? asm_exc_invalid_op+0x16/0x20 
      [  536.496066]  ? refcount_warn_saturate+0xee/0x150 
      [  536.496071]  ? refcount_warn_saturate+0xee/0x150 
      [  536.496074]  nfsd_create_serv+0x3ce/0x420 [nfsd] 
      [  536.496130]  __write_ports_addfd+0x17d/0x620 [nfsd] 
      [  536.496180]  ? __pfx___write_ports_addfd+0x10/0x10 [nfsd] 
      [  536.496230]  ? __pfx_lock_acquire+0x10/0x10 
      [  536.496236]  ? do_raw_spin_trylock+0xb5/0x180 
      [  536.496241]  ? __might_fault+0xbc/0x160 
      [  536.496260]  ? lock_release+0x285/0x380 
      [  536.496265]  write_ports+0x1eb/0x260 [nfsd] 
      [  536.496310]  ? __pfx_write_ports+0x10/0x10 [nfsd] 
      [  536.496357]  nfsctl_transaction_write+0xaf/0x110 [nfsd] 
      [  536.496410]  ? preempt_count_add+0x7d/0x150 
      [  536.496451]  vfs_write+0x260/0xe50 
      [  536.496458]  ? __pfx_lock_acquire+0x10/0x10 
      [  536.496462]  ? __pfx_vfs_write+0x10/0x10 
      [  536.496465]  ? do_raw_spin_trylock+0xb5/0x180 
      [  536.496469]  ? lock_acquire+0x4ec/0x640 
      [  536.496473]  ? __pfx_lock_acquire+0x10/0x10 
      [  536.496477]  ? __fget_light+0x51/0x240 
      [  536.496484]  ksys_write+0xf9/0x1d0 
      [  536.496488]  ? __pfx_ksys_write+0x10/0x10 
      [  536.496493]  ? __pfx___x64_sys_write+0x10/0x10 
      [  536.496502]  do_syscall_64+0x5c/0x90 
      [  536.496506]  ? do_syscall_64+0x69/0x90 
      [  536.496510]  ? do_syscall_64+0x69/0x90 
      [  536.496513]  ? do_syscall_64+0x69/0x90 
      [  536.496517]  ? syscall_exit_to_user_mode+0x1e/0x60 
      [  536.496521]  ? trace_hardirqs_on_prepare+0xbd/0x220 
      [  536.496535]  ? do_syscall_64+0x69/0x90 
      [  536.496538]  ? irqentry_exit_to_user_mode+0xa/0x40 
      [  536.496541]  ? trace_hardirqs_on_prepare+0xbd/0x220 
      [  536.496545]  entry_SYSCALL_64_after_hwframe+0x72/0xdc 
      [  536.496549] RIP: 0033:0x7fe40d33ed07 
      [  536.496599] Code: 0c 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24 
      [  536.496602] RSP: 002b:00007fff58c72b78 EFLAGS: 00000246 ORIG_RAX: 0000000000000001 
      [  536.496612] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fe40d33ed07 
      [  536.496614] RDX: 0000000000000002 RSI: 0000563366e3ac20 RDI: 0000000000000003 
      [  536.496616] RBP: 0000000000000003 R08: 0000000000000000 R09: 00007fff58c72a10 
      [  536.496618] R10: 0000000000000004 R11: 0000000000000246 R12: 00005633682498b0 
      [  536.496620] R13: 0000563366e37184 R14: 0000563366e37180 R15: 0000000000000004 
      [  536.496626]  </TASK> 
      [  536.496632] irq event stamp: 9636 
      [  536.496640] hardirqs last  enabled at (9635): [<ffffffffa5026286>] bad_range+0x286/0x350 
      [  536.496651] hardirqs last disabled at (9634): [<ffffffffa5026256>] bad_range+0x256/0x350 
      [  536.496655] softirqs last  enabled at (7474): [<ffffffffa6be8261>] __do_softirq+0x621/0x9c2 
      [  536.496665] softirqs last disabled at (9636): [<ffffffffc11cd7f9>] svc_xprt_names+0x39/0x290 [sunrpc] 
      [  536.496762] ---[ end trace 7c9c49f25f91c647 ]--- 

      Please provide the package NVR for which bug is seen:

      kernel-5.14.0-397.el9

      How reproducible:

      80%

      Steps to reproduce

      clone https://beaker.engineering.redhat.com/jobs/8655532

      Beaker jobs:
      kernel-5.14.0-397.el9 (panic)
      https://beaker.engineering.redhat.com/jobs/8655532
      https://beaker-archive.host.prod.eng.bos.redhat.com/beaker-logs/2023/12/86555/8655532/15154221/console.log

      kernel-5.14.0-396.el9:
      https://beaker.engineering.redhat.com/jobs/8655566

              jlayton@redhat.com Jeffrey Layton (Inactive)
              rh-ee-yieli Zhi Li
              NFS Team NFS Team
              Zhi Li Zhi Li
              Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

                Created:
                Updated:
                Resolved: