View unanswered posts    View active topics

All times are UTC - 6 hours





Post new topic Reply to topic  [ 22 posts ] 
Go to page 1, 2  Next

Print view Previous topic   Next topic  
Author Message
Search for:
PostPosted: Thu Mar 01, 2007 9:37 am 
Offline
Joined: Sat Feb 11, 2006 5:26 pm
Posts: 282
Location: Winnipeg - Canada
I was running into this problem previously, but upping my mpg buffers to 16mb did the trick. I've since gone into my recording profiles and increased my bitrate to squeeze out slightly better quality (now running at 720 by 480 instead of 480 by 480) Click here to read thread regarding increase to my bitrate

I'm not positive, but i'm fairly certain that the following errors occured last night during a timeframe when I was recording 2 shows and my mythfilldatabase executed.

Code:
Feb 28 23:25:01 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Feb 28 23:25:14 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Feb 28 23:25:21 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Feb 28 23:25:24 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Feb 28 23:25:26 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Feb 28 23:25:30 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Feb 28 23:25:34 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Feb 28 23:26:52 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Feb 28 23:27:02 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Feb 28 23:27:15 backend kernel: ivtv0: Cause: the application is not reading fast enough.


This was discussed here (among other places) and a "fix" had been found that seemed to do the job for me. I had bumped my mpg buffers to 16mb and things were running smoothly.

http://mysettopbox.tv/phpBB2/viewtopic. ... highlight=

Things are no longer running smoothly, I'm now encountering the same glitching and the same errors in my log. I suppose it stands to reason that if my bitrate is higher my buffers fill faster, and I experience the same problem as I was previously.

There was talk elsewhere of patching MythTV or something, but it messed up mythweb (and a few other minor things) and it also sounded like it wasn't even effective at solving the problem.

I did a bit of searching, and have stumbled on a few things that look to me like they may be related. Here is one set of posts that I had read.

http://www.mail-archive.com/ivtv-devel@ ... 04294.html

Is this indicating that this is an IVTV problem? Is there a new version I could/should be running that might clear this up? I'm currently running R5E50 with whatever version of IVTV it comes with.

Does anybody know if there has been any progress towards an actual fix for this rather than simply treating the symptoms by giving it a bigger buffer to work with so that it doesn't overrun itself during certain activities.

EDIT: Here is a little more information, it seems that I'm running 0.8.2

Code:
root@backend:~# dmesg | grep ivtv
ivtv:  ==================== START INIT IVTV ====================
ivtv:  version 0.8.2 (tagged release) loading


My Kernel is 2.6.18
Code:
root@backend:~# uname -a
Linux backend 2.6.18-chw-13 #1 SMP PREEMPT Sun Dec 3 23:47:01 PST 2006 i686 GNU/Linux


Wiki wrote:
If your kernel is 2.6.18 you must use one of the 0.8.x or 0.10.x series drivers.


Will the 0.10.x series correct this issue? Here is the Wiki link for updating IVTV, will proceeding with the steps here lessen my headache at all?

_________________
Currently Running:
Too lazy to update this with my current hardware, I'll redo it during my next install =)


Last edited by rando on Sat Mar 03, 2007 11:41 am, edited 1 time in total.


Top
 Profile  
 
 Post subject:
PostPosted: Thu Mar 01, 2007 12:34 pm 
Offline
Joined: Thu Apr 27, 2006 1:07 am
Posts: 54
Let me know if the 0.10.x drivers resolve for you. I still think the thread for the patch mentioned earlier implies the issue is driven by the MythTV code rather than ivtv but that is not to say that if 0.10.x is more efficient that it may make the issue not show up. I am suprised that more folks are not seeing this. How many tuners do you have? I have a PVR-150 and PVR-500 so with the three buffers maybe that is the knee of the curve. With the 16 Mb buffer we discussed earlier I still see this creep up every now and then but not near as often with the default buffer size.


Top
 Profile  
 
 Post subject:
PostPosted: Thu Mar 01, 2007 12:45 pm 
Offline
Joined: Sat Feb 11, 2006 5:26 pm
Posts: 282
Location: Winnipeg - Canada
I've been reading a little more about this throughout the morning, and I agree, it's starting to seem to me like it's not an IVTV error, but a MythTV error. I think other people have known this all along, but I've just clued in on this recently....

I am running a pair of PVR 150s. I was running at the default bitrate for my recordings, and things where working good with 16mb buffers. I've recently upped my resolution to 720 by 480 (and increased my bitrate as well) which has caused the problem to crop up again. I guess it's not surprising to see that more bitrate = faster buffer filling. The other change I've introduced lately is that I"m starting to encode a very large amount of my recordings to XviD files..... which is running at a nice 19, but still may be getting in the way somehow, I dunno.

I'm going to hold off on putting 0.10 in as at this point it seems to me that it's not going to solve things.... I'd rather not muck up more stuff, I'm only a moderately advanced linux user, and I could very easily find myself in deep water if I play too much.....

For now I'm increasing my buffers to 64mb each, and will see what that yields me over the next few days.

Does anybody know if there is a way to see how much of a buffer is in use? sgunther, you mentioned in another post that "modinfo ivtv" would show the buffers.... but I don't see anything in the output of that that would tell me how full my buffers are......

_________________
Currently Running:
Too lazy to update this with my current hardware, I'll redo it during my next install =)


Top
 Profile  
 
 Post subject:
PostPosted: Thu Mar 01, 2007 12:58 pm 
Offline
Joined: Thu Apr 27, 2006 1:07 am
Posts: 54
The modinfo shows the default but does not mention max values. I got on the ivtv IRC a few weeks back and the concensus on the channel was that you are limited by installed memory. The buffer will always allocate all memory you specify but in terms of how much is used I don't know any way to show filled buffer amount. If you jump to 64mb it would be an interesting test point to see if this is a "patch" for the time being. I am running at 2500 kbps default -3500 kbps max for ~1.2 gb per hour (quality is not great but I want the space...) So I am putting ~ 8500 kbps to 11000 kbps on the bus with a 16 Mb buffer per card.


Top
 Profile  
 
 Post subject:
PostPosted: Thu Mar 01, 2007 1:13 pm 
Offline
Joined: Sat Feb 11, 2006 5:26 pm
Posts: 282
Location: Winnipeg - Canada
Jumping from 4mb to 16mb certainly made a diff when I did that a few weeks back. It's just since I've upped my bitrate and/or piled on other tasks (like the Xvid encoding) that i've started to notice this again.....

To me that suggests that increasing the buffer is a good bandaid fix, it's just a matter of finding out how high it needs to be increased for each particular set of circumstances. I don't have the numbers handy for what I ended up bumping my bitrates to.... but I can peek later and see what my values are.

I'm currently recording 2 shows (at my highest quality - can't recall bitrate), flagging a set of commerials, encoding an Xvid and manually running mythfilldatabase in an effort to cause my box to stumble..... hopefully the jump to 64mb will prove sufficient for me.

_________________
Currently Running:
Too lazy to update this with my current hardware, I'll redo it during my next install =)


Top
 Profile  
 
 Post subject:
PostPosted: Thu Mar 01, 2007 1:32 pm 
Offline
Joined: Sat Feb 11, 2006 5:26 pm
Posts: 282
Location: Winnipeg - Canada
No go, still hitting problems with this.

Code:
root@backend:~# tail -f /var/log/kern.log | grep application




13:07 database fill started
Mar  1 13:16:07 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:16:25 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:16:32 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:16:43 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:16:43 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Mar  1 13:16:55 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Mar  1 13:17:13 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:17:13 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Mar  1 13:17:22 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:17:24 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:20:05 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:20:12 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:20:27 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Mar  1 13:20:33 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:20:35 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Mar  1 13:23:03 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Mar  1 13:23:06 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:23:15 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Mar  1 13:23:18 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Mar  1 13:23:28 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:23:46 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Mar  1 13:23:46 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:23:52 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:23:56 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Mar  1 13:24:00 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:24:03 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Mar  1 13:24:16 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:24:32 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:24:41 backend kernel: ivtv0: Cause: the application is not reading fast enough.
Mar  1 13:24:48 backend kernel: ivtv0: Cause: the application is not reading fast enough.


Here is what I was able to grab from the mythfilldatabase output (i should have redirected the output to a file, but i didn't think of that until after)


Code:
2007-03-01 13:11:07.665 Data is already present for Mon Mar 12 2007, skipping
2007-03-01 13:11:07.665
2007-03-01 13:11:07.665 Checking day @ offset 12, date: Tue Mar 13 2007
2007-03-01 13:11:07.728 Data Refresh needed because offset day 12 has less than 4 programs per channel for the 6PM - midnight time window for channels that normally have data. We want at least 252 programs, but only found 220
2007-03-01 13:11:07.962 Refreshing data for Tue Mar 13 2007
2007-03-01 13:11:08.009 Retrieving datadirect data.
2007-03-01 13:11:08.010 Grabbing data for Thu Mar 1 2007 offset 12
2007-03-01 13:11:08.010 From Tue Mar 13 06:00:00 2007 to Wed Mar 14 06:00:00 2007 (UTC)
2007-03-01 13:11:08.010 Grabbing listing data
--13:11:08--  http://datadirect.webservices.zap2it.com/tvlistings/xtvdService
           => `-'
Resolving datadirect.webservices.zap2it.com... 206.18.98.160
Connecting to datadirect.webservices.zap2it.com|206.18.98.160|:80... connected.
HTTP request sent, awaiting response... 401 Unauthorized
Reusing existing connection to datadirect.webservices.zap2it.com:80.
HTTP request sent, awaiting response... 200 OK
Length: unspecified [text/xml]

    [           <=>                                             ] 285,126       54.73K/s

13:11:13 (54.69 KB/s) - `-' saved [285126]

2007-03-01 13:11:14.405 DataDirect: Your subscription expires on 05/22/07 17:23:00
2007-03-01 13:11:31.244 Grab complete.  Actual data from Tue Mar 13 06:00:00 2007 to Wed Mar 14 06:00:00 2007 (UTC)
2007-03-01 13:11:31.503 Main temp tables populated.
2007-03-01 13:11:31.650 Clearing data for source.
2007-03-01 13:11:31.650 Clearing from Tue Mar 13 01:00:00 2007 to Wed Mar 14 01:00:00 2007 (localtime)
2007-03-01 13:12:14.436 Data for source cleared.
2007-03-01 13:12:14.436 Updating programs.
2007-03-01 13:12:30.308 Program table update complete.
2007-03-01 13:12:30.308
2007-03-01 13:12:30.308 Checking day @ offset 13, date: Wed Mar 14 2007
2007-03-01 13:12:32.217 Data Refresh needed because offset day 13 has less than 4 programs per channel for the 6PM - midnight time window for channels that normally have data. We want at least 236 programs, but only found 33
2007-03-01 13:12:32.217 Refreshing data for Wed Mar 14 2007
2007-03-01 13:12:32.218 Retrieving datadirect data.
2007-03-01 13:12:32.218 Grabbing data for Thu Mar 1 2007 offset 13
2007-03-01 13:12:32.218 From Wed Mar 14 06:00:00 2007 to Thu Mar 15 06:00:00 2007 (UTC)
2007-03-01 13:12:32.219 Grabbing listing data
--13:12:32--  http://datadirect.webservices.zap2it.com/tvlistings/xtvdService
           => `-'
Resolving datadirect.webservices.zap2it.com... 206.18.98.160
Connecting to datadirect.webservices.zap2it.com|206.18.98.160|:80... connected.
HTTP request sent, awaiting response... 401 Unauthorized
Reusing existing connection to datadirect.webservices.zap2it.com:80.
HTTP request sent, awaiting response... 200 OK
Length: unspecified [text/xml]

    [             <=>                                           ] 374,468       69.88K/s

13:12:37 (69.80 KB/s) - `-' saved [374468]

2007-03-01 13:12:38.105 DataDirect: Your subscription expires on 05/22/07 17:23:00
2007-03-01 13:13:03.381 Grab complete.  Actual data from Tue Mar 13 00:00:00 2007 to Wed Mar 14 23:59:59 2007 (UTC)
2007-03-01 13:13:03.383 Main temp tables populated.
2007-03-01 13:13:03.610 Clearing data for source.
2007-03-01 13:13:03.611 Clearing from Mon Mar 12 19:00:00 2007 to Wed Mar 14 18:59:59 2007 (localtime)
2007-03-01 13:13:47.547 Data for source cleared.
2007-03-01 13:13:47.547 Updating programs.
2007-03-01 13:14:10.834 Program table update complete.
2007-03-01 13:14:10.834 Updating source #2 (Digital Source) with grabber datadirect
2007-03-01 13:14:10.835
2007-03-01 13:14:10.835 Checking day @ offset 0, date: Thu Mar 1 2007
2007-03-01 13:14:19.646 Data is already present for Thu Mar 1 2007, skipping
2007-03-01 13:14:19.646
2007-03-01 13:14:19.646 Checking day @ offset 1, date: Fri Mar 2 2007
2007-03-01 13:14:19.646 Refreshing data for Fri Mar 2 2007
2007-03-01 13:14:19.683 Retrieving datadirect data.
2007-03-01 13:14:19.683 Grabbing data for Thu Mar 1 2007 offset 1
2007-03-01 13:14:19.683 From Fri Mar 2 06:00:00 2007 to Sat Mar 3 06:00:00 2007 (UTC)
2007-03-01 13:14:19.683 Grabbing listing data
--13:14:19--  http://datadirect.webservices.zap2it.com/tvlistings/xtvdService
           => `-'
Resolving datadirect.webservices.zap2it.com... 206.18.98.160
Connecting to datadirect.webservices.zap2it.com|206.18.98.160|:80... connected.
HTTP request sent, awaiting response... 401 Unauthorized
Reusing existing connection to datadirect.webservices.zap2it.com:80.
HTTP request sent, awaiting response... 200 OK
Length: unspecified [text/xml]

    [                <=>                                        ] 333,734       40.61K/s

13:14:28 (40.58 KB/s) - `-' saved [333734]

2007-03-01 13:14:28.851 DataDirect: Your subscription expires on 05/22/07 17:23:00
2007-03-01 13:14:47.544 Grab complete.  Actual data from Fri Mar 2 06:00:00 2007 to Sat Mar 3 06:00:00 2007 (UTC)
2007-03-01 13:14:47.545 Main temp tables populated.
2007-03-01 13:14:47.545 Updating myth channels.
2007-03-01 13:14:47.852 Updating icons for sourceid: 2
2007-03-01 13:14:47.872 Channels updated.
2007-03-01 13:14:48.408 Clearing data for source.
2007-03-01 13:14:48.408 Clearing from Fri Mar 2 00:00:00 2007 to Sat Mar 3 00:00:00 2007 (localtime)
2007-03-01 13:17:21.857 Data for source cleared.
2007-03-01 13:17:21.857 Updating programs.
2007-03-01 13:17:57.391 Program table update complete.
2007-03-01 13:17:57.391
2007-03-01 13:17:57.391 Checking day @ offset 2, date: Sat Mar 3 2007
2007-03-01 13:18:02.241 Data is already present for Sat Mar 3 2007, skipping
2007-03-01 13:18:02.241
2007-03-01 13:18:02.241 Checking day @ offset 3, date: Sun Mar 4 2007
2007-03-01 13:18:02.384 Data is already present for Sun Mar 4 2007, skipping
2007-03-01 13:18:02.385
2007-03-01 13:18:02.385 Checking day @ offset 4, date: Mon Mar 5 2007
2007-03-01 13:18:02.631 Data is already present for Mon Mar 5 2007, skipping
2007-03-01 13:18:02.631
2007-03-01 13:18:02.631 Checking day @ offset 5, date: Tue Mar 6 2007
2007-03-01 13:18:02.774 Data is already present for Tue Mar 6 2007, skipping
2007-03-01 13:18:02.774
2007-03-01 13:18:02.775 Checking day @ offset 6, date: Wed Mar 7 2007
2007-03-01 13:18:03.040 Data is already present for Wed Mar 7 2007, skipping
2007-03-01 13:18:03.040
2007-03-01 13:18:03.040 Checking day @ offset 7, date: Thu Mar 8 2007
2007-03-01 13:18:03.310 Data is already present for Thu Mar 8 2007, skipping
2007-03-01 13:18:03.310
2007-03-01 13:18:03.310 Checking day @ offset 8, date: Fri Mar 9 2007
2007-03-01 13:18:03.451 Data is already present for Fri Mar 9 2007, skipping
2007-03-01 13:18:03.451
2007-03-01 13:18:03.452 Checking day @ offset 9, date: Sat Mar 10 2007
2007-03-01 13:18:03.597 Data is already present for Sat Mar 10 2007, skipping
2007-03-01 13:18:03.597
2007-03-01 13:18:03.597 Checking day @ offset 10, date: Sun Mar 11 2007
2007-03-01 13:18:03.735 Data is already present for Sun Mar 11 2007, skipping
2007-03-01 13:18:03.735
2007-03-01 13:18:03.735 Checking day @ offset 11, date: Mon Mar 12 2007
2007-03-01 13:18:03.872 Data is already present for Mon Mar 12 2007, skipping
2007-03-01 13:18:03.872
2007-03-01 13:18:03.872 Checking day @ offset 12, date: Tue Mar 13 2007
2007-03-01 13:18:04.057 Data Refresh needed because offset day 12 has less than 4 programs per channel for the 6PM - midnight time window for channels that normally have data. We want at least 916 programs, but only found 557
2007-03-01 13:18:04.057 Refreshing data for Tue Mar 13 2007
2007-03-01 13:18:04.085 Retrieving datadirect data.
2007-03-01 13:18:04.085 Grabbing data for Thu Mar 1 2007 offset 12
2007-03-01 13:18:04.085 From Tue Mar 13 06:00:00 2007 to Wed Mar 14 06:00:00 2007 (UTC)
2007-03-01 13:18:04.085 Grabbing listing data
--13:18:04--  http://datadirect.webservices.zap2it.com/tvlistings/xtvdService
           => `-'
Resolving datadirect.webservices.zap2it.com... 206.18.98.160
Connecting to datadirect.webservices.zap2it.com|206.18.98.160|:80... connected.
HTTP request sent, awaiting response... 401 Unauthorized
Reusing existing connection to datadirect.webservices.zap2it.com:80.
HTTP request sent, awaiting response... 200 OK
Length: unspecified [text/xml]

    [           <=>                                             ] 285,126       64.83K/s

13:18:09 (64.77 KB/s) - `-' saved [285126]

2007-03-01 13:18:09.583 DataDirect: Your subscription expires on 05/22/07 17:23:00
2007-03-01 13:18:25.617 Grab complete.  Actual data from Tue Mar 13 06:00:00 2007 to Wed Mar 14 06:00:00 2007 (UTC)
2007-03-01 13:18:25.618 Main temp tables populated.
2007-03-01 13:18:26.070 Clearing data for source.
2007-03-01 13:18:26.071 Clearing from Tue Mar 13 01:00:00 2007 to Wed Mar 14 01:00:00 2007 (localtime)
2007-03-01 13:20:33.750 Data for source cleared.
2007-03-01 13:20:33.750 Updating programs.
2007-03-01 13:21:08.682 Program table update complete.
2007-03-01 13:21:08.682
2007-03-01 13:21:08.682 Checking day @ offset 13, date: Wed Mar 14 2007
2007-03-01 13:21:13.961 Data Refresh needed because offset day 13 has less than 4 programs per channel for the 6PM - midnight time window for channels that normally have data. We want at least 620 programs, but only found 82
2007-03-01 13:21:13.961 Refreshing data for Wed Mar 14 2007
2007-03-01 13:21:14.051 Retrieving datadirect data.
2007-03-01 13:21:14.051 Grabbing data for Thu Mar 1 2007 offset 13
2007-03-01 13:21:14.051 From Wed Mar 14 06:00:00 2007 to Thu Mar 15 06:00:00 2007 (UTC)
2007-03-01 13:21:14.051 Grabbing listing data
--13:21:14--  http://datadirect.webservices.zap2it.com/tvlistings/xtvdService
           => `-'
Resolving datadirect.webservices.zap2it.com... 206.18.98.160
Connecting to datadirect.webservices.zap2it.com|206.18.98.160|:80... connected.
HTTP request sent, awaiting response... 401 Unauthorized
Reusing existing connection to datadirect.webservices.zap2it.com:80.
HTTP request sent, awaiting response... 200 OK
Length: unspecified [text/xml]

    [               <=>                                         ] 374,468       57.83K/s

13:21:21 (57.79 KB/s) - `-' saved [374468]

2007-03-01 13:21:21.968 DataDirect: Your subscription expires on 05/22/07 17:23:00
2007-03-01 13:21:44.985 Grab complete.  Actual data from Tue Mar 13 00:00:00 2007 to Wed Mar 14 23:59:59 2007 (UTC)
2007-03-01 13:21:44.986 Main temp tables populated.
2007-03-01 13:21:45.707 Clearing data for source.
2007-03-01 13:21:45.707 Clearing from Mon Mar 12 19:00:00 2007 to Wed Mar 14 18:59:59 2007 (localtime)
2007-03-01 13:24:12.274 Data for source cleared.
2007-03-01 13:24:12.274 Updating programs.
2007-03-01 13:24:44.588 Program table update complete.
2007-03-01 13:25:12.511 New DB connection, total: 5
2007-03-01 13:25:12.511 Connected to database 'mythconverg' at host: localhost
2007-03-01 13:25:12.812 Data fetching complete.
2007-03-01 13:25:12.812 Adjusting program database end times.
2007-03-01 13:25:25.183     0 replacements made
2007-03-01 13:25:25.183 Marking generic episodes.
2007-03-01 13:25:28.237     Found 5465
2007-03-01 13:25:28.237 Marking repeats.
2007-03-01 13:25:33.592     Found 11860
2007-03-01 13:25:33.593 Unmarking new episode rebroadcast repeats.
2007-03-01 13:25:34.506     Found 33
2007-03-01 13:25:44.287 Marking episode first showings.
2007-03-01 13:26:24.965     Found 19514
2007-03-01 13:26:24.965 Marking episode last showings.
2007-03-01 13:27:00.918     Found 19514
2007-03-01 13:27:01.281 Grabbing next suggested grabbing time
2007-03-01 13:27:01.977 DataDirect: BlockedTime is: 2007-03-01T13:27:02
2007-03-01 13:27:01.978 DataDirect: NextSuggestedTime is: 2007-03-02T05:23:03
2007-03-01 13:27:01.998
===============================================================
| Attempting to contact the master backend for rescheduling.  |
| If the master is not running, rescheduling will happen when |
| the master backend is restarted.                            |
===============================================================
2007-03-01 13:27:02.004 Connecting to backend server: 192.168.0.200:6543 (try 1 of 5)
2007-03-01 13:27:02.005 Using protocol version 31
2007-03-01 13:27:02.018 Received a remote 'Clear Cache' request
2007-03-01 13:27:02.097 mythfilldatabase run complete.
root@backend:~#



I can't imagine that I'd need to increase the buffer past 64mb. If it was working at 16mb without my bitrate increase, then I should be fine now... I don't remember what my before/after bitrates are, but I gotta think that I didn't increase by a factor of 4. If memory serves I upped my bitrate by about 50%.

/scratches head.

Maybe backing up to R5D1 is my best answer?

_________________
Currently Running:
Too lazy to update this with my current hardware, I'll redo it during my next install =)


Top
 Profile  
 
 Post subject:
PostPosted: Thu Mar 01, 2007 2:20 pm 
Offline
Joined: Thu Apr 27, 2006 1:07 am
Posts: 54
In my experience mythfilldatabse is a resource hog! I do not know what the default nice level is but it always brings my CPU to a grind. I always run it between 1:30AM and 5:00AM at times when I am not recording. You can limit the times in the backend setup. Do you still have errors with everything else running without mythfilldatabase?


Top
 Profile  
 
 Post subject:
PostPosted: Thu Mar 01, 2007 2:37 pm 
Offline
Joined: Sat Feb 11, 2006 5:26 pm
Posts: 282
Location: Winnipeg - Canada
I'm in the middle of running another test (recording two shows at once and comflagging them as I go, also running a mythfilldatabase (it's running at a nice of 0) at the same time). I am experiencing the same "application not fast enough" errors in my kern.log. It was about 10 minutes into my fill before I saw these errors start to popup. If you want to peek at the log files I've got copies of my kern.log, my mythbackend.log and my mythfilldatabase run results.

http://myth.goloudorgohome.net/stuff/

they are named mythfilldatabase.log kern.log and mythbackend.log (I started the run at about 14:18 - so ignore the first 10 lines in kern.log)

from the kern.log file
Code:
Mar  1 14:28:12 backend kernel: ivtv1: All encoder MPEG stream buffers are full. Dropping data.
Mar  1 14:28:12 backend kernel: ivtv1: Cause: the application is not reading fast enough.
Mar  1 14:28:15 backend kernel: ivtv0: All encoder MPEG stream buffers are full. Dropping data.
Mar  1 14:28:15 backend kernel: ivtv0: Cause: the application is not reading fast enough.


matches up nicely with this snippet from the mythfilldatabase.log
Code:
2007-03-01 14:28:25.447 Data for source cleared.
2007-03-01 14:28:25.447 Updating programs.
2007-03-01 14:28:52.917 Program table update complete.


When looking at earlier results, it seemed to me that a series of buffer drops would usually occur right around the time that the Program table update would be finishing up.

I guess I'll restrict my mythfill to run only within a very narrow window of time, and simply keep an eye on my logs over the next day or two to see if this continues to occur. I can't confirm at this point that this is ever happening when i'm not running mythfilldatabase.

_________________
Currently Running:
Too lazy to update this with my current hardware, I'll redo it during my next install =)


Top
 Profile  
 
 Post subject:
PostPosted: Thu Mar 01, 2007 3:13 pm 
Offline
Joined: Thu Apr 27, 2006 1:07 am
Posts: 54
Not that it is related but what are all of the
Code:
2007-03-01 14:27:29.000 TFW, Error: Write() -- IOBOUND begin cnt(2048) free(2047)
2007-03-01 14:27:29.549 TFW, Error: Write() -- IOBOUND end
2007-03-01 14:27:34.685 TFW, Error: Write() -- IOBOUND end
2007-03-01 14:27:34.991 TFW, Error: Write() -- IOBOUND begin cnt(2048) free(2047)
2007-03-01 14:27:37.131 TFW, Error: Write() -- IOBOUND begin cnt(2048) free(2047)
2007-03-01 14:27:38.601 TFW, Error: Write() -- IOBOUND end
2007-03-01 14:27:39.192 TFW, Error: Write() -- IOBOUND end
2007-03-01 14:27:39.513 TFW, Error: Write() -- IOBOUND begin cnt(2048) free(2047)
2007-03-01 14:27:39.842 TFW, Error: Write() -- IOBOUND begin cnt(2048) free(2047)
2007-03-01 14:27:40.276 TFW, Error: Write() -- IOBOUND end
2007-03-01 14:27:40.637 TFW, Error: Write() -- IOBOUND end
2007-03-01 14:27:41.061 TFW, Error: Write() -- IOBOUND begin cnt(2048) free(2047)
2007-03-01 14:27:41.332 TFW, Error: Write() -- IOBOUND begin cnt(2048) free(2047)
2007-03-01 14:27:41.554 TFW, Error: Write() -- IOBOUND end
errors in the mythbackend? They are not normal.

It looks like the dropouts happened when the process started but not when it war running.... Could it be that the nice level takes a second to properly set the level and there is a delay in the buffer reads as the process hogs the CPU until the nice settings kick in?


Top
 Profile  
 
 Post subject:
PostPosted: Thu Mar 01, 2007 3:18 pm 
Offline
Joined: Sat Feb 11, 2006 5:26 pm
Posts: 282
Location: Winnipeg - Canada
I have no idea, nor do I have any idea how to find out =)

Thats a good theory though!

_________________
Currently Running:
Too lazy to update this with my current hardware, I'll redo it during my next install =)


Top
 Profile  
 
 Post subject:
PostPosted: Thu Mar 01, 2007 5:25 pm 
Offline
Joined: Mon Oct 09, 2006 11:27 am
Posts: 75
Location: Raleigh, NC
I've had those "application not reading fast enough" errors, and I too used the buffer settings to compensate. It improved things, but I'd still see errors during heavy activity like recording two programs and watching a third. Mythfilldb would really generate the errors, so I have it scheduled to run in the early morning hours, away from my mainstream recording.

I was a little wary of 0.10.0 as those buffer settings aren't available (it's noted in the wiki), but I went for it and have found the situation to be much improved.

Since I upgraded (a little over a week ago), I've only seen the IOBOUND errors once ... just a couple of hits, and it occurred when mythfilldb ran during a late night recording. The recording exhibited just one minor glitch.

I've still got mythfilldb running in off-hours as I don't consider the issue "resolved," but it is much improved. Also, I didn't get any of the "black box" issues reported by another poster here ...

http://mysettopbox.tv/phpBB2/viewtopic.php?t=14376

so your mileage may vary ...


Top
 Profile  
 
 Post subject:
PostPosted: Thu Mar 01, 2007 5:55 pm 
Offline
Joined: Sat Feb 11, 2006 5:26 pm
Posts: 282
Location: Winnipeg - Canada
If I jump up to 0.10.x is it just as easy to jump back to 0.8.2 if I find things are worse? I saw that the command to increase the buffer was not available, and that did indeed scare me. If i'm seeing this with a 64mb buffer I assumed I would see lots when my buffer defaulted to 4mb again.

_________________
Currently Running:
Too lazy to update this with my current hardware, I'll redo it during my next install =)


Top
 Profile  
 
 Post subject:
PostPosted: Thu Mar 01, 2007 6:11 pm 
Offline
Joined: Mon Oct 09, 2006 11:27 am
Posts: 75
Location: Raleigh, NC
I'd guess it's not a big deal to go back, but I haven't done it. It looks like the poster in the thread I referred to didn't have any trouble going back.

I had the buffers maxed before the upgrade, and it still improved.

If you go for it, post back. I've been watching for others trying out 0.10.0, but it's been pretty quiet. I'm curious if others have the same positive experience I did.


Top
 Profile  
 
 Post subject:
PostPosted: Thu Mar 01, 2007 7:16 pm 
Offline
Joined: Sat Feb 11, 2006 5:26 pm
Posts: 282
Location: Winnipeg - Canada
Will do, I may take a stab at things sometime on sat or sunday, it won't be before that.

I really hope I don't mess things up even worse =)

_________________
Currently Running:
Too lazy to update this with my current hardware, I'll redo it during my next install =)


Top
 Profile  
 
 Post subject:
PostPosted: Sat Mar 03, 2007 10:04 am 
Offline
Joined: Sat Feb 11, 2006 5:26 pm
Posts: 282
Location: Winnipeg - Canada
Ok, so I think i've mostly got things cleaned up and running better.

I am still getting lots of IOBOUND errors in my mythbackend.log but they aren't seeming to affect anything, and a buddy of mine says he's seeing them to (and he hasn't made any changes at all to his MythTV setup in a very long while) so I'm not worried about those.

I did two things that both seemed to help out here.

I started by testing my HD speeds, from a prompt:

Code:
root@backend:~# hdparm -tT /dev/hda

/dev/hda:
 Timing cached reads:   770 MB in  2.00 seconds = 384.40 MB/sec
 Timing buffered disk reads:  152 MB in  3.02 seconds =  50.27 MB/sec
root@backend:~#


I was seeing about 18MB/sec on the Timed Buffered reads. Not so fabulous.... so I did this.....

Code:
root@backend:~# hdparm -i /dev/hda

/dev/hda:

 Model=WDC WD3200JB-00KFA0, FwRev=08.05J08, SerialNo=WD-WCAMR2859842
 Config={ HardSect NotMFM HdSw>15uSec SpinMotCtl Fixed DTR>5Mbs FmtGapReq }
 RawCHS=16383/16/63, TrkSize=0, SectSize=0, ECCbytes=65
 BuffType=unknown, BuffSize=8192kB, MaxMultSect=16, MultSect=16
 CurCHS=16383/16/63, CurSects=16514064, LBA=yes, LBAsects=268435455
 IORDY=on/off, tPIO={min:120,w/IORDY:120}, tDMA={min:120,rec:120}
 PIO modes:  pio0 pio3 pio4
 DMA modes:  mdma0 mdma1 mdma2
 UDMA modes: udma0 udma1 udma2 udma3 udma4 *udma5 udma3 udma4 *udma5
 AdvancedPM=no WriteCache=enabled
 Drive conforms to: Unspecified:  ATA/ATAPI-1 ATA/ATAPI-2 ATA/ATAPI-3 ATA/ATAPI-4 ATA/ATAPI-5 ATA/ATAPI-6

 * signifies the current active mode

root@backend:~#


My UDMA mode was set to udma2 and I was unable to bump it up to 5. I checked with a few friends to see what theirs was and they were sitting at 5 (and also getting much better speeds in the tests). I rebooted the system, jumped into the bios, and found that my Ultra DMA was disabled. Flipped that to on, rebooted, and lo and behold my udma mode was now set to 5. the -tT test was now showing buffered reads in the 50-60MB range, which is obviously a pretty big improvement.

That alone wasn't enough to completely resolve things... I ended up dropping my bitrates down to what they were initially.... I ran a few tests and couldn't see any difference in image quality from 6000/8000 to 4400/6600 on my PVR 150 cards. So now I'm running 4400/6600 @ 720by480 for my High Quality recordings and things are looking good.

I'm able to record two shows while at the same time encode 2 shows to xvid and I don't see any stutters or issues regarding the full mpg buffers.


I'd suggest anyone else running into similar troubles try these things.

_________________
Currently Running:
Too lazy to update this with my current hardware, I'll redo it during my next install =)


Top
 Profile  
 

Display posts from previous:  Sort by  
Post new topic Reply to topic  [ 22 posts ] 
Go to page 1, 2  Next



All times are UTC - 6 hours




Who is online

Users browsing this forum: No registered users and 65 guests


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot post attachments in this forum

Jump to:  
Powered by phpBB® Forum Software © phpBB Group

Theme Created By ceyhansuyu