recording glitches

[drewg]

Hi,

I occasionally see "glitches" near the start of some of my primetime recordings.

I'm running SageTV V6.4.8.1 on 64-bit Ubuntu 8.04 using Sun java (JVM version=1.5.0_16). The machine I'm using has 4GB of RAM. I record over the air (ATSC) using PCI tuner cards. My recordings are stored on an XFS filesystem in a 1T RAID5 Sata array, inernal to the machine. The server is attached to a good UPS.

I enabled debug logging, trying to figure out whats happening. On Fri night, I recorded 2 shows at 8pm. These shows were recorded from different tuner cards, each attached to its own separate antenna. The two recordings were a low-bitrate 480i "Curious George" from PBS-kids, and a 1080i "The Mentalist" from CBS. Both recordings showed glitches at exactly the same times.

In the verbose log, I saw " Scheduler.updateSchedule()" run just before the glitches started. Each glitch corresponds roughly to a "Sage waiting for GC to free up some memory" message. Eg, there is a glitch at 20:00:55, one at 20:01:07 and one at 20:01:18. See the log below.

Any suggestions as to where to look first? Would increasing the java heap size from the default 256MB (-Xmx256m) help? The box has 4GB..

Thanks,

Drew

Fri 9/26 20:00:55.425 Sage waiting for GC to free up some memory usage%=0.98817545
Fri 9/26 20:00:56.125 Sage done waiting for GC to free up some memory usage%=0.96026677Fri 9/26 20:00:56.550 Sage waiting for GC to free up some memory usage%=0.9637177
Fri 9/26 20:00:57.212 Ministry is waiting for 180 sec
Fri 9/26 20:01:03.010 Sage done waiting for GC to free up some memory usage%=0.9641672
Fri 9/26 20:01:03.010 Wizard locating time holes in airing table...
Fri 9/26 20:01:03.264 Wizard plugging the 17 time holes in the airing table...
Fri 9/26 20:01:03.379 Wizard fixing duration for 18 noshow airings...
Fri 9/26 20:01:03.434 Sage waiting for GC to free up some memory usage%=0.9642833
Fri 9/26 20:01:10.122 Sage done waiting for GC to free up some memory usage%=0.95927835
Fri 9/26 20:01:10.222 Wizard removing 0 expired Channels of 62 total...
Fri 9/26 20:01:10.338 Wizard removing 47 expired Shows of 12897 total...
Fri 9/26 20:01:10.788 Retaining 22533 total title & people & category & bonus ids.
Fri 9/26 20:01:10.800 Clearing out 10 titles of 10309 total.
Fri 9/26 20:01:10.885 Clearing out 0 prime titles of 0 total.
Fri 9/26 20:01:10.948 Clearing out 43 people of 11982 total.
Fri 9/26 20:01:11.063 Clearing out 1 categories of 107 total.
Fri 9/26 20:01:11.115 Clearing out 0 subcategories of 80 total.
Fri 9/26 20:01:11.165 Clearing out 1 bonuses of 28 total.
Fri 9/26 20:01:11.217 Wizard is fixing the media mask on the Show objects...
Fri 9/26 20:01:11.269 Wizard is fixing the media mask on the Titles...
Fri 9/26 20:01:11.321 Wizard is fixing the media mask on the Years...
Fri 9/26 20:01:11.372 Wizard is fixing the media mask on the Peoples...
Fri 9/26 20:01:11.425 Wizard is fixing the media mask on the Categories...
Fri 9/26 20:01:11.476 Wizard is fixing the media mask on the SubCategories...
Fri 9/26 20:01:11.527 Wizard is fixing the media mask on the Rated...
Fri 9/26 20:01:11.578 Wizard is fixing the media mask on the PR...
Fri 9/26 20:01:11.629 Wizard is fixing the media mask on the ERs...
Fri 9/26 20:01:11.681 Wizard is fixing the media mask on the Bonus...
Fri 9/26 20:01:11.682 Sage waiting for GC to free up some memory usage%=0.9668846
Fri 9/26 20:01:18.329 Sage done waiting for GC to free up some memory usage%=0.96689606
Fri 9/26 20:01:18.429 Wizard backing up database file...
Fri 9/26 20:01:18.434 Wizard compressing new file...
Fri 9/26 20:01:18.436 Wizard writing out table info for Year
Fri 9/26 20:01:18.438 Wizard writing out table info for Network
Fri 9/26 20:01:18.439 Wizard writing out table info for Title
Fri 9/26 20:01:18.503 Wizard writing out table info for Channel
Fri 9/26 20:01:18.506 Wizard writing out table info for People
Fri 9/26 20:01:18.540 Wizard writing out table info for SubCategory
Fri 9/26 20:01:18.542 Wizard writing out table info for Rated
Fri 9/26 20:01:18.544 Wizard writing out table info for ParentalRating
Fri 9/26 20:01:18.545 Wizard writing out table info for ExtendedRating
Fri 9/26 20:01:18.547 Wizard writing out table info for Category
Fri 9/26 20:01:18.549 Wizard writing out table info for PrimeTitle
Fri 9/26 20:01:18.550 Wizard writing out table info for Bonus
Fri 9/26 20:01:18.552 Wizard writing out table info for Show
Fri 9/26 20:01:19.074 Wizard writing out table info for Airing
Fri 9/26 20:01:19.102 Wizard writing out table info for ManualRecord
Fri 9/26 20:01:19.114 Wizard writing out table info for MediaFile
Fri 9/26 20:01:19.557 Wizard writing out table info for Watched
Fri 9/26 20:01:19.561 Wizard writing out table info for Agent
Fri 9/26 20:01:19.564 Wizard writing out table info for Wasted
Fri 9/26 20:01:19.567 Wizard writing out table info for Playlist
Fri 9/26 20:01:19.568 Wizard writing out table info for TVEditorial
Fri 9/26 20:01:19.571 Wizard writing out table info for SeriesInfo
Fri 9/26 20:01:19.653 Sage waiting for GC to free up some memory usage%=0.9676408

[drewg]

Doubling the memory seems to have helped. The last few days' recordings have been glitch free. Woo-hoo!

Drew