[mythtv] ringbuffer.cpp

[Jonas Arndt]

On 02/20/2014 04:56 PM, Jean-Yves Avenard wrote:
>
>
> Le vendredi 21 février 2014, Jonas Arndt 
> <jonas.arndt at thearndtfamily.com 
> <mailto:jonas.arndt at thearndtfamily.com>> a écrit :
>
>
>
>
>     I actually had a freeze on my system just now. This after having
>     worked all day. I am on the committed patch on the back-end. Just
>     rewinding slightly on the front-end, followed by a pause/play
>     fixed it.
>
>
> Well, that's a big improvement already, with the previous bug, it 
> wouldn't  have recovered at all.
>
> But your issue is different here.
>
>
>     On the backend, just
>     Feb 20 15:52:03 myth1204 mythbackend: mythbackend[14662]: N Expire
>     autoexpire.cpp:641 (SendDeleteMessages) Expiring 0 MB for 7653 at
>     2014-02-20T22:50:42Z => "The Ellen DeGeneres Show"
>     Feb 20 15:54:03 myth1204 mythbackend: mythbackend[14662]: N Expire
>     autoexpire.cpp:641 (SendDeleteMessages) Expiring 18 MB for 7653 at
>     2014-02-20T22:50:43Z => "The Ellen DeGeneres Show"
>     Feb 20 15:54:03 myth1204 mythbackend: mythbackend[14662]: N Expire
>     autoexpire.cpp:641 (SendDeleteMessages) Expiring 0 MB for 7689 at
>     2014-02-20T22:51:04Z => "XXII Winter Olympics":Hockey
>     Feb 20 16:04:03 myth1204 mythbackend: mythbackend[14662]: N Expire
>     autoexpire.cpp:264 (CalcParams) AutoExpire: CalcParams(): Max
>     required Free Space: 3.0 GB w/freq: 14 min
>     Feb 20 16:04:03 myth1204 mythbackend: mythbackend[14662]: N Expire
>     autoexpire.cpp:641 (SendDeleteMessages) Expiring 9983 MB for 7736
>     at 2014-02-20T02:03:01Z => "Billy Madison"
>     Feb 20 16:04:11 myth1204 mythbackend: mythbackend[14662]: W
>     TFWWrite threadedfilewriter.cpp:545 (DiskLoop)
>     TFW(/Recordings/7689_20140220225105.mpg:85): write(65424) cnt 131
>     total 8540088 -- took a long time, 4082 ms
>     Feb 20 16:04:16 myth1204 mythbackend: mythbackend[14662]: W
>     TFWWrite threadedfilewriter.cpp:545 (DiskLoop)
>     TFW(/Recordings/7689_20140220225105.mpg:85): write(65424) cnt 132
>     total 8503240 -- took a long time, 3919 ms
>
>     Could this be the other issue you were talking about?
>
>
> No. It's something else. Look at how long it takes for your backend to 
> write 64kB of data: over 4s each time.
> There's no way playback can recover from that, nor anything I can do 
> about it. Writing is just too slow, it will sooner or later exhaust 
> the buffer and the frontend as no other choice but pause.
>
> Now of course, what the frontend does next is another problem 
> altogether: it doesn't restart.
> But you can't prevent that freeze.
>
> You see on my system, it never takes more than a few ms to write 64kB, 
> it may sometimes takes slightly more if the system finds itself very 
> busy. But 4s, no way.
>
> You need to look at your hardware here, I'll push soon some unit tests 
> that stress the disks and give you some some benchmark about the speed 
> of your disk.
>
> Also, if there was a problem in myth (which in your particular case, I 
> doubt) you've truncated your logs way too much, and it doesn't have 
> the info I would need.
> You need to start the backend with -v file --loglevel=debug
>
> I strongly recommend you modify the threadedfilewriter.cpp file and 
> comment the two lines I mentioned earlier, otherwise you'll die under 
> the amount of logs it will spit out.
>
> If it took a day for the system to experience the issue, that's MB 
> over MB of logs.
>
> You need to track what else your backend was doing at the time, but 8s 
> to write 128kB isn't good
>
>
Yeah, all good points.
I have the libmythbase-0.27.so.0.27.0 with the commented out log in 
place. I will activate when I get home later to night. In my case I am 
running on a VM with direct access to a physical 1TB disk. I am thinking 
there could be other reasons why  it was slow at writing to the disk 
(there are other VMs on the host, but they don't have access to this 
disk). I am running sysstat on the VM. The only thing I could see going 
on there at this time was a peek in "dentunusd" (Number of unused cache 
entries in the directory cache). The peak was not high though. I have 
much higher values when the system is unloaded. I just noted the peak at 
the exact time when we had the long writes. On the host there was no 
changes in resources around that time (sysstat there as well).

Thanks,

// Jonas
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.mythtv.org/pipermail/mythtv-dev/attachments/20140220/98ad20e9/attachment.html>