Bug 814939

Summary:	BUG: soft lockup - CPU#4 stuck for 22s! [btrfs-endio-wri:1589]
Product:	[Fedora] Fedora	Reporter:	Mikko Tiihonen <mikko.tiihonen>
Component:	kernel	Assignee:	Zach Brown <zab>
Status:	CLOSED INSUFFICIENT_DATA	QA Contact:	Fedora Extras Quality Assurance <extras-qa>
Severity:	unspecified	Docs Contact:
Priority:	unspecified
Version:	17	CC:	chapinjeff, gansalmon, itamar, jforbes, jonathan, kernel-maint, madhu.chinakonda, sweil
Target Milestone:	---
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:	first=3.4 btrfs
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2013-01-02 13:15:29 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:

Description Mikko Tiihonen 2012-04-21 13:09:16 UTC

Description of problem:
Machine got stuck when trying to log in to gnome

Version-Release number of selected component (if applicable):
kernel 3.4.0-0.rc3.git2.1.fc18.x86_64 with Fedora 17 userspace


BUG: soft lockup - CPU#4 stuck for 22s! [btrfs-endio-wri:1589]
Modules linked in: tda10048 tda827x tda10023 dvb_usb_ttusb2 dvb_usb dvb_core rc_core nf_conntrack_netbios_ns nf_conntrack_broadcast ipt_MASQUERADE ip6table_mangle ip6t_REJECT nf_conntrack_igle nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ip6table_filter ip6_tables ebtable_nat ebtables lockd sunrpc rfcomm bnep btusb bluetooth arc4 uvcvideo videobuf2_vmalloc video usbnet mii cdc_wdm cdc_acm snd_hda_codec_hdmi coretemp microcode iwlwifi snd_hda_codec_conexant mac80211 i2c_i801 iTCO_wdt iTCO_vendor_support cfg80211 snd_hda_intel snd_hda_codec snd_hwded_acpi snd soundcore rfkill binfmt_misc vhost_net tun macvtap macvlan kvm_intel kvm uinput btrfs libcrc32c zlib_deflate crc32c_intel ghash_clmulni_intel sdhci_pci firewire_ohci sdhci firewideo drm_kms_helper ttm drm i2
loaded: scsi_wait_scan]
irq event stamp: 284581
hardirqs last  enabled at (284580): [<ffffffff816b87f0>] restore_args+0x0/0x30
hardirqs last disabled at (284581): [<ffffffff816c1cea>] apic_timer_interrupt+0x6a/0x80
softirqs last  enabled at (231256): [<ffffffff8106a404>] __do_softirq+0x154/0x3b0
softirqs last disabled at (231269): [<ffffffff816c26ec>] call_softirq+0x1c/0x30
CPU 4 
Modules linked in: tda10048 tda827x tda10023 dvb_usb_ttusb2 dvb_usb dvb_core rc_core nf_conntrack_netbios_ns nf_conntrack_broadcast ipt_MASQUERADE ip6table_mangle ip6t_REJECT nf_conntrack_igle nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ip6table_filter ip6_tables ebtable_nat ebtables lockd sunrpc rfcomm bnep btusb bluetooth arc4 uvcvideo videobuf2_vmalloc video usbnet mii cdc_wdm cdc_acm snd_hda_codec_hdmi coretemp microcode iwlwifi snd_hda_codec_conexant mac80211 i2c_i801 iTCO_wdt iTCO_vendor_support cfg80211 snd_hda_intel snd_hda_codec snd_hwded_acpi snd soundcore rfkill binfmt_misc vhost_net tun macvtap macvlan kvm_intel kvm uinput btrfs libcrc32c zlib_deflate crc32c_intel ghash_clmulni_intel sdhci_pci firewire_ohci sdhci firewideo drm_kms_helper ttm drm i2
loaded: scsi_wait_scan]

Pid: 1589, comm: btrfs-endio-wri Not tainted 3.4.0-0.rc3.git2.1.fc18.x86_64 #1 LENOVO 42844DG/42844DG
RIP: 0010:[<ffffffff816ade60>]  [<ffffffff816ade60>] free_debug_processing+0x1ca/0x1fc
RSP: 0018:ffff88042ce03ce0  EFLAGS: 00000282
RAX: ffff8803fcb10000 RBX: ffffffff816b87f0 RCX: 0000000000000002
RDX: 0000000000002f20 RSI: ffff8803fcb108f0 RDI: 0000000000000282
RBP: ffff88042ce03d20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffff88042ce03c58
R13: ffffffff816c1cef R14: ffff88042ce03d20 R15: ffff88042133a6c8
FS:  0000000000000000(0000) GS:ffff88042ce00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 00000000055870b8 CR3: 00000003fc81f000 CR4: 00000000000407e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process btrfs-endio-wri (pid: 1589, threadinfo ffff8803ff312000, task ffff8803fcb10000)
Stack:
 ffff88042ce03d00 ffffffffa020470d 0000000000000286 ffffea00104a1600
 ffff88042133a6c8 ffffea00104a1600 ffffffffa020470d ffff88042133a6c8
 ffff88042ce03dc0 ffffffff816ae4aa ffff88042ce03dc0 ffffffff8133ea8c
Call Trace:
 <IRQ> 
 [<ffffffffa020470d>] ? __free_extent_buffer+0x3d/0x50 [btrfs]
 [<ffffffffa020470d>] ? __free_extent_buffer+0x3d/0x50 [btrfs]
 [<ffffffff816ae4aa>] __slab_free+0x3d/0x266
 [<ffffffff8133ea8c>] ? debug_check_no_obj_freed+0x16c/0x210
 [<ffffffff816b835f>] ? _raw_spin_unlock_irqrestore+0x3f/0x80
 [<ffffffffa020470d>] ? __free_extent_buffer+0x3d/0x50 [btrfs]
 [<ffffffffa020470d>] ? __free_extent_buffer+0x3d/0x50 [btrfs]
 [<ffffffff811a5ab9>] kmem_cache_free+0x249/0x260
 [<ffffffffa020470d>] __free_extent_buffer+0x3d/0x50 [btrfs]
 [<ffffffffa0204730>] btrfs_release_extent_buffer_rcu+0x10/0x20 [btrfs]
 [<ffffffff81114602>] __rcu_process_callbacks+0x1b2/0x4b0
 [<ffffffff8111492f>] rcu_process_callbacks+0x2f/0x270
 [<ffffffff8106a390>] __do_softirq+0xe0/0x3b0
 [<ffffffff81020cc3>] ? native_sched_clock+0x13/0x80
 [<ffffffff816c26ec>] call_softirq+0x1c/0x30
 [<ffffffff8101b325>] do_softirq+0xa5/0xe0
 [<ffffffff8106a9d5>] irq_exit+0xd5/0xe0
 [<ffffffff816c306e>] smp_apic_timer_interrupt+0x6e/0x99
 [<ffffffff816c1cef>] apic_timer_interrupt+0x6f/0x80
 <EOI> 
 [<ffffffff816b87f0>] ? retint_restore_args+0x13/0x13
 [<ffffffff816ade60>] ? free_debug_processing+0x1ca/0x1fc
 [<ffffffffa02054af>] ? free_extent_state.part.32+0x3f/0x160 [btrfs]
 [<ffffffffa02054af>] ? free_extent_state.part.32+0x3f/0x160 [btrfs]
 [<ffffffff816ae4aa>] __slab_free+0x3d/0x266
 [<ffffffff8133ea8c>] ? debug_check_no_obj_freed+0x16c/0x210
 [<ffffffffa02054af>] ? free_extent_state.part.32+0x3f/0x160 [btrfs]
 [<ffffffffa02054af>] ? free_extent_state.part.32+0x3f/0x160 [btrfs]
 [<ffffffff811a5ab9>] kmem_cache_free+0x249/0x260
 [<ffffffffa0205781>] ? free_extent_state+0x21/0x30 [btrfs]
 [<ffffffffa02054af>] free_extent_state.part.32+0x3f/0x160 [btrfs]
 [<ffffffffa0205781>] free_extent_state+0x21/0x30 [btrfs]
 [<ffffffffa0205998>] merge_state+0x158/0x160 [btrfs]
 [<ffffffffa0205a06>] insert_state+0x66/0xd0 [btrfs]
 [<ffffffff816b7912>] ? _raw_spin_lock+0x72/0x80
 [<ffffffffa020601b>] __set_extent_bit+0x3eb/0x440 [btrfs]
 [<ffffffffa02065c3>] set_extent_bit+0x23/0x30 [btrfs]
 [<ffffffffa0206980>] set_extent_dirty+0x20/0x30 [btrfs]
 [<ffffffffa01df4ae>] ? btrfs_set_buffer_uptodate+0xe/0x10 [btrfs]
 [<ffffffffa01d34ec>] btrfs_init_new_buffer+0xdc/0x160 [btrfs]
 [<ffffffffa01d3705>] btrfs_alloc_free_block+0x195/0x380 [btrfs]
 [<ffffffffa01bf914>] __btrfs_cow_block+0x134/0x510 [btrfs]
 [<ffffffffa01bfde7>] btrfs_cow_block+0xf7/0x2e0 [btrfs]
 [<ffffffffa01c3f07>] btrfs_search_slot+0x3e7/0x8f0 [btrfs]
 [<ffffffffa01c8d5b>] lookup_inline_extent_backref+0x8b/0x490 [btrfs]
 [<ffffffffa01be9ca>] ? btrfs_alloc_path+0x1a/0x20 [btrfs]
 [<ffffffffa01cb7fd>] __btrfs_free_extent+0xbd/0x7b0 [btrfs]
 [<ffffffffa01d1185>] run_clustered_refs+0x315/0xa40 [btrfs]
 [<ffffffffa0229b48>] ? find_ref_head+0xc8/0xf0 [btrfs]
 [<ffffffffa01d1a27>] btrfs_run_delayed_refs+0x177/0x4e0 [btrfs]
 [<ffffffff810c96cf>] ? lock_release_holdtime.part.27+0xf/0x180
 [<ffffffff816b83cb>] ? _raw_spin_unlock+0x2b/0x50
 [<ffffffffa01cab11>] ? block_rsv_release_bytes+0x121/0x240 [btrfs]
 [<ffffffffa01e424f>] __btrfs_end_transaction+0x9f/0x350 [btrfs]
 [<ffffffffa01e4575>] btrfs_end_transaction+0x15/0x20 [btrfs]
 [<ffffffffa01ea195>] btrfs_finish_ordered_io+0x185/0x3e0 [btrfs]
 [<ffffffffa01ea43c>] btrfs_writepage_end_io_hook+0x4c/0x170 [btrfs]
 [<ffffffffa0208545>] end_extent_writepage+0x65/0x110 [btrfs]
 [<ffffffffa0208633>] end_bio_extent_writepage+0x43/0xa0 [btrfs]
 [<ffffffff811f85cd>] bio_endio+0x1d/0x40
 [<ffffffffa01db581>] end_workqueue_fn+0x41/0x50 [btrfs]
 [<ffffffffa0215d19>] worker_loop+0x149/0x5d0 [btrfs]
 [<ffffffffa0215bd0>] ? btrfs_queue_worker+0x310/0x310 [btrfs]
 [<ffffffff8108b0b7>] kthread+0xb7/0xc0
 [<ffffffff816c25f4>] kernel_thread_helper+0x4/0x10
 [<ffffffff816b87f0>] ? retint_restore_args+0x13/0x13
 [<ffffffff8108b000>] ? kthread_worker_fn+0x1a0/0x1a0
 [<ffffffff816c25f0>] ? gs_change+0x13/0x13
Code: 89 df e8 94 47 af ff 41 f7 c7 00 02 00 00 75 11 4c 89 ff 57 9d 66 66 90 66 90 e8 cc af a1 ff eb 2a e8 b5 13 a2 ff 4c 89 ff 57 9d <66> 66 90 66 90 eb 19 4c 89 ea 48 c7 c6 97 29 9f 81 4c 89 e7 31 
Call Trace:
 <IRQ>  [<ffffffffa020470d>] ? __free_extent_buffer+0x3d/0x50 [btrfs]
 [<ffffffffa020470d>] ? __free_extent_buffer+0x3d/0x50 [btrfs]
 [<ffffffff816ae4aa>] __slab_free+0x3d/0x266
 [<ffffffff8133ea8c>] ? debug_check_no_obj_freed+0x16c/0x210
 [<ffffffff816b835f>] ? _raw_spin_unlock_irqrestore+0x3f/0x80
 [<ffffffffa020470d>] ? __free_extent_buffer+0x3d/0x50 [btrfs]
 [<ffffffffa020470d>] ? __free_extent_buffer+0x3d/0x50 [btrfs]
 [<ffffffff811a5ab9>] kmem_cache_free+0x249/0x260
 [<ffffffffa020470d>] __free_extent_buffer+0x3d/0x50 [btrfs]
 [<ffffffffa0204730>] btrfs_release_extent_buffer_rcu+0x10/0x20 [btrfs]
 [<ffffffff81114602>] __rcu_process_callbacks+0x1b2/0x4b0
 [<ffffffff8111492f>] rcu_process_callbacks+0x2f/0x270
 [<ffffffff8106a390>] __do_softirq+0xe0/0x3b0
 [<ffffffff81020cc3>] ? native_sched_clock+0x13/0x80
 [<ffffffff816c26ec>] call_softirq+0x1c/0x30
 [<ffffffff8101b325>] do_softirq+0xa5/0xe0
 [<ffffffff8106a9d5>] irq_exit+0xd5/0xe0
 [<ffffffff816c306e>] smp_apic_timer_interrupt+0x6e/0x99
 [<ffffffff816c1cef>] apic_timer_interrupt+0x6f/0x80
 <EOI>  [<ffffffff816b87f0>] ? retint_restore_args+0x13/0x13
 [<ffffffff816ade60>] ? free_debug_processing+0x1ca/0x1fc
 [<ffffffffa02054af>] ? free_extent_state.part.32+0x3f/0x160 [btrfs]
 [<ffffffffa02054af>] ? free_extent_state.part.32+0x3f/0x160 [btrfs]
 [<ffffffff816ae4aa>] __slab_free+0x3d/0x266
 [<ffffffff8133ea8c>] ? debug_check_no_obj_freed+0x16c/0x210
 [<ffffffffa02054af>] ? free_extent_state.part.32+0x3f/0x160 [btrfs]
 [<ffffffffa02054af>] ? free_extent_state.part.32+0x3f/0x160 [btrfs]
 [<ffffffff811a5ab9>] kmem_cache_free+0x249/0x260
 [<ffffffffa0205781>] ? free_extent_state+0x21/0x30 [btrfs]
 [<ffffffffa02054af>] free_extent_state.part.32+0x3f/0x160 [btrfs]
 [<ffffffffa0205781>] free_extent_state+0x21/0x30 [btrfs]
 [<ffffffffa0205998>] merge_state+0x158/0x160 [btrfs]
 [<ffffffffa0205a06>] insert_state+0x66/0xd0 [btrfs]
 [<ffffffff816b7912>] ? _raw_spin_lock+0x72/0x80
 [<ffffffffa020601b>] __set_extent_bit+0x3eb/0x440 [btrfs]
 [<ffffffffa02065c3>] set_extent_bit+0x23/0x30 [btrfs]
 [<ffffffffa0206980>] set_extent_dirty+0x20/0x30 [btrfs]
 [<ffffffffa01df4ae>] ? btrfs_set_buffer_uptodate+0xe/0x10 [btrfs]
 [<ffffffffa01d34ec>] btrfs_init_new_buffer+0xdc/0x160 [btrfs]
 [<ffffffffa01d3705>] btrfs_alloc_free_block+0x195/0x380 [btrfs]
 [<ffffffffa01bf914>] __btrfs_cow_block+0x134/0x510 [btrfs]
 [<ffffffffa01bfde7>] btrfs_cow_block+0xf7/0x2e0 [btrfs]
 [<ffffffffa01c3f07>] btrfs_search_slot+0x3e7/0x8f0 [btrfs]
 [<ffffffffa01c8d5b>] lookup_inline_extent_backref+0x8b/0x490 [btrfs]
 [<ffffffffa01be9ca>] ? btrfs_alloc_path+0x1a/0x20 [btrfs]
 [<ffffffffa01cb7fd>] __btrfs_free_extent+0xbd/0x7b0 [btrfs]
 [<ffffffffa01d1185>] run_clustered_refs+0x315/0xa40 [btrfs]
 [<ffffffffa0229b48>] ? find_ref_head+0xc8/0xf0 [btrfs]
 [<ffffffffa01d1a27>] btrfs_run_delayed_refs+0x177/0x4e0 [btrfs]
 [<ffffffff810c96cf>] ? lock_release_holdtime.part.27+0xf/0x180
 [<ffffffff816b83cb>] ? _raw_spin_unlock+0x2b/0x50
 [<ffffffffa01cab11>] ? block_rsv_release_bytes+0x121/0x240 [btrfs]
 [<ffffffffa01e424f>] __btrfs_end_transaction+0x9f/0x350 [btrfs]
 [<ffffffffa01e4575>] btrfs_end_transaction+0x15/0x20 [btrfs]
 [<ffffffffa01ea195>] btrfs_finish_ordered_io+0x185/0x3e0 [btrfs]
 [<ffffffffa01ea43c>] btrfs_writepage_end_io_hook+0x4c/0x170 [btrfs]
 [<ffffffffa0208545>] end_extent_writepage+0x65/0x110 [btrfs]
 [<ffffffffa0208633>] end_bio_extent_writepage+0x43/0xa0 [btrfs]
 [<ffffffff811f85cd>] bio_endio+0x1d/0x40
 [<ffffffffa01db581>] end_workqueue_fn+0x41/0x50 [btrfs]
 [<ffffffffa0215d19>] worker_loop+0x149/0x5d0 [btrfs]
 [<ffffffffa0215bd0>] ? btrfs_queue_worker+0x310/0x310 [btrfs]
 [<ffffffff8108b0b7>] kthread+0xb7/0xc0
 [<ffffffff816c25f4>] kernel_thread_helper+0x4/0x10
 [<ffffffff816b87f0>] ? retint_restore_args+0x13/0x13
 [<ffffffff8108b000>] ? kthread_worker_fn+0x1a0/0x1a0
 [<ffffffff816c25f0>] ? gs_change+0x13/0x13

Comment 1 J Chapin 2012-06-18 14:41:50 UTC

3.4.0-1.fc17.x86_64 #1 SMP Sun Jun 3 06:35:17 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux is also showing this issue.

Comment 2 Justin M. Forbes 2012-12-07 16:39:30 UTC

Is this still happening with 3.6.9?