[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <20140602065357.GA8851@localhost>
Date: Mon, 2 Jun 2014 14:53:57 +0800
From: Fengguang Wu <fengguang.wu@...el.com>
To: Jesse Barnes <jbarnes@...tuousgeek.org>
Cc: Jet Chen <jet.chen@...el.com>, Yuanhan Liu <yuanhan.liu@...el.com>,
dri-devel@...ts.freedesktop.org, linux-kernel@...r.kernel.org
Subject: [drm] INFO: task swapper:1 blocked for more than 120 seconds.
Hi Jesse,
0day kernel testing robot got the below dmesg and the first bad commit is
git://people.freedesktop.org/~jbarnes/linux async-fb-probe
commit b739c9982801e5f76097311b67dfd76891b10988
Author: Jesse Barnes <jbarnes@...tuousgeek.org>
AuthorDate: Wed May 28 10:21:17 2014 -0700
Commit: Jesse Barnes <jbarnes@...tuousgeek.org>
CommitDate: Wed May 28 12:17:34 2014 -0700
drm: take modeset locks around initial fb helper probing
Drivers ought to complain otherwise.
Signed-off-by: Jesse Barnes <jbarnes@...tuousgeek.org>
===================================================
PARENT COMMIT NOT CLEAN. LOOK OUT FOR WRONG BISECT!
===================================================
1 /kernel/i386-randconfig-c1-06021140/071f9c57eea4876288ba1254c9ac3b0f077c2dd6
Attached dmesg for the parent commit, too, to help confirm whether it is a noise error.
+-------------------------------------------------------------+------------+------------+
| | 071f9c57ee | b739c99828 |
+-------------------------------------------------------------+------------+------------+
| boot_successes | 59 | 0 |
| boot_failures | 1 | 20 |
| WARNING:CPU:PID:at_mm/page_alloc.c:__alloc_pages_slowpath() | 1 | |
| backtrace:SYSC_socketcall | 1 | |
| backtrace:SyS_socketcall | 1 | |
| INFO:task_blocked_for_more_than_seconds | 0 | 20 |
| EIP_is_at_native_apic_mem_write | 0 | 20 |
| Kernel_panic-not_syncing:hung_task:blocked_tasks | 0 | 20 |
| backtrace:drm_fb_helper_initial_config | 0 | 20 |
| backtrace:cirrus_fbdev_init | 0 | 20 |
| backtrace:cirrus_modeset_init | 0 | 20 |
| backtrace:__pci_register_driver | 0 | 20 |
| backtrace:drm_pci_init | 0 | 20 |
| backtrace:cirrus_init | 0 | 20 |
| backtrace:kernel_init_freeable | 0 | 20 |
| backtrace:watchdog | 0 | 20 |
+-------------------------------------------------------------+------------+------------+
[ 8.873617] [drm] Initialized drm 1.1.0 20060810
[ 8.874286] [drm] radeon kernel modesetting enabled.
[ 8.876773] [TTM] Zone kernel: Available graphics memory: 135440 kiB
[ 8.877424] [TTM] Initializing pool allocator
[ 61.017759] spin_lock-torture: Writes: Total: 2 Max/Min: 0/0 Fail: 0
[ 121.025590] spin_lock-torture: Writes: Total: 2 Max/Min: 0/0 Fail: 0
[ 181.030819] spin_lock-torture: Writes: Total: 2 Max/Min: 0/0 Fail: 0
[ 240.212728] INFO: task swapper:1 blocked for more than 120 seconds.
[ 240.213429] Not tainted 3.15.0-rc5-00087-gb739c99 #1
[ 240.213994] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 240.214777] swapper D d3429c24 5944 1 0 0x00000000
[ 240.215484] d3429c48 00000046 00000000 d3429c24 c184af4c c2f31008 d3422000 d1f2d034
[ 240.216408] c2f31008 d1f2d034 c2f30fe0 c2f30fe0 d3429c1c c10bbfe0 d1f2d02c c2f30fe0
[ 240.217339] d3429c2c c10bc022 d1f2d02c 00000001 00000001 c10bc839 00000002 c2f30fe0
[ 240.218258] Call Trace:
[ 240.218551] [<c184af4c>] ? rb_erase+0x3d/0x576
[ 240.219043] [<c10bbfe0>] ? __dequeue_entity+0x4d/0x5f
[ 240.219573] [<c10bc022>] ? set_next_entity+0x30/0x63
[ 240.220108] [<c10bc839>] ? pick_next_task_fair+0x267/0x29a
[ 240.220698] [<c25fab5f>] __schedule+0x893/0xa1b
[ 240.221178] [<c25fae2c>] schedule+0x145/0x155
[ 240.221629] [<c25fae66>] schedule_preempt_disabled+0x2a/0x4e
[ 240.222220] [<c25fc513>] mutex_lock_nested+0x470/0x8cd
[ 240.222763] [<c1a52953>] ? drm_modeset_lock_all+0x23/0x80
[ 240.223321] [<c1a52953>] ? drm_modeset_lock_all+0x23/0x80
[ 240.223872] [<c1a52953>] drm_modeset_lock_all+0x23/0x80
[ 240.224418] [<c1a3c19f>] drm_fb_helper_initial_config+0x2d0/0x78e
[ 240.225059] [<c10c411d>] ? debug_mutex_unlock+0x31a/0x3ca
[ 240.225629] [<c25fd107>] ? _mutex_lock_nest_lock+0x797/0x8c9
[ 240.226213] [<c25fe6cc>] ? __mutex_unlock_slowpath+0x2eb/0x30f
[ 240.226811] [<c1a52a13>] ? drm_modeset_unlock_all+0x63/0x76
[ 240.227406] [<c1cbd75d>] cirrus_fbdev_init+0xf8/0x115
[ 240.227947] [<c1cbc61b>] cirrus_modeset_init+0x2ee/0x3a9
[ 240.228505] [<c1cba8f8>] ? cirrus_device_init+0x153/0x1e9
[ 240.229083] [<c1cbabeb>] cirrus_driver_load+0x134/0x1c3
[ 240.229633] [<c1a4bd17>] drm_dev_register+0xf0/0x1f4
[ 240.230149] [<c1a4e5ea>] drm_get_pci_dev+0x207/0x336
[ 240.230668] [<c1cbc9e9>] ? cirrus_kick_out_firmware_fb+0x11c/0x137
[ 240.231312] [<c11d5f8e>] ? kfree+0x14e/0x1d4
[ 240.231764] [<c1cbca50>] cirrus_pci_probe+0x4c/0x5e
[ 240.232279] [<c18a468b>] pci_device_probe+0xd0/0x1a5
[ 240.232824] [<c127c9fc>] ? sysfs_create_link+0x20/0x30
[ 240.233376] [<c1e212f8>] driver_probe_device+0x137/0x3fe
[ 240.233926] [<c1e2165f>] __driver_attach+0xa0/0xf4
[ 240.234420] [<c1e1e4ee>] bus_for_each_dev+0x96/0xf3
[ 240.234926] [<c1e20df6>] driver_attach+0x25/0x35
[ 240.235413] [<c1e215bf>] ? driver_probe_device+0x3fe/0x3fe
[ 240.235976] [<c1e1f40a>] bus_add_driver+0x161/0x389
[ 240.236483] [<c1e225eb>] driver_register+0x16e/0x1f6
[ 240.237006] [<c10cbcfb>] ? __raw_spin_lock_init+0x49/0x78
[ 240.237570] [<c18a4305>] __pci_register_driver+0x61/0x72
[ 240.238129] [<c1a4e7b6>] drm_pci_init+0x9d/0x18c
[ 240.238623] [<c33bb5ca>] ? ftrace_define_fields_i915_gem_object_create+0xa9/0xa9
[ 240.239367] [<c33bb601>] cirrus_init+0x37/0x4f
[ 240.239838] [<c333e5fb>] do_one_initcall+0xf4/0x26c
[ 240.240346] [<c1854fe9>] ? trace_hardirqs_on_thunk+0xc/0x10
[ 240.240959] [<c26039d6>] ? restore_all+0xf/0xf
[ 240.241420] [<c333ec04>] kernel_init_freeable+0x491/0x62a
[ 240.241990] [<c333d652>] ? do_early_param+0x12b/0x12b
[ 240.242531] [<c259fe0e>] kernel_init+0x19/0x1f6
[ 240.243013] [<c10b4d92>] ? schedule_tail+0x1a/0xa9
[ 240.243517] [<c26042a0>] ret_from_kernel_thread+0x20/0x30
[ 240.244076] [<c259fdf5>] ? rest_init+0x1dd/0x1dd
[ 240.244565] 5 locks held by swapper/1:
[ 240.244959] #0: (&dev->mutex){......}, at: [<c1e20553>] device_lock+0x1b/0x2b
[ 240.245769] #1: (&dev->mutex){......}, at: [<c1e20553>] device_lock+0x1b/0x2b
[ 240.246599] #2: (drm_global_mutex){......}, at: [<c1a4bc4b>] drm_dev_register+0x24/0x1f4
[ 240.247513] #3: (&dev->mode_config.mutex){......}, at: [<c1a3c18a>] drm_fb_helper_initial_config+0x2bb/0x78e
[ 240.248628] #4: (&dev->mode_config.mutex){......}, at: [<c1a52953>] drm_modeset_lock_all+0x23/0x80
[ 240.249627] sending NMI to all CPUs:
[ 240.250023] NMI backtrace for cpu 0
[ 240.250387] CPU: 0 PID: 8 Comm: khungtaskd Not tainted 3.15.0-rc5-00087-gb739c99 #1
[ 240.251155] task: d35d0410 ti: d35f8000 task.ti: d35f8000
[ 240.251694] EIP: 0060:[<c10458b6>] EFLAGS: 00000046 CPU: 0
[ 240.252263] EIP is at native_apic_mem_write+0x20/0x30
[ 240.252623] EAX: ffffb300 EBX: 00000201 ECX: fffff000 EDX: 00000c00
[ 240.252623] ESI: 00000002 EDI: 01000000 EBP: d35f9e9c ESP: d35f9e9c
[ 240.252623] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[ 240.252623] CR0: 8005003b CR2: 00000000 CR3: 11ec1000 CR4: 000006d0
[ 240.252623] Stack:
[ 240.252623] d35f9eb4 c1045a5c 00000800 00000246 00000001 00000000 d35f9ed0 c1045f92
[ 240.252623] 00000002 00000000 00000002 d3422000 d3422000 d35f9ed8 c1045fee d35f9ee8
[ 240.252623] c10462cd c2d5dce2 00000002 d35f9f30 c111fecf c2d6bb8b c3480e6c c2ef6456
[ 240.252623] Call Trace:
[ 240.252623] [<c1045a5c>] __default_send_IPI_dest_field+0xec/0x100
[ 240.252623] [<c1045f92>] default_send_IPI_mask_logical+0x16c/0x17d
[ 240.252623] [<c1045fee>] default_send_IPI_all+0x38/0x94
[ 240.252623] [<c10462cd>] arch_trigger_all_cpu_backtrace+0xc5/0x1b8
[ 240.252623] [<c111fecf>] watchdog+0x55d/0x61a
[ 240.252623] [<c111f972>] ? rcu_read_lock+0x81/0x81
[ 240.252623] [<c10a2581>] kthread+0x115/0x128
[ 240.252623] [<c10c7fed>] ? lock_release+0x3ca/0x48a
[ 240.252623] [<c26042a0>] ret_from_kernel_thread+0x20/0x30
[ 240.252623] [<c10a246c>] ? __kthread_unpark+0x9b/0x9b
[ 240.252623] Code: 83 15 f4 db 46 c3 00 89 c8 5d c3 55 89 e5 83 05 08 dc 46 c3 01 83 15 0c dc 46 c3 00 8b 0d 74 bd f1 c2 8d 84 08 00 c0 ff ff 89 10 <83> 05 10 dc 46 c3 01 83 15 14 dc 46 c3 00 5d c3 55 89 e5 09 c8
git bisect start 5dba024fe84a491ec3ca15193923fcbb938e68f7 fad01e866afdbe01a1f3ec06a39c3a8b9e197014 --
git bisect good 12072cdd5c9b56bb6d4169c5a52c9d0bf64b7f84 # 12:32 20+ 0 Merge 'gxt/unicore32' into devel-hourly-2014060210
git bisect good eb1a12ad1d5a7312a6f3dc6a8b77c51cbe58641e # 12:42 20+ 0 Merge 'luto/auditsc-lite' into devel-hourly-2014060210
git bisect good d641155270aff21eacd2622e30129cd91fe8d2d2 # 12:51 20+ 0 Merge 'wsa/i2c/for-next' into devel-hourly-2014060210
git bisect good 002fa82dac6f0be486333e6424968c0c42c0e799 # 13:01 20+ 0 Merge 'jbarnes/async' into devel-hourly-2014060210
git bisect bad 1ea52a9605be1234b7da3e4d134917c7ba3be93d # 13:15 0- 5 Merge 'jbarnes/async-fb-probe' into devel-hourly-2014060210
git bisect bad f728080d6bac47aab2d570492acef88317ac8e03 # 13:41 0- 10 drm/i915: make fbdev initialization asynchronous v2
git bisect bad b739c9982801e5f76097311b67dfd76891b10988 # 13:50 0- 11 drm: take modeset locks around initial fb helper probing
# first bad commit: [b739c9982801e5f76097311b67dfd76891b10988] drm: take modeset locks around initial fb helper probing
git bisect good 071f9c57eea4876288ba1254c9ac3b0f077c2dd6 # 14:01 60+ 1 drm/i915/vlv: enable PPGTT
git bisect bad 5dba024fe84a491ec3ca15193923fcbb938e68f7 # 14:01 0- 13 0day head guard for 'devel-hourly-2014060210'
git bisect good fad01e866afdbe01a1f3ec06a39c3a8b9e197014 # 14:08 60+ 0 Linux 3.15-rc8
git bisect good 322c030f5462a44ce42f8804284eb52b7cd2ba41 # 14:25 60+ 60 Add linux-next specific files for 20140530
This script may reproduce the error.
-----------------------------------------------------------------------------
#!/bin/bash
kernel=$1
initrd=yocto-minimal-i386.cgz
wget --no-clobber https://github.com/fengguang/reproduce-kernel-bug/blob/master/initrd/$initrd
kvm=(
qemu-system-x86_64 -cpu kvm64 -enable-kvm
-kernel $kernel
-initrd $initrd
-smp 2
-m 256M
-net nic,vlan=0,macaddr=00:00:00:00:00:00,model=virtio
-net user,vlan=0
-net nic,vlan=1,model=e1000
-net user,vlan=1
-boot order=nc
-no-reboot
-watchdog i6300esb
-serial stdio
-display none
-monitor null
)
append=(
debug
sched_debug
apic=debug
ignore_loglevel
sysrq_always_enabled
panic=10
prompt_ramdisk=0
earlyprintk=ttyS0,115200
console=ttyS0,115200
console=tty0
vga=normal
root=/dev/ram0
rw
)
"${kvm[@]}" --append "${append[*]}"
-----------------------------------------------------------------------------
Thanks,
Fengguang
View attachment "dmesg-yocto-ivb42-69:20140602135027:i386-randconfig-c1-06021140:3.15.0-rc5-00087-gb739c99:1" of type "text/plain" (35767 bytes)
View attachment "dmesg-quantal-ivb42-28:20140602135742:i386-randconfig-c1-06021140:3.15.0-rc5-00086-g071f9c5:1" of type "text/plain" (44249 bytes)
Download attachment "i386-randconfig-c1-06021140-5dba024fe84a491ec3ca15193923fcbb938e68f7-blocked-for-more-than-----seconds-128869.log" of type "application/octet-stream" (58040 bytes)
View attachment "config-3.15.0-rc5-00087-gb739c99" of type "text/plain" (83458 bytes)
_______________________________________________
LKP mailing list
LKP@...ux.intel.com
Powered by blists - more mailing lists