[mythtv-commits] Ticket #9864: RingBuffer locking problem
MythTV
noreply at mythtv.org
Thu Jun 23 18:56:44 UTC 2011
#9864: RingBuffer locking problem
-------------------------------------------------+-------------------------
Reporter: Jim Stichnoth <stichnot@…> | Owner: janne
Type: Bug Report - General | Status: new
Priority: minor | Milestone: unknown
Component: MythTV - Video Playback | Version: Trunk Head
Severity: medium | Keywords:
Ticket locked: 0 |
-------------------------------------------------+-------------------------
There is a RingBuffer locking related issue that causes long delays in
loading ISO videos with several titles using storage groups. (This is the
same as issue 2 in #9854.)
See the attached frontend log using "-v
important,general,playback,file,extra". This is for playback of an ISO
with 9 titles, played on an ION frontend, single core, hyperthreading,
gigabit network connection to the backend. There are frequent sections of
the log that look like this:
{{{
2011-06-23 06:05:05.792052 I [20123/20123] CoreContext ringbuffer.cpp:1140
(ReadPriv) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso):
ReadPriv(..2048, normal) @4096 -- begin
2011-06-23 06:05:05.796801 I [20123/20323] RingBuffer ringbuffer.cpp:822
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso):
safe_read(... at 7340032, 1048576) -- begin
2011-06-23 06:05:05.822328 I [20123/20323] RingBuffer ringbuffer.cpp:836
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso):
safe_read(... at 7340032, 1048576) -> 1048576, took 26 ms (322.639Mbps)
2011-06-23 06:05:05.822364 I [20123/20323] RingBuffer ringbuffer.cpp:849
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): rbwpos +=
1024K requested 1024K in read
2011-06-23 06:05:05.822387 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:05.872488 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:05.922579 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:05.972667 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.022773 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.072870 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.122967 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.173060 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.223177 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.273272 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.323366 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.373455 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.423552 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.473641 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.523730 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.573818 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.623906 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.674175 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.724286 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.774376 I [20123/20323] RingBuffer ringbuffer.cpp:896
(run) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso): @ end of read
ahead loop
2011-06-23 06:05:06.792228 I [20123/20123] CoreContext ringbuffer.cpp:1224
(ReadPriv) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso):
ReadPriv(..2048, normal) -- copying data
2011-06-23 06:05:06.792280 I [20123/20123] CoreContext ringbuffer.cpp:1239
(ReadPriv) - RingBuf(myth://Videos@192.168.0.205:6543/test.iso):
ReadPriv(..2048, normal) -- checksum 16626
}}}
Adding extra instrumentation indicates that the thread running ReadPriv()
is delayed for 1 second in the WaitForReadsAllowed() call in the
generalWait.wait() statement, while the readahead thread is idle. It
appears that readsallowed is changing from false to true without a
notification, resulting in the full 1000ms wait. Not sure if the lack of
notification is by design.
A workaround is to change the 1000ms timeout in WaitForReadsAllowed() to
something small like 25ms, resulting in big improvements in startup time.
In this example, the original startup time is 4s to the bookmark dialog
followed by 65s to playback, but with the 25ms timeout the startup time is
1s to the bookmark dialog followed by 14s to playback.
--
Ticket URL: <http://code.mythtv.org/trac/ticket/9864>
MythTV <http://code.mythtv.org/trac>
MythTV Media Center
More information about the mythtv-commits
mailing list