Opened 6 years ago

Closed 6 years ago

Last modified 4 years ago

#10428 closed Bug Report - General (Fixed)

mythbackend logs RingBuf-messages every few seconds while playing LiveTV

Reported by: Kenni Lund [kenni a kelu dot dk] Owned by: danielk
Priority: minor Milestone: 0.26
Component: MythTV - Recording Version: Master Head
Severity: medium Keywords:
Cc: Ticket locked: yes

Description

After upgrading from 0.24-fixes to master/0.25, the backend continuously writes out RingBuf? log messages about it waiting for data:

mythbackend[9601]: RingBuf(/data/mythtv/livetv/1001_20120310153618.mpg): Waited 1.0 seconds for data #012#011#011#011to become available... 130980 < 196608

While it does this, LiveTV works fine with no stuttering. The issue seems consistent on all channels in LiveTV and playing back recordings does NOT give the RingBuf? logs. Eg. playing back any recording - even the just-recorded LiveTV recording from the recordings menu - does NOT cause the backend to write out these messages.

Logs from ~5 minutes of LiveTV playback is attached. If more verbose logs are required to identify the issue, I'll be happy to provide them.

The tuner is a European HDHR dual DVB-C tuner. The backend is a 3.4GHz Core i5 with 12GB RAM and database+OS on a SSD, so it seems unlikely that this is a local performance issue.

Attachments (3)

mythbackend_RingBuf.log (59.1 KB) - added by Kenni Lund [kenni a kelu dot dk] 6 years ago.
mythfrontend_RingBuf.log (44.3 KB) - added by Kenni Lund [kenni a kelu dot dk] 6 years ago.
mythbackend_log_while_skipping.log (68.6 KB) - added by Kenni Lund [kenni a kelu dot dk] 6 years ago.
Log illustrating the issue while skipping back and forward

Download all attachments as: .zip

Change History (15)

Changed 6 years ago by Kenni Lund [kenni a kelu dot dk]

Attachment: mythbackend_RingBuf.log added

Changed 6 years ago by Kenni Lund [kenni a kelu dot dk]

Attachment: mythfrontend_RingBuf.log added

comment:1 Changed 6 years ago by Kenni Lund [kenni a kelu dot dk]

I forgot to add that disabling barriers on the ext4 file systems have no impact on the issue.

comment:2 Changed 6 years ago by danielk

I think perhaps we are reading too close to the end of the file.

Does this occur if you skip back a few seconds after LiveTV starts?

i.e. start Live TV, wait 5 seconds, hit the back arrow. Do any new RingBuffer? messages occur in the next minute or so?

Changed 6 years ago by Kenni Lund [kenni a kelu dot dk]

Log illustrating the issue while skipping back and forward

comment:3 Changed 6 years ago by Kenni Lund [kenni a kelu dot dk]

Heh, this is interesting :) When I start LiveTV the playback is 4-5 seconds behind according to the OSD. If I skip back once, it's 10-11 seconds behind, but still spits out the log-messages with the same rate as before. If I skip back once more, it is now 15-16 seconds behind and the log-messages disappear completely. I've uploaded a new log file, mythbackend_log_while_skipping.log, which illustrates this behaviour.

comment:4 Changed 6 years ago by Daniel Thor Kristjansson <danielk@…>

In 483e06f6b8a9066f66cef3fcf0a5f844519f51f9/mythtv:

Refs #10428. Fix off-by-1000 error in RingBuffer?.

The estimated bit rate is in kilobits not bits...

Also increase the seconds of buffering from 0.25 to 0.35
for a better LiveTV experience.

comment:5 Changed 6 years ago by JoeB@…

Hi danielk,

How do we apply this fix? Will it be in an update upstream in the MythTV PPA repository or do we have to do any configuration?

Thanks,

JoeB.

comment:6 Changed 6 years ago by Kenni Lund [kenni a kelu dot dk]

Ticket locked: set

JoeB, please use the mythtv-users mailing list for questions, not our bugtracker. The commit has been committed to master/pre0.26, and it will therefore at least be part of the soon-to-be-released MythTV 0.26. The commit might be backported to 0.25-fixes, if so, you'll see the 0.25-fixes commit here and you should be able to pick it up from the Mythbuntu autobuilds.

comment:7 Changed 6 years ago by danielk

Milestone: unknown0.26
Resolution: Fixed
Status: newclosed

Fixed by [483e06f6b8a].

comment:8 Changed 4 years ago by Jean-Yves Avenard <jyavenard@…>

In 43cba6537fae95cef0ff5ce6ba7352c52abcd947/mythtv:

Never attempt to read more than in 512kB blocks

Also increase the threshold at which we increase the read block size.
512kB ought to be enough to read a file smoothly (famous last words)

This reduces the amount of unnecessary verbosity. When watching a SD 3Mbit/s DVB stream, it will take over a second to get 1MB of data, leading to a warning entry in the log for every single read.

Refs #10428

comment:9 Changed 4 years ago by Jean-Yves Avenard <jyavenard@…>

In 801df9ec4c55df348ec821caf7fc0035300ea2a6/mythtv:

Never attempt to read more than in 512kB blocks

Also increase the threshold at which we increase the read block size.
512kB ought to be enough to read a file smoothly (famous last words)

This reduces the amount of unnecessary verbosity. When watching a SD 3Mbit/s DVB stream, it will take over a second to get 1MB of data, leading to a warning entry in the log for every single read.

Refs #10428

(cherry picked from commit 43cba6537fae95cef0ff5ce6ba7352c52abcd947)

comment:10 Changed 4 years ago by Jean-Yves Avenard <jyavenard@…>

In 1cfdfa3f56876eb20170f33e9592b5c7ffd05064/mythtv:

Never attempt to read more than in 512kB blocks

Recalculate the threshold and read block size when we've encountered EOF several times in a row.
512kB ought to be enough to read a file smoothly (famous last words)

This reduces the amount of unnecessary verbosity. When watching a SD 3Mbit/s DVB stream, it will take over a second to get 1MB of data, leading to a warning entry in the log for every single read.

Refs #10428

comment:11 Changed 4 years ago by Jean-Yves Avenard <jyavenard@…>

In 24aa672b0486ef723c1e4ee15fe66dc3a2334c48/mythtv:

Never attempt to read more than in 512kB blocks

Recalculate the threshold and read block size when we've encountered EOF several times in a row.
512kB ought to be enough to read a file smoothly (famous last words)

This reduces the amount of unnecessary verbosity. When watching a SD 3Mbit/s DVB stream, it will take over a second to get 1MB of data, leading to a warning entry in the log for every single read.

Refs #10428
(cherry picked from commit 1cfdfa3f56876eb20170f33e9592b5c7ffd05064)

comment:12 Changed 4 years ago by Jean-Yves Avenard <jyavenard@…>

In 57c32eacfa87783b75412184cc98c6a46dea99c0/mythtv:

Never attempt to read more than in 512kB blocks

Recalculate the threshold and read block size when we've encountered EOF several times in a row.
512kB ought to be enough to read a file smoothly (famous last words)

This reduces the amount of unnecessary verbosity. When watching a SD 3Mbit/s DVB stream, it will take over a second to get 1MB of data, leading to a warning entry in the log for every single read.

Refs #10428

(cherry picked from commit 1cfdfa3f56876eb20170f33e9592b5c7ffd05064)

Note: See TracTickets for help on using tickets.