Problem: ov511 driver for Creative Labs Webcam III locks system up
Contact: Lawrence Glaister [EMAIL PROTECTED]
Symptoms:
-ov511 application runs anywhere from 10 minutes to 24 hours then locks up
the system requiring reset of box (soft boot)
-application does not seem to have an obvious memory leak (no growth as
indicated by gtop)
-application has survived up to 30,000 open/read/close cycles on the camera
but sometimes the system dies after a few hundred cycles
-problem has been demonstrated in 2.3.99 + 2.4.0 kernels (earlier versions
not
tested)
-a similar problem which may be related has existed in the ov511 driver
since I started testing with 2.3.51. Running xawtv, the image capture does
not survive an overnight test... system does not crash, but the camera
locks
up and does not return any further images.
- the system seems to stay alive longer with high levels (4) of debug set
on the
ov511 driver (although syslogd goes crazy trying to write all the info to
disk) This may indicate a timing related problem (race).
- very occasional image corruption has been noticed in random locations on
the
screen.. this may be due to a comm problem, a camera problem or someone in
the driver overwriting the buffer. I notice Mark that one of your sample
pictures
also have image corruption on the coke machine.
- the problem occurs with both uhci.o and usb-uhci.o, so I do not suspect
these drivers. It is possible the problem could be in videodev or ov511.. I
dont know if any other camera drivers are experiencing similar problems.
Suggestions:
- I am new to kernel drivers, but learning fast...
- set traps in ov511 driver to catch suspect pointers
- try and detect abnormal camera activity (timeouts) and reset device
it would be nice if one did not have to unplug the camera usb cable
to get the camera reset... usb power control should do this as the camera
is powered off the usb bus.
- the lockup conditions would seem to indicate that there is either a
hardware problem occurring or someone in kernel space is nuking memory.
- I have a gnome webcam security (time lapse) program available that seems
to reliably lockup the system within 24 hours... let me know if you need a
copy of the project.
===================== ov511 with debug level 4 kernel log
===================
========= last block of messages before lockup at 18:04:33
Jun 14 18:04:30 speedy kernel: ov511.c: [ov511_isoc_irq:1513] hmmm... not
streaming, but got interrupt
Jun 14 18:04:30 speedy kernel: ov511.c: [ov511_isoc_irq:1513] hmmm... not
streaming, but got interrupt
Jun 14 18:04:30 speedy kernel: ov511.c: [ov511_open:1690] opening
Jun 14 18:04:30 speedy kernel: ov511.c: [ov511_open:1711] frame [0] @
d0864000
Jun 14 18:04:30 speedy kernel: ov511.c: [ov511_open:1721] sbuf[0] @ c3b38000
Jun 14 18:04:30 speedy kernel: ov511.c: [ov511_open:1711] frame [1] @
d0864000
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_open:1721] sbuf[1] @ c4fd8000
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_init_isoc:1537] ***
Initializing capture ***
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_stop:683] stopping
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_set_packet_size:734] set
packet size: 993, mult=31, alt=1
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_reset:669] Reset: type=0x3F
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_restart:690] restarting
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_ioctl:1780] IOCtl: 0x803C7601
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_ioctl:1790] VIDIOCGCAP
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_ioctl:1780] IOCtl: 0x80887614
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_mmap:2246] mmap: 1847296
(1C3000) bytes
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_ioctl:1780] IOCtl: 0x40107613
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_ioctl:1995] MCAPTURE
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_ioctl:1997] frame: 0, size:
640x480, format: 4
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_new_frame:1638]
ov511->curframe = -1, framenum = 0
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_new_frame:1655] framenum = 0,
width = 640, height = 480
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_ioctl:1780] IOCtl: 0x40047612
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_ioctl:2043] syncing to frame
0, grabstate = 2
Jun 14 18:04:31 speedy kernel: ov511.c: [ov511_move_data:1315] Moving 10
packets
Jun 14 18:04:32 speedy last message repeated 44 times
Jun 14 18:04:32 speedy kernel: ov511.c: [ov511_move_data:14ts
Jun 14 18:04:32 speedy kernel: ov511.c: [ov511_move_data:1315] Moving 10
packets
Jun 14 18:04:32 speedy last message repeated 3 times
Jun 14 18:04:32 speedy kernel: VFS: Disk change detected on device
ide1(22,0)
Jun 14 18:04:32 speedy kernel: ov511.c: [ov511_move_data:1315] Moving 10
packets
Jun 14 18:04:32 speedy last message repeated 6 times
Jun 14 18:04:32 speedy kernel: ov511.c: [ov511_move_data:1402] Frame start,
framenum = 0
Jun 14 18:04:32 speedy kernel: ov511.c: [ov511_move_data:1315] Moving 10
packets
Jun 14 18:04:33 speedy last message repeated 46 times
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_move_data:1365] Frame end,
curframe = 0, packnum=210, hw=79, vw=59
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_move_data:1388] Frame done!
congratulations
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_close:1741] ov511_close
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_stop_isoc:1611] *** Stopping
capture ***
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_stop:683] stopping
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_set_packet_size:734] set
packet size: 0, mult=0, alt=7
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_reset:669] Reset: type=0x3F
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_restart:690] restarting
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_isoc_irq:1513] hmmm... not
streaming, but got interrupt
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_isoc_irq:1513] hmmm... not
streaming, but got interrupt
============ start of last open read close cycle
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_open:1690] opening
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_open:1711] frame [0] @
d0864000
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_open:1721] sbuf[0] @ c3b38000
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_open:1711] frame [1] @
d0864000
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_open:1721] sbuf[1] @ c4fd8000
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_init_isoc:1537] ***
Initializing capture ***
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_stop:683] stopping
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_set_packet_size:734] set
packet size: 993, mult=31, alt=1
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_reset:669] Reset: type=0x3F
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_restart:690] restarting
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_ioctl:1780] IOCtl: 0x803C7601
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_ioctl:1790] VIDIOCGCAP
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_ioctl:1780] IOCtl: 0x80887614
Jun 14 18:04:33 speedy kernel: ov511.c: [ov511_mmap:2246] mmap: 1847296
(1C3000) bytes
============= at this point computer is hung, no
mouse/keyboard/sysreq/display
============= chances are that some of the last kernel messages did not make
it
============= to disk (are they flushed each time or cached?)
============= soft boot using power switch on atx power supply
============= reboot from 2.4.0-test1-ac9 floppy (it says ac8, but I'm sure
I
applied ac9 patch)
Jun 15 09:08:47 speedy kernel: klogd 1.3-3, log source = /proc/kmsg started.
Jun 15 09:08:47 speedy kernel: Inspecting /boot/System.map
Jun 15 09:08:47 speedy kernel: Symbol table has incorrect version number.
Jun 15 09:08:47 speedy kernel: Cannot find map file.
Jun 15 09:08:47 speedy kernel: No module symbols loaded.
Jun 15 09:08:47 speedy kernel: Linux version 2.4.0-test1-ac8 (root@speedy)
(gcc version egcs-2.91.66 19990314/Linux (egcs-1.1.2 release)) #1 SMP Sat
Jun 10 20:00:31 PDT 2000
======================= results of cat /proc/pci ========================
PCI devices found:
Bus 0, device 0, function 0:
Host bridge: Intel Corporation 440BX/ZX - 82443BX/ZX Host bridge (rev
3).
Master Capable. Latency=64.
Prefetchable 32 bit memory at 0xe7000000 [0xe7ffffff].
Bus 0, device 1, function 0:
PCI bridge: Intel Corporation 440BX/ZX - 82443BX/ZX AGP bridge (rev 3).
Master Capable. Latency=64. Min Gnt=136.
Bus 0, device 4, function 0:
ISA bridge: Intel Corporation 82371AB PIIX4 ISA (rev 2).
Bus 0, device 4, function 1:
IDE interface: Intel Corporation 82371AB PIIX4 IDE (rev 1).
Master Capable. Latency=32.
I/O at 0xd800 [0xd80f].
Bus 0, device 4, function 2:
USB Controller: Intel Corporation 82371AB PIIX4 USB (rev 1).
IRQ 9.
Master Capable. Latency=32.
I/O at 0xd400 [0xd41f].
Bus 0, device 4, function 3:
Bridge: Intel Corporation 82371AB PIIX4 ACPI (rev 2).
Bus 0, device 10, function 0:
SCSI storage controller: Symbios Logic Inc. (formerly NCR) 53c810 (rev
2).
IRQ 10.
Master Capable. Latency=64.
I/O at 0xd000 [0xd0ff].
Non-prefetchable 32 bit memory at 0xe4000000 [0xe40000ff].
Bus 0, device 11, function 0:
Ethernet controller: 3Com Corporation 3c900B-TPO [Etherlink XL TPO] (rev
4).
IRQ 11.
Master Capable. Latency=32. Min Gnt=10.Max Lat=48.
I/O at 0xb800 [0xb87f].
Non-prefetchable 32 bit memory at 0xe3800000 [0xe380007f].
Bus 1, device 0, function 0:
VGA compatible controller: Matrox Graphics, Inc. MGA G200 AGP (rev 3).
IRQ 11.
Master Capable. Latency=64. Min Gnt=16.Max Lat=32.
Prefetchable 32 bit memory at 0xe6000000 [0xe6ffffff].
Non-prefetchable 32 bit memory at 0xe5000000 [0xe5003fff].
Non-prefetchable 32 bit memory at 0xe4800000 [0xe4ffffff].
============================== after reboot and modprobe usb-uhci, ov511
Jun 15 09:21:05 speedy kernel: usb.c: registered new driver usbdevfs
Jun 15 09:21:05 speedy kernel: usb.c: registered new driver hub
Jun 15 09:21:06 speedy kernel: usb-uhci.c: $Revision: 1.231 $ time 20:08:52
Jun 10 2000
Jun 15 09:21:06 speedy kernel: usb-uhci.c: High bandwidth mode enabled
Jun 15 09:21:06 speedy kernel: usb-uhci.c: Intel USB controller: setting
latency timer to 0
Jun 15 09:21:06 speedy kernel: usb-uhci.c: USB UHCI at I/O 0xd400, IRQ 9
Jun 15 09:21:06 speedy kernel: usb-uhci.c: Detected 2 ports
Jun 15 09:21:06 speedy kernel: usb.c: new USB bus registered, assigned bus
number 1
Jun 15 09:21:06 speedy kernel: usb.c: USB new device connect, assigned
device number 1
Jun 15 09:21:06 speedy kernel: hub.c: USB hub found
Jun 15 09:21:06 speedy kernel: hub.c: 2 ports detected
Jun 15 09:21:06 speedy kernel: usb.c: USB new device connect, assigned
device number 2
Jun 15 09:21:06 speedy kernel: usb-uhci.c: interrupt, status 2, frame# 811
Jun 15 09:21:06 speedy kernel: usb-uhci-debug.h: TD @ ce8667e0/0E8667E0,
MaxLen=07 DT0 EP=0 Dev=0 PID=(SETUP) buf=0c2c4a80
Jun 15 09:21:06 speedy kernel: usb-uhci-debug.h: Len=07 e0 SPD Stalled
CRC/Timeo
Jun 15 09:21:06 speedy kernel: usb-uhci-debug.h: Link points to TD @
0e866820, Breadth first
Jun 15 09:21:06 speedy kernel: usb.c: USB device not accepting new address
(error=-110)
Jun 15 09:21:06 speedy kernel: usb.c: USB disconnect on device -1
Jun 15 09:21:07 speedy kernel: VFS: Disk change detected on device
ide1(22,0)
Jun 15 09:21:07 speedy kernel: usb.c: USB new device connect, assigned
device number 2
Jun 15 09:21:07 speedy kernel: usb.c: This device is not recognized by any
installed USB driver.
Jun 15 09:21:09 speedy kernel: VFS: Disk change detected on device
ide1(22,0)
Jun 15 09:21:11 speedy kernel: VFS: Disk change detected on device
ide1(22,0)
Jun 15 09:21:12 speedy kernel: Linux video capture interface: v1.00
Jun 15 09:21:12 speedy kernel: usb.c: registered new driver ov511
Jun 15 09:21:12 speedy kernel: ov511.c: [ov511_probe:2562] probing for
device...
============( looks like webcam III device is not responding )
Jun 15 09:21:12 speedy kernel: ov511.c: ov511 driver version 1.15cm3
registered
============= camera unplugged and plugged back in
Jun 15 09:25:57 speedy kernel: usb.c: USB new device connect, assigned
device number 3
Jun 15 09:25:57 speedy kernel: ov511.c: [ov511_probe:2562] probing for
device...
Jun 15 09:25:57 speedy kernel: ov511.c: USB OV511 camera found
Jun 15 09:25:57 speedy kernel: ov511.c: [ov511_probe:2611] CustomID = 21
Jun 15 09:25:57 speedy kernel: ov511.c: camera: Creative Labs WebCam 3
Jun 15 09:25:57 speedy kernel: ov511.c: [ov511_stop:683] stopping
Jun 15 09:25:57 speedy kernel: ov511.c: [ov511_set_packet_size:734] set
packet size: 0, mult=0, alt=7
Jun 15 09:25:57 speedy kernel: ov511.c: [ov511_reset:669] Reset: type=0x3F
Jun 15 09:25:57 speedy kernel: ov511.c: [ov511_restart:690] restarting
Jun 15 09:25:57 speedy kernel: ov511.c: [ov76xx_configure:2365] starting
configuration
Jun 15 09:25:57 speedy kernel: ov511.c: [ov511_reset:669] Reset: type=0x3F
Jun 15 09:25:57 speedy kernel: ov511.c: [ov76xx_configure:2393] I2C synced
in 1 attempt(s)
Jun 15 09:25:57 speedy kernel: ov511.c: Sensor is an OV7610
Jun 15 09:25:57 speedy kernel: ov511.c: [ov76xx_configure:2431] Writing 7610
registers
Jun 15 09:25:58 speedy kernel: ov511.c: [ov511_mode_init_regs:870]
width:640, height:480, mode:4, sub:0
Jun 15 09:25:58 speedy kernel: ov511.c: [ov511_stop:683] stopping
Jun 15 09:25:58 speedy kernel: ov511.c: [ov511_restart:690] restarting
camera now works
[root@speedy lg]# cat /proc/bus/usb/devices
T: Bus=01 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#= 1 Spd=12 MxCh= 2
B: Alloc= 0/900 us ( 0%), #Int= 0, #Iso= 0
D: Ver= 1.00 Cls=09(hub ) Sub=00 Prot=00 MxPS= 8 #Cfgs= 1
P: Vendor=0000 ProdID=0000 Rev= 0.00
S: Product=USB UHCI Root Hub
S: SerialNumber=d400
C:* #Ifs= 1 Cfg#= 1 Atr=40 MxPwr= 0mA
I: If#= 0 Alt= 0 #EPs= 1 Cls=09(hub ) Sub=00 Prot=00 Driver=hub
E: Ad=81(I) Atr=03(Int.) MxPS= 8 Ivl=255ms
T: Bus=01 Lev=01 Prnt=01 Port=00 Cnt=01 Dev#= 3 Spd=12 MxCh= 0
D: Ver= 1.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS= 8 #Cfgs= 1
P: Vendor=05a9 ProdID=0511 Rev= 1.00
C:* #Ifs= 1 Cfg#= 1 Atr=80 MxPwr=500mA
I: If#= 0 Alt= 0 #EPs= 1 Cls=ff(vend.) Sub=00 Prot=00 Driver=ov511
E: Ad=81(I) Atr=01(Isoc) MxPS= 992 Ivl= 1ms
I: If#= 0 Alt= 1 #EPs= 1 Cls=ff(vend.) Sub=00 Prot=00 Driver=ov511
E: Ad=81(I) Atr=01(Isoc) MxPS= 993 Ivl= 1ms
I: If#= 0 Alt= 2 #EPs= 1 Cls=ff(vend.) Sub=00 Prot=00 Driver=ov511
E: Ad=81(I) Atr=01(Isoc) MxPS= 768 Ivl= 1ms
I: If#= 0 Alt= 3 #EPs= 1 Cls=ff(vend.) Sub=00 Prot=00 Driver=ov511
E: Ad=81(I) Atr=01(Isoc) MxPS= 769 Ivl= 1ms
I: If#= 0 Alt= 4 #EPs= 1 Cls=ff(vend.) Sub=00 Prot=00 Driver=ov511
E: Ad=81(I) Atr=01(Isoc) MxPS= 512 Ivl= 1ms
I: If#= 0 Alt= 5 #EPs= 1 Cls=ff(vend.) Sub=00 Prot=00 Driver=ov511
E: Ad=81(I) Atr=01(Isoc) MxPS= 513 Ivl= 1ms
I: If#= 0 Alt= 6 #EPs= 1 Cls=ff(vend.) Sub=00 Prot=00 Driver=ov511
E: Ad=81(I) Atr=01(Isoc) MxPS= 257 Ivl= 1ms
I: If#= 0 Alt= 7 #EPs= 1 Cls=ff(vend.) Sub=00 Prot=00 Driver=ov511
E: Ad=81(I) Atr=01(Isoc) MxPS= 0 Ivl= 1ms
T: Bus=01 Lev=01 Prnt=01 Port=01 Cnt=02 Dev#= 2 Spd=12 MxCh= 0
D: Ver= 1.00 Cls=ff(vend.) Sub=ff Prot=ff MxPS= 8 #Cfgs= 1
P: Vendor=06bd ProdID=2061 Rev= 1.1e
S: Manufacturer=AGFA
S: Product= Snapscan1212u_2
C:* #Ifs= 1 Cfg#= 1 Atr=40 MxPwr=100mA
I: If#= 0 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=ff Prot=ff Driver=(none)
E: Ad=81(I) Atr=02(Bulk) MxPS= 64 Ivl= 0ms
E: Ad=02(O) Atr=02(Bulk) MxPS= 8 Ivl= 0ms
E: Ad=83(I) Atr=03(Int.) MxPS= 8 Ivl= 16ms
============== modules loaded
[root@speedy lg]# /sbin/lsmod
Module Size Used by
ov511 28924 0
videodev 3168 1 [ov511]
usb-uhci 23208 0 (unused)
usbcore 48736 1 [ov511 usb-uhci]
sb 6480 1 (autoclean)
sb_lib 35892 0 (autoclean) [sb]
uart401 6800 1 (autoclean) [sb_lib]
sound 62188 0 (autoclean) [sb sb_lib uart401]
soundcore 4068 5 (autoclean) [sb_lib sound]
=======================================================
Lawrence Glaister VE7IT email: [EMAIL PROTECTED]
1462 Madrona Drive http://jfm.bc.ca
Nanoose Bay BC Canada
V9P 9C9
=======================================================
---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]
