[12334.773269] Lustre: DEBUG MARKER: == sanity test 60a: llog_test run from kernel module and test llog_reader ========================================================== 18:57:02 (1724932622)
[12335.864847] Lustre: DEBUG MARKER: ! which run-llog.sh &> /dev/null
[12337.853204] Lustre: DEBUG MARKER: /sbin/lctl mark test_60 run 5905 - from kernel mode
[12339.177294] Lustre: DEBUG MARKER: test_60 run 5905 - from kernel mode
[12340.118356] Lustre: DEBUG MARKER: /sbin/lctl dk > /dev/null
[12343.741896] Lustre: DEBUG MARKER: bash run-llog.sh
[12347.342040] Lustre: 57074:0:(llog_test.c:2290:llog_test_setup()) Setup llog-test device over MGS device
[12347.345267] Lustre: 57074:0:(llog_test.c:96:llog_test_1()) 1a: create a log with name: e9705074
[12347.349643] Lustre: 57074:0:(llog_test.c:113:llog_test_1()) 1b: close newly-created log
[12347.351723] Lustre: 57074:0:(llog_test.c:144:llog_test_2()) 2a: re-open a log with name: e9705074
[12347.356373] Lustre: 57074:0:(llog_test.c:164:llog_test_2()) 2b: create a log without specified NAME & LOGID
[12347.360991] Lustre: 57074:0:(llog_test.c:182:llog_test_2()) 2b: write 1 llog records, check llh_count
[12347.366882] Lustre: 57074:0:(llog_test.c:195:llog_test_2()) 2c: re-open the log by LOGID and verify llh_count
[12347.374326] Lustre: 57074:0:(llog_test.c:242:llog_test_2()) 2d: destroy this log
[12347.378704] Lustre: 57074:0:(llog_test.c:402:llog_test_3()) 3a: write 1023 fixed-size llog records
[12347.548078] Lustre: 57074:0:(llog_test.c:365:llog_test3_process()) test3: processing records from index 501 to the end
[12347.611203] Lustre: 57074:0:(llog_test.c:375:llog_test3_process()) test3: total 525 records processed with 0 paddings
[12347.618980] Lustre: 57074:0:(llog_test.c:458:llog_test_3()) 3b: write 566 variable size llog records
[12347.784194] Lustre: 57074:0:(llog_test.c:529:llog_test_3()) 3c: write records with variable size until BITMAP_SIZE, return -ENOSPC
[12356.606378] Lustre: 57074:0:(llog_test.c:552:llog_test_3()) 3c: wrote 63962 more records before end of llog is reached
[12356.609061] Lustre: 57074:0:(llog_test.c:582:llog_test_4()) 4a: create a catalog log with name: e9705075
[12356.612415] Lustre: 57074:0:(llog_test.c:597:llog_test_4()) 4b: write 1 record into the catalog
[12356.619013] Lustre: 57074:0:(llog_test.c:624:llog_test_4()) 4c: cancel 1 log record
[12356.622563] Lustre: 57074:0:(llog_test.c:636:llog_test_4()) 4d: write 64767 more log records
[12373.127378] Lustre: 57074:0:(llog_test.c:652:llog_test_4()) 4e: add 5 large records, one record per block
[12373.135004] Lustre: 57074:0:(llog_test.c:672:llog_test_4()) 4f: put newly-created catalog
[12373.136912] Lustre: 57074:0:(llog_test.c:770:llog_test_5()) 5a: re-open catalog by id
[12373.139601] Lustre: 57074:0:(llog_test.c:783:llog_test_5()) 5b: print the catalog entries.. we expect 2
[12373.141251] ==================================================================
[12373.142740] BUG: KASAN: global-out-of-bounds in llog_process_or_fork+0xd0e/0xd60 [obdclass]
[12373.144371] Read of size 4 at addr ffffffffc35baef4 by task lctl/57074
[12373.147085] CPU: 1 PID: 57074 Comm: lctl Kdump: loaded Tainted: G W OE 6.10.6-1.ldiskfs.el9.x86_64 #1
[12373.148490] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.15.0-1 04/01/2014
[12373.149829] Call Trace:
[12373.151125] <TASK>
[12373.152420] dump_stack_lvl+0x75/0xb0
[12373.153738] print_address_description.constprop.0+0x2c/0x390
[12373.155021] ? llog_process_or_fork+0xd0e/0xd60 [obdclass]
[12373.156405] print_report+0xb4/0x270
[12373.157608] ? llog_process_or_fork+0xd0e/0xd60 [obdclass]
[12373.159011] ? kasan_addr_to_slab+0x9/0xa0
[12373.160190] kasan_report+0x89/0xc0
[12373.161342] ? llog_process_or_fork+0xd0e/0xd60 [obdclass]
[12373.162591] llog_process_or_fork+0xd0e/0xd60 [obdclass]
[12373.163805] llog_process+0x10/0x20 [obdclass]
[12373.164980] llog_test_5+0x335/0x1860 [llog_test]
[12373.166026] ? __pfx_llog_test_5+0x10/0x10 [llog_test]
[12373.167065] ? llog_run_tests+0x1d4/0xe70 [llog_test]
[12373.168093] ? rcu_is_watching+0x11/0xb0
[12373.169120] llog_run_tests+0x7ec/0xe70 [llog_test]
[12373.170142] ? __pfx_llog_run_tests+0x10/0x10 [llog_test]
[12373.171193] ? __pfx_get_random_u32+0x10/0x10
[12373.172207] ? do_raw_spin_unlock+0xe0/0x1f0
[12373.173204] ? _raw_spin_unlock+0x29/0x50
[12373.174183] llog_test_setup+0xf6c/0x12a0 [llog_test]
[12373.175174] ? __pfx_llog_test_setup+0x10/0x10 [llog_test]
[12373.176166] ? __module_address.part.0+0x6a/0x210
[12373.177149] obd_setup+0x504/0x7b0 [obdclass]
[12373.178263] ? __pfx_obd_setup+0x10/0x10 [obdclass]
[12373.179395] ? cfs_hash_buckets_realloc.part.0+0x8af/0x1050 [libcfs]
[12373.180431] ? __pfx_cfs_hash_buckets_realloc.part.0+0x10/0x10 [libcfs]
[12373.181428] ? static_obj+0x9c/0xd0
[12373.182427] ? lockdep_init_map_type+0x2c7/0x7d0
[12373.183400] ? cfs_hash_create+0x84d/0x1590 [libcfs]
[12373.184378] class_setup+0xa96/0x11d0 [obdclass]
[12373.185456] class_process_config+0x2dad/0x3d40 [obdclass]
[12373.186501] ? rcu_is_watching+0x11/0xb0
[12373.187395] ? __pfx_class_process_config+0x10/0x10 [obdclass]
[12373.188445] ? rcu_is_watching+0x11/0xb0
[12373.189335] ? lock_acquire+0x1ca/0x250
[12373.190212] ? __might_fault+0xbf/0x170
[12373.191098] ? __might_fault+0x117/0x170
[12373.191980] ? rcu_is_watching+0x11/0xb0
[12373.192838] ? lock_release+0x1ec/0x270
[12373.193692] class_handle_ioctl+0x45a/0x2f80 [obdclass]
[12373.194659] ? __pfx_class_handle_ioctl+0x10/0x10 [obdclass]
[12373.195628] ? _copy_to_user+0x4f/0x70
[12373.196456] ? __x64_sys_rt_sigaction+0x15a/0x260
[12373.197303] ? rcu_is_watching+0x11/0xb0
[12373.198184] ? security_capable+0x53/0xa0
[12373.198998] obd_class_ioctl+0x268/0x3b0 [obdclass]
[12373.199937] __x64_sys_ioctl+0x12e/0x1a0
[12373.200735] do_syscall_64+0x73/0x190
[12373.201536] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[12373.202319] RIP: 0033:0x7fa300e3ec6b
[12373.203069] Code: 73 01 c3 48 8b 0d b5 b1 1b 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 85 b1 1b 00 f7 d8 64 89 01 48
[12373.204725] RSP: 002b:00007ffea4317568 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[12373.205561] RAX: ffffffffffffffda RBX: 00007fa3011372b0 RCX: 00007fa300e3ec6b
[12373.206398] RDX: 00007ffea43177f0 RSI: 00000000c00866b8 RDI: 0000000000000003
[12373.207228] RBP: 00000000c00866b8 R08: 00007ffea43175b0 R09: 000055e28670ab40
[12373.208082] R10: 00007ffea43177f0 R11: 0000000000000246 R12: 00007ffea43177f0
[12373.208926] R13: 000055e26ad86641 R14: 00007ffea4319850 R15: 0000000000000001
[12373.209802] </TASK>
[12373.211488] The buggy address belongs to the variable:
[12373.212330] _note_14+0x2eb8/0xfffffffffffcffc4 [llog_test]
[12373.214037] Memory state around the buggy address:
[12373.214917] ffffffffc35bad80: f9 f9 f9 f9 00 00 00 00 07 f9 f9 f9 f9 f9 f9 f9
[12373.215818] ffffffffc35bae00: 00 f9 f9 f9 f9 f9 f9 f9 00 00 00 00 f9 f9 f9 f9
[12373.216689] >ffffffffc35bae80: 00 00 00 00 00 05 f9 f9 f9 f9 f9 f9 07 f9 f9 f9
[12373.217556] ^
[12373.218459] ffffffffc35baf00: f9 f9 f9 f9 00 00 00 00 00 02 f9 f9 f9 f9 f9 f9
[12373.219360] ffffffffc35baf80: 00 00 00 03 f9 f9 f9 f9 00 00 00 00 00 03 f9 f9
[12373.220237] ==================================================================
[12373.223545] Lustre: 57080:0:(llog_test.c:699:cat_print_cb()) seeing record at index 1 - [0x1:0x3:0x0] in log [0xa:0x8:0x0]
[12373.224899] Lustre: 57074:0:(llog_test.c:795:llog_test_5()) 5c: Cancel 64767 records, see one log zapped
Bug
Minor