FAQ  •  Register  •  Login

Serviio ffmpeg fails with valid rtmp streams.

<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Fri Oct 04, 2013 11:10 pm

Serviio ffmpeg fails with valid rtmp streams.

Using streams from Castalba.com in a WebResource, ffmpeg fails (when transcoding to flv for mediabrowser playback, or mpegts for Serviigo playback) as documented below, but will occasionally work correctly.
Using the links directly with ffmpeg or ffplay command always works correctly as also documented below.
Note the streams expire and so are declared as expiresimmediately and I have tested as "live=true" and "live=false"

Opened bit bucket ticket 717 https://bitbucket.org/xnejp03/serviio/i ... ranscoding

As live=true:
  Code:
2013-10-04 18:10:23,408 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-04 18:10:23,408 DEBUG [VideoDeliveryEngine] Extracting new URL for the expired feed item
2013-10-04 18:10:23,408 DEBUG [FeedItemUrlExtractor] Castalba: Starting extraction of url for item: BBC News
2013-10-04 18:10:24,184 DEBUG [FeedItemUrlExtractor] Castalba: call castalba
2013-10-04 18:10:24,187 DEBUG [FeedItemUrlExtractor] Castalba: Extracted Url for http://www.castalba.tv/channel/9417 - 178734?313338303932353039325f3036636161333366646434303938373331643436623037643664386631306266
2013-10-04 18:10:24,188 DEBUG [FeedItemUrlExtractor] Castalba: Finished extraction of url: ContentURLContainer [fileType=VIDEO, contentUrl=rtmp://173.192.70.168/live app=live tcUrl=rtmp://173.192.70.168/live playpath=178734?313338303932353039325f3036636161333366646434303938373331643436623037643664386631306266 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1, thumbnailUrl=http://castalba.tv/images/zaps/178734.jpg, expiresOn=Fri Oct 04 19:15:00 EDT 2013, expiresImmediately=true, cacheKey=http://www.castalba.tv/channel/9417, live=true, ]
2013-10-04 18:10:24,188 DEBUG [VideoDeliveryEngine] Successfully set new URL for the feed item
2013-10-04 18:10:24,188 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: rtmp://173.192.70.168/live app=live tcUrl=rtmp://173.192.70.168/live playpath=178734?313338303932353039325f3036636161333366646434303938373331643436623037643664386631306266 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1
2013-10-04 18:10:24,189 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -analyzeduration 10000000 -fflags +genpts -threads 8 -i rtmp://173.192.70.168/live app=live tcUrl=rtmp://173.192.70.168/live playpath=178734?313338303932353039325f3036636161333366646434303938373331643436623037643664386631306266 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 -y -threads 8 -c:v copy -c:a libmp3lame -b:a 48k -ar 44100 -ac 2 -map 0:0 -map 0:1 -sn -f flv pipe:
2013-10-04 18:10:29,629 DEBUG [TimeoutStreamDelegator] Closing piped input stream and closing related feeder process
2013-10-04 18:10:34,260 DEBUG [SearchManager] Committing search index
2013-10-04 18:10:37,306 WARN  [ProcessExecutor] Process cmd has a return code of 1! This is a possible error. Detailed output follows.
libavfilter     3. 77.101 /  3. 77.101
libswscale      2.  3.100 /  2.  3.100
libswresample   0. 17.102 /  0. 17.102
libpostproc    52.  3.100 / 52.  3.100
rtmp://173.192.70.168/live app=live tcUrl=rtmp://173.192.70.168/live playpath=178734?313338303932353039325f3036636161333366646434303938373331643436623037643664386631306266 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: Unknown error occurred


but ffmpeg works fine
  Code:
C:\Users\John>ffmpeg -i "rtmp://173.192.70.168/live app=live tcUrl=rtmp://173.19
2.70.168/live playpath=178734?313338303932353039325f3036636161333366646434303938
373331643436623037643664386631306266 pageUrl=http://castalba.tv/channel/9417 swf
Url=http://static.castalba.tv/player5.9.swf live=1"
ffmpeg version N-55020-g768e40b Copyright (c) 2000-2013 the FFmpeg developers
  built on Jul 28 2013 18:01:30 with gcc 4.7.3 (GCC)
  configuration: --enable-gpl --enable-version3 --disable-w32threads --enable-av
isynth --enable-bzlib --enable-fontconfig --enable-frei0r --enable-gnutls --enab
le-iconv --enable-libass --enable-libbluray --enable-libcaca --enable-libfreetyp
e --enable-libgsm --enable-libilbc --enable-libmodplug --enable-libmp3lame --ena
ble-libopencore-amrnb --enable-libopencore-amrwb --enable-libopenjpeg --enable-l
ibopus --enable-librtmp --enable-libschroedinger --enable-libsoxr --enable-libsp
eex --enable-libtheora --enable-libtwolame --enable-libvo-aacenc --enable-libvo-
amrwbenc --enable-libvorbis --enable-libvpx --enable-libx264 --enable-libxavs --
enable-libxvid --enable-zlib
  libavutil      52. 40.100 / 52. 40.100
  libavcodec     55. 19.100 / 55. 19.100
  libavformat    55. 12.102 / 55. 12.102
  libavdevice    55.  3.100 / 55.  3.100
  libavfilter     3. 81.103 /  3. 81.103
  libswscale      2.  4.100 /  2.  4.100
  libswresample   0. 17.103 /  0. 17.103
  libpostproc    52.  3.100 / 52.  3.100
Metadata:
  width                 512.00
  height                288.00
  videodatarate         448.00
  videocodecid          7.00
  audiodatarate         48.00
  audiosamplerate       44100.00
Input #0, flv, from 'rtmp://173.192.70.168/live app=live tcUrl=rtmp://173.192.70
.168/live playpath=178734?313338303932353039325f30366361613333666464343039383733
31643436623037643664386631306266 pageUrl=http://castalba.tv/channel/9417 swfUrl=
http://static.castalba.tv/player5.9.swf live=1':
  Duration: N/A, start: 0.000000, bitrate: 507 kb/s
    Stream #0:0: Video: h264 (Baseline), yuv420p, 512x288 [SAR 1:1 DAR 16:9], 45
8 kb/s, 25 tbr, 1k tbn, 50 tbc
    Stream #0:1: Audio: aac, 44100 Hz, stereo, fltp, 49 kb/s
At least one output file must be specified


As live=false
  Code:
2013-10-04 17:55:35,910 DEBUG [VideoDeliveryEngine] Extracting new URL for the expired feed item
2013-10-04 17:55:35,910 DEBUG [FeedItemUrlExtractor] Castalba: Starting extraction of url for item: BBC News
2013-10-04 17:55:36,559 DEBUG [FeedItemUrlExtractor] Castalba: call castalba
2013-10-04 17:55:36,561 DEBUG [FeedItemUrlExtractor] Castalba: Extracted Url for http://www.castalba.tv/channel/9417 - 178734?313338303932343230345f3334343436646162313830363936653631626361653437303365613739623639
2013-10-04 17:55:36,561 DEBUG [FeedItemUrlExtractor] Castalba: Finished extraction of url: ContentURLContainer [fileType=VIDEO, contentUrl=rtmp://159.253.145.164/live app=live tcUrl=rtmp://159.253.145.164/live playpath=178734?313338303932343230345f3334343436646162313830363936653631626361653437303365613739623639 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1, thumbnailUrl=http://castalba.tv/images/zaps/178734.jpg, expiresImmediately=true, cacheKey=http://www.castalba.tv/channel/9417, live=false, ]
2013-10-04 17:55:36,561 DEBUG [VideoDeliveryEngine] Successfully set new URL for the feed item
2013-10-04 17:55:36,562 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: rtmp://159.253.145.164/live app=live tcUrl=rtmp://159.253.145.164/live playpath=178734?313338303932343230345f3334343436646162313830363936653631626361653437303365613739623639 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000
2013-10-04 17:55:36,562 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -analyzeduration 10000000 -fflags +genpts -threads 8 -i rtmp://159.253.145.164/live app=live tcUrl=rtmp://159.253.145.164/live playpath=178734?313338303932343230345f3334343436646162313830363936653631626361653437303365613739623639 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000 -y -threads 8 -c:v copy -c:a libmp3lame -b:a 48k -ar 44100 -ac 2 -map 0:0 -map 0:1 -sn -f flv C:\Windows\Temp\Serviio\transcoding-temp-1000002090003169-flv_player-ORIGINAL.stf
2013-10-04 17:55:36,990 DEBUG [CDSRetrieveMediaServerResource] GET http://localhost:23424/cds/resource/1000002090003169/MEDIA_ITEM/FLV-0/ORIGINAL?profile=flv_player&authToken=d7df83f1e9e84d2b981e74d43860dcf2 HTTP/1.1, headers = [host: localhost:23424,connection: keep-alive,user-agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/30.0.1599.66 Safari/537.36,accept: */*,referer: http://localhost:23424/mediabrowser/,accept-encoding: gzip,deflate,sdch,accept-language: en-US,en;q=0.8]
2013-10-04 17:55:36,991 DEBUG [CDSRetrieveMediaServerResource] Creating client with id '127.0.0.1'
2013-10-04 17:55:36,991 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-04 17:55:36,991 DEBUG [ResourceDeliveryProcessor] Request for resource 1000002090003169 and type 'MEDIA_ITEM' received
2013-10-04 17:55:36,991 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000002090003169 (online)
2013-10-04 17:55:36,991 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 209)
2013-10-04 17:55:36,992 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 209)
2013-10-04 17:55:36,993 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1000002090003169, format FLV and profile Flash player
2013-10-04 17:55:36,993 DEBUG [AbstractTranscodingDeliveryEngine] Getting media info for transcoded version of file rtmp://159.253.143.62/live app=live tcUrl=rtmp://159.253.143.62/live playpath=178734?313338303932323639355f6532336632343632383038393132356461346236353138656438633964646432 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1
2013-10-04 17:55:36,994 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://159.253.143.62/live app=live tcUrl=rtmp://159.253.143.62/live playpath=178734?313338303932323639355f6532336632343632383038393132356461346236353138656438633964646432 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-04 17:55:36,994 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://159.253.143.62/live app=live tcUrl=rtmp://159.253.143.62/live playpath=178734?313338303932323639355f6532336632343632383038393132356461346236353138656438633964646432 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-04 17:55:36,994 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://159.253.143.62/live app=live tcUrl=rtmp://159.253.143.62/live playpath=178734?313338303932323639355f6532336632343632383038393132356461346236353138656438633964646432 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-04 17:55:36,994 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000002090003169 (online)
2013-10-04 17:55:36,994 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 209)
2013-10-04 17:55:36,995 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 209)
2013-10-04 17:55:36,996 DEBUG [VideoDeliveryEngine] Delivering item '1000002090003169' for client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-04 17:55:36,996 DEBUG [VideoDeliveryEngine] Delivering file 'rtmp://159.253.143.62/live app=live tcUrl=rtmp://159.253.143.62/live playpath=178734?313338303932323639355f6532336632343632383038393132356461346236353138656438633964646432 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1' using transcoding
2013-10-04 17:55:50,284 WARN  [ProcessExecutor] Process cmd has a return code of 1! This is a possible error. Detailed output follows.
libavfilter     3. 77.101 /  3. 77.101
libswscale      2.  3.100 /  2.  3.100
libswresample   0. 17.102 /  0. 17.102
libpostproc    52.  3.100 / 52.  3.100
rtmp://159.253.145.164/live app=live tcUrl=rtmp://159.253.145.164/live playpath=178734?313338303932343230345f3334343436646162313830363936653631626361653437303365613739623639 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000: Unknown error occurred

again ffmpeg works fine
  Code:
C:\Users\John>ffmpeg -i "rtmp://159.253.145.164/live app=live tcUrl=rtmp://159.2
53.145.164/live playpath=178734?313338303932343230345f33343434366461623138303639
36653631626361653437303365613739623639 pageUrl=http://castalba.tv/channel/9417 s
wfUrl=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000: Unknown e
rror occurred
ffmpeg version N-55020-g768e40b Copyright (c) 2000-2013 the FFmpeg developers
  built on Jul 28 2013 18:01:30 with gcc 4.7.3 (GCC)
  configuration: --enable-gpl --enable-version3 --disable-w32threads --enable-av
isynth --enable-bzlib --enable-fontconfig --enable-frei0r --enable-gnutls --enab
le-iconv --enable-libass --enable-libbluray --enable-libcaca --enable-libfreetyp
e --enable-libgsm --enable-libilbc --enable-libmodplug --enable-libmp3lame --ena
ble-libopencore-amrnb --enable-libopencore-amrwb --enable-libopenjpeg --enable-l
ibopus --enable-librtmp --enable-libschroedinger --enable-libsoxr --enable-libsp
eex --enable-libtheora --enable-libtwolame --enable-libvo-aacenc --enable-libvo-
amrwbenc --enable-libvorbis --enable-libvpx --enable-libx264 --enable-libxavs --
enable-libxvid --enable-zlib
  libavutil      52. 40.100 / 52. 40.100
  libavcodec     55. 19.100 / 55. 19.100
  libavformat    55. 12.102 / 55. 12.102
  libavdevice    55.  3.100 / 55.  3.100
  libavfilter     3. 81.103 /  3. 81.103
  libswscale      2.  4.100 /  2.  4.100
  libswresample   0. 17.103 /  0. 17.103
  libpostproc    52.  3.100 / 52.  3.100
Metadata:
  width                 512.00
  height                288.00
  videodatarate         448.00
  videocodecid          7.00
  audiodatarate         48.00
  audiosamplerate       44100.00
Input #0, flv, from 'rtmp://159.253.145.164/live app=live tcUrl=rtmp://159.253.1
45.164/live playpath=178734?313338303932343230345f333434343664616231383036393665
3631626361653437303365613739623639 pageUrl=http://castalba.tv/channel/9417 swfUr
l=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000: Unknown error
 occurred':
  Duration: N/A, start: 0.000000, bitrate: 507 kb/s
    Stream #0:0: Video: h264 (Baseline), yuv420p, 512x288 [SAR 1:1 DAR 16:9], 45
8 kb/s, 25 tbr, 1k tbn, 50 tbc
    Stream #0:1: Audio: aac, 44100 Hz, stereo, fltp, 49 kb/s
At least one output file must be specified

C:\Users\John>ffmpeg -i "rtmp://159.253.145.164/live app=live tcUrl=rtmp://159.2
53.145.164/live playpath=178734?313338303932343230345f33343434366461623138303639
36653631626361653437303365613739623639 pageUrl=http://castalba.tv/channel/9417 s
wfUrl=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000"
ffmpeg version N-55020-g768e40b Copyright (c) 2000-2013 the FFmpeg developers
  built on Jul 28 2013 18:01:30 with gcc 4.7.3 (GCC)
  configuration: --enable-gpl --enable-version3 --disable-w32threads --enable-av
isynth --enable-bzlib --enable-fontconfig --enable-frei0r --enable-gnutls --enab
le-iconv --enable-libass --enable-libbluray --enable-libcaca --enable-libfreetyp
e --enable-libgsm --enable-libilbc --enable-libmodplug --enable-libmp3lame --ena
ble-libopencore-amrnb --enable-libopencore-amrwb --enable-libopenjpeg --enable-l
ibopus --enable-librtmp --enable-libschroedinger --enable-libsoxr --enable-libsp
eex --enable-libtheora --enable-libtwolame --enable-libvo-aacenc --enable-libvo-
amrwbenc --enable-libvorbis --enable-libvpx --enable-libx264 --enable-libxavs --
enable-libxvid --enable-zlib
  libavutil      52. 40.100 / 52. 40.100
  libavcodec     55. 19.100 / 55. 19.100
  libavformat    55. 12.102 / 55. 12.102
  libavdevice    55.  3.100 / 55.  3.100
  libavfilter     3. 81.103 /  3. 81.103
  libswscale      2.  4.100 /  2.  4.100
  libswresample   0. 17.103 /  0. 17.103
  libpostproc    52.  3.100 / 52.  3.100
Metadata:
  width                 512.00
  height                288.00
  videodatarate         448.00
  videocodecid          7.00
  audiodatarate         48.00
  audiosamplerate       44100.00
Input #0, flv, from 'rtmp://159.253.145.164/live app=live tcUrl=rtmp://159.253.1
45.164/live playpath=178734?313338303932343230345f333434343664616231383036393665
3631626361653437303365613739623639 pageUrl=http://castalba.tv/channel/9417 swfUr
l=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000':
  Duration: N/A, start: 0.000000, bitrate: 507 kb/s
    Stream #0:0: Video: h264 (Baseline), yuv420p, 512x288 [SAR 1:1 DAR 16:9], 45
8 kb/s, 25 tbr, 1k tbn, 50 tbc
    Stream #0:1: Audio: aac, 44100 Hz, stereo, fltp, 49 kb/s
At least one output file must be specified


and here is the failure transcoding to mpegts
  Code:
2013-10-04 18:44:16,760 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: rtmp://173.192.70.165/live app=live tcUrl=rtmp://173.192.70.165/live playpath=178734?313338303932373132355f3062643936373862313139313330386361633938663264356466393563666338 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1
2013-10-04 18:44:16,760 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -analyzeduration 10000000 -fflags +genpts -threads 8 -i rtmp://173.192.70.165/live app=live tcUrl=rtmp://173.192.70.165/live playpath=178734?313338303932373132355f3062643936373862313139313330386361633938663264356466393563666338 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 -y -threads 8 -c:v copy -bsf:v h264_mp4toannexb -c:a copy -map 0:0 -map 0:1 -sn -f mpegts pipe:
2013-10-04 18:44:30,486 WARN  [ProcessExecutor] Process cmd has a return code of 1! This is a possible error. Detailed output follows.
libavfilter     3. 77.101 /  3. 77.101
libswscale      2.  3.100 /  2.  3.100
libswresample   0. 17.102 /  0. 17.102
libpostproc    52.  3.100 / 52.  3.100
rtmp://173.192.70.165/live app=live tcUrl=rtmp://173.192.70.165/live playpath=178734?313338303932373132355f3062643936373862313139313330386361633938663264356466393563666338 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: Unknown error occurred
<<

zip

User avatar

Serviio developer / Site Admin

Posts: 16505

Joined: Sat Oct 24, 2009 12:24 pm

Location: London, UK

Post Fri Oct 04, 2013 11:31 pm

Re: Serviio ffmpeg fails with valid rtmp streams.

you only provided results of ffmpeg -i, it looks like it actually failed the transcoding command. Can you try to run the whole process (and output to a file instead of pipe:) to see if it fails at some point.
<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Sat Oct 05, 2013 1:17 am

Re: Serviio ffmpeg fails with valid rtmp streams.

Pipes fine to command window but hangs it so I changed pipe to create a file
  Code:
"C:\Program Files\Serviio\lib\ffmpeg.exe" -analyzeduration 10000000 -fflags +genpts -threads 8 -i "rtmp://173.192.70.169/live app=live tcUrl=rtmp://173.192.70.169/live playpath=178734?313338303933353531355f3666633532643937303463636233313237383439336139643033636163306262 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1" -y -threads 8 -c:v copy -c:a libmp3lame -b:a 48k -ar 44100 -ac 2 -map 0:0 -map 0:1 -sn -f flv D:\mov.flv


See video at http://www.filedropper.com/mov

Also generated transcode file from live=false but its too big to send.

  Code:
"C:\Program Files\Serviio\lib\ffmpeg.exe" -analyzeduration 10000000 -fflags +genpts -threads 8 -i "rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338303933363331375f3133363163306332323734343466323765313238316262363639396434353637 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000" -y -threads 8 -c:v copy -c:a libmp3lame -b:a 48k -ar 44100 -ac 2 -map 0:0 -map 0:1 -sn -f flv C:\Windows\Temp\Serviio\transcoding-temp-1000002090003727-flv_player-ORIGINAL.stf
<<

zip

User avatar

Serviio developer / Site Admin

Posts: 16505

Joined: Sat Oct 24, 2009 12:24 pm

Location: London, UK

Post Sat Oct 05, 2013 10:35 am

Re: Serviio ffmpeg fails with valid rtmp streams.

So it creates the file fine? Is there a delay before it starts?

The error message seems to come from FFmpeg, don't think it's related to Serviio code.
<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Mon Oct 07, 2013 4:00 am

Re: Serviio ffmpeg fails with valid rtmp streams.

I've tested this all weekend, trying different options, and it does appear that this BBC News stream is getting an ffmpeg error when the command is initially entered but is often successful on a subsequent retry both within Serviio (see below) and in a command window. I've been unable to bypass or eliminate the error with either different command parms or ffmpeg versions.

What I have found is that when Serviio encounters the ffmpeg error, it then repeats the Get sequence.(see the attached for a sample sequence) Its not clear to me when you introduced this retry or under what circumstances, or how many times you will retry. Often the first retry is successful, but I think I have seen it retry 3 or 4 times before giving up but here is no log message indicating the retry or when it gives up. I have also seen it restart the Get sequence after the reextract but before the first ffmpeg command so I am confused. Can you clarify the retry logic or add log messages?

Note that the following commands include the erroneous user-agent in rtmp urls which is a previously reported bug, but my wrapper removes it before sending the command to ffmpeg. I get the same log results without the wrapper if I do not include the useragent so its not a wrapper problem.
  Code:
2013-10-06 23:29:57,175 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:29:57,855 DEBUG [CDSRetrieveMediaServerResource] GET http://localhost:23424/cds/resource/1000000650004707/MEDIA_ITEM/FLV-0/ORIGINAL?profile=flv_player&authToken=23a2d9ff0f2e463690762be3322cff52 HTTP/1.1, headers = [host: localhost:23424,connection: keep-alive,user-agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/30.0.1599.66 Safari/537.36,accept: */*,referer: http://localhost:23424/mediabrowser/,accept-encoding: gzip,deflate,sdch,accept-language: en-US,en;q=0.8]
2013-10-06 23:29:57,855 DEBUG [CDSRetrieveMediaServerResource] Creating client with id '127.0.0.1'
2013-10-06 23:29:57,855 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-06 23:29:57,855 DEBUG [ResourceDeliveryProcessor] Request for resource 1000000650004707 and type 'MEDIA_ITEM' received
2013-10-06 23:29:57,855 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000650004707 (online)
2013-10-06 23:29:57,855 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:29:57,856 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:29:57,856 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1000000650004707, format FLV and profile Flash player
2013-10-06 23:29:57,856 DEBUG [AbstractTranscodingDeliveryEngine] Getting media info for transcoded version of file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1
2013-10-06 23:29:57,856 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:29:57,856 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:29:57,857 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:29:57,857 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000650004707 (online)
2013-10-06 23:29:57,857 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:29:57,857 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:29:57,858 DEBUG [VideoDeliveryEngine] Delivering item '1000000650004707' for client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-06 23:29:57,858 DEBUG [VideoDeliveryEngine] Delivering file 'rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1' using transcoding
2013-10-06 23:29:57,858 DEBUG [AbstractTranscodingDeliveryEngine] Stopping previous transcoding job of file 'transcoding-temp-1000002130002365-flv_player-ORIGINAL.stf'
2013-10-06 23:29:57,858 DEBUG [ProcessExecutor] Stopping external process: Thread[Thread-1099,5,main]
2013-10-06 23:29:57,858 DEBUG [ProcessUtils] Killing the Windows process: 6032
2013-10-06 23:29:57,871 DEBUG [TranscodingJobListener] Transcoding finished; successful: true
2013-10-06 23:29:57,873 DEBUG [TranscodingJobListener] Deleted temp file 'C:\Windows\Temp\Serviio\transcoding-temp-1000002130002365-flv_player-ORIGINAL.stf': true
2013-10-06 23:29:57,873 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-06 23:29:57,873 DEBUG [VideoDeliveryEngine] Extracting new URL for the expired feed item
2013-10-06 23:29:57,873 DEBUG [FeedItemUrlExtractor] Castalba: Starting extraction of url for item: BBC News
2013-10-06 23:29:58,622 DEBUG [FeedItemUrlExtractor] Castalba: call castalba
2013-10-06 23:29:58,625 DEBUG [FeedItemUrlExtractor] Castalba: Extracted Url for http://www.castalba.tv/channel/9417 - 178734?313338313131373131315f6433656661303966643664303065313862356139376633326266653062326636
2013-10-06 23:29:58,625 DEBUG [FeedItemUrlExtractor] Castalba: Finished extraction of url: ContentURLContainer [fileType=VIDEO, contentUrl=rtmp://37.58.66.163/live app=live tcUrl=rtmp://37.58.66.163/live playpath=178734?313338313131373131315f6433656661303966643664303065313862356139376633326266653062326636 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1, thumbnailUrl=http://castalba.tv/images/zaps/178734.jpg, expiresOn=Mon Oct 07 00:34:00 EDT 2013, expiresImmediately=true, cacheKey=http://www.castalba.tv/channel/9417, live=false, userAgent=Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.1 (KHTML, like Gecko) Chrome/21.0.1180.83 Safari/537.1]
2013-10-06 23:29:58,625 DEBUG [VideoDeliveryEngine] Successfully set new URL for the feed item
2013-10-06 23:29:58,626 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: rtmp://37.58.66.163/live app=live tcUrl=rtmp://37.58.66.163/live playpath=178734?313338313131373131315f6433656661303966643664303065313862356139376633326266653062326636 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000
2013-10-06 23:29:58,626 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\lib\ffdump.bat -analyzeduration 10000000 -fflags +genpts -user-agent Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.1 (KHTML, like Gecko) Chrome/21.0.1180.83 Safari/537.1 -threads 1 -i rtmp://37.58.66.163/live app=live tcUrl=rtmp://37.58.66.163/live playpath=178734?313338313131373131315f6433656661303966643664303065313862356139376633326266653062326636 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000 -y -threads 1 -c:v copy -c:a libmp3lame -b:a 48k -ar 44100 -ac 2 -map 0:0 -map 0:1 -sn -f flv C:\Windows\Temp\Serviio\transcoding-temp-1000000650004707-flv_player-ORIGINAL.stf
2013-10-06 23:30:12,665 WARN  [ProcessExecutor] Process cmd has a return code of 1! This is a possible error. Detailed output follows.
libswscale      2.  5.100 /  2.  5.100
libswresample   0. 17.103 /  0. 17.103
libpostproc    52.  3.100 / 52.  3.100
INFO: Connected...
pipe:: Invalid data found when processing input
2013-10-06 23:30:12,665 DEBUG [TranscodingJobListener] Transcoding finished; successful: false
2013-10-06 23:30:23,628 DEBUG [TranscodingJobListener] Deleted temp file 'C:\Windows\Temp\Serviio\transcoding-temp-1000000650004707-flv_player-ORIGINAL.stf': false
2013-10-06 23:30:23,628 DEBUG [AbstractTranscodingDeliveryEngine] Removing transcoding listener with id transcoding-temp-1000000650004707-flv_player-ORIGINAL.stf
2013-10-06 23:30:23,629 WARN  [ServiioStatusService] IOException occured. Returning error code 500 to the REST layer. Message: Transcoded file 'C:\Windows\Temp\Serviio\transcoding-temp-1000000650004707-flv_player-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
2013-10-06 23:30:23,629 DEBUG [ServiioStatusService] Detailed exception:
java.io.IOException: Transcoded file 'C:\Windows\Temp\Serviio\transcoding-temp-1000000650004707-flv_player-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
   at org.serviio.delivery.resource.transcode.FileBasedTranscodingDeliveryStrategy.createInputStream(FileBasedTranscodingDeliveryStrategy.java:47)
   at org.serviio.delivery.resource.transcode.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:134)
   at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:110)
   at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:153)
   at org.serviio.delivery.GETMethodProcessor.retrieveResource(GETMethodProcessor.java:121)
   at org.serviio.delivery.GETMethodProcessor.buildDeliveryContainer(GETMethodProcessor.java:48)
   at org.serviio.delivery.AbstractMethodProcessor.handleRequest(AbstractMethodProcessor.java:132)
   at org.serviio.delivery.ResourceDeliveryProcessor.deliverContent(ResourceDeliveryProcessor.java:81)
   at org.serviio.upnp.service.contentdirectory.rest.resources.server.CDSRetrieveMediaServerResource.deliver(CDSRetrieveMediaServerResource.java:78)
   at sun.reflect.GeneratedMethodAccessor57.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
   at java.lang.reflect.Method.invoke(Unknown Source)
   at org.restlet.resource.ServerResource.doHandle(ServerResource.java:449)
   at org.restlet.resource.ServerResource.get(ServerResource.java:645)
   at org.restlet.resource.ServerResource.doHandle(ServerResource.java:527)
   at org.restlet.resource.ServerResource.doNegotiatedHandle(ServerResource.java:587)
   at org.restlet.resource.ServerResource.doConditionalHandle(ServerResource.java:299)
   at org.serviio.restlet.AbstractServerResource.doConditionalHandle(AbstractServerResource.java:48)
   at org.serviio.restlet.AbstractProEditionServerResource.doConditionalHandle(AbstractProEditionServerResource.java:35)
   at org.serviio.upnp.service.contentdirectory.rest.resources.server.AbstractCDSServerResource.doConditionalHandle(AbstractCDSServerResource.java:57)
   at org.serviio.upnp.service.contentdirectory.rest.resources.server.AbstractRestrictedCDSServerResource.doConditionalHandle(AbstractRestrictedCDSServerResource.java:45)
   at org.restlet.resource.ServerResource.handle(ServerResource.java:846)
   at org.restlet.resource.Finder.handle(Finder.java:510)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.routing.Router.doHandle(Router.java:497)
   at org.restlet.routing.Router.handle(Router.java:737)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.engine.application.StatusFilter.doHandle(StatusFilter.java:151)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.engine.ChainHelper.handle(ChainHelper.java:111)
   at org.restlet.engine.application.ApplicationHelper.handle(ApplicationHelper.java:72)
   at org.restlet.Application.handle(Application.java:391)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.routing.Router.doHandle(Router.java:497)
   at org.restlet.routing.Router.handle(Router.java:737)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.routing.Router.doHandle(Router.java:497)
   at org.restlet.routing.Router.handle(Router.java:737)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.engine.application.StatusFilter.doHandle(StatusFilter.java:151)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.engine.ChainHelper.handle(ChainHelper.java:111)
   at org.restlet.Component.handle(Component.java:388)
   at org.restlet.Server.handle(Server.java:488)
   at org.restlet.engine.http.connector.BaseServerHelper.handle(BaseServerHelper.java:158)
   at org.restlet.engine.http.connector.BaseServerHelper.handleInbound(BaseServerHelper.java:167)
   at org.restlet.engine.http.connector.BaseHelper.handleNextInbound(BaseHelper.java:418)
   at org.restlet.engine.http.connector.Connection.readMessages(Connection.java:696)
   at org.restlet.engine.http.connector.Controller$2.run(Controller.java:95)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
   at java.lang.Thread.run(Unknown Source)
2013-10-06 23:30:24,064 DEBUG [CDSRetrieveMediaServerResource] GET http://localhost:23424/cds/resource/1000000650004707/MEDIA_ITEM/FLV-0/ORIGINAL?profile=flv_player&authToken=23a2d9ff0f2e463690762be3322cff52 HTTP/1.1, headers = [host: localhost:23424,connection: keep-alive,user-agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/30.0.1599.66 Safari/537.36,accept: */*,referer: http://localhost:23424/mediabrowser/,accept-encoding: gzip,deflate,sdch,accept-language: en-US,en;q=0.8]
2013-10-06 23:30:24,064 DEBUG [CDSRetrieveMediaServerResource] Creating client with id '127.0.0.1'
2013-10-06 23:30:24,064 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-06 23:30:24,064 DEBUG [ResourceDeliveryProcessor] Request for resource 1000000650004707 and type 'MEDIA_ITEM' received
2013-10-06 23:30:24,064 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000650004707 (online)
2013-10-06 23:30:24,064 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:30:24,065 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:30:24,066 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1000000650004707, format FLV and profile Flash player
2013-10-06 23:30:24,066 DEBUG [AbstractTranscodingDeliveryEngine] Getting media info for transcoded version of file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1
2013-10-06 23:30:24,066 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:30:24,067 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:30:24,067 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:30:24,067 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000650004707 (online)
2013-10-06 23:30:24,067 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:30:24,068 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:30:24,068 DEBUG [VideoDeliveryEngine] Delivering item '1000000650004707' for client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-06 23:30:24,069 DEBUG [VideoDeliveryEngine] Delivering file 'rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1' using transcoding
2013-10-06 23:30:24,069 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-06 23:30:24,069 DEBUG [VideoDeliveryEngine] Extracting new URL for the expired feed item
2013-10-06 23:30:24,069 DEBUG [FeedItemUrlExtractor] Castalba: Starting extraction of url for item: BBC News
2013-10-06 23:30:24,826 DEBUG [FeedItemUrlExtractor] Castalba: call castalba
2013-10-06 23:30:24,829 DEBUG [FeedItemUrlExtractor] Castalba: Extracted Url for http://www.castalba.tv/channel/9417 - 178734?313338313131373133375f6139396436323664396461323938613131623666346661323961386466616136
2013-10-06 23:30:24,830 DEBUG [FeedItemUrlExtractor] Castalba: Finished extraction of url: ContentURLContainer [fileType=VIDEO, contentUrl=rtmp://50.23.113.228/live app=live tcUrl=rtmp://50.23.113.228/live playpath=178734?313338313131373133375f6139396436323664396461323938613131623666346661323961386466616136 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1, thumbnailUrl=http://castalba.tv/images/zaps/178734.jpg, expiresOn=Mon Oct 07 00:35:00 EDT 2013, expiresImmediately=true, cacheKey=http://www.castalba.tv/channel/9417, live=false, userAgent=Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.1 (KHTML, like Gecko) Chrome/21.0.1180.83 Safari/537.1]
2013-10-06 23:30:24,830 DEBUG [VideoDeliveryEngine] Successfully set new URL for the feed item
2013-10-06 23:30:24,831 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: rtmp://50.23.113.228/live app=live tcUrl=rtmp://50.23.113.228/live playpath=178734?313338313131373133375f6139396436323664396461323938613131623666346661323961386466616136 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000
2013-10-06 23:30:24,831 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\lib\ffdump.bat -analyzeduration 10000000 -fflags +genpts -user-agent Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.1 (KHTML, like Gecko) Chrome/21.0.1180.83 Safari/537.1 -threads 1 -i rtmp://50.23.113.228/live app=live tcUrl=rtmp://50.23.113.228/live playpath=178734?313338313131373133375f6139396436323664396461323938613131623666346661323961386466616136 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000 -y -threads 1 -c:v copy -c:a libmp3lame -b:a 48k -ar 44100 -ac 2 -map 0:0 -map 0:1 -sn -f flv C:\Windows\Temp\Serviio\transcoding-temp-1000000650004707-flv_player-ORIGINAL.stf
2013-10-06 23:30:31,331 DEBUG [FileBasedTranscodingDeliveryStrategy] Sending transcoding stream
2013-10-06 23:30:31,332 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://50.23.113.228/live app=live tcUrl=rtmp://50.23.113.228/live playpath=178734?313338313131373133375f6139396436323664396461323938613131623666346661323961386466616136 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:30:31,332 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://50.23.113.228/live app=live tcUrl=rtmp://50.23.113.228/live playpath=178734?313338313131373133375f6139396436323664396461323938613131623666346661323961386466616136 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:30:31,332 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://50.23.113.228/live app=live tcUrl=rtmp://50.23.113.228/live playpath=178734?313338313131373133375f6139396436323664396461323938613131623666346661323961386466616136 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:30:31,332 DEBUG [GETMethodProcessor] Entity will be consumed till the end
2013-10-06 23:30:31,332 DEBUG [GETMethodProcessor] Stream entity has length: -1
<<

zip

User avatar

Serviio developer / Site Admin

Posts: 16505

Joined: Sat Oct 24, 2009 12:24 pm

Location: London, UK

Post Mon Oct 07, 2013 8:16 am

Re: Serviio ffmpeg fails with valid rtmp streams.

the retry I see in the log it caused by the renderer, right? Once the first fails and returns 500, there is a new incoming GET request.
<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Mon Oct 07, 2013 12:40 pm

Re: Serviio ffmpeg fails with valid rtmp streams.

zip wrote:the retry I see in the log it caused by the renderer, right? Once the first fails and returns 500, there is a new incoming GET request.

I did not know that...so its the Mediabrowser that detects its Get request failed and so it asks again, then gives up after 2 retries and displays a failed to read message in the mb window. Makes sense.

So it almost seems like the Castalba server returns something "unique" for the BBC News stream, the first time it is requested with a particular time stamp key, that causes ffmpeg to return "Invalid data found when processing input. But then subsequent requests with that same key prior to its expiry 2-3 minutes later, do not contain that "unique" and ffmpeg processes the stream correctly. Unfortunately this is not always repeatable and subsequent requests can fail as well. Strange.
<<

zip

User avatar

Serviio developer / Site Admin

Posts: 16505

Joined: Sat Oct 24, 2009 12:24 pm

Location: London, UK

Post Mon Oct 07, 2013 12:54 pm

Re: Serviio ffmpeg fails with valid rtmp streams.

Possibly. Might be something strange with the stream or librtmp bug.

In any way, doesn't seem to be a problem with Serviio, could you close the issue?
<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Mon Oct 07, 2013 1:18 pm

[Closed] Serviio ffmpeg fails with valid rtmp streams.

Done
<<

jhb50

DLNA master

Posts: 2854

Joined: Thu Jun 30, 2011 9:32 pm

Post Mon Oct 07, 2013 9:35 pm

Re: Serviio ffmpeg fails with valid rtmp streams.

On further review, I have determined that the ability of the renderer to retry playback after an ffmpeg error as documented above was dependent on the stream being declared live=false.

I have raised ticket #719 to also enable retrys on live=true streams. Details follow:

Enable Retrys with Live=true LiveStreams
====================================
Reference - Previously Closed Ticket 717
Situation - Playing an ExpiresImmediately Live Stream that requires transcoding but fails in ffmpeg

When the Content container is set to live=true so the transcode is piped, no error is sent back to the renderer on an ffmpeg failure, so the mediabrowser is unable to take further action, either by displaying an error message or retrying the GET, and so just hangs on a black screen.

If the Content container is set to live=false so the transcode is to a file, when ffmpeg fails to generate the file a 500 error is sent to the renderer and so the mediabrowser is able to attempt a retry and issue an error message if unsuccessful.

The request is to also generate an error back to the renderer on LIVE=TRUE streams to yield retrys and error messages.

See following logs.

LIVE=TRUE - NO ERROR MESSAGE - NO RETRY

  Code:
2013-10-07 16:55:52,754 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 209)
2013-10-07 16:55:53,554 DEBUG [CDSRetrieveMediaServerResource] GET http://localhost:23424/cds/resource/1000002090004101/MEDIA_ITEM/FLV-0/ORIGINAL?profile=flv_player&authToken=ed0e31cb0df047509318f7e540d784ae HTTP/1.1, headers = [host: localhost:23424,connection: keep-alive,user-agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/30.0.1599.69 Safari/537.36,accept: */*,referer: http://localhost:23424/mediabrowser/,accept-encoding: gzip,deflate,sdch,accept-language: en-US,en;q=0.8]
2013-10-07 16:55:53,554 DEBUG [CDSRetrieveMediaServerResource] Creating client with id '127.0.0.1'
2013-10-07 16:55:53,555 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-07 16:55:53,555 DEBUG [ResourceDeliveryProcessor] Request for resource 1000002090004101 and type 'MEDIA_ITEM' received
2013-10-07 16:55:53,555 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000002090004101 (online)
2013-10-07 16:55:53,555 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 209)
2013-10-07 16:55:53,555 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 209)
2013-10-07 16:55:53,556 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1000002090004101, format FLV and profile Flash player
2013-10-07 16:55:53,556 DEBUG [AbstractTranscodingDeliveryEngine] Getting media info for transcoded version of file rtmp://173.192.70.168/live app=live tcUrl=rtmp://173.192.70.168/live playpath=178734?313338313132323031345f3763633435623330336362326630333165643838643561396132303365653465 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1
2013-10-07 16:55:53,556 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.192.70.168/live app=live tcUrl=rtmp://173.192.70.168/live playpath=178734?313338313132323031345f3763633435623330336362326630333165643838643561396132303365653465 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-07 16:55:53,556 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.192.70.168/live app=live tcUrl=rtmp://173.192.70.168/live playpath=178734?313338313132323031345f3763633435623330336362326630333165643838643561396132303365653465 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-07 16:55:53,556 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.192.70.168/live app=live tcUrl=rtmp://173.192.70.168/live playpath=178734?313338313132323031345f3763633435623330336362326630333165643838643561396132303365653465 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-07 16:55:53,556 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000002090004101 (online)
2013-10-07 16:55:53,556 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 209)
2013-10-07 16:55:53,556 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 209)
2013-10-07 16:55:53,557 DEBUG [VideoDeliveryEngine] Delivering item '1000002090004101' for client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-07 16:55:53,557 DEBUG [VideoDeliveryEngine] Delivering file 'rtmp://173.192.70.168/live app=live tcUrl=rtmp://173.192.70.168/live playpath=178734?313338313132323031345f3763633435623330336362326630333165643838643561396132303365653465 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1' using transcoding
2013-10-07 16:55:53,557 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-07 16:55:53,557 DEBUG [VideoDeliveryEngine] Extracting new URL for the expired feed item
2013-10-07 16:55:53,557 DEBUG [FeedItemUrlExtractor] Castalba: Starting extraction of url for item: BBC News
2013-10-07 16:55:54,042 DEBUG [FeedItemUrlExtractor] Castalba: call castalba
2013-10-07 16:55:54,045 DEBUG [FeedItemUrlExtractor] Castalba: Extracted Url for http://www.castalba.tv/channel/9417 - 178734?313338313137393838305f3830346664343437393034333836646238613732363432346338396662623236
2013-10-07 16:55:54,046 DEBUG [FeedItemUrlExtractor] Castalba: Finished extraction of url: ContentURLContainer [fileType=VIDEO, contentUrl=rtmp://173.192.70.169/live app=live tcUrl=rtmp://173.192.70.169/live playpath=178734?313338313137393838305f3830346664343437393034333836646238613732363432346338396662623236 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1, thumbnailUrl=http://castalba.tv/images/zaps/178734.jpg, expiresImmediately=true, cacheKey=http://www.castalba.tv/channel/9417, live=true, userAgent=Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.1 (KHTML, like Gecko) Chrome/21.0.1180.83 Safari/537.1]
2013-10-07 16:55:54,046 DEBUG [VideoDeliveryEngine] Successfully set new URL for the feed item
2013-10-07 16:55:54,046 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: rtmp://173.192.70.169/live app=live tcUrl=rtmp://173.192.70.169/live playpath=178734?313338313137393838305f3830346664343437393034333836646238613732363432346338396662623236 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1
2013-10-07 16:55:54,047 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\lib\ffdump.bat -analyzeduration 10000000 -fflags +genpts -user-agent Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.1 (KHTML, like Gecko) Chrome/21.0.1180.83 Safari/537.1 -threads 1 -i rtmp://173.192.70.169/live app=live tcUrl=rtmp://173.192.70.169/live playpath=178734?313338313137393838305f3830346664343437393034333836646238613732363432346338396662623236 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 -y -threads 1 -c:v copy -c:a libmp3lame -b:a 48k -ar 44100 -ac 2 -map 0:0 -map 0:1 -sn -f flv pipe:
2013-10-07 16:56:07,345 WARN  [ProcessExecutor] Process cmd has a return code of 1! This is a possible error. Detailed output follows.
libswscale      2.  5.100 /  2.  5.100
libswresample   0. 17.103 /  0. 17.103
libpostproc    52.  3.100 / 52.  3.100
INFO: Connected...
pipe:: Invalid data found when processing input
2013-10-07 16:56:07,345 DEBUG [TranscodingJobListener] Transcoding finished; successful: false
2013-10-07 16:56:20,549 DEBUG [StreamBasedTranscodingDeliveryStrategy] Transcoded stream is empty, connection may have been lost
2013-10-07 16:56:20,549 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.192.70.169/live app=live tcUrl=rtmp://173.192.70.169/live playpath=178734?313338313137393838305f3830346664343437393034333836646238613732363432346338396662623236 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-07 16:56:20,549 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.192.70.169/live app=live tcUrl=rtmp://173.192.70.169/live playpath=178734?313338313137393838305f3830346664343437393034333836646238613732363432346338396662623236 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-07 16:56:20,549 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.192.70.169/live app=live tcUrl=rtmp://173.192.70.169/live playpath=178734?313338313137393838305f3830346664343437393034333836646238613732363432346338396662623236 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-07 16:56:20,549 DEBUG [GETMethodProcessor] Entity will be consumed till the end
2013-10-07 16:56:20,549 DEBUG [GETMethodProcessor] Stream entity has length: -1[/code

LIVE = FALSE  500 Error and renderer successful retry.

[code]2013-10-06 23:29:57,175 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:29:57,855 DEBUG [CDSRetrieveMediaServerResource] GET http://localhost:23424/cds/resource/1000000650004707/MEDIA_ITEM/FLV-0/ORIGINAL?profile=flv_player&authToken=23a2d9ff0f2e463690762be3322cff52 HTTP/1.1, headers = [host: localhost:23424,connection: keep-alive,user-agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/30.0.1599.66 Safari/537.36,accept: */*,referer: http://localhost:23424/mediabrowser/,accept-encoding: gzip,deflate,sdch,accept-language: en-US,en;q=0.8]
2013-10-06 23:29:57,855 DEBUG [CDSRetrieveMediaServerResource] Creating client with id '127.0.0.1'
2013-10-06 23:29:57,855 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-06 23:29:57,855 DEBUG [ResourceDeliveryProcessor] Request for resource 1000000650004707 and type 'MEDIA_ITEM' received
2013-10-06 23:29:57,855 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000650004707 (online)
2013-10-06 23:29:57,855 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:29:57,856 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:29:57,856 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1000000650004707, format FLV and profile Flash player
2013-10-06 23:29:57,856 DEBUG [AbstractTranscodingDeliveryEngine] Getting media info for transcoded version of file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1
2013-10-06 23:29:57,856 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:29:57,856 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:29:57,857 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:29:57,857 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000650004707 (online)
2013-10-06 23:29:57,857 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:29:57,857 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:29:57,858 DEBUG [VideoDeliveryEngine] Delivering item '1000000650004707' for client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-06 23:29:57,858 DEBUG [VideoDeliveryEngine] Delivering file 'rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1' using transcoding
2013-10-06 23:29:57,873 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-06 23:29:57,873 DEBUG [VideoDeliveryEngine] Extracting new URL for the expired feed item
2013-10-06 23:29:57,873 DEBUG [FeedItemUrlExtractor] Castalba: Starting extraction of url for item: BBC News
2013-10-06 23:29:58,622 DEBUG [FeedItemUrlExtractor] Castalba: call castalba
2013-10-06 23:29:58,625 DEBUG [FeedItemUrlExtractor] Castalba: Extracted Url for http://www.castalba.tv/channel/9417 - 178734?313338313131373131315f6433656661303966643664303065313862356139376633326266653062326636
2013-10-06 23:29:58,625 DEBUG [FeedItemUrlExtractor] Castalba: Finished extraction of url: ContentURLContainer [fileType=VIDEO, contentUrl=rtmp://37.58.66.163/live app=live tcUrl=rtmp://37.58.66.163/live playpath=178734?313338313131373131315f6433656661303966643664303065313862356139376633326266653062326636 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1, thumbnailUrl=http://castalba.tv/images/zaps/178734.jpg, expiresOn=Mon Oct 07 00:34:00 EDT 2013, expiresImmediately=true, cacheKey=http://www.castalba.tv/channel/9417, live=false, userAgent=Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.1 (KHTML, like Gecko) Chrome/21.0.1180.83 Safari/537.1]
2013-10-06 23:29:58,625 DEBUG [VideoDeliveryEngine] Successfully set new URL for the feed item
2013-10-06 23:29:58,626 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: rtmp://37.58.66.163/live app=live tcUrl=rtmp://37.58.66.163/live playpath=178734?313338313131373131315f6433656661303966643664303065313862356139376633326266653062326636 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000
2013-10-06 23:29:58,626 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\lib\ffdump.bat -analyzeduration 10000000 -fflags +genpts -user-agent Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.1 (KHTML, like Gecko) Chrome/21.0.1180.83 Safari/537.1 -threads 1 -i rtmp://37.58.66.163/live app=live tcUrl=rtmp://37.58.66.163/live playpath=178734?313338313131373131315f6433656661303966643664303065313862356139376633326266653062326636 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000 -y -threads 1 -c:v copy -c:a libmp3lame -b:a 48k -ar 44100 -ac 2 -map 0:0 -map 0:1 -sn -f flv C:\Windows\Temp\Serviio\transcoding-temp-1000000650004707-flv_player-ORIGINAL.stf
2013-10-06 23:30:12,665 WARN  [ProcessExecutor] Process cmd has a return code of 1! This is a possible error. Detailed output follows.
libswscale      2.  5.100 /  2.  5.100
libswresample   0. 17.103 /  0. 17.103
libpostproc    52.  3.100 / 52.  3.100
INFO: Connected...
pipe:: Invalid data found when processing input
2013-10-06 23:30:12,665 DEBUG [TranscodingJobListener] Transcoding finished; successful: false
2013-10-06 23:30:23,628 DEBUG [TranscodingJobListener] Deleted temp file 'C:\Windows\Temp\Serviio\transcoding-temp-1000000650004707-flv_player-ORIGINAL.stf': false
2013-10-06 23:30:23,628 DEBUG [AbstractTranscodingDeliveryEngine] Removing transcoding listener with id transcoding-temp-1000000650004707-flv_player-ORIGINAL.stf
2013-10-06 23:30:23,629 WARN  [ServiioStatusService] IOException occured. Returning error code 500 to the REST layer. Message: Transcoded file 'C:\Windows\Temp\Serviio\transcoding-temp-1000000650004707-flv_player-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
2013-10-06 23:30:23,629 DEBUG [ServiioStatusService] Detailed exception:
java.io.IOException: Transcoded file 'C:\Windows\Temp\Serviio\transcoding-temp-1000000650004707-flv_player-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
   at org.serviio.delivery.resource.transcode.FileBasedTranscodingDeliveryStrategy.createInputStream(FileBasedTranscodingDeliveryStrategy.java:47)
   at org.serviio.delivery.resource.transcode.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:134)
   at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:110)
   at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:153)
   at org.serviio.delivery.GETMethodProcessor.retrieveResource(GETMethodProcessor.java:121)
   at org.serviio.delivery.GETMethodProcessor.buildDeliveryContainer(GETMethodProcessor.java:48)
   at org.serviio.delivery.AbstractMethodProcessor.handleRequest(AbstractMethodProcessor.java:132)
   at org.serviio.delivery.ResourceDeliveryProcessor.deliverContent(ResourceDeliveryProcessor.java:81)
   at org.serviio.upnp.service.contentdirectory.rest.resources.server.CDSRetrieveMediaServerResource.deliver(CDSRetrieveMediaServerResource.java:78)
   at sun.reflect.GeneratedMethodAccessor57.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
   at java.lang.reflect.Method.invoke(Unknown Source)
   at org.restlet.resource.ServerResource.doHandle(ServerResource.java:449)
   at org.restlet.resource.ServerResource.get(ServerResource.java:645)
   at org.restlet.resource.ServerResource.doHandle(ServerResource.java:527)
   at org.restlet.resource.ServerResource.doNegotiatedHandle(ServerResource.java:587)
   at org.restlet.resource.ServerResource.doConditionalHandle(ServerResource.java:299)
   at org.serviio.restlet.AbstractServerResource.doConditionalHandle(AbstractServerResource.java:48)
   at org.serviio.restlet.AbstractProEditionServerResource.doConditionalHandle(AbstractProEditionServerResource.java:35)
   at org.serviio.upnp.service.contentdirectory.rest.resources.server.AbstractCDSServerResource.doConditionalHandle(AbstractCDSServerResource.java:57)
   at org.serviio.upnp.service.contentdirectory.rest.resources.server.AbstractRestrictedCDSServerResource.doConditionalHandle(AbstractRestrictedCDSServerResource.java:45)
   at org.restlet.resource.ServerResource.handle(ServerResource.java:846)
   at org.restlet.resource.Finder.handle(Finder.java:510)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.routing.Router.doHandle(Router.java:497)
   at org.restlet.routing.Router.handle(Router.java:737)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.engine.application.StatusFilter.doHandle(StatusFilter.java:151)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.engine.ChainHelper.handle(ChainHelper.java:111)
   at org.restlet.engine.application.ApplicationHelper.handle(ApplicationHelper.java:72)
   at org.restlet.Application.handle(Application.java:391)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.routing.Router.doHandle(Router.java:497)
   at org.restlet.routing.Router.handle(Router.java:737)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.routing.Router.doHandle(Router.java:497)
   at org.restlet.routing.Router.handle(Router.java:737)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.engine.application.StatusFilter.doHandle(StatusFilter.java:151)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.routing.Filter.doHandle(Filter.java:156)
   at org.restlet.routing.Filter.handle(Filter.java:203)
   at org.restlet.engine.ChainHelper.handle(ChainHelper.java:111)
   at org.restlet.Component.handle(Component.java:388)
   at org.restlet.Server.handle(Server.java:488)
   at org.restlet.engine.http.connector.BaseServerHelper.handle(BaseServerHelper.java:158)
   at org.restlet.engine.http.connector.BaseServerHelper.handleInbound(BaseServerHelper.java:167)
   at org.restlet.engine.http.connector.BaseHelper.handleNextInbound(BaseHelper.java:418)
   at org.restlet.engine.http.connector.Connection.readMessages(Connection.java:696)
   at org.restlet.engine.http.connector.Controller$2.run(Controller.java:95)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
   at java.lang.Thread.run(Unknown Source)
2013-10-06 23:30:24,064 DEBUG [CDSRetrieveMediaServerResource] GET http://localhost:23424/cds/resource/1000000650004707/MEDIA_ITEM/FLV-0/ORIGINAL?profile=flv_player&authToken=23a2d9ff0f2e463690762be3322cff52 HTTP/1.1, headers = [host: localhost:23424,connection: keep-alive,user-agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/30.0.1599.66 Safari/537.36,accept: */*,referer: http://localhost:23424/mediabrowser/,accept-encoding: gzip,deflate,sdch,accept-language: en-US,en;q=0.8]
2013-10-06 23:30:24,064 DEBUG [CDSRetrieveMediaServerResource] Creating client with id '127.0.0.1'
2013-10-06 23:30:24,064 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-06 23:30:24,064 DEBUG [ResourceDeliveryProcessor] Request for resource 1000000650004707 and type 'MEDIA_ITEM' received
2013-10-06 23:30:24,064 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000650004707 (online)
2013-10-06 23:30:24,064 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:30:24,065 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:30:24,066 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1000000650004707, format FLV and profile Flash player
2013-10-06 23:30:24,066 DEBUG [AbstractTranscodingDeliveryEngine] Getting media info for transcoded version of file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1
2013-10-06 23:30:24,066 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:30:24,067 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:30:24,067 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:30:24,067 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000650004707 (online)
2013-10-06 23:30:24,067 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:30:24,068 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 65)
2013-10-06 23:30:24,068 DEBUG [VideoDeliveryEngine] Delivering item '1000000650004707' for client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-06 23:30:24,069 DEBUG [VideoDeliveryEngine] Delivering file 'rtmp://173.193.32.188/live app=live tcUrl=rtmp://173.193.32.188/live playpath=178734?313338313131373030365f3734383736303438363832623232383531393635633162383730363364656333 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1' using transcoding
2013-10-06 23:30:24,069 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'Identifier=127.0.0.1, Profile=Flash player'
2013-10-06 23:30:24,069 DEBUG [VideoDeliveryEngine] Extracting new URL for the expired feed item
2013-10-06 23:30:24,069 DEBUG [FeedItemUrlExtractor] Castalba: Starting extraction of url for item: BBC News
2013-10-06 23:30:24,826 DEBUG [FeedItemUrlExtractor] Castalba: call castalba
2013-10-06 23:30:24,829 DEBUG [FeedItemUrlExtractor] Castalba: Extracted Url for http://www.castalba.tv/channel/9417 - 178734?313338313131373133375f6139396436323664396461323938613131623666346661323961386466616136
2013-10-06 23:30:24,830 DEBUG [FeedItemUrlExtractor] Castalba: Finished extraction of url: ContentURLContainer [fileType=VIDEO, contentUrl=rtmp://50.23.113.228/live app=live tcUrl=rtmp://50.23.113.228/live playpath=178734?313338313131373133375f6139396436323664396461323938613131623666346661323961386466616136 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1, thumbnailUrl=http://castalba.tv/images/zaps/178734.jpg, expiresOn=Mon Oct 07 00:35:00 EDT 2013, expiresImmediately=true, cacheKey=http://www.castalba.tv/channel/9417, live=false, userAgent=Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.1 (KHTML, like Gecko) Chrome/21.0.1180.83 Safari/537.1]
2013-10-06 23:30:24,830 DEBUG [VideoDeliveryEngine] Successfully set new URL for the feed item
2013-10-06 23:30:24,831 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: rtmp://50.23.113.228/live app=live tcUrl=rtmp://50.23.113.228/live playpath=178734?313338313131373133375f6139396436323664396461323938613131623666346661323961386466616136 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000
2013-10-06 23:30:24,831 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\lib\ffdump.bat -analyzeduration 10000000 -fflags +genpts -user-agent Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.1 (KHTML, like Gecko) Chrome/21.0.1180.83 Safari/537.1 -threads 1 -i rtmp://50.23.113.228/live app=live tcUrl=rtmp://50.23.113.228/live playpath=178734?313338313131373133375f6139396436323664396461323938613131623666346661323961386466616136 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1 buffer=100000000 -y -threads 1 -c:v copy -c:a libmp3lame -b:a 48k -ar 44100 -ac 2 -map 0:0 -map 0:1 -sn -f flv C:\Windows\Temp\Serviio\transcoding-temp-1000000650004707-flv_player-ORIGINAL.stf
2013-10-06 23:30:31,331 DEBUG [FileBasedTranscodingDeliveryStrategy] Sending transcoding stream
2013-10-06 23:30:31,332 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://50.23.113.228/live app=live tcUrl=rtmp://50.23.113.228/live playpath=178734?313338313131373133375f6139396436323664396461323938613131623666346661323961386466616136 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:30:31,332 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://50.23.113.228/live app=live tcUrl=rtmp://50.23.113.228/live playpath=178734?313338313131373133375f6139396436323664396461323938613131623666346661323961386466616136 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:30:31,332 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://50.23.113.228/live app=live tcUrl=rtmp://50.23.113.228/live playpath=178734?313338313131373133375f6139396436323664396461323938613131623666346661323961386466616136 pageUrl=http://castalba.tv/channel/9417 swfUrl=http://static.castalba.tv/player5.9.swf live=1: FLV
2013-10-06 23:30:31,332 DEBUG [GETMethodProcessor] Entity will be consumed till the end
2013-10-06 23:30:31,332 DEBUG [GETMethodProcessor] Stream entity has length: -1

Return to Plugin development

Who is online

Users browsing this forum: No registered users and 2 guests

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