[ivtv-users] cx18: Extensive interrupt and buffer handling changes need test
Al McIntosh
al at allanmcintosh.com
Fri Nov 21 20:21:35 CET 2008
On Thu, Nov 20, 2008 at 9:34 PM, Andy Walls <awalls at radix.net> wrote:
> On Wed, 2008-11-19 at 21:04 -0500, Al McIntosh wrote:
> >
> >
> > On Wed, Nov 19, 2008 at 12:10 AM, Andy Walls <awalls at radix.net> wrote:
> > cx18 driver users:
> >
> > I have implemented quite a few cx18 driver changes in my
> > current
> > experimental repo at
> >
> > http://linuxtv.org/hg/~awalls/cx18-bugfix<http://linuxtv.org/hg/%7Eawalls/cx18-bugfix>
> >
> > The goal behind these changes is to fix problems with
> > simultaneous
> > analog and digital capture causing the driver to quit after a
> > while.
> > And to fix related problems with buffers getting lost and
> > falling out of
> > the driver<->firmware transfer rotation.
>
> > Please test the debug parameter with at least info and warn
> > set:
> >
> > # modprobe cx18 debug=3
> >
> >
> > I am especially interested in
> >
> >
> > 1. How often you get messages like the following on your
> > system?
> >
> > cx18-0 warning: Possibly falling behind: CPU self-ack'ed our
> > incoming CPU to EPU mailbox (sequence no. nnnn)
> >
> > I need to get a feel for if I need to have the cx18 driver not
> > request a
> > shared IRQ line for most user applications.
> >
> > On my system where irq balance/migration is turned off, and
> > the HVR-1600
> > shares an interrupt with the SATA controller, I get them quite
> > a bit
> > doing simultaneous analog and digital capture with MythTV
> > (I've
> > approximated a busy, single CPU machine with that setup).
>
>
> > For the following system:
>
>
> > $ cat /proc/cpuinfo
> > processor : 0
> > vendor_id : AuthenticAMD
> > cpu family : 15
> > model : 28
> > model name : AMD Sempron(tm) Processor 2800+
> > stepping : 0
> > cpu MHz : 1607.382
> > cache size : 256 KB
> [snip]
> > bogomips : 3214.76
>
> OK. Single core.
>
>
>
> > $grep cx18 /proc/interrupts
> > 18: 72358 IO-APIC-fasteoi cx18-0, nvidia
>
> Sharing an interrupt line with the video graphics hardware. Not ideal.
> The only thing that could as bad is sharing an interrupt with the disk
> controller (MythTV is constantly accessing disk when recording and
> stimulating disk interrupts, and I'll assume X11/nvidia has setup for
> regular video interrupts will rending the video in MythTV.)
>
> >From your output below, the last CX23418 to host interrupt sequence # is
> 4684. For every buffer we get from the CX23418 we send one command back
> (approximately) and get an interrupt for those too. So the lasted
> missed cx18 driver mailbox log message let's us account for 9300, heck
> let's round up, 10,000 of those 72358 interrupts. I'd say the nvidia
> hardware is generating a lot of interrupts on that line too, and causing
> the cx18 driver to fall behind on servicing interrupts from the CX23418
> while the kernel and nvidia driver irq handling has the line disabled.
>
>
>
> > $ uname -a
> > Linux nelson 2.6.27-7-generic #1 SMP Fri Oct 24 06:42:44 UTC 2008 i686
> > GNU/Linux
> >
> >
> > I built and installed the following:
> >
> > http://linuxtv.org/hg/~awalls/cx18-bugfix/archive/891eedf234a5.tar.bz2<http://linuxtv.org/hg/%7Eawalls/cx18-bugfix/archive/891eedf234a5.tar.bz2>
> >
> > Here is the debug output:
>
> [snip]
> > [ 11.643132] cx18: Start initialization, version 1.0.2
> > [ 11.648808] cx18-0: Initializing card #0
> > [ 11.648815] cx18-0: Autodetected Hauppauge card
> > [ 11.648819] cx18-0 info: base addr: 0xf8000000
> > [ 11.648822] cx18-0 info: Enabling pci device
> > [ 11.649212] ACPI: PCI Interrupt Link [APC3] enabled at IRQ 18
> > [ 11.649223] cx18 0000:01:08.0: PCI INT A -> Link[APC3] -> GSI 18
> > (level, low) -> IRQ 18
> > [ 11.649233] cx18-0: Unreasonably low latency timer, setting to 64
> > (was 32)
> > [ 11.649239] cx18-0 info: cx23418 (rev 0) at 01:08.0, irq: 18,
> > latency: 64, memory: 0xf8000000
> [snip - everything looks cool]
> > [ 13.673758] cx18-0: Initialized card #0: Hauppauge HVR-1600
> > [ 13.674278] cx18: End initialization
> > [ 13.984265] ACPI: PCI Interrupt Link [APC4] enabled at IRQ 19
> > [ 13.984278] EMU10K1_Audigy 0000:01:09.0: PCI INT A -> Link[APC4] ->
> > GSI 19 (level, low) -> IRQ 19
> > [ 14.017458] Linux agpgart interface v0.103
>
>
>
>
> > [ 14.200463] nvidia: module license 'NVIDIA' taints kernel.
> > [ 14.795264] nvidia 0000:05:00.0: PCI INT A -> Link[APC3] -> GSI 18
> > (level, low) -> IRQ 18
> > [ 14.795274] nvidia 0000:05:00.0: setting latency timer to 64
> > [ 14.795670] NVRM: loading NVIDIA UNIX x86 Kernel Module 173.14.12
> > Thu Jul 17 18:11:36 PDT 2008
>
> A binary module. We have no hope of improving the nvidia driver's irq
> handling top half. We have no way of easily knowing how efficient it is
> either. Note, it is using IRQ 18 as well as the CX23418.
>
> [snip]
> > [ 32.816051] firmware: requesting v4l-cx23418-apu.fw
> > [ 32.889470] cx18-0 info: load segment a00000-a07fff
> > [ 32.908330] cx18-0 info: load segment ae0000-ae00ff
> > [ 32.908482] cx18-0 info: load segment b00000-b1a65f
> > [ 32.970481] cx18-0: loaded v4l-cx23418-apu.fw firmware V00120000
> > (141200 bytes)
> > [ 33.472733] firmware: requesting v4l-cx23418-cpu.fw
> > [ 33.582593] cx18-0: loaded v4l-cx23418-cpu.fw firmware (158332
> > bytes)
> > [ 33.588746] cx18-0 info: 1 MiniMe Encoder Firmware 0.0.74.0
> > (Release 2007/03/12)
> > [ 33.588755] cx18-0: FW version: 0.0.74.0 (Release 2007/03/12)
> > [ 33.784035] firmware: requesting v4l-cx23418-apu.fw
> > [ 33.788935] cx18-0 info: load segment a00000-a07fff
> > [ 33.807756] cx18-0 info: load segment ae0000-ae00ff
> > [ 33.807908] cx18-0 info: load segment b00000-b1a65f
> > [ 34.368013] firmware: requesting v4l-cx23418-cpu.fw
> > [ 34.469963] cx18-0 info: 1 MiniMe Encoder Firmware 0.0.74.0
> > (Release 2007/03/12)
> > [ 34.664016] cx18-0 info: Changing input from 1 to 0
> > [ 34.664021] cx18-0 info: Mute
> > [ 34.664025] cx18-0 info: cmd 4008646f triggered fw load
> > [ 34.664028] firmware: requesting v4l-cx23418-dig.fw
> > [ 34.849528] cx18-0: loaded v4l-cx23418-dig.fw firmware (16382
> > bytes)
> > [ 34.849570] cx18-0 info: decoder set video input 7, audio input 8
> > [ 34.852749] cx18-0 info: decoder set video input 7, audio input 8
> > [ 34.853726] cx18-0 info: Unmute
> > [ 34.853732] cx18-0 info: Switching standard to 1000.
> > [ 34.853736] cx18-0 info: changing video std to fmt 1
> > [ 34.853750] cx18-0 info: PLL regs = int: 15, frac: 2876158, post: 4
> > [ 34.853753] cx18-0 info: PLL = 108.000014 MHz
> > [ 34.853756] cx18-0 info: PLL/8 = 13.500001 MHz
> > [ 34.853759] cx18-0 info: ADC Sampling freq = 14.317384 MHz
> > [ 34.853762] cx18-0 info: Chroma sub-carrier freq = 3.579545 MHz
> > [ 34.853766] cx18-0 info: hblank 122, hactive 720, vblank 26 ,
> > vactive 487, vblank656 26, src_dec 543,burst 0x5b, luma_lpf 1, uv_lpf
> > 1, comb 0x66, sc 0x087c1f
> > [ 34.861431] cx18-0 info: Mute
> > [ 34.861436] cx18-0 info: v4l2 ioctl: set frequency 1076
> > [ 34.863303] cx18-0 info: Unmute
> > [ 35.009920] cx18-0 info: Changing input from 0 to 1
> > [ 35.009930] cx18-0 info: Mute
> > [ 35.009934] cx18-0 info: decoder set video input 1296, audio input
> > 8
> > [ 35.013455] cx18-0 info: decoder set video input 1296, audio input
> > 0
> > [ 35.014359] cx18-0 info: Unmute
> > [ 35.014806] cx18-0 info: Switching standard to b000.
> > [ 35.014812] cx18-0 info: changing video std to fmt 1
> > [ 35.014826] cx18-0 info: PLL regs = int: 15, frac: 2876158, post: 4
> > [ 35.014830] cx18-0 info: PLL = 108.000014 MHz
> > [ 35.014832] cx18-0 info: PLL/8 = 13.500001 MHz
> > [ 35.014835] cx18-0 info: ADC Sampling freq = 14.317384 MHz
> > [ 35.014838] cx18-0 info: Chroma sub-carrier freq = 3.579545 MHz
> > [ 35.014842] cx18-0 info: hblank 122, hactive 720, vblank 26 ,
> > vactive 487, vblank656 26, src_dec 543,burst 0x5b, luma_lpf 1, uv_lpf
> > 1, comb 0x66, sc 0x087c1f
> > [ 35.023866] cx18-0 info: Input unchanged
> > [ 35.024540] cx18-0 info: Mute
> > [ 35.024546] cx18-0 info: v4l2 ioctl: set frequency 980
> > [ 35.026401] cx18-0 info: Unmute
> > [ 35.095604] cx18-0 info: Mute
> > [ 35.095613] cx18-0 info: v4l2 ioctl: set frequency 980
> > [ 35.097794] cx18-0 info: Unmute
> [snip]
> > [ 83.801929] cx18-0 info: Start encoder stream encoder MPEG
> > [ 88.328814] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 52) while
> > processing
> > [ 89.526914] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 67) while
> > processing
> > [ 112.046227] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 357) while
> > processing
> > [ 128.563274] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 576) while
> > processing
> > [ 144.781984] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 795) while
> > processing
>
> These are all happening too close together. The cx18 irq handler is not
> being passed control in a timely fashion when the CX23418 signals an
> interrupt.
>
>
> > [ 155.334230] cx18-0 info: User stopped encoder MPEG
> > [ 155.335043] cx18-0 info: close stopping capture
> > [ 155.335051] cx18-0 info: Stop Capture
> > [ 422.270549] cx18-0 info: Input unchanged
> > [ 422.271205] cx18-0 info: Mute
> > [ 422.271211] cx18-0 info: v4l2 ioctl: set frequency 980
> > [ 422.273081] cx18-0 info: Unmute
> > [ 422.276845] cx18-0 info: Mute
> > [ 422.276853] cx18-0 info: v4l2 ioctl: set frequency 980
> > [ 422.278831] cx18-0 info: Unmute
> > [ 428.728899] cx18-0 info: Start encoder stream encoder MPEG
> > [ 434.640532] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 1320) while
> > processing
> > [ 435.033614] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 1340) while
> > processing
> > [ 438.009412] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 1488)
> > [ 440.165578] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 1594) while
> > processing
> > [ 450.877048] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 2138) while
> > processing
> > [ 462.228374] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 2722) while
> > processing
> > [ 469.673531] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 3104) while
> > processing
> > [ 469.866070] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 3114) while
> > processing
> > [ 472.342068] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 3237) while
> > processing
>
> Same as above. Too frequent to be comfortable.
>
> > [ 499.116283] cx18-0 info: close stopping capture
> > [ 499.116292] cx18-0 info: Stop Capture
> > [ 724.246799] cx18-0 info: Start encoder stream encoder MPEG
> > [ 725.454632] cx18-0 warning: Possibly falling behind: CPU
> > self-ack'ed our incoming CPU to EPU mailbox (sequence no. 4684) while
> > processing
> > [ 757.880500] cx18-0 info: User stopped encoder MPEG
> > [ 757.881320] cx18-0 info: close stopping capture
> > [ 757.881328] cx18-0 info: Stop Capture
> >
> >
> > If you're interested in viewing the result email me and I will email
> > you a URL to dl an mpg.
>
> > I am tempted to put the card into another dual core system to see how
> > it performs.
>
> /proc/cpuinfo and /proc/interrupts indicated the machine the card is in
> is a single core machine.
>
> The real problem is interrupt sharing with a busy device, and perhaps a
> suboptimal nvidia module irq handler on a single core machine
> contributes as well.
>
>
> I need to look at the implications of requesting an exclusive IRQ line
> for a device that supports shared IRQs. I think things will be OK. I
> just have to do tests.
>
> Ultimately I guess I'll change the driver to always request an exclusive
> IRQ line first, and then fall back to a shared line if it can't get an
> exclusive one.
>
> In the meantime, if you're feeling adventurous, you may wish to try
> removing "IRQF_SHARED |" from line 730 in cx18-driver.c:cx18_probe():
>
>
> /* Register IRQ */
> retval = request_irq(cx->dev->irq, cx18_irq_handler,
> IRQF_SHARED | IRQF_DISABLED, cx->name, (void
> *)cx);
> ^^^^^^^^^^^^^
> Try removing this ---+
>
> recompile and reinstall the driver and see what happens. Hopefully the
> cx18 driver will then get it's own interrupt line and things will be
> better for you.
>
I will definitely test this for you, likely won't be until next week, off to
Montreal for the weekend. :)
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://ivtvdriver.org/pipermail/ivtv-users/attachments/20081121/fabc1cdf/attachment-0001.html
More information about the ivtv-users
mailing list