FAQ  •  Register  •  Login

[Explained] Timeout Logic

<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Fri Jul 27, 2012 10:24 pm

[Explained] Timeout Logic

Using castalba.groovy it continually times out on the BBC TWO item however the link is valid and responds immediately in both the browser and ffpmeg. The log is attached and as you can see by the time stamps, the 30000 milliseconds failure occurs 30 seconds after the feed parsing starts rather than the item parsing.

To verify this I added a 5 second sleep after each feed item and sure nuf after 30 seconds from start of feed parsing the SKY 24 item kicks out per the second log.

  Code:
2012-07-27 17:40:30,627 DEBUG [OnlineLibraryManager] Resource http://www.castalba.tv/channels not in cache yet, loading it
2012-07-27 17:40:30,627 DEBUG [WebResourceParser] Parsing web resource 'http://www.castalba.tv/channels'
2012-07-27 17:40:30,627 DEBUG [WebResourceParser] Found matching url extractor (Castalba) for resource http://www.castalba.tv/channels
2012-07-27 17:40:30,627 DEBUG [FeedItemUrlExtractor] Castalba: Starting parsing resource: http://www.castalba.tv/channels
2012-07-27 17:40:33,813 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Chelsea TV - http://www.castalba.tv/channel/4199 - rtmpe://cp96798.live.edgefcs.net/live//ChelTV_Ch01_1000k@26291 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:40:36,556 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Bloomberg TV - http://www.castalba.tv/channel/4190 - rtmpt://cp87869.live.edgefcs.net:1935/live/us_300@21006 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:40:39,386 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Al Jazeera News - http://www.castalba.tv/channel/4182 - rtmpt://cp79926.live.edgefcs.net:1935/live/ajmm@53707 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:40:42,129 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Sky TG24 - http://www.castalba.tv/channel/4191 - rtmpt://cp49989.live.edgefcs.net:1935/live/streamRM1@2564 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:40:44,990 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Telemadrid - http://www.castalba.tv/channel/5551 - rtmp://cp118141.live.edgefcs.net/live//TSAlaotra@47718 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:40:47,745 DEBUG [FeedItemUrlExtractor] Castalba: ADDED SSF - http://www.castalba.tv/channel/4892 - rtmp://ipmedia.mpl.miisolutions.net/ipmedia-live01//mp4:ssflive swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:40:50,545 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Deluxe Music - http://www.castalba.tv/channel/7950 - rtmp://flash.cdn.deluxemusic.tv/deluxemusic.tv-live//web_850.stream swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:40:53,333 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Sky Poker - http://www.castalba.tv/channel/7948 - rtmpe://cp67698.live.edgefcs.net/live//SkyPoker_500k@9124 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:40:56,113 DEBUG [FeedItemUrlExtractor] Castalba: ADDED ESPN UK - http://www.castalba.tv/channel/8659 - rtmp://173.193.15.138/live/177569 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:40:58,856 DEBUG [FeedItemUrlExtractor] Castalba: ADDED BBC Two - http://www.castalba.tv/channel/6768 - rtmp://173.193.15.138/live/174956 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:41:00,631 WARN  [FeedUpdaterThread] An error occured while scanning for online item information, will continue
java.io.IOException: Unexpected error while invoking plugin (Castalba): 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
2012-07-27 17:41:01,581 DEBUG [FeedItemUrlExtractor] Castalba: ADDED ESPN - http://www.castalba.tv/channel/9662 - rtmp://173.193.15.138/live/179043 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:41:04,360 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Sat1 - http://www.castalba.tv/channel/6863 - rtmp://173.193.15.138/live/175071 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:41:07,898 DEBUG [FeedItemUrlExtractor] Castalba: ADDED RTL - http://www.castalba.tv/channel/7810 - rtmp://173.193.15.138/live/176307 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:41:10,734 DEBUG [FeedItemUrlExtractor] Castalba: ADDED BBC News - http://www.castalba.tv/channel/9417 - rtmp://173.193.15.138/live/178734 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:41:13,544 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Pro7 - http://www.castalba.tv/channel/6862 - rtmp://173.193.15.138/live/175070 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:41:16,396 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Svensk Fotboll - http://www.castalba.tv/channel/7589 - rtmp://173.193.15.138/live/175962 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:41:19,131 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Fotboll - http://www.castalba.tv/channel/8480 - rtmp://173.193.15.138/live/177327 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:41:22,111 DEBUG [FeedItemUrlExtractor] Castalba: ADDED fridayfun - http://www.castalba.tv/channel/9890 - rtmp://173.193.15.138/live/179451 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 17:41:22,922 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-07-27 17:41:22,923 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-07-27 17:41:23,156 DEBUG [FeedItemUrlExtractor] Castalba: Castalba Folder Refresh Set to Console Default


Add 5 second delay between items.

  Code:
2012-07-27 18:11:14,018 DEBUG [OnlineLibraryManager] Resource http://www.castalba.tv/channels not in cache yet, loading it
2012-07-27 18:11:14,018 DEBUG [WebResourceParser] Parsing web resource 'http://www.castalba.tv/channels'
2012-07-27 18:11:14,019 DEBUG [WebResourceParser] Found matching url extractor (Castalba) for resource http://www.castalba.tv/channels
2012-07-27 18:11:14,019 DEBUG [FeedItemUrlExtractor] Castalba: Starting parsing resource: http://www.castalba.tv/channels
2012-07-27 18:11:17,268 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Chelsea TV - http://www.castalba.tv/channel/4199 - rtmpe://cp96798.live.edgefcs.net/live//ChelTV_Ch01_1000k@26291 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 18:11:25,040 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Bloomberg TV - http://www.castalba.tv/channel/4190 - rtmpt://cp87869.live.edgefcs.net:1935/live/us_300@21006 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 18:11:30,650 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-07-27 18:11:30,650 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-07-27 18:11:31,154 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.10:57538
2012-07-27 18:11:31,154 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-07-27 18:11:31,154 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:57538
2012-07-27 18:11:32,451 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:48
2012-07-27 18:11:32,946 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Al Jazeera News - http://www.castalba.tv/channel/4182 - rtmpt://cp79926.live.edgefcs.net:1935/live/ajmm@53707 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 18:11:40,779 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Sky TG24 - http://www.castalba.tv/channel/4191 - rtmpt://cp49989.live.edgefcs.net:1935/live/streamRM1@2564 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 18:11:44,023 WARN  [FeedUpdaterThread] An error occured while scanning for online item information, will continue
java.io.IOException: Unexpected error while invoking plugin (Castalba): 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
2012-07-27 18:11:48,538 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Telemadrid - http://www.castalba.tv/channel/5551 - rtmp://cp118141.live.edgefcs.net/live//TSAlaotra@47718 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 18:11:56,316 DEBUG [FeedItemUrlExtractor] Castalba: ADDED SSF - http://www.castalba.tv/channel/4892 - rtmp://ipmedia.mpl.miisolutions.net/ipmedia-live01//mp4:ssflive swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 18:11:59,509 DEBUG [PlaylistDAOImpl] Reading all Playlists
2012-07-27 18:11:59,513 DEBUG [PlaylistMaintainerThread] Playlist ALL MUSIC FOR WIIMC+ has unresolved items, checking if they are in the library now
2012-07-27 18:11:59,513 DEBUG [PlaylistParser] Parsing playlist 'D:\My Music\- Playlists\ALL MUSIC FOR WIIMC+.m3u'
2012-07-27 18:11:59,513 DEBUG [PlaylistParser] Reading playlist from a local file
2012-07-27 18:11:59,514 DEBUG [PlaylistParser] Found a suitable playlist parser strategy: M3UParserStrategy
2012-07-27 18:11:59,523 DEBUG [PlaylistDAOImpl] Reading items for playlist 9
2012-07-27 18:11:59,528 DEBUG [MediaItemDAOImpl] Looking up a media item for file path: D:\My Music\Creedence.Clearwater.Revival-Collection-TB\Creedence_Clearwater_Revival-Ch._1_The_20_Greatest_Hits-1990-arP\13-run_th, ignore case: true
2012-07-27 18:12:04,145 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Deluxe Music - http://www.castalba.tv/channel/7950 - rtmp://flash.cdn.deluxemusic.tv/deluxemusic.tv-live//web_850.stream swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
2012-07-27 18:12:11,880 DEBUG [FeedItemUrlExtractor] Castalba: ADDED Sky Poker - http://www.castalba.tv/channel/7948 - rtmpe://cp67698.live.edgefcs.net/live//SkyPoker_500k@9124 swfUrl=http://static.castalba.tv/player.swf pageURL=http://castalba.tv swfVfy=0 live=1 
Last edited by jhb50 on Sat Jul 28, 2012 2:29 am, edited 1 time in total.
<<

zip

User avatar

Serviio developer / Site Admin

Posts: 16858

Joined: Sat Oct 24, 2009 12:24 pm

Location: London, UK

Post Fri Jul 27, 2012 10:46 pm

Re: Erroneous Timeout Logic

so there are currently two timeouts (both 30 seconds):

- one for execution of extractItems() - getting list of items should not take more than 30 seconds. This timeout is there only for Web Resource plugins
- one for extractUrl() - each item has 30 second to get it's URL

What you are seeing it the first timeout. Not sure why it's taking so long, are you actually getting the RTMP url's inside extractItems() ? If yes then it's bad design of the plugin.
<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Sat Jul 28, 2012 12:21 am

Re: Erroneous Timeout Logic

OK understood. Thanks. I've changed the logic to extract the rtmps in extractUrl.

Return to Plugin development

Who is online

Users browsing this forum: No registered users and 4 guests

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