ivtv driver inputs randomly "block"

DISCUSSION Brian J. Murrell 3 participants 14 messages Nov 28, 2012 – Dec 5, 2012 1 message not in the archive Media (V4L/DVB)

lore

Share & tools

lore

Brian J. Murrell

author

2012-11-28 03:24 UTC #0 lore raw

I have a machine with a PVR-150 and a PVR-500 in it on a 3.2.0-33-generic (Ubuntu kernel, based on 3.2.1 IIUC) kernel.

I am having problems where at random times random /dev/video[0,1,2] inputs will just block on read. It's not the same input every time and it's not even the same card every time. This is all hardware which has worked without any such problems before.

To remedy the hanging input I simply have to rmmod ivtv && modprobe ivtv and all is back to normal again, until it happens again.

Any ideas?

Ezequiel Garcia

2012-11-28 13:09 UTC #1 lore raw

Quoted 6 lines · Brian J. Murrell

To remedy the hanging input I simply have to rmmod ivtv && modprobe ivtv and all is back to normal again, until it happens again.
Any ideas?

Can you post a dmesg output when this happens?

Thanks,

Ezequiel

Brian J. Murrell

author

2012-11-28 13:18 UTC #2 lore raw

Quoted 2 lines · Ezequiel Garcia

Can you post a dmesg output when this happens?

Unfortunately, there is nothing at all in dmesg when this happens.

Ezequiel Garcia

2012-11-28 13:13 UTC #3 lore raw

Quoted 6 lines · Brian J. Murrell

Quoted 2 lines · Ezequiel Garcia
Can you post a dmesg output when this happens?
Unfortunately, there is nothing at all in dmesg when this happens.

Try again with
modprobe ivtv ivtv_debug=10

Brian J. Murrell

author

2012-11-28 13:34 UTC #4 lore raw

Quoted 3 lines · Ezequiel Garcia

Try again with
modprobe ivtv ivtv_debug=10

That actually errored out but I think you meant:

# modprobe ivtv debug=10

which actually was successful in loading the module. Now we just wait for the failure and see.

I will update here as soon as I see it again.

Cheers,
b.

Brian J. Murrell

author

2012-11-28 23:19 UTC #5 lore raw

In reply to Ezequiel Garcia

Quoted 3 lines · Ezequiel Garcia

Try again with
modprobe ivtv ivtv_debug=10

OK. Happened again. The kernel log for the whole day since starting the module with debug this morning can be found at
http://brian.interlinx.bc.ca/ivtv-dmesg.txt.bz2.

Associated with that log there was a successful recording from 09:00:00 until 10:00:00 then another successful recording from 14:00:00 until 15:00:00 and then failed recordings starting at 15:00:00 until 18:00:00.

The log cuts off just short of 18:00:00 but there's nothing different about the pattern from the end of the log until 18:00:04 from the previous 3 hours or so.

It seems that the problem lies in amongst the start of these lines from the log, as my best guess:

Nov 28 15:00:05 cmurrell kernel: [868297.536049] ivtv0 encoder MPG: VIDIOC_ENCODER_CMD cmd=0, flags=0
Nov 28 15:00:07 cmurrell kernel: [868300.039324] ivtv0:  ioctl: V4L2_ENC_CMD_STOP
Nov 28 15:00:07 cmurrell kernel: [868300.039330] ivtv0:  info: close stopping capture
Nov 28 15:00:07 cmurrell kernel: [868300.039334] ivtv0:  info: Stop Capture
Nov 28 15:00:09 cmurrell kernel: [868302.140151] ivtv0 encoder MPG: VIDIOC_ENCODER_CMD cmd=1, flags=1
Nov 28 15:00:09 cmurrell kernel: [868302.148093] ivtv0:  ioctl: V4L2_ENC_CMD_START
Nov 28 15:00:09 cmurrell kernel: [868302.148101] ivtv0:  info: Start encoder stream encoder MPG
Nov 28 15:00:09 cmurrell kernel: [868302.188580] ivtv0:  info: Setup VBI API header 0x0000bd03 pkts 1 buffs 4 ln 24 sz 1456
Nov 28 15:00:09 cmurrell kernel: [868302.188655] ivtv0:  info: Setup VBI start 0x002fea04 frames 4 fpi 1
Nov 28 15:00:09 cmurrell kernel: [868302.191952] ivtv0:  info: PGM Index at 0x00180150 with 400 elements
Nov 28 15:00:10 cmurrell kernel: [868302.544052] ivtv0 encoder MPG: VIDIOC_ENCODER_CMD cmd=0, flags=0
Nov 28 15:00:12 cmurrell kernel: [868305.047260] ivtv0:  ioctl: V4L2_ENC_CMD_STOP
Nov 28 15:00:12 cmurrell kernel: [868305.047265] ivtv0:  info: close stopping capture
Nov 28 15:00:12 cmurrell kernel: [868305.047270] ivtv0:  info: Stop Capture

...

FWIW, the recording software here is MythTV completely up to date on the 0.25-fixes branch.

Thoughts?

A message that is not in the archive (sent off-list or not yet received): CALF0-+X0yyQEw+jJCxuQO18gDagtyX-RZW_kurMPS69RQHNPMA@mail.gmail.com

Ezequiel Garcia

2012-11-29 15:29 UTC #7 lore raw

Hi Brian,

See my comments below.

Quoted 34 lines · Brian J. Murrell

Quoted 3 lines · Ezequiel Garcia
Try again with
modprobe ivtv ivtv_debug=10
OK. Happened again. The kernel log for the whole day since starting the module with debug this morning can be found at
http://brian.interlinx.bc.ca/ivtv-dmesg.txt.bz2.
Associated with that log there was a successful recording from 09:00:00 until 10:00:00 then another successful recording from 14:00:00 until 15:00:00 and then failed recordings starting at 15:00:00 until 18:00:00.
The log cuts off just short of 18:00:00 but there's nothing different about the pattern from the end of the log until 18:00:04 from the previous 3 hours or so.
It seems that the problem lies in amongst the start of these lines from the log, as my best guess:
Nov 28 15:00:05 cmurrell kernel: [868297.536049] ivtv0 encoder MPG: VIDIOC_ENCODER_CMD cmd=0, flags=0
Nov 28 15:00:07 cmurrell kernel: [868300.039324] ivtv0:  ioctl: V4L2_ENC_CMD_STOP
Nov 28 15:00:07 cmurrell kernel: [868300.039330] ivtv0:  info: close stopping capture
Nov 28 15:00:07 cmurrell kernel: [868300.039334] ivtv0:  info: Stop Capture
Nov 28 15:00:09 cmurrell kernel: [868302.140151] ivtv0 encoder MPG: VIDIOC_ENCODER_CMD cmd=1, flags=1
Nov 28 15:00:09 cmurrell kernel: [868302.148093] ivtv0:  ioctl: V4L2_ENC_CMD_START
Nov 28 15:00:09 cmurrell kernel: [868302.148101] ivtv0:  info: Start encoder stream encoder MPG
Nov 28 15:00:09 cmurrell kernel: [868302.188580] ivtv0:  info: Setup VBI API header 0x0000bd03 pkts 1 buffs 4 ln 24 sz 1456
Nov 28 15:00:09 cmurrell kernel: [868302.188655] ivtv0:  info: Setup VBI start 0x002fea04 frames 4 fpi 1
Nov 28 15:00:09 cmurrell kernel: [868302.191952] ivtv0:  info: PGM Index at 0x00180150 with 400 elements
Nov 28 15:00:10 cmurrell kernel: [868302.544052] ivtv0 encoder MPG: VIDIOC_ENCODER_CMD cmd=0, flags=0
Nov 28 15:00:12 cmurrell kernel: [868305.047260] ivtv0:  ioctl: V4L2_ENC_CMD_STOP
Nov 28 15:00:12 cmurrell kernel: [868305.047265] ivtv0:  info: close stopping capture
Nov 28 15:00:12 cmurrell kernel: [868305.047270] ivtv0:  info: Stop Capture

Quoted 7 lines

...
FWIW, the recording software here is MythTV completely up to date on the 0.25-fixes branch.
Thoughts?

Mmm, the log shows this repeating pattern:

---

Nov 28 17:54:46 cmurrell kernel: [878779.229702] ivtv0:  info: Setup
VBI start 0x002fea04 frames 4 fpi 1
Nov 28 17:54:46 cmurrell kernel: [878779.233129] ivtv0:  info: PGM
Index at 0x00180150 with 400 elements
Nov 28 17:54:47 cmurrell kernel: [878779.556039] ivtv0 encoder MPG:
VIDIOC_ENCODER_CMD cmd=0, flags=0
Nov 28 17:54:49 cmurrell kernel: [878782.059204] ivtv0:  ioctl:
V4L2_ENC_CMD_STOP
Nov 28 17:54:49 cmurrell kernel: [878782.059209] ivtv0:  info: close
stopping capture
Nov 28 17:54:49 cmurrell kernel: [878782.059214] ivtv0:  info: Stop Capture
Nov 28 17:54:51 cmurrell kernel: [878784.156135] ivtv0 encoder MPG:
VIDIOC_ENCODER_CMD cmd=1, flags=1
Nov 28 17:54:51 cmurrell kernel: [878784.166157] ivtv0:  ioctl:
V4L2_ENC_CMD_START
Nov 28 17:54:51 cmurrell kernel: [878784.166165] ivtv0:  info: Start

encoder stream encoder MPG
---

And from 15:00 to 18:00 recording fails?

Perhaps it would make sense to restart application upon driver failure, now that output is more verbose.

Regards,

Ezequiel

PS: Please don't drop linux-media list from Cc

Andy Walls

2012-11-29 15:50 UTC #8 lore raw

Quoted 66 lines · Ezequiel Garcia

Hi Brian,
See my comments below.
Quoted 34 lines · Brian J. Murrell
Quoted 3 lines · Ezequiel Garcia
Try again with
modprobe ivtv ivtv_debug=10
OK. Happened again. The kernel log for the whole day since starting the module with debug this morning can be found at
http://brian.interlinx.bc.ca/ivtv-dmesg.txt.bz2.
Associated with that log there was a successful recording from 09:00:00 until 10:00:00 then another successful recording from 14:00:00 until 15:00:00 and then failed recordings starting at 15:00:00 until 18:00:00.
The log cuts off just short of 18:00:00 but there's nothing different about the pattern from the end of the log until 18:00:04 from the previous 3 hours or so.
It seems that the problem lies in amongst the start of these lines from the log, as my best guess:
Nov 28 15:00:05 cmurrell kernel: [868297.536049] ivtv0 encoder MPG: VIDIOC_ENCODER_CMD cmd=0, flags=0
Nov 28 15:00:07 cmurrell kernel: [868300.039324] ivtv0:  ioctl: V4L2_ENC_CMD_STOP
Nov 28 15:00:07 cmurrell kernel: [868300.039330] ivtv0:  info: close stopping capture
Nov 28 15:00:07 cmurrell kernel: [868300.039334] ivtv0:  info: Stop Capture
Nov 28 15:00:09 cmurrell kernel: [868302.140151] ivtv0 encoder MPG: VIDIOC_ENCODER_CMD cmd=1, flags=1
Nov 28 15:00:09 cmurrell kernel: [868302.148093] ivtv0:  ioctl: V4L2_ENC_CMD_START
Nov 28 15:00:09 cmurrell kernel: [868302.148101] ivtv0:  info: Start encoder stream encoder MPG
Nov 28 15:00:09 cmurrell kernel: [868302.188580] ivtv0:  info: Setup VBI API header 0x0000bd03 pkts 1 buffs 4 ln 24 sz 1456
Nov 28 15:00:09 cmurrell kernel: [868302.188655] ivtv0:  info: Setup VBI start 0x002fea04 frames 4 fpi 1
Nov 28 15:00:09 cmurrell kernel: [868302.191952] ivtv0:  info: PGM Index at 0x00180150 with 400 elements
Nov 28 15:00:10 cmurrell kernel: [868302.544052] ivtv0 encoder MPG: VIDIOC_ENCODER_CMD cmd=0, flags=0
Nov 28 15:00:12 cmurrell kernel: [868305.047260] ivtv0:  ioctl: V4L2_ENC_CMD_STOP
Nov 28 15:00:12 cmurrell kernel: [868305.047265] ivtv0:  info: close stopping capture
Nov 28 15:00:12 cmurrell kernel: [868305.047270] ivtv0:  info: Stop Capture
Quoted 7 lines
...
FWIW, the recording software here is MythTV completely up to date on the 0.25-fixes branch.
Thoughts?
Mmm, the log shows this repeating pattern:
---
Nov 28 17:54:46 cmurrell kernel: [878779.229702] ivtv0:  info: Setup
VBI start 0x002fea04 frames 4 fpi 1
Nov 28 17:54:46 cmurrell kernel: [878779.233129] ivtv0:  info: PGM
Index at 0x00180150 with 400 elements
Nov 28 17:54:47 cmurrell kernel: [878779.556039] ivtv0 encoder MPG:
VIDIOC_ENCODER_CMD cmd=0, flags=0
Nov 28 17:54:49 cmurrell kernel: [878782.059204] ivtv0:  ioctl:
V4L2_ENC_CMD_STOP
Nov 28 17:54:49 cmurrell kernel: [878782.059209] ivtv0:  info: close
stopping capture
Nov 28 17:54:49 cmurrell kernel: [878782.059214] ivtv0:  info: Stop Capture
Nov 28 17:54:51 cmurrell kernel: [878784.156135] ivtv0 encoder MPG:
VIDIOC_ENCODER_CMD cmd=1, flags=1
Nov 28 17:54:51 cmurrell kernel: [878784.166157] ivtv0:  ioctl:
V4L2_ENC_CMD_START
Nov 28 17:54:51 cmurrell kernel: [878784.166165] ivtv0:  info: Start

Quoted 7 lines

encoder stream encoder MPG
---
And from 15:00 to 18:00 recording fails?
Perhaps it would make sense to restart application upon driver failure, now that output is more verbose.

Hi Ezequiel,

Nope. IIRC, that's just MythTV timing-out, closing the device node, and reopening the device node, in attempt to make things work again.

Hi Brian,
I haven't checked the log you provided yet, but you'll likely need to set the module debug flags a little more verbose.

/sbin/modinfo ivtv | less
[...]
parm: debug:Debug level (bitmask). Default: 0

			   1/0x0001: warning
			   2/0x0002: info
			   4/0x0004: mailbox
			   8/0x0008: ioctl
			  16/0x0010: file
			  32/0x0020: dma
			  64/0x0040: irq
			 128/0x0080: decoder
			 256/0x0100: yuv
			 512/0x0200: i2c
			1024/0x0400: high volume

[..]

So maybe as root

# echo 0x07f > /sys/module/ivtv/parameters/debug

until the problem appears. Then once you experience the problem change it to high volume

# echo 0x47f > /sys/module/ivtv/parameters/debug

You may want to also get a baseline of what a good capture looks like using high volume debugging. Be aware that high volume debugging will fill up your logs and degrade performance a little, so you don't want to normally use high volume debugging.

Quoted 5 lines

Regards,
Ezequiel
PS: Please don't drop linux-media list from Cc

The ideas or interest of one individual often spurs that of others.

Regards,
Andy

Brian J. Murrell

author

2012-11-29 16:12 UTC #9 lore raw

Quoted 5 lines · Andy Walls

Hi Ezequiel,
Nope. IIRC, that's just MythTV timing-out, closing the device node, and reopening the device node, in attempt to make things work again.

Seems a very reasonable explanation.

Quoted 1 line

Hi Brian,

Hi Andy,

Quoted 2 lines

I haven't checked the log you provided yet, but you'll likely need to set the module debug flags a little more verbose.

OK.

Quoted 14 lines

/sbin/modinfo ivtv | less
[...]
parm: debug:Debug level (bitmask). Default: 0

			   1/0x0001: warning
			   2/0x0002: info
			   4/0x0004: mailbox
			   8/0x0008: ioctl
			  16/0x0010: file
			  32/0x0020: dma
			  64/0x0040: irq
			 128/0x0080: decoder
			 256/0x0100: yuv
			 512/0x0200: i2c
			1024/0x0400: high volume

Quoted 8 lines

[..]
So maybe as root
# echo 0x07f > /sys/module/ivtv/parameters/debug
until the problem appears. Then once you experience the problem change it to high volume

Will waiting for MythTV to report an error, such as:

MPEGRec(/dev/video1): Device error detected

be too late to turn up debugging or should that be sufficient enough timing?

Although, MythTV seems to report that error at the end of every recording so I'm not sure how I will filter out the false reports -- unless I write a smarter (i.e. than a single line match) log watcher. Anyway, that's my problem, not yours. :-)

Quoted 4 lines

# echo 0x47f > /sys/module/ivtv/parameters/debug
You may want to also get a baseline of what a good capture looks like using high volume debugging.

Just did that. Reduced to 0x07f after about a minute and 23 seconds.

Quoted 3 lines

Be aware that high volume debugging will
fill up your logs and degrade performance a little, so you don't want to normally use high volume debugging.

Indeed, it's quite verbose.

Quoted 3 lines

+1
The ideas or interest of one individual often spurs that of others.

Indeed, I always keep list replies on list and as I mentioned to Ezequiel (sorry Ezequiel, I got your name wrong on my previous post. my apologies) and I am seeing the copies -- but through gmane. I don't see the copies on the spincs.net archive. I suspect there is a lag at gmane posting to the list.

In any case, I have CC'd this one directly to the list @vger.kernel.org and will just hope it has an open posting policy.

Cheers and thanks much!

Brian J. Murrell

author

2012-11-29 19:47 UTC #10 lore raw

In reply to Andy Walls

Quoted 2 lines · Andy Walls

until the problem appears.

I'm afraid I didn't notice the problem until about 40m into the recording bug given that MythTV is in a loop repeatedly opening the card and trying to use it perhaps the high volume even 40 minutes into the recording is useful.

Quoted 4 lines

Then once you experience the problem change
it to high volume
# echo 0x47f > /sys/module/ivtv/parameters/debug

It seems to be a loop of:

Nov 29 14:39:47 cmurrell kernel: [953479.593771] ivtv0:  file: Encoder poll
Nov 29 14:39:47 cmurrell kernel: [953479.594127] ivtv0:  ioctl: V4L2_ENC_CMD_STOP
Nov 29 14:39:47 cmurrell kernel: [953479.594131] ivtv0:  file: close() of encoder MPG
Nov 29 14:39:47 cmurrell kernel: [953479.594134] ivtv0:  info: close stopping capture
Nov 29 14:39:47 cmurrell kernel: [953479.594137] ivtv0:  info: Stop Capture
Nov 29 14:39:47 cmurrell kernel: [953479.594142] ivtv0:  mb: MB Call: CX2341X_ENC_STOP_CAPTURE
Nov 29 14:39:49 cmurrell kernel: [953481.592013] ivtv0:  warn: encoder MPG: EOS interrupt not received! stopping anyway.
Nov 29 14:39:49 cmurrell kernel: [953481.592021] ivtv0:  warn: encoder MPG: waited 2000 ms.
Nov 29 14:39:49 cmurrell kernel: [953481.692036] ivtv0:  mb: MB Call: CX2341X_ENC_STOP_CAPTURE
Nov 29 14:39:49 cmurrell kernel: [953481.692138] ivtv0 encoder MPG: VIDIOC_ENCODER_CMD cmd=1, flags=1
Nov 29 14:39:49 cmurrell kernel: [953481.692161] ivtv0:  file: close encoder MPG
Nov 29 14:39:49 cmurrell kernel: [953481.692165] ivtv0:  file: close() of encoder MPG
Nov 29 14:39:49 cmurrell kernel: [953481.692208] ivtv0:  file: open encoder MPG
Nov 29 14:39:49 cmurrell kernel: [953481.692211] ivtv0:  mb: MB Call: CX2341X_ENC_PING_FW
Nov 29 14:39:49 cmurrell kernel: [953481.692272] ivtv0:  mb: MB Call: CX2341X_ENC_MISC
Nov 29 14:39:49 cmurrell kernel: [953481.692348] ivtv0:  ioctl: V4L2_ENC_CMD_START
Nov 29 14:39:49 cmurrell kernel: [953481.692352] ivtv0:  info: Start encoder stream encoder MPG
Nov 29 14:39:49 cmurrell kernel: [953481.692356] ivtv0:  mb: MB Call: CX2341X_ENC_SET_DMA_BLOCK_SIZE
Nov 29 14:39:49 cmurrell kernel: [953481.692359] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VERT_CROP_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.692422] ivtv0:  mb: MB Call: CX2341X_ENC_MISC
Nov 29 14:39:49 cmurrell kernel: [953481.692485] ivtv0:  mb: MB Call: CX2341X_ENC_MISC
Nov 29 14:39:49 cmurrell kernel: [953481.692553] ivtv0:  mb: MB Call: CX2341X_ENC_MISC
Nov 29 14:39:49 cmurrell kernel: [953481.692617] ivtv0:  mb: MB Call: CX2341X_ENC_MISC
Nov 29 14:39:49 cmurrell kernel: [953481.692684] ivtv0:  mb: MB Call: CX2341X_ENC_SET_PLACEHOLDER
Nov 29 14:39:49 cmurrell kernel: [953481.692688] ivtv0:  mb: MB Call: CX2341X_ENC_SET_NUM_VSYNC_LINES
Nov 29 14:39:49 cmurrell kernel: [953481.692691] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.718739] ivtv0:  info: Setup VBI API header 0x0000bd03 pkts 1 buffs 4 ln 24 sz 1456
Nov 29 14:39:49 cmurrell kernel: [953481.718746] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_CONFIG
Nov 29 14:39:49 cmurrell kernel: [953481.718830] ivtv0:  info: Setup VBI start 0x002fea04 frames 4 fpi 1
Nov 29 14:39:49 cmurrell kernel: [953481.718834] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.718906] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.718978] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.719052] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.719126] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.719196] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.719269] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.719352] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.719445] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.719522] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.719592] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.719662] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.719732] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.719807] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.719893] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.719967] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.720060] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.720144] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.720213] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.720283] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.720351] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.720421] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.720497] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.720566] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.720635] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.720707] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.720778] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.720852] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.720922] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.720993] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.721063] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.721137] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.721208] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.721278] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.721348] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.721417] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.721492] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.721561] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.721629] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.721700] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.721770] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.721845] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.721914] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.721984] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.722054] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.722256] ivtv0:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
Nov 29 14:39:49 cmurrell kernel: [953481.722348] ivtv0:  mb: MB Call: CX2341X_ENC_SET_PGM_INDEX_INFO
Nov 29 14:39:49 cmurrell kernel: [953481.722412] ivtv0:  info: PGM Index at 0x00180150 with 400 elements
Nov 29 14:39:49 cmurrell kernel: [953481.722415] ivtv0:  mb: MB Call: CX2341X_ENC_SET_OUTPUT_PORT
Nov 29 14:39:49 cmurrell kernel: [953481.722419] ivtv0:  mb: MB Call: CX2341X_ENC_SET_FRAME_RATE
Nov 29 14:39:49 cmurrell kernel: [953481.727659] ivtv0:  mb: MB Call: CX2341X_ENC_SET_FRAME_SIZE
Nov 29 14:39:49 cmurrell kernel: [953481.727672] ivtv0:  mb: MB Call: CX2341X_ENC_SET_STREAM_TYPE
Nov 29 14:39:49 cmurrell kernel: [953481.727676] ivtv0:  mb: MB Call: CX2341X_ENC_SET_BIT_RATE
Nov 29 14:39:49 cmurrell kernel: [953481.727681] ivtv0:  mb: MB Call: CX2341X_ENC_SET_AUDIO_PROPERTIES
Nov 29 14:39:49 cmurrell kernel: [953481.727686] ivtv0:  mb: MB Call: CX2341X_ENC_MUTE_AUDIO
Nov 29 14:39:49 cmurrell kernel: [953481.727757] ivtv0:  mb: MB Call: CX2341X_ENC_SET_ASPECT_RATIO
Nov 29 14:39:49 cmurrell kernel: [953481.727761] ivtv0:  mb: MB Call: CX2341X_ENC_SET_GOP_PROPERTIES
Nov 29 14:39:49 cmurrell kernel: [953481.727765] ivtv0:  mb: MB Call: CX2341X_ENC_SET_GOP_CLOSURE
Nov 29 14:39:49 cmurrell kernel: [953481.727769] ivtv0:  mb: MB Call: CX2341X_ENC_SET_FRAME_DROP_RATE
Nov 29 14:39:49 cmurrell kernel: [953481.727772] ivtv0:  mb: MB Call: CX2341X_ENC_MUTE_VIDEO
Nov 29 14:39:49 cmurrell kernel: [953481.727883] ivtv0:  mb: MB Call: CX2341X_ENC_SET_DNR_FILTER_MODE
Nov 29 14:39:49 cmurrell kernel: [953481.727886] ivtv0:  mb: MB Call: CX2341X_ENC_SET_DNR_FILTER_PROPS
Nov 29 14:39:49 cmurrell kernel: [953481.727890] ivtv0:  mb: MB Call: CX2341X_ENC_SET_SPATIAL_FILTER_TYPE
Nov 29 14:39:49 cmurrell kernel: [953481.727894] ivtv0:  mb: MB Call: CX2341X_ENC_SET_CORING_LEVELS
Nov 29 14:39:49 cmurrell kernel: [953481.727898] ivtv0:  mb: MB Call: CX2341X_ENC_MISC
Nov 29 14:39:49 cmurrell kernel: [953482.044030] ivtv0:  mb: MB Call: CX2341X_ENC_INITIALIZE_INPUT
Nov 29 14:39:49 cmurrell kernel: [953482.047873] ivtv0:  mb: MB Call: CX2341X_ENC_START_CAPTURE
Nov 29 14:39:49 cmurrell kernel: [953482.060040] ivtv0 encoder MPG: VIDIOC_ENCODER_CMD cmd=0, flags=0
Nov 29 14:39:49 cmurrell kernel: [953482.060347] ivtv0:  file: Encoder poll

Cheers,
b.

Brian J. Murrell

author

2012-12-02 19:52 UTC #11 lore raw

Quoted 6 lines · Brian J. Murrell

I'm afraid I didn't notice the problem until about 40m into the recording bug given that MythTV is in a loop repeatedly opening the card and trying to use it perhaps the high volume even 40 minutes into the recording is useful.

Quoted 7 lines

Quoted 4 lines
Then once you experience the problem change
it to high volume
# echo 0x47f > /sys/module/ivtv/parameters/debug
It seems to be a loop of:
...

Was this information helpful? If not, please let me know what else I can provide to give you something you can diagnose with.

Cheers and much thanks,
b.

Brian J. Murrell

author

2012-12-05 14:12 UTC #12 lore raw

Quoted 3 lines · Brian J. Murrell

Was this information helpful? If not, please let me know what else I can provide to give you something you can diagnose with.

Here's something interesting...

When a tuner/encoder is blocking reads, the following is printed to the kernel log:

[1451927.797336] ivtv1:  file: open encoder MPG
[1451927.797344] ivtv1:  mb: MB Call: CX2341X_ENC_PING_FW
[1451927.797413] ivtv1:  mb: MB Call: CX2341X_ENC_MISC
[1451927.797513] ivtv1 encoder MPG: unknown ioctl 'T', dir=--, #1 (0x00005401) error -22
[1451927.797531] ivtv1:  info: Start encoder stream encoder MPG
[1451927.797535] ivtv1:  mb: MB Call: CX2341X_ENC_SET_DMA_BLOCK_SIZE
[1451927.797539] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VERT_CROP_LINE
[1451927.797609] ivtv1:  mb: MB Call: CX2341X_ENC_MISC
[1451927.797679] ivtv1:  mb: MB Call: CX2341X_ENC_MISC
[1451927.797752] ivtv1:  mb: MB Call: CX2341X_ENC_MISC
[1451927.797831] ivtv1:  mb: MB Call: CX2341X_ENC_MISC
[1451927.797904] ivtv1:  mb: MB Call: CX2341X_ENC_SET_PLACEHOLDER
[1451927.797907] ivtv1:  mb: MB Call: CX2341X_ENC_SET_NUM_VSYNC_LINES
[1451927.797911] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.821351] ivtv1:  info: Setup VBI API header 0x0000bd03 pkts 1 buffs 4 ln 24 sz 1456
[1451927.821358] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_CONFIG
[1451927.821439] ivtv1:  info: Setup VBI start 0x002fea04 frames 4 fpi 1
[1451927.821442] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.821519] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.821595] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.821673] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.821750] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.821828] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.821905] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.821980] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.822056] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.822135] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.822211] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.822289] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.822367] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.822443] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.822519] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.822594] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.822672] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.822749] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.822827] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.822902] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.822979] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.823057] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.823134] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.823211] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.823287] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.823363] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.823438] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.823516] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.823593] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.823670] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.823747] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.823826] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.823902] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.823979] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.824095] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.824174] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.824248] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.824324] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.824400] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.824478] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.824554] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.824629] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.824706] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.824782] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.824857] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.824934] ivtv1:  mb: MB Call: CX2341X_ENC_SET_VBI_LINE
[1451927.825009] ivtv1:  mb: MB Call: CX2341X_ENC_SET_PGM_INDEX_INFO
[1451927.825079] ivtv1:  info: PGM Index at 0x00180150 with 400 elements
[1451927.825082] ivtv1:  mb: MB Call: CX2341X_ENC_SET_OUTPUT_PORT
[1451927.825086] ivtv1:  mb: MB Call: CX2341X_ENC_SET_FRAME_RATE
[1451927.832028] ivtv1:  mb: MB Call: CX2341X_ENC_SET_FRAME_SIZE
[1451927.832042] ivtv1:  mb: MB Call: CX2341X_ENC_SET_STREAM_TYPE
[1451927.832046] ivtv1:  mb: MB Call: CX2341X_ENC_SET_BIT_RATE
[1451927.832051] ivtv1:  mb: MB Call: CX2341X_ENC_SET_AUDIO_PROPERTIES
[1451927.832055] ivtv1:  mb: MB Call: CX2341X_ENC_MUTE_AUDIO
[1451927.832130] ivtv1:  mb: MB Call: CX2341X_ENC_SET_ASPECT_RATIO
[1451927.832144] ivtv1:  mb: MB Call: CX2341X_ENC_SET_GOP_PROPERTIES
[1451927.832148] ivtv1:  mb: MB Call: CX2341X_ENC_SET_GOP_CLOSURE
[1451927.832151] ivtv1:  mb: MB Call: CX2341X_ENC_SET_FRAME_DROP_RATE
[1451927.832154] ivtv1:  mb: MB Call: CX2341X_ENC_MUTE_VIDEO
[1451927.832267] ivtv1:  mb: MB Call: CX2341X_ENC_SET_DNR_FILTER_MODE
[1451927.832271] ivtv1:  mb: MB Call: CX2341X_ENC_SET_DNR_FILTER_PROPS
[1451927.832274] ivtv1:  mb: MB Call: CX2341X_ENC_SET_SPATIAL_FILTER_TYPE
[1451927.832277] ivtv1:  mb: MB Call: CX2341X_ENC_SET_CORING_LEVELS
[1451927.832282] ivtv1:  mb: MB Call: CX2341X_ENC_MISC
[1451928.140030] ivtv1:  mb: MB Call: CX2341X_ENC_INITIALIZE_INPUT
[1451928.144018] ivtv1:  mb: MB Call: CX2341X_ENC_START_CAPTURE
[1451934.405980] ivtv1:  info: User stopped encoder MPG
[1451934.406074] ivtv1:  file: close encoder MPG
[1451934.406079] ivtv1:  file: close() of encoder MPG
[1451934.406082] ivtv1:  info: close stopping capture
[1451934.406085] ivtv1:  info: Stop Capture
[1451934.406089] ivtv1:  mb: MB Call: CX2341X_ENC_STOP_CAPTURE
[1451934.504032] ivtv1:  mb: MB Call: CX2341X_ENC_STOP_CAPTURE

The read(2) from /dev/video1 just doesn't get any data given to it while this is happening.

Cheers,
b.

Brian J. Murrell

author

2012-11-29 15:53 UTC #13 lore raw

In reply to Ezequiel Garcia

Quoted 1 line · Ezequiel Garcia

Hi Brian,

Hi Garcia,

Quoted 19 lines

Mmm, the log shows this repeating pattern:

---

Nov 28 17:54:46 cmurrell kernel: [878779.229702] ivtv0:  info: Setup
VBI start 0x002fea04 frames 4 fpi 1
Nov 28 17:54:46 cmurrell kernel: [878779.233129] ivtv0:  info: PGM
Index at 0x00180150 with 400 elements
Nov 28 17:54:47 cmurrell kernel: [878779.556039] ivtv0 encoder MPG:
VIDIOC_ENCODER_CMD cmd=0, flags=0
Nov 28 17:54:49 cmurrell kernel: [878782.059204] ivtv0:  ioctl:
V4L2_ENC_CMD_STOP
Nov 28 17:54:49 cmurrell kernel: [878782.059209] ivtv0:  info: close
stopping capture
Nov 28 17:54:49 cmurrell kernel: [878782.059214] ivtv0:  info: Stop Capture
Nov 28 17:54:51 cmurrell kernel: [878784.156135] ivtv0 encoder MPG:
VIDIOC_ENCODER_CMD cmd=1, flags=1
Nov 28 17:54:51 cmurrell kernel: [878784.166157] ivtv0:  ioctl:
V4L2_ENC_CMD_START
Nov 28 17:54:51 cmurrell kernel: [878784.166165] ivtv0:  info: Start

Quoted 1 line

encoder stream encoder MPG

Yes, as I indicated.

Quoted 1 line

And from 15:00 to 18:00 recording fails?

Yes.

Quoted 2 lines

Perhaps it would make sense to restart application upon driver failure, now that output is more verbose.

Meaning what exactly? Restart MythTV? How would I restart MythTV when the failure occurs? Do you mean like having a daemon watching dmesg that restarts MythTV when this happens? That's a very ugly hack-around that will have negative side effects per below...

This failure doesn't necessarily affect all tuners at the same time so I would potentially be restarting MythTV while other tuners are recording, interrupting good recordings to fix one tuner which is having a problem.

I am sure you would agree that this is not really a suitable work-around, yes?

Quoted 1 line

PS: Please don't drop linux-media list from Cc

I don't think I did. All of my messages have been copied to the list, albeit I post them through gmane rather than posting to the list directly since I read via gmane and am not a direct subscriber to the list. Most lists will disallow postings by non-subscribers. I know vger.kernel.org does allow posting by non-subscribers on at least some of their lists but I am not aware of it being a site-wide policy or not so to be on the safe side I just let gmane post it to the list.

Perhaps you got the copy I CC'd to you directly before you got the copy that went to the list via gmane.

Cheers,
b.

Ezequiel Garcia

2012-11-29 16:40 UTC #14 lore raw

Hi Brian,

On Thu, Nov 29, 2012 at 12:53 PM, Brian J. Murrell <[email protected]> wrote:
[...]

Quoted 4 lines

I am sure you would agree that this is not really a suitable work-around, yes?

I meant doing that just as a debug trial to know if maybe MythTV was doing something wrong.

Andy already answered explaining this shouldn't be the case.

In fact now that Andy is helping you,
you'll get far better help from him than from me.

Quoted 2 lines

Quoted 1 line
PS: Please don't drop linux-media list from Cc

[...]

Quoted 4 lines

Perhaps you got the copy I CC'd to you directly before you got the copy that went to the list via gmane.

Well, this very mail I'm answering appears as being sent to me alone. However, the mail can be found on mail-archive so it must be something in the way I got it. Never mind.

Thanks,

Ezequiel