FAQ  •  Register  •  Login

30 second timeout - error and problem

<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Thu Jan 03, 2013 3:51 am

30 second timeout - error and problem

When the 30 sec timeout kicks in in theWebResourceContainer extractItems method, the method continues to extract items to completion even though the ContentURLContainer extractUrl fails to run on any of the items because the timeout occurred. Obviously this is not a problem if the method has hung up but it is a problem if the extract is running fine and only times out because of too many items or other non error conditions.

If a second groovy then encounters the same problem, Serviio hangs up trying to extract both groovys but never getting them done.

When the timeout occurs the item extraction should stop but the extracy url method should run against those items then extracted.
<<

zip

User avatar

Serviio developer / Site Admin

Posts: 16505

Joined: Sat Oct 24, 2009 12:24 pm

Location: London, UK

Post Thu Jan 03, 2013 9:56 am

Re: 30 second timeout - error and problem

Don't quite understand. BUt if Serviio interrupts the first method it can't run extract URL on anything as it won't get any return value from the first method. There is no partial list of items or anything.
<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Thu Jan 03, 2013 4:22 pm

Re: 30 second timeout - error and problem

OK, I now understand why you cannot extract the URL's for the items that have been created because the WebResource container has not been created and returned. I can implement my own timer to fix that.

But the bug I'm reporting is that the extract of the items, does not stop after the 30 second timeout on the ExtractItems method. As the following log shows(I've removed the m-search and playlist messages), hahasport hits the limit and the stopstream plugin starts, and then both extract in parallel.

  Code:
2013-01-02 18:47:58,262 DEBUG [OnlineLibraryManager] Resource http://www.hahasport.com/c-6.html?estreams=9 not in cache yet, loading it
2013-01-02 18:47:58,262 DEBUG [WebResourceParser] Parsing web resource 'http://www.hahasport.com/c-6.html?estreams=9'
2013-01-02 18:47:58,267 DEBUG [WebResourceParser] Found matching url extractor (HaHaSport) for resource http://www.hahasport.com/c-6.html?estreams=9
2013-01-02 18:47:58,267 DEBUG [FeedItemUrlExtractor] HaHaSport: Starting parsing resource: http://www.hahasport.com/c-6.html?estreams=9
2013-01-02 18:47:58,521 DEBUG [FeedItemUrlExtractor] HaHaSport: Parsing with hahasport V17
2013-01-02 18:48:08,821 DEBUG [FeedItemUrlExtractor] HaHaSport: NO SRC ITEM - 'Wed 16:00-19:00 Chicago Bulls vs. Orlando Magic-NBA'
2013-01-02 18:48:10,228 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - coolsp - Wed 16:00-19:00 Chicago Bulls vs. Orlando Magic-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:12,144 DEBUG [FeedItemUrlExtractor] HaHaSport: NO SRC ITEM - 'Wed 16:00-19:00 Portland Trail Blazers vs. Toronto Raptors-NBA'
2013-01-02 18:48:12,617 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - coolsp - Wed 16:00-19:00 Portland Trail Blazers vs. Toronto Raptors-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:13,127 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - nutjob - Wed 16:00-19:00 Portland Trail Blazers vs. Toronto Raptors-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:14,876 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - coolsp - Wed 16:00-19:00 Sacramento Kings vs. Cleveland Cavaliers-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:16,026 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - nutjob - Wed 16:00-19:00 Sacramento Kings vs. Cleveland Cavaliers-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:17,459 DEBUG [FeedItemUrlExtractor] HaHaSport: NO SRC ITEM - 'Wed 16:00-19:00 Washington Wizards vs. Indiana Pacers-NBA'
2013-01-02 18:48:18,816 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - coolsp - Wed 16:00-19:00 Washington Wizards vs. Indiana Pacers-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:20,223 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - nutjob - Wed 16:00-19:00 Washington Wizards vs. Indiana Pacers-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:21,576 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - letont - Wed 16:30-19:30 Dallas Mavericks vs. Miami Heat-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:22,984 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - ilivet - Wed 16:30-19:30 Dallas Mavericks vs. Miami Heat-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:27,687 DEBUG [FeedItemUrlExtractor] HaHaSport: NULL ITEM - http://onlinefreefootball.info/1.html - Wed 16:30-19:30 Dallas Mavericks vs. Miami Heat-NBA
2013-01-02 18:48:28,274 WARN  [FeedUpdaterThread] An error occured while scanning for online item information, will continue
java.io.IOException: Unexpected error while invoking plugin (HaHaSport): The operation took more than 30000 ms and has been cancelled.
   at org.serviio.library.online.WebResourceParser.parse(WebResourceParser.java:58)
   at org.serviio.library.online.OnlineLibraryManager.findResource(OnlineLibraryManager.java:171)
   at org.serviio.library.online.OnlineLibraryManager.findResourceInCacheOrParse(OnlineLibraryManager.java:186)
   at org.serviio.library.online.metadata.FeedUpdaterThread.getOnlineItems(FeedUpdaterThread.java:159)
   at org.serviio.library.online.metadata.FeedUpdaterThread.run(FeedUpdaterThread.java:96)
Caused by: java.lang.RuntimeException: The operation took more than 30000 ms and has been cancelled.
   at org.serviio.library.online.PluginExecutionProcessor.execute(PluginExecutionProcessor.java:64)
   at org.serviio.library.online.WebResourceUrlExtractor.parseWebResource(WebResourceUrlExtractor.java:29)
   at org.serviio.library.online.WebResourceParser.parse(WebResourceParser.java:56)
   ... 4 more
2013-01-02 18:48:28,276 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 133)
2013-01-02 18:48:28,277 DEBUG [OnlineLibraryManager] Resource http://www.stopstream.tv/6?estreams=9 not in cache yet, loading it
2013-01-02 18:48:28,277 DEBUG [WebResourceParser] Parsing web resource 'http://www.stopstream.tv/6?estreams=9'
2013-01-02 18:48:28,279 DEBUG [WebResourceParser] Found matching url extractor (Stopstream) for resource http://www.stopstream.tv/6?estreams=9
2013-01-02 18:48:28,279 DEBUG [FeedItemUrlExtractor] Stopstream: Starting parsing resource: http://www.stopstream.tv/6?estreams=9
2013-01-02 18:48:28,280 DEBUG [FeedItemUrlExtractor] Stopstream: Parsing with Stopstream V1
2013-01-02 18:48:29,094 DEBUG [FeedItemUrlExtractor] HaHaSport: NULL ITEM - http://lsh1.magicstream.tv - Wed 16:30-19:30 Dallas Mavericks vs. Miami Heat-NBA
2013-01-02 18:48:31,542 DEBUG [FeedItemUrlExtractor] HaHaSport: NULL ITEM - http://heyyouyayou.webs.com/ - Wed 16:30-19:30 Dallas Mavericks vs. Miami Heat-NBA
2013-01-02 18:48:37,064 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - nutjob - Wed 16:30-19:30 Dallas Mavericks vs. Miami Heat-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:39,109 DEBUG [FeedItemUrlExtractor] HaHaSport: NULL ITEM - http://watch.vipi.tv/?id=grizlies15 - Wed 16:30-19:30 Memphis Grizzlies vs. Boston Celtics-NBA
2013-01-02 18:48:40,555 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - ilivet - Wed 16:30-19:30 Memphis Grizzlies vs. Boston Celtics-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:41,208 DEBUG [FeedItemUrlExtractor] Stopstream: NO SRC ITEM - 'Wed 16:00-19:00 Chicago Bulls vs. Orlando Magic-NBA'
2013-01-02 18:48:42,779 DEBUG [FeedItemUrlExtractor] Stopstream: LIVE ITEM - coolsp - Wed 16:00-19:00 Chicago Bulls vs. Orlando Magic-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:44,331 DEBUG [FeedItemUrlExtractor] Stopstream: LIVE ITEM - nutjob - Wed 16:00-19:00 Chicago Bulls vs. Orlando Magic-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:45,348 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - coolsp - Wed 16:30-19:30 Memphis Grizzlies vs. Boston Celtics-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:45,885 DEBUG [FeedItemUrlExtractor] Stopstream: NO SRC ITEM - 'Wed 16:00-19:00 Portland Trail Blazers vs. Toronto Raptors-NBA'
2013-01-02 18:48:46,731 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - nutjob - Wed 16:30-19:30 Memphis Grizzlies vs. Boston Celtics-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:47,381 DEBUG [FeedItemUrlExtractor] Stopstream: LIVE ITEM - coolsp - Wed 16:00-19:00 Portland Trail Blazers vs. Toronto Raptors-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:47,544 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - coolsp - Wed 16:30-19:30 Memphis Grizzlies vs. Boston Celtics-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:47,982 DEBUG [FeedItemUrlExtractor] Stopstream: LIVE ITEM - nutjob - Wed 16:00-19:00 Portland Trail Blazers vs. Toronto Raptors-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:48,638 DEBUG [FeedItemUrlExtractor] Stopstream: NO SRC ITEM - 'Wed 16:00-19:00 Sacramento Kings vs. Cleveland Cavaliers-NBA'
2013-01-02 18:48:48,946 DEBUG [FeedItemUrlExtractor] HaHaSport: LIVE ITEM - nutjob - Wed 16:30-19:30 Memphis Grizzlies vs. Boston Celtics-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:49,310 DEBUG [FeedItemUrlExtractor] Stopstream: LIVE ITEM - coolsp - Wed 16:00-19:00 Sacramento Kings vs. Cleveland Cavaliers-NBA - Refresh at 19:10 on Wed
2013-01-02 18:48:49,709 DEBUG [FeedItemUrlExtractor] HaHaSport: NULL ITEM - http://watch.vipi.tv/?id=citythunder1 - Wed 17:00-20:00 Brooklyn Nets vs. Oklahoma City Thunder-NBA
2013-01-02


You can also see that 30 seconds is just not enough time. Only 13 items were processed before it timed out. It took 4 seconds for playlists to be processed and 6 seconds for the plugin to verify the network was available then 1.5 seconds per item (I'm on a 750KB network at this location) then boom! I can see 30 seconds for each URL extract but the timeout for item extracts should be longer. Seems to me that if a movie or something is playing in parallel with the extract that that time is included in the 30 seconds which it should not be. I say this because there are some rather large gaps between the time stamps for some of the items like 5 seconds.
<<

zip

User avatar

Serviio developer / Site Admin

Posts: 16505

Joined: Sat Oct 24, 2009 12:24 pm

Location: London, UK

Post Thu Jan 03, 2013 4:48 pm

Re: 30 second timeout - error and problem

Interesting, I'll check why it didn't cancel properly.
<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Fri Jan 04, 2013 12:19 am

Re: 30 second timeout - error and problem

I say this because there are some rather large gaps between the time stamps for some of the items like 5 seconds.

I investigated these time gaps, and found that they were due to groovy taking multiple seconds to process the statement if(regexMatcher.size()==0) when the size is 0. Changing the statement to if(!regexMatcher) processed immediately. So you need to watch how you use groovy!

I've also added my own timer in the groovy to exit normally after 27 seconds and process the items extracted until 1.2 gives me control over this.
<<

mqojdn

Streaming enthusiast

Posts: 44

Joined: Thu Jan 03, 2013 6:39 pm

Post Sat Jan 05, 2013 5:27 pm

Re: 30 second timeout - error and problem

Indeed, the plugin thread is not stopped, Serviio just stops waiting for the result. As you can see here http://forum.serviio.org/viewtopic.php?p=60092#p60092 the plugin is still running after the timeout.
And if the plugin is too slow, Serviio just keeps spawning more of these plugin threads, that would have even less chance to finish in time, since the previous ones are still bogging down the CPU. And everything goes to an unending 100% CPU load.
<<

zip

User avatar

Serviio developer / Site Admin

Posts: 16505

Joined: Sat Oct 24, 2009 12:24 pm

Location: London, UK

Post Sun Jan 06, 2013 4:52 pm

Re: 30 second timeout - error and problem

Ok, so after some more reading, it looks that interrupting a thread in Java is a bit of a hit&miss. The implementation I use will interrupt certain operations, but not others - for example most I/O operations. So if Serviio happens to interrupt the thread while there is some URL opening going on (for example), it'd probably fail. In that case you would have to implement some login in the plugin to periodically check if the thread has beed interrupted, and if yes, exit the plugin (e.g. throw RuntimeException, or return items that you currently have).

You could try this by checking this method: http://docs.oracle.com/javase/1.5.0/doc ... terrupted()

Hopefully it'll return true after the 30 seconds. If not, I could add a new method that would return the boolean instead.
<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Sun Jan 06, 2013 6:00 pm

Re: 30 second timeout - error and problem

Added
  Code:
            if (isInterrupted()){
      
               log ("30 second interrupt has occurred")
            
            }
            


and
  Code:
import java.lang.Thread.*;


but get
  Code:
Jan 6, 2013 9:56:52 AM org.restlet.engine.http.connector.HttpClientHelper start
INFO: Starting the default HTTP client
Caught: groovy.lang.MissingMethodException: No signature of method: HaHaSport.is
Interrupted() is applicable for argument types: () values: []
groovy.lang.MissingMethodException: No signature of method: HaHaSport.isInterrup
ted() is applicable for argument types: () values: []
        at HaHaSport.extractItems(HaHaSport.groovytest.txt:283)
        at HaHaSport$extractItems.call(Unknown Source)
        at HaHaSport.main(HaHaSport.groovytest.txt:1560)


How do I use this correctly?
<<

zip

User avatar

Serviio developer / Site Admin

Posts: 16505

Joined: Sat Oct 24, 2009 12:24 pm

Location: London, UK

Post Sun Jan 06, 2013 7:14 pm

Re: 30 second timeout - error and problem

  Code:
Thread.isInterrupted()
<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Sun Jan 06, 2013 7:55 pm

Re: 30 second timeout - error and problem

Sorry for my lack of knowledge but
if (Thread.isInterrupted()){

log ("30 second interrupt has occurred")

}

also gives
Jan 6, 2013 11:48:59 AM org.restlet.engine.http.connector.HttpClientHelper start

INFO: Starting the default HTTP client
Caught: groovy.lang.MissingMethodException: No signature of method: static java.
lang.Thread.isInterrupted() is applicable for argument types: () values: []
Possible solutions: isInterrupted(), interrupted(), interrupt()
groovy.lang.MissingMethodException: No signature of method: static java.lang.Thr
ead.isInterrupted() is applicable for argument types: () values: []
Possible solutions: isInterrupted(), interrupted(), interrupt()
at HaHaSport.extractItems(HaHaSport.groovytest.txt:283)
at HaHaSport$extractItems.call(Unknown Source)
at HaHaSport.main(HaHaSport.groovytest.txt:1560)
<<

will

DLNA master

Posts: 2120

Joined: Mon Aug 30, 2010 11:18 am

Location: UK

Post Sun Jan 06, 2013 8:16 pm

Re: 30 second timeout - error and problem

Off the top of my head, try

Thread.getCurrentThread().isInterrupted()
Will
Beta Tester Group
ServiiDroid (Android Console) Developer: Download | Home | Support
ServiiGo (Android 3G/4G/WiFi Playback App) Developer: More info

Player: Sony BDP S370 | Server: Debian 6.0 x86
HowTo: Provide supported formats of a device HowTo: Record a new ticket on Bitbucket
HowTo: Provide details of a video file that doesn't play
<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Sun Jan 06, 2013 8:24 pm

Re: 30 second timeout - error and problem

Great ..
  Code:
if (Thread.currentThread().isInterrupted()){
            
               log ("30 second interrupt has occurred")
            
            }

works! Thanks
<<

zip

User avatar

Serviio developer / Site Admin

Posts: 16505

Joined: Sat Oct 24, 2009 12:24 pm

Location: London, UK

Post Sun Jan 06, 2013 8:34 pm

Re: 30 second timeout - error and problem

  Code:
Thread.currentThread().isInterrupted()
<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Sun Jan 06, 2013 9:44 pm

[Solved] 30 second timeout - error and problem

Ok that works.
After 30 second time out the interrupt can be detected as above and the groovy can use that detect to terminate further parsing.
<<

zip

User avatar

Serviio developer / Site Admin

Posts: 16505

Joined: Sat Oct 24, 2009 12:24 pm

Location: London, UK

Post Mon Jan 07, 2013 12:58 pm

Re: 30 second timeout - error and problem

cool. It's a bit of a pain to leave it up to the plugin dev, but unfortunately i don't see any way around it. A typical scenario would be checking for false when you iterate over the items, something like

  Code:
while( !Thread.currentThread().isInterrupted() && matcher.size() < counter) {

// do your item pocessing here
}
<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Mon Jan 07, 2013 7:00 pm

Re: 30 second timeout - error and problem

I don't think its that big a deal. Its really only a problem if the groovy extracts too many items and the user or the groovy has not set a limit.(ie: it is not hung up but keeps running).

In this event the groovy should be doing its own time test so that it will stop extracting just before the 30 seconds and exit correctly so that the items extracted at that point will have their url's extracted. I do that now with hahasport, stopstream and ilive all of which can yield many items that exceed the 30 seconds.

Return to Plugin development

Who is online

Users browsing this forum: No registered users and 3 guests

Powered by phpBB © 2000, 2002, 2005, 2007 phpBB Group.
Designed by ST Software for PTF.