www.ceskatelevize.cz problem

Some new video downloads failed, e.g. (October 23)

[www.ceskatelevize.cz]

app log (part):
-----
Sat Oct 24 10:43:41 CEST 2015 WARNING: Invalid URL - 'http://www.ceskatelevize.cz/ivysilani/embed/iFramePlayer.php?hash=53a97d6992cc2a97d3c6f6b3209136d898327fa7&IDEC=215 522 16160/0033&channelID=1&width=100%' does not match URI specification with URI charset UTF-8
Sat Oct 24 10:43:41 CEST 2015 WARNING: Loading file failed
-----

I am using the latest FRD 0.9u4, plugin v. 2.0.3.

Maybe there was some change in October 16/17, because the followig is OK (October 16)

[www.ceskatelevize.cz]

the following is not OK (October 17):

[www.ceskatelevize.cz]

Your sample link #1 and #2 work fine for me. As for #3, it's not available in my country.

Can you attach app.log in debug mode? To enable debug mode, see point #5 on "Troubleshooting" section of this page.

Probably the directory ivysilani is restricted to region, another access to link #3 is [www.ceskatelevize.cz].

I tried the link #1 [www.ceskatelevize.cz] at the debug mode. The resulting log file (part concerning the download) is too large to be presented here (73 kB, 1 line has about 48000 characters), can be found on [webshare.cz] (I replaced my username by "..." only). The following is obtained if the extremely long line is shortened by "......" (end separated by empty lines).

at Oct 24 16:30:20 CEST 2015 INFO: Property changed: lastComboPath
Sat Oct 24 16:30:20 CEST 2015 INFO: Cache hit
Sat Oct 24 16:30:20 CEST 2015 INFO: =====Saving updated/added files into the database (1) =====
Sat Oct 24 16:30:20 CEST 2015 INFO: Creating pool workWithFile
Sat Oct 24 16:30:20 CEST 2015 INFO: Loading plugin with ID=ceskatelevize.cz
Sat Oct 24 16:30:20 CEST 2015 INFO: Plugin loaded
Sat Oct 24 16:30:20 CEST 2015 INFO: plug-in started - applehls@1.0.7 (active/total: 1 of 935)
Sat Oct 24 16:30:20 CEST 2015 INFO: plug-in started - ceskatelevize.cz@2.0.3 (active/total: 2 of 935)
Sat Oct 24 16:30:20 CEST 2015 INFO: Plugin with ID=ceskatelevize.cz was loaded
Sat Oct 24 16:30:20 CEST 2015 INFO: Setting state to QUEUED
Sat Oct 24 16:30:20 CEST 2015 INFO: Getting downloadFile [www.ceskatelevize.cz]
Sat Oct 24 16:30:20 CEST 2015 INFO: Loading plugin with ID=ceskatelevize.cz
Sat Oct 24 16:30:20 CEST 2015 INFO: Plugin with ID=ceskatelevize.cz was loaded
Sat Oct 24 16:30:20 CEST 2015 INFO: Getting plugin: PluginMetaData{dbId=467 id='ceskatelevize.cz' Version=2.0.3}
Sat Oct 24 16:30:20 CEST 2015 INFO: preventSystemStandby(true)
Sat Oct 24 16:30:20 CEST 2015 INFO: Setting state to TESTING
Sat Oct 24 16:30:20 CEST 2015 INFO: Test for sleeping
Sat Oct 24 16:30:20 CEST 2015 INFO: starting download in state s = TESTING
Sat Oct 24 16:30:20 CEST 2015 INFO: Starting 'runCheck' for file [www.ceskatelevize.cz]
Sat Oct 24 16:30:21 CEST 2015 INFO: Setting state to QUEUED
Sat Oct 24 16:30:21 CEST 2015 INFO: preventSystemStandby(false)
Sat Oct 24 16:30:21 CEST 2015 INFO: Getting downloadFile [www.ceskatelevize.cz]
Sat Oct 24 16:30:21 CEST 2015 INFO: Loading plugin with ID=ceskatelevize.cz
Sat Oct 24 16:30:21 CEST 2015 INFO: Plugin with ID=ceskatelevize.cz was loaded
Sat Oct 24 16:30:21 CEST 2015 INFO: Getting plugin: PluginMetaData{dbId=467 id='ceskatelevize.cz' Version=2.0.3}
Sat Oct 24 16:30:21 CEST 2015 INFO: preventSystemStandby(true)
Sat Oct 24 16:30:21 CEST 2015 INFO: Setting state to GETTING
Sat Oct 24 16:30:21 CEST 2015 INFO: Test for sleeping
Sat Oct 24 16:30:21 CEST 2015 INFO: starting download in state s = GETTING
Sat Oct 24 16:30:21 CEST 2015 INFO: Setting state to WAITING
Sat Oct 24 16:30:21 CEST 2015 INFO: Going to sleep for 4 seconds
Sat Oct 24 16:30:25 CEST 2015 INFO: Setting state to GETTING
Sat Oct 24 16:30:25 CEST 2015 INFO: Starting 'run' for file [www.ceskatelevize.cz]
Sat Oct 24 16:30:25 CEST 2015 INFO: Starting download in TASK [www.ceskatelevize.cz]
Sat Oct 24 16:30:25 CEST 2015 INFO: Setting referer to [www.ceskatelevize.cz]
Sat Oct 24 16:30:25 CEST 2015 INFO: Converting [www.ceskatelevize.cz] 522 16160/0033&channelID=1&width=100% with URI charset UTF-8
Sat Oct 24 16:30:25 CEST 2015 WARNING: Invalid URL - 'http://www.ceskatelevize.cz/ivysilani/embed/iFramePlayer.php?hash=00c0173e6c9d8c2a46815388390e9b92564652fe&IDEC=215 522 16160/0033&channelID=1&width=100%' does not match URI specification with URI charset UTF-8
Sat Oct 24 16:30:26 CEST 2015 INFO: Setting referer to [www.ceskatelevize.cz]
Sat Oct 24 16:30:26 CEST 2015 INFO: Converting [www.ceskatelevize.cz] with URI charset UTF-8
Sat Oct 24 16:30:26 CEST 2015 INFO: Found switch item: SwitchItem{id='61924494877082646', duration=3131.4, url=http://80.188.65.18:80/cdn/uri/get/?token=a736c8c44d60e7ff3c88e3e583a3c7e8e3bc9b17&contentType=vod&expiry=1445700633&id=61924494877082646&playerType=flash&quality=web®ion=1&skipIpAddressCheck=false&userId=df772d7c-2a2a-43bb-8959-12385c6e2f86}
Sat Oct 24 16:30:26 CEST 2015 INFO: Selected switch item : SwitchItem{id='61924494877082646', duration=3131.4, url=http://80.188.65.18:80/cdn/uri/get/?token=a736c8c44d60e7ff3c88e3e583a3c7e8e3bc9b17&contentType=vod&expiry=1445700633&id=61924494877082646&playerType=flash&quality=web®ion=1&skipIpAddressCheck=false&userId=df772d7c-2a2a-43bb-8959-12385c6e2f86}
Sat Oct 24 16:30:26 CEST 2015 INFO: Settings config: CeskaTelevizeSettingsConfig{videoQuality=Highest quality}
Sat Oct 24 16:30:26 CEST 2015 INFO: Playlist URL: [80.188.65.18]
Sat Oct 24 16:30:27 CEST 2015 INFO: Found media list: [HlsMedia{url='http://80.188.78.172:80/atip/eb9e373f304cbec0227c709ab1b980e5/1445697033429/sess/7e6c9f4149dc52c5c96c080aa0ef9376/61924494877082622/1502.k.m3u8', bandwidth=500 Kbps, quality=0}, HlsMedia{url='http://80.188.78.172:80/atip/c2ea3e697462136955617c195ed65cdd/1445697033429/sess/7e6c9f4149dc52c5c96c080aa0ef9376/61924494877082622/1503.k.m3u8', bandwidth=1032 Kbps, quality=0}, HlsMedia{url='http://80.188.78.172:80/atip/78819cd6a4f7e857c71fee4662682d3d/1445697033429/sess/7e6c9f4149dc52c5c96c080aa0ef9376/61924494877082622/1504.k.m3u8', bandwidth=2048 Kbps, quality=0}, HlsMedia{url='http://80.188.78.172:80/atip/04c1f8bf04b840261c01a6d028083b52/1445697033429/sess/7e6c9f4149dc52c5c96c080aa0ef9376/61924494877082622/1505.k.m3u8', bandwidth=3584 Kbps, quality=0}]
Sat Oct 24 16:30:27 CEST 2015 INFO: Downloading media: HlsMedia{url='http://80.188.78.172:80/atip/04c1f8bf04b840261c01a6d028083b52/1445697033429/sess/7e6c9f4149dc52c5c96c080aa0ef9376/61924494877082622/1505.k.m3u8', bandwidth=3584 Kbps, quality=0}
Sat Oct 24 16:30:27 CEST 2015 INFO: Playlist URL: [80.188.78.172]

Sat Oct 24 16:30:27 CEST 2015 INFO: Found segment media list: [HlsMedia{url='http://80.188.78.172:80/atip/41ac55ee7886e58d98f68612c070f2f4/1445697033429/sess/008ab24659f2232d74d8ce22eb478260/0/1505/220-20280-5402-17/0.k.ts', bandwidth=3584 Kbps, quality=0}, HlsMedia{url='http://80.188.78.172:80/atip/f1d03b7cd76dc3f630b7d86283695cb9/1445697033429/sess/008ab24659f2232d74d8ce22eb478260/0/1505/220-20280-5402-17/1.k.ts', bandwidth=3584 Kbps, quality=0}, HlsMedia{url='http://80.188.78.172:80/atip/73f0ef797604ab93fa025a1d6fac83d1/1445697033429/sess/008ab24659f2232d74d8ce22eb478260/0/1505/220-20280-5402-18/0.k.ts', bandwidth=3584 Kbps, quality=0}, ......]

Sat Oct 24 16:30:27 CEST 2015 INFO: Starting HLS download
Sat Oct 24 16:30:27 CEST 2015 INFO: Free space on disk: 46313394176
Sat Oct 24 16:30:27 CEST 2015 INFO: Setting state to DOWNLOADING
Sat Oct 24 16:30:27 CEST 2015 INFO: starting download from position 0
Sat Oct 24 16:30:27 CEST 2015 INFO: Downloading: [80.188.78.172]
Sat Oct 24 16:30:27 CEST 2015 INFO: ===============HTTP METHOD===============
Sat Oct 24 16:30:27 CEST 2015 INFO: path = /atip/41ac55ee7886e58d98f68612c070f2f4/1445697033429/sess/008ab24659f2232d74d8ce22eb478260/0/1505/220-20280-5402-17/0.k.ts
Sat Oct 24 16:30:27 CEST 2015 INFO: header =
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: en-US,en;q=0.5
Accept-Encoding: gzip
Referer: [www.ceskatelevize.cz]
Sat Oct 24 16:30:27 CEST 2015 INFO: post parameters:
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: en-US,en;q=0.5
Accept-Encoding: gzip
Referer: [www.ceskatelevize.cz]
Sat Oct 24 16:30:27 CEST 2015 INFO: query string = null
Sat Oct 24 16:30:27 CEST 2015 INFO: =========================================
Sat Oct 24 16:30:27 CEST 2015 INFO: Response content length is not known
Sat Oct 24 16:30:27 CEST 2015 WARNING: Loading file failed
Sat Oct 24 16:30:30 CEST 2015 SEVERE: cz.vity.freerapid.core.tasks.DownloadTask@243e70 failed: java.io.IOException: Failed to request segment 1
java.io.IOException: Failed to request segment 1
at cz.vity.freerapid.plugins.services.applehls.SegmentRequester.nextSegment(Unknown Source)
at cz.vity.freerapid.plugins.services.applehls.HlsInputStream.read(Unknown Source)
at java.io.InputStream.read(Unknown Source)
at cz.vity.freerapid.core.tasks.DownloadTask.saveToFile(DownloadTask.java:242)
at cz.vity.freerapid.plugins.services.applehls.HlsDownloader.tryDownloadAndSaveFile(Unknown Source)
at cz.vity.freerapid.plugins.services.applehls.HlsDownloader.tryDownloadAndSaveFile(Unknown Source)
at cz.vity.freerapid.plugins.services.ceskatelevize.CeskaTelevizeFileRunner.run(Unknown Source)
at cz.vity.freerapid.plugins.webclient.AbstractFileShareService.run(AbstractFileShareService.java:102)
at cz.vity.freerapid.core.tasks.DownloadTask.doInBackground(DownloadTask.java:98)
at cz.vity.freerapid.core.tasks.DownloadTask.doInBackground(DownloadTask.java:42)
at javax.swing.SwingWorker$1.call(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at javax.swing.SwingWorker.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Sat Oct 24 16:30:30 CEST 2015 SEVERE:
java.io.IOException: Failed to request segment 1
at cz.vity.freerapid.plugins.services.applehls.SegmentRequester.nextSegment(Unknown Source)
at cz.vity.freerapid.plugins.services.applehls.HlsInputStream.read(Unknown Source)
at java.io.InputStream.read(Unknown Source)
at cz.vity.freerapid.core.tasks.DownloadTask.saveToFile(DownloadTask.java:242)
at cz.vity.freerapid.plugins.services.applehls.HlsDownloader.tryDownloadAndSaveFile(Unknown Source)
at cz.vity.freerapid.plugins.services.applehls.HlsDownloader.tryDownloadAndSaveFile(Unknown Source)
at cz.vity.freerapid.plugins.services.ceskatelevize.CeskaTelevizeFileRunner.run(Unknown Source)
at cz.vity.freerapid.plugins.webclient.AbstractFileShareService.run(AbstractFileShareService.java:102)
at cz.vity.freerapid.core.tasks.DownloadTask.doInBackground(DownloadTask.java:98)
at cz.vity.freerapid.core.tasks.DownloadTask.doInBackground(DownloadTask.java:42)
at javax.swing.SwingWorker$1.call(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at javax.swing.SwingWorker.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Sat Oct 24 16:30:30 CEST 2015 INFO: Setting state to ERROR
Sat Oct 24 16:30:30 CEST 2015 INFO: preventSystemStandby(false)
Sat Oct 24 16:30:30 CEST 2015 INFO: Test for sleeping
Sat Oct 24 16:30:30 CEST 2015 INFO: =====Saving updated/added files into the database (1) =====
Sat Oct 24 16:30:33 CEST 2015 INFO: Property changed: proxy.password
Sat Oct 24 16:30:33 CEST 2015 WARNING: Couldn't create fir C:\Users\...\AppData\Roaming\VitySoft\FRD
Sat Oct 24 16:30:35 CEST 2015 INFO: Setting state to DELETED
Sat Oct 24 16:30:35 CEST 2015 INFO: Test for sleeping
Sat Oct 24 16:30:35 CEST 2015 INFO: =====Removing deleted files from the database (1) =====

Finally, the file was downloaded in about the 10th try (and the 3rd attempt in it). Sorry for disturbing.

"WARNING: Loading file failed" line from log means that server sent non-200 as status code, so makeRequestForFile() returned null input stream, and HLS plugin threw this as an exception: "java.io.IOException: Failed to request segment 1".

I can't reproduce this issue. I tried to download link #1 5 times, and server always sent 200 as status code. I only tested to download ~10MB, because the file is big (~1.38GB for Highest Quality), and my connection is slow. So I'm not sure what's wrong here. Temporary server issue perhaps?



Edited 1 time(s). Last edit at 10/25/2015 08:37AM by tong2shot.

> Temporary server issue perhaps?

Probably. I expect there might be some problems occasionally, hence I tested several files several times within a week before reporting the problem. There was a strict difference: all files until October 16 without a problem and all files after October 17 non-downloadable. This does not appear now. I tested it appr. 6 hours ago and a couple of minutes ago (I also downloaded another file from yesterday meanwhile) and the only problem was that the link #1 started download at the third/second attempt (this sometimes happens).