[Intel-gfx] ✗ Fi.CI.BAT: failure for i915 PMU and engine busy stats (rev18)

Chris Wilson chris at chris-wilson.co.uk
Tue Oct 17 11:21:56 UTC 2017


Quoting Patchwork (2017-10-17 12:12:55)
> == Series Details ==
> 
> Series: i915 PMU and engine busy stats (rev18)
> URL   : https://patchwork.freedesktop.org/series/27488/
> State : failure
> 
> == Summary ==
> 
> Series 27488v18 i915 PMU and engine busy stats
> https://patchwork.freedesktop.org/api/1.0/series/27488/revisions/18/mbox/
> 
> Test gem_exec_suspend:
>         Subgroup basic-s3:
>                 pass       -> INCOMPLETE (fi-pnv-d510)
>                 pass       -> INCOMPLETE (fi-byt-j1900)
>                 pass       -> INCOMPLETE (fi-glk-1)

At least glk had pstore!

<6>[  251.557743] Disabling non-boot CPUs ...
<4>[  251.576367] IRQ 127: no longer affine to CPU1
<6>[  251.578495] smpboot: CPU 1 is now offline
<4>[  251.599991] IRQ 121: no longer affine to CPU2
<6>[  251.602337] smpboot: CPU 2 is now offline
<4>[  251.618470] INFO: trying to register non-static key.
<4>[  251.618472] the code is fine but needs lockdep annotation.
<4>[  251.618473] turning off the locking correctness validator.
<4>[  251.618481] CPU: 3 PID: 26 Comm: cpuhp/3 Tainted: G     U          4.14.0-rc5-CI-Patchwork_6068+ #1
<4>[  251.618483] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
<4>[  251.618486] Call Trace:
<4>[  251.618500]  dump_stack+0x68/0x9f
<4>[  251.618507]  register_lock_class+0x3fd/0x580
<4>[  251.618515]  ? __save_stack_trace+0x73/0xd0
<4>[  251.618522]  __lock_acquire+0xa4/0x1b00
<4>[  251.618527]  ? padata_cpu_prep_down+0x35/0x60
<4>[  251.618534]  ? __slab_free+0x3b4/0x540
<4>[  251.618539]  ? __this_cpu_preempt_check+0x13/0x20
<4>[  251.618545]  lock_acquire+0xb0/0x200
<4>[  251.618548]  ? lock_acquire+0xb0/0x200
<4>[  251.618552]  ? padata_cpu_prep_down+0x35/0x60
<4>[  251.618559]  __mutex_lock+0x86/0x9b0
<4>[  251.618562]  ? padata_cpu_prep_down+0x35/0x60
<4>[  251.618566]  ? padata_cpu_prep_down+0x35/0x60
<4>[  251.618570]  ? __lock_acquire+0x4ab/0x1b00
<4>[  251.618577]  mutex_lock_nested+0x1b/0x20
<4>[  251.618581]  ? mutex_lock_nested+0x1b/0x20
<4>[  251.618584]  padata_cpu_prep_down+0x35/0x60
<4>[  251.618590]  cpuhp_invoke_callback+0x161/0xbf0
<4>[  251.618594]  ? cpuhp_thread_fun+0x41/0x240
<4>[  251.618597]  ? padata_remove_cpu+0x80/0x80
<4>[  251.618602]  cpuhp_thread_fun+0x17b/0x240
<4>[  251.618609]  ? smpboot_thread_fn+0x2d/0x280
<4>[  251.618613]  smpboot_thread_fn+0x18a/0x280
<4>[  251.618617]  kthread+0x114/0x150
<4>[  251.618621]  ? sort_range+0x30/0x30
<4>[  251.618624]  ? kthread_create_on_node+0x40/0x40
<4>[  251.618630]  ret_from_fork+0x27/0x40
<3>[  251.618696] ODEBUG: assert_init not available (active state 0) object type: timer_list hint: ONEf+0x1741e/0xba963
<4>[  251.618737] ------------[ cut here ]------------
<4>[  251.618743] WARNING: CPU: 3 PID: 26 at lib/debugobjects.c:291 debug_print_object+0x76/0x80
<4>[  251.618746] Modules linked in: snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm mei_me r8169 prime_numbers mii mei i2c_hid pinctrl_geminilake pinctrl_intel
<4>[  251.618809] CPU: 3 PID: 26 Comm: cpuhp/3 Tainted: G     U          4.14.0-rc5-CI-Patchwork_6068+ #1
<4>[  251.618812] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
<4>[  251.618816] task: ffff88017ab5cec0 task.stack: ffffc90000140000
<4>[  251.618821] RIP: 0010:debug_print_object+0x76/0x80
<4>[  251.618825] RSP: 0018:ffffc90000143c78 EFLAGS: 00010296
<4>[  251.618830] RAX: 0000000000000065 RBX: ffffc90000143ca0 RCX: 0000000000000000
<4>[  251.618833] RDX: 0000000080000001 RSI: 0000000000000001 RDI: ffffffff810ee876
<4>[  251.618836] RBP: ffffc90000143c90 R08: 0000000000000001 R09: 0000000000000000
<4>[  251.618839] R10: 0000000000000000 R11: 0000000000000000 R12: ffffffff81e4f5e0
<4>[  251.618843] R13: ffffffff81cc1c4b R14: ffffffff82d63ba8 R15: 0000000000000000
<4>[  251.618847] FS:  0000000000000000(0000) GS:ffff88017fd80000(0000) knlGS:0000000000000000
<4>[  251.618850] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  251.618854] CR2: 00007f830b4ddd70 CR3: 00000001733f7000 CR4: 00000000003406e0
<4>[  251.618857] Call Trace:
<4>[  251.618865]  debug_object_assert_init+0x129/0x140
<4>[  251.618873]  ? del_timer_sync+0x5/0xb0
<4>[  251.618880]  try_to_del_timer_sync+0x1f/0x70
<4>[  251.618884]  ? try_to_del_timer_sync+0x1f/0x70
<4>[  251.618889]  del_timer_sync+0x8c/0xb0
<4>[  251.618895]  padata_flush_queues+0x5a/0xc0
<4>[  251.618901]  padata_replace+0x58/0x110
<4>[  251.618907]  __padata_remove_cpu+0x82/0xb0
<4>[  251.618913]  padata_cpu_prep_down+0x40/0x60
<4>[  251.618919]  cpuhp_invoke_callback+0x161/0xbf0
<4>[  251.618925]  ? cpuhp_thread_fun+0x41/0x240
<4>[  251.618929]  ? padata_remove_cpu+0x80/0x80
<4>[  251.618937]  cpuhp_thread_fun+0x17b/0x240
<4>[  251.618944]  ? smpboot_thread_fn+0x2d/0x280
<4>[  251.618950]  smpboot_thread_fn+0x18a/0x280
<4>[  251.618956]  kthread+0x114/0x150
<4>[  251.618961]  ? sort_range+0x30/0x30
<4>[  251.618965]  ? kthread_create_on_node+0x40/0x40
<4>[  251.618973]  ret_from_fork+0x27/0x40
<4>[  251.618983] Code: 49 89 c1 8b 43 10 8b 4b 14 4c 89 ee 4d 8b 04 24 48 c7 c7 68 1a cc 81 83 05 1f 4e 87 01 01 48 8b 14 c5 80 c8 a6 81 e8 db ee c5 ff <0f> ff eb a5 45 31 c9 eb cf 90 55 48 89 e5 41 57 41 56 41 55 41 
<4>[  251.619153] ---[ end trace b31bdc7f94776dac ]---
<4>[  251.619178] ------------[ cut here ]------------
<4>[  251.619186] WARNING: CPU: 3 PID: 26 at mm/vmalloc.c:245 vmalloc_to_page+0x137/0x140
<4>[  251.619189] Modules linked in: snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm mei_me r8169 prime_numbers mii mei i2c_hid pinctrl_geminilake pinctrl_intel
<4>[  251.619242] CPU: 3 PID: 26 Comm: cpuhp/3 Tainted: G     U  W       4.14.0-rc5-CI-Patchwork_6068+ #1
<4>[  251.619245] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
<4>[  251.619248] task: ffff88017ab5cec0 task.stack: ffffc90000140000
<4>[  251.619253] RIP: 0010:vmalloc_to_page+0x137/0x140
<4>[  251.619257] RSP: 0018:ffffc90000143d48 EFLAGS: 00010082
<4>[  251.619262] RAX: 8000000101a001e3 RBX: ffff88017fff9a00 RCX: 8000000101a001e3
<4>[  251.619265] RDX: 00003fffffe00000 RSI: ffff880000000000 RDI: ffff880101be3c00
<4>[  251.619268] RBP: ffffc90000143d48 R08: 80000000000001e3 R09: ffffc000001fffff
<4>[  251.619271] R10: 000000010f11e000 R11: ffffffff811bd999 R12: ffff880101a63c00
<4>[  251.619274] R13: ffffffff81e63c00 R14: 0000000000000287 R15: 0000000000000000
<4>[  251.619278] FS:  0000000000000000(0000) GS:ffff88017fd80000(0000) knlGS:0000000000000000
<4>[  251.619282] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  251.619285] CR2: 00007f830b4ddd70 CR3: 00000001733f7000 CR4: 00000000003406e0
<4>[  251.619287] Call Trace:
<4>[  251.619299]  free_percpu+0x120/0x290
<4>[  251.619306]  padata_replace+0x62/0x110
<4>[  251.619312]  __padata_remove_cpu+0x82/0xb0
<4>[  251.619317]  padata_cpu_prep_down+0x40/0x60
<4>[  251.619324]  cpuhp_invoke_callback+0x161/0xbf0
<4>[  251.619329]  ? cpuhp_thread_fun+0x41/0x240
<4>[  251.619334]  ? padata_remove_cpu+0x80/0x80
<4>[  251.619341]  cpuhp_thread_fun+0x17b/0x240
<4>[  251.619348]  ? smpboot_thread_fn+0x2d/0x280
<4>[  251.619353]  smpboot_thread_fn+0x18a/0x280
<4>[  251.619359]  kthread+0x114/0x150
<4>[  251.619364]  ? sort_range+0x30/0x30
<4>[  251.619368]  ? kthread_create_on_node+0x40/0x40
<4>[  251.619376]  ret_from_fork+0x27/0x40
<4>[  251.619386] Code: 01 01 00 00 74 1b 48 c1 e0 12 48 ba 00 00 00 00 00 ea ff ff 48 c1 e8 1e 48 c1 e0 06 48 01 d0 5d c3 31 c0 5d c3 0f ff 31 c0 5d c3 <0f> ff 31 c0 5d c3 0f 1f 00 0f 1f 44 00 00 55 48 89 e5 e8 b2 fe 
<4>[  251.619529] ---[ end trace b31bdc7f94776dad ]---
<1>[  251.619540] BUG: unable to handle kernel NULL pointer dereference at 0000000000000010
<1>[  251.619550] IP: free_percpu+0x120/0x290
<6>[  251.619554] PGD 0 P4D 0 
<4>[  251.619562] Oops: 0000 [#1] PREEMPT SMP
<4>[  251.619565] Modules linked in: snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm mei_me r8169 prime_numbers mii mei i2c_hid pinctrl_geminilake pinctrl_intel
<4>[  251.619617] CPU: 3 PID: 26 Comm: cpuhp/3 Tainted: G     U  W       4.14.0-rc5-CI-Patchwork_6068+ #1
<4>[  251.619620] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
<4>[  251.619623] task: ffff88017ab5cec0 task.stack: ffffc90000140000
<4>[  251.619628] RIP: 0010:free_percpu+0x120/0x290
<4>[  251.619631] RSP: 0018:ffffc90000143d58 EFLAGS: 00010046
<4>[  251.619637] RAX: 0000000000000000 RBX: ffff88017fff9a00 RCX: 8000000101a001e3
<4>[  251.619640] RDX: 00003fffffe00000 RSI: ffff880000000000 RDI: ffff880101be3c00
<4>[  251.619643] RBP: ffffc90000143d80 R08: 80000000000001e3 R09: ffffc000001fffff
<4>[  251.619646] R10: 000000010f11e000 R11: ffffffff811bd999 R12: ffff880101a63c00
<4>[  251.619649] R13: ffffffff81e63c00 R14: 0000000000000287 R15: 0000000000000000
<4>[  251.619653] FS:  0000000000000000(0000) GS:ffff88017fd80000(0000) knlGS:0000000000000000
<4>[  251.619656] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  251.619659] CR2: 0000000000000010 CR3: 00000001733f7000 CR4: 00000000003406e0
<4>[  251.619662] Call Trace:
<4>[  251.619669]  padata_replace+0x62/0x110
<4>[  251.619675]  __padata_remove_cpu+0x82/0xb0
<4>[  251.619681]  padata_cpu_prep_down+0x40/0x60
<4>[  251.619687]  cpuhp_invoke_callback+0x161/0xbf0
<4>[  251.619692]  ? cpuhp_thread_fun+0x41/0x240
<4>[  251.619697]  ? padata_remove_cpu+0x80/0x80
<4>[  251.619704]  cpuhp_thread_fun+0x17b/0x240
<4>[  251.619711]  ? smpboot_thread_fn+0x2d/0x280
<4>[  251.619716]  smpboot_thread_fn+0x18a/0x280
<4>[  251.619722]  kthread+0x114/0x150
<4>[  251.619727]  ? sort_range+0x30/0x30
<4>[  251.619731]  ? kthread_create_on_node+0x40/0x40
<4>[  251.619739]  ret_from_fork+0x27/0x40
<4>[  251.619749] Code: 63 43 50 48 01 d0 49 39 c4 0f 83 72 ff ff ff 48 8b 15 bd 51 b7 00 4c 89 e7 65 8b 05 b3 c6 e4 7e 48 98 48 03 3c c2 e8 a0 2a 02 00 <48> 8b 58 10 48 8b 53 20 e9 49 ff ff ff 65 8b 05 94 c6 e4 7e 89 
<1>[  251.619894] RIP: free_percpu+0x120/0x290 RSP: ffffc90000143d58
<4>[  251.619897] CR2: 0000000000000010
<4>[  251.619903] ---[ end trace b31bdc7f94776dae ]---
<3>[  251.729960] BUG: sleeping function called from invalid context at ./include/linux/percpu-rwsem.h:33
<3>[  251.729963] in_atomic(): 1, irqs_disabled(): 1, pid: 26, name: cpuhp/3
<4>[  251.729964] INFO: lockdep is turned off.
<4>[  251.729965] irq event stamp: 2999
<4>[  251.729970] hardirqs last  enabled at (2999): [<ffffffff811fd794>] __slab_free+0x3b4/0x540
<4>[  251.729972] hardirqs last disabled at (2998): [<ffffffff811fd4f4>] __slab_free+0x114/0x540
<4>[  251.729975] softirqs last  enabled at (2752): [<ffffffff819122d6>] __do_softirq+0x3a6/0x4ae
<4>[  251.729978] softirqs last disabled at (2727): [<ffffffff8108619e>] irq_exit+0xae/0xc0
<3>[  251.729979] Preemption disabled at:
<4>[  251.729983] [<ffffffff811bd999>] free_percpu+0x39/0x290
<4>[  251.729987] CPU: 3 PID: 26 Comm: cpuhp/3 Tainted: G     UD W       4.14.0-rc5-CI-Patchwork_6068+ #1
<4>[  251.729988] Hardware name: Intel Corp. Geminilake/GLK RVP2 LP4SD (07), BIOS GELKRVPA.X64.0062.B30.1708222146 08/22/2017
<4>[  251.729989] Call Trace:
<4>[  251.729997]  dump_stack+0x68/0x9f
<4>[  251.729999]  ___might_sleep+0x1e5/0x240
<4>[  251.730001]  __might_sleep+0x4a/0x80
<4>[  251.730005]  exit_signals+0x24/0x2a0
<4>[  251.730008]  ? smpboot_thread_fn+0x18a/0x280
<4>[  251.730009]  do_exit+0x9a/0xca0
<4>[  251.730011]  ? kthread+0x114/0x150
<4>[  251.730013]  ? sort_range+0x30/0x30
<4>[  251.730015]  rewind_stack_do_exit+0x17/0x20
<6>[  251.730092] note: cpuhp/3[26] exited with preempt_count 1
<2>[  337.964669] softdog: Initiating panic
<0>[  337.964674] Kernel panic - not syncing: Software Watchdog Timer expired
<0>[  337.964698] Kernel Offset: disabled

All look like a bug you may have tickled rather than caused. Though I'd
kasan for a use-after-free. But an odd mixtures of Atoms; presuming they
are all the same.
-Chris


More information about the Intel-gfx mailing list