Wed Sep 28, 2011 4:55 pm
Media Server Error
I am running the linux version of Serviio 0.5.2. My renderer is a Playstation 3 (PS3). My "AVI" files play fine, but I am trying to play ".MKV" files and I am receiving the following error:
"Media Server Error: A network error has occurred. (00000000)"
All 56 of my ".MKV" files return the error message (above). Transcoding is enabled and it is set to downmix audio.
The following is my "Serviio.log" file (in DEBUG mode) after playing the "Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi.mkv" file:
--------------------------------------------------------------------------------------------------------------------
2011-09-28 16:23:14,451 DEBUG [WebServer] Incoming connection from /192.168.1.123:58226
2011-09-28 16:23:14,454 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:14,455 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:14,546 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:14,654 DEBUG [WebServer] Incoming connection from /192.168.1.123:58225
2011-09-28 16:23:14,658 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:14,658 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:14,764 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:14,779 DEBUG [WebServer] Incoming connection from /192.168.1.123:58224
2011-09-28 16:23:14,783 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:14,783 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:14,880 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = 0, 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, startIndex = 0, count = 1, sortCriteria =
2011-09-28 16:23:14,893 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2011-09-28 16:23:14,923 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:14,932 DEBUG [WebServer] Incoming connection from /192.168.1.123:58223
2011-09-28 16:23:14,935 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:14,936 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:15,047 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = 0, browseFlag = BrowseDirectChildren, 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, startIndex = 0, count = 10, sortCriteria =
2011-09-28 16:23:15,058 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface em0 (em0) and address 192.168.1.247, timeout = 0
2011-09-28 16:23:15,063 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 7e77d808-59f9-342a-8af9-5da50f774213
2011-09-28 16:23:15,059 DEBUG [LocalContentCacheDecorator] Stored entry in the cache (local_default), returning it
2011-09-28 16:23:15,084 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:15,121 DEBUG [WebServer] Incoming connection from /192.168.1.123:58222
2011-09-28 16:23:15,124 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:15,125 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:15,232 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:15,240 DEBUG [WebServer] Incoming connection from /192.168.1.123:58221
2011-09-28 16:23:15,243 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:15,244 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:15,349 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = 0, 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, startIndex = 0, count = 1, sortCriteria =
2011-09-28 16:23:15,350 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2011-09-28 16:23:15,362 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:16,287 DEBUG [WebServer] Incoming connection from /192.168.1.123:58220
2011-09-28 16:23:16,290 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:16,290 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:16,385 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:16,393 DEBUG [WebServer] Incoming connection from /192.168.1.123:58219
2011-09-28 16:23:16,397 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:16,397 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:16,494 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:16,515 DEBUG [WebServer] Incoming connection from /192.168.1.123:58218
2011-09-28 16:23:16,517 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:16,517 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:16,606 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V, 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, startIndex = 0, count = 1, sortCriteria =
2011-09-28 16:23:16,608 DEBUG [LocalContentCacheDecorator] Stored entry in the cache (local_default), returning it
2011-09-28 16:23:16,620 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:16,631 DEBUG [WebServer] Incoming connection from /192.168.1.123:58217
2011-09-28 16:23:16,634 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:16,634 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:16,743 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V, browseFlag = BrowseDirectChildren, 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, startIndex = 0, count = 10, sortCriteria =
2011-09-28 16:23:16,785 DEBUG [VideoDAOImpl] Retrieving number of video initials
2011-09-28 16:23:17,172 DEBUG [VideoDAOImpl] Retrieving number of videos of type 2
2011-09-28 16:23:17,203 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:01:27
2011-09-28 16:23:17,527 DEBUG [WebServer] Incoming connection from /192.168.1.123:58216
2011-09-28 16:23:17,708 DEBUG [DeviceDescriptionRequestHandler] DeviceDescription request received for device 7e77d808-59f9-342a-8af9-5da50f774213 from 192.168.1.123 (headers = [Host: 192.168.1.247:8895,Date: Wed, 28 Sep 2011 16:26:51 GMT,User-Agent: UPnP/1.0,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";])
2011-09-28 16:23:17,708 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:17,710 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:17,720 DEBUG [DeviceDescriptionRequestHandler] Sending DeviceDescription XML back using profile 'Playstation 3'
2011-09-28 16:23:17,729 DEBUG [SeriesDAOImpl] Retrieving number of series
2011-09-28 16:23:17,787 DEBUG [RepositoryDAOImpl] Retrieving number of repositories for VIDEO
2011-09-28 16:23:17,814 DEBUG [VideoDAOImpl] Retrieving number of 10 last viewed videos
2011-09-28 16:23:17,855 DEBUG [VideoDAOImpl] Retrieving number of 10 last added videos
2011-09-28 16:23:17,855 DEBUG [VideoDAOImpl] Retrieving number of videos of type 0
2011-09-28 16:23:17,888 DEBUG [GenreDAOImpl] Retrieving number of genres for VIDEO
2011-09-28 16:23:17,973 DEBUG [PersonDAOImpl] Retrieving number of person initials for role ACTOR
2011-09-28 16:23:18,229 DEBUG [PersonDAOImpl] Retrieving number of person initials for role DIRECTOR
2011-09-28 16:23:18,258 DEBUG [PersonDAOImpl] Retrieving number of person initials for role PRODUCER
2011-09-28 16:23:18,268 DEBUG [LocalContentCacheDecorator] Stored entry in the cache (local_default), returning it
2011-09-28 16:23:18,280 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:18,411 DEBUG [WebServer] Incoming connection from /192.168.1.123:58215
2011-09-28 16:23:18,412 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:18,412 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:18,508 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:18,512 DEBUG [WebServer] Incoming connection from /192.168.1.123:58214
2011-09-28 16:23:18,513 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:18,513 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:18,607 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V, 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, startIndex = 0, count = 1, sortCriteria =
2011-09-28 16:23:18,607 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2011-09-28 16:23:18,610 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:23,461 DEBUG [WebServer] Incoming connection from /192.168.1.123:58213
2011-09-28 16:23:23,464 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:23,465 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:23,555 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:23,565 DEBUG [WebServer] Incoming connection from /192.168.1.123:58212
2011-09-28 16:23:23,569 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:23,570 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:23,664 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:23,679 DEBUG [WebServer] Incoming connection from /192.168.1.123:58211
2011-09-28 16:23:23,682 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:23,683 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:23,776 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_LV, 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, startIndex = 0, count = 1, sortCriteria =
2011-09-28 16:23:23,778 DEBUG [VideoDAOImpl] Retrieving number of 10 last viewed videos
2011-09-28 16:23:23,806 DEBUG [LocalContentCacheDecorator] Stored entry in the cache (local_resetafterplay), returning it
2011-09-28 16:23:23,817 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:23,826 DEBUG [WebServer] Incoming connection from /192.168.1.123:58210
2011-09-28 16:23:23,829 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:23,829 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:23,942 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_LV, browseFlag = BrowseDirectChildren, 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, startIndex = 0, count = 10, sortCriteria =
2011-09-28 16:23:23,945 DEBUG [VideoDAOImpl] Retrieving list of 10 last viewed videos (from=0, count=10)
2011-09-28 16:23:24,415 DEBUG [GenreDAOImpl] Reading a Genre (id = 16)
2011-09-28 16:23:24,483 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1028)
2011-09-28 16:23:24,530 DEBUG [MediaItemDAOImpl] Getting file of media item 1028
2011-09-28 16:23:24,701 DEBUG [VideoDAOImpl] Reading a Video (id = 1028)
2011-09-28 16:23:24,730 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1028 and profile Playstation 3
2011-09-28 16:23:24,733 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi.mkv: AVC_TS_MP_HD_AC3_ISO
2011-09-28 16:23:24,739 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1113)
2011-09-28 16:23:24,808 DEBUG [GenreDAOImpl] Reading a Genre (id = 2)
2011-09-28 16:23:24,809 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1090)
2011-09-28 16:23:24,811 DEBUG [MediaItemDAOImpl] Getting file of media item 1090
2011-09-28 16:23:24,828 DEBUG [VideoDAOImpl] Reading a Video (id = 1090)
2011-09-28 16:23:24,837 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1090 and profile Playstation 3
2011-09-28 16:23:24,837 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file tron.legacy.2010.bluray.1080p.dts.x264-chd.mkv: AVC_TS_MP_HD_AC3_ISO
2011-09-28 16:23:24,838 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1147)
2011-09-28 16:23:24,843 DEBUG [GenreDAOImpl] Reading a Genre (id = 7)
2011-09-28 16:23:24,845 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 997)
2011-09-28 16:23:24,846 DEBUG [MediaItemDAOImpl] Getting file of media item 997
2011-09-28 16:23:24,857 DEBUG [VideoDAOImpl] Reading a Video (id = 997)
2011-09-28 16:23:24,859 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 997 and profile Playstation 3
2011-09-28 16:23:24,859 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file American.Graffiti.1973.1080p.BluRay.X264-AMIABLE.mkv: AVC_TS_MP_HD_AC3_ISO
2011-09-28 16:23:24,859 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1101)
2011-09-28 16:23:24,861 DEBUG [GenreDAOImpl] Reading a Genre (id = 2)
2011-09-28 16:23:24,867 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1000)
2011-09-28 16:23:24,868 DEBUG [MediaItemDAOImpl] Getting file of media item 1000
2011-09-28 16:23:24,878 DEBUG [VideoDAOImpl] Reading a Video (id = 1000)
2011-09-28 16:23:24,879 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1000 and profile Playstation 3
2011-09-28 16:23:24,880 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1104)
2011-09-28 16:23:24,900 DEBUG [GenreDAOImpl] Reading a Genre (id = 8)
2011-09-28 16:23:24,901 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 999)
2011-09-28 16:23:24,903 DEBUG [MediaItemDAOImpl] Getting file of media item 999
2011-09-28 16:23:24,907 DEBUG [VideoDAOImpl] Reading a Video (id = 999)
2011-09-28 16:23:24,908 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 999 and profile Playstation 3
2011-09-28 16:23:24,909 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1103)
2011-09-28 16:23:24,910 DEBUG [GenreDAOImpl] Reading a Genre (id = 2)
2011-09-28 16:23:24,911 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 998)
2011-09-28 16:23:24,913 DEBUG [MediaItemDAOImpl] Getting file of media item 998
2011-09-28 16:23:24,924 DEBUG [VideoDAOImpl] Reading a Video (id = 998)
2011-09-28 16:23:24,925 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 998 and profile Playstation 3
2011-09-28 16:23:24,926 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1102)
2011-09-28 16:23:24,931 DEBUG [GenreDAOImpl] Reading a Genre (id = 17)
2011-09-28 16:23:24,932 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1107)
2011-09-28 16:23:24,934 DEBUG [MediaItemDAOImpl] Getting file of media item 1107
2011-09-28 16:23:24,953 DEBUG [VideoDAOImpl] Reading a Video (id = 1107)
2011-09-28 16:23:24,956 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1107 and profile Playstation 3
2011-09-28 16:23:24,956 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file No.Country.for.Old.Men.2007.Blu-ray.1080p.DTS.x264-CtrlHD.mkv: AVC_TS_MP_HD_AC3_ISO
2011-09-28 16:23:24,956 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1157)
2011-09-28 16:23:24,962 DEBUG [GenreDAOImpl] Reading a Genre (id = 26)
2011-09-28 16:23:24,972 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1501)
2011-09-28 16:23:24,974 DEBUG [MediaItemDAOImpl] Getting file of media item 1501
2011-09-28 16:23:24,998 DEBUG [VideoDAOImpl] Reading a Video (id = 1501)
2011-09-28 16:23:25,001 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1501 and profile Playstation 3
2011-09-28 16:23:25,001 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file Inside.Job.2010.Blu-ray.1080p.x264.DTS-Dolby.(DMT).mkv: AVC_TS_MP_HD_AC3_ISO
2011-09-28 16:23:25,001 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1565)
2011-09-28 16:23:25,007 DEBUG [GenreDAOImpl] Reading a Genre (id = 2)
2011-09-28 16:23:25,007 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1034)
2011-09-28 16:23:25,010 DEBUG [MediaItemDAOImpl] Getting file of media item 1034
2011-09-28 16:23:25,029 DEBUG [VideoDAOImpl] Reading a Video (id = 1034)
2011-09-28 16:23:25,031 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1034 and profile Playstation 3
2011-09-28 16:23:25,031 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file Fast.Five.2011.BluRay.1080p.DTS.x264-CHD.mkv: AVC_TS_MP_HD_AC3_ISO
2011-09-28 16:23:25,031 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1116)
2011-09-28 16:23:25,033 DEBUG [GenreDAOImpl] Reading a Genre (id = 2)
2011-09-28 16:23:25,034 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1015)
2011-09-28 16:23:25,035 DEBUG [MediaItemDAOImpl] Getting file of media item 1015
2011-09-28 16:23:25,054 DEBUG [VideoDAOImpl] Reading a Video (id = 1015)
2011-09-28 16:23:25,055 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1015 and profile Playstation 3
2011-09-28 16:23:25,055 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file 2012.2009.BluRay.1080p.DTS.x264-CHD.mkv: AVC_TS_MP_HD_AC3_ISO
2011-09-28 16:23:25,056 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1106)
2011-09-28 16:23:25,061 DEBUG [VideoDAOImpl] Retrieving number of 10 last viewed videos
2011-09-28 16:23:25,064 DEBUG [LocalContentCacheDecorator] Stored entry in the cache (local_resetafterplay), returning it
2011-09-28 16:23:25,109 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:25,391 DEBUG [WebServer] Incoming connection from /192.168.1.123:58209
2011-09-28 16:23:25,394 DEBUG [ResourceTransportRequestHandler] GET /resource/1113/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,395 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:25,397 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:25,399 DEBUG [ResourceTransportRequestHandler] Request for resource 1113 and type 'COVER_IMAGE' received
2011-09-28 16:23:25,401 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1113)
2011-09-28 16:23:25,406 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1113
2011-09-28 16:23:25,409 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:25,410 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:25,410 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:25,410 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:25 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,516 DEBUG [WebServer] Incoming connection from /192.168.1.123:58208
2011-09-28 16:23:25,518 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:25,518 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:25,570 DEBUG [WebServer] Incoming connection from /192.168.1.123:58207
2011-09-28 16:23:25,576 DEBUG [ResourceTransportRequestHandler] GET /resource/1147/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,578 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:25,580 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:25,580 DEBUG [ResourceTransportRequestHandler] Request for resource 1147 and type 'COVER_IMAGE' received
2011-09-28 16:23:25,580 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1147)
2011-09-28 16:23:25,588 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1147
2011-09-28 16:23:25,589 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:25,589 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:25,589 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:25,589 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:25 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,616 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:25,622 DEBUG [WebServer] Incoming connection from /192.168.1.123:58206
2011-09-28 16:23:25,623 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:25,623 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:25,718 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_LV, 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, startIndex = 0, count = 1, sortCriteria =
2011-09-28 16:23:25,719 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_resetafterplay), returning it
2011-09-28 16:23:25,723 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:25,724 DEBUG [WebServer] Incoming connection from /192.168.1.123:58205
2011-09-28 16:23:25,725 DEBUG [ResourceTransportRequestHandler] GET /resource/1101/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,726 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:25,727 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:25,727 DEBUG [ResourceTransportRequestHandler] Request for resource 1101 and type 'COVER_IMAGE' received
2011-09-28 16:23:25,727 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1101)
2011-09-28 16:23:25,729 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1101
2011-09-28 16:23:25,729 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:25,729 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:25,729 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:25,729 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:25 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,854 DEBUG [WebServer] Incoming connection from /192.168.1.123:58204
2011-09-28 16:23:25,855 DEBUG [ResourceTransportRequestHandler] GET /resource/1104/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,855 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:25,856 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:25,856 DEBUG [ResourceTransportRequestHandler] Request for resource 1104 and type 'COVER_IMAGE' received
2011-09-28 16:23:25,857 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1104)
2011-09-28 16:23:25,858 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1104
2011-09-28 16:23:25,858 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:25,858 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:25,858 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:25,859 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:25 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,985 DEBUG [WebServer] Incoming connection from /192.168.1.123:58203
2011-09-28 16:23:25,986 DEBUG [ResourceTransportRequestHandler] GET /resource/1103/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,986 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:25,987 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:25,988 DEBUG [ResourceTransportRequestHandler] Request for resource 1103 and type 'COVER_IMAGE' received
2011-09-28 16:23:25,988 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1103)
2011-09-28 16:23:25,989 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1103
2011-09-28 16:23:25,990 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:25,990 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:25,990 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:25,990 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:25 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,102 DEBUG [WebServer] Incoming connection from /192.168.1.123:58202
2011-09-28 16:23:26,102 DEBUG [ResourceTransportRequestHandler] GET /resource/1102/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,103 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:26,104 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:26,105 DEBUG [ResourceTransportRequestHandler] Request for resource 1102 and type 'COVER_IMAGE' received
2011-09-28 16:23:26,105 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1102)
2011-09-28 16:23:26,108 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1102
2011-09-28 16:23:26,108 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:26,108 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:26,108 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:26,108 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:26 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,221 DEBUG [WebServer] Incoming connection from /192.168.1.123:58201
2011-09-28 16:23:26,222 DEBUG [ResourceTransportRequestHandler] GET /resource/1157/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,222 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:26,224 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:26,224 DEBUG [ResourceTransportRequestHandler] Request for resource 1157 and type 'COVER_IMAGE' received
2011-09-28 16:23:26,224 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1157)
2011-09-28 16:23:26,226 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1157
2011-09-28 16:23:26,226 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:26,226 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:26,226 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:26,226 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:26 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,319 DEBUG [WebServer] Incoming connection from /192.168.1.123:58200
2011-09-28 16:23:26,319 DEBUG [ResourceTransportRequestHandler] GET /resource/1565/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,320 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:26,321 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:26,321 DEBUG [ResourceTransportRequestHandler] Request for resource 1565 and type 'COVER_IMAGE' received
2011-09-28 16:23:26,322 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1565)
2011-09-28 16:23:26,323 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1565
2011-09-28 16:23:26,323 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:26,323 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:26,324 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:26,324 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:26 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,419 DEBUG [WebServer] Incoming connection from /192.168.1.123:58199
2011-09-28 16:23:26,419 DEBUG [ResourceTransportRequestHandler] GET /resource/1116/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,419 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:26,421 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:26,421 DEBUG [ResourceTransportRequestHandler] Request for resource 1116 and type 'COVER_IMAGE' received
2011-09-28 16:23:26,421 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1116)
2011-09-28 16:23:26,423 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1116
2011-09-28 16:23:26,423 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:26,423 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:26,423 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:26,430 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:26 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,552 DEBUG [WebServer] Incoming connection from /192.168.1.123:58198
2011-09-28 16:23:26,553 DEBUG [ResourceTransportRequestHandler] GET /resource/1106/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,554 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:26,555 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:26,556 DEBUG [ResourceTransportRequestHandler] Request for resource 1106 and type 'COVER_IMAGE' received
2011-09-28 16:23:26,556 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1106)
2011-09-28 16:23:26,558 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1106
2011-09-28 16:23:26,558 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:26,558 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:26,559 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:26,559 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:26 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:33,319 DEBUG [WebServer] Incoming connection from /192.168.1.123:58197
2011-09-28 16:23:33,321 DEBUG [ResourceTransportRequestHandler] GET /resource/1028/MEDIA_ITEM/AVC_TS_MP_HD_AC3_ISO$0 HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Streaming,TimeSeekRange.dlna.org: npt=0.000-]]
2011-09-28 16:23:33,321 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:33,325 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:33,327 DEBUG [ResourceTransportRequestHandler] Request for resource 1028 and type 'MEDIA_ITEM' received
2011-09-28 16:23:33,327 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1028)
2011-09-28 16:23:33,335 DEBUG [VideoDAOImpl] Reading a Video (id = 1028)
2011-09-28 16:23:33,351 DEBUG [VideoDeliveryEngine] Delivering item '1028' for client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:33,354 DEBUG [VideoDeliveryEngine] Delivering file 'Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi.mkv' using transcoding
2011-09-28 16:23:33,356 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:33,362 DEBUG [MediaItemDAOImpl] Getting file of media item 1028
2011-09-28 16:23:33,381 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: /mnt/Media/Movies/DTS/Core (1.5Mbps)/Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi/Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi.mkv
2011-09-28 16:23:33,384 DEBUG [ProcessExecutor] Starting ffmpeg -i /mnt/Media/Movies/DTS/Core (1.5Mbps)/Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi/Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi.mkv -y -vcodec copy -vbsf h264_mp4toannexb -copyts -acodec ac3 -ab 192k -ac 2 -map 0:0 -map 0:1 -sn -f mpegts /var/tmp/Serviio/transcoding-temp-1028-MPEG2TS.stf
2011-09-28 16:23:34,234 WARN [ProcessExecutor] Process ffmpeg has a return code of 1! This is a possible error.
2011-09-28 16:23:34,235 DEBUG [TranscodingJobListener] Transcoding finished; successful: false
2011-09-28 16:23:34,505 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.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:116)
at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:89)
at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:116)
at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:115)
at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:54)
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:187)
2011-09-28 16:23:34,515 DEBUG [WebServer] Incoming connection from /192.168.1.123:58196
2011-09-28 16:23:34,519 DEBUG [ResourceTransportRequestHandler] GET /resource/1028/MEDIA_ITEM/AVC_TS_MP_HD_AC3_ISO$0 HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Streaming,TimeSeekRange.dlna.org: npt=0.000-]]
2011-09-28 16:23:34,519 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:34,520 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:34,521 DEBUG [ResourceTransportRequestHandler] Request for resource 1028 and type 'MEDIA_ITEM' received
2011-09-28 16:23:34,521 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1028)
2011-09-28 16:23:34,522 DEBUG [VideoDAOImpl] Reading a Video (id = 1028)
2011-09-28 16:23:34,524 DEBUG [VideoDeliveryEngine] Delivering item '1028' for client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:34,524 DEBUG [VideoDeliveryEngine] Delivering file 'Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi.mkv' using transcoding
2011-09-28 16:23:34,524 DEBUG [AbstractTranscodingDeliveryEngine] A suitable transcoding job already exists, re-use it for client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:34,524 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.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:116)
at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:89)
at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:116)
at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:115)
at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:54)
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:187)
2011-09-28 16:23:39,800 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:MediaServer:1 from address /192.168.1.109:49153
2011-09-28 16:23:39,803 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.109:49153
--------------------------------------------------------------------------------------------------------------------
The following are the results of a manually executed "ffmpeg" against the "Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi.mkv" file.
/usr/bin# ffmpeg -i "/mnt/Media/Movies/DTS/Core (1.5Mbps)/Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi"
FFmpeg version 0.5, Copyright (c) 2000-2009 Fabrice Bellard, et al.
configuration: --prefix=/usr/local --mandir=/usr/local/man --enable-shared --enable-gpl --enable-swscale --enable-postproc --enable-avfilter --enable-avfilter-lavf --enable-pthreads --enable-memalign-hack --cc=cc --extra-cflags=-I/usr/local/include/vorbis -I/usr/local/include --extra-ldflags=-L/usr/local/lib --extra-libs=-pthread --disable-debug --disable-sse --disable-mmx --disable-libamr-nb --disable-libamr-wb --disable-libdirac --disable-libfaac --enable-libfaad --enable-libfaadbin --disable-libgsm --disable-vhook --enable-ipv6 --disable-libmp3lame --disable-libopenjpeg --enable-libschroedinger --disable-ffplay --disable-libspeex --enable-libtheora --enable-libvorbis --disable-x11grab --enable-libx264 --enable-libxvid
libavutil 49.15. 0 / 49.15. 0
libavcodec 52.20. 0 / 52.20. 0
libavformat 52.31. 0 / 52.31. 0
libavdevice 52. 1. 0 / 52. 1. 0
libavfilter 0. 4. 0 / 0. 4. 0
libswscale 0. 7. 1 / 0. 7. 1
libpostproc 51. 2. 0 / 51. 2. 0
built on Mar 7 2010 00:34:41, gcc: 4.2.1 20070719 [FreeBSD]
/mnt/Media/Movies/DTS/Core (1.5Mbps)/Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi: Unknown format
Note: The "Core (1.5Mbps)" directory has spaces in it, so the path is encapsulated in quotes (above)
"Media Server Error: A network error has occurred. (00000000)"
All 56 of my ".MKV" files return the error message (above). Transcoding is enabled and it is set to downmix audio.
The following is my "Serviio.log" file (in DEBUG mode) after playing the "Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi.mkv" file:
--------------------------------------------------------------------------------------------------------------------
2011-09-28 16:23:14,451 DEBUG [WebServer] Incoming connection from /192.168.1.123:58226
2011-09-28 16:23:14,454 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:14,455 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:14,546 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:14,654 DEBUG [WebServer] Incoming connection from /192.168.1.123:58225
2011-09-28 16:23:14,658 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:14,658 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:14,764 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:14,779 DEBUG [WebServer] Incoming connection from /192.168.1.123:58224
2011-09-28 16:23:14,783 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:14,783 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:14,880 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = 0, 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, startIndex = 0, count = 1, sortCriteria =
2011-09-28 16:23:14,893 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2011-09-28 16:23:14,923 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:14,932 DEBUG [WebServer] Incoming connection from /192.168.1.123:58223
2011-09-28 16:23:14,935 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:14,936 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:15,047 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = 0, browseFlag = BrowseDirectChildren, 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, startIndex = 0, count = 10, sortCriteria =
2011-09-28 16:23:15,058 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface em0 (em0) and address 192.168.1.247, timeout = 0
2011-09-28 16:23:15,063 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 7e77d808-59f9-342a-8af9-5da50f774213
2011-09-28 16:23:15,059 DEBUG [LocalContentCacheDecorator] Stored entry in the cache (local_default), returning it
2011-09-28 16:23:15,084 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:15,121 DEBUG [WebServer] Incoming connection from /192.168.1.123:58222
2011-09-28 16:23:15,124 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:15,125 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:15,232 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:15,240 DEBUG [WebServer] Incoming connection from /192.168.1.123:58221
2011-09-28 16:23:15,243 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:15,244 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:15,349 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = 0, 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, startIndex = 0, count = 1, sortCriteria =
2011-09-28 16:23:15,350 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2011-09-28 16:23:15,362 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:16,287 DEBUG [WebServer] Incoming connection from /192.168.1.123:58220
2011-09-28 16:23:16,290 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:16,290 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:16,385 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:16,393 DEBUG [WebServer] Incoming connection from /192.168.1.123:58219
2011-09-28 16:23:16,397 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:16,397 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:16,494 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:16,515 DEBUG [WebServer] Incoming connection from /192.168.1.123:58218
2011-09-28 16:23:16,517 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:16,517 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:16,606 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V, 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, startIndex = 0, count = 1, sortCriteria =
2011-09-28 16:23:16,608 DEBUG [LocalContentCacheDecorator] Stored entry in the cache (local_default), returning it
2011-09-28 16:23:16,620 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:16,631 DEBUG [WebServer] Incoming connection from /192.168.1.123:58217
2011-09-28 16:23:16,634 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:16,634 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:16,743 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V, browseFlag = BrowseDirectChildren, 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, startIndex = 0, count = 10, sortCriteria =
2011-09-28 16:23:16,785 DEBUG [VideoDAOImpl] Retrieving number of video initials
2011-09-28 16:23:17,172 DEBUG [VideoDAOImpl] Retrieving number of videos of type 2
2011-09-28 16:23:17,203 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:01:27
2011-09-28 16:23:17,527 DEBUG [WebServer] Incoming connection from /192.168.1.123:58216
2011-09-28 16:23:17,708 DEBUG [DeviceDescriptionRequestHandler] DeviceDescription request received for device 7e77d808-59f9-342a-8af9-5da50f774213 from 192.168.1.123 (headers = [Host: 192.168.1.247:8895,Date: Wed, 28 Sep 2011 16:26:51 GMT,User-Agent: UPnP/1.0,X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";])
2011-09-28 16:23:17,708 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:17,710 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:17,720 DEBUG [DeviceDescriptionRequestHandler] Sending DeviceDescription XML back using profile 'Playstation 3'
2011-09-28 16:23:17,729 DEBUG [SeriesDAOImpl] Retrieving number of series
2011-09-28 16:23:17,787 DEBUG [RepositoryDAOImpl] Retrieving number of repositories for VIDEO
2011-09-28 16:23:17,814 DEBUG [VideoDAOImpl] Retrieving number of 10 last viewed videos
2011-09-28 16:23:17,855 DEBUG [VideoDAOImpl] Retrieving number of 10 last added videos
2011-09-28 16:23:17,855 DEBUG [VideoDAOImpl] Retrieving number of videos of type 0
2011-09-28 16:23:17,888 DEBUG [GenreDAOImpl] Retrieving number of genres for VIDEO
2011-09-28 16:23:17,973 DEBUG [PersonDAOImpl] Retrieving number of person initials for role ACTOR
2011-09-28 16:23:18,229 DEBUG [PersonDAOImpl] Retrieving number of person initials for role DIRECTOR
2011-09-28 16:23:18,258 DEBUG [PersonDAOImpl] Retrieving number of person initials for role PRODUCER
2011-09-28 16:23:18,268 DEBUG [LocalContentCacheDecorator] Stored entry in the cache (local_default), returning it
2011-09-28 16:23:18,280 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:18,411 DEBUG [WebServer] Incoming connection from /192.168.1.123:58215
2011-09-28 16:23:18,412 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:18,412 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:18,508 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:18,512 DEBUG [WebServer] Incoming connection from /192.168.1.123:58214
2011-09-28 16:23:18,513 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:18,513 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:18,607 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V, 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, startIndex = 0, count = 1, sortCriteria =
2011-09-28 16:23:18,607 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_default), returning it
2011-09-28 16:23:18,610 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:23,461 DEBUG [WebServer] Incoming connection from /192.168.1.123:58213
2011-09-28 16:23:23,464 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:23,465 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:23,555 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:23,565 DEBUG [WebServer] Incoming connection from /192.168.1.123:58212
2011-09-28 16:23:23,569 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:23,570 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:23,664 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:23,679 DEBUG [WebServer] Incoming connection from /192.168.1.123:58211
2011-09-28 16:23:23,682 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:23,683 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:23,776 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_LV, 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, startIndex = 0, count = 1, sortCriteria =
2011-09-28 16:23:23,778 DEBUG [VideoDAOImpl] Retrieving number of 10 last viewed videos
2011-09-28 16:23:23,806 DEBUG [LocalContentCacheDecorator] Stored entry in the cache (local_resetafterplay), returning it
2011-09-28 16:23:23,817 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:23,826 DEBUG [WebServer] Incoming connection from /192.168.1.123:58210
2011-09-28 16:23:23,829 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:23,829 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:23,942 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_LV, browseFlag = BrowseDirectChildren, 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, startIndex = 0, count = 10, sortCriteria =
2011-09-28 16:23:23,945 DEBUG [VideoDAOImpl] Retrieving list of 10 last viewed videos (from=0, count=10)
2011-09-28 16:23:24,415 DEBUG [GenreDAOImpl] Reading a Genre (id = 16)
2011-09-28 16:23:24,483 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1028)
2011-09-28 16:23:24,530 DEBUG [MediaItemDAOImpl] Getting file of media item 1028
2011-09-28 16:23:24,701 DEBUG [VideoDAOImpl] Reading a Video (id = 1028)
2011-09-28 16:23:24,730 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1028 and profile Playstation 3
2011-09-28 16:23:24,733 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi.mkv: AVC_TS_MP_HD_AC3_ISO
2011-09-28 16:23:24,739 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1113)
2011-09-28 16:23:24,808 DEBUG [GenreDAOImpl] Reading a Genre (id = 2)
2011-09-28 16:23:24,809 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1090)
2011-09-28 16:23:24,811 DEBUG [MediaItemDAOImpl] Getting file of media item 1090
2011-09-28 16:23:24,828 DEBUG [VideoDAOImpl] Reading a Video (id = 1090)
2011-09-28 16:23:24,837 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1090 and profile Playstation 3
2011-09-28 16:23:24,837 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file tron.legacy.2010.bluray.1080p.dts.x264-chd.mkv: AVC_TS_MP_HD_AC3_ISO
2011-09-28 16:23:24,838 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1147)
2011-09-28 16:23:24,843 DEBUG [GenreDAOImpl] Reading a Genre (id = 7)
2011-09-28 16:23:24,845 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 997)
2011-09-28 16:23:24,846 DEBUG [MediaItemDAOImpl] Getting file of media item 997
2011-09-28 16:23:24,857 DEBUG [VideoDAOImpl] Reading a Video (id = 997)
2011-09-28 16:23:24,859 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 997 and profile Playstation 3
2011-09-28 16:23:24,859 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file American.Graffiti.1973.1080p.BluRay.X264-AMIABLE.mkv: AVC_TS_MP_HD_AC3_ISO
2011-09-28 16:23:24,859 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1101)
2011-09-28 16:23:24,861 DEBUG [GenreDAOImpl] Reading a Genre (id = 2)
2011-09-28 16:23:24,867 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1000)
2011-09-28 16:23:24,868 DEBUG [MediaItemDAOImpl] Getting file of media item 1000
2011-09-28 16:23:24,878 DEBUG [VideoDAOImpl] Reading a Video (id = 1000)
2011-09-28 16:23:24,879 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1000 and profile Playstation 3
2011-09-28 16:23:24,880 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1104)
2011-09-28 16:23:24,900 DEBUG [GenreDAOImpl] Reading a Genre (id = 8)
2011-09-28 16:23:24,901 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 999)
2011-09-28 16:23:24,903 DEBUG [MediaItemDAOImpl] Getting file of media item 999
2011-09-28 16:23:24,907 DEBUG [VideoDAOImpl] Reading a Video (id = 999)
2011-09-28 16:23:24,908 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 999 and profile Playstation 3
2011-09-28 16:23:24,909 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1103)
2011-09-28 16:23:24,910 DEBUG [GenreDAOImpl] Reading a Genre (id = 2)
2011-09-28 16:23:24,911 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 998)
2011-09-28 16:23:24,913 DEBUG [MediaItemDAOImpl] Getting file of media item 998
2011-09-28 16:23:24,924 DEBUG [VideoDAOImpl] Reading a Video (id = 998)
2011-09-28 16:23:24,925 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 998 and profile Playstation 3
2011-09-28 16:23:24,926 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1102)
2011-09-28 16:23:24,931 DEBUG [GenreDAOImpl] Reading a Genre (id = 17)
2011-09-28 16:23:24,932 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1107)
2011-09-28 16:23:24,934 DEBUG [MediaItemDAOImpl] Getting file of media item 1107
2011-09-28 16:23:24,953 DEBUG [VideoDAOImpl] Reading a Video (id = 1107)
2011-09-28 16:23:24,956 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1107 and profile Playstation 3
2011-09-28 16:23:24,956 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file No.Country.for.Old.Men.2007.Blu-ray.1080p.DTS.x264-CtrlHD.mkv: AVC_TS_MP_HD_AC3_ISO
2011-09-28 16:23:24,956 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1157)
2011-09-28 16:23:24,962 DEBUG [GenreDAOImpl] Reading a Genre (id = 26)
2011-09-28 16:23:24,972 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1501)
2011-09-28 16:23:24,974 DEBUG [MediaItemDAOImpl] Getting file of media item 1501
2011-09-28 16:23:24,998 DEBUG [VideoDAOImpl] Reading a Video (id = 1501)
2011-09-28 16:23:25,001 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1501 and profile Playstation 3
2011-09-28 16:23:25,001 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file Inside.Job.2010.Blu-ray.1080p.x264.DTS-Dolby.(DMT).mkv: AVC_TS_MP_HD_AC3_ISO
2011-09-28 16:23:25,001 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1565)
2011-09-28 16:23:25,007 DEBUG [GenreDAOImpl] Reading a Genre (id = 2)
2011-09-28 16:23:25,007 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1034)
2011-09-28 16:23:25,010 DEBUG [MediaItemDAOImpl] Getting file of media item 1034
2011-09-28 16:23:25,029 DEBUG [VideoDAOImpl] Reading a Video (id = 1034)
2011-09-28 16:23:25,031 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1034 and profile Playstation 3
2011-09-28 16:23:25,031 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file Fast.Five.2011.BluRay.1080p.DTS.x264-CHD.mkv: AVC_TS_MP_HD_AC3_ISO
2011-09-28 16:23:25,031 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1116)
2011-09-28 16:23:25,033 DEBUG [GenreDAOImpl] Reading a Genre (id = 2)
2011-09-28 16:23:25,034 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1015)
2011-09-28 16:23:25,035 DEBUG [MediaItemDAOImpl] Getting file of media item 1015
2011-09-28 16:23:25,054 DEBUG [VideoDAOImpl] Reading a Video (id = 1015)
2011-09-28 16:23:25,055 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 1015 and profile Playstation 3
2011-09-28 16:23:25,055 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file 2012.2009.BluRay.1080p.DTS.x264-CHD.mkv: AVC_TS_MP_HD_AC3_ISO
2011-09-28 16:23:25,056 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1106)
2011-09-28 16:23:25,061 DEBUG [VideoDAOImpl] Retrieving number of 10 last viewed videos
2011-09-28 16:23:25,064 DEBUG [LocalContentCacheDecorator] Stored entry in the cache (local_resetafterplay), returning it
2011-09-28 16:23:25,109 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:25,391 DEBUG [WebServer] Incoming connection from /192.168.1.123:58209
2011-09-28 16:23:25,394 DEBUG [ResourceTransportRequestHandler] GET /resource/1113/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,395 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:25,397 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:25,399 DEBUG [ResourceTransportRequestHandler] Request for resource 1113 and type 'COVER_IMAGE' received
2011-09-28 16:23:25,401 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1113)
2011-09-28 16:23:25,406 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1113
2011-09-28 16:23:25,409 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:25,410 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:25,410 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:25,410 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:25 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,516 DEBUG [WebServer] Incoming connection from /192.168.1.123:58208
2011-09-28 16:23:25,518 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"' from 192.168.1.123:
2011-09-28 16:23:25,518 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:25,570 DEBUG [WebServer] Incoming connection from /192.168.1.123:58207
2011-09-28 16:23:25,576 DEBUG [ResourceTransportRequestHandler] GET /resource/1147/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,578 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:25,580 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:25,580 DEBUG [ResourceTransportRequestHandler] Request for resource 1147 and type 'COVER_IMAGE' received
2011-09-28 16:23:25,580 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1147)
2011-09-28 16:23:25,588 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1147
2011-09-28 16:23:25,589 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:25,589 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:25,589 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:25,589 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:25 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,616 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:25,622 DEBUG [WebServer] Incoming connection from /192.168.1.123:58206
2011-09-28 16:23:25,623 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.1.123:
2011-09-28 16:23:25,623 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:25,718 DEBUG [ContentDirectory] Browse() called for renderer Playstation 3 (profile 4) with parameters: objectID = V_LV, 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, startIndex = 0, count = 1, sortCriteria =
2011-09-28 16:23:25,719 DEBUG [LocalContentCacheDecorator] Found entry in the cache (local_resetafterplay), returning it
2011-09-28 16:23:25,723 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-09-28 16:23:25,724 DEBUG [WebServer] Incoming connection from /192.168.1.123:58205
2011-09-28 16:23:25,725 DEBUG [ResourceTransportRequestHandler] GET /resource/1101/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,726 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:25,727 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:25,727 DEBUG [ResourceTransportRequestHandler] Request for resource 1101 and type 'COVER_IMAGE' received
2011-09-28 16:23:25,727 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1101)
2011-09-28 16:23:25,729 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1101
2011-09-28 16:23:25,729 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:25,729 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:25,729 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:25,729 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:25 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,854 DEBUG [WebServer] Incoming connection from /192.168.1.123:58204
2011-09-28 16:23:25,855 DEBUG [ResourceTransportRequestHandler] GET /resource/1104/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,855 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:25,856 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:25,856 DEBUG [ResourceTransportRequestHandler] Request for resource 1104 and type 'COVER_IMAGE' received
2011-09-28 16:23:25,857 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1104)
2011-09-28 16:23:25,858 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1104
2011-09-28 16:23:25,858 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:25,858 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:25,858 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:25,859 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:25 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,985 DEBUG [WebServer] Incoming connection from /192.168.1.123:58203
2011-09-28 16:23:25,986 DEBUG [ResourceTransportRequestHandler] GET /resource/1103/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:25,986 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:25,987 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:25,988 DEBUG [ResourceTransportRequestHandler] Request for resource 1103 and type 'COVER_IMAGE' received
2011-09-28 16:23:25,988 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1103)
2011-09-28 16:23:25,989 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1103
2011-09-28 16:23:25,990 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:25,990 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:25,990 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:25,990 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:25 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,102 DEBUG [WebServer] Incoming connection from /192.168.1.123:58202
2011-09-28 16:23:26,102 DEBUG [ResourceTransportRequestHandler] GET /resource/1102/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,103 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:26,104 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:26,105 DEBUG [ResourceTransportRequestHandler] Request for resource 1102 and type 'COVER_IMAGE' received
2011-09-28 16:23:26,105 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1102)
2011-09-28 16:23:26,108 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1102
2011-09-28 16:23:26,108 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:26,108 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:26,108 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:26,108 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:26 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,221 DEBUG [WebServer] Incoming connection from /192.168.1.123:58201
2011-09-28 16:23:26,222 DEBUG [ResourceTransportRequestHandler] GET /resource/1157/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,222 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:26,224 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:26,224 DEBUG [ResourceTransportRequestHandler] Request for resource 1157 and type 'COVER_IMAGE' received
2011-09-28 16:23:26,224 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1157)
2011-09-28 16:23:26,226 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1157
2011-09-28 16:23:26,226 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:26,226 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:26,226 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:26,226 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:26 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,319 DEBUG [WebServer] Incoming connection from /192.168.1.123:58200
2011-09-28 16:23:26,319 DEBUG [ResourceTransportRequestHandler] GET /resource/1565/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,320 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:26,321 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:26,321 DEBUG [ResourceTransportRequestHandler] Request for resource 1565 and type 'COVER_IMAGE' received
2011-09-28 16:23:26,322 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1565)
2011-09-28 16:23:26,323 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1565
2011-09-28 16:23:26,323 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:26,323 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:26,324 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:26,324 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:26 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,419 DEBUG [WebServer] Incoming connection from /192.168.1.123:58199
2011-09-28 16:23:26,419 DEBUG [ResourceTransportRequestHandler] GET /resource/1116/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,419 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:26,421 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:26,421 DEBUG [ResourceTransportRequestHandler] Request for resource 1116 and type 'COVER_IMAGE' received
2011-09-28 16:23:26,421 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1116)
2011-09-28 16:23:26,423 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1116
2011-09-28 16:23:26,423 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:26,423 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:26,423 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:26,430 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:26 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,552 DEBUG [WebServer] Incoming connection from /192.168.1.123:58198
2011-09-28 16:23:26,553 DEBUG [ResourceTransportRequestHandler] GET /resource/1106/COVER_IMAGE HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:26,554 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:26,555 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:26,556 DEBUG [ResourceTransportRequestHandler] Request for resource 1106 and type 'COVER_IMAGE' received
2011-09-28 16:23:26,556 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1106)
2011-09-28 16:23:26,558 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 1106
2011-09-28 16:23:26,558 DEBUG [ResourceTransportRequestHandler] Entity will be consumed till the end
2011-09-28 16:23:26,558 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: -1
2011-09-28 16:23:26,559 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-09-28 16:23:26,559 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: image/jpeg,Date: Wed, 28 Sep 2011 16:23:26 GMT,Server: FreeBSD, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Interactive]]
2011-09-28 16:23:33,319 DEBUG [WebServer] Incoming connection from /192.168.1.123:58197
2011-09-28 16:23:33,321 DEBUG [ResourceTransportRequestHandler] GET /resource/1028/MEDIA_ITEM/AVC_TS_MP_HD_AC3_ISO$0 HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Streaming,TimeSeekRange.dlna.org: npt=0.000-]]
2011-09-28 16:23:33,321 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:33,325 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:33,327 DEBUG [ResourceTransportRequestHandler] Request for resource 1028 and type 'MEDIA_ITEM' received
2011-09-28 16:23:33,327 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1028)
2011-09-28 16:23:33,335 DEBUG [VideoDAOImpl] Reading a Video (id = 1028)
2011-09-28 16:23:33,351 DEBUG [VideoDeliveryEngine] Delivering item '1028' for client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:33,354 DEBUG [VideoDeliveryEngine] Delivering file 'Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi.mkv' using transcoding
2011-09-28 16:23:33,356 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:33,362 DEBUG [MediaItemDAOImpl] Getting file of media item 1028
2011-09-28 16:23:33,381 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: /mnt/Media/Movies/DTS/Core (1.5Mbps)/Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi/Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi.mkv
2011-09-28 16:23:33,384 DEBUG [ProcessExecutor] Starting ffmpeg -i /mnt/Media/Movies/DTS/Core (1.5Mbps)/Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi/Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi.mkv -y -vcodec copy -vbsf h264_mp4toannexb -copyts -acodec ac3 -ab 192k -ac 2 -map 0:0 -map 0:1 -sn -f mpegts /var/tmp/Serviio/transcoding-temp-1028-MPEG2TS.stf
2011-09-28 16:23:34,234 WARN [ProcessExecutor] Process ffmpeg has a return code of 1! This is a possible error.
2011-09-28 16:23:34,235 DEBUG [TranscodingJobListener] Transcoding finished; successful: false
2011-09-28 16:23:34,505 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.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:116)
at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:89)
at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:116)
at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:115)
at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:54)
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:187)
2011-09-28 16:23:34,515 DEBUG [WebServer] Incoming connection from /192.168.1.123:58196
2011-09-28 16:23:34,519 DEBUG [ResourceTransportRequestHandler] GET /resource/1028/MEDIA_ITEM/AVC_TS_MP_HD_AC3_ISO$0 HTTP/1.1, headers = [Host: 192.168.1.247:8895,User-Agent: PLAYSTATION 3,Connection: Keep-Alive,Accept-Encoding: identity,transferMode.dlna.org: Streaming,TimeSeekRange.dlna.org: npt=0.000-]]
2011-09-28 16:23:34,519 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.123
2011-09-28 16:23:34,520 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:34,521 DEBUG [ResourceTransportRequestHandler] Request for resource 1028 and type 'MEDIA_ITEM' received
2011-09-28 16:23:34,521 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1028)
2011-09-28 16:23:34,522 DEBUG [VideoDAOImpl] Reading a Video (id = 1028)
2011-09-28 16:23:34,524 DEBUG [VideoDeliveryEngine] Delivering item '1028' for client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:34,524 DEBUG [VideoDeliveryEngine] Delivering file 'Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi.mkv' using transcoding
2011-09-28 16:23:34,524 DEBUG [AbstractTranscodingDeliveryEngine] A suitable transcoding job already exists, re-use it for client 'IPAddress=/192.168.1.123, Profile=Playstation 3'
2011-09-28 16:23:34,524 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.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:116)
at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:89)
at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:116)
at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:115)
at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:54)
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:187)
2011-09-28 16:23:39,800 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:MediaServer:1 from address /192.168.1.109:49153
2011-09-28 16:23:39,803 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.109:49153
--------------------------------------------------------------------------------------------------------------------
The following are the results of a manually executed "ffmpeg" against the "Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi.mkv" file.
/usr/bin# ffmpeg -i "/mnt/Media/Movies/DTS/Core (1.5Mbps)/Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi"
FFmpeg version 0.5, Copyright (c) 2000-2009 Fabrice Bellard, et al.
configuration: --prefix=/usr/local --mandir=/usr/local/man --enable-shared --enable-gpl --enable-swscale --enable-postproc --enable-avfilter --enable-avfilter-lavf --enable-pthreads --enable-memalign-hack --cc=cc --extra-cflags=-I/usr/local/include/vorbis -I/usr/local/include --extra-ldflags=-L/usr/local/lib --extra-libs=-pthread --disable-debug --disable-sse --disable-mmx --disable-libamr-nb --disable-libamr-wb --disable-libdirac --disable-libfaac --enable-libfaad --enable-libfaadbin --disable-libgsm --disable-vhook --enable-ipv6 --disable-libmp3lame --disable-libopenjpeg --enable-libschroedinger --disable-ffplay --disable-libspeex --enable-libtheora --enable-libvorbis --disable-x11grab --enable-libx264 --enable-libxvid
libavutil 49.15. 0 / 49.15. 0
libavcodec 52.20. 0 / 52.20. 0
libavformat 52.31. 0 / 52.31. 0
libavdevice 52. 1. 0 / 52. 1. 0
libavfilter 0. 4. 0 / 0. 4. 0
libswscale 0. 7. 1 / 0. 7. 1
libpostproc 51. 2. 0 / 51. 2. 0
built on Mar 7 2010 00:34:41, gcc: 4.2.1 20070719 [FreeBSD]
/mnt/Media/Movies/DTS/Core (1.5Mbps)/Crazy.Heart.2009.1080p.BluRay.x264.DTS-WiKi: Unknown format
Note: The "Core (1.5Mbps)" directory has spaces in it, so the path is encapsulated in quotes (above)
