How do we debug this?

[jhb50]

I am encountering a repeatable failure of Serviios Feed Item Extractor. After running for a day or so it will just hang up and the Debug log will freeze at that point, although I can continue to play streams and videos on the TV. This occurs at random points but always while parsing a different groovy which has parsed successfully many time before.

When this occurs I can still use the console and force refresh streams, which will be removed in the log but will not reparse. The ability to shutdown Serviio via the Task Bar icon also fails and the only way to shut down is to kill the Serviio Service Process, which at that point is using 15% of my I7 8core cpu.

This is about the sixth time this has occurred in the last 10 days.
A snapshot of the log follows. The process errors are normal when a stream is dark when the TV tries to play it, so you can see where I played after the log froze. You can also see the removal of a resource when a forced refresh was requested.

2012-03-04 15:38:27,741 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-03-04 15:38:27,775 DEBUG [OnlineLibraryManager] Online resource http://www.mysport.com/c-6.html?refresh=60 expired, will reload it
2012-03-04 15:38:27,775 DEBUG [OnlineLibraryManager] Resource http://www.mysport.com/c-6.html?refresh=60 not in cache yet, loading it
2012-03-04 15:38:27,775 DEBUG [WebResourceParser] Parsing web resource 'http://www.mysport.com/c-6.html?refresh=60'
2012-03-04 15:38:27,775 DEBUG [WebResourceParser] Found matching url extractor (MySport) for resource http://www.mysport.com/c-6.html?refresh=60
2012-03-04 15:38:27,775 DEBUG [FeedItemUrlExtractor] MySport: Starting parsing resource: http://www.mysport.com/c-6.html?refresh=60
2012-03-04 15:38:29,408 DEBUG [FeedItemUrlExtractor] MySport: LIVE ITEM - leto - 'Sun 13:00-16:00 My event' - Refresh at 16:10 on Sun
2012-03-04 23:34:48,261 WARN [ProcessExecutor] Process cmd has a return code of 1! This is a possible error.
2012-03-04 23:35:27,276 WARN [ProcessExecutor] Process cmd has a return code of 1! This is a possible error.
2012-03-04 23:37:06,218 WARN [ProcessExecutor] Process cmd has a return code of 1! This is a possible error.
2012-03-04 23:44:47,094 WARN [ProcessExecutor] Process cmd has a return code of 1! This is a possible error.
2012-03-04 23:48:47,002 WARN [ProcessExecutor] Process cmd has a return code of 1! This is a possible error.
2012-03-04 23:52:06,813 DEBUG [OnlineContentCacheDecorator] Removed online content 'https://sites.google.com/site/serviiorss/LiveFeeds_TV_Networks.rss' from cache (online_feeds)
2012-03-04 23:52:26,600 WARN [ProcessExecutor] Process cmd has a return code of 1! This is a possible error.
2012-03-04 23:53:53,059 WARN [IndexedDiskCache] Region [thumbnails] Disk cache not shutdown properly, shutting down now.

[zip]

does this mean the plugin is stuck or it's just not logging any more?

[jhb50]

It happens on any plugin so I don't believe that is the cause, and the logging freezes and a forced refresh shows the removal but no refresh of the feed, so my guess is that the extractor has failed. I've also seen weird things like suddenly a groovy error starts logging that a variable is undeclared even though that groovy has run correctly earlier in the session thru the same code, and the high cpu load, and a rash of 500 no connect errors, and the lockup of the exit Serviio icon that all point to gradual corruption of the code.

Note that I am frequently refreshing feeds that are constantly changing so I am giving the extractor a heavy workout, so this is not an every 8 hour refresh scenario, but rather a refresh about every 5 minutes on average.

[zip]

How's the memory doing? Is the heap maxing out?

[jhb50]

I'll keep my eye on it..but wouldn't I get an error message?

[jhb50]

After running clean for 34 hours it hung again when beginning to parse a groovy (the same groovy successfully parsed 13 minutes earlier) and the systray console icon will not terminate Serviio. The cpuload from serviio however is 0. The heap size for the console is only using 50% of the allocated 9 megs and the Permgen whatever that is, is at 99.9% of the allocated 24 megs.

I've now restarted Serviio using the bats instead of the exe in order to monitor its heap size. At startup Serviio sawtoothed between 13 and 19 million of the 21million heap bytes. When it went to 21 million the heap size jumped to 23 Million. I'll leave VisualVM running.

[zip]

ok, you're running out og permgen space. Try to add this to the vmoptions file

  Code:

-XX:MaxPermSize=128m

[jhb50]

The max permgen for both the console and service is 85megs and I'm no where near that so I don't think that is the problem. Java is changing the allocated as required to meet the actual permgen and heap.

Currently the only vm option is -Xmx384m for the service which I assume you provided with the install, and that sets the max for the server heap which is only 29megs now.

[zip]

Permgen whatever that is, is at 99.9% of the allocated 24 megs.

This tells me you're running out or permgen

[jhb50]

Permgen whatever that is, is at 99.9% of the allocated 24 megs.

This tells me you're running out or permgen

No .. heres the screen. Java only allocates what is needed and there is 85megs available if required