2024-02-29 15:44:29

by Oliver Sang

[permalink] [raw]
Subject: [broonie-ci:regmap-test-format] [regmap] af560701e3: RIP:__regmap_init



Hello,

kernel test robot noticed "RIP:__regmap_init" on:

commit: af560701e366502504aebae54af374710e35b55b ("regmap: Provide a callback for bus specific initialisation")
https://git.kernel.org/cgit/linux/kernel/git/broonie/ci.git regmap-test-format

in testcase: ftrace-onoff
version:
with following parameters:

runtime: 5m



compiler: gcc-12
test machine: 8 threads 1 sockets Intel(R) Core(TM) i7-7700 CPU @ 3.60GHz (Kaby Lake) with 32G memory

(please refer to attached dmesg/kmsg for entire log/backtrace)



If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <[email protected]>
| Closes: https://lore.kernel.org/oe-lkp/[email protected]



System Message B[ 19.311388][ T211] RIP: 0010:__regmap_init+0x26fa/0x4a40
[ 19.318140][ T211] Code: bc 97 ff ff 4c 63 e8 45 85 ed 0f 85 06 10 00 00 48 8b 44 24 08 48 8d 78 08 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 <80> 3c 02 00 0f 85 c4 21 00 00 48 8b 44 24 08 48 8b 40 08 48 85 c0
[ 19.330604][ T191] scsi host0: ahci
[ 19.338703][ T211] RSP: 0018:ffffc90000ccf408 EFLAGS: 00010202
[ 19.338707][ T211] RAX: dffffc0000000000 RBX: ffff888172c27800 RCX: ffffffff83a271cb
[ 19.338708][ T211] RDX: 0000000000000001 RSI: 0000000000000246 RDI: 0000000000000008
[ 19.338709][ T211] RBP: ffff888172c279f8 R08: 0000000000000001 R09: fffff52000199e6a
[ 19.345023][ T191] scsi host1: ahci
[ 19.348120][ T211] R10: 0000000000000003 R11: ffffffff83c0009f R12: 0000000000000000
[ 19.348122][ T211] R13: 0000000000000000 R14: ffff888172c27a55 R15: 0000000000000000
[ 19.348123][ T211] FS: 00007efca7a8e8c0(0000) GS:ffff8887a5500000(0000) knlGS:0000000000000000
[ 19.348125][ T211] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 19.348127][ T211] CR2: 00007efca702c55b CR3: 0000000807fe0001 CR4: 00000000003706f0
[ 19.357944][ T191] scsi host2: ahci
[ 19.363655][ T211] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 19.363657][ T211] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 19.363658][ T211] Call Trace:
[ 19.363659][ T211] <TASK>
[ 19.363660][ T211] ? die_addr+0x40/0xa0
[ 19.373829][ T191] scsi host3: ahci
[ 19.374968][ T211] ? exc_general_protection+0x150/0x220
[ 19.374975][ T211] ? asm_exc_general_protection+0x26/0x30
[ 19.384252][ T191] ata1: SATA max UDMA/133 abar m2048@0xf704b000 port 0xf704b100 irq 125 lpm-pol 0
[ 19.390500][ T211] ? entry_SYSCALL_64_after_hwframe+0x63/0x6b
[ 19.399218][ T191] ata2: SATA max UDMA/133 abar m2048@0xf704b000 port 0xf704b180 irq 125 lpm-pol 0
[ 19.405598][ T211] ? _raw_spin_lock_irqsave+0x8b/0xe0
[ 19.413367][ T191] ata3: SATA max UDMA/133 abar m2048@0xf704b000 port 0xf704b200 irq 125 lpm-pol 0
[ 19.416904][ T211] ? __regmap_init+0x26fa/0x4a40
[ 19.424672][ T191] ata4: SATA max UDMA/133 abar m2048@0xf704b000 port 0xf704b280 irq 125 lpm-pol 0
[ 19.432429][ T211] ? __regmap_init+0x26d4/0x4a40
[ 19.432434][ T211] ? __devres_alloc_node+0x4c/0x170
[ 19.521757][ T211] ? __devres_alloc_node+0x4c/0x170
[ 19.521776][ T211] __devm_regmap_init+0x6c/0xd0
0m] Reached targ[ 19.539892][ T211] ? clk_hw_create_clk+0x87/0x3b0
[ 19.554331][ T211] ? really_probe+0x3d2/0xb40
[ 19.559630][ T211] ? 0xffffffffc0442000
[ 19.559632][ T211] ? dw_reg_read+0x90/0x90 [i2c_designware_core]
0m] Reached targ[ 19.559640][ T211] ? _raw_read_unlock_irqrestore+0x50/0x50
[ 19.559659][ T211] i2c_dw_probe_master+0x10c/0xbb0 [i2c_designware_core]
[ 19.559663][ T211] ? _raw_read_unlock_irqrestore+0x50/0x50
[ 19.559666][ T211] ? i2c_dw_unprepare_recovery+0x60/0x60 [i2c_designware_core]
[ 19.610796][ T211] ? ktime_get_mono_fast_ns+0x87/0x1e0
[ 19.616188][ T211] ? dmi_matches+0xc0/0x2d0
[ 19.620616][ T211] dw_i2c_plat_probe+0x9c6/0xbe0 [i2c_designware_platform]
[ 19.627721][ T211] platform_probe+0x9f/0x140
[ 19.632260][ T211] really_probe+0x3d2/0xb40
[ 19.636687][ T211] __driver_probe_device+0x18c/0x440
[ 19.641890][ T211] ? __device_attach_driver+0x260/0x260
[ 19.647354][ T211] driver_probe_device+0x4a/0x120
[ 19.652311][ T211] __driver_attach+0x1d2/0x490
[ 19.656997][ T211] ? __device_attach_driver+0x260/0x260
[ 19.662459][ T211] bus_for_each_dev+0x103/0x180
[ 19.667261][ T211] ? bus_remove_file+0x40/0x40
[ 19.671948][ T211] ? klist_add_tail+0x133/0x260
[ 19.676724][ T211] bus_add_driver+0x29a/0x570
[ 19.681327][ T211] driver_register+0x134/0x450
[ 19.686013][ T211] ? 0xffffffffc0602000
[ 19.690096][ T211] do_one_initcall+0xa1/0x370
[ 19.694698][ T211] ? trace_event_raw_event_initcall_level+0x1a0/0x1a0
[ 19.701369][ T211] ? kasan_unpoison+0x27/0x50
[ 19.705973][ T211] do_init_module+0x22e/0x720
[ 19.710576][ T211] load_module+0x1826/0x25e0
[ 19.715093][ T211] ? post_relocation+0x370/0x370
[ 19.719954][ T211] ? kernel_read_file+0x243/0x820
[ 19.724900][ T211] ? __x64_sys_fspick+0x2a0/0x2a0
[ 19.729848][ T211] ? init_module_from_file+0xd1/0x130
[ 19.735137][ T211] init_module_from_file+0xd1/0x130
[ 19.739737][ T242] ata4: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[ 19.740147][ T211] ? __ia32_sys_init_module+0xb0/0xb0
[ 19.740151][ T211] ? userfaultfd_unmap_prep+0x3d0/0x3d0
[ 19.747013][ T235] ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[ 19.752147][ T211] ? _raw_write_lock_irq+0xe0/0xe0
[ 19.752151][ T211] idempotent_init_module+0x23b/0x660
[ 19.757541][ T240] ata3: SATA link down (SStatus 4 SControl 300)
[ 19.764317][ T211] ? init_module_from_file+0x130/0x130
[ 19.764320][ T211] ? __fget_light+0x58/0x410
[ 19.764323][ T211] ? security_capable+0x6e/0xa0
[ 19.769389][ T242] ata4.00: ATA-10: CT1000BX500SSD1, M6CR030, max UDMA/133
[ 19.774437][ T211] __x64_sys_finit_module+0xbe/0x130
[ 19.774440][ T211] do_syscall_64+0x63/0x170
[ 19.780525][ T238] ata2: SATA link down (SStatus 4 SControl 300)
[ 19.785763][ T211] entry_SYSCALL_64_after_hwframe+0x63/0x6b
[ 19.790336][ T242] ata4.00: 1953525168 sectors, multi 1: LBA48 NCQ (depth 32), AA
[ 19.794849][ T211] RIP: 0033:0x7efca7f479b9
[ 19.801759][ T235] ata1.00: ATA-8: ST1000DM003-1CH162, CC44, max UDMA/133
[ 19.806848][ T211] Code: 00 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d a7 54 0c 00 f7 d8 64 89 01 48
[ 19.811574][ T235] ata1.00: 1953525168 sectors, multi 16: LBA48 NCQ (depth 32), AA
[ 19.817209][ T211] RSP: 002b:00007ffd75a31238 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[ 19.817212][ T211] RAX: ffffffffffffffda RBX: 0000555f15f8b4e0 RCX: 00007efca7f479b9
[ 19.817215][ T211] RDX: 0000000000000000 RSI: 00007efca80d2e2d RDI: 000000000000000f
[ 19.823854][ T235] ata1.00: configured for UDMA/133
[ 19.830418][ T211] RBP: 0000000000020000 R08: 0000000000000000 R09: 0000555f15f830c0
[ 19.830420][ T211] R10: 000000000000000f R11: 0000000000000246 R12: 00007efca80d2e2d
[ 19.830421][ T211] R13: 0000000000000000 R14: 0000555f15f82b50 R15: 0000555f15f8b4e0
[ 19.830424][ T211] </TASK>
[ 19.834659][ T242] ata4.00: Features: Dev-Sleep
[ 19.835192][ T65] scsi 0:0:0:0: Direct-Access ATA ST1000DM003-1CH1 CC44 PQ: 0 ANSI: 5
[ 19.841470][ T211] Modules linked in: kvm(+) drm_buddy intel_gtt
[ 19.870688][ T242] ata4.00: configured for UDMA/133
[ 19.876667][ T211] irqbypass drm_display_helper crct10dif_pclmul crc32_pclmul crc32c_intel ttm ghash_clmulni_intel sha512_ssse3 mei_wdt
[ 19.884870][ T11] scsi 3:0:0:0: Direct-Access ATA CT1000BX500SSD1 030 PQ: 0 ANSI: 5
[ 19.892195][ T211] drm_kms_helper rapl ahci wmi_bmof libahci video intel_cstate intel_uncore mei_me i2c_designware_platform(+) libata mei idma64 i2c_designware_core wmi pinctrl_sunrisepoint acpi_pad drm fuse ip_tables
[ 19.992664][ T211] ---[ end trace 0000000000000000 ]---
[ 19.998347][ T211] RIP: 0010:__regmap_init+0x26fa/0x4a40
[ 20.003858][ T211] Code: bc 97 ff ff 4c 63 e8 45 85 ed 0f 85 06 10 00 00 48 8b 44 24 08 48 8d 78 08 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 <80> 3c 02 00 0f 85 c4 21 00 00 48 8b 44 24 08 48 8b 40 08 48 85 c0
[ 20.023434][ T211] RSP: 0018:ffffc90000ccf408 EFLAGS: 00010202
[ 20.029498][ T211] RAX: dffffc0000000000 RBX: ffff888172c27800 RCX: ffffffff83a271cb
[ 20.037438][ T211] RDX: 0000000000000001 RSI: 0000000000000246 RDI: 0000000000000008
[ 20.045401][ T211] RBP: ffff888172c279f8 R08: 0000000000000001 R09: fffff52000199e6a
[ 20.053349][ T211] R10: 0000000000000003 R11: ffffffff83c0009f R12: 0000000000000000
[ 20.061290][ T211] R13: 0000000000000000 R14: ffff888172c27a55 R15: 0000000000000000
[ 20.069224][ T211] FS: 00007efca7a8e8c0(0000) GS:ffff8887a5500000(0000) knlGS:0000000000000000
[ 20.078096][ T211] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 20.084627][ T211] CR2: 00007efca702c55b CR3: 0000000807fe0001 CR4: 00000000003706f0
[ 20.092563][ T211] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 20.100496][ T211] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 20.108433][ T211] Kernel panic - not syncing: Fatal exception
[ 20.114453][ T211] Kernel Offset: disabled



The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20240229/[email protected]



--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki



2024-02-29 15:47:50

by Mark Brown

[permalink] [raw]
Subject: Re: [broonie-ci:regmap-test-format] [regmap] af560701e3: RIP:__regmap_init

On Thu, Feb 29, 2024 at 11:43:55PM +0800, kernel test robot wrote:
>
>
> Hello,
>
> kernel test robot noticed "RIP:__regmap_init" on:
>
> commit: af560701e366502504aebae54af374710e35b55b ("regmap: Provide a callback for bus specific initialisation")
> https://git.kernel.org/cgit/linux/kernel/git/broonie/ci.git regmap-test-format
>
> in testcase: ftrace-onoff
> version:
> with following parameters:
>
> runtime: 5m

I have no idea how I'm supposed to be able to tell from this mail what
on earth this test is, and it doesn't seem plausible that anything to
do with ftrace would be related to a change in the regmap KUnit tests.


Attachments:
(No filename) (657.00 B)
signature.asc (499.00 B)
Download all attachments

2024-03-01 01:37:41

by Oliver Sang

[permalink] [raw]
Subject: Re: [broonie-ci:regmap-test-format] [regmap] af560701e3: RIP:__regmap_init

hi, Mark Brown,

On Thu, Feb 29, 2024 at 03:47:33PM +0000, Mark Brown wrote:
> On Thu, Feb 29, 2024 at 11:43:55PM +0800, kernel test robot wrote:
> >
> >
> > Hello,
> >
> > kernel test robot noticed "RIP:__regmap_init" on:
> >
> > commit: af560701e366502504aebae54af374710e35b55b ("regmap: Provide a callback for bus specific initialisation")
> > https://git.kernel.org/cgit/linux/kernel/git/broonie/ci.git regmap-test-format
> >
> > in testcase: ftrace-onoff
> > version:
> > with following parameters:
> >
> > runtime: 5m
>
> I have no idea how I'm supposed to be able to tell from this mail what
> on earth this test is, and it doesn't seem plausible that anything to
> do with ftrace would be related to a change in the regmap KUnit tests.

sorry for the information is not clear enough.

normally, we want users to follow our reproducer as in
https://download.01.org/0day-ci/archive/20240229/[email protected]/reproduce

however, this 'ftrace-onoff' is just a simple Ftrace on/off test, as in
https://github.com/intel/lkp-tests/blob/master/programs/ftrace-onoff/run
details is as [1]

thanks a lot for pointing out our problems! we are really working on how to make
our reports have clearer tesecase description, this reminders us we should also
pay attention to this kind of simple tests.


regarding the issue itself, we reported due to it can always be reproduced on
this commit, but clean on parent:

5b071e8b2e3e7f02 af560701e366502504aebae54af
---------------- ---------------------------
fail:runs %reproduction fail:runs
| | |
:6 100% 6:6 dmesg.Kernel_panic-not_syncing:Fatal_exception
:6 100% 6:6 dmesg.RIP:__regmap_init

and we noticed there is changes in __regmap_init(), we also noticed the issue
seems happen before the test even starts to run. not sure if the detail dmesg in
https://download.01.org/0day-ci/archive/20240229/[email protected]/dmesg.xz
could supply more information?

if you still think this is a wrong report, or you want us to test any patch,
please just let us know. it's always our great pleasure. Thanks!


[1]
#!/bin/sh
# - runtime

## Ftrace is an internal tracer designed to help out developers and
## designers of systems to find what is going on inside the kernel.
## It can be used for debugging or analyzing latencies and
## performance issues that take place outside of user-space.

$LKP_SRC/lib/reproduce-log.sh

cd /sys/kernel/debug/tracing || die "no /sys/kernel/debug/tracing"

: "${runtime:=300}"

do_test()
{
for tracer in $(cat available_tracers)
do
log_eval "echo $tracer > current_tracer"
log_eval "echo 1 > tracing_on"
log_eval "echo 0 > tracing_on"
done
}

$LKP_SRC/lib/runtime_loop.sh
runtime_loop

2024-03-01 03:30:45

by Oliver Sang

[permalink] [raw]
Subject: Re: [broonie-ci:regmap-test-format] [regmap] af560701e3: RIP:__regmap_init

hi, Mark Brown,

On Fri, Mar 01, 2024 at 09:37:21AM +0800, Oliver Sang wrote:
> hi, Mark Brown,
>
> On Thu, Feb 29, 2024 at 03:47:33PM +0000, Mark Brown wrote:
> > On Thu, Feb 29, 2024 at 11:43:55PM +0800, kernel test robot wrote:
> > >
> > >

..

>
> and we noticed there is changes in __regmap_init(), we also noticed the issue
> seems happen before the test even starts to run. not sure if the detail dmesg in
> https://download.01.org/0day-ci/archive/20240229/[email protected]/dmesg.xz
> could supply more information?
>
> if you still think this is a wrong report, or you want us to test any patch,
> please just let us know. it's always our great pleasure. Thanks!
>
>

we checked this issue more, and found it could be platform specific.

we just try a simple boot with af560701e3 on below machine which we made origial
report and reproduced the issue (dmesg is attached).

test machine: 8 threads 1 sockets Intel(R) Core(TM) i7-7700 CPU @ 3.60GHz (Kaby Lake) with 32G memory


at the same time, we test this commit with boot jobs on various other platforms
(Sapphire Rapids, Ice Lake, Cascade Lake, etc.) but didn't reproduce the issue.


Attachments:
(No filename) (1.18 kB)
dmesg.xz (18.29 kB)
Download all attachments

2024-03-01 12:08:08

by Mark Brown

[permalink] [raw]
Subject: Re: [broonie-ci:regmap-test-format] [regmap] af560701e3: RIP:__regmap_init

On Fri, Mar 01, 2024 at 11:30:13AM +0800, Oliver Sang wrote:
> On Fri, Mar 01, 2024 at 09:37:21AM +0800, Oliver Sang wrote:
> > On Thu, Feb 29, 2024 at 03:47:33PM +0000, Mark Brown wrote:
> > > On Thu, Feb 29, 2024 at 11:43:55PM +0800, kernel test robot wrote:

> > and we noticed there is changes in __regmap_init(), we also noticed the issue
> > seems happen before the test even starts to run. not sure if the detail dmesg in

The patch adds a callback but nothing yet provides that callback, it is
very difficult to see how that might be an issue.

> > https://download.01.org/0day-ci/archive/20240229/[email protected]/dmesg.xz
> > could supply more information?

> > if you still think this is a wrong report, or you want us to test any patch,
> > please just let us know. it's always our great pleasure. Thanks!

> we checked this issue more, and found it could be platform specific.
>
> we just try a simple boot with af560701e3 on below machine which we made origial
> report and reproduced the issue (dmesg is attached).
>
> test machine: 8 threads 1 sockets Intel(R) Core(TM) i7-7700 CPU @ 3.60GHz (Kaby Lake) with 32G memory

My best guess would be that this has somehow managed to trigger a
preexisting issue which happens to manifest on whatever platform you're
running. I can't from the backtrace alone tell where that might be,
there's not enough information about where regmap_init() is being called
from.


Attachments:
(No filename) (1.44 kB)
signature.asc (499.00 B)
Download all attachments