11929 – CIFS error results in a kernel oops from cifs_mount

Bug 11929 - CIFS error results in a kernel oops from cifs_mount

Summary: CIFS error results in a kernel oops from cifs_mount

Status:	RESOLVED PATCH_ALREADY_AVAILABLE

Alias:	None

Product:	File System
Classification:	Unclassified
Component:	CIFS (show other bugs)
Hardware:	All Linux

Importance:	P1 normal
Assignee:	Steve French

URL:
Keywords:

Depends on:
Blocks:

Reported:	2008-10-31 18:10 UTC by Brandon Ehle
Modified:	2009-02-18 14:17 UTC (History)
CC List:	2 users (show)

See Also:
Kernel Version:	2.6.27
Subsystem:
Regression:	---
Bisected commit-id:

Attachments
Add an attachment (proposed patch, testcase, etc.)

Description Brandon Ehle 2008-10-31 18:10:51 UTC

Distribution: Debian/testing
Hardware Environment: Intel(R) Pentium(R) 4 CPU 2.80GHz
Steps to reproduce: Unknown (low reproduction rate)
Problem Description: Kernel oops on boot in cifs_mount


kern.log from boot earlier that day:


Oct 31 10:15:56 kernel: e1000e: Intel(R) PRO/1000 Network Driver - 0.3.3.3-k6
Oct 31 10:15:56 kernel: e1000e: Copyright (c) 1999-2008 Intel Corporation.
Oct 31 10:15:56 kernel: e1000e 0000:01:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
Oct 31 10:15:56 kernel: e1000e 0000:01:00.0: setting latency timer to 64

[...snip...]

Oct 31 10:15:56 meowmix kernel: NET: Registered protocol family 10
Oct 31 10:15:56 meowmix kernel: lo: Disabled Privacy Extensions
Oct 31 10:15:56 meowmix kernel: ADDRCONF(NETDEV_UP): eth0: link is not ready
Oct 31 10:15:56 meowmix kernel: 0000:01:00.0: eth0: Link is Up 1000 Mbps Full Duplex, Flow Control: RX/TX
Oct 31 10:15:56 meowmix kernel: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Oct 31 10:15:56 meowmix kernel: lsb_release used greatest stack depth: 356 bytes left
Oct 31 10:15:56 meowmix kernel: eth0: no IPv6 routers present
Oct 31 10:15:56 meowmix kernel:  CIFS VFS: Error -104 sending data on socket to server
Oct 31 10:15:56 meowmix kernel: BUG: unable to handle kernel NULL pointer dereference at 00000518
Oct 31 10:15:56 meowmix kernel: IP: [<c0151c35>] __lock_acquire+0x5d/0xf79
Oct 31 10:15:56 meowmix kernel: *pde = 00000000
Oct 31 10:15:56 meowmix kernel: Oops: 0000 [#1] PREEMPT SMP
Oct 31 10:15:56 meowmix kernel: Modules linked in: ipv6 dm_snapshot dm_mirror dm_log dm_mod it87 hwmon_vid sbp2 psmouse ide_disk ide_cd_mod cx88_dvb cx88_vp3054
_i2c mt352 s5h1409 dvb_pll s5h1411 or51132 videobuf_dvb nxt200x isl6421 zl10353 cx24123 lgdt330x dvb_core cx22702 tuner tea5767 tda8290 tda18271 tda827x tuner_x
c2028 xc5000 tda9887 tuner_simple tuner_types mt20xx snd_intel8x0 tea5761 snd_ac97_codec v4l2_common ac97_bus snd_pcm_oss cx8802 snd_mixer_oss cx88xx videodev v
4l1_compat snd_pcm ir_common snd_timer i2c_algo_bit pcspkr tveeprom i2c_i801 rtc_cmos btcx_risc snd videobuf_dma_sg videobuf_core i2c_core soundcore iTCO_wdt sn
d_page_alloc intel_agp agpgart button joydev evdev usb_storage sg usbhid hid ff_memless sr_mod cdrom sd_mod ide_pci_generic piix ahci ide_core ata_generic ohci1
394 ieee1394 floppy firewire_ohci firewire_core pata_acpi ata_piix r8169 libata scsi_mod dock ehci_hcd uhci_hcd e1000e usbcore thermal processor fan thermal_sys
 hwmon
Oct 31 10:15:56 meowmix kernel:
Oct 31 10:15:56 meowmix kernel: Pid: 2973, comm: mount.cifs Not tainted (2.6.27 #50)
Oct 31 10:15:56 meowmix kernel: EIP: 0060:[<c0151c35>] EFLAGS: 00010046 CPU: 0
Oct 31 10:15:56 meowmix kernel: EIP is at __lock_acquire+0x5d/0xf79
Oct 31 10:15:56 meowmix kernel: EAX: 00000002 EBX: 00000046 ECX: 00000514 EDX: 00000000
Oct 31 10:15:56 meowmix kernel: ESI: 00000002 EDI: 00000001 EBP: c3179d04 ESP: c3179c9c
Oct 31 10:15:56 meowmix kernel:  DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
Oct 31 10:15:56 meowmix kernel: Process mount.cifs (pid: 2973, ti=c3179000 task=c3068000 task.ti=c3179000)
Oct 31 10:15:56 meowmix kernel: Stack: c087c080 00000009 1417a047 00000047 00000000 c09d541c c3068000 00000000
Oct 31 10:15:56 meowmix kernel:        00000514 c3068000 0000000e 00000046 c3179cd8 c014f09c 906a8245 c3179ce0
Oct 31 10:15:56 meowmix kernel:        c014f12a c3068000 0000000e 00000046 c3179cf8 c014f09c 906a8560 00000046
Oct 31 10:15:56 meowmix kernel: Call Trace:
Oct 31 10:15:56 meowmix kernel:  [<c014f09c>] ? trace_hardirqs_off_caller+0x15/0x98
Oct 31 10:15:56 meowmix kernel:  [<c014f12a>] ? trace_hardirqs_off+0xb/0xd
Oct 31 10:15:56 meowmix kernel:  [<c014f09c>] ? trace_hardirqs_off_caller+0x15/0x98
Oct 31 10:15:56 meowmix kernel:  [<c0152bc2>] ? lock_acquire+0x71/0x94
Oct 31 10:15:56 meowmix kernel:  [<c013ae4a>] ? force_sig_info+0x25/0xbd
Oct 31 10:15:56 meowmix kernel:  [<c063d235>] ? _spin_lock_irqsave+0x61/0x8e
Oct 31 10:15:56 meowmix kernel:  [<c013ae4a>] ? force_sig_info+0x25/0xbd
Oct 31 10:15:56 meowmix kernel:  [<c013ae4a>] ? force_sig_info+0x25/0xbd
Oct 31 10:15:56 meowmix kernel:  [<c013aef6>] ? force_sig+0x14/0x16
Oct 31 10:15:56 meowmix kernel:  [<c0302f66>] ? cifs_mount+0x991/0x2358
Oct 31 10:15:56 meowmix kernel:  [<c014f09c>] ? trace_hardirqs_off_caller+0x15/0x98
Oct 31 10:15:56 meowmix kernel:  [<c0151982>] ? trace_hardirqs_on+0xb/0xd
Oct 31 10:15:56 meowmix kernel:  [<c015193e>] ? trace_hardirqs_on_caller+0x10a/0x143
Oct 31 10:15:56 meowmix kernel:  [<c02f6d68>] ? cifs_get_sb+0x89/0x1b1
Oct 31 10:15:56 meowmix kernel:  [<c01a09fd>] ? vfs_kern_mount+0x5e/0x11c
Oct 31 10:15:56 meowmix kernel:  [<c01a0b0f>] ? do_kern_mount+0x38/0xc2
Oct 31 10:15:56 meowmix kernel:  [<c01b701b>] ? do_new_mount+0x5e/0x7c
Oct 31 10:15:56 meowmix kernel:  [<c01b7540>] ? do_mount+0x1ce/0x1e4
Oct 31 10:15:56 meowmix kernel:  [<c0103f16>] ? restore_nocheck_notrace+0x0/0xe
Oct 31 10:15:56 meowmix kernel:  [<c051332f>] ? _raw_spin_trylock+0xf/0x31
Oct 31 10:15:56 meowmix kernel:  [<c01b75db>] ? sys_mount+0x85/0xba
Oct 31 10:15:56 meowmix kernel:  [<c0103e2f>] ? sysenter_do_call+0x12/0x43
Oct 31 10:15:56 meowmix kernel:  =======================
Oct 31 10:15:56 meowmix kernel: Code: 2b 01 00 00 9c 58 90 8d b4 26 00 00 00 00 f6 c4 02 0f 85 13 03 00 00 83 fa 07 0f 87 51 03 00 00 85 d2 0f 85 11 01 00 00 8b
 4d b8 <8b> 59 04 85 db 0f 84 03 01 00 00 8b 7d bc 8b bf b8 04 00 00 89
Oct 31 10:15:56 meowmix kernel: EIP: [<c0151c35>] __lock_acquire+0x5d/0xf79 SS:ESP 0068:c3179c9c
Oct 31 10:15:56 meowmix kernel: ---[ end trace f3f72a65f106052a ]---
Oct 31 10:15:56 meowmix kernel: note: mount.cifs[2973] exited with preempt_count 2
Oct 31 10:15:56 meowmix kernel: BUG: unable to handle kernel NULL pointer dereference at 00000504
Oct 31 10:15:56 meowmix kernel: IP: [<c0119718>] __ticket_spin_trylock+0x6/0x20
Oct 31 10:15:56 meowmix kernel: *pde = 00000000
Oct 31 10:15:56 meowmix kernel: Oops: 0000 [#2] PREEMPT SMP
Oct 31 10:15:56 meowmix kernel: Modules linked in: ipv6 dm_snapshot dm_mirror dm_log dm_mod it87 hwmon_vid sbp2 psmouse ide_disk ide_cd_mod cx88_dvb cx88_vp3054
_i2c mt352 s5h1409 dvb_pll s5h1411 or51132 videobuf_dvb nxt200x isl6421 zl10353 cx24123 lgdt330x dvb_core cx22702 tuner tea5767 tda8290 tda18271 tda827x tuner_x
c2028 xc5000 tda9887 tuner_simple tuner_types mt20xx snd_intel8x0 tea5761 snd_ac97_codec v4l2_common ac97_bus snd_pcm_oss cx8802 snd_mixer_oss cx88xx videodev v
4l1_compat snd_pcm ir_common snd_timer i2c_algo_bit pcspkr tveeprom i2c_i801 rtc_cmos btcx_risc snd videobuf_dma_sg videobuf_core i2c_core soundcore iTCO_wdt sn
d_page_alloc intel_agp agpgart button joydev evdev usb_storage sg usbhid hid ff_memless sr_mod cdrom sd_mod ide_pci_generic piix ahci ide_core ata_generic ohci1
394 ieee1394 floppy firewire_ohci firewire_core pata_acpi ata_piix r8169 libata scsi_mod dock ehci_hcd uhci_hcd e1000e usbcore thermal processor fan thermal_sys
 hwmon
Oct 31 10:15:56 meowmix kernel:
Oct 31 10:15:56 meowmix kernel: Pid: 2975, comm: mount.cifs Tainted: G      D   (2.6.27 #50)
Oct 31 10:15:56 meowmix kernel: EIP: 0060:[<c0119718>] EFLAGS: 00010096 CPU: 0
Oct 31 10:15:56 meowmix kernel: EIP is at __ticket_spin_trylock+0x6/0x20
Oct 31 10:15:56 meowmix kernel: EAX: 00000504 EBX: 00000504 ECX: 00000000 EDX: 00000000
Oct 31 10:15:56 meowmix kernel: ESI: 00000504 EDI: 00000286 EBP: f66e4d10 ESP: f66e4d0c
Oct 31 10:15:56 meowmix kernel:  DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
Oct 31 10:15:56 meowmix kernel: Process mount.cifs (pid: 2975, ti=f66e4000 task=f67b6680 task.ti=f66e4000)
Oct 31 10:15:56 meowmix kernel: Stack: 00000514 f66e4d28 c051332f 00000000 c013ae4a 00000514 00000504 f66e4d4c
Oct 31 10:15:56 meowmix kernel:        c063d23c 00000000 00000002 00000000 c013ae4a c31e8b00 f6bc3d80 00000009
Oct 31 10:15:56 meowmix kernel:        f66e4d78 c013ae4a c0dd4810 00000000 00000001 fffffffe c326b6c0 f66e4d80
Oct 31 10:15:56 meowmix kernel: Call Trace:
Oct 31 10:15:56 meowmix kernel:  [<c051332f>] ? _raw_spin_trylock+0xf/0x31
Oct 31 10:15:56 meowmix kernel:  [<c013ae4a>] ? force_sig_info+0x25/0xbd
Oct 31 10:15:56 meowmix kernel:  [<c063d23c>] ? _spin_lock_irqsave+0x68/0x8e
Oct 31 10:15:56 meowmix kernel:  [<c013ae4a>] ? force_sig_info+0x25/0xbd
Oct 31 10:15:56 meowmix kernel:  [<c013ae4a>] ? force_sig_info+0x25/0xbd
Oct 31 10:15:56 meowmix kernel:  [<c013aef6>] ? force_sig+0x14/0x16
Oct 31 10:15:56 meowmix kernel:  [<c03034da>] ? cifs_mount+0xf05/0x2358
Oct 31 10:15:56 meowmix kernel:  [<c063fb55>] ? do_page_fault+0x1b5/0x970
Oct 31 10:15:56 meowmix kernel:  [<c015184a>] ? trace_hardirqs_on_caller+0x16/0x143
Oct 31 10:15:56 meowmix kernel:  [<c02f6d68>] ? cifs_get_sb+0x89/0x1b1
Oct 31 10:15:56 meowmix kernel:  [<c01a09fd>] ? vfs_kern_mount+0x5e/0x11c
Oct 31 10:15:56 meowmix kernel:  [<c01a0b0f>] ? do_kern_mount+0x38/0xc2
Oct 31 10:15:56 meowmix kernel:  [<c01b701b>] ? do_new_mount+0x5e/0x7c
Oct 31 10:15:56 meowmix kernel:  [<c01b7540>] ? do_mount+0x1ce/0x1e4
Oct 31 10:15:56 meowmix kernel:  [<c0103f16>] ? restore_nocheck_notrace+0x0/0xe
Oct 31 10:15:56 meowmix kernel:  [<c051332f>] ? _raw_spin_trylock+0xf/0x31
Oct 31 10:15:56 meowmix kernel:  [<c01b75db>] ? sys_mount+0x85/0xba
Oct 31 10:15:56 meowmix kernel:  [<c0103e2f>] ? sysenter_do_call+0x12/0x43
Oct 31 10:15:56 meowmix kernel:  =======================
Oct 31 10:15:56 meowmix kernel: Code: 00 83 e8 01 0f 9f c0 0f b6 c0 5d c3 55 89 e5 ba 00 01 00 00 f0 66 0f c1 10 38 f2 74 06 f3 90 8a 10 eb f6 5d c3 55 89 e5 53
 89 c3 <66> 8b 03 38 e0 75 0a 66 89 c1 fe c5 f0 66 0f b1 0b 0f 94 c1 0f
Oct 31 10:15:56 meowmix kernel: EIP: [<c0119718>] __ticket_spin_trylock+0x6/0x20 SS:ESP 0068:f66e4d0c
Oct 31 10:15:56 meowmix kernel: ---[ end trace f3f72a65f106052a ]---
Oct 31 10:15:56 meowmix kernel: note: mount.cifs[2975] exited with preempt_count 2



Some point after that I began receiving an endless number of these in the dmesg output:



BUG: soft lockup - CPU#1 stuck for 61s! [kstop1:20486]
Modules linked in: binfmt_misc ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_conntrack ip_tables x_tables i915 drm rfcomm l2cap bluetooth tun ppdev par
port_pc lp parport ac battery speedstep_lib cpufreq_userspace cpufreq_stats cpufreq_powersave cpufreq_ondemand freq_table cpufreq_conservative ipv6 dm_snapshot
dm_mirror dm_log dm_mod it87 hwmon_vid sbp2 psmouse ide_disk ide_cd_mod cx88_dvb cx88_vp3054_i2c mt352 s5h1409 dvb_pll s5h1411 or51132 videobuf_dvb nxt200x isl6
421 zl10353 cx24123 lgdt330x dvb_core cx22702 tuner tea5767 tda8290 tda18271 tda827x tuner_xc2028 xc5000 tda9887 tuner_simple tuner_types mt20xx snd_intel8x0 te
a5761 snd_ac97_codec v4l2_common ac97_bus snd_pcm_oss cx8802 snd_mixer_oss cx88xx videodev v4l1_compat snd_pcm ir_common snd_timer i2c_algo_bit pcspkr tveeprom
i2c_i801 rtc_cmos btcx_risc snd videobuf_dma_sg videobuf_core i2c_core soundcore iTCO_wdt snd_page_alloc intel_agp agpgart button joydev evdev usb_storage sg us
bhid hid ff_memless sr_mod cdrom sd_mod ide_pci_generic piix ahci ide_core ata_generic ohci1394 ieee1394 floppy firewire_ohci firewire_core pata_acpi ata_piix r
8169 libata scsi_mod dock ehci_hcd uhci_hcd e1000e usbcore thermal processor fan thermal_sys hwmon
irq event stamp: 0
hardirqs last  enabled at (0): [<00000000>] 0x0
hardirqs last disabled at (0): [<c012ca7b>] copy_process+0x4e8/0x11d3
softirqs last  enabled at (0): [<c012ca99>] copy_process+0x506/0x11d3
softirqs last disabled at (0): [<00000000>] 0x0

Pid: 20486, comm: kstop1 Tainted: G      D   (2.6.27 #50)
EIP: 0060:[<c015fc6d>] EFLAGS: 00000246 CPU: 1
EIP is at stop_cpu+0x67/0xaa
EAX: 00000001 EBX: f7866f68 ECX: fffffffc EDX: c21f2900
ESI: 00000001 EDI: f7866f68 EBP: e7b24fd0 ESP: e7b24fc4
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b6db7000 CR3: 009a2000 CR4: 000006d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<c015fc06>] ? stop_cpu+0x0/0xaa
 [<c0141826>] kthread+0x41/0x6b
 [<c01417e5>] ? kthread+0x0/0x6b
 [<c0104b6b>] kernel_thread_helper+0x7/0x10
 =======================

Comment 1 Shirish Pargaonkar 2009-02-17 02:18:18 UTC

Is this recreatable?  What are the steps that lead up to this oops?

Comment 2 Jeff Layton 2009-02-17 04:23:06 UTC

This may be due to the mount/umount races that were fixed last fall. Those *should* be fixed now in both >= 2.6.28 and in recent 2.6.27 stable kernels. Can you let us know whether you're still seeing this on more recent kernels?

Comment 3 Steve French 2009-02-17 13:45:12 UTC

I agree with Jeff - any lock related conflicts in this area were likely to have been cleared by the mount fixes which went into mainline and also into 2.6.27.9 (or later) stable kernel series.

Any occurrences at that level or later (2.6.27.9 or later)?

Comment 4 Brandon Ehle 2009-02-17 14:52:09 UTC

The machine that I reproduced this on a couple times is now on 2.6.29-rc5 and I haven't seen the problem, but I haven't been using CIFS as much lately.

Comment 5 Steve French 2009-02-18 14:17:10 UTC

OK - please reopen this (or a new defect) if you see anything similar in the future.  The locking in this area is much better and it is very likely the problem was resolved by that patch series.

Note You need to log in before you can comment on or make changes to this bug.