Re: [PATCH 1/2]: media: hdpvr: Add adaptive sleeping in hdpvr_start_streaming
On 08/07/19 04:58, Hans Verkuil wrote: > On 8/4/19 12:09 AM, Keith Pyle wrote: >> The hdpvr firmware reacts poorly to a fast close/open sequence. Delaying >> a few seconds between the close and next open produces generally reliable >> results. Rather than requiring user programs to implement this delay and >> coordinate among themselves when the device is handed from one program to >> another, add kernel support for delaying the attempt to start streaming if >> the device only recently stopped streaming. A delay of 4 seconds seems to >> be sufficient, but some administrators may wish to push their luck by >> trying shorter delays. To allow administrators to change the delay, add a >> new parameter to the hdpvr module: `hdpvr_close_to_open_ms_delay`, which >> specifies the delay in milliseconds between a close and subsequent >> start-streaming. If the user application has already delayed by at least >> that long for its own reasons, this feature will add no further delay. >> >> Signed-off-by: Keith Pyle >> Tested-by: Keith Pyle >> --- >> Changes since v2: >> - Rewrapped comments again, per request from Hans. >> - Per advice from checkpatch.pl --strict (suggested by Hans), added >> spacing around `|` for mode permissions. This satisfies checkpatch, >> but reduces consistency in hdpvr-core.c, which had preexisting uses that >> violate checkpatch --strict. > That's OK. > >> - Changed indentation of declaration of jiffies_next_start_streaming to >> line up when viewed with tabstop=8. >> Changes since v1: >> - Rewrapped output at 80 columns, per request from Hans. Literal strings >> still exceed 80 columns where necessary to keep an entire string together, >> since this makes it easier for grep to find the file and line that >> generates a given message. >> - Reviewed Hans request to use `jiffies` instead of `get_jiffies_64()`. >> Per the documentation, raw `jiffies` appears to be inappropriate > Per what documentation? 'jiffies' is used everywhere, so this makes no sense. > Just look at the use counts: > > $ git grep [^_a-z0-9]jiffies[^_a-z0-9]|wc > 10712 60812 810344 > $ git grep get_jiffies_64|wc > 83 4016342 > > get_jiffies_64() should only be used in the rare cases where you need a > 64-bit jiffies value, even on a 32-bit system. That's not needed here. > > Doing unusual things requires a good reason, and there is no good reason > to use get_jiffies_64 here. As I explained on July 26, there is a good reason to use a 64 jiffies: to avoid jiffies rollover on a 32-bit system. I stated: > Actually, it isn't. Contrary to your interpretation, we intentionally used > the 64 bit value for jiffies on both 32 and 64 > bit systems since the get_jiffies_64 macro returns a u64 in all cases. > Recording systems using HD-PVR devices frequently > have long uptimes, so rollover of a 32-bit jiffies value could be a problem > (i.e., the necessary delay before a streaming > restart would be missing in the event of a rollover). Extra code for > rollover detection would be needed. > Also, include/linux/jiffies.h specifically says "The 64-bit value is not > atomic - you MUST NOT read it...", so we use the > get_jiffies_64 macro as the header recommends. On a 64-bit system, the macro > becomes an inline return of jiffies. On a > 32-bit system, it becomes an appropriate function call. I don't see any reason to knowingly introduce a roll-over bug for the 32-bit builds, even if it would be a low probability issue. Since we continue to disagree on this point, you can consider both of these patches withdrawn. >> on 32-bit systems, so the patch continues to use `get_jiffies_64()`. >> On 64-bit systems, `get_jiffies_64()` becomes a direct read of `jiffies`. >> Further, both uses of `get_jiffies_64()` are on relatively cold paths >> (one just before starting streaming, the other just before a 10ms >> hardcoded sleep), so the performance impact even on the 32-bit path >> should be trivial relative to the time required for the surrounding code. >> --- >> drivers/media/usb/hdpvr/hdpvr-core.c | 4 >> drivers/media/usb/hdpvr/hdpvr-video.c | 22 ++ >> drivers/media/usb/hdpvr/hdpvr.h | 5 + >> 3 files changed, 31 insertions(+) >> >> diff --git a/drivers/media/usb/hdpvr/hdpvr-core.c >> b/drivers/media/usb/hdpvr/hdpvr-core.c >> index 23d3d0754308..a3d2f632fe38 100644 >> --- a/drivers/media/usb/hdpvr/hdpvr-core.c >> +++ b/drivers/media/usb/hdpvr/hdpvr-core.c >> @@ -39,6 +39,10 @@ int hdpvr_debug; >> module_param(hdpvr_debug, int, S_IRUGO
[PATCH 1/2]: media: hdpvr: Add adaptive sleeping in hdpvr_start_streaming
The hdpvr firmware reacts poorly to a fast close/open sequence. Delaying
a few seconds between the close and next open produces generally reliable
results. Rather than requiring user programs to implement this delay and
coordinate among themselves when the device is handed from one program to
another, add kernel support for delaying the attempt to start streaming if
the device only recently stopped streaming. A delay of 4 seconds seems to
be sufficient, but some administrators may wish to push their luck by
trying shorter delays. To allow administrators to change the delay, add a
new parameter to the hdpvr module: `hdpvr_close_to_open_ms_delay`, which
specifies the delay in milliseconds between a close and subsequent
start-streaming. If the user application has already delayed by at least
that long for its own reasons, this feature will add no further delay.
Signed-off-by: Keith Pyle
Tested-by: Keith Pyle
---
Changes since v2:
- Rewrapped comments again, per request from Hans.
- Per advice from checkpatch.pl --strict (suggested by Hans), added
spacing around `|` for mode permissions. This satisfies checkpatch,
but reduces consistency in hdpvr-core.c, which had preexisting uses that
violate checkpatch --strict.
- Changed indentation of declaration of jiffies_next_start_streaming to
line up when viewed with tabstop=8.
Changes since v1:
- Rewrapped output at 80 columns, per request from Hans. Literal strings
still exceed 80 columns where necessary to keep an entire string together,
since this makes it easier for grep to find the file and line that
generates a given message.
- Reviewed Hans request to use `jiffies` instead of `get_jiffies_64()`.
Per the documentation, raw `jiffies` appears to be inappropriate
on 32-bit systems, so the patch continues to use `get_jiffies_64()`.
On 64-bit systems, `get_jiffies_64()` becomes a direct read of `jiffies`.
Further, both uses of `get_jiffies_64()` are on relatively cold paths
(one just before starting streaming, the other just before a 10ms
hardcoded sleep), so the performance impact even on the 32-bit path
should be trivial relative to the time required for the surrounding code.
---
drivers/media/usb/hdpvr/hdpvr-core.c | 4
drivers/media/usb/hdpvr/hdpvr-video.c | 22 ++
drivers/media/usb/hdpvr/hdpvr.h | 5 +
3 files changed, 31 insertions(+)
diff --git a/drivers/media/usb/hdpvr/hdpvr-core.c
b/drivers/media/usb/hdpvr/hdpvr-core.c
index 23d3d0754308..a3d2f632fe38 100644
--- a/drivers/media/usb/hdpvr/hdpvr-core.c
+++ b/drivers/media/usb/hdpvr/hdpvr-core.c
@@ -39,6 +39,10 @@ int hdpvr_debug;
module_param(hdpvr_debug, int, S_IRUGO|S_IWUSR);
MODULE_PARM_DESC(hdpvr_debug, "enable debugging output");
+uint hdpvr_close_to_open_ms_delay = 4000;
+module_param(hdpvr_close_to_open_ms_delay, uint, S_IRUGO | S_IWUSR);
+MODULE_PARM_DESC(hdpvr_close_to_open_ms_delay, "delay restarting streaming by
the specified number of milliseconds");
+
static uint default_video_input = HDPVR_VIDEO_INPUTS;
module_param(default_video_input, uint, S_IRUGO|S_IWUSR);
MODULE_PARM_DESC(default_video_input, "default video input: 0=Component /
1=S-Video / 2=Composite");
diff --git a/drivers/media/usb/hdpvr/hdpvr-video.c
b/drivers/media/usb/hdpvr/hdpvr-video.c
index 3d199d5d6738..7e5897dd8dff 100644
--- a/drivers/media/usb/hdpvr/hdpvr-video.c
+++ b/drivers/media/usb/hdpvr/hdpvr-video.c
@@ -278,6 +278,8 @@ static int hdpvr_start_streaming(struct hdpvr_device *dev)
{
int ret;
struct hdpvr_video_info vidinf;
+ u64 now_jiffies, delta_jiffies;
+ uint msec_to_sleep;
if (dev->status == STATUS_STREAMING)
return 0;
@@ -298,6 +300,22 @@ static int hdpvr_start_streaming(struct hdpvr_device *dev)
v4l2_dbg(MSG_BUFFER, hdpvr_debug, &dev->v4l2_dev,
"video signal: %dx%d@%dhz\n", vidinf.width,
vidinf.height, vidinf.fps);
+ now_jiffies = get_jiffies_64();
+ /* inline time_after64 since the result of the subtraction is needed for
+* the sleep
+*/
+ delta_jiffies = dev->jiffies_next_start_streaming - now_jiffies;
+ if ((__s64)delta_jiffies > 0) {
+ /* device firmware may not be ready yet */
+ msec_to_sleep = jiffies_to_msecs(delta_jiffies);
+ v4l2_dbg(MSG_INFO, hdpvr_debug, &dev->v4l2_dev,
+"firmware may not be ready, sleeping for %u ms\n",
+msec_to_sleep);
+ msleep(msec_to_sleep);
+ } else {
+ v4l2_dbg(MSG_INFO, hdpvr_debug, &dev->v4l2_dev,
+"firmware assumed to be ready, not sleeping\n");
+ }
/* start streaming 2 request */
hdpvr_usb_lock(dev, HDPVR_USB_CTRL);
@@ -332,6 +350,7 @@ static int hdpvr_stop_streaming(struct hdpvr_device *dev)
int actu
[PATCH 2/2]: media: hdpvr: Add optional restart, with optional delay, after restarting streaming
`hdpvr_read` attempts to restart streaming if the device is read while
it is both not ready and not disconnected. However, the device is often
still not ready immediately after the call to `hdpvr_start_streaming`
returns, causing the condition `if (buf->status != BUFSTAT_READY)` to
exit the loop without reading any further data. By itself, this would
merely cause a short read, which should be easily recoverable. However,
if no data has been read so far, this causes `hdpvr_read` to return 0,
which results in an end-of-file for the user application.
Compensate for this by adding the ability to delay after the call to
`hdpvr_start_streaming`, then `continue;` back to the top, so that
`hdpvr_read` can call `wait_event_interruptible_timeout` again to wait
for the device to become ready. This delay complements the prior patch.
The prior patch delays before issuing the start-streaming command, to
give the firmware time to stabilize before receiving the command. This
delay is after the start-streaming command, to give the firmware time to
bring the device to a ready state. This delay is configurable through a
new module parameter, `hdpvr_restart_streaming_ms_delay`, which defaults
to a 100 millisecond delay.
To avoid an infinite loop in `hdpvr_read`, add a limit to how many times
`hdpvr_read` can restart the device before returning. This limit is
configurable through a new module parameter,
`hdpvr_restart_streaming_max_tries`, and defaults to one restart.
Administrators may set the limit to 0 to request that `hdpvr_read` never
attempt to restart streaming. Previously, there was no way for
administrators to opt out of an attempted restart.
Signed-off-by: Keith Pyle
Tested-by: Keith Pyle
---
Changes since v2:
- Rewrapped comments again, per request from Hans.
- Per advice from checkpatch.pl --strict (suggested by Hans), added
spacing around `|` for mode permissions. This satisfies checkpatch,
but reduces consistency in hdpvr-core.c, which had preexisting uses that
violate checkpatch --strict.
- Per request from Hans, switched from pre-decrement to post-decrement.
Changes since v1:
- Rewrapped output at 80 columns, per request from Hans. Literal strings
still exceed 80 columns where necessary to keep an entire string together,
since this makes it easier for grep to find the file and line that
generates a given message.
---
drivers/media/usb/hdpvr/hdpvr-core.c | 8 ++
drivers/media/usb/hdpvr/hdpvr-video.c | 36 +++
drivers/media/usb/hdpvr/hdpvr.h | 2 ++
3 files changed, 46 insertions(+)
diff --git a/drivers/media/usb/hdpvr/hdpvr-core.c
b/drivers/media/usb/hdpvr/hdpvr-core.c
index a3d2f632fe38..1be3911e43ed 100644
--- a/drivers/media/usb/hdpvr/hdpvr-core.c
+++ b/drivers/media/usb/hdpvr/hdpvr-core.c
@@ -43,6 +43,14 @@ uint hdpvr_close_to_open_ms_delay = 4000;
module_param(hdpvr_close_to_open_ms_delay, uint, S_IRUGO | S_IWUSR);
MODULE_PARM_DESC(hdpvr_close_to_open_ms_delay, "delay restarting streaming by
the specified number of milliseconds");
+uint hdpvr_restart_streaming_max_tries = 1;
+module_param(hdpvr_restart_streaming_max_tries, uint, S_IRUGO | S_IWUSR);
+MODULE_PARM_DESC(hdpvr_restart_streaming_max_tries, "restart streaming at most
this many times within one read");
+
+uint hdpvr_restart_streaming_ms_delay = 100;
+module_param(hdpvr_restart_streaming_ms_delay, uint, S_IRUGO | S_IWUSR);
+MODULE_PARM_DESC(hdpvr_restart_streaming_ms_delay, "delay continue by the
specified number of milliseconds after restarting streaming");
+
static uint default_video_input = HDPVR_VIDEO_INPUTS;
module_param(default_video_input, uint, S_IRUGO|S_IWUSR);
MODULE_PARM_DESC(default_video_input, "default video input: 0=Component /
1=S-Video / 2=Composite");
diff --git a/drivers/media/usb/hdpvr/hdpvr-video.c
b/drivers/media/usb/hdpvr/hdpvr-video.c
index 7e5897dd8dff..aa7b473b501b 100644
--- a/drivers/media/usb/hdpvr/hdpvr-video.c
+++ b/drivers/media/usb/hdpvr/hdpvr-video.c
@@ -441,6 +441,8 @@ static ssize_t hdpvr_read(struct file *file, char __user
*buffer, size_t count,
struct hdpvr_buffer *buf = NULL;
struct urb *urb;
unsigned int ret = 0;
+ unsigned int restarts_remaining = hdpvr_restart_streaming_max_tries;
+ unsigned int delay;
int rem, cnt;
if (*pos)
@@ -491,6 +493,19 @@ static ssize_t hdpvr_read(struct file *file, char __user
*buffer, size_t count,
goto err;
}
if (!err) {
+ if (restarts_remaining == 0) {
+ v4l2_dbg(MSG_BUFFER, hdpvr_debug,
+&dev->v4l2_dev,
+"timeout: no further restarts
allowed by hdpvr_restart_streaming_max_tries; returning to caller with ret=%u",
+
Re: [PATCH 1/2]: media: hdpvr: Add adaptive sleeping in hdpvr_start_streaming
On 07/25/19 02:10, Hans Verkuil wrote:
> On 7/7/19 11:15 PM, Keith Pyle wrote:
>> The hdpvr firmware reacts poorly to a fast close/open sequence. Delaying
>> a few seconds between the close and next open produces generally reliable
>> results. Rather than requiring user programs to implement this delay and
>> coordinate among themselves when the device is handed from one program to
>> another, add kernel support for delaying the attempt to start streaming if
>> the device only recently stopped streaming. A delay of 4 seconds seems to
>> be sufficient, but some administrators may wish to push their luck by
>> trying shorter delays. To allow administrators to change the delay, add a
>> new parameter to the hdpvr module: `hdpvr_close_to_open_ms_delay`, which
>> specifies the delay in milliseconds between a close and subsequent
>> start-streaming. If the user application has already delayed by at least
>> that long for its own reasons, this feature will add no further delay.
>>
>> Signed-off-by: Keith Pyle
>> Tested-by: Keith Pyle
>> ---
>> Changes since v1:
>> - Rewrapped output at 80 columns, per request from Hans. Literal strings
>> still exceed 80 columns where necessary to keep an entire string together,
>> since this makes it easier for grep to find the file and line that
>> generates a given message.
>> - Reviewed Hans request to use `jiffies` instead of `get_jiffies_64()`.
>> Per the documentation, raw `jiffies` appears to be inappropriate
>> on 32-bit systems, so the patch continues to use `get_jiffies_64()`.
> That's news to all the 32-bit systems that have been using jiffies since the
> dawn of time.
>
> Please use jiffies, like everyone else. 'jiffies' is an unsigned long, so
> 32 bits on a 32 bit system and 64 bit on a 64 bit system. Just want you
> want.
Actually, it isn't. Contrary to your interpretation, we intentionally used the
64 bit value for jiffies on both 32 and 64 bit systems since the get_jiffies_64
macro returns a u64 in all cases. Recording systems using HD-PVR devices
frequently have long uptimes, so rollover of a 32-bit jiffies value could be a
problem (i.e., the necessary delay before a streaming restart would be missing
in the event of a rollover). Extra code for rollover detection would be needed.
Also, include/linux/jiffies.h specifically says "The 64-bit value is not atomic
- you MUST NOT read it...", so we use the get_jiffies_64 macro as the header
recommends. On a 64-bit system, the macro becomes an inline return of jiffies.
On a 32-bit system, it becomes an appropriate function call.
>> On 64-bit systems, `get_jiffies_64()` becomes a direct read of `jiffies`.
>> Further, both uses of `get_jiffies_64()` are on relatively cold paths
>> (one just before starting streaming, the other just before a 10ms
>> hardcoded sleep), so the performance impact even on the 32-bit path
>> should be trivial relative to the time required for the surrounding code.
>> ---
>> drivers/media/usb/hdpvr/hdpvr-core.c | 4
>> drivers/media/usb/hdpvr/hdpvr-video.c | 22 ++
>> drivers/media/usb/hdpvr/hdpvr.h | 5 +
>> 3 files changed, 31 insertions(+)
>>
>> diff --git a/drivers/media/usb/hdpvr/hdpvr-core.c
>> b/drivers/media/usb/hdpvr/hdpvr-core.c
>> index 23d3d0754308..fd7608e7e94c 100644
>> --- a/drivers/media/usb/hdpvr/hdpvr-core.c
>> +++ b/drivers/media/usb/hdpvr/hdpvr-core.c
>> @@ -39,6 +39,10 @@ int hdpvr_debug;
>> module_param(hdpvr_debug, int, S_IRUGO|S_IWUSR);
>> MODULE_PARM_DESC(hdpvr_debug, "enable debugging output");
>>
>> +uint hdpvr_close_to_open_ms_delay = 4000;
>> +module_param(hdpvr_close_to_open_ms_delay, uint, S_IRUGO|S_IWUSR);
>> +MODULE_PARM_DESC(hdpvr_close_to_open_ms_delay, "delay restarting streaming
>> by the specified number of milliseconds");
>> +
>> static uint default_video_input = HDPVR_VIDEO_INPUTS;
>> module_param(default_video_input, uint, S_IRUGO|S_IWUSR);
>> MODULE_PARM_DESC(default_video_input, "default video input: 0=Component /
>> 1=S-Video / 2=Composite");
>> diff --git a/drivers/media/usb/hdpvr/hdpvr-video.c
>> b/drivers/media/usb/hdpvr/hdpvr-video.c
>> index 3d199d5d6738..8a2b883d372e 100644
>> --- a/drivers/media/usb/hdpvr/hdpvr-video.c
>> +++ b/drivers/media/usb/hdpvr/hdpvr-video.c
>> @@ -278,6 +278,8 @@ static int hdpvr_start_streaming(struct hdpvr_device
>> *dev)
>> {
>> int ret;
>> struct hdpvr_video_info vidinf;
>> +u64 now_jiffies, delta_jiffies;
>> +uint msec_to_sleep;
>>
[PATCH 1/2]: media: hdpvr: Add adaptive sleeping in hdpvr_start_streaming
The hdpvr firmware reacts poorly to a fast close/open sequence. Delaying
a few seconds between the close and next open produces generally reliable
results. Rather than requiring user programs to implement this delay and
coordinate among themselves when the device is handed from one program to
another, add kernel support for delaying the attempt to start streaming if
the device only recently stopped streaming. A delay of 4 seconds seems to
be sufficient, but some administrators may wish to push their luck by
trying shorter delays. To allow administrators to change the delay, add a
new parameter to the hdpvr module: `hdpvr_close_to_open_ms_delay`, which
specifies the delay in milliseconds between a close and subsequent
start-streaming. If the user application has already delayed by at least
that long for its own reasons, this feature will add no further delay.
Signed-off-by: Keith Pyle
Tested-by: Keith Pyle
---
Changes since v1:
- Rewrapped output at 80 columns, per request from Hans. Literal strings
still exceed 80 columns where necessary to keep an entire string together,
since this makes it easier for grep to find the file and line that
generates a given message.
- Reviewed Hans request to use `jiffies` instead of `get_jiffies_64()`.
Per the documentation, raw `jiffies` appears to be inappropriate
on 32-bit systems, so the patch continues to use `get_jiffies_64()`.
On 64-bit systems, `get_jiffies_64()` becomes a direct read of `jiffies`.
Further, both uses of `get_jiffies_64()` are on relatively cold paths
(one just before starting streaming, the other just before a 10ms
hardcoded sleep), so the performance impact even on the 32-bit path
should be trivial relative to the time required for the surrounding code.
---
drivers/media/usb/hdpvr/hdpvr-core.c | 4
drivers/media/usb/hdpvr/hdpvr-video.c | 22 ++
drivers/media/usb/hdpvr/hdpvr.h | 5 +
3 files changed, 31 insertions(+)
diff --git a/drivers/media/usb/hdpvr/hdpvr-core.c
b/drivers/media/usb/hdpvr/hdpvr-core.c
index 23d3d0754308..fd7608e7e94c 100644
--- a/drivers/media/usb/hdpvr/hdpvr-core.c
+++ b/drivers/media/usb/hdpvr/hdpvr-core.c
@@ -39,6 +39,10 @@ int hdpvr_debug;
module_param(hdpvr_debug, int, S_IRUGO|S_IWUSR);
MODULE_PARM_DESC(hdpvr_debug, "enable debugging output");
+uint hdpvr_close_to_open_ms_delay = 4000;
+module_param(hdpvr_close_to_open_ms_delay, uint, S_IRUGO|S_IWUSR);
+MODULE_PARM_DESC(hdpvr_close_to_open_ms_delay, "delay restarting streaming by
the specified number of milliseconds");
+
static uint default_video_input = HDPVR_VIDEO_INPUTS;
module_param(default_video_input, uint, S_IRUGO|S_IWUSR);
MODULE_PARM_DESC(default_video_input, "default video input: 0=Component /
1=S-Video / 2=Composite");
diff --git a/drivers/media/usb/hdpvr/hdpvr-video.c
b/drivers/media/usb/hdpvr/hdpvr-video.c
index 3d199d5d6738..8a2b883d372e 100644
--- a/drivers/media/usb/hdpvr/hdpvr-video.c
+++ b/drivers/media/usb/hdpvr/hdpvr-video.c
@@ -278,6 +278,8 @@ static int hdpvr_start_streaming(struct hdpvr_device *dev)
{
int ret;
struct hdpvr_video_info vidinf;
+ u64 now_jiffies, delta_jiffies;
+ uint msec_to_sleep;
if (dev->status == STATUS_STREAMING)
return 0;
@@ -298,6 +300,22 @@ static int hdpvr_start_streaming(struct hdpvr_device *dev)
v4l2_dbg(MSG_BUFFER, hdpvr_debug, &dev->v4l2_dev,
"video signal: %dx%d@%dhz\n", vidinf.width,
vidinf.height, vidinf.fps);
+ now_jiffies = get_jiffies_64();
+ /* inline time_after64 since the result of the subtraction is needed
+* for the sleep
+*/
+ delta_jiffies = dev->jiffies_next_start_streaming - now_jiffies;
+ if ((__s64)delta_jiffies > 0) {
+ /* device firmware may not be ready yet */
+ msec_to_sleep = jiffies_to_msecs(delta_jiffies);
+ v4l2_dbg(MSG_INFO, hdpvr_debug, &dev->v4l2_dev,
+"firmware may not be ready, sleeping for %u ms\n",
+msec_to_sleep);
+ msleep(msec_to_sleep);
+ } else {
+ v4l2_dbg(MSG_INFO, hdpvr_debug, &dev->v4l2_dev,
+"firmware assumed to be ready, not sleeping\n");
+ }
/* start streaming 2 request */
hdpvr_usb_lock(dev, HDPVR_USB_CTRL);
@@ -332,6 +350,7 @@ static int hdpvr_stop_streaming(struct hdpvr_device *dev)
int actual_length;
uint c = 0;
u8 *buf;
+ u64 now_jiffies;
if (dev->status == STATUS_IDLE)
return 0;
@@ -368,6 +387,9 @@ static int hdpvr_stop_streaming(struct hdpvr_device *dev)
kfree(buf);
v4l2_dbg(MSG_BUFFER, hdpvr_debug, &dev->v4l2_dev,
"used %d urbs to empty device buffers\n", c-1);
+ now_jiffies
[PATCH 2/2]: media: hdpvr: Add optional restart, with optional delay, after restarting streaming
`hdpvr_read` attempts to restart streaming if the device is read while
it is both not ready and not disconnected. However, the device is often
still not ready immediately after the call to `hdpvr_start_streaming`
returns, causing the condition `if (buf->status != BUFSTAT_READY)` to
exit the loop without reading any further data. By itself, this would
merely cause a short read, which should be easily recoverable. However,
if no data has been read so far, this causes `hdpvr_read` to return 0,
which results in an end-of-file for the user application.
Compensate for this by adding the ability to delay after the call to
`hdpvr_start_streaming`, then `continue;` back to the top, so that
`hdpvr_read` can call `wait_event_interruptible_timeout` again to wait
for the device to become ready. This delay complements the prior patch.
The prior patch delays before issuing the start-streaming command, to
give the firmware time to stabilize before receiving the command. This
delay is after the start-streaming command, to give the firmware time to
bring the device to a ready state. This delay is configurable through a
new module parameter, `hdpvr_restart_streaming_ms_delay`, which defaults
to a 100 millisecond delay.
To avoid an infinite loop in `hdpvr_read`, add a limit to how many times
`hdpvr_read` can restart the device before returning. This limit is
configurable through a new module parameter,
`hdpvr_restart_streaming_max_tries`, and defaults to one restart.
Administrators may set the limit to 0 to request that `hdpvr_read` never
attempt to restart streaming. Previously, there was no way for
administrators to opt out of an attempted restart.
Signed-off-by: Keith Pyle
Tested-by: Keith Pyle
---
Changes since v1:
- Rewrapped output at 80 columns, per request from Hans. Literal strings
still exceed 80 columns where necessary to keep an entire string together,
since this makes it easier for grep to find the file and line that
generates a given message.
---
drivers/media/usb/hdpvr/hdpvr-core.c | 8 ++
drivers/media/usb/hdpvr/hdpvr-video.c | 40 +++
drivers/media/usb/hdpvr/hdpvr.h | 2 ++
3 files changed, 50 insertions(+)
diff --git a/drivers/media/usb/hdpvr/hdpvr-core.c
b/drivers/media/usb/hdpvr/hdpvr-core.c
index fd7608e7e94c..b7ac63113ac0 100644
--- a/drivers/media/usb/hdpvr/hdpvr-core.c
+++ b/drivers/media/usb/hdpvr/hdpvr-core.c
@@ -43,6 +43,14 @@ uint hdpvr_close_to_open_ms_delay = 4000;
module_param(hdpvr_close_to_open_ms_delay, uint, S_IRUGO|S_IWUSR);
MODULE_PARM_DESC(hdpvr_close_to_open_ms_delay, "delay restarting streaming by
the specified number of milliseconds");
+uint hdpvr_restart_streaming_max_tries = 1;
+module_param(hdpvr_restart_streaming_max_tries, uint, S_IRUGO|S_IWUSR);
+MODULE_PARM_DESC(hdpvr_restart_streaming_max_tries, "restart streaming at most
this many times within one read");
+
+uint hdpvr_restart_streaming_ms_delay = 100;
+module_param(hdpvr_restart_streaming_ms_delay, uint, S_IRUGO|S_IWUSR);
+MODULE_PARM_DESC(hdpvr_restart_streaming_ms_delay, "delay continue by the
specified number of milliseconds after restarting streaming");
+
static uint default_video_input = HDPVR_VIDEO_INPUTS;
module_param(default_video_input, uint, S_IRUGO|S_IWUSR);
MODULE_PARM_DESC(default_video_input, "default video input: 0=Component /
1=S-Video / 2=Composite");
diff --git a/drivers/media/usb/hdpvr/hdpvr-video.c
b/drivers/media/usb/hdpvr/hdpvr-video.c
index 8a2b883d372e..e2ca5d955f4a 100644
--- a/drivers/media/usb/hdpvr/hdpvr-video.c
+++ b/drivers/media/usb/hdpvr/hdpvr-video.c
@@ -441,6 +441,8 @@ static ssize_t hdpvr_read(struct file *file, char __user
*buffer, size_t count,
struct hdpvr_buffer *buf = NULL;
struct urb *urb;
unsigned int ret = 0;
+ unsigned int restarts_remaining = hdpvr_restart_streaming_max_tries;
+ unsigned int delay;
int rem, cnt;
if (*pos)
@@ -491,6 +493,20 @@ static ssize_t hdpvr_read(struct file *file, char __user
*buffer, size_t count,
goto err;
}
if (!err) {
+ if (restarts_remaining == 0) {
+ v4l2_dbg(MSG_BUFFER, hdpvr_debug,
+&dev->v4l2_dev,
+"timeout: no further restarts
allowed by hdpvr_restart_streaming_max_tries; returning to caller with ret=%u",
+ret);
+ /* This break will return the
+* count of bytes copied so far,
+* which may be 0. In that
+* situation, the user
+* application will get an EOF.
+
Re: hdpvr mutex deadlock on kernel 5.1.x
On 06/20/19 06:33, Hans Verkuil wrote:
On 6/19/19 4:29 AM, Keith Pyle wrote:
On 06/18/19 02:16, Hans Verkuil wrote:
Hi Keith,
On 6/18/19 6:17 AM, Keith Pyle wrote:
We made the suggested change, compiled, installed, and rebooted. There was some
progress - test 2 (turning the HD-PVR off) no longer produces a splat. Test 1
(start capture) and test 3 (run capture
and trigger HD-PVR to stop streaming) both still produce a traceback (see
below). Test 3 also still results in the unkillable process.
Try the following patch. Test 2 was caused by locking when it shouldn't, test 3
was caused by not
locking when it should :-) and I think test 1 was caused by locking when it is
not allowed.
Let me know if this works!
Regards,
Hans
Good news! With these patches, lockdep does not report any of the prior
problems and the capture process does not deadlock for my test3.
There is one item I noted: hdpvr_read has the line
msec_to_jiffies(4000);
Oops!
that doesn't really do anything. This should be a 4 second sleep, based on our
discussion back in 2014
(https://www.mail-archive.com/linux-media@vger.kernel.org/msg75163.html), since
the restart will
certainly fail unless the HD-PVR is given at least 3 seconds to reset after the
stop.
I think a msleep(4000) at that point is solving only one use-case. I assume
the same problem will occur if you read() from the video device, then close()
it, re-open it and read() again, all within 4 seconds.
The real fix would be to store a timestamp (jiffies) when you stop streaming,
and in start_streaming check if there are less than 4 seconds between the last
stop and new start, and then sleep until 4 seconds have passed.
Is this something you can work on and provide a patch?
For now I'll post a patch fixing the deadlocks etc. so you can develop your
patch for this on top.
Regards,
Hans
I've included below a proposed two-part patch for media/usb/hdpvr to be
added on top of your commit 0fda628d1a97aec51e2120115f1a2adb7c56be5e.
The proposed patch includes:
- Add the following module parameters:
- hdpvr_close_to_open_ms_delay: specifies the amount of time that
must elapse, in milliseconds,
between stopping streaming and starting streaming since the HD-PVR
generally takes >3 seconds
to become ready for reads; defaults to 4000 ms.
- hdpvr_restart_streaming_max_tries: prevents the driver from getting
into an out of control
restart loop; can be set to 0 to emulate the old driver behavior of
no auto restarts; defaults to 1
- hdpvr_restart_streaming_ms_delay: after a streaming restart, the
HD-PVR will not properly
respond for a brief time; this sets the delay applied after a
restart; defaults to 100 milliseconds
- hdpvr_stop_streaming saves the stop time (in jiffies).
- hdpvr_start_streaming will sleep as needed to ensure that
hdpvr_close_to_open_ms_delay has elapsed
since the last stop streaming.
- Remove the fixed sleep between the hdpvr_stop_streaming and
hdpvr_start_streaming calls in hdpvr_read
since hdpvr_start_streaming now includes the necessary sleep for all
starts.
- Fix bug where restarting streaming could incorrectly cause hdpvr_read
to return 0 (EOF).
From 38f265a0563a6aac16aea29f57d96fd2650d93e8 Mon Sep 17 00:00:00 2001
Date: Mon, 24 Jun 2019 22:04:48 -0500
Subject: [PATCH 1/2] Add adaptive sleeping in hdpvr_start_streaming
---
drivers/media/usb/hdpvr/hdpvr-core.c | 4
drivers/media/usb/hdpvr/hdpvr-video.c | 18 ++
drivers/media/usb/hdpvr/hdpvr.h | 5 +
3 files changed, 27 insertions(+)
diff --git a/drivers/media/usb/hdpvr/hdpvr-core.c
b/drivers/media/usb/hdpvr/hdpvr-core.c
index 29ac7fc5b039..5f28174d409c 100644
--- a/drivers/media/usb/hdpvr/hdpvr-core.c
+++ b/drivers/media/usb/hdpvr/hdpvr-core.c
@@ -39,6 +39,10 @@ int hdpvr_debug;
module_param(hdpvr_debug, int, S_IRUGO|S_IWUSR);
MODULE_PARM_DESC(hdpvr_debug, "enable debugging output");
+uint hdpvr_close_to_open_ms_delay = 4000;
+module_param(hdpvr_close_to_open_ms_delay, uint, S_IRUGO|S_IWUSR);
+MODULE_PARM_DESC(hdpvr_close_to_open_ms_delay, "delay restarting
streaming by the specified number of milliseconds");
+
static uint default_video_input = HDPVR_VIDEO_INPUTS;
module_param(default_video_input, uint, S_IRUGO|S_IWUSR);
MODULE_PARM_DESC(default_video_input, "default video input:
0=Component / 1=S-Video / 2=Composite");
diff --git a/drivers/media/usb/hdpvr/hdpvr-video.c
b/drivers/media/usb/hdpvr/hdpvr-video.c
index 693c6169fc01..d114eff06469 100644
--- a/drivers/media/usb/hdpvr/hdpvr-video.c
+++ b/drivers/media/usb/hdpvr/hdpvr-video.c
@@ -276,6 +276,8 @@ static int hdpvr_start_streaming(struct hdpvr_device
*dev)
{
int ret;
struct hdpvr_video_info vidinf;
+ u64 now_jiffies, delta_jiffies;
+ unsigned msec_to_sleep;
if (dev->status == STATUS_STREAMING)
return 0;
@@ -296,6 +298,19 @@ st
Re: hdpvr mutex deadlock on kernel 5.1.x
On 06/20/19 06:33, Hans Verkuil wrote: On 6/19/19 4:29 AM, Keith Pyle wrote: On 06/18/19 02:16, Hans Verkuil wrote: Hi Keith, On 6/18/19 6:17 AM, Keith Pyle wrote: We made the suggested change, compiled, installed, and rebooted. There was some progress - test 2 (turning the HD-PVR off) no longer produces a splat. Test 1 (start capture) and test 3 (run capture and trigger HD-PVR to stop streaming) both still produce a traceback (see below). Test 3 also still results in the unkillable process. Try the following patch. Test 2 was caused by locking when it shouldn't, test 3 was caused by not locking when it should :-) and I think test 1 was caused by locking when it is not allowed. Let me know if this works! Regards, Hans Good news! With these patches, lockdep does not report any of the prior problems and the capture process does not deadlock for my test3. There is one item I noted: hdpvr_read has the line msec_to_jiffies(4000); Oops! that doesn't really do anything. This should be a 4 second sleep, based on our discussion back in 2014 (https://www.mail-archive.com/linux-media@vger.kernel.org/msg75163.html), since the restart will certainly fail unless the HD-PVR is given at least 3 seconds to reset after the stop. I think a msleep(4000) at that point is solving only one use-case. I assume the same problem will occur if you read() from the video device, then close() it, re-open it and read() again, all within 4 seconds. The real fix would be to store a timestamp (jiffies) when you stop streaming, and in start_streaming check if there are less than 4 seconds between the last stop and new start, and then sleep until 4 seconds have passed. Is this something you can work on and provide a patch? For now I'll post a patch fixing the deadlocks etc. so you can develop your patch for this on top. Regards, Hans I agree with your analysis that it would be better to have every start_streaming make the check and sleep if needed. Yes, I can work on it. Keith
Re: [PATCH] hdpvr: fix locking and a missing msleep
On 06/20/19 06:43, Hans Verkuil wrote:
This driver has three locking issues:
- The wait_event_interruptible() condition calls hdpvr_get_next_buffer(dev)
which uses a mutex, which is not allowed. Rewrite with list_empty_careful()
that doesn't need locking.
- In hdpvr_read() the call to hdpvr_stop_streaming() didn't lock io_mutex,
but it should have since stop_streaming expects that.
- In hdpvr_device_release() io_mutex was locked when calling flush_work(),
but there it shouldn't take that mutex since the work done by flush_work()
also wants to lock that mutex.
There are also two other changes (suggested by Keith):
- msecs_to_jiffies(4000); (a NOP) should have been msleep(4000).
- Change v4l2_dbg to v4l2_info to always log if streaming had to be restarted.
Reported-by: Keith Pyle
Suggested-by: Keith Pyle
Signed-off-by: Hans Verkuil
This patch looks good.
I have repeated my tests and all passed (simple captures, capture with
HD-PVR restart streaming) . There were no lockdep reports and no
process deadlocks. The streaming restart now works and logs the restart
in kern.log.
Keith
---
diff --git a/drivers/media/usb/hdpvr/hdpvr-video.c
b/drivers/media/usb/hdpvr/hdpvr-video.c
index 3786ddcc0d18..5b3e67b80627 100644
--- a/drivers/media/usb/hdpvr/hdpvr-video.c
+++ b/drivers/media/usb/hdpvr/hdpvr-video.c
@@ -435,7 +435,7 @@ static ssize_t hdpvr_read(struct file *file, char __user
*buffer, size_t count,
/* wait for the first buffer */
if (!(file->f_flags & O_NONBLOCK)) {
if (wait_event_interruptible(dev->wait_data,
-hdpvr_get_next_buffer(dev)))
+
!list_empty_careful(&dev->rec_buff_list)))
return -ERESTARTSYS;
}
@@ -461,10 +461,17 @@ static ssize_t hdpvr_read(struct file *file, char __user
*buffer, size_t count,
goto err;
}
if (!err) {
- v4l2_dbg(MSG_INFO, hdpvr_debug, &dev->v4l2_dev,
- "timeout: restart streaming\n");
+ v4l2_info(&dev->v4l2_dev,
+ "timeout: restart streaming\n");
+ mutex_lock(&dev->io_mutex);
hdpvr_stop_streaming(dev);
- msecs_to_jiffies(4000);
+ mutex_unlock(&dev->io_mutex);
+ /*
+* The FW needs about 4 seconds after streaming
+* stopped before it is ready to restart
+* streaming.
+*/
+ msleep(4000);
err = hdpvr_start_streaming(dev);
if (err) {
ret = err;
@@ -1124,9 +1131,7 @@ static void hdpvr_device_release(struct video_device
*vdev)
struct hdpvr_device *dev = video_get_drvdata(vdev);
hdpvr_delete(dev);
- mutex_lock(&dev->io_mutex);
flush_work(&dev->worker);
- mutex_unlock(&dev->io_mutex);
v4l2_device_unregister(&dev->v4l2_dev);
v4l2_ctrl_handler_free(&dev->hdl);
Re: hdpvr mutex deadlock on kernel 5.1.x
On 06/18/19 02:16, Hans Verkuil wrote:
Hi Keith,
On 6/18/19 6:17 AM, Keith Pyle wrote:
We made the suggested change, compiled, installed, and rebooted. There was some
progress - test 2 (turning the HD-PVR off) no longer produces a splat. Test 1
(start capture) and test 3 (run capture
and trigger HD-PVR to stop streaming) both still produce a traceback (see
below). Test 3 also still results in the unkillable process.
Try the following patch. Test 2 was caused by locking when it shouldn't, test 3
was caused by not
locking when it should :-) and I think test 1 was caused by locking when it is
not allowed.
Let me know if this works!
Regards,
Hans
Good news! With these patches, lockdep does not report any of the prior
problems and the capture process does not deadlock for my test3.
There is one item I noted: hdpvr_read has the line
msec_to_jiffies(4000);
that doesn't really do anything. This should be a 4 second sleep, based
on our discussion back in 2014
(https://www.mail-archive.com/linux-media@vger.kernel.org/msg75163.html),
since the restart will certainly fail unless the HD-PVR is given at
least 3 seconds to reset after the stop.
Keith
Signed-off-by: Hans Verkuil
---
diff --git a/drivers/media/usb/hdpvr/hdpvr-video.c
b/drivers/media/usb/hdpvr/hdpvr-video.c
index 3786ddcc0d18..4ba134a3bc25 100644
--- a/drivers/media/usb/hdpvr/hdpvr-video.c
+++ b/drivers/media/usb/hdpvr/hdpvr-video.c
@@ -435,7 +435,7 @@ static ssize_t hdpvr_read(struct file *file, char __user
*buffer, size_t count,
/* wait for the first buffer */
if (!(file->f_flags & O_NONBLOCK)) {
if (wait_event_interruptible(dev->wait_data,
-hdpvr_get_next_buffer(dev)))
+
!list_empty_careful(&dev->rec_buff_list)))
return -ERESTARTSYS;
}
@@ -463,7 +463,9 @@ static ssize_t hdpvr_read(struct file *file, char __user
*buffer, size_t count,
if (!err) {
v4l2_dbg(MSG_INFO, hdpvr_debug, &dev->v4l2_dev,
"timeout: restart streaming\n");
+ mutex_lock(&dev->io_mutex);
hdpvr_stop_streaming(dev);
+ mutex_unlock(&dev->io_mutex);
msecs_to_jiffies(4000);
err = hdpvr_start_streaming(dev);
if (err) {
@@ -1124,9 +1126,7 @@ static void hdpvr_device_release(struct video_device
*vdev)
struct hdpvr_device *dev = video_get_drvdata(vdev);
hdpvr_delete(dev);
- mutex_lock(&dev->io_mutex);
flush_work(&dev->worker);
- mutex_unlock(&dev->io_mutex);
v4l2_device_unregister(&dev->v4l2_dev);
v4l2_ctrl_handler_free(&dev->hdl);
--- test 1 trace
[ 286.987001] [ cut here ]
[ 286.987006] do not call blocking ops when !TASK_RUNNING; state=1 set at
[<07f37036>] prepare_to_wait_event+0xa7/0xe5
[ 286.987009] WARNING: CPU: 1 PID: 2768 at __might_sleep+0x52/0x65
[ 286.987010] Modules linked in: x86_pkg_temp_thermal hdpvr efivarfs
[ 286.987013] CPU: 1 PID: 2768 Comm: cat_hdpvr Not tainted 5.1.10-ld+ #4
[ 286.987014] Hardware name: MSI MS-7A72/Z270 PC MATE (MS-7A72), BIOS 1.60
07/11/2017
[ 286.987015] RIP: 0010:__might_sleep+0x52/0x65
[ 286.987016] Code: 80 3d e7 98 43 01 00 75 23 48 8b 90 38 21 00 00 48 c7 c7 ce 46
11 b7 c6 05 d0 98 43 01 01 48 8b 70 10 48 89 d1 e8 56 b2 fd ff <0f> 0b 44 89 e2
89 ee 48 89 df 5b 5d 41 5c e9 de fd
ff ff 83 fe 07
[ 286.987017] RSP: 0018:a24480677d30 EFLAGS: 00010282
[ 286.987018] RAX: 0070 RBX: b71164a0 RCX: 0007
[ 286.987019] RDX: RSI: 0006 RDI: 9f1c5ea95610
[ 286.987020] RBP: 038c R08: 0001 R09: 000c
[ 286.987020] R10: a24480677e18 R11: 012dadcb5f34 R12:
[ 286.987021] R13: 2000 R14: 0002 R15:
[ 286.987022] FS: 7f8130e71540() GS:9f1c5ea8()
knlGS:
[ 286.987023] CS: 0010 DS: ES: CR0: 80050033
[ 286.987024] CR2: 7ffc0fb650a0 CR3: 00043f3c6002 CR4: 001606e0
[ 286.987025] DR0: DR1: DR2:
[ 286.987025] DR3: DR6: fffe0ff0 DR7: 0400
[ 286.987026] Call Trace:
[ 286.987028] __mutex_lock+0x47/0x7ac
[ 286.987031] ? hdpvr_get_next_buffer+0x16/0x4a [hdpvr]
[ 286.987032] ? find_held_lock+0x2b/0x6e
[ 286.987033] ? prepare_to_wait_event+0xdc/0xe5
[ 286.987034] ? _raw_spin_unlock_irqrestore+0x37/0x4a
[ 286.987036] ? hdpvr_get_next_buffer+0x16/0x4a [hdp
Re: hdpvr mutex deadlock on kernel 5.1.x
On 06/17/19 05:22, Hans Verkuil wrote: On 6/15/19 10:06 PM, Keith Pyle wrote: We have observed a hard mutex deadlock in the hdpvr driver on both 5.1.8 and 5.1.10. The problem occurs while reading from the HD-PVR device and results in an unkillable user process. It is readily reproducible. The problem has been reproduced on two different systems and with two different HD-PVR devices using the 0x1e firmware. We're not particularly familiar with the hdpvr code and could use advice/assistance on this problem. We're certainly willing to test patches. Great! :-) Can you try this first: Edit drivers/media/usb/hdpvr/hdpvr-video.c, go to function hdpvr_device_release() and remove the mutex_lock/unlock around the flush_work(&dev->worker); call. That's definitely wrong. Compile and try again. I expect this will at least solve 1 and 2, but I'm not sure about 3 (read deadlock). Regards, Hans As of this writing, origin/master is 0011572c883082a95e02d47f45fc4a42dc0e8634 (a commit in Linus' tree). `git log v5.1.10..origin/master --grep=hdpvr --` returns no output, so there appear to be no post-5.1 commits mentioning the hdpvr directly. `git log v5.1.10..origin/master -- drivers/media/usb/hdpvr/` shows only some comment updates and a strncpy change. There's nothing that appears locking related. - Steps taken to characterize and demonstrate the problem: We enabled kernel lock debugging using these options: CONFIG_LOCK_DEBUGGING_SUPPORT=y CONFIG_LOCKDEP_SUPPORT=y CONFIG_LOCKDEP=y CONFIG_DEBUG_RT_MUTEXES=y CONFIG_DEBUG_SPINLOCK=y CONFIG_DEBUG_MUTEXES=y CONFIG_DEBUG_WW_MUTEX_SLOWPATH=y CONFIG_DEBUG_RWSEMS=y CONFIG_DEBUG_LOCK_ALLOC=y CONFIG_DEBUG_ATOMIC_SLEEP=y The kernel was built with: gcc version 7.4.0 (Gentoo Hardened 7.4.0-r1 p1.2) GNU ld (Gentoo 2.31.1 p5) 2.31.1 Three snippets of lockdep output are included below. 1. On opening the device, lockdep reported the following: [ 113.195852] [ cut here ] [ 113.195869] do not call blocking ops when !TASK_RUNNING; state=1 set at [<e54b9652>] prepare_to_wait_event+0xa7/0xe5 [ 113.195885] WARNING: CPU: 2 PID: 2616 at __might_sleep+0x52/0x65 [ 113.195889] Modules linked in: hdpvr x86_pkg_temp_thermal efivarfs [ 113.195902] CPU: 2 PID: 2616 Comm: cat Not tainted 5.1.10-ld+ #4 [ 113.195906] Hardware name: MSI MS-7A72/Z270 PC MATE (MS-7A72), BIOS 1.60 07/11/2017 [ 113.195914] RIP: 0010:__might_sleep+0x52/0x65 [ 113.195920] Code: 80 3d e7 98 43 01 00 75 23 48 8b 90 38 21 00 00 48 c7 c7 ce 46 11 b8 c6 05 d0 98 43 01 01 48 8b 70 10 48 89 d1 e8 56 b2 fd ff <0f> 0b 44 89 e2 89 ee 48 89 df 5b 5d 41 5c e9 de fd ff ff 83 fe 07 [ 113.195925] RSP: 0018:b73b0057fd30 EFLAGS: 00010282 [ 113.195930] RAX: 0070 RBX: b81164a0 RCX: 0007 [ 113.195935] RDX: RSI: 0006 RDI: 9ed35eb15610 [ 113.195939] RBP: 038c R08: 0001 R09: 000c [ 113.195943] R10: b73b0057fe18 R11: 008391c86b93 R12: [ 113.195947] R13: 0002 R14: 0002 R15: [ 113.195953] FS: 7fa6eee2c580() GS:9ed35eb0() knlGS: [ 113.195958] CS: 0010 DS: ES: CR0: 80050033 [ 113.195963] CR2: 56533197de84 CR3: 0004425de002 CR4: 001606e0 [ 113.195967] DR0: DR1: DR2: [ 113.195972] DR3: DR6: fffe0ff0 DR7: 0400 [ 113.195975] Call Trace: [ 113.195985] __mutex_lock+0x47/0x7ac [ 113.195997] ? hdpvr_get_next_buffer+0x16/0x4a [hdpvr] [ 113.196005] ? _raw_spin_unlock_irqrestore+0x39/0x4a [ 113.196013] ? hdpvr_get_next_buffer+0x16/0x4a [hdpvr] [ 113.196020] hdpvr_get_next_buffer+0x16/0x4a [hdpvr]hdpvr_submit_buffers [ 113.196029] hdpvr_read+0x174/0x450 [hdpvr] [ 113.196037] ? wait_woken+0x86/0x86 [ 113.196044] v4l2_read+0x38/0x7a [ 113.196052] vfs_read+0xad/0x136 [ 113.196059] ksys_read+0x53/0x95 [ 113.196066] do_syscall_64+0x52/0x155 [ 113.196074] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 113.196079] RIP: 0033:0x7fa6eed52005 [ 113.196085] Code: 00 00 0f 1f 00 48 83 ec 38 64 48 8b 04 25 28 00 00 00 48 89 44 24 28 31 c0 48 8d 05 35 85 0d 00 8b 00 85 c0 75 27 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 63 48 8b 4c 24 28 64 48 33 0c 25 28 00 00 00 [ 113.196089] RSP: 002b:7fffd97d5630 EFLAGS: 0246 ORIG_RAX: [ 113.196096] RAX: ffda RBX: 0002 RCX: 7fa6eed52005 [ 113.196100] RDX: 0002 RSI: 7fa6eee31000 RDI: 0003 [ 113.196104] RBP: 0002 R08: R09: [ 113.196109] R10: 0022 R11: 0246 R12: 7fa6eee31000 [ 113.196113] R13: 0003 R14: 0002 R15: [ 113.196119] irq event stamp: 1514 [ 113.19612
hdpvr mutex deadlock on kernel 5.1.x
We have observed a hard mutex deadlock in the hdpvr driver on both 5.1.8 and 5.1.10. The problem occurs while reading from the HD-PVR device and results in an unkillable user process. It is readily reproducible. The problem has been reproduced on two different systems and with two different HD-PVR devices using the 0x1e firmware. We're not particularly familiar with the hdpvr code and could use advice/assistance on this problem. We're certainly willing to test patches. As of this writing, origin/master is 0011572c883082a95e02d47f45fc4a42dc0e8634 (a commit in Linus' tree). `git log v5.1.10..origin/master --grep=hdpvr --` returns no output, so there appear to be no post-5.1 commits mentioning the hdpvr directly. `git log v5.1.10..origin/master -- drivers/media/usb/hdpvr/` shows only some comment updates and a strncpy change. There's nothing that appears locking related. - Steps taken to characterize and demonstrate the problem: We enabled kernel lock debugging using these options: CONFIG_LOCK_DEBUGGING_SUPPORT=y CONFIG_LOCKDEP_SUPPORT=y CONFIG_LOCKDEP=y CONFIG_DEBUG_RT_MUTEXES=y CONFIG_DEBUG_SPINLOCK=y CONFIG_DEBUG_MUTEXES=y CONFIG_DEBUG_WW_MUTEX_SLOWPATH=y CONFIG_DEBUG_RWSEMS=y CONFIG_DEBUG_LOCK_ALLOC=y CONFIG_DEBUG_ATOMIC_SLEEP=y The kernel was built with: gcc version 7.4.0 (Gentoo Hardened 7.4.0-r1 p1.2) GNU ld (Gentoo 2.31.1 p5) 2.31.1 Three snippets of lockdep output are included below. 1. On opening the device, lockdep reported the following: [ 113.195852] [ cut here ] [ 113.195869] do not call blocking ops when !TASK_RUNNING; state=1 set at [] prepare_to_wait_event+0xa7/0xe5 [ 113.195885] WARNING: CPU: 2 PID: 2616 at __might_sleep+0x52/0x65 [ 113.195889] Modules linked in: hdpvr x86_pkg_temp_thermal efivarfs [ 113.195902] CPU: 2 PID: 2616 Comm: cat Not tainted 5.1.10-ld+ #4 [ 113.195906] Hardware name: MSI MS-7A72/Z270 PC MATE (MS-7A72), BIOS 1.60 07/11/2017 [ 113.195914] RIP: 0010:__might_sleep+0x52/0x65 [ 113.195920] Code: 80 3d e7 98 43 01 00 75 23 48 8b 90 38 21 00 00 48 c7 c7 ce 46 11 b8 c6 05 d0 98 43 01 01 48 8b 70 10 48 89 d1 e8 56 b2 fd ff <0f> 0b 44 89 e2 89 ee 48 89 df 5b 5d 41 5c e9 de fd ff ff 83 fe 07 [ 113.195925] RSP: 0018:b73b0057fd30 EFLAGS: 00010282 [ 113.195930] RAX: 0070 RBX: b81164a0 RCX: 0007 [ 113.195935] RDX: RSI: 0006 RDI: 9ed35eb15610 [ 113.195939] RBP: 038c R08: 0001 R09: 000c [ 113.195943] R10: b73b0057fe18 R11: 008391c86b93 R12: [ 113.195947] R13: 0002 R14: 0002 R15: [ 113.195953] FS: 7fa6eee2c580() GS:9ed35eb0() knlGS: [ 113.195958] CS: 0010 DS: ES: CR0: 80050033 [ 113.195963] CR2: 56533197de84 CR3: 0004425de002 CR4: 001606e0 [ 113.195967] DR0: DR1: DR2: [ 113.195972] DR3: DR6: fffe0ff0 DR7: 0400 [ 113.195975] Call Trace: [ 113.195985] __mutex_lock+0x47/0x7ac [ 113.195997] ? hdpvr_get_next_buffer+0x16/0x4a [hdpvr] [ 113.196005] ? _raw_spin_unlock_irqrestore+0x39/0x4a [ 113.196013] ? hdpvr_get_next_buffer+0x16/0x4a [hdpvr] [ 113.196020] hdpvr_get_next_buffer+0x16/0x4a [hdpvr] [ 113.196029] hdpvr_read+0x174/0x450 [hdpvr] [ 113.196037] ? wait_woken+0x86/0x86 [ 113.196044] v4l2_read+0x38/0x7a [ 113.196052] vfs_read+0xad/0x136 [ 113.196059] ksys_read+0x53/0x95 [ 113.196066] do_syscall_64+0x52/0x155 [ 113.196074] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 113.196079] RIP: 0033:0x7fa6eed52005 [ 113.196085] Code: 00 00 0f 1f 00 48 83 ec 38 64 48 8b 04 25 28 00 00 00 48 89 44 24 28 31 c0 48 8d 05 35 85 0d 00 8b 00 85 c0 75 27 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 63 48 8b 4c 24 28 64 48 33 0c 25 28 00 00 00 [ 113.196089] RSP: 002b:7fffd97d5630 EFLAGS: 0246 ORIG_RAX: [ 113.196096] RAX: ffda RBX: 0002 RCX: 7fa6eed52005 [ 113.196100] RDX: 0002 RSI: 7fa6eee31000 RDI: 0003 [ 113.196104] RBP: 0002 R08: R09: [ 113.196109] R10: 0022 R11: 0246 R12: 7fa6eee31000 [ 113.196113] R13: 0003 R14: 0002 R15: [ 113.196119] irq event stamp: 1514 [ 113.196128] hardirqs last enabled at (1513): [] console_unlock+0x493/0x4da [ 113.196134] hardirqs last disabled at (1514): [] trace_hardirqs_off_thunk+0x1a/0x1c [ 113.196140] softirqs last enabled at (1500): [] __do_softirq+0x376/0x3b2 [ 113.196148] softirqs last disabled at (1491): [] irq_exit+0x4e/0x9d [ 113.196152] ---[ end trace 0881f93401450644 ]--- 2. A short capture from the device proceeded successfully and lockdep reported the following on turning the device off: [ 227.915296]
Re: [PATCH 1/1] hdpvr: code cleanup
On 02/14/17 19:18, Jonathan Sims wrote:
> This is a code cleanup after recent changes introduced by commit
> a503ff812430e104f591287b512aa4e3a83f20b1.
>
> Signed-off-by: Jonathan Sims
> ---
>
> drivers/media/usb/hdpvr/hdpvr-video.c | 18 +++---
> 1 file changed, 7 insertions(+), 11 deletions(-)
>
> diff --git a/drivers/media/usb/hdpvr/hdpvr-video.c
> b/drivers/media/usb/hdpvr/hdpvr-video.c
> index 7fb036d6a86e..b2ce5c0807fb 100644
> --- a/drivers/media/usb/hdpvr/hdpvr-video.c
> +++ b/drivers/media/usb/hdpvr/hdpvr-video.c
> @@ -449,7 +449,7 @@ static ssize_t hdpvr_read(struct file *file, char __user
> *buffer, size_t count,
>
> if (buf->status != BUFSTAT_READY &&
> dev->status != STATUS_DISCONNECTED) {
> - int err;
> +
> /* return nonblocking */
> if (file->f_flags & O_NONBLOCK) {
> if (!ret)
> @@ -457,23 +457,19 @@ static ssize_t hdpvr_read(struct file *file, char
> __user *buffer, size_t count, goto err;
> }
>
> - err =
> wait_event_interruptible_timeout(dev->wait_data,
> + ret =
> wait_event_interruptible_timeout(dev->wait_data, buf->status ==
> BUFSTAT_READY, msecs_to_jiffies(1000));
> - if (err < 0) {
> - ret = err;
> + if (ret < 0)
> goto err;
> - }
> - if (!err) {
> + if (!ret) {
> v4l2_dbg(MSG_INFO, hdpvr_debug,
> &dev->v4l2_dev, "timeout: restart streaming\n");
> hdpvr_stop_streaming(dev);
> - msecs_to_jiffies(4000);
> - err = hdpvr_start_streaming(dev);
> - if (err) {
> - ret = err;
> + msleep(4000);
> + ret = hdpvr_start_streaming(dev);
> + if (ret)
> goto err;
> - }
> }
> }
>
One comment and one suggestion:
I believe that the overall solution proposed above is an appropriate
means of dealing with hardware/firmware issues in the HD-PVR that lead
to failed captures reported by many people. It will be a definite
improvement over the current situation. However, it is important to
note that some player applications may have minor problems with the
resulting mpeg stream. Restarting HD-PVR streaming results in the
equivalent of concatenating two separate mpeg streams into one file.
Each segment has its own mpeg frame timestamps starting at 0. ffmpeg
based applications don't fully handle such files. For example, both
mplayer and vlc will play these streams correctly, but both have issues
attempting to skip within the stream (vlc skips little or not at all,
mplayer will skip but in smaller increments than normal). ffprobe of
such a file will report the mpeg length as that of the last capture
segment rather than the total length of the file. Still, having a
nearly complete capture (absent a few seconds during the restart) with
skip problems is far better than having a capture that stops well short
of the intended length.
Suggestion: Rather than just having a v4l2 debug message that streaming
was restarted, I think it would be desirable to have a timestamped
printk message showing the restart and the name of the HD-PVR device
(should the system have more than one). This would allow users to more
readily tell that they have had this condition occur and how frequently.
Keith
Re: [PATCH] hdpvr: fix interrupted recording
On 05/12/14 07:41, Hans Verkuil wrote:
Ryley, Keith, can you test this one more time and if it works reply with
a 'Tested-by' tag that I can add to the patch?
Thanks!
Hans
This issue was reported by Ryley Angus:
I record from my satellite set top box using component video and optical
audio input. I basically use "cat /dev/video0 > ~/video.ts” or use dd. The
box is set to output audio as AC-3 over optical, but most channels are
actually output as stereo PCM. When the channel is changed between a PCM
channel and (typically to a movie channel) to a channel utilising AC-3,
the HD-PVR stops the recording as the set top box momentarily outputs no
audio. Changing between PCM channels doesn't cause any issues.
My main problem was that when this happens, cat/dd doesn't actually exit.
When going through the hdpvr driver source and the dmesg output, I found
the hdpvr driver wasn't actually shutting down the device properly until
I manually killed cat/dd.
I've seen references to this issue being a hardware issue from as far back
as
2010:http://forums.gbpvr.com/showthread.php?46429-HD-PVR-drops-recording-on-channel-change-Hauppauge-says-too-bad
.
I tracked my issue to the file hdpvr-video.c. Specifically:
"if (wait_event_interruptible(dev->wait_data, buf->status = BUFSTAT_READY)) {"
(line ~450). The device seems to get stuck waiting for the buffer to become
ready. But as far as I can tell, when the channel is changed between a PCM
and AC-3 broadcast the buffer status will never actually become ready.
Angus provided a hack to fix this, which I've rewritten.
Signed-off-by: Hans Verkuil
Reported-by: Ryley Angus
---
drivers/media/usb/hdpvr/hdpvr-video.c | 20 +---
1 file changed, 17 insertions(+), 3 deletions(-)
diff --git a/drivers/media/usb/hdpvr/hdpvr-video.c
b/drivers/media/usb/hdpvr/hdpvr-video.c
index 0500c417..44227da 100644
--- a/drivers/media/usb/hdpvr/hdpvr-video.c
+++ b/drivers/media/usb/hdpvr/hdpvr-video.c
@@ -454,6 +454,8 @@ static ssize_t hdpvr_read(struct file *file, char __user
*buffer, size_t count,
if (buf->status != BUFSTAT_READY &&
dev->status != STATUS_DISCONNECTED) {
+ int err;
+
/* return nonblocking */
if (file->f_flags & O_NONBLOCK) {
if (!ret)
@@ -461,11 +463,23 @@ static ssize_t hdpvr_read(struct file *file, char __user
*buffer, size_t count,
goto err;
}
- if (wait_event_interruptible(dev->wait_data,
- buf->status == BUFSTAT_READY)) {
- ret = -ERESTARTSYS;
+ err = wait_event_interruptible_timeout(dev->wait_data,
+ buf->status == BUFSTAT_READY,
+ msecs_to_jiffies(3000));
+ if (err < 0) {
+ ret = err;
goto err;
}
+ if (!err) {
+ v4l2_dbg(MSG_INFO, hdpvr_debug, &dev->v4l2_dev,
+ "timeout: restart streaming\n");
+ hdpvr_stop_streaming(dev);
+ err = hdpvr_start_streaming(dev);
+ if (err) {
+ ret = err;
+ goto err;
+ }
+ }
}
if (buf->status != BUFSTAT_READY)
Unfortunately, 2 of my 3 tests failed. The new code correctly detected
the loss of signal and generated the timeout message for all three
tests. For tests 1 & 3, the HD-PVR did not restart streaming. Test 1
gave a 'Resource temporarily unavailable' error. Test 3 did not produce
an error message.
I believe I understand the problem. In my user-space code that (mostly)
deals with this problem, my algorithm differs slightly from that in
Hans' code. The proposed patch has this flow:
1. watch for time-out on read for 3 seconds
2. if no data is received in time-out period, close streaming on HD-PVR
3. immediately re-open streaming from the HD-PVR
In my testing last year, I found that the HD-PVR is sensitive to being
re-opened too soon. The HD-PVR firmware seems to take a few seconds to
reset itself after a close and be ready to accept a new open. So, my
flow is:
1. watch for time-out on read for 1 second
2. if no data received in timeout period, close the HD-PVR device
3. sleep for 4 seconds
4. re-open the HD-PVR device
I believe that Hans' patch fails my tests because there is no delay
between the stop and start streaming calls in his patch. The minimum
reliable time between such actions on my HD-PVR is 3 seconds. I
established this value by running a number of tests where I
Re: [RFC] Fix interrupted recording with Hauppauge HD-PVR
On 05/09/14 06:08, Hans Verkuil wrote:
On 04/08/2014 07:07 PM, Ryley Angus wrote:
Hi Kyle.
It may be possible that the delay in acceptable grace periods is due to a
difference in our input AV sources more so than the Hauppauge units
themselves. I'm wondering if it would be useful to control the timeout
period via a module parameter that defaults to 3 seconds perhaps?
It is OK for both of you if I set the timeout to 3 seconds in my patch? So it
will use "msecs_to_jiffies(3000));".
If you can both confirm that that works, then I'll merge the patch.
Sorry for being late with my reply, it's been busy lately :-)
Regards,
Hans
As far as the issues with concatenated output, I've just looked at the files
containing a channel change and realized that VLC does show the duration as
0:00. Seeking with a keyboard isn't functional. Seeking with the timeline
and a mouse is fine. Avidemux seems to have trouble editing the file. If I
cut a section from a file that is from a single recording "session" it's
duration is correct, sync is correct and audio properties are correct. I
cannot cut across segments. MPC-HC also has duration issues with the
recording.
If I run the recordings through "ffmpeg -fflags +genpts -I -c:v copy
-c:a copy ", the resultant file duration is correct in VLC, I can
seek with the keyboard and mouse and editing is perfect with Avidemux. But
would it be better if the device just cleanly stopped recording instead of
automatically resuming? Or, continuing with the module parameters idea,
could we determine whether or not it will automatically restart based off a
module parameter?
I feel bad for not noticing the VLC issues earlier, but I mostly just use
VLC to broadcast the recordings through my home network to client instances
of VLC. This works well, but obviously seeking isn't relevant.
ryley
-Original Message-
From: Keith Pyle [mailto:kp...@austin.rr.com]
Sent: Wednesday, April 09, 2014 12:28 AM
To: Ryley Angus; 'Hans Verkuil'; linux-media@vger.kernel.org
Subject: Re: [RFC] Fix interrupted recording with Hauppauge HD-PVR
On 04/07/14 22:32, Ryley Angus wrote:
Thanks Hans for getting back to me.
I've been trying out your patch and I found the device wasn't actually
restarting the streaming/recording properly after a channel change. I
changed "msecs_to_jiffies(500))" to "msecs_to_jiffies(1000))" and had
the same issue, but "msecs_to_jiffies(2000))"
seems to be working well. I'll let it keep going for a few more hours,
but at the moment it seems to be working well. The recordings can be
ended without anything hanging, and turning off the device ends the
recording properly (mine neglected this occurrence).
I'll let you know if I have any more issues,
ryley
-Original Message-
From: Hans Verkuil [mailto:hverk...@xs4all.nl]
Sent: Tuesday, April 08, 2014 12:07 AM
To: Ryley Angus; linux-media@vger.kernel.org
Subject: Re: [RFC] Fix interrupted recording with Hauppauge HD-PVR
Hi Ryley,
Thank you for the patch. Your analysis seems sound. The patch is
actually not bad for a first attempt, but I did it a bit differently.
Can you test my patch?
Regards,
Hans
Signed-off-by: Hans Verkuil
diff --git a/drivers/media/usb/hdpvr/hdpvr-video.c
b/drivers/media/usb/hdpvr/hdpvr-video.c
index 0500c417..a61373e 100644
--- a/drivers/media/usb/hdpvr/hdpvr-video.c
+++ b/drivers/media/usb/hdpvr/hdpvr-video.c
@@ -454,6 +454,8 @@ static ssize_t hdpvr_read(struct file *file, char
__user *buffer, size_t count,
if (buf->status != BUFSTAT_READY &&
dev->status != STATUS_DISCONNECTED) {
+ int err;
+
/* return nonblocking */
if (file->f_flags & O_NONBLOCK) {
if (!ret)
@@ -461,11 +463,23 @@ static ssize_t hdpvr_read(struct file *file,
char __user *buffer, size_t count,
goto err;
}
- if (wait_event_interruptible(dev->wait_data,
- buf->status == BUFSTAT_READY))
{
- ret = -ERESTARTSYS;
+ err =
wait_event_interruptible_timeout(dev->wait_data,
+ buf->status == BUFSTAT_READY,
+ msecs_to_jiffies(500));
+ if (err < 0) {
+ ret = err;
goto err;
}
+ if (!err) {
+ v4l2_dbg(MSG_INFO, hdpvr_debug,
&dev->v4l2_dev,
+ "timeout: restart streaming\n");
+ hdpvr_stop_streaming(dev);
+
Re: [RFC] Fix interrupted recording with Hauppauge HD-PVR
On 04/08/14 12:07, Ryley Angus wrote: Hi Kyle. It may be possible that the delay in acceptable grace periods is due to a difference in our input AV sources more so than the Hauppauge units themselves. I'm wondering if it would be useful to control the timeout period via a module parameter that defaults to 3 seconds perhaps? As far as the issues with concatenated output, I've just looked at the files containing a channel change and realized that VLC does show the duration as 0:00. Seeking with a keyboard isn't functional. Seeking with the timeline and a mouse is fine. Avidemux seems to have trouble editing the file. If I cut a section from a file that is from a single recording "session" it's duration is correct, sync is correct and audio properties are correct. I cannot cut across segments. MPC-HC also has duration issues with the recording. If I run the recordings through "ffmpeg -fflags +genpts -I -c:v copy -c:a copy ", the resultant file duration is correct in VLC, I can seek with the keyboard and mouse and editing is perfect with Avidemux. But would it be better if the device just cleanly stopped recording instead of automatically resuming? Or, continuing with the module parameters idea, could we determine whether or not it will automatically restart based off a module parameter? I feel bad for not noticing the VLC issues earlier, but I mostly just use VLC to broadcast the recordings through my home network to client instances of VLC. This works well, but obviously seeking isn't relevant. ryley ... I doubt that the multiple segment problem can be easily fixed in the hdpvr Linux driver. With the caveat that I'm far away from being an expert on MPEG, TS, and the like, I believe that the HD-PVR encoder generates the timing data into the stream with its origin being defined when the encoder starts the stream. So, if the capture is restarted, the encoder is re-initialized by the HD-PVR firmware and the result is a new origin for the following stream segment. The only real fix would be in the HD-PVR firmware - which we can't get and is why we have this problem in the first place. Regardless of this problem, I think the proposed driver patch is a distinct improvement over the current situation. Without the patch, we get truncated recordings. With the patch, we get nearly complete recordings which have skip issues. As you noted, this problem may be fixed with ffmpeg. Keith -- To unsubscribe from this list: send the line "unsubscribe linux-media" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [RFC] Fix interrupted recording with Hauppauge HD-PVR
On 04/07/14 22:32, Ryley Angus wrote:
Thanks Hans for getting back to me.
I've been trying out your patch and I found the device wasn't actually
restarting the streaming/recording properly after a channel
change. I changed "msecs_to_jiffies(500))" to "msecs_to_jiffies(1000))" and
had the same issue, but "msecs_to_jiffies(2000))"
seems to be working well. I'll let it keep going for a few more hours, but
at the moment it seems to be working well. The recordings
can be ended without anything hanging, and turning off the device ends the
recording properly (mine neglected this occurrence).
I'll let you know if I have any more issues,
ryley
-Original Message-
From: Hans Verkuil [mailto:hverk...@xs4all.nl]
Sent: Tuesday, April 08, 2014 12:07 AM
To: Ryley Angus; linux-media@vger.kernel.org
Subject: Re: [RFC] Fix interrupted recording with Hauppauge HD-PVR
Hi Ryley,
Thank you for the patch. Your analysis seems sound. The patch is actually
not bad for a first attempt, but I did it a bit differently.
Can you test my patch?
Regards,
Hans
Signed-off-by: Hans Verkuil
diff --git a/drivers/media/usb/hdpvr/hdpvr-video.c
b/drivers/media/usb/hdpvr/hdpvr-video.c
index 0500c417..a61373e 100644
--- a/drivers/media/usb/hdpvr/hdpvr-video.c
+++ b/drivers/media/usb/hdpvr/hdpvr-video.c
@@ -454,6 +454,8 @@ static ssize_t hdpvr_read(struct file *file, char __user
*buffer, size_t count,
if (buf->status != BUFSTAT_READY &&
dev->status != STATUS_DISCONNECTED) {
+ int err;
+
/* return nonblocking */
if (file->f_flags & O_NONBLOCK) {
if (!ret)
@@ -461,11 +463,23 @@ static ssize_t hdpvr_read(struct file *file, char
__user *buffer, size_t count,
goto err;
}
- if (wait_event_interruptible(dev->wait_data,
- buf->status == BUFSTAT_READY))
{
- ret = -ERESTARTSYS;
+ err =
wait_event_interruptible_timeout(dev->wait_data,
+ buf->status == BUFSTAT_READY,
+ msecs_to_jiffies(500));
+ if (err < 0) {
+ ret = err;
goto err;
}
+ if (!err) {
+ v4l2_dbg(MSG_INFO, hdpvr_debug,
&dev->v4l2_dev,
+ "timeout: restart streaming\n");
+ hdpvr_stop_streaming(dev);
+ err = hdpvr_start_streaming(dev);
+ if (err) {
+ ret = err;
+ goto err;
+ }
+ }
}
if (buf->status != BUFSTAT_READY)
On 04/07/2014 02:04 AM, Ryley Angus wrote:
(Sorry in advance for probably breaking a few conventions of the
mailing lists. First time using one so please let me know what I'm
doing wrong)
I'm writing this because of an issue I had with my Hauppauge HD-PVR.
I record from my satellite set top box using component video and
optical audio input. I basically use "cat /dev/video0 > ~/video.ts"
or use dd. The box is set to output audio as AC-3 over optical, but
most channels are actually output as stereo PCM. When the channel is
changed between a PCM channel and (typically to a movie channel) to a
channel utilising AC-3, the HD-PVR stops the recording as the set top
box momentarily outputs no audio. Changing between PCM channels
doesn't cause any issues.
My main problem was that when this happens, cat/dd doesn't actually
exit. When going through the hdpvr driver source and the dmesg output,
I found the hdpvr driver wasn't actually shutting down the device
properly until I manually killed cat/dd.
I've seen references to this issue being a hardware issue from as far
back as 2010:
http://forums.gbpvr.com/showthread.php?46429-HD-PVR-drops-recording-on
-channel-change-Hauppauge-says-too-bad
.
I tracked my issue to the file "hdpvr-video.c". Specifically, "if
(wait_event_interruptible(dev->wait_data, buf->status =
BUFSTAT_READY)) {" (line ~450). The device seems to get stuck waiting
for the buffer to become ready. But as far as I can tell, when the
channel is changed between a PCM and AC-3 broadcast the buffer status
will never actually become ready.
...
I've seen the same problem Ryley describes and handled it in user space
with a cat-like program that could detect stalls and re-open the hdpvr
device. This approach seems much better. Kudos to both Ryley and Hans.
I concur that the 500 ms. timeout is too small. When testing my
program, I tried using a variety of timeout values when I found that the
HD-PVR seems to require some delay following a close before it
Re: HD-PVR fails consistently on Linux, works on Windows
On 09/26/12 21:42, Keith Pyle wrote: I recently purchased a Hauppauge HD-PVR (the 1212 version, label on bottom 49001LF, Rev F2). I have consistent capture failures on Linux where data from the device simply stops, generally within a few minutes of starting a capture. Yet, the device works flawlessly on Windows with the same USB and component cables, same power supply, and same physical position. This suggests that the device itself has acceptable power, is not overheating, etc. I'll detail below the testing I've done thus far and would appreciate any suggestions on how to further test or address the problem. The good news is that I have a highly reproducible failure on Linux, but then that's the bad news too. Thanks. Keith -- Linux tests -- I started trying to use the HD-PVR directly with my MythTV backend. I have subsequently switched all of my testing to simple direct captures from the /dev/video? device using /bin/cat to eliminate as many variables as possible. I've done a large number of tests with combinations of the following: OS: gentoo 3.4.7, gentoo 3.5.4 HD-PVR firmware: 1.5.7.0 (0x15), 1.7.1.30059 (0x1e) Input resolution: fixed to 720p, fixed to 1080i, floating based on input USB ports: motherboard ports on Intel DP45SG, motherboard ports on MSI X58 Pro-E, ports on SIIG USB PCIe card Captures fail consistently. Here's some interesting new information. On noticing that the 3.6 kernel included several USB related commits, I updated the kernel of my test system (MSI X58 Pro-E) from 3.5.4 to 3.6.2. I ran a series of capture tests with firmware 0x1e and all other variables exactly as before - same USB cable, port, physical position, etc. I have 20 successful 1-hour captures and 1 failure. There are no logged messages for the failed capture but the timing coincides within a minute after initializing a wireless joystick on a different USB bus. I've been unable to reproduce this failure, so I cannot conclusively state that there is a correlation. The results of the kernel change are dramatic. Under 3.5.x and earlier, the failure rate for 1-hour captures was 100%. Most failed in less than 10 minutes. There were some instances of hard hangs on the HD-PVR (i.e., power cycle required). With 3.6.2, it is less than 5% failure. The one failure was a truncated recording. I am continuing capture tests on my test system to build more data. I will next be updating my MythTV backend to 3.6 and trying the capture tests on it since it has a different motherboard. It would be quite interesting if others with HD-PVR problems see similar results for 3.6.2 or better. Keith -- To unsubscribe from this list: send the line "unsubscribe linux-media" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: HD-PVR fails consistently on Linux, works on Windows
On 10/13/12 14:17, David Röthlisberger wrote: On Wed, 26 Sep 2012 21:42:32 -0500 Keith Pyle wrote: I recently purchased a Hauppauge HD-PVR (the 1212 version, label on bottom 49001LF, Rev F2). I have consistent capture failures on Linux where data from the device simply stops, generally within a few minutes of starting a capture. [...] Sep 21 17:01:01 mythbe kernel: [535043.703947] hdpvr 9-1:1.0: firmware version 0x15 dated Jun 17 2010 09:26:53 When we contacted Hauppauge regarding the stability issue, they recommended upgrading to the latest firmware dated Mar 26 2012. We *think* this has improved stability, but it certainly hasn't fixed it completely. Upgrading the firmware requires a Windows PC -- see http://www.hauppauge.com/site/support/support_hdpvr.html The Mar 26, 2012 firmware is the 1.7.1.30059 version that shows as 0x1e in the kernel messages. In my case, I've tried both 0x1e and 0x15 with no discernible difference in stability. That is, both hang reliably and repeatedly on Linux but not when using a Windows system. On 13 Oct 2012, at 16:28, Jonathan wrote: It may be a coincidence but I since I started using irqbalance ( https://code.google.com/p/irqbalance/ ) my HD-PVR has been completely stable. Before that I was experiencing daily lockups. Interesting. You definitely didn't upgrade the firmware around the same time? We think the stability is worse when the Linux PC is heavily loaded: We do real-time image processing on the video stream from the HD PVR, so the CPUs are maxed out, and we get frequent lock-ups. We also think the lock-ups are more frequent when we have several HD PVRs connected to the same PC, all running at the same time. I'll have to try this irqbalance. --Dave. All of my tests have been using only one HD-PVR on otherwise nearly idle systems with *lots* of system resources available. One test system is an Intel Core 2 Quad Q9400 (2.66 GHz) and the other is an Intel i7 950 (3.0 GHz). CPU loads are low during captures - not anywhere near having any core at 100%. While system load could certainly be a factor for some, I do not believe it is in my tests. Keith -- To unsubscribe from this list: send the line "unsubscribe linux-media" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
HD-PVR fails consistently on Linux, works on Windows
I recently purchased a Hauppauge HD-PVR (the 1212 version, label on bottom 49001LF, Rev F2). I have consistent capture failures on Linux where data from the device simply stops, generally within a few minutes of starting a capture. Yet, the device works flawlessly on Windows with the same USB and component cables, same power supply, and same physical position. This suggests that the device itself has acceptable power, is not overheating, etc. I'll detail below the testing I've done thus far and would appreciate any suggestions on how to further test or address the problem. The good news is that I have a highly reproducible failure on Linux, but then that's the bad news too. Thanks. Keith -- Linux tests -- I started trying to use the HD-PVR directly with my MythTV backend. I have subsequently switched all of my testing to simple direct captures from the /dev/video? device using /bin/cat to eliminate as many variables as possible. I've done a large number of tests with combinations of the following: OS: gentoo 3.4.7, gentoo 3.5.4 HD-PVR firmware: 1.5.7.0 (0x15), 1.7.1.30059 (0x1e) Input resolution: fixed to 720p, fixed to 1080i, floating based on input USB ports: motherboard ports on Intel DP45SG, motherboard ports on MSI X58 Pro-E, ports on SIIG USB PCIe card Captures fail consistently. I've verified that the HD-PVR is the only device on the USB bus and that the bus shows as "Linux Foundation 2.0 root hub" in all tests. I've increased the debug output level for the hdpvr driver to 6 (/sys/module/hdpvr/parameters/hdpvr_debug) and collected the following: Sep 21 17:01:00 mythbe kernel: [535043.504450] usb 9-1: New USB device found, idVendor=2040, idProduct=4903 Sep 21 17:01:00 mythbe kernel: [535043.504453] usb 9-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Sep 21 17:01:00 mythbe kernel: [535043.504456] usb 9-1: Product: Hauppauge HD PVR Sep 21 17:01:00 mythbe kernel: [535043.504458] usb 9-1: Manufacturer: AMBA Sep 21 17:01:00 mythbe kernel: [535043.504459] usb 9-1: SerialNumber: 00A6DD48 Sep 21 17:01:00 mythbe kernel: [535043.504523] usb 9-1: ep 0x1 - rounding interval to 32768 microframes, ep desc says 0 microframes Sep 21 17:01:00 mythbe kernel: [535043.504528] usb 9-1: ep 0x81 - rounding interval to 32768 microframes, ep desc says 0 microframes Sep 21 17:01:01 mythbe kernel: [535043.703947] hdpvr 9-1:1.0: firmware version 0x15 dated Jun 17 2010 09:26:53 Sep 21 17:01:01 mythbe kernel: [535043.889144] IR keymap rc-hauppauge not found Sep 21 17:01:01 mythbe kernel: [535043.889146] Registered IR keymap rc-empty Sep 21 17:01:01 mythbe kernel: [535043.889190] input: i2c IR (HD-PVR) as /devices/virtual/rc/rc5/input16 Sep 21 17:01:01 mythbe kernel: [535043.889415] rc5: i2c IR (HD-PVR) as /devices/virtual/rc/rc5 Sep 21 17:01:01 mythbe kernel: [535043.889417] ir-kbd-i2c: i2c IR (HD-PVR) detected at i2c-8/8-0071/ir0 [Hauppage HD PVR I2C] Sep 21 17:01:01 mythbe kernel: [535043.889518] hdpvr 9-1:1.0: device now attached to video6 Sep 21 17:01:01 mythbe kernel: [535043.889534] usbcore: registered new interface driver hdpvr Sep 21 17:05:11 mythbe kernel: [535293.776318] hdpvr 9-1:1.0: video signal: 1920x1080@30hz Sep 21 17:05:14 mythbe kernel: [535297.312589] hdpvr 9-1:1.0: encoder start control request returned 0 Sep 21 17:05:15 mythbe kernel: [535297.670830] hdpvr 9-1:1.0: config call request for value 0x700 returned 1 Sep 21 17:05:15 mythbe kernel: [535297.670833] hdpvr 9-1:1.0: streaming started Sep 21 17:05:15 mythbe kernel: [535297.670839] hdpvr 9-1:1.0: hdpvr_read:442 buffer stat: 64 free, 0 proc Sep 21 17:05:15 mythbe kernel: [535297.670882] hdpvr 9-1:1.0: hdpvr_submit_buffers:209 buffer stat: 0 free, 64 proc Sep 21 17:05:15 mythbe kernel: [535297.709079] hdpvr 9-1:1.0: hdpvr_read:502 buffer stat: 1 free, 63 proc Sep 21 17:05:15 mythbe kernel: [535297.709088] hdpvr 9-1:1.0: hdpvr_submit_buffers:209 buffer stat: 0 free, 64 proc (many repeats of the above two line sequence) Sep 21 17:17:09 mythbe kernel: [536011.936858] hdpvr 9-1:1.0: hdpvr_read:502 buffer stat: 1 free, 63 proc Sep 21 17:17:09 mythbe kernel: [536011.936866] hdpvr 9-1:1.0: hdpvr_submit_buffers:209 buffer stat: 0 free, 64 proc Sep 21 17:17:36 mythbe kernel: [536038.853044] hdpvr 9-1:1.0: config call request for value 0x800 returned -110 Sep 21 17:17:36 mythbe kernel: [536038.853052] hdpvr 9-1:1.0: transmit worker exited Sep 21 17:17:36 mythbe kernel: [536038.996035] hdpvr 9-1:1.0: used 0 urbs to empty device buffers If I understand correctly, this is showing a ETIMEDOUT error. When I've looked at the cat with strace, it is always blocked on a read. So, it seems like the HD-PVR just stops sending. I also ran a USB capture with wireshark and see much the same thing. While I haven't tried to decode the USB packets, the pattern is that the HD-PVR sends, the host sends a message/ack, this pattern repeats, and then nothing. The majority of the failures occur in les
