Serviio

DLNA media server
https://www.serviio.org/forum/

Strange issue with PBSKids plugin

https://www.serviio.org/forum/viewtopic.php?f=22&t=7107

Page 1 of 1

Strange issue with PBSKids plugin

PostPosted: Fri Aug 17, 2012 11:17 pm
by xs2inattar
So, i wrote the plugin for PBSKids: viewtopic.php?f=20&t=7106

It seems to be workign fine. But for some clips the video would just end abruptly and i cant figure out why.

Below is log.

  Code:
2012-08-17 18:24:25,241 DEBUG [VideoDeliveryEngine] Delivering item '1000000001440001' for client 'IPAddress=/192.168.1.3, Profile=Generic DLNA profile'
2012-08-17 18:24:25,241 DEBUG [VideoDeliveryEngine] Delivering file 'rtmp://s3h56pp78s3goi.cloudfront.net/cfx/st/ playpath=mp4:PBS_CP_Curious_George/CUGE314_EpisodeB_web4x3.mp4?player=PreKplayer&mediaID=2223987701' using transcoding
2012-08-17 18:24:25,241 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.1.3, Profile=Generic DLNA profile'
2012-08-17 18:24:25,242 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: rtmp://s3h56pp78s3goi.cloudfront.net/cfx/st/ playpath=mp4:PBS_CP_Curious_George/CUGE314_EpisodeB_web4x3.mp4?player=PreKplayer&mediaID=2223987701
2012-08-17 18:24:25,242 DEBUG [ProcessExecutor] Starting /volume1/@appstore/Serviio/bin/ffmpeg -fflags +genpts -i rtmp://s3h56pp78s3goi.cloudfront.net/cfx/st/ playpath=mp4:PBS_CP_Curious_George/CUGE314_EpisodeB_web4x3.mp4?player=PreKplayer&mediaID=2223987701 -y -copyts -c:v copy -vbsf h264_mp4toannexb -c:a ac3_fixed -b:a 384k -ac 2 -map 0:0 -map 0:1 -sn -f mpegts pipe:
2012-08-17 18:24:25,586 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface eth0 (eth0) and address 192.168.1.11, timeout = 0
2012-08-17 18:24:25,587 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 61cd396e-1894-3da9-91a2-e8090bcf4e54
2012-08-17 18:24:26,255 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://s3h56pp78s3goi.cloudfront.net/cfx/st/ playpath=mp4:PBS_CP_Curious_George/CUGE314_EpisodeB_web4x3.mp4?player=PreKplayer&mediaID=2223987701: AVC_TS_MP_SD_AC3_ISO
2012-08-17 18:24:26,256 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 50000000000
2012-08-17 18:24:26,256 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-08-17 18:24:26,256 DEBUG [ResourceTransportRequestHandler] Creating entity with chunked transfer
2012-08-17 18:24:26,256 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: video/mpeg,Date: Fri, 17 Aug 2012 22:24:26 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Streaming]]
2012-08-17 18:24:27,565 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:45
2012-08-17 18:24:54,998 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.3:2741
2012-08-17 18:24:54,998 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.3
2012-08-17 18:24:55,000 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.3:2741
2012-08-17 18:24:55,000 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.3:2741
2012-08-17 18:24:55,001 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.3
2012-08-17 18:24:55,002 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.3:2741
2012-08-17 18:25:11,387 DEBUG [WebServer] I/O error: Connection reset
2012-08-17 18:25:13,006 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface eth0 (eth0) and address 192.168.1.11, timeout = 0
2012-08-17 18:25:13,007 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 61cd396e-1894-3da9-91a2-e8090bcf4e54
2012-08-17 18:25:14,985 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:46
2012-08-17 18:25:16,615 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-17 18:25:16,615 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-17 18:25:16,619 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 143)
2012-08-17 18:25:16,620 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 144)
2012-08-17 18:25:16,642 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 145)
2012-08-17 18:25:42,668 DEBUG [WebServer] Incoming connection from /192.168.1.3:29047
2012-08-17 18:25:42,668 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.3
2012-08-17 18:25:42,670 DEBUG [ResourceTransportRequestHandler] GET /resource/1000000001440001/MEDIA_ITEM/AVC_TS_MP_SD_AC3_ISO-0/ORIGINAL HTTP/1.1, headers = [Range: bytes=12285380-,User-Agent: XBMC/11.0 Git:20120321-14feb09 (Windows NT 6.1; http://www.xbmc.org),Host: 192.168.1.11:8895,Accept: */*,Connection: keep-alive]]
2012-08-17 18:25:42,670 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.3
2012-08-17 18:25:42,671 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.3, Profile=Generic DLNA profile'
2012-08-17 18:25:42,672 DEBUG [ResourceDeliveryProcessor] Request for resource 1000000001440001 and type 'MEDIA_ITEM' received
2012-08-17 18:25:42,672 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000001440001 (online)
2012-08-17 18:25:42,672 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 144)
2012-08-17 18:25:42,673 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 144)
2012-08-17 18:25:42,675 DEBUG [VideoDeliveryEngine] Delivering item '1000000001440001' for client 'IPAddress=/192.168.1.3, Profile=Generic DLNA profile'
2012-08-17 18:25:42,675 DEBUG [VideoDeliveryEngine] Delivering file 'rtmp://s3h56pp78s3goi.cloudfront.net/cfx/st/ playpath=mp4:PBS_CP_Curious_George/CUGE314_EpisodeB_web4x3.mp4?player=PreKplayer&mediaID=2223987701' using transcoding
2012-08-17 18:25:42,676 DEBUG [AbstractTranscodingDeliveryEngine] A suitable transcoding job already exists, re-use it for client 'IPAddress=/192.168.1.3, Profile=Generic DLNA profile'
2012-08-17 18:25:43,685 DEBUG [StreamBasedTranscodingDeliveryStrategy] Transcoded stream is empty, connection may have been lost
2012-08-17 18:25:43,685 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://s3h56pp78s3goi.cloudfront.net/cfx/st/ playpath=mp4:PBS_CP_Curious_George/CUGE314_EpisodeB_web4x3.mp4?player=PreKplayer&mediaID=2223987701: AVC_TS_MP_SD_AC3_ISO
2012-08-17 18:25:43,686 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 50000000000
2012-08-17 18:25:43,686 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-08-17 18:25:43,686 DEBUG [ResourceTransportRequestHandler] Creating entity with chunked transfer
2012-08-17 18:25:43,686 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: video/mpeg,Date: Fri, 17 Aug 2012 22:25:43 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Streaming]]
2012-08-17 18:25:43,972 DEBUG [WebServer] I/O error: Broken pipe
2012-08-17 18:25:43,972 DEBUG [NonClosingPipedInputStream] Scheduling stream stop to happen in 20 seconds if there is no traffic
2012-08-17 18:25:44,079 DEBUG [WebServer] I/O error: Broken pipe
2012-08-17 18:25:44,079 DEBUG [NonClosingPipedInputStream] Scheduling stream stop to happen in 20 seconds if there is no traffic
2012-08-17 18:25:49,589 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.3:2741
2012-08-17 18:25:49,589 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.3
2012-08-17 18:25:49,591 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.3:2741
2012-08-17 18:25:49,592 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.3:2741
2012-08-17 18:25:49,592 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.3
2012-08-17 18:25:49,594 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.3:2741
2012-08-17 18:26:01,416 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface eth0 (eth0) and address 192.168.1.11, timeout = 0
2012-08-17 18:26:01,416 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 61cd396e-1894-3da9-91a2-e8090bcf4e54
2012-08-17 18:26:03,395 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:52
2012-08-17 18:26:04,085 DEBUG [NonClosingPipedInputStream] Closing piped input stream and closing related feeder process
2012-08-17 18:26:04,085 DEBUG [ProcessExecutor] Stopping external process: Thread[Thread-1012,5,main]
2012-08-17 18:26:04,085 DEBUG [ProcessUtils] Sending kill -9 to the Unix process: 19421
2012-08-17 18:26:04,086 DEBUG [ProcessExecutor] Starting kill -9 19421
2012-08-17 18:26:04,094 WARN  [ProcessExecutor] Process /volume1/@appstore/Serviio/bin/ffmpeg has a return code of 137! This is a possible error.
2012-08-17 18:26:04,094 DEBUG [TranscodingJobListener] Transcoding finished; successful: false
2012-08-17 18:26:04,095 DEBUG [TranscodingJobListener] Transcoding finished; successful: true
2012-08-17 18:26:16,615 DEBUG [WebServer] Incoming connection from /192.168.1.3:29067
2012-08-17 18:26:16,616 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.3
2012-08-17 18:26:16,617 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.3:
2012-08-17 18:26:16,617 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.3
2012-08-17 18:26:16,654 DEBUG [ContentDirectory] Browse() called for renderer Windows Media Player (profile 1) with parameters: objectID = V_OF^FOL_FD144, browseFlag = BrowseDirectChildren, filter = *, startIndex = 0, count = 30, sortCriteria =
2012-08-17 18:26:16,654 DEBUG [AccessGroupDAOImpl] Reading a AccessGroup (id = 1)
2012-08-17 18:26:16,676 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 144)
2012-08-17 18:26:16,678 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1000000001440001 and profile Generic DLNA profile
2012-08-17 18:26:16,678 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://s3h56pp78s3goi.cloudfront.net/cfx/st/ playpath=mp4:PBS_CP_Curious_George/CUGE314_EpisodeB_web4x3.mp4?player=PreKplayer&mediaID=2223987701: AVC_TS_MP_SD_AC3_ISO
2012-08-17 18:26:16,680 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1000000001440002 and profile Generic DLNA profile
2012-08-17 18:26:16,680 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file rtmp://s3h56pp78s3goi.cloudfront.net/cfx/st/ playpath=mp4:PBS_CP_Curious_George/CUGE608_3_web16x9.mp4?player=PreKplayer&mediaID=2249082559: AVC_TS_MP_SD_AC3_ISO
2012-08-17 18:26:16,761 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 144)
2012-08-17 18:26:17,083 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-08-17 18:26:17,635 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-17 18:26:17,635 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-17 18:26:17,649 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 143)
2012-08-17 18:26:17,650 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 144)
2012-08-17 18:26:17,683 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 145)
2012-08-17 18:26:44,407 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.3:2741
2012-08-17 18:26:44,408 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.3
2012-08-17 18:26:44,409 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.3:2741
2012-08-17 18:26:44,410 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.3:2741
2012-08-17 18:26:44,410 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.3
2012-08-17 18:26:44,412 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.3:2741
2012-08-17 18:26:55,936 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface eth0 (eth0) and address 192.168.1.11, timeout = 0
2012-08-17 18:26:55,937 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 61cd396e-1894-3da9-91a2-e8090bcf4e54
2012-08-17 18:26:57,915 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:43





This abrupt end of the video happens at exactly the same time. for e.g. for one video it always occured between 1:48 to 1:51 in the video.

In my opinion the problem seems to be the following line from the above log.

  Code:
...
2012-08-17 18:25:43,972 DEBUG [NonClosingPipedInputStream] Scheduling stream stop to happen in 20 seconds if there is no traffic
2012-08-17 18:25:44,079 DEBUG [WebServer] I/O error: Broken pipe
2012-08-17 18:25:44,079 DEBUG [NonClosingPipedInputStream] Scheduling stream stop to happen in 20 seconds if there is no traffic
...
2012-08-17 18:26:04,085 DEBUG [NonClosingPipedInputStream] Closing piped input stream and closing related feeder process
2012-08-17 18:26:04,085 DEBUG [ProcessExecutor] Stopping external process: Thread[Thread-1012,5,main]
2012-08-17 18:26:04,085 DEBUG [ProcessUtils] Sending kill -9 to the Unix process: 19421
2012-08-17 18:26:04,086 DEBUG [ProcessExecutor] Starting kill -9 19421
2012-08-17 18:26:04,094 WARN  [ProcessExecutor] Process /volume1/@appstore/Serviio/bin/ffmpeg has a return code of 137! This is a possible error.
2012-08-17 18:26:04,094 DEBUG [TranscodingJobListener] Transcoding finished; successful: false
2012-08-17 18:26:04,095 DEBUG [TranscodingJobListener] Transcoding finished; successful: true
...



No idea why it keeps killing the ffmpeg process when the video is still running.

Re: Strange issue with PBSKids plugin

PostPosted: Sat Aug 18, 2012 10:08 am
by zip
is that a live stream? Looks like it, it checks if there is no read for 20 seconds it kills the live stream.

Re: Strange issue with PBSKids plugin

PostPosted: Sat Aug 18, 2012 2:54 pm
by xs2inattar
These are short online clips ranging from 2 - 12 mins.

So based on your comment since this is not a livestream and just a short clip, i removed live=true from the content item. But after doing that the stream does not even start.

Logs and ffmpeg results are as follows.

CLIP-1
Log:
  Code:
2012-08-18 09:54:43,462 DEBUG [VideoDeliveryEngine] Delivering item '1000000001440001' for client 'IPAddress=/192.168.1.3, Profile=Generic DLNA profile'
2012-08-18 09:54:43,462 DEBUG [VideoDeliveryEngine] Delivering file 'rtmp://s3h56pp78s3goi.cloudfront.net/cfx/st/ playpath=mp4:PBS_CP_Curious_George/CUGE314_EpisodeB_web4x3.mp4?player=PreKplayer&mediaID=2223987701' using transcoding
2012-08-18 09:54:43,463 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.1.3, Profile=Generic DLNA profile'
2012-08-18 09:54:43,463 DEBUG [VideoDeliveryEngine] Extracting new URL for the expired feed item
2012-08-18 09:54:43,463 DEBUG [FeedItemUrlExtractor] pbskids.org: Starting extraction of url for item: Something New Under the Sun
2012-08-18 09:54:43,654 DEBUG [FeedItemUrlExtractor] pbskids.org: Finished extraction of url: ContentURLContainer [fileType=VIDEO, contentUrl=rtmp://s3h56pp78s3goi.cloudfront.net/cfx/st/ playpath=mp4:PBS_CP_Curious_George/CUGE314_EpisodeB_web4x3.mp4?player=PreKplayer&mediaID=2223987701, thumbnailUrl=http://www-tc.pbs.org/cove-media/http/PBS_CP_Curious_George/73/983/CUGE314_EpisodeB_web4x3_69x53_2223993445.jpg, expiresImmediately=true, cacheKey=PBSKids_XlFVm6a07q1rJBjRiL6UImmRuYr2v2Ny, live=false, ]
2012-08-18 09:54:43,654 DEBUG [VideoDeliveryEngine] Successfully set new URL for the feed item
2012-08-18 09:54:43,655 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: rtmp://s3h56pp78s3goi.cloudfront.net/cfx/st/ playpath=mp4:PBS_CP_Curious_George/CUGE314_EpisodeB_web4x3.mp4?player=PreKplayer&mediaID=2223987701 buffer=100000000
2012-08-18 09:54:43,656 DEBUG [ProcessExecutor] Starting /volume1/@appstore/Serviio/bin/ffmpeg -fflags +genpts -i rtmp://s3h56pp78s3goi.cloudfront.net/cfx/st/ playpath=mp4:PBS_CP_Curious_George/CUGE314_EpisodeB_web4x3.mp4?player=PreKplayer&mediaID=2223987701 buffer=100000000 -y -copyts -c:v copy -vbsf h264_mp4toannexb -c:a ac3_fixed -b:a 384k -ac 2 -map 0:0 -map 0:1 -sn -f mpegts /.tmp/Serviio/transcoding-temp-1000000001440001-1-ORIGINAL.stf
2012-08-18 09:54:45,027 WARN  [ProcessExecutor] Process /volume1/@appstore/Serviio/bin/ffmpeg has a return code of 1! This is a possible error.
2012-08-18 09:54:45,027 DEBUG [TranscodingJobListener] Transcoding finished; successful: false
2012-08-18 09:54:45,294 ERROR [ResourceTransportRequestHandler] Error while processing resource, sending back 500 error. Message: FFmpeg execution failed
java.io.IOException: FFmpeg execution failed
   at org.serviio.delivery.resource.transcode.FileBasedTranscodingDeliveryStrategy.createInputStream(FileBasedTranscodingDeliveryStrategy.java:47)
   at org.serviio.delivery.resource.transcode.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:125)
   at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:95)
   at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:120)
   at org.serviio.delivery.ResourceDeliveryProcessor.deliverContent(ResourceDeliveryProcessor.java:84)
   at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:79)
   at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:61)
   at org.apache.http.protocol.HttpService.doService(HttpService.java:293)
   at org.serviio.upnp.webserver.ServiioHttpService.doService(ServiioHttpService.java:58)
   at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:212)
   at org.serviio.upnp.webserver.WebServer$WorkerThread.run(WebServer.java:191)

FFmpeg:
  Code:
RR-DS212plus> /volume1/@appstore/Serviio/bin/ffmpeg -fflags +genpts -i "rtmp://s3h56pp78s3goi.cloudfront.net/cfx/st/ playpath=mp4:PBS_CP_Curious_George/CUGE3
14_EpisodeB_web4x3.mp4?player=PreKplayer&mediaID=2223987701 buffer=100000000" -y -copyts -c:v copy -vbsf h264_mp4toannexb -c:a ac3_fixed -b:a 384k -ac 2
-map 0:0 -map 0:1 -sn -f mpegts /.tmp/Serviio/transcoding-temp-1000000001440001-1-ORIGINAL.stf
ffmpeg version N-42368-gbf53863-Serviio Copyright (c) 2000-2012 the FFmpeg developers
  built on Jul 11 2012 01:45:53 with gcc 4.2.3
  configuration: --arch=arm --enable-armv5te --prefix=/opt --extra-cflags=-I/opt/include --extra-ldflags=-L/tmp/lib --enable-static --disable-shared --disable-ffplay --disable-ffserver --enable-pthreads --enable-libmp3lame --enable-librtmp --extra-version=Serviio
  libavutil      51. 64.100 / 51. 64.100
  libavcodec     54. 33.100 / 54. 33.100
  libavformat    54. 15.102 / 54. 15.102
  libavdevice    54.  1.100 / 54.  1.100
  libavfilter     3.  1.100 /  3.  1.100
  libswscale      2.  1.100 /  2.  1.100
  libswresample   0. 15.100 /  0. 15.100
Metadata:
  duration              744.48
  moovPosition          66783343.00
  width                 480.00
  height                360.00
  videocodecid          avc1
  audiocodecid          mp4a
  avcprofile            77.00
  avclevel              31.00
  aacaot                2.00
  videoframerate        15.00
  audiosamplerate       44100.00
  audiochannels         2.00
trackinfo:
  length                11167000.00
  timescale             15000.00
  language              und
sampledescription:
  sampletype            avc1
  length                32831488.00
  timescale             44100.00
  language              eng
sampledescription:
  sampletype            mp4a
Input #0, flv, from 'rtmp://s3h56pp78s3goi.cloudfront.net/cfx/st/ playpath=mp4:PBS_CP_Curious_George/CUGE314_EpisodeB_web4x3.mp4?player=PreKplayer&mediaID=2223987701 buffer=100000000':
  Metadata:
    moovPosition    : 66783343
    avcprofile      : 77
    avclevel        : 31
    aacaot          : 2
    videoframerate  : 15
    audiochannels   : 2
  Duration: 00:12:24.47, start: 0.000000, bitrate: N/A
    Stream #0:0: Video: h264 (Main), yuv420p, 480x360, 15 tbr, 1k tbn, 30 tbc
    Stream #0:1: Audio: aac, 44100 Hz, stereo, s16
[graph 0 input from stream 0:1 @ 0x1056be0] tb:1/44100 samplefmt:s16 samplerate:44100 chlayout:0x3
[mpegts @ 0x107f370] muxrate VBR, pcr every 1 pkts, sdt every 200, pat/pmt every 40 pkts
Output #0, mpegts, to '/.tmp/Serviio/transcoding-temp-1000000001440001-1-ORIGINAL.stf':
  Metadata:
    moovPosition    : 66783343
    avcprofile      : 77
    avclevel        : 31
    aacaot          : 2
    videoframerate  : 15
    audiochannels   : 2
    encoder         : Lavf54.15.102
    Stream #0:0: Video: h264, yuv420p, 480x360, q=2-31, 90k tbn, 15 tbc
    Stream #0:1: Audio: ac3, 44100 Hz, stereo, s16, 384 kb/s
Stream mapping:
  Stream #0:0 -> #0:0 (copy)
  Stream #0:1 -> #0:1 (aac -> ac3_fixed)
Press [q] to stop, [?] for help
frame=  705 fps= 67 q=-1.0 Lsize=    5192kB time=00:00:46.99 bitrate= 904.9kbits/s
video:2311kB audio:2204kB subtitle:0 global headers:0kB muxing overhead 15.000715%




CLIP-2
Log:
  Code:
2012-08-18 09:59:33,572 DEBUG [VideoDeliveryEngine] Delivering item '1000000001450001' for client 'IPAddress=/192.168.1.3, Profile=Generic DLNA profile'
2012-08-18 09:59:33,572 DEBUG [VideoDeliveryEngine] Delivering file 'http://www-tc.pbs.org/cove-media/http/PBS_CP_Angelina_Ballerina/68/594/ABAL505_1_web16x9.mp4' using transcoding
2012-08-18 09:59:33,573 DEBUG [AbstractTranscodingDeliveryEngine] No other client uses transcoding job of file 'transcoding-temp-1000000001440001-1-ORIGINAL.stf', will stop the job
2012-08-18 09:59:33,573 DEBUG [AbstractTranscodingDeliveryEngine] Stopping previous transcoding job of file 'transcoding-temp-1000000001440001-1-ORIGINAL.stf'
2012-08-18 09:59:33,573 DEBUG [TranscodingJobListener] Deleted temp file '/.tmp/Serviio/transcoding-temp-1000000001440001-1-ORIGINAL.stf': true
2012-08-18 09:59:33,573 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.1.3, Profile=Generic DLNA profile'
2012-08-18 09:59:33,573 DEBUG [VideoDeliveryEngine] Extracting new URL for the expired feed item
2012-08-18 09:59:33,574 DEBUG [FeedItemUrlExtractor] pbskids.org: Starting extraction of url for item: Ballet Pantomime
2012-08-18 09:59:33,766 DEBUG [FeedItemUrlExtractor] pbskids.org: Finished extraction of url: ContentURLContainer [fileType=VIDEO, contentUrl=http://www-tc.pbs.org/cove-media/http/PBS_CP_Angelina_Ballerina/68/594/ABAL505_1_web16x9.mp4, thumbnailUrl=http://www-tc.pbs.org/cove-media/http/PBS_CP_Angelina_Ballerina/68/594/ABAL505_1_web16x9_69x53_2218393679.jpg, expiresImmediately=true, cacheKey=PBSKids_tW0_qpfdJftq2Nb1EK5wWbSN06xxTpVO, live=false, ]
2012-08-18 09:59:33,766 DEBUG [VideoDeliveryEngine] Successfully set new URL for the feed item
2012-08-18 09:59:33,767 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: http://www-tc.pbs.org/cove-media/http/PBS_CP_Angelina_Ballerina/68/594/ABAL505_1_web16x9.mp4
2012-08-18 09:59:33,768 DEBUG [ProcessExecutor] Starting /volume1/@appstore/Serviio/bin/ffmpeg -fflags +genpts -i http://www-tc.pbs.org/cove-media/http/PBS_CP_Angelina_Ballerina/68/594/ABAL505_1_web16x9.mp4 -y -copyts -c:v copy -vbsf h264_mp4toannexb -c:a ac3_fixed -b:a 384k -ac 2 -map 0:0 -map 0:1 -sn -f mpegts /.tmp/Serviio/transcoding-temp-1000000001450001-1-ORIGINAL.stf
2012-08-18 09:59:34,675 WARN  [ProcessExecutor] Process /volume1/@appstore/Serviio/bin/ffmpeg has a return code of 1! This is a possible error.
2012-08-18 09:59:34,675 DEBUG [TranscodingJobListener] Transcoding finished; successful: false
2012-08-18 09:59:34,784 ERROR [ResourceTransportRequestHandler] Error while processing resource, sending back 500 error. Message: FFmpeg execution failed
java.io.IOException: FFmpeg execution failed
   at org.serviio.delivery.resource.transcode.FileBasedTranscodingDeliveryStrategy.createInputStream(FileBasedTranscodingDeliveryStrategy.java:47)
   at org.serviio.delivery.resource.transcode.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:125)
   at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:95)
   at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:120)
   at org.serviio.delivery.ResourceDeliveryProcessor.deliverContent(ResourceDeliveryProcessor.java:84)
   at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:79)
   at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:61)
   at org.apache.http.protocol.HttpService.doService(HttpService.java:293)
   at org.serviio.upnp.webserver.ServiioHttpService.doService(ServiioHttpService.java:58)
   at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:212)
   at org.serviio.upnp.webserver.WebServer$WorkerThread.run(WebServer.java:191)


FFmpeg:
  Code:
RR-DS212plus> /volume1/@appstore/Serviio/bin/ffmpeg -fflags +genpts -i "http://www-tc.pbs.org/cove-media/http/PBS_CP_Angelina_Ballerina/68/594/ABAL505_1_web1
6x9.mp4" -y -copyts -c:v copy -vbsf h264_mp4toannexb -c:a ac3_fixed -b:a 384k -ac 2 -map 0:0 -map 0:1 -sn -f mpegts /.tmp/Serviio/transcoding-temp-1000000001
450001-1-ORIGINAL.stf
ffmpeg version N-42368-gbf53863-Serviio Copyright (c) 2000-2012 the FFmpeg developers
  built on Jul 11 2012 01:45:53 with gcc 4.2.3
  configuration: --arch=arm --enable-armv5te --prefix=/opt --extra-cflags=-I/opt/include --extra-ldflags=-L/tmp/lib --enable-static --disable-shared --disable-ffplay --disable-ffserver --enable-pthreads --enable-libmp3lame --enable-librtmp --extra-version=Serviio
  libavutil      51. 64.100 / 51. 64.100
  libavcodec     54. 33.100 / 54. 33.100
  libavformat    54. 15.102 / 54. 15.102
  libavdevice    54.  1.100 / 54.  1.100
  libavfilter     3.  1.100 /  3.  1.100
  libswscale      2.  1.100 /  2.  1.100
  libswresample   0. 15.100 /  0. 15.100
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from 'http://www-tc.pbs.org/cove-media/http/PBS_CP_Angelina_Ballerina/68/594/ABAL505_1_web16x9.mp4':
  Metadata:
    major_brand     : M4V
    minor_version   : 1
    compatible_brands: isomavc1mp42
    creation_time   : 1942-02-22 01:02:34
  Duration: 00:01:40.68, start: 0.066667, bitrate: 721 kb/s
    Stream #0:0(und): Video: h264 (Main) (avc1 / 0x31637661), yuv420p, 512x288, 399 kb/s, SAR 1:1 DAR 16:9, 15 fps, 15 tbr, 15k tbn, 30 tbc
    Metadata:
      creation_time   : 1942-02-22 01:02:34
      handler_name    : ETI ISO Video Media Handler
    Stream #0:1(eng): Audio: aac (mp4a / 0x6134706D), 44100 Hz, stereo, s16, 318 kb/s
    Metadata:
      creation_time   : 1942-02-22 01:02:34
      handler_name    : ETI ISO Audio Media Handler
[graph 0 input from stream 0:1 @ 0xf8f270] tb:1/44100 samplefmt:s16 samplerate:44100 chlayout:0x3
[mpegts @ 0xf9ad20] muxrate VBR, pcr every 1 pkts, sdt every 200, pat/pmt every 40 pkts
Output #0, mpegts, to '/.tmp/Serviio/transcoding-temp-1000000001450001-1-ORIGINAL.stf':
  Metadata:
    major_brand     : M4V
    minor_version   : 1
    compatible_brands: isomavc1mp42
    encoder         : Lavf54.15.102
    Stream #0:0(und): Video: h264 (avc1 / 0x31637661), yuv420p, 512x288 [SAR 1:1 DAR 16:9], q=2-31, 399 kb/s, 15 fps, 90k tbn, 15 tbc
    Metadata:
      creation_time   : 1942-02-22 01:02:34
      handler_name    : ETI ISO Video Media Handler
    Stream #0:1(eng): Audio: ac3, 44100 Hz, stereo, s16, 384 kb/s
    Metadata:
      creation_time   : 1942-02-22 01:02:34
      handler_name    : ETI ISO Audio Media Handler
Stream mapping:
  Stream #0:0 -> #0:0 (copy)
  Stream #0:1 -> #0:1 (aac -> ac3_fixed)
Press [q] to stop, [?] for help
frame=  214 fps= 89 q=-1.0 Lsize=    1600kB time=00:00:14.10 bitrate= 929.6kbits/s
video:730kB audio:661kB subtitle:0 global headers:0kB muxing overhead 14.991125%



I am not sure whats wrong here. Everything seems to be fine but serviio keeps failing on ffmpeg for these clips.

Re: Strange issue with PBSKids plugin

PostPosted: Sun Aug 19, 2012 10:37 am
by zip
is it using the same ffmpeg as you when run manually? Is it not the write access to the temp folder?

Re: Strange issue with PBSKids plugin

PostPosted: Sun Aug 19, 2012 3:57 pm
by xs2inattar
Petr, rights to the tmp folder are setup correctly.

Any ideas what might be the issue here?

Re: Strange issue with PBSKids plugin

PostPosted: Sun Aug 19, 2012 7:09 pm
by zip
NO, it looks like it runs all the way if you run the ffmpeg command manually.... in that case it's either looking at another ffmpeg or the write access is not right.

Re: Strange issue with PBSKids plugin

PostPosted: Sun Aug 19, 2012 8:02 pm
by xs2inattar
OK so deleting the tmp folder, and restarting Serviio allowing it to create a new tmp folder fixed the issue.

But still ocnfused.

Re: Strange issue with PBSKids plugin

PostPosted: Sun Aug 19, 2012 8:09 pm
by zip
I'm not sure how the NAS manages users/access rights. Usually this doesn't happen.
All times are UTC
Page 1 of 1
Powered by phpBB © 2000, 2002, 2005, 2007 phpBB Group
http://www.phpbb.com/