Bug 797306

Summary: [abrt] kernel: WARNING: at fs/inode.c:346 inc_nlink+0x36/0x50()
Product: [Fedora] Fedora Reporter: Tom <thomasbelvin>
Component: kernelAssignee: Zach Brown <zab>
Status: CLOSED INSUFFICIENT_DATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 19CC: AppelonD, dzansolov, gansalmon, itamar, jforbes, jonathan, josef, kernel-maint, madhu.chinakonda, mevsspam, pal666, sweil
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Unspecified   
Whiteboard: abrt_hash:bd6d66a4e824fd66f662bf021f569eadf62aae4d
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-04-12 15:00:18 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Tom 2012-02-24 21:37:11 UTC
libreport version: 2.0.8
abrt_version:   2.0.7
cmdline:        BOOT_IMAGE=/vmlinuz-3.3.0-0.rc4.git0.1.fc18.x86_64 root=/dev/mapper/vg_hostname-lv_root ro rd.lvm.lv=vg_hostname/lv_swap rd.md=0 rd.dm=0 rd.lvm.lv=vg_hostname/lv_root KEYTABLE=us quiet rd.luks.uuid=luks-3c2245cb-b999-4cec-a064-5b85d35b9f41 SYSFONT=latarcyrheb-sun16 rhgb LANG=en_US.UTF-8
kernel:         3.3.0-0.rc4.git0.1.fc18.x86_64
reason:         WARNING: at fs/inode.c:346 inc_nlink+0x36/0x50()
time:           Fri 24 Feb 2012 04:30:16 PM EST

backtrace:
:WARNING: at fs/inode.c:346 inc_nlink+0x36/0x50()
:Hardware name: Aspire 5552G
:Modules linked in: btrfs libcrc32c zlib_deflate xts gf128mul dm_crypt video wmi radeon i2c_algo_bit drm_kms_helper ttm drm i2c_core
:Pid: 430, comm: mount Not tainted 3.3.0-0.rc4.git0.1.fc18.x86_64 #1
:Call Trace:
: [<ffffffff8105556f>] warn_slowpath_common+0x7f/0xc0
: [<ffffffff810555ca>] warn_slowpath_null+0x1a/0x20
: [<ffffffff81194086>] inc_nlink+0x36/0x50
: [<ffffffffa01c4108>] link_to_fixup_dir+0xb8/0xe0 [btrfs]
: [<ffffffffa01c6481>] replay_one_buffer+0x1b1/0x340 [btrfs]
: [<ffffffffa01c3c12>] walk_down_log_tree+0x1e2/0x3a0 [btrfs]
: [<ffffffffa01c3e8d>] walk_log_tree+0xbd/0x1d0 [btrfs]
: [<ffffffffa01c7791>] btrfs_recover_log_trees+0x211/0x2f0 [btrfs]
: [<ffffffffa01c62d0>] ? fixup_inode_link_counts+0x150/0x150 [btrfs]
: [<ffffffffa0190538>] open_ctree+0x1438/0x18d0 [btrfs]
: [<ffffffff812a94ba>] ? disk_name+0xba/0xc0
: [<ffffffffa016f0c2>] btrfs_mount+0x5c2/0x6b0 [btrfs]
: [<ffffffff8113c4ab>] ? pcpu_next_pop+0x4b/0x60
: [<ffffffff8113d9ba>] ? pcpu_alloc+0x8ba/0x9c0
: [<ffffffff812bbc68>] ? ida_get_new_above+0x218/0x2a0
: [<ffffffff8117f853>] mount_fs+0x43/0x1b0
: [<ffffffff8113dad0>] ? __alloc_percpu+0x10/0x20
: [<ffffffff81198977>] vfs_kern_mount+0x67/0xf0
: [<ffffffff81199494>] do_kern_mount+0x54/0x110
: [<ffffffff8119acfa>] do_mount+0x26a/0x840
: [<ffffffff8113806b>] ? strndup_user+0x5b/0x80
: [<ffffffff8119b40d>] sys_mount+0x8d/0xe0
: [<ffffffff815f0a29>] system_call_fastpath+0x16/0x1b

smolt_data:
:
:
:General
:=================================
:UUID: 8c9683d5-583e-410d-aeee-e9de96d330d1
:OS: Fedora release 18 (Rawhide)
:Default run level: Unknown
:Language: en_US.UTF-8
:Platform: x86_64
:BogoMIPS: 5984.73
:CPU Vendor: AuthenticAMD
:CPU Model: AMD Phenom(tm) II N660 Dual-Core Processor
:CPU Stepping: 3
:CPU Family: 16
:CPU Model Num: 6
:Number of CPUs: 2
:CPU Speed: 3000
:System Memory: 3951
:System Swap: 5983
:Vendor: Acer
:System: Aspire 5552G V2.14
:Form factor: Notebook
:Kernel: 3.3.0-0.rc4.git0.1.fc18.x86_64
:SELinux Enabled: 1
:SELinux Policy: targeted
:SELinux Enforce: Permissive
:MythTV Remote: Unknown
:MythTV Role: Unknown
:MythTV Theme: Unknown
:MythTV Plugin: 
:MythTV Tuner: -1
:
:
:Devices
:=================================
:(4098:17297:4133:1161) pci, ahci, STORAGE, SB7x0/SB8x0/SB9x0 SATA Controller [AHCI mode]
:(4098:17302:4133:1161) pci, ehci_hcd, USB, SB7x0/SB8x0/SB9x0 USB EHCI Controller
:(5772:46:6706:8969) pci, ath9k, NETWORK, AR9287 Wireless Network Adapter (PCI-Express)
:(4130:38401:4133:1161) pci, None, HOST/PCI, RS880 Host Bridge
:(4130:4612:0:0) pci, None, HOST/PCI, Family 10h Processor Link Control
:(5348:5778:4133:1161) pci, tg3, ETHERNET, NetLink BCM57780 Gigabit Ethernet PCIe
:(4130:4608:0:0) pci, None, HOST/PCI, Family 10h Processor HyperTransport Configuration
:(4130:4611:0:0) pci, k10temp, HOST/PCI, Family 10h Processor Miscellaneous Control
:(4130:4610:0:0) pci, None, HOST/PCI, Family 10h Processor DRAM Controller
:(4130:4609:0:0) pci, None, HOST/PCI, Family 10h Processor Address Map
:(4130:38403:4133:1161) pci, pcieport, PCI/PCI, RS780 PCI to PCI bridge (ext gfx port 0)
:(4098:17285:4133:1161) pci, piix4_smbus, SERIAL, SBx00 SMBus Controller
:(4098:17309:4133:1161) pci, None, PCI/ISA, SB7x0/SB8x0/SB9x0 LPC host controller
:(4098:17283:4133:1161) pci, snd_hda_intel, MULTIMEDIA, SBx00 Azalia (Intel HDA)
:(4098:17305:4133:1161) pci, ohci_hcd, USB, SB7x0/SB8x0/SB9x0 USB OHCI2 Controller
:(4098:17284:0:0) pci, None, PCI/PCI, SBx00 PCI to PCI Bridge
:(4098:43664:4133:1161) pci, snd_hda_intel, MULTIMEDIA, N/A
:(4098:26433:4133:1161) pci, radeon, VIDEO, NI Whistler [AMD Radeon HD 6600M Series]
:(4098:17303:4133:1161) pci, ohci_hcd, USB, SB7x0/SB8x0/SB9x0 USB OHCI0 Controller
:(4098:17302:4133:1161) pci, ehci_hcd, USB, SB7x0/SB8x0/SB9x0 USB EHCI Controller
:(4098:17303:4133:1161) pci, ohci_hcd, USB, SB7x0/SB8x0/SB9x0 USB OHCI0 Controller
:(4130:38404:4133:1161) pci, pcieport, PCI/PCI, RS780 PCI to PCI bridge (PCIE port 0)
:(4130:38405:4133:1161) pci, pcieport, PCI/PCI, RS780 PCI to PCI bridge (PCIE port 1)
:
:
:Filesystem Information
:=================================
:device mtpt type bsize frsize blocks bfree bavail file ffree favail
:-------------------------------------------------------------------
:/dev/mapper/vg_hostname-lv_root / btrfs 4096 4096 13107200 7763659 7055519 0 0 0
:/dev/sda2 /boot ext4 1024 1024 508745 407034 381434 128016 127786 127786
:/dev/mapper/vg_hostname-lv_home /home btrfs 4096 4096 58474496 57393676 55119496 0 0 0
:

Comment 1 Josh Boyer 2012-02-24 21:54:26 UTC
This is:

void inc_nlink(struct inode *inode)
{
        if (WARN_ON(inode->i_nlink == 0))
                atomic_long_dec(&inode->i_sb->s_remove_count);


Seems the fixup dir is created and the inode is supposed to have it's nlink incremented.  However, with commit 7ada4db8 we do the WARN_ON above.

Josef, should btrfs be using set_nlink(inode, 1); in btrfs/tree-log.c:link_to_fixup_dir instead, or is the 0 i_nlink normal for this kind of recovery operation?

Comment 2 Josh Boyer 2012-02-24 21:56:00 UTC
(In reply to comment #1)
> This is:
> 
> void inc_nlink(struct inode *inode)
> {
>         if (WARN_ON(inode->i_nlink == 0))
>                 atomic_long_dec(&inode->i_sb->s_remove_count);
> 
> 
> Seems the fixup dir is created and the inode is supposed to have it's nlink
> incremented.  However, with commit 7ada4db8 we do the WARN_ON above.
> 
> Josef, should btrfs be using set_nlink(inode, 1); in
> btrfs/tree-log.c:link_to_fixup_dir instead, or is the 0 i_nlink normal for this
> kind of recovery operation?

Er, I meant "is the 0 i_nlink actually _abnormal_ for this kind of recovery operation".

Comment 3 Dennis Appelon Nielsen 2012-05-15 20:52:08 UTC
Cheese webcam program, causes this problem, and I see the same problem when I try to do a Google Plus Hangout, with dual monitor setup.

Package: kernel
OS Release: Fedora release 16 (Verne)

Comment 4 Dennis Appelon Nielsen 2012-07-29 16:45:30 UTC
Jul 29 18:30:22 laptop kernel: [  304.100251] ------------[ cut here ]------------
Jul 29 18:30:22 laptop kernel: [  304.100261] WARNING: at kernel/watchdog.c:241 watchdog_overflow_callback+0x9a/0xc0()
Jul 29 18:30:22 laptop kernel: [  304.100264] Hardware name: 4391DL3
Jul 29 18:30:22 laptop kernel: [  304.100266] Watchdog detected hard LOCKUP on cpu 5
Jul 29 18:30:22 laptop kernel: [  304.100268] Modules linked in: fuse be2iscsi iscsi_boot_sysfs bnx2i cnic uio cxgb4i cxgb4 cxgb3i cxgb3 mdio libcxgbi ib_iser lockd sunrpc tpm_bios rdma_cm ib_addr iw_cm ib_cm ib_sa ib_mad ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi rfcomm bnep ebtable_nat ebtables nf_conntrack_ipv4 nf_defrag_ipv4 ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 xt_state nf_conntrack ip6table_filter ip6_tables snd_hda_codec_hdmi binfmt_misc arc4 snd_hda_codec_conexant coretemp microcode i7core_edac edac_core uvcvideo videobuf2_vmalloc i2c_i801 videobuf2_memops videobuf2_core videodev media qcserial usb_wwan wacom snd_usb_audio snd_usbmidi_lib snd_rawmidi snd_seq_device usblp btusb bluetooth vhost_net tun macvtap macvlan kvm_intel kvm iTCO_wdt iTCO_vendor_support uinput iwlwifi mac80211 cfg80211 snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_page_alloc e1000e snd_timer thinkpad_acpi snd soundcore rfkill xts gf128mul dm_crypt btrfs libcrc32c zlib_deflate crc32c_intel firewire_ohci f
Jul 29 18:30:22 laptop kernel: irewire_core sdhci_pci crc_itu_t sdhci mmc_core nouveau mxm_wmi wmi video i2c_algo_bit drm_kms_helper ttm drm i2c_core [last unloaded: scsi_wait_scan]
Jul 29 18:30:22 laptop kernel: [  304.100359] Pid: 0, comm: swapper/5 Not tainted 3.4.6-2.fc17.x86_64 #1
Jul 29 18:30:22 laptop kernel: [  304.100362] Call Trace:
Jul 29 18:30:22 laptop kernel: [  304.100364]  <NMI>  [<ffffffff81056ecf>] warn_slowpath_common+0x7f/0xc0
Jul 29 18:30:22 laptop kernel: [  304.100374]  [<ffffffff81056fc6>] warn_slowpath_fmt+0x46/0x50
Jul 29 18:30:22 laptop kernel: [  304.100379]  [<ffffffff810df580>] ? touch_nmi_watchdog+0x80/0x80
Jul 29 18:30:22 laptop kernel: [  304.100383]  [<ffffffff810df61a>] watchdog_overflow_callback+0x9a/0xc0
Jul 29 18:30:22 laptop kernel: [  304.100388]  [<ffffffff811181ed>] __perf_event_overflow+0x9d/0x230
Jul 29 18:30:22 laptop kernel: [  304.100394]  [<ffffffff81024147>] ? x86_perf_event_set_period+0xd7/0x160
Jul 29 18:30:22 laptop kernel: [  304.100398]  [<ffffffff81118be4>] perf_event_overflow+0x14/0x20
Jul 29 18:30:22 laptop kernel: [  304.100402]  [<ffffffff81029307>] intel_pmu_handle_irq+0x197/0x320
Jul 29 18:30:22 laptop kernel: [  304.100409]  [<ffffffff815f684d>] perf_event_nmi_handler+0x1d/0x20
Jul 29 18:30:22 laptop kernel: [  304.100413]  [<ffffffff815f6029>] nmi_handle.isra.0+0x49/0x80
Jul 29 18:30:22 laptop kernel: [  304.100417]  [<ffffffff815f6148>] do_nmi+0xe8/0x320
Jul 29 18:30:22 laptop kernel: [  304.100421]  [<ffffffff815f567c>] end_repeat_nmi+0x1a/0x1e
Jul 29 18:30:22 laptop kernel: [  304.100428]  [<ffffffff8142cb69>] ? iso_sched_free+0x39/0x40
Jul 29 18:30:22 laptop kernel: [  304.100436]  [<ffffffffa0602c61>] ? uvc_video_decode_start+0x401/0x800 [uvcvideo]
Jul 29 18:30:22 laptop kernel: [  304.100443]  [<ffffffffa0602c61>] ? uvc_video_decode_start+0x401/0x800 [uvcvideo]
Jul 29 18:30:22 laptop kernel: [  304.100450]  [<ffffffffa0602c61>] ? uvc_video_decode_start+0x401/0x800 [uvcvideo]
Jul 29 18:30:22 laptop kernel: [  304.100452]  <<EOE>>  <IRQ>  [<ffffffff8142e68a>] ? ehci_urb_done+0x8a/0xc0
Jul 29 18:30:22 laptop kernel: [  304.100462]  [<ffffffffa05e9494>] ? vb2_buffer_done+0xc4/0xc30 [videobuf2_core]
Jul 29 18:30:22 laptop kernel: [  304.100468]  [<ffffffffa0603db7>] uvc_video_decode_isoc+0x107/0x1b0 [uvcvideo]
Jul 29 18:30:22 laptop kernel: [  304.100475]  [<ffffffffa0604476>] uvc_video_complete+0xd6/0x100 [uvcvideo]
Jul 29 18:30:22 laptop kernel: [  304.100480]  [<ffffffff81417825>] usb_hcd_giveback_urb+0x65/0xf0
Jul 29 18:30:22 laptop kernel: [  304.100484]  [<ffffffff8142e682>] ehci_urb_done+0x82/0xc0
Jul 29 18:30:22 laptop kernel: [  304.100487]  [<ffffffff81431353>] ehci_work+0x993/0xa70
Jul 29 18:30:22 laptop kernel: [  304.100491]  [<ffffffff814316d4>] ehci_irq+0x234/0x460
Jul 29 18:30:22 laptop kernel: [  304.100496]  [<ffffffff812c6ff0>] ? rb_insert_color+0x110/0x150
Jul 29 18:30:22 laptop kernel: [  304.100500]  [<ffffffff812c9704>] ? timerqueue_add+0x74/0xc0
Jul 29 18:30:22 laptop kernel: [  304.100505]  [<ffffffff8107c559>] ? enqueue_hrtimer+0x29/0x90
Jul 29 18:30:22 laptop kernel: [  304.100509]  [<ffffffff8141684c>] usb_hcd_irq+0x3c/0x60
Jul 29 18:30:22 laptop kernel: [  304.100514]  [<ffffffff810e0404>] handle_irq_event_percpu+0x54/0x200
Jul 29 18:30:22 laptop kernel: [  304.100518]  [<ffffffff810e05f1>] handle_irq_event+0x41/0x70
Jul 29 18:30:22 laptop kernel: [  304.100522]  [<ffffffff810e37d9>] handle_fasteoi_irq+0x59/0x100
Jul 29 18:30:22 laptop kernel: [  304.100527]  [<ffffffff8101514f>] handle_irq+0xbf/0x150
Jul 29 18:30:22 laptop kernel: [  304.100531]  [<ffffffff815f8b02>] ? __atomic_notifier_call_chain+0x12/0x20
Jul 29 18:30:22 laptop kernel: [  304.100535]  [<ffffffff815f8b26>] ? atomic_notifier_call_chain+0x16/0x20
Jul 29 18:30:22 laptop kernel: [  304.100539]  [<ffffffff815fe92a>] do_IRQ+0x5a/0xe0
Jul 29 18:30:22 laptop kernel: [  304.100544]  [<ffffffff815f506a>] common_interrupt+0x6a/0x6a
Jul 29 18:30:22 laptop kernel: [  304.100546]  <EOI>  [<ffffffff8131c5fa>] ? intel_idle+0xea/0x150
Jul 29 18:30:22 laptop kernel: [  304.100554]  [<ffffffff8131c5db>] ? intel_idle+0xcb/0x150
Jul 29 18:30:22 laptop kernel: [  304.100560]  [<ffffffff814a6009>] cpuidle_enter+0x19/0x20
Jul 29 18:30:22 laptop kernel: [  304.100564]  [<ffffffff814a6629>] cpuidle_idle_call+0xa9/0x240
Jul 29 18:30:22 laptop kernel: [  304.100568]  [<ffffffff8101c51f>] cpu_idle+0xaf/0x120
Jul 29 18:30:22 laptop kernel: [  304.100573]  [<ffffffff815e3bab>] start_secondary+0x248/0x24a
Jul 29 18:30:22 laptop kernel: [  304.100576] ---[ end trace eea67604a4f72295 ]---

This problem with webcam continues, and it have nothing to do with monitor setup, or flash or nvidia. I really have no idea what is causing it, but I really would like to make use of my webcam with a browser...

Comment 5 Dave Jones 2012-07-30 14:09:05 UTC
that trace has nothing in common with the one this bug is about.

Comment 6 Josef Bacik 2012-11-01 19:57:22 UTC
Sorry it took me so long to get to this, I should check my bugzilla folder more often.  Obviously the warning is no good and we need to fix it, but I think it's a needless warning for our case.  I'm going to try and force this to happen, but I assume that if we unlink a file, fsync it and crash then we can have a file with nlink of 0 in our log.  This all works out ok because we do our orphan processing afterwards and the file will get cleaned up, it just ends up tripping up this code.  I'll try and reproduce and if it is in fact whats happening I'll fix it up and send it to stable.

Comment 7 Fedora End Of Life 2013-04-03 19:48:17 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 19 development cycle.
Changing version to '19'.

(As we did not run this process for some time, it could affect also pre-Fedora 19 development
cycle bugs. We are very sorry. It will help us with cleanup during Fedora 19 End Of Life. Thank you.)

More information and reason for this action is here:
https://fedoraproject.org/wiki/BugZappers/HouseKeeping/Fedora19

Comment 8 Justin M. Forbes 2013-04-05 15:53:47 UTC
Is this still a problem with 3.9 based F19 kernels?

Comment 9 Tom 2013-04-12 08:18:35 UTC
I'm unable to test F19.

Comment 10 Justin M. Forbes 2013-04-12 15:00:18 UTC
Closing insufficient data, please reopen if you can reproduce on F19