Fri Oct 12, 2012 3:49 pm by Kovally
Illico wrote:Kovally wrote:2012-10-12 10:26:19,061 ERROR [ResourceTransportRequestHandler] Error while processing resource, sending back 500 error. Message: FFmpeg execution failed
Could ou enable
detailed logging (see signature), find the ffmpeg command line used for transcoding and try locally the same command line ?
Try open 3 different mkv files. One opened two does not open with different errors.
serviio.log (past from WARN and below)
- Code:
2012-10-12 19:19:23,407 WARN [ProcessExecutor] Process /root/.serviio/opt/bin/ffmpeg has a return code of 137! This is a possible error.
2012-10-12 19:19:23,407 DEBUG [TranscodingJobListener] Transcoding finished; successful: false
2012-10-12 19:19:23,409 DEBUG [TranscodingJobListener] Transcoding finished; successful: true
2012-10-12 19:19:23,537 DEBUG [TranscodingJobListener] Deleted temp file '/share/MD0_DATA/.qpkg/Serviio1/tmp/Serviio/transcoding-temp-473-4-ORIGINAL.stf': true
2012-10-12 19:19:23,559 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:19:23,559 DEBUG [MediaItemDAOImpl] Getting file of media item 465
2012-10-12 19:19:23,560 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: /share/Download/transmission/completed/Nely/Hodejegerne.2011.BluRay.1080p.x264.DTS-HDChina.Rus.Eng.mkv
2012-10-12 19:19:23,560 DEBUG [ProcessExecutor] Starting /root/.serviio/opt/bin/ffmpeg -fflags +genpts -i /share/Download/transmission/completed/Nely/Hodejegerne.2011.BluRay.1080p.x264.DTS-HDChina.Rus.Eng.mkv -y -copyts -c:v copy -vbsf h264_mp4toannexb -c:a ac3 -b:a 384k -ac 2 -map 0:0 -map 0:1 -sn -f mpegts /share/MD0_DATA/.qpkg/Serviio1/tmp/Serviio/transcoding-temp-465-4-ORIGINAL.stf
2012-10-12 19:19:24,061 DEBUG [FileBasedTranscodingDeliveryStrategy] Sending transcoding stream
2012-10-12 19:19:24,061 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file Hodejegerne.2011.BluRay.1080p.x264.DTS-HDChina.Rus.Eng.mkv: AVC_TS_MP_HD_AC3_ISO
2012-10-12 19:19:24,061 DEBUG [MediaItemDAOImpl] Marking MediaItem (id = 465) as read
2012-10-12 19:19:24,098 DEBUG [LocalContentCacheDecorator] Cleared cache (local_resetafterplay)
2012-10-12 19:19:24,098 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 50000000000
2012-10-12 19:19:24,099 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-10-12 19:19:24,099 DEBUG [ResourceTransportRequestHandler] Creating entity with chunked transfer
2012-10-12 19:19:24,099 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: video/mpeg,TimeSeekRange.dlna.org: npt=0.0-6006.0/6006,Date: Fri, 12 Oct 2012 15:19:24 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Streaming]]
2012-10-12 19:19:27,121 DEBUG [WebServer] I/O error: Broken pipe
2012-10-12 19:19:27,123 DEBUG [WebServer] Incoming connection from /192.168.1.196:54993
2012-10-12 19:19:27,123 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:19:27,124 DEBUG [ResourceTransportRequestHandler] GET /resource/465/MEDIA_ITEM/AVC_TS_MP_HD_AC3_ISO-0/ORIGINAL HTTP/1.1, headers = [Host: 192.168.1.152:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,TimeSeekRange.dlna.org: npt=0.000-,transferMode.dlna.org: Streaming,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment"; mn="PLAYSTATION 3"; mv="1.0";]]
2012-10-12 19:19:27,124 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:19:27,125 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:19:27,125 DEBUG [ResourceDeliveryProcessor] Request for resource 465 and type 'MEDIA_ITEM' received
2012-10-12 19:19:27,125 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 465 (local)
2012-10-12 19:19:27,125 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 465)
2012-10-12 19:19:27,126 DEBUG [VideoDAOImpl] Reading a Video (id = 465)
2012-10-12 19:19:27,127 DEBUG [VideoDeliveryEngine] Delivering item '465' for client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:19:27,127 DEBUG [VideoDeliveryEngine] Delivering file 'Hodejegerne.2011.BluRay.1080p.x264.DTS-HDChina.Rus.Eng.mkv' using transcoding
2012-10-12 19:19:27,127 DEBUG [AbstractTranscodingDeliveryEngine] A suitable transcoding job already exists, re-use it for client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:19:27,127 DEBUG [FileBasedTranscodingDeliveryStrategy] Sending transcoding stream
2012-10-12 19:19:27,128 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file Hodejegerne.2011.BluRay.1080p.x264.DTS-HDChina.Rus.Eng.mkv: AVC_TS_MP_HD_AC3_ISO
2012-10-12 19:19:27,128 DEBUG [MediaItemDAOImpl] Marking MediaItem (id = 465) as read
2012-10-12 19:19:27,198 DEBUG [LocalContentCacheDecorator] Cleared cache (local_resetafterplay)
2012-10-12 19:19:27,198 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 50000000000
2012-10-12 19:19:27,198 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-10-12 19:19:27,198 DEBUG [ResourceTransportRequestHandler] Creating entity with chunked transfer
2012-10-12 19:19:27,198 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: video/mpeg,TimeSeekRange.dlna.org: npt=0.0-6006.0/6006,Date: Fri, 12 Oct 2012 15:19:27 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Streaming]]
2012-10-12 19:19:28,311 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers
2012-10-12 19:19:32,665 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-10-12 19:19:32,665 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-10-12 19:19:33,319 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers
2012-10-12 19:19:38,326 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers
2012-10-12 19:19:43,333 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers
2012-10-12 19:19:48,340 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers
2012-10-12 19:19:53,346 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers
2012-10-12 19:19:58,354 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers
2012-10-12 19:19:58,798 DEBUG [WebServer] I/O error: Broken pipe
2012-10-12 19:19:59,336 DEBUG [WebServer] Incoming connection from /192.168.1.196:54989
2012-10-12 19:19:59,336 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:19:59,337 DEBUG [ResourceTransportRequestHandler] GET /resource/573/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.152:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment"; mn="PLAYSTATION 3"; mv="1.0";]]
2012-10-12 19:19:59,337 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:19:59,337 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:19:59,338 DEBUG [ResourceDeliveryProcessor] Request for resource 573 and type 'COVER_IMAGE' received
2012-10-12 19:19:59,338 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 573)
2012-10-12 19:19:59,338 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 573
2012-10-12 19:19:59,338 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 826
2012-10-12 19:19:59,339 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-10-12 19:19:59,339 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Content-Length: 826,Date: Fri, 12 Oct 2012 15:19:59 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2012-10-12 19:20:02,040 DEBUG [WebServer] Incoming connection from /192.168.1.196:54988
2012-10-12 19:20:02,041 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,042 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.196:
2012-10-12 19:20:02,042 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,048 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:02,052 DEBUG [WebServer] Incoming connection from /192.168.1.196:54987
2012-10-12 19:20:02,053 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,053 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.196:
2012-10-12 19:20:02,053 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,059 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_F, browseFlag = BrowseMetadata, filter = @id,upnp:class,res,res@protocolInfo,res@av:authenticationUri,res@size,dc:title,upnp:albumArtURI,res@dlna:ifoFileURI,res@protection,res@bitrate,res@duration,res@sampleFrequency,res@bitsPerSample,res@nrAudioChannels,res@resolution,res@colorDepth,dc:date,av:dateTime,upnp:artist,upnp:album,upnp:genre,dc:contributer,upnp:storageFree,upnp:storageUsed,upnp:originalTrackNumber,dc:publisher,dc:language,dc:region,dc:description,upnp:toc,@childCount,upnp:albumArtURI@dlna:profileID,res@dlna:cleartextSize, startIndex = 0, count = 1, sortCriteria =
2012-10-12 19:20:02,060 DEBUG [AccessGroupDAOImpl] Reading a AccessGroup (id = 1)
2012-10-12 19:20:02,060 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2012-10-12 19:20:02,065 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:02,068 DEBUG [WebServer] Incoming connection from /192.168.1.196:54986
2012-10-12 19:20:02,069 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,070 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.196:
2012-10-12 19:20:02,070 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,077 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:02,081 DEBUG [WebServer] Incoming connection from /192.168.1.196:54985
2012-10-12 19:20:02,081 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,082 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.196:
2012-10-12 19:20:02,082 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,090 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_F, browseFlag = BrowseMetadata, filter = @id,upnp:class,res,res@protocolInfo,res@av:authenticationUri,res@size,dc:title,upnp:albumArtURI,res@dlna:ifoFileURI,res@protection,res@bitrate,res@duration,res@sampleFrequency,res@bitsPerSample,res@nrAudioChannels,res@resolution,res@colorDepth,dc:date,av:dateTime,upnp:artist,upnp:album,upnp:genre,dc:contributer,upnp:storageFree,upnp:storageUsed,upnp:originalTrackNumber,dc:publisher,dc:language,dc:region,dc:description,upnp:toc,@childCount,upnp:albumArtURI@dlna:profileID,res@dlna:cleartextSize, startIndex = 0, count = 1, sortCriteria =
2012-10-12 19:20:02,090 DEBUG [AccessGroupDAOImpl] Reading a AccessGroup (id = 1)
2012-10-12 19:20:02,091 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2012-10-12 19:20:02,098 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:02,139 DEBUG [WebServer] Incoming connection from /192.168.1.196:54984
2012-10-12 19:20:02,185 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,186 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.196:
2012-10-12 19:20:02,186 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,195 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:02,198 DEBUG [WebServer] Incoming connection from /192.168.1.196:54983
2012-10-12 19:20:02,198 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,199 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.196:
2012-10-12 19:20:02,199 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,206 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_F, browseFlag = BrowseMetadata, filter = @id,upnp:class,res,res@protocolInfo,res@av:authenticationUri,res@size,dc:title,upnp:albumArtURI,res@dlna:ifoFileURI,res@protection,res@bitrate,res@duration,res@sampleFrequency,res@bitsPerSample,res@nrAudioChannels,res@resolution,res@colorDepth,dc:date,av:dateTime,upnp:artist,upnp:album,upnp:genre,dc:contributer,upnp:storageFree,upnp:storageUsed,upnp:originalTrackNumber,dc:publisher,dc:language,dc:region,dc:description,upnp:toc,@childCount,upnp:albumArtURI@dlna:profileID,res@dlna:cleartextSize, startIndex = 0, count = 1, sortCriteria =
2012-10-12 19:20:02,206 DEBUG [AccessGroupDAOImpl] Reading a AccessGroup (id = 1)
2012-10-12 19:20:02,206 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2012-10-12 19:20:02,214 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:02,491 DEBUG [WebServer] Incoming connection from /192.168.1.196:54982
2012-10-12 19:20:02,491 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,492 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.196:
2012-10-12 19:20:02,492 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,499 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:02,502 DEBUG [WebServer] Incoming connection from /192.168.1.196:54981
2012-10-12 19:20:02,503 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,503 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.196:
2012-10-12 19:20:02,504 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,514 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_F^FOL_R1, browseFlag = BrowseMetadata, filter = @id,upnp:class,res,res@protocolInfo,res@av:authenticationUri,res@size,dc:title,upnp:albumArtURI,res@dlna:ifoFileURI,res@protection,res@bitrate,res@duration,res@sampleFrequency,res@bitsPerSample,res@nrAudioChannels,res@resolution,res@colorDepth,dc:date,av:dateTime,upnp:artist,upnp:album,upnp:genre,dc:contributer,upnp:storageFree,upnp:storageUsed,upnp:originalTrackNumber,dc:publisher,dc:language,dc:region,dc:description,upnp:toc,@childCount,upnp:albumArtURI@dlna:profileID,res@dlna:cleartextSize, startIndex = 0, count = 1, sortCriteria =
2012-10-12 19:20:02,515 DEBUG [AccessGroupDAOImpl] Reading a AccessGroup (id = 1)
2012-10-12 19:20:02,515 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2012-10-12 19:20:02,520 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:02,527 DEBUG [WebServer] Incoming connection from /192.168.1.196:54980
2012-10-12 19:20:02,527 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,528 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.196:
2012-10-12 19:20:02,528 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,534 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:02,538 DEBUG [WebServer] Incoming connection from /192.168.1.196:54979
2012-10-12 19:20:02,538 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,539 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.196:
2012-10-12 19:20:02,539 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,545 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_F^FOL_R1, browseFlag = BrowseMetadata, filter = @id,upnp:class,res,res@protocolInfo,res@av:authenticationUri,res@size,dc:title,upnp:albumArtURI,res@dlna:ifoFileURI,res@protection,res@bitrate,res@duration,res@sampleFrequency,res@bitsPerSample,res@nrAudioChannels,res@resolution,res@colorDepth,dc:date,av:dateTime,upnp:artist,upnp:album,upnp:genre,dc:contributer,upnp:storageFree,upnp:storageUsed,upnp:originalTrackNumber,dc:publisher,dc:language,dc:region,dc:description,upnp:toc,@childCount,upnp:albumArtURI@dlna:profileID,res@dlna:cleartextSize, startIndex = 0, count = 1, sortCriteria =
2012-10-12 19:20:02,545 DEBUG [AccessGroupDAOImpl] Reading a AccessGroup (id = 1)
2012-10-12 19:20:02,546 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2012-10-12 19:20:02,551 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:02,559 DEBUG [WebServer] Incoming connection from /192.168.1.196:54978
2012-10-12 19:20:02,559 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,560 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.196:
2012-10-12 19:20:02,560 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,567 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:02,570 DEBUG [WebServer] Incoming connection from /192.168.1.196:54977
2012-10-12 19:20:02,571 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,572 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.196:
2012-10-12 19:20:02,572 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:02,578 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_F^FOL_R1, browseFlag = BrowseMetadata, filter = @id,upnp:class,res,res@protocolInfo,res@av:authenticationUri,res@size,dc:title,upnp:albumArtURI,res@dlna:ifoFileURI,res@protection,res@bitrate,res@duration,res@sampleFrequency,res@bitsPerSample,res@nrAudioChannels,res@resolution,res@colorDepth,dc:date,av:dateTime,upnp:artist,upnp:album,upnp:genre,dc:contributer,upnp:storageFree,upnp:storageUsed,upnp:originalTrackNumber,dc:publisher,dc:language,dc:region,dc:description,upnp:toc,@childCount,upnp:albumArtURI@dlna:profileID,res@dlna:cleartextSize, startIndex = 0, count = 1, sortCriteria =
2012-10-12 19:20:02,578 DEBUG [AccessGroupDAOImpl] Reading a AccessGroup (id = 1)
2012-10-12 19:20:02,579 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2012-10-12 19:20:02,584 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:03,361 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers
2012-10-12 19:20:03,775 DEBUG [WebServer] Incoming connection from /192.168.1.196:54976
2012-10-12 19:20:03,776 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,777 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.196:
2012-10-12 19:20:03,777 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,783 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:03,787 DEBUG [WebServer] Incoming connection from /192.168.1.196:54975
2012-10-12 19:20:03,787 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,788 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.196:
2012-10-12 19:20:03,788 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,794 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_F^FOL_R1$F1, browseFlag = BrowseMetadata, filter = @id,upnp:class,res,res@protocolInfo,res@av:authenticationUri,res@size,dc:title,upnp:albumArtURI,res@dlna:ifoFileURI,res@protection,res@bitrate,res@duration,res@sampleFrequency,res@bitsPerSample,res@nrAudioChannels,res@resolution,res@colorDepth,dc:date,av:dateTime,upnp:artist,upnp:album,upnp:genre,dc:contributer,upnp:storageFree,upnp:storageUsed,upnp:originalTrackNumber,dc:publisher,dc:language,dc:region,dc:description,upnp:toc,@childCount,upnp:albumArtURI@dlna:profileID,res@dlna:cleartextSize, startIndex = 0, count = 1, sortCriteria =
2012-10-12 19:20:03,794 DEBUG [AccessGroupDAOImpl] Reading a AccessGroup (id = 1)
2012-10-12 19:20:03,794 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2012-10-12 19:20:03,799 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:03,802 DEBUG [WebServer] Incoming connection from /192.168.1.196:54974
2012-10-12 19:20:03,802 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,803 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.196:
2012-10-12 19:20:03,803 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,809 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:03,813 DEBUG [WebServer] Incoming connection from /192.168.1.196:54973
2012-10-12 19:20:03,813 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,814 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.196:
2012-10-12 19:20:03,814 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,820 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_F^FOL_R1$F1, browseFlag = BrowseMetadata, filter = @id,upnp:class,res,res@protocolInfo,res@av:authenticationUri,res@size,dc:title,upnp:albumArtURI,res@dlna:ifoFileURI,res@protection,res@bitrate,res@duration,res@sampleFrequency,res@bitsPerSample,res@nrAudioChannels,res@resolution,res@colorDepth,dc:date,av:dateTime,upnp:artist,upnp:album,upnp:genre,dc:contributer,upnp:storageFree,upnp:storageUsed,upnp:originalTrackNumber,dc:publisher,dc:language,dc:region,dc:description,upnp:toc,@childCount,upnp:albumArtURI@dlna:profileID,res@dlna:cleartextSize, startIndex = 0, count = 1, sortCriteria =
2012-10-12 19:20:03,820 DEBUG [AccessGroupDAOImpl] Reading a AccessGroup (id = 1)
2012-10-12 19:20:03,821 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2012-10-12 19:20:03,825 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:03,833 DEBUG [WebServer] Incoming connection from /192.168.1.196:54972
2012-10-12 19:20:03,834 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,834 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.196:
2012-10-12 19:20:03,834 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,841 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:03,845 DEBUG [WebServer] Incoming connection from /192.168.1.196:54971
2012-10-12 19:20:03,845 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,846 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.196:
2012-10-12 19:20:03,846 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,853 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_F^FOL_R1$F1, browseFlag = BrowseMetadata, filter = @id,upnp:class,res,res@protocolInfo,res@av:authenticationUri,res@size,dc:title,upnp:albumArtURI,res@dlna:ifoFileURI,res@protection,res@bitrate,res@duration,res@sampleFrequency,res@bitsPerSample,res@nrAudioChannels,res@resolution,res@colorDepth,dc:date,av:dateTime,upnp:artist,upnp:album,upnp:genre,dc:contributer,upnp:storageFree,upnp:storageUsed,upnp:originalTrackNumber,dc:publisher,dc:language,dc:region,dc:description,upnp:toc,@childCount,upnp:albumArtURI@dlna:profileID,res@dlna:cleartextSize, startIndex = 0, count = 1, sortCriteria =
2012-10-12 19:20:03,853 DEBUG [AccessGroupDAOImpl] Reading a AccessGroup (id = 1)
2012-10-12 19:20:03,853 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2012-10-12 19:20:03,862 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2012-10-12 19:20:03,879 DEBUG [WebServer] Incoming connection from /192.168.1.196:54970
2012-10-12 19:20:03,879 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,879 DEBUG [ResourceTransportRequestHandler] GET /resource/554/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.152:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment"; mn="PLAYSTATION 3"; mv="1.0";]]
2012-10-12 19:20:03,880 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,880 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:03,880 DEBUG [ResourceDeliveryProcessor] Request for resource 554 and type 'COVER_IMAGE' received
2012-10-12 19:20:03,881 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 554)
2012-10-12 19:20:03,881 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 554
2012-10-12 19:20:03,881 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 887
2012-10-12 19:20:03,881 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-10-12 19:20:03,882 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Content-Length: 887,Date: Fri, 12 Oct 2012 15:20:03 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2012-10-12 19:20:03,953 DEBUG [WebServer] Incoming connection from /192.168.1.196:54969
2012-10-12 19:20:03,953 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,954 DEBUG [ResourceTransportRequestHandler] GET /resource/560/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.152:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment"; mn="PLAYSTATION 3"; mv="1.0";]]
2012-10-12 19:20:03,954 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:03,955 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:03,955 DEBUG [ResourceDeliveryProcessor] Request for resource 560 and type 'COVER_IMAGE' received
2012-10-12 19:20:03,955 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 560)
2012-10-12 19:20:03,956 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 560
2012-10-12 19:20:03,956 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 2869
2012-10-12 19:20:03,956 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-10-12 19:20:03,956 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Content-Length: 2869,Date: Fri, 12 Oct 2012 15:20:03 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2012-10-12 19:20:04,106 DEBUG [WebServer] Incoming connection from /192.168.1.196:54968
2012-10-12 19:20:04,106 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,107 DEBUG [ResourceTransportRequestHandler] GET /resource/570/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.152:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment"; mn="PLAYSTATION 3"; mv="1.0";]]
2012-10-12 19:20:04,107 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,108 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:04,108 DEBUG [ResourceDeliveryProcessor] Request for resource 570 and type 'COVER_IMAGE' received
2012-10-12 19:20:04,108 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 570)
2012-10-12 19:20:04,109 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 570
2012-10-12 19:20:04,109 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 959
2012-10-12 19:20:04,109 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-10-12 19:20:04,109 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Content-Length: 959,Date: Fri, 12 Oct 2012 15:20:04 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2012-10-12 19:20:04,139 DEBUG [WebServer] Incoming connection from /192.168.1.196:54967
2012-10-12 19:20:04,140 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,140 DEBUG [ResourceTransportRequestHandler] GET /resource/569/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.152:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment"; mn="PLAYSTATION 3"; mv="1.0";]]
2012-10-12 19:20:04,141 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,141 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:04,141 DEBUG [ResourceDeliveryProcessor] Request for resource 569 and type 'COVER_IMAGE' received
2012-10-12 19:20:04,141 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 569)
2012-10-12 19:20:04,142 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 569
2012-10-12 19:20:04,142 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 1839
2012-10-12 19:20:04,142 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-10-12 19:20:04,142 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Content-Length: 1839,Date: Fri, 12 Oct 2012 15:20:04 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2012-10-12 19:20:04,189 DEBUG [WebServer] Incoming connection from /192.168.1.196:54966
2012-10-12 19:20:04,189 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,190 DEBUG [ResourceTransportRequestHandler] GET /resource/550/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.152:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment"; mn="PLAYSTATION 3"; mv="1.0";]]
2012-10-12 19:20:04,190 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,191 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:04,210 DEBUG [ResourceDeliveryProcessor] Request for resource 550 and type 'COVER_IMAGE' received
2012-10-12 19:20:04,210 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 550)
2012-10-12 19:20:04,211 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 550
2012-10-12 19:20:04,211 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 826
2012-10-12 19:20:04,211 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-10-12 19:20:04,211 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Content-Length: 826,Date: Fri, 12 Oct 2012 15:20:04 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2012-10-12 19:20:04,240 DEBUG [WebServer] Incoming connection from /192.168.1.196:54965
2012-10-12 19:20:04,240 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,241 DEBUG [ResourceTransportRequestHandler] GET /resource/553/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.152:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment"; mn="PLAYSTATION 3"; mv="1.0";]]
2012-10-12 19:20:04,241 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,242 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:04,242 DEBUG [ResourceDeliveryProcessor] Request for resource 553 and type 'COVER_IMAGE' received
2012-10-12 19:20:04,242 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 553)
2012-10-12 19:20:04,243 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 553
2012-10-12 19:20:04,243 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 3322
2012-10-12 19:20:04,244 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-10-12 19:20:04,244 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Content-Length: 3322,Date: Fri, 12 Oct 2012 15:20:04 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2012-10-12 19:20:04,356 DEBUG [WebServer] Incoming connection from /192.168.1.196:54964
2012-10-12 19:20:04,357 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,358 DEBUG [ResourceTransportRequestHandler] GET /resource/556/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.152:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment"; mn="PLAYSTATION 3"; mv="1.0";]]
2012-10-12 19:20:04,358 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,359 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:04,359 DEBUG [ResourceDeliveryProcessor] Request for resource 556 and type 'COVER_IMAGE' received
2012-10-12 19:20:04,359 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 556)
2012-10-12 19:20:04,360 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 556
2012-10-12 19:20:04,360 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 918
2012-10-12 19:20:04,360 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-10-12 19:20:04,361 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Content-Length: 918,Date: Fri, 12 Oct 2012 15:20:04 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2012-10-12 19:20:04,390 DEBUG [WebServer] Incoming connection from /192.168.1.196:54963
2012-10-12 19:20:04,390 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,391 DEBUG [ResourceTransportRequestHandler] GET /resource/551/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.152:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment"; mn="PLAYSTATION 3"; mv="1.0";]]
2012-10-12 19:20:04,391 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,392 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:04,392 DEBUG [ResourceDeliveryProcessor] Request for resource 551 and type 'COVER_IMAGE' received
2012-10-12 19:20:04,392 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 551)
2012-10-12 19:20:04,392 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 551
2012-10-12 19:20:04,393 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 826
2012-10-12 19:20:04,393 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-10-12 19:20:04,393 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Content-Length: 826,Date: Fri, 12 Oct 2012 15:20:04 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2012-10-12 19:20:04,423 DEBUG [WebServer] Incoming connection from /192.168.1.196:54962
2012-10-12 19:20:04,423 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,424 DEBUG [ResourceTransportRequestHandler] GET /resource/555/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.152:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment"; mn="PLAYSTATION 3"; mv="1.0";]]
2012-10-12 19:20:04,424 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,425 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:04,425 DEBUG [ResourceDeliveryProcessor] Request for resource 555 and type 'COVER_IMAGE' received
2012-10-12 19:20:04,425 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 555)
2012-10-12 19:20:04,426 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 555
2012-10-12 19:20:04,426 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 894
2012-10-12 19:20:04,426 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-10-12 19:20:04,426 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Content-Length: 894,Date: Fri, 12 Oct 2012 15:20:04 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2012-10-12 19:20:04,456 DEBUG [WebServer] Incoming connection from /192.168.1.196:54961
2012-10-12 19:20:04,456 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,457 DEBUG [ResourceTransportRequestHandler] GET /resource/552/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.152:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment"; mn="PLAYSTATION 3"; mv="1.0";]]
2012-10-12 19:20:04,457 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:04,458 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:04,458 DEBUG [ResourceDeliveryProcessor] Request for resource 552 and type 'COVER_IMAGE' received
2012-10-12 19:20:04,458 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 552)
2012-10-12 19:20:04,459 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 552
2012-10-12 19:20:04,459 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 904
2012-10-12 19:20:04,459 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-10-12 19:20:04,459 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Content-Length: 904,Date: Fri, 12 Oct 2012 15:20:04 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2012-10-12 19:20:05,396 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface bond0 (bond0) and address 192.168.1.152, timeout = 0
2012-10-12 19:20:05,405 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 3915ea68-96c8-3d46-8665-8207a6f30e6c
2012-10-12 19:20:07,143 DEBUG [WebServer] Incoming connection from /192.168.1.196:54960
2012-10-12 19:20:07,144 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:07,145 DEBUG [DeviceDescriptionRequestHandler] DeviceDescription request received for device 3915ea68-96c8-3d46-8665-8207a6f30e6c from 192.168.1.196 (headers = [Host: 192.168.1.152:8895,Date: Fri, 12 Oct 2012 15:20:06 GMT,User-Agent: UPnP/1.0,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";])
2012-10-12 19:20:07,145 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:07,146 DEBUG [RendererManager] Looking for a renderer profile for Http headers: [Host: 192.168.1.152:8895,Date: Fri, 12 Oct 2012 15:20:06 GMT,User-Agent: UPnP/1.0,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";]
2012-10-12 19:20:07,146 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:07,150 DEBUG [DeviceDescriptionRequestHandler] Sending DeviceDescription XML back using profile 'Playstation 3'
2012-10-12 19:20:07,211 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:47
2012-10-12 19:20:08,369 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers
2012-10-12 19:20:11,051 DEBUG [WebServer] Incoming connection from /192.168.1.196:54959
2012-10-12 19:20:11,052 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:11,053 DEBUG [ResourceTransportRequestHandler] GET /resource/11/MEDIA_ITEM/AVC_TS_MP_HD_AC3_ISO-0/ORIGINAL HTTP/1.1, headers = [Host: 192.168.1.152:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Streaming,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment"; mn="PLAYSTATION 3"; mv="1.0";,TimeSeekRange.dlna.org: npt=0.000-]]
2012-10-12 19:20:11,053 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:11,053 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:11,054 DEBUG [ResourceDeliveryProcessor] Request for resource 11 and type 'MEDIA_ITEM' received
2012-10-12 19:20:11,054 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 11 (local)
2012-10-12 19:20:11,054 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 11)
2012-10-12 19:20:11,054 DEBUG [VideoDAOImpl] Reading a Video (id = 11)
2012-10-12 19:20:11,055 DEBUG [VideoDeliveryEngine] Delivering item '11' for client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:11,055 DEBUG [VideoDeliveryEngine] Delivering file 'Killer.Elite.2011.Blu-ray.1080p.AVC.Rus.Eng.mkv' using transcoding
2012-10-12 19:20:11,055 DEBUG [AbstractTranscodingDeliveryEngine] No other client uses transcoding job of file 'transcoding-temp-465-4-ORIGINAL.stf', will stop the job
2012-10-12 19:20:11,056 DEBUG [AbstractTranscodingDeliveryEngine] Stopping previous transcoding job of file 'transcoding-temp-465-4-ORIGINAL.stf'
2012-10-12 19:20:11,056 DEBUG [ProcessExecutor] Stopping external process: Thread[Thread-240,5,main]
2012-10-12 19:20:11,056 DEBUG [ProcessUtils] Sending kill -9 to the Unix process: 11897
2012-10-12 19:20:11,056 DEBUG [ProcessExecutor] Starting kill -9 11897
2012-10-12 19:20:11,061 WARN [ProcessExecutor] Process /root/.serviio/opt/bin/ffmpeg has a return code of 137! This is a possible error.
2012-10-12 19:20:11,061 DEBUG [TranscodingJobListener] Transcoding finished; successful: true
2012-10-12 19:20:11,061 DEBUG [TranscodingJobListener] Transcoding finished; successful: false
2012-10-12 19:20:11,225 DEBUG [TranscodingJobListener] Deleted temp file '/share/MD0_DATA/.qpkg/Serviio1/tmp/Serviio/transcoding-temp-465-4-ORIGINAL.stf': true
2012-10-12 19:20:11,226 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:11,226 DEBUG [MediaItemDAOImpl] Getting file of media item 11
2012-10-12 19:20:11,226 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: /share/Download/transmission/completed/Movie/Killer.Elite.2011.Blu-ray.1080p.AVC.Rus.Eng.mkv
2012-10-12 19:20:11,227 DEBUG [ProcessExecutor] Starting /root/.serviio/opt/bin/ffmpeg -fflags +genpts -i /share/Download/transmission/completed/Movie/Killer.Elite.2011.Blu-ray.1080p.AVC.Rus.Eng.mkv -y -copyts -c:v copy -vbsf h264_mp4toannexb -c:a copy -map 0:0 -map 0:1 -sn -f mpegts /share/MD0_DATA/.qpkg/Serviio1/tmp/Serviio/transcoding-temp-11-4-ORIGINAL.stf
2012-10-12 19:20:11,368 WARN [ProcessExecutor] Process /root/.serviio/opt/bin/ffmpeg has a return code of 1! This is a possible error.
2012-10-12 19:20:11,368 DEBUG [TranscodingJobListener] Transcoding finished; successful: false
2012-10-12 19:20:11,727 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)
2012-10-12 19:20:11,732 DEBUG [WebServer] Incoming connection from /192.168.1.196:54957
2012-10-12 19:20:11,732 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:11,733 DEBUG [ResourceTransportRequestHandler] GET /resource/11/MEDIA_ITEM/AVC_TS_MP_HD_AC3_ISO-0/ORIGINAL HTTP/1.1, headers = [Host: 192.168.1.152:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Streaming,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment"; mn="PLAYSTATION 3"; mv="1.0";,TimeSeekRange.dlna.org: npt=0.000-]]
2012-10-12 19:20:11,733 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.196
2012-10-12 19:20:11,734 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:11,734 DEBUG [ResourceDeliveryProcessor] Request for resource 11 and type 'MEDIA_ITEM' received
2012-10-12 19:20:11,734 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 11 (local)
2012-10-12 19:20:11,734 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 11)
2012-10-12 19:20:11,735 DEBUG [VideoDAOImpl] Reading a Video (id = 11)
2012-10-12 19:20:11,735 DEBUG [VideoDeliveryEngine] Delivering item '11' for client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:11,736 DEBUG [VideoDeliveryEngine] Delivering file 'Killer.Elite.2011.Blu-ray.1080p.AVC.Rus.Eng.mkv' using transcoding
2012-10-12 19:20:11,736 DEBUG [AbstractTranscodingDeliveryEngine] A suitable transcoding job already exists, re-use it for client 'IPAddress=/192.168.1.196, Profile=Playstation 3'
2012-10-12 19:20:11,736 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)
2012-10-12 19:20:13,374 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers
2012-10-12 19:20:18,379 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers
2012-10-12 19:20:23,785 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers
2012-10-12 19:20:28,389 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers
2012-10-12 19:20:32,666 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-10-12 19:20:32,666 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-10-12 19:20:33,394 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers
2012-10-12 19:20:38,399 DEBUG [RendererDAOImpl] Retrieving list of all stored renderers