lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [thread-next>] [day] [month] [year] [list]
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