[mythtv-users] Add some timing lines! [was: I'm in....]

[Edward Wildgoose]

> After perusing some code a little (experts, please correct me if I'm
> wrong... I'm just trying to learn/understand and _not_ complaining :-),
> it seems that the thread communication in mythfrontend is a little laxed
> in handling state changes (probably done on purpose because it simplifies
> development, not as many semaphores/mutexes/etc to deal with, which
> means less chance for deadlock).  For instance, in libmythtv/tv_rec.cpp,
> I notice a few busy-waits here and there such as:

This is an interesting avenue to persue:

People who are finding channel changing slow can do some useful tests to find out where the delay is though, rather than just speculating.

For example in tv_play.cpp, patch as follows:

For me at least, using DVB, this shows that there is up to 800ms being wasted in: 
"activenvp->Pause(false);"

I haven't traced down exactly what's causing that, but if this persists for people on analogue tv as well, then you can get nearly a 1 second speedup by fixing this!

Those who are noticing slow channel changes, try doing more stuff like this and try to work out where the slowdown is occuring.  At least this way you can talk accurately about where to put the coding effort.

Note: This routine only covers the delay up until we start piping to the decoder.  You will need to add timing info to other routines to understand the delay while the decoder decides whether it has buffered enough frames to start playing.  This pause is also significant

Good luck!


Index: tv_play.cpp
===================================================================
RCS file: /var/lib/mythcvs/mythtv/libs/libmythtv/tv_play.cpp,v
retrieving revision 1.119
diff -u -r1.119 tv_play.cpp
--- tv_play.cpp 10 Nov 2003 21:45:00 -0000      1.119
+++ tv_play.cpp 17 Nov 2003 10:08:36 -0000
@@ -1669,6 +1669,8 @@

 void TV::ChangeChannel(int direction)
 {
+    QTime qtm;qtm.start();
+    cout << "Starting Channel Change\r\n";
     bool muted = false;

     if (volumeControl && !volumeControl->GetMute() && activenvp == nvp)
@@ -1684,9 +1686,12 @@
         paused = false;
     }

+    cout << "Before Pause:" << qtm.elapsed() << "\r\n";
     activenvp->Pause(false);
+    cout << "Pause Issued:" << qtm.elapsed() << "\r\n";
     // all we care about is the ringbuffer being paused, here..
     activerbuffer->WaitForPause();
+    cout << "Paused:" << qtm.elapsed() << "\r\n";

     // Save the current channel if this is the first time
     if (channame_vector.size() == 0 && activenvp == nvp)
@@ -1694,10 +1699,14 @@

     activerecorder->Pause();
     activerbuffer->Reset();
+    cout << "Active Recorder Paused:" << qtm.elapsed() << "\r\n";
     activerecorder->ChangeChannel(direction);
+    cout << "Active Recorder Channel Changed:" << qtm.elapsed() << "\r\n";

     activenvp->ResetPlaying();
+    cout << "Reset Playing:" << qtm.elapsed() << "\r\n";
     activenvp->Unpause(false);
+    cout << "Un Paused:" << qtm.elapsed() << "\r\n";

     if (activenvp == nvp)
     {