2708 – (IRDA) spin_lock already locked in sir_dev.c

Bug 2708 - (IRDA) spin_lock already locked in sir_dev.c

Summary: (IRDA) spin_lock already locked in sir_dev.c

Status:	CLOSED CODE_FIX

Alias:	None

Product:	Drivers
Classification:	Unclassified
Component:	Network (show other bugs)
Hardware:	i386 Linux

Importance:	P2 high
Assignee:	Jeff Garzik

URL:
Keywords:

Depends on:
Blocks:

Reported:	2004-05-14 04:12 UTC by Tom Parker
Modified:	2006-04-15 02:27 UTC (History)
CC List:	3 users (show)

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

Attachments
Add missing spin_unlock (342 bytes, patch) 2004-05-14 09:46 UTC, Domen Puncer Kugler	Details \| Diff
Add an attachment (proposed patch, testcase, etc.)

Description Tom Parker 2004-05-14 04:12:02 UTC

Distribution: debian unstable
Hardware Environment: i686, tekram irda on pl2303 usb serial port
Software Environment: 
irda-utils/unstable uptodate 0.9.16-3
libmultisync-plugin-opie/unstable uptodate 0.82-1
libmultisync-plugin-irmc/unstable uptodate 0.82-1
libmultisync-plugin-backup/unstable uptodate 0.82-1
multisync/unstable uptodate 0.82-1

CONFIG_X86=y
CONFIG_MMU=y
CONFIG_UID16=y
CONFIG_GENERIC_ISA_DMA=y
CONFIG_EXPERIMENTAL=y
CONFIG_CLEAN_COMPILE=y
CONFIG_BROKEN_ON_SMP=y
CONFIG_SWAP=y
CONFIG_SYSVIPC=y
CONFIG_SYSCTL=y
CONFIG_LOG_BUF_SHIFT=14
CONFIG_IKCONFIG=y
CONFIG_IKCONFIG_PROC=y
CONFIG_KALLSYMS=y
CONFIG_FUTEX=y
CONFIG_EPOLL=y
CONFIG_IOSCHED_NOOP=y
CONFIG_IOSCHED_AS=y
CONFIG_IOSCHED_DEADLINE=y
CONFIG_IOSCHED_CFQ=y
CONFIG_MODULES=y
CONFIG_MODULE_UNLOAD=y
CONFIG_MODULE_FORCE_UNLOAD=y
CONFIG_OBSOLETE_MODPARM=y
CONFIG_KMOD=y
CONFIG_X86_PC=y
CONFIG_MPENTIUMIII=y
CONFIG_X86_CMPXCHG=y
CONFIG_X86_XADD=y
CONFIG_X86_L1_CACHE_SHIFT=5
CONFIG_RWSEM_XCHGADD_ALGORITHM=y
CONFIG_X86_WP_WORKS_OK=y
CONFIG_X86_INVLPG=y
CONFIG_X86_BSWAP=y
CONFIG_X86_POPAD_OK=y
CONFIG_X86_GOOD_APIC=y
CONFIG_X86_INTEL_USERCOPY=y
CONFIG_X86_USE_PPRO_CHECKSUM=y
CONFIG_X86_TSC=y
CONFIG_X86_MCE=y
CONFIG_NOHIGHMEM=y
CONFIG_MTRR=y
CONFIG_REGPARM=y
CONFIG_PM=y
CONFIG_PM_DISK=y
CONFIG_PM_DISK_PARTITION="/dev/hda1"
CONFIG_ACPI_BOOT=y
CONFIG_PCI=y
CONFIG_PCI_GOANY=y
CONFIG_PCI_BIOS=y
CONFIG_PCI_DIRECT=y
CONFIG_PCI_MMCONFIG=y
CONFIG_PCI_NAMES=y
CONFIG_BINFMT_ELF=y
CONFIG_BLK_DEV_FD=m
CONFIG_BLK_DEV_LOOP=m
CONFIG_BLK_DEV_NBD=m
CONFIG_IDE=y
CONFIG_BLK_DEV_IDE=y
CONFIG_BLK_DEV_IDEDISK=y
CONFIG_IDEDISK_MULTI_MODE=y
CONFIG_BLK_DEV_IDECD=y
CONFIG_IDE_GENERIC=y
CONFIG_BLK_DEV_IDEPCI=y
CONFIG_IDEPCI_SHARE_IRQ=y
CONFIG_BLK_DEV_GENERIC=y
CONFIG_BLK_DEV_IDEDMA_PCI=y
CONFIG_IDEDMA_PCI_AUTO=y
CONFIG_BLK_DEV_ADMA=y
CONFIG_BLK_DEV_PIIX=y
CONFIG_BLK_DEV_IDEDMA=y
CONFIG_IDEDMA_AUTO=y
CONFIG_SCSI=m
CONFIG_SCSI_PROC_FS=y
CONFIG_BLK_DEV_SD=m
CONFIG_SCSI_REPORT_LUNS=y
CONFIG_SCSI_SPI_ATTRS=m
CONFIG_SCSI_AIC7XXX=m
CONFIG_AIC7XXX_CMDS_PER_DEVICE=32
CONFIG_AIC7XXX_RESET_DELAY_MS=15000
CONFIG_AIC7XXX_DEBUG_MASK=0
CONFIG_SCSI_QLA2XXX=m
CONFIG_I2O=m
CONFIG_I2O_PCI=m
CONFIG_I2O_PROC=m
CONFIG_NET=y
CONFIG_PACKET=y
CONFIG_UNIX=y
CONFIG_INET=y
CONFIG_IP_MULTICAST=y
CONFIG_IP_PNP=y
CONFIG_IP_PNP_DHCP=y
CONFIG_IRDA=m
CONFIG_IRLAN=m
CONFIG_IRCOMM=m
CONFIG_IRDA_ULTRA=y
CONFIG_IRDA_CACHE_LAST_LSAP=y
CONFIG_IRDA_FAST_RR=y
CONFIG_IRDA_DEBUG=y
CONFIG_IRTTY_SIR=m
CONFIG_DONGLE=y
CONFIG_ESI_DONGLE=m
CONFIG_ACTISYS_DONGLE=m
CONFIG_TEKRAM_DONGLE=m
CONFIG_LITELINK_DONGLE=m
CONFIG_MA600_DONGLE=m
CONFIG_GIRBIL_DONGLE=m
CONFIG_MCP2120_DONGLE=m
CONFIG_OLD_BELKIN_DONGLE=m
CONFIG_ACT200L_DONGLE=m
CONFIG_NETDEVICES=y
CONFIG_NET_ETHERNET=y
CONFIG_NET_VENDOR_3COM=y
CONFIG_VORTEX=y
CONFIG_INPUT=y
CONFIG_INPUT_MOUSEDEV=y
CONFIG_INPUT_MOUSEDEV_PSAUX=y
CONFIG_INPUT_MOUSEDEV_SCREEN_X=1024
CONFIG_INPUT_MOUSEDEV_SCREEN_Y=768
CONFIG_SOUND_GAMEPORT=y
CONFIG_SERIO=y
CONFIG_SERIO_I8042=y
CONFIG_INPUT_KEYBOARD=y
CONFIG_KEYBOARD_ATKBD=y
CONFIG_INPUT_MOUSE=y
CONFIG_MOUSE_PS2=y
CONFIG_VT=y
CONFIG_VT_CONSOLE=y
CONFIG_HW_CONSOLE=y
CONFIG_SERIAL_8250=y
CONFIG_SERIAL_8250_NR_UARTS=4
CONFIG_SERIAL_CORE=y
CONFIG_UNIX98_PTYS=y
CONFIG_HW_RANDOM=m
CONFIG_RTC=m
CONFIG_GEN_RTC=m
CONFIG_GEN_RTC_X=y
CONFIG_AGP=y
CONFIG_AGP_INTEL=y
CONFIG_DRM=y
CONFIG_DRM_MGA=y
CONFIG_I2C=m
CONFIG_I2C_CHARDEV=m
CONFIG_I2C_ALGOBIT=m
CONFIG_I2C_I801=m
CONFIG_I2C_ISA=m
CONFIG_I2C_SENSOR=m
CONFIG_SENSORS_ADM1021=m
CONFIG_SENSORS_DS1621=m
CONFIG_SENSORS_FSCHER=m
CONFIG_SENSORS_IT87=m
CONFIG_SENSORS_LM75=m
CONFIG_SENSORS_LM78=m
CONFIG_SENSORS_LM80=m
CONFIG_SENSORS_LM83=m
CONFIG_SENSORS_LM85=m
CONFIG_SENSORS_LM90=m
CONFIG_SENSORS_VIA686A=m
CONFIG_SENSORS_W83781D=m
CONFIG_SENSORS_W83L785TS=m
CONFIG_SENSORS_W83627HF=m
CONFIG_SENSORS_EEPROM=m
CONFIG_VIDEO_DEV=m
CONFIG_VIDEO_BT848=m
CONFIG_VIDEO_TUNER=m
CONFIG_VIDEO_BUF=m
CONFIG_VIDEO_BTCX=m
CONFIG_VIDEO_IR=m
CONFIG_VGA_CONSOLE=y
CONFIG_DUMMY_CONSOLE=y
CONFIG_SOUND=y
CONFIG_SND=m
CONFIG_SND_TIMER=m
CONFIG_SND_PCM=m
CONFIG_SND_HWDEP=m
CONFIG_SND_RAWMIDI=m
CONFIG_SND_OSSEMUL=y
CONFIG_SND_MIXER_OSS=m
CONFIG_SND_PCM_OSS=m
CONFIG_SND_RTCTIMER=m
CONFIG_SND_AC97_CODEC=m
CONFIG_SND_BT87X=m
CONFIG_SND_EMU10K1=m
CONFIG_USB=m
CONFIG_USB_DEVICEFS=y
CONFIG_USB_UHCI_HCD=m
CONFIG_USB_STORAGE=m
CONFIG_USB_SERIAL=m
CONFIG_USB_SERIAL_GENERIC=y
CONFIG_USB_SERIAL_PL2303=m
CONFIG_USB_LED=m
CONFIG_REISERFS_FS=y
CONFIG_ISO9660_FS=m
CONFIG_JOLIET=y
CONFIG_UDF_FS=m
CONFIG_FAT_FS=m
CONFIG_MSDOS_FS=m
CONFIG_VFAT_FS=m
CONFIG_PROC_FS=y
CONFIG_PROC_KCORE=y
CONFIG_SYSFS=y
CONFIG_RAMFS=y
CONFIG_NFS_FS=y
CONFIG_NFS_V3=y
CONFIG_ROOT_NFS=y
CONFIG_LOCKD=y
CONFIG_LOCKD_V4=y
CONFIG_SUNRPC=y
CONFIG_SMB_FS=m
CONFIG_MSDOS_PARTITION=y
CONFIG_NLS=y
CONFIG_NLS_DEFAULT="iso8859-1"
CONFIG_NLS_CODEPAGE_437=y
CONFIG_NLS_ISO8859_1=y
CONFIG_DEBUG_KERNEL=y
CONFIG_EARLY_PRINTK=y
CONFIG_DEBUG_STACKOVERFLOW=y
CONFIG_DEBUG_SLAB=y
CONFIG_MAGIC_SYSRQ=y
CONFIG_DEBUG_SPINLOCK=y
CONFIG_DEBUG_PAGEALLOC=y
CONFIG_DEBUG_INFO=y
CONFIG_DEBUG_SPINLOCK_SLEEP=y
CONFIG_FRAME_POINTER=y
CONFIG_4KSTACKS=y
CONFIG_X86_BIOS_REBOOT=y
CONFIG_X86_STD_RESOURCES=y
CONFIG_PC=y

Problem Description:
unbranded (but apparently tekram) irda device does not work, can see phone in irdadump output, but when you search for devices in multisync you get nasty errors in the kernel log:

May 14 22:42:07 tv kernel: usbcore: registered new driver usbfs
May 14 22:42:07 tv kernel: usbcore: registered new driver hub
May 14 22:42:07 tv kernel: USB Universal Host Controller Interface driver v2.2
May 14 22:42:07 tv kernel: PCI: Found IRQ 11 for device 0000:00:1f.2
May 14 22:42:07 tv kernel: uhci_hcd 0000:00:1f.2: Intel Corp. 82801AA USB
May 14 22:42:07 tv kernel: uhci_hcd 0000:00:1f.2: irq 11, io base 0000ff80
May 14 22:42:07 tv kernel: uhci_hcd 0000:00:1f.2: new USB bus registered, assigned bus number 1
May 14 22:42:07 tv kernel: hub 1-0:1.0: USB hub found
May 14 22:42:07 tv kernel: hub 1-0:1.0: 2 ports detected
May 14 22:42:08 tv kernel: usb 1-1: new full speed USB device using address 2
May 14 22:42:17 tv kernel: drivers/usb/serial/usb-serial.c: USB Serial support registered for Generic
May 14 22:42:17 tv kernel: usbcore: registered new driver usbserial
May 14 22:42:17 tv kernel: drivers/usb/serial/usb-serial.c: USB Serial Driver core v2.0
May 14 22:42:17 tv kernel: drivers/usb/serial/usb-serial.c: USB Serial support registered for PL-2303
May 14 22:42:17 tv kernel: pl2303 1-1:1.0: PL-2303 converter detected
May 14 22:42:17 tv kernel: usb 1-1: PL-2303 converter now attached to ttyUSB0 (or usb/tts/0 for devfs)
May 14 22:42:17 tv kernel: usbcore: registered new driver pl2303
May 14 22:42:17 tv kernel: drivers/usb/serial/pl2303.c: Prolific PL2303 USB to serial adaptor driver v0.10
May 14 22:42:58 tv kernel: NET: Registered protocol family 23
May 14 22:43:00 tv irattach: executing: 'echo tv > /proc/sys/net/irda/devname'
May 14 22:43:00 tv irattach: executing: 'echo 1 > /proc/sys/net/irda/discovery'
May 14 22:43:00 tv irattach: Starting device irda0
May 14 22:45:33 tv kernel: drivers/net/irda/sir_dev.c:341: spin_is_locked(drivers/net/irda/sir_dev.c:c786cbb0) already locked by drivers/net/irda/sir_dev.c/142
May 14 22:45:33 tv kernel: drivers/net/irda/sir_dev.c:346: spin_lock(drivers/net/irda/sir_dev.c:c786cbb0) already locked by drivers/net/irda/sir_dev.c/142
May 14 22:45:36 tv kernel: IrLAP, no activity on link!
May 14 22:45:45 tv last message repeated 3 times
May 14 22:45:46 tv kernel: drivers/net/irda/sir_dev.c:341: spin_is_locked(drivers/net/irda/sir_dev.c:c786cbb0) already locked by drivers/net/irda/sir_dev.c/142
May 14 22:45:46 tv kernel: drivers/net/irda/sir_dev.c:346: spin_lock(drivers/net/irda/sir_dev.c:c786cbb0) already locked by drivers/net/irda/sir_dev.c/142
May 14 22:48:40 tv shutdown[671]: shutting down for system reboot

Steps to reproduce:
This problem seems quite repeatable, I can provide further information or testing as required.

modprobe uhci-hcd
modprobe pl2303
irattach /dev/ttyUSB0 -d tekram -s

start multisync, select irmc device and search for devices, device found but serial number is "serial number" and the above messages appear in the kernel log.

I also have the following that was generated by a different 2.6.6 build on the same hardware. Sorry I don't have the kernel config for this kernel, however I do know that preemptitive kernel was turned on and all the kernel debug was turned off.

May 14 18:57:58 tv irattach: executing: 'echo tv > /proc/sys/net/irda/devname'
May 14 18:57:58 tv irattach: executing: 'echo 1 > /proc/sys/net/irda/discovery'
May 14 18:57:58 tv irattach: Starting device irda0
May 14 18:58:55 tv kernel: Call Trace:
May 14 18:58:55 tv kernel:  [<c024db35>] schedule+0x5a5/0x5b0
May 14 18:58:55 tv kernel:  [<cab45655>] sirdev_receive+0x85/0x130 [sir_dev]
May 14 18:58:55 tv kernel:  [<c0120a45>] worker_thread+0x255/0x270
May 14 18:58:55 tv kernel:  [<cab390b0>] usb_serial_port_softint+0x0/0xe0 [usbserial]
May 14 18:58:55 tv kernel:  [<c0110490>] default_wake_function+0x0/0x10
May 14 18:58:55 tv kernel:  [<c0110490>] default_wake_function+0x0/0x10
May 14 18:58:55 tv kernel:  [<c01207f0>] worker_thread+0x0/0x270
May 14 18:58:55 tv kernel:  [<c0123c08>] kthread+0x98/0xa0
May 14 18:58:55 tv kernel:  [<c0123b70>] kthread+0x0/0xa0
May 14 18:58:55 tv kernel:  [<c010203d>] kernel_thread_helper+0x5/0x18
May 14 18:58:55 tv kernel:
May 14 18:58:55 tv kernel: Call Trace:
May 14 18:58:55 tv kernel:  [<c024db35>] schedule+0x5a5/0x5b0
May 14 18:58:55 tv kernel:  [<c0120a45>] worker_thread+0x255/0x270
May 14 18:58:55 tv kernel:  [<cab390b0>] usb_serial_port_softint+0x0/0xe0 [usbserial]
May 14 18:58:55 tv kernel:  [<c0110490>] default_wake_function+0x0/0x10
May 14 18:58:55 tv kernel:  [<c0110490>] default_wake_function+0x0/0x10
May 14 18:58:55 tv kernel:  [<c01207f0>] worker_thread+0x0/0x270
May 14 18:58:55 tv kernel:  [<c0123c08>] kthread+0x98/0xa0
May 14 18:58:55 tv kernel:  [<c0123b70>] kthread+0x0/0xa0
May 14 18:58:55 tv kernel:  [<c010203d>] kernel_thread_helper+0x5/0x18
May 14 18:58:55 tv kernel:
May 14 18:58:55 tv kernel: Call Trace:
May 14 18:58:55 tv kernel:  [<c024db35>] schedule+0x5a5/0x5b0
May 14 18:58:55 tv kernel:  [<c0120a45>] worker_thread+0x255/0x270
May 14 18:58:55 tv kernel:  [<cab390b0>] usb_serial_port_softint+0x0/0xe0 [usbserial]
May 14 18:58:55 tv kernel:  [<c0110490>] default_wake_function+0x0/0x10
May 14 18:58:55 tv kernel:  [<c0110490>] default_wake_function+0x0/0x10
May 14 18:58:55 tv kernel:  [<c01207f0>] worker_thread+0x0/0x270
May 14 18:58:55 tv kernel:  [<c0123c08>] kthread+0x98/0xa0
May 14 18:58:55 tv kernel:  [<c0123b70>] kthread+0x0/0xa0
May 14 18:58:55 tv kernel:  [<c010203d>] kernel_thread_helper+0x5/0x18
May 14 18:58:55 tv kernel:
May 14 18:58:56 tv kernel: Call Trace:
May 14 18:58:56 tv kernel:  [<c024db35>] schedule+0x5a5/0x5b0
May 14 18:58:56 tv kernel:  [<c0120a45>] worker_thread+0x255/0x270
May 14 18:58:56 tv kernel:  [<cab390b0>] usb_serial_port_softint+0x0/0xe0 [usbserial]
May 14 18:58:56 tv kernel:  [<c0110490>] default_wake_function+0x0/0x10
May 14 18:58:56 tv kernel:  [<c0110490>] default_wake_function+0x0/0x10
May 14 18:58:56 tv kernel:  [<c01207f0>] worker_thread+0x0/0x270
May 14 18:58:56 tv kernel:  [<c0123c08>] kthread+0x98/0xa0
May 14 18:58:56 tv kernel:  [<c0123b70>] kthread+0x0/0xa0
May 14 18:58:56 tv kernel:  [<c010203d>] kernel_thread_helper+0x5/0x18
May 14 18:58:56 tv kernel:
May 14 18:58:56 tv kernel: Call Trace:
May 14 18:58:56 tv kernel:  [<c024db35>] schedule+0x5a5/0x5b0
May 14 18:58:56 tv kernel:  [<c0120a45>] worker_thread+0x255/0x270
May 14 18:58:56 tv kernel:  [<cab390b0>] usb_serial_port_softint+0x0/0xe0 [usbserial]
May 14 18:58:56 tv kernel:  [<c0110490>] default_wake_function+0x0/0x10
May 14 18:58:56 tv kernel:  [<c0110490>] default_wake_function+0x0/0x10
May 14 18:58:56 tv kernel:  [<c01207f0>] worker_thread+0x0/0x270
May 14 18:58:56 tv kernel:  [<c0123c08>] kthread+0x98/0xa0
May 14 18:58:56 tv kernel:  [<c0123b70>] kthread+0x0/0xa0
May 14 18:58:56 tv kernel:  [<c010203d>] kernel_thread_helper+0x5/0x18
May 14 18:58:56 tv kernel:

and many more

Comment 1 Domen Puncer Kugler 2004-05-14 09:46:58 UTC

Created attachment 2863 [details]
Add missing spin_unlock

It adds missing spinlock on what seems like an error path, so device might
still not work, but it should get rid of that "already locked" message.

Comment 2 Tom Parker 2004-05-14 22:25:14 UTC

The attached patch means I get no complaints about spin locks in the log. However I am still unable to sync with my phone.;;echo 9600 > /proc/sys/net/irda/max_baud_rate;;seems to fix that problem (although syncing takes longer).;;I tried the same irda dongle with debian stable and 2.4.26 on a different motherboard and got a kernel panic about sheduling in an interrupt. Should I do a full report on that here, or open a new bug?

Comment 3 Tom Parker 2004-05-27 02:48:06 UTC

see bug 2779 for this kernel panic with this device on 2.4.26. To reiterate, the
patch attached to this bug does fix the problems on 2.6.6 (although the device
does have to be slowed down to operate)

Comment 4 Adrian Bunk 2006-01-01 04:41:38 UTC

What is the status of this issue in recent 2.6 kernels?

Comment 5 Samuel Ortiz 2006-03-12 05:43:21 UTC

The missing spinlock restore is in the latest 2.6 kernels.

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