<br><br><div class="gmail_quote">On Fri, Oct 12, 2012 at 6:15 AM, Ronald Frazier <span dir="ltr"><<a href="mailto:ron@ronfrazier.net" target="_blank">ron@ronfrazier.net</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<div class="im">On Fri, Oct 12, 2012 at 1:27 AM, Chris Pinkham <<a href="mailto:cpinkham@bc2va.org">cpinkham@bc2va.org</a>> wrote:<br>
> * On Thu Oct 11, 2012 at 10:39:08PM -0400, Ronald Frazier wrote:<br>
>> 2012-10-11 22:02:42.595376 D DownloadManager: downloadProgress:<br>
>> <a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService</a><br>
>> to is at 53402 of -1 bytes downloaded<br>
><br>
>> 2012-10-11 22:02:52.596673 D DownloadManager: Aborting download -<br>
>> lack of data transfer<br>
><br>
>> You can see at 2012-10-11 22:02:52.596673 it seems to time out and<br>
>> abort. I will say that Krys seems to have 3 lineups that are all (at<br>
>> least to me) quite large in number of channels. Not sure if that has<br>
>> anything to do with it (maybe SD is taking longer to process some of<br>
>> the data or something.<br>
><br>
> This is due to the 10-second idle timeout in mythdownloadmanager.cpp.<br>
><br>
> I'm curious how long this is taking to see if it makes sense to bump the<br>
> timeout up or if we're going to allow specifying a timeout per download<br>
> to allow Schedules Direct / TMS downloads to take longer.<br>
><br>
> If you compile from source, can you try something?<br>
><br>
> Edit libs/libmythbase/mythdownloadmanager.cpp and look around line 816 for this:<br>
><br>
> (dlInfo->m_lastStat.secsTo(MythDate::current()) < 10)) ||<br>
><br>
> Change that 10 to a 15 and try again. If that doesn't work, bump it up to 20<br>
> and try again, seeing how high you have to go to get it to work. Also, how<br>
> many channels are we talking about?<br>
<br>
<br>
</div>I didn't have time this morning to give it multiple tries, so I just<br>
bumped it right to 120 seconds and it worked. The logs are below. It<br>
looks like we had about a 45 second pause. As for the reason why, I<br>
haven't looked at the SD output in a few years, but isn't it broken<br>
into multiple sections...like <list of channels><list of<br>
programs><list of descriptions><list of actors> or something? My guess<br>
is that their system streams each section as it is generated and there<br>
is a large pause at the beginning of generating one of the sections.<br>
<br>
<br>
<br>
2012-10-12 07:04:03.349695 D MythSocketThread: Got data on select<br>
2012-10-12 07:04:03.349715 D MythSocketThread: Processing ready reads<br>
2012-10-12 07:04:03.349744 D MythSocketThread(sock<br>
0x7fd8a000f860:64): socket is readable<br>
2012-10-12 07:04:03.349759 D MythSocketThread(sock<br>
0x7fd8a000f860:64): calling m_cb->readyRead()<br>
2012-10-12 07:04:03.349787 D MythSocket(7fd8a000f860:64):<br>
readBlock(0x7fd8a00bad48, 8) called<br>
2012-10-12 07:04:03.349815 D MythSocket(7fd8a000f860:64):<br>
readBlock(0x7fd8a09dde38, 82) called<br>
2012-10-12 07:04:03.349847 I MythSocket(7fd8a000f860:64): read <- 64<br>
82 BACKEND_MESSAGE[]:[]UPDATE_FILE_SIZE 6259 2012-10-12T10:52:38<br>
1346305036[]:[]empty<br>
2012-10-12 07:04:03.349870 I MythEvent: UPDATE_FILE_SIZE 6259<br>
2012-10-12T10:52:38 1346305036<br>
2012-10-12 07:04:03.349907 D MythSocketThread: Total read time: 0ms,<br>
on sockets {64,0ms}<br>
2012-10-12 07:04:03.349919 D MythSocketThread: Reacquired ready read lock<br>
2012-10-12 07:04:03.349948 D MythSocketThread: ProcessAddRemoveQueues<br>
2012-10-12 07:04:03.349953 D MythSocketThread: Construct FD_SET<br>
2012-10-12 07:04:03.349961 D MythSocketThread: Waiting on select..<br>
2012-10-12 07:04:07.562482 I Fetching lineups from Schedules Direct...<br>
2012-10-12 07:04:07.609753 I DataDirect: Grabbing channel data<br>
2012-10-12 07:04:07.609839 I Downloading DataDirect feed<br>
2012-10-12 07:04:07.670611 D DownloadManager:<br>
postAuth('<a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService</a>',<br>
'140735795771536')<br>
2012-10-12 07:04:07.671622 D Checking cache for<br>
<a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService
2012-10-12" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService<br>
2012-10-12</a> 07:04:08.476154 D Calling auth callback<br>
2012-10-12 07:04:08.476172 D DataDirect auth callback<br>
2012-10-12 07:04:10.278472 D DownloadManager: downloadProgress(10,<br>
-1) (for reply 22743888)<br>
2012-10-12 07:04:10.278518 D DownloadManager: downloadProgress:<br>
<a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService</a><br>
<div class="im">to is at 10 of -1 bytes downloaded<br>
</div>2012-10-12 07:04:11.279312 D DownloadManager: downloadProgress(25520,<br>
-1) (for reply 22743888)<br>
2012-10-12 07:04:11.279340 D DownloadManager: downloadProgress:<br>
<a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService</a><br>
<div class="im">to is at 25520 of -1 bytes downloaded<br>
</div>2012-10-12 07:04:11.679727 D DownloadManager: downloadProgress(34280,<br>
-1) (for reply 22743888)<br>
2012-10-12 07:04:11.679775 D DownloadManager: downloadProgress:<br>
<a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService</a><br>
to is at 34280 of -1 bytes downloaded<br>
2012-10-12 07:04:11.880015 D DownloadManager: downloadProgress(53402,<br>
-1) (for reply 22743888)<br>
2012-10-12 07:04:11.880045 D DownloadManager: downloadProgress:<br>
<div class="im"><a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService</a><br>
to is at 53402 of -1 bytes downloaded<br>
</div>2012-10-12 07:04:13.353145 D MythSocketThread: Got data on select<br>
2012-10-12 07:04:13.353158 D MythSocketThread: Processing ready reads<br>
2012-10-12 07:04:13.353183 D MythSocketThread(sock<br>
0x7fd8a000f860:64): socket is readable<br>
2012-10-12 07:04:13.353196 D MythSocketThread(sock<br>
0x7fd8a000f860:64): calling m_cb->readyRead()<br>
2012-10-12 07:04:13.353219 D MythSocket(7fd8a000f860:64):<br>
readBlock(0x7fd8ac2d0828, 8) called<br>
2012-10-12 07:04:13.353240 D MythSocket(7fd8a000f860:64):<br>
readBlock(0x7fd8ac0a6e68, 82) called<br>
2012-10-12 07:04:13.353262 I MythSocket(7fd8a000f860:64): read <- 64<br>
82 BACKEND_MESSAGE[]:[]UPDATE_FILE_SIZE 6259 2012-10-12T10:52:38<br>
1365753448[]:[]empty<br>
2012-10-12 07:04:13.353280 I MythEvent: UPDATE_FILE_SIZE 6259<br>
2012-10-12T10:52:38 1365753448<br>
2012-10-12 07:04:13.353304 D MythSocketThread: Total read time: 0ms,<br>
on sockets {64,0ms}<br>
2012-10-12 07:04:13.353310 D MythSocketThread: Reacquired ready read lock<br>
2012-10-12 07:04:13.353315 D MythSocketThread: ProcessAddRemoveQueues<br>
2012-10-12 07:04:13.353319 D MythSocketThread: Construct FD_SET<br>
2012-10-12 07:04:13.353326 D MythSocketThread: Waiting on select..<br>
2012-10-12 07:04:23.358183 D MythSocketThread: Got data on select<br>
2012-10-12 07:04:23.358202 D MythSocketThread: Processing ready reads<br>
2012-10-12 07:04:23.358255 D MythSocketThread(sock<br>
0x7fd8a000f860:64): socket is readable<br>
2012-10-12 07:04:23.358268 D MythSocketThread(sock<br>
0x7fd8a000f860:64): calling m_cb->readyRead()<br>
2012-10-12 07:04:23.358292 D MythSocket(7fd8a000f860:64):<br>
readBlock(0x7fd8ac3b2668, 8) called<br>
2012-10-12 07:04:23.358313 D MythSocket(7fd8a000f860:64):<br>
readBlock(0x7fd8ac0a6e68, 82) called<br>
2012-10-12 07:04:23.358334 I MythSocket(7fd8a000f860:64): read <- 64<br>
82 BACKEND_MESSAGE[]:[]UPDATE_FILE_SIZE 6259 2012-10-12T10:52:38<br>
1384674708[]:[]empty<br>
2012-10-12 07:04:23.358351 I MythEvent: UPDATE_FILE_SIZE 6259<br>
2012-10-12T10:52:38 1384674708<br>
2012-10-12 07:04:23.358379 D MythSocketThread: Total read time: 0ms,<br>
on sockets {64,0ms}<br>
2012-10-12 07:04:23.358384 D MythSocketThread: Reacquired ready read lock<br>
2012-10-12 07:04:23.358390 D MythSocketThread: ProcessAddRemoveQueues<br>
2012-10-12 07:04:23.358393 D MythSocketThread: Construct FD_SET<br>
2012-10-12 07:04:23.358400 D MythSocketThread: Waiting on select..<br>
2012-10-12 07:04:33.363553 D MythSocketThread: Got data on select<br>
2012-10-12 07:04:33.363572 D MythSocketThread: Processing ready reads<br>
2012-10-12 07:04:33.363596 D MythSocketThread(sock<br>
0x7fd8a000f860:64): socket is readable<br>
2012-10-12 07:04:33.363626 D MythSocketThread(sock<br>
0x7fd8a000f860:64): calling m_cb->readyRead()<br>
2012-10-12 07:04:33.363651 D MythSocket(7fd8a000f860:64):<br>
readBlock(0x7fd8ac3b2668, 8) called<br>
2012-10-12 07:04:33.363672 D MythSocket(7fd8a000f860:64):<br>
readBlock(0x7fd8ac0a6e68, 82) called<br>
2012-10-12 07:04:33.363694 I MythSocket(7fd8a000f860:64): read <- 64<br>
82 BACKEND_MESSAGE[]:[]UPDATE_FILE_SIZE 6259 2012-10-12T10:52:38<br>
1402962784[]:[]empty<br>
2012-10-12 07:04:33.363712 I MythEvent: UPDATE_FILE_SIZE 6259<br>
2012-10-12T10:52:38 1402962784<br>
2012-10-12 07:04:33.363737 D MythSocketThread: Total read time: 0ms,<br>
on sockets {64,0ms}<br>
2012-10-12 07:04:33.363743 D MythSocketThread: Reacquired ready read lock<br>
2012-10-12 07:04:33.363749 D MythSocketThread: ProcessAddRemoveQueues<br>
2012-10-12 07:04:33.363756 D MythSocketThread: Construct FD_SET<br>
2012-10-12 07:04:33.363763 D MythSocketThread: Waiting on select..<br>
2012-10-12 07:04:43.368358 D MythSocketThread: Got data on select<br>
2012-10-12 07:04:43.368371 D MythSocketThread: Processing ready reads<br>
2012-10-12 07:04:43.368393 D MythSocketThread(sock<br>
0x7fd8a000f860:64): socket is readable<br>
2012-10-12 07:04:43.368405 D MythSocketThread(sock<br>
0x7fd8a000f860:64): calling m_cb->readyRead()<br>
2012-10-12 07:04:43.368446 D MythSocket(7fd8a000f860:64):<br>
readBlock(0x7fd8ac39f128, 8) called<br>
2012-10-12 07:04:43.368470 D MythSocket(7fd8a000f860:64):<br>
readBlock(0x7fd8ac6eb098, 82) called<br>
2012-10-12 07:04:43.368491 I MythSocket(7fd8a000f860:64): read <- 64<br>
82 BACKEND_MESSAGE[]:[]UPDATE_FILE_SIZE 6259 2012-10-12T10:52:38<br>
1422676840[]:[]empty<br>
2012-10-12 07:04:43.368509 I MythEvent: UPDATE_FILE_SIZE 6259<br>
2012-10-12T10:52:38 1422676840<br>
2012-10-12 07:04:43.368533 D MythSocketThread: Total read time: 0ms,<br>
on sockets {64,0ms}<br>
2012-10-12 07:04:43.368538 D MythSocketThread: Reacquired ready read lock<br>
2012-10-12 07:04:43.368544 D MythSocketThread: ProcessAddRemoveQueues<br>
2012-10-12 07:04:43.368549 D MythSocketThread: Construct FD_SET<br>
2012-10-12 07:04:43.368556 D MythSocketThread: Waiting on select..<br>
2012-10-12 07:04:53.373195 D MythSocketThread: Got data on select<br>
2012-10-12 07:04:53.373209 D MythSocketThread: Processing ready reads<br>
2012-10-12 07:04:53.373231 D MythSocketThread(sock<br>
0x7fd8a000f860:64): socket is readable<br>
2012-10-12 07:04:53.373242 D MythSocketThread(sock<br>
0x7fd8a000f860:64): calling m_cb->readyRead()<br>
2012-10-12 07:04:53.373266 D MythSocket(7fd8a000f860:64):<br>
readBlock(0x7fd8ac1d9c38, 8) called<br>
2012-10-12 07:04:53.373286 D MythSocket(7fd8a000f860:64):<br>
readBlock(0x7fd8ac07f758, 82) called<br>
2012-10-12 07:04:53.373306 I MythSocket(7fd8a000f860:64): read <- 64<br>
82 BACKEND_MESSAGE[]:[]UPDATE_FILE_SIZE 6259 2012-10-12T10:52:38<br>
1442569308[]:[]empty<br>
2012-10-12 07:04:53.373324 I MythEvent: UPDATE_FILE_SIZE 6259<br>
2012-10-12T10:52:38 1442569308<br>
2012-10-12 07:04:53.373384 D MythSocketThread: Total read time: 0ms,<br>
on sockets {64,0ms}<br>
2012-10-12 07:04:53.373392 D MythSocketThread: Reacquired ready read lock<br>
2012-10-12 07:04:53.373398 D MythSocketThread: ProcessAddRemoveQueues<br>
2012-10-12 07:04:53.373402 D MythSocketThread: Construct FD_SET<br>
2012-10-12 07:04:53.373409 D MythSocketThread: Waiting on select..<br>
2012-10-12 07:04:56.506536 D DownloadManager: downloadProgress(82416,<br>
-1) (for reply 22743888)<br>
2012-10-12 07:04:56.506565 D DownloadManager: downloadProgress:<br>
<a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService</a><br>
to is at 82416 of -1 bytes downloaded<br>
2012-10-12 07:04:56.906929 D DownloadManager: downloadProgress(91176,<br>
-1) (for reply 22743888)<br>
2012-10-12 07:04:56.906959 D DownloadManager: downloadProgress:<br>
<a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService</a><br>
to is at 91176 of -1 bytes downloaded<br>
2012-10-12 07:04:57.107181 D DownloadManager:<br>
downloadProgress(109308, -1) (for reply 22743888)<br>
2012-10-12 07:04:57.107210 D DownloadManager: downloadProgress:<br>
<a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService</a><br>
to is at 109308 of -1 bytes downloaded<br>
2012-10-12 07:04:57.707630 D DownloadManager:<br>
downloadProgress(118068, -1) (for reply 22743888)<br>
2012-10-12 07:04:57.707676 D DownloadManager: downloadProgress:<br>
<a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService</a><br>
to is at 118068 of -1 bytes downloaded<br>
2012-10-12 07:04:57.907954 D DownloadManager:<br>
downloadProgress(135636, -1) (for reply 22743888)<br>
2012-10-12 07:04:57.907990 D DownloadManager: downloadProgress:<br>
<a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService</a><br>
to is at 135636 of -1 bytes downloaded<br>
2012-10-12 07:04:59.308945 D DownloadManager:<br>
downloadProgress(169890, -1) (for reply 22743888)<br>
2012-10-12 07:04:59.308991 D DownloadManager: downloadProgress:<br>
<a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService</a><br>
to is at 169890 of -1 bytes downloaded<br>
2012-10-12 07:04:59.709494 D DownloadManager:<br>
downloadProgress(169890, 169890) (for reply 22743888)<br>
2012-10-12 07:04:59.709520 D DownloadManager: downloadProgress:<br>
<a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService</a><br>
to is at 169890 of 169890 bytes downloaded<br>
2012-10-12 07:04:59.709554 D DownloadManager: downloadFinished(22743888)<br>
2012-10-12 07:04:59.709585 D DownloadManager: redirectUrl()<br>
2012-10-12 07:04:59.709603 D downloadFinished(140568576492288):<br>
COMPLETE: <a href="http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService
2012-10-12" target="_blank">http://webservices.schedulesdirect.tmsdatadirect.com/schedulesdirect/tvlistings/xtvdService<br>
2012-10-12</a> 07:04:59.710171 I Downloaded 169890 bytes<br>
<span class="HOEnZb"><font color="#888888"><br>
<br>
<br>
--<br>
Ron Frazier<br>
</font></span><div class="HOEnZb"><div class="h5">_______________________________________________<br>
mythtv-users mailing list<br>
<a href="mailto:mythtv-users@mythtv.org">mythtv-users@mythtv.org</a><br>
<a href="http://www.mythtv.org/mailman/listinfo/mythtv-users" target="_blank">http://www.mythtv.org/mailman/listinfo/mythtv-users</a><br>
</div></div></blockquote></div><br><div><br></div><div>I didn't have time to get real scientific, however I added and removed channels manually from my lineup to try and see where the breaking point was. It turns out that its real flaky and I don't know that there is a set amount of channels that causes it to fail. One thing I did find was that if I tried to create a new source with all of my channels it would fail, but if I go into SD and remove most of my channels then the fetch would work. Where it gets interesting is I can then go back to SD and add all of my channels back in and the fetch would still work as long as I don't exit out of the source screen.</div>