Testing with Sony KDL32V5810

I have Serviio running on Windows Home Server (WHS).
Serviio worked 'out of the box' with the Sony TV. Some observations:
* I've played our 'home movies', in MPEG2 format, full screen and without problems. There's an occasional skip in the video but the network topology is definitely sub-optimal so I'm quite surprised it works at all...
* The fact that under each category (Audio/Video/Image) on the TV I see listed "folders" for all three, only one of which is playable, has been noted by others. It's puzzling but nothing more.
* Audio seems fine.
* The big disappointment is images (photos). A high resolution image (12 MPixel, about 2MB file) takes 4-8s to display, making a slideshow quite tedious. Much more seriously, browsing is severely limited: the 'Year' view appears reasonably quickly but in my case a year's worth of pictures is about 5000, so finding a specific one takes a long time. However, my pictures are arranged in folders by shooting day so the 'Folder' view ought to be easier. However, I find that the 'folder' view, once I descend lower than the top levels of the structure, takes so long to update (minutes) that I've never had the patience to wait for it. This is the case even when the folder in question contains only six or so pictures. So something's wrong here: I have no idea how to find out where the bottleneck is.

I'm delighted with and impressed by Serviio, and very grateful for your work.
Phil

[zip]

Please post detailed log (see HOWTO) of Serviio when you browse your images that take too long.

Obtaining a useful log is proving to be quite difficult. With my Shared Folders configured the way I want them, it seems that Serviio runs continuously at 100% cpu, and a library update takes longer than the 5 minute update period. This means that, if I turn on logging, the log file builds continuously with routine entries.

So: I decided to reduce the number of files/folders in the database. Unfortunately when I remove the entries from the shared folders list and click "Save", the Save button stays 'pressed' and nothing further changes unless I restart Serviio (service and console) - in which case the changes to my shared folders are lost.

[zip]

No, there is a 5 minute gap after library update is finished....

How many files do you have?

When you save new folder setup it'll remove entries for files in removed folders, which might take a while if your library is huge. I think it also kicks off library refresh immediately after.

Well, I've been watching for several days now and I've not seen a moment when Serviio is running and cpu has been less than 95%.

Anyhow, I've finally managed to cut down the library and the browsing speed improved dramatically, even for a folder with just a few photos in it that was very slow before. Here's a log from that browse (not sure which bit you want to see):

20:01:14,929 DEBUG [LibraryUpdaterThread] Looking for files to share in folder: D:\shares\Photos\Family\1978
20:01:14,929 DEBUG [LibraryUpdaterThread] Found file '3713439119_a84ba4a240_b.jpg', checking if it's already in the Library
20:01:14,929 DEBUG [MediaItemDAOImpl] Checking if DB already contains media item 3713439119_a84ba4a240_b.jpg
20:01:15,070 DEBUG [MediaItemDAOImpl] Media item 3713439119_a84ba4a240_b.jpg already exists in DB
20:01:15,070 DEBUG [LibraryUpdaterThread] Found file '3713446613_084f1d3ef5_b.jpg', checking if it's already in the Library
20:01:15,070 DEBUG [MediaItemDAOImpl] Checking if DB already contains media item 3713446613_084f1d3ef5_b.jpg
20:01:15,085 DEBUG [MediaItemDAOImpl] Media item 3713446613_084f1d3ef5_b.jpg already exists in DB
20:01:15,085 DEBUG [LibraryUpdaterThread] Found file '3713449289_a44c566543_b.jpg', checking if it's already in the Library
20:01:15,085 DEBUG [MediaItemDAOImpl] Checking if DB already contains media item 3713449289_a44c566543_b.jpg
20:01:15,085 DEBUG [MediaItemDAOImpl] Media item 3713449289_a44c566543_b.jpg already exists in DB
20:01:15,085 DEBUG [LibraryUpdaterThread] Found file '3714246422_5601cbb2c7_b.jpg', checking if it's already in the Library
20:01:15,085 DEBUG [MediaItemDAOImpl] Checking if DB already contains media item 3714246422_5601cbb2c7_b.jpg
20:01:15,085 DEBUG [MediaItemDAOImpl] Media item 3714246422_5601cbb2c7_b.jpg already exists in DB
20:01:15,101 DEBUG [LibraryUpdaterThread] Found file '3714248626_bbbe768895_b.jpg', checking if it's already in the Library
20:01:15,101 DEBUG [MediaItemDAOImpl] Checking if DB already contains media item 3714248626_bbbe768895_b.jpg
20:01:15,101 DEBUG [MediaItemDAOImpl] Media item 3714248626_bbbe768895_b.jpg already exists in DB
20:01:15,101 DEBUG [LibraryUpdaterThread] Found file '3716761883_5dd8556357_b.jpg', checking if it's already in the Library
20:01:15,101 DEBUG [MediaItemDAOImpl] Checking if DB already contains media item 3716761883_5dd8556357_b.jpg
20:01:15,101 DEBUG [MediaItemDAOImpl] Media item 3716761883_5dd8556357_b.jpg already exists in DB
20:01:15,101 DEBUG [LibraryUpdaterThread] Found file '3716763729_bf17a4c9ae_b.jpg', checking if it's already in the Library
20:01:15,101 DEBUG [MediaItemDAOImpl] Checking if DB already contains media item 3716763729_bf17a4c9ae_b.jpg
20:01:15,116 DEBUG [MediaItemDAOImpl] Media item 3716763729_bf17a4c9ae_b.jpg already exists in DB
20:01:15,116 DEBUG [LibraryUpdaterThread] Found file '3717572690_cdd9b05a23_b.jpg', checking if it's already in the Library
20:01:15,116 DEBUG [MediaItemDAOImpl] Checking if DB already contains media item 3717572690_cdd9b05a23_b.jpg
20:01:15,116 DEBUG [MediaItemDAOImpl] Media item 3717572690_cdd9b05a23_b.jpg already exists in DB
20:01:15,116 DEBUG [LibraryUpdaterThread] Looking for updated metadata
20:01:15,116 DEBUG [MediaItemDAOImpl] Reading MediaItems for Repository (id = 10)
20:01:15,148 DEBUG [MetadataExtractorConfigDAOImpl] Reading a list of Extractor configuration for type AUDIO
20:01:15,163 DEBUG [MetadataExtractorConfigDAOImpl] Reading a list of Extractor configuration for type VIDEO
20:01:15,163 DEBUG [MetadataExtractorConfigDAOImpl] Reading a list of Extractor configuration for type IMAGE
20:01:15,163 DEBUG [MetadataDescriptorDAOImpl] Reading MetadataDescriptor for MediaItem (id = 41885) and extractor EMBEDDED
20:01:15,210 DEBUG [MediaItemDAOImpl] Getting file of media item 41885
20:01:15,210 DEBUG [MetadataDescriptorDAOImpl] Reading MetadataDescriptor for MediaItem (id = 41886) and extractor EMBEDDED
20:01:15,210 DEBUG [MediaItemDAOImpl] Getting file of media item 41886
20:01:15,210 DEBUG [MetadataDescriptorDAOImpl] Reading MetadataDescriptor for MediaItem (id = 41887) and extractor EMBEDDED
20:01:15,210 DEBUG [MediaItemDAOImpl] Getting file of media item 41887
20:01:15,226 DEBUG [MetadataDescriptorDAOImpl] Reading MetadataDescriptor for MediaItem (id = 41888) and extractor EMBEDDED
20:01:15,226 DEBUG [MediaItemDAOImpl] Getting file of media item 41888
20:01:15,226 DEBUG [MetadataDescriptorDAOImpl] Reading MetadataDescriptor for MediaItem (id = 41889) and extractor EMBEDDED
20:01:15,226 DEBUG [MediaItemDAOImpl] Getting file of media item 41889
20:01:15,241 DEBUG [MetadataDescriptorDAOImpl] Reading MetadataDescriptor for MediaItem (id = 41890) and extractor EMBEDDED
20:01:15,241 DEBUG [MediaItemDAOImpl] Getting file of media item 41890
20:01:15,241 DEBUG [MetadataDescriptorDAOImpl] Reading MetadataDescriptor for MediaItem (id = 41891) and extractor EMBEDDED
20:01:15,241 DEBUG [MediaItemDAOImpl] Getting file of media item 41891
20:01:15,241 DEBUG [MetadataDescriptorDAOImpl] Reading MetadataDescriptor for MediaItem (id = 41892) and extractor EMBEDDED
20:01:15,257 DEBUG [MediaItemDAOImpl] Getting file of media item 41892
20:01:15,257 DEBUG [LibraryUpdaterThread] Updating dirty metadata
20:01:15,257 DEBUG [MediaItemDAOImpl] Reading dirty MediaItems for Repository (id = 10)
20:02:07,335 DEBUG [DiscoverySearchListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:MediaServer:1 from address /192.168.1.68:64649
20:02:07,351 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s)
20:02:07,445 DEBUG [DiscoverySearchListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:MediaServer:1 from address /192.168.1.68:64649
20:02:07,445 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s)
20:02:07,570 DEBUG [DiscoverySearchListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:MediaServer:1 from address /192.168.1.68:64649
20:02:07,570 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s)
20:02:07,585 DEBUG [WebServer] Incoming connection from /192.168.1.68:61127
20:02:07,585 DEBUG [DeviceDescriptionRequestHandler] DeviceDescription request received for device 163bb252-8bb9-344d-a704-55ad0ac6ba08 from UPnP/1.0
20:02:07,601 DEBUG [DeviceDescriptionRequestHandler] Sending DeviceDescription XML back using profile 'Generic DLNA profile'
20:02:07,663 DEBUG [WebServer] Incoming connection from /192.168.1.68:61128
20:02:07,663 DEBUG [ServiceDescriptionRequestHandler] ServiceDescription request received for service ConnectionManager
20:02:07,695 DEBUG [ServiceDescriptionRequestHandler] Sending ServiceDescription XML back
20:02:07,851 DEBUG [WebServer] Incoming connection from /192.168.1.68:61130
20:02:07,851 DEBUG [ServiceDescriptionRequestHandler] ServiceDescription request received for service ContentDirectory
20:02:07,991 DEBUG [ServiceDescriptionRequestHandler] Sending ServiceDescription XML back
20:02:08,210 DEBUG [WebServer] Incoming connection from /192.168.1.68:61132
20:02:08,210 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSortCapabilities"' from UPnP/1.0 DLNADOC/1.50:
20:02:08,741 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
20:02:08,773 DEBUG [WebServer] Incoming connection from /192.168.1.68:61133
20:02:08,788 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ConnectionManager:1#GetProtocolInfo"' from UPnP/1.0 DLNADOC/1.50:
20:02:08,913 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
20:02:10,195 DEBUG [DiscoverySearchListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:MediaServer:1 from address /192.168.1.68:64649
20:02:10,195 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s)
20:02:10,570 DEBUG [DiscoverySearchListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:MediaServer:1 from address /192.168.1.68:64649
20:02:10,570 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s)
20:02:10,570 DEBUG [WebServer] Incoming connection from /192.168.1.68:61134
20:02:10,585 DEBUG [DeviceDescriptionRequestHandler] DeviceDescription request received for device 163bb252-8bb9-344d-a704-55ad0ac6ba08 from UPnP/1.0
20:02:10,585 DEBUG [DeviceDescriptionRequestHandler] Sending DeviceDescription XML back using profile 'Generic DLNA profile'
20:02:10,648 DEBUG [WebServer] Incoming connection from /192.168.1.68:61135
20:02:10,648 DEBUG [ServiceDescriptionRequestHandler] ServiceDescription request received for service ConnectionManager
20:02:10,648 DEBUG [ServiceDescriptionRequestHandler] Sending ServiceDescription XML back
20:02:10,663 DEBUG [DiscoverySearchListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:MediaServer:1 from address /192.168.1.68:64649
20:02:10,663 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s)
20:02:10,804 DEBUG [WebServer] Incoming connection from /192.168.1.68:61136
20:02:10,804 DEBUG [ServiceDescriptionRequestHandler] ServiceDescription request received for service ContentDirectory
20:02:10,804 DEBUG [ServiceDescriptionRequestHandler] Sending ServiceDescription XML back
20:02:11,007 DEBUG [WebServer] Incoming connection from /192.168.1.68:61137
20:02:11,007 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSortCapabilities"' from UPnP/1.0 DLNADOC/1.50:
20:02:11,288 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
20:02:11,304 DEBUG [WebServer] Incoming connection from /192.168.1.68:61138
20:02:11,304 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ConnectionManager:1#GetProtocolInfo"' from UPnP/1.0 DLNADOC/1.50:
20:02:11,429 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
20:02:13,476 DEBUG [WebServer] Incoming connection from /192.168.1.68:61141
20:02:13,476 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from UPnP/1.0 DLNADOC/1.50:
20:02:14,491 DEBUG [ContentDirectory] Browse() called for profile Generic DLNA profile with parameters: objectID = 0, browseFlag = BrowseDirectChildren, filter = dc:title,av:mediaClass,dc:date,@childCount,res,upnp:class,res@resolution,upnp:album,upnp:genre,upnp:albumArtURI,upnp:albumArtURI@dlna:profileID,dc:creator,res@size,res@duration,res@bitrate,res@protocolInfo, startIndex = 0, count = 10, sortCriteria =
20:02:14,523 INFO [ContentDirectoryDefinitionParser] Parsing ContentDirectory definition
20:02:14,523 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=0, title=Serviio Media Library, class=CONTAINER
20:02:14,570 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=A, title=Audio, class=CONTAINER
20:02:14,585 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=A_A, title=Artists, class=CONTAINER
20:02:14,601 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.person.ListArtistsByNameCommand, containerClass=MUSIC_ARTIST, itemClass=null, idPrefix=ART, recursive=false
20:02:14,616 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.audio.ListAlbumsForArtistCommand, containerClass=MUSIC_ALBUM, itemClass=null, idPrefix=A, recursive=false
20:02:14,648 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.audio.ListSongsForArtistAndAlbumCommand, containerClass=null, itemClass=MUSIC_TRACK, idPrefix=S, recursive=false
20:02:14,663 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=A_F, title=Folders, class=CONTAINER
20:02:14,835 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.audio.ListAudioFoldersByNameCommand, containerClass=STORAGE_FOLDER, itemClass=MUSIC_TRACK, idPrefix=FOL, recursive=true
20:02:14,851 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=A_G, title=Genres, class=CONTAINER
20:02:14,866 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.audio.ListAudioGenresByNameCommand, containerClass=MUSIC_GENRE, itemClass=null, idPrefix=GEN, recursive=false
20:02:14,882 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.audio.ListSongsForGenreCommand, containerClass=null, itemClass=MUSIC_TRACK, idPrefix=S, recursive=false
20:02:14,898 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=A_T, title=Titles, class=CONTAINER
20:02:14,913 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.audio.ListSongInitialsCommand, containerClass=CONTAINER, itemClass=null, idPrefix=INI, recursive=false
20:02:14,929 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.audio.ListSongsForInitialCommand, containerClass=null, itemClass=MUSIC_TRACK, idPrefix=S, recursive=false
20:02:14,945 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=A_S, title=All songs, class=CONTAINER
20:02:14,945 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.audio.ListAllSongsCommand, containerClass=null, itemClass=MUSIC_TRACK, idPrefix=S, recursive=false
20:02:14,960 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=A_AS, title=Artist Songs, class=CONTAINER
20:02:14,976 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.person.ListArtistsByNameCommand, containerClass=MUSIC_ARTIST, itemClass=null, idPrefix=ART_S, recursive=false
20:02:14,991 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.audio.ListSongsForArtistCommand, containerClass=null, itemClass=MUSIC_TRACK, idPrefix=S, recursive=false
20:02:15,007 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=A_ALB, title=All albums, class=CONTAINER
20:02:15,023 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.audio.ListAllAlbumsCommand, containerClass=MUSIC_ALBUM, itemClass=null, idPrefix=ALB, recursive=false
20:02:15,038 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.audio.ListSongsForAlbumCommand, containerClass=null, itemClass=MUSIC_TRACK, idPrefix=S, recursive=false
20:02:15,038 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=I, title=Image, class=CONTAINER
20:02:15,054 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=I_A, title=Albums, class=CONTAINER
20:02:15,257 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.image.ListFlatImageFoldersByNameCommand, containerClass=CONTAINER, itemClass=null, idPrefix=ALB, recursive=false
20:02:15,273 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.image.ListImagesForFolderCommand, containerClass=null, itemClass=PHOTO, idPrefix=I, recursive=false
20:02:15,273 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=I_F, title=Folders, class=CONTAINER
20:02:15,304 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.image.ListImageFoldersByNameCommand, containerClass=STORAGE_FOLDER, itemClass=PHOTO, idPrefix=FOL, recursive=true
20:02:15,304 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=I_Y, title=Year, class=CONTAINER
20:02:15,320 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.image.ListImagesCreationYearsCommand, containerClass=CONTAINER, itemClass=null, idPrefix=YEAR, recursive=false
20:02:15,335 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.image.ListImagesForCreationYearCommand, containerClass=null, itemClass=PHOTO, idPrefix=I, recursive=false
20:02:15,351 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=I_T, title=Timeline, class=CONTAINER
20:02:15,366 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.image.ListImagesCreationYearsCommand, containerClass=CONTAINER, itemClass=null, idPrefix=YEAR, recursive=false
20:02:15,366 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.image.ListImagesCreationMonthsCommand, containerClass=CONTAINER, itemClass=null, idPrefix=MON, recursive=false
20:02:15,398 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.image.ListImagesForCreationMonthAndYearCommand, containerClass=null, itemClass=PHOTO, idPrefix=I, recursive=false
20:02:15,398 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=I_AI, title=All images, class=CONTAINER
20:02:15,413 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.image.ListAllImagesCommand, containerClass=null, itemClass=PHOTO, idPrefix=I, recursive=false
20:02:15,429 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=V, title=Video, class=CONTAINER
20:02:15,445 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=V_T, title=All titles, class=CONTAINER
20:02:15,460 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.video.ListVideoInitialsCommand, containerClass=CONTAINER, itemClass=null, idPrefix=INI, recursive=false
20:02:15,632 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.video.ListVideosForInitialCommand, containerClass=null, itemClass=VIDEO_ITEM, idPrefix=V, recursive=false
20:02:15,648 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=V_M, title=Movies, class=CONTAINER
20:02:15,679 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.video.ListMovieVideosByNameCommand, containerClass=null, itemClass=VIDEO_ITEM, idPrefix=V, recursive=false
20:02:15,695 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=V_S, title=Series, class=CONTAINER
20:02:15,710 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.video.ListSeriesByNameCommand, containerClass=CONTAINER, itemClass=null, idPrefix=SER, recursive=false
20:02:15,741 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.video.ListSeasonsForSeriesCommand, containerClass=CONTAINER, itemClass=null, idPrefix=SSN, recursive=false
20:02:15,757 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.video.ListEpisodesForSeriesSeasonCommand, containerClass=null, itemClass=VIDEO_ITEM, idPrefix=V, recursive=false
20:02:15,773 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=V_F, title=Folders, class=CONTAINER
20:02:15,788 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.video.ListVideoFoldersByNameCommand, containerClass=STORAGE_FOLDER, itemClass=VIDEO_ITEM, idPrefix=FOL, recursive=true
20:02:15,788 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=V_LV, title=Last viewed, class=CONTAINER
20:02:15,804 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.video.ListLastViewedVideosCommand, containerClass=null, itemClass=VIDEO_ITEM, idPrefix=V, recursive=false
20:02:15,820 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=V_LA, title=Last added, class=CONTAINER
20:02:15,835 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.video.ListLastAddedVideosCommand, containerClass=null, itemClass=VIDEO_ITEM, idPrefix=V, recursive=false
20:02:15,851 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=V_G, title=Genres, class=CONTAINER
20:02:15,866 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.video.ListVideoGenresByNameCommand, containerClass=CONTAINER, itemClass=null, idPrefix=GEN, recursive=false
20:02:15,866 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.video.ListVideosForGenreCommand, containerClass=null, itemClass=VIDEO_ITEM, idPrefix=V, recursive=false
20:02:16,038 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=V_A, title=Actors, class=CONTAINER
20:02:16,054 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.person.ListActorInitialsCommand, containerClass=CONTAINER, itemClass=null, idPrefix=INI, recursive=false
20:02:16,070 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.person.ListActorsForInitialCommand, containerClass=PERSON, itemClass=null, idPrefix=P, recursive=false
20:02:16,116 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.video.ListVideosForActorCommand, containerClass=null, itemClass=VIDEO_ITEM, idPrefix=V, recursive=false
20:02:16,116 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=V_D, title=Directors, class=CONTAINER
20:02:16,132 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.person.ListDirectorInitialsCommand, containerClass=CONTAINER, itemClass=null, idPrefix=INI, recursive=false
20:02:16,148 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.person.ListDirectorsForInitialCommand, containerClass=PERSON, itemClass=null, idPrefix=P, recursive=false
20:02:16,163 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.video.ListVideosForDirectorCommand, containerClass=null, itemClass=VIDEO_ITEM, idPrefix=V, recursive=false
20:02:16,179 DEBUG [ContentDirectoryDefinitionParser] Found Container node with attributes: id=V_P, title=Producers, class=CONTAINER
20:02:16,195 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.person.ListProducerInitialsCommand, containerClass=CONTAINER, itemClass=null, idPrefix=INI, recursive=false
20:02:16,210 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.person.ListProducersForInitialCommand, containerClass=PERSON, itemClass=null, idPrefix=P, recursive=false
20:02:16,226 DEBUG [ContentDirectoryDefinitionParser] Found Action node with attributes: command=org.serviio.upnp.service.contentdirectory.command.video.ListVideosForProducerCommand, containerClass=null, itemClass=VIDEO_ITEM, idPrefix=V, recursive=false
20:02:16,351 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
20:02:16,804 DEBUG [WebServer] Incoming connection from /192.168.1.68:61145
20:02:16,804 DEBUG [DeviceDescriptionRequestHandler] DeviceDescription request received for device 163bb252-8bb9-344d-a704-55ad0ac6ba08 from UPnP/1.0
20:02:16,820 DEBUG [DeviceDescriptionRequestHandler] Sending DeviceDescription XML back using profile 'Generic DLNA profile'
20:02:16,945 DEBUG [WebServer] Incoming connection from /192.168.1.68:61146
20:02:16,945 DEBUG [ServiceDescriptionRequestHandler] ServiceDescription request received for service ConnectionManager
20:02:16,960 DEBUG [ServiceDescriptionRequestHandler] Sending ServiceDescription XML back
20:02:17,116 DEBUG [WebServer] Incoming connection from /192.168.1.68:61147
20:02:17,116 DEBUG [ServiceDescriptionRequestHandler] ServiceDescription request received for service ContentDirectory
20:02:17,132 DEBUG [ServiceDescriptionRequestHandler] Sending ServiceDescription XML back
20:02:17,351 DEBUG [WebServer] Incoming connection from /192.168.1.68:61148
20:02:17,351 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#GetSortCapabilities"' from UPnP/1.0 DLNADOC/1.50:
20:02:17,460 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
20:02:17,476 DEBUG [WebServer] Incoming connection from /192.168.1.68:61149
20:02:17,476 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ConnectionManager:1#GetProtocolInfo"' from UPnP/1.0 DLNADOC/1.50:
20:02:17,663 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
20:02:21,304 DEBUG [WebServer] Incoming connection from /192.168.1.68:61155
20:02:21,304 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from UPnP/1.0 DLNADOC/1.50:
20:02:21,491 DEBUG [ContentDirectory] Browse() called for profile Generic DLNA profile with parameters: objectID = I, browseFlag = BrowseDirectChildren, filter = dc:title,av:mediaClass,dc:date,@childCount,res,upnp:class,res@resolution,upnp:album,upnp:genre,upnp:albumArtURI,upnp:albumArtURI@dlna:profileID,dc:creator,res@size,res@duration,res@bitrate,res@protocolInfo, startIndex = 0, count = 10, sortCriteria =
20:02:21,491 DEBUG [FolderDAOImpl] Retrieving number of leaf folders
20:02:21,538 DEBUG [RepositoryDAOImpl] Retrieving number of repositories for IMAGE
20:02:21,570 DEBUG [ImageDAOImpl] Retrieving number of images' years
20:02:21,601 DEBUG [ImageDAOImpl] Retrieving number of images' years
20:02:21,616 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
20:02:24,413 DEBUG [WebServer] Incoming connection from /192.168.1.68:61156
20:02:24,413 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from UPnP/1.0 DLNADOC/1.50:
20:02:24,601 DEBUG [ContentDirectory] Browse() called for profile Generic DLNA profile with parameters: objectID = I_F, browseFlag = BrowseDirectChildren, filter = dc:title,av:mediaClass,dc:date,@childCount,res,upnp:class,res@resolution,upnp:album,upnp:genre,upnp:albumArtURI,upnp:albumArtURI@dlna:profileID,dc:creator,res@size,res@duration,res@bitrate,res@protocolInfo, startIndex = 0, count = 10, sortCriteria =
20:02:24,601 DEBUG [RepositoryDAOImpl] Retrieving list of Repositories for IMAGE (from=0, count=10)
20:02:24,632 DEBUG [FolderDAOImpl] Getting number of IMAGE sub-folders and media items in folder null
20:02:24,695 DEBUG [RepositoryDAOImpl] Retrieving number of repositories for IMAGE
20:02:24,710 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
20:02:29,398 DEBUG [WebServer] Incoming connection from /192.168.1.68:61157
20:02:29,398 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from UPnP/1.0 DLNADOC/1.50:
20:02:29,695 DEBUG [ContentDirectory] Browse() called for profile Generic DLNA profile with parameters: objectID = I_F#FOL_R10, browseFlag = BrowseDirectChildren, filter = dc:title,av:mediaClass,dc:date,@childCount,res,upnp:class,res@resolution,upnp:album,upnp:genre,upnp:albumArtURI,upnp:albumArtURI@dlna:profileID,dc:creator,res@size,res@duration,res@bitrate,res@protocolInfo, startIndex = 0, count = 10, sortCriteria =
20:02:29,695 DEBUG [FolderDAOImpl] Getting list of sub-Folders in folder null
20:02:29,741 DEBUG [ImageDAOImpl] Retrieving list of images for folder 1885 (from=0, count=2147483647)
20:02:29,773 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:29,804 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37910)
20:02:29,866 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:29,866 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37909)
20:02:29,866 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:29,866 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37911)
20:02:29,882 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:29,882 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37906)
20:02:29,882 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:29,882 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37905)
20:02:29,882 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:29,882 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37904)
20:02:29,882 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:29,898 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37908)
20:02:29,898 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:29,898 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37907)
20:02:29,898 DEBUG [FolderDAOImpl] Getting number of IMAGE sub-folders and media items in folder null
20:02:29,960 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
20:02:30,366 DEBUG [WebServer] Incoming connection from /192.168.1.68:61158
20:02:30,366 DEBUG [ResourceTransportRequestHandler] GET /resource/37910/COVER_IMAGE HTTP/1.1, headers = [transferMode.dlna.org: Interactive, X-AV-Physical-Unit-Info: pa="BRAVIA KDL-32V5810 ";, X-AV-Client-Info: av=5.0; cn="Sony Corporation"; mn="BRAVIA KDL-32V5810 "; mv="1.7";, Host: 192.168.1.77:8895, ]
20:02:30,366 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using renderer profile 'Generic DLNA profile'
20:02:30,366 DEBUG [ResourceTransportRequestHandler] Request for resource 37910 and type 'COVER_IMAGE' received
20:02:30,366 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37910)
20:02:30,382 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 37910
20:02:30,382 DEBUG [ResourceTransportRequestHandler] Sending file back
20:02:30,382 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [Content-Type: image/jpeg, Content-Length: 5772, Cache-control: no-cache, Pragma: no-cache, Server: Windows 2003 UPnP/1.0 Serviio 0.3.1, transferMode.dlna.org: Interactive, ]
20:02:30,648 DEBUG [WebServer] Incoming connection from /192.168.1.68:61159
20:02:30,648 DEBUG [ResourceTransportRequestHandler] GET /resource/37909/COVER_IMAGE HTTP/1.1, headers = [transferMode.dlna.org: Interactive, X-AV-Physical-Unit-Info: pa="BRAVIA KDL-32V5810 ";, X-AV-Client-Info: av=5.0; cn="Sony Corporation"; mn="BRAVIA KDL-32V5810 "; mv="1.7";, Host: 192.168.1.77:8895, ]
20:02:30,648 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using renderer profile 'Generic DLNA profile'
20:02:30,648 DEBUG [ResourceTransportRequestHandler] Request for resource 37909 and type 'COVER_IMAGE' received
20:02:30,648 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37909)
20:02:30,648 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 37909
20:02:30,648 DEBUG [ResourceTransportRequestHandler] Sending file back
20:02:30,648 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [Content-Type: image/jpeg, Content-Length: 5803, Cache-control: no-cache, Pragma: no-cache, Server: Windows 2003 UPnP/1.0 Serviio 0.3.1, transferMode.dlna.org: Interactive, ]
20:02:30,804 DEBUG [WebServer] Incoming connection from /192.168.1.68:61160
20:02:30,804 DEBUG [ResourceTransportRequestHandler] GET /resource/37911/COVER_IMAGE HTTP/1.1, headers = [transferMode.dlna.org: Interactive, X-AV-Physical-Unit-Info: pa="BRAVIA KDL-32V5810 ";, X-AV-Client-Info: av=5.0; cn="Sony Corporation"; mn="BRAVIA KDL-32V5810 "; mv="1.7";, Host: 192.168.1.77:8895, ]
20:02:30,804 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using renderer profile 'Generic DLNA profile'
20:02:30,804 DEBUG [ResourceTransportRequestHandler] Request for resource 37911 and type 'COVER_IMAGE' received
20:02:30,804 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37911)
20:02:30,820 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 37911
20:02:30,820 DEBUG [ResourceTransportRequestHandler] Sending file back
20:02:30,820 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [Content-Type: image/jpeg, Content-Length: 4113, Cache-control: no-cache, Pragma: no-cache, Server: Windows 2003 UPnP/1.0 Serviio 0.3.1, transferMode.dlna.org: Interactive, ]
20:02:31,054 DEBUG [WebServer] Incoming connection from /192.168.1.68:61161
20:02:31,054 DEBUG [ResourceTransportRequestHandler] GET /resource/37906/COVER_IMAGE HTTP/1.1, headers = [transferMode.dlna.org: Interactive, X-AV-Physical-Unit-Info: pa="BRAVIA KDL-32V5810 ";, X-AV-Client-Info: av=5.0; cn="Sony Corporation"; mn="BRAVIA KDL-32V5810 "; mv="1.7";, Host: 192.168.1.77:8895, ]
20:02:31,054 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using renderer profile 'Generic DLNA profile'
20:02:31,054 DEBUG [ResourceTransportRequestHandler] Request for resource 37906 and type 'COVER_IMAGE' received
20:02:31,054 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37906)
20:02:31,054 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 37906
20:02:31,054 DEBUG [ResourceTransportRequestHandler] Sending file back
20:02:31,054 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [Content-Type: image/jpeg, Content-Length: 4616, Cache-control: no-cache, Pragma: no-cache, Server: Windows 2003 UPnP/1.0 Serviio 0.3.1, transferMode.dlna.org: Interactive, ]
20:02:31,195 DEBUG [WebServer] Incoming connection from /192.168.1.68:61162
20:02:31,195 DEBUG [ResourceTransportRequestHandler] GET /resource/37905/COVER_IMAGE HTTP/1.1, headers = [transferMode.dlna.org: Interactive, X-AV-Physical-Unit-Info: pa="BRAVIA KDL-32V5810 ";, X-AV-Client-Info: av=5.0; cn="Sony Corporation"; mn="BRAVIA KDL-32V5810 "; mv="1.7";, Host: 192.168.1.77:8895, ]
20:02:31,195 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using renderer profile 'Generic DLNA profile'
20:02:31,195 DEBUG [ResourceTransportRequestHandler] Request for resource 37905 and type 'COVER_IMAGE' received
20:02:31,195 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37905)
20:02:31,195 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 37905
20:02:31,195 DEBUG [ResourceTransportRequestHandler] Sending file back
20:02:31,195 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [Content-Type: image/jpeg, Content-Length: 6285, Cache-control: no-cache, Pragma: no-cache, Server: Windows 2003 UPnP/1.0 Serviio 0.3.1, transferMode.dlna.org: Interactive, ]
20:02:31,351 DEBUG [WebServer] Incoming connection from /192.168.1.68:61163
20:02:31,351 DEBUG [ResourceTransportRequestHandler] GET /resource/37904/COVER_IMAGE HTTP/1.1, headers = [transferMode.dlna.org: Interactive, X-AV-Physical-Unit-Info: pa="BRAVIA KDL-32V5810 ";, X-AV-Client-Info: av=5.0; cn="Sony Corporation"; mn="BRAVIA KDL-32V5810 "; mv="1.7";, Host: 192.168.1.77:8895, ]
20:02:31,351 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using renderer profile 'Generic DLNA profile'
20:02:31,351 DEBUG [ResourceTransportRequestHandler] Request for resource 37904 and type 'COVER_IMAGE' received
20:02:31,351 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37904)
20:02:31,351 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 37904
20:02:31,351 DEBUG [ResourceTransportRequestHandler] Sending file back
20:02:31,366 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [Content-Type: image/jpeg, Content-Length: 4691, Cache-control: no-cache, Pragma: no-cache, Server: Windows 2003 UPnP/1.0 Serviio 0.3.1, transferMode.dlna.org: Interactive, ]
20:02:31,382 DEBUG [WebServer] Incoming connection from /192.168.1.68:61164
20:02:31,382 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from UPnP/1.0 DLNADOC/1.50:
20:02:31,413 DEBUG [WebServer] Incoming connection from /192.168.1.68:61165
20:02:31,413 DEBUG [ResourceTransportRequestHandler] GET /resource/37908/COVER_IMAGE HTTP/1.1, headers = [transferMode.dlna.org: Interactive, X-AV-Physical-Unit-Info: pa="BRAVIA KDL-32V5810 ";, X-AV-Client-Info: av=5.0; cn="Sony Corporation"; mn="BRAVIA KDL-32V5810 "; mv="1.7";, Host: 192.168.1.77:8895, ]
20:02:31,413 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using renderer profile 'Generic DLNA profile'
20:02:31,413 DEBUG [ResourceTransportRequestHandler] Request for resource 37908 and type 'COVER_IMAGE' received
20:02:31,413 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37908)
20:02:31,413 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 37908
20:02:31,413 DEBUG [ResourceTransportRequestHandler] Sending file back
20:02:31,413 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [Content-Type: image/jpeg, Content-Length: 4587, Cache-control: no-cache, Pragma: no-cache, Server: Windows 2003 UPnP/1.0 Serviio 0.3.1, transferMode.dlna.org: Interactive, ]
20:02:31,538 DEBUG [ContentDirectory] Browse() called for profile Generic DLNA profile with parameters: objectID = I_F#FOL_R10, browseFlag = BrowseDirectChildren, filter = dc:title,av:mediaClass,dc:date,@childCount,res,upnp:class,res@resolution,upnp:album,upnp:genre,upnp:albumArtURI,upnp:albumArtURI@dlna:profileID,dc:creator,res@size,res@duration,res@bitrate,res@protocolInfo, startIndex = 0, count = 10, sortCriteria =
20:02:31,538 DEBUG [FolderDAOImpl] Getting list of sub-Folders in folder null
20:02:31,538 DEBUG [ImageDAOImpl] Retrieving list of images for folder 1885 (from=0, count=2147483647)
20:02:31,554 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:31,554 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37910)
20:02:31,554 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:31,554 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37909)
20:02:31,570 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:31,570 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37911)
20:02:31,570 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:31,570 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37906)
20:02:31,585 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:31,585 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37905)
20:02:31,585 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:31,585 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37904)
20:02:31,585 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:31,585 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37908)
20:02:31,585 DEBUG [FolderDAOImpl] Reading a Folder (id = 1885)
20:02:31,585 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37907)
20:02:31,601 DEBUG [FolderDAOImpl] Getting number of IMAGE sub-folders and media items in folder null
20:02:31,648 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
20:02:31,663 DEBUG [WebServer] Incoming connection from /192.168.1.68:61166
20:02:31,663 DEBUG [ResourceTransportRequestHandler] GET /resource/37907/COVER_IMAGE HTTP/1.1, headers = [transferMode.dlna.org: Interactive, X-AV-Physical-Unit-Info: pa="BRAVIA KDL-32V5810 ";, X-AV-Client-Info: av=5.0; cn="Sony Corporation"; mn="BRAVIA KDL-32V5810 "; mv="1.7";, Host: 192.168.1.77:8895, ]
20:02:31,663 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using renderer profile 'Generic DLNA profile'
20:02:31,663 DEBUG [ResourceTransportRequestHandler] Request for resource 37907 and type 'COVER_IMAGE' received
20:02:31,663 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 37907)
20:02:31,663 DEBUG [CoverImageRetrievalStrategy] Retrieving Cover image with id 37907
20:02:31,663 DEBUG [ResourceTransportRequestHandler] Sending file back
20:02:31,663 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [Content-Type: image/jpeg, Content-Length: 3570, Cache-control: no-cache, Pragma: no-cache, Server: Windows 2003 UPnP/1.0 Serviio 0.3.1, transferMode.dlna.org: Interactive, ]
20:02:40,898 DEBUG [WebServer] Incoming connection from /192.168.1.68:61167
20:02:40,898 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from UPnP/1.0 DLNADOC/1.50:
20:02:41,101 DEBUG [ContentDirectory] Browse() called for profile Generic DLNA profile with parameters: objectID = I_F, browseFlag = BrowseDirectChildren, filter = dc:title,av:mediaClass,dc:date,@childCount,res,upnp:class,res@resolution,upnp:album,upnp:genre,upnp:albumArtURI,upnp:albumArtURI@dlna:profileID,dc:creator,res@size,res@duration,res@bitrate,res@protocolInfo, startIndex = 0, count = 10, sortCriteria =
20:02:41,101 DEBUG [RepositoryDAOImpl] Retrieving list of Repositories for IMAGE (from=0, count=10)
20:02:41,101 DEBUG [FolderDAOImpl] Getting number of IMAGE sub-folders and media items in folder null
20:02:41,101 DEBUG [RepositoryDAOImpl] Retrieving number of repositories for IMAGE
20:02:41,116 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
20:02:57,491 DEBUG [WebServer] Incoming connection from /192.168.1.68:61168
20:02:57,491 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from UPnP/1.0 DLNADOC/1.50:
20:02:57,695 DEBUG [ContentDirectory] Browse() called for profile Generic DLNA profile with parameters: objectID = I, browseFlag = BrowseDirectChildren, filter = dc:title,av:mediaClass,dc:date,@childCount,res,upnp:class,res@resolution,upnp:album,upnp:genre,upnp:albumArtURI,upnp:albumArtURI@dlna:profileID,dc:creator,res@size,res@duration,res@bitrate,res@protocolInfo, startIndex = 0, count = 10, sortCriteria =
20:02:57,695 DEBUG [FolderDAOImpl] Retrieving number of leaf folders
20:02:57,695 DEBUG [RepositoryDAOImpl] Retrieving number of repositories for IMAGE
20:02:57,695 DEBUG [ImageDAOImpl] Retrieving number of images' years
20:02:57,695 DEBUG [ImageDAOImpl] Retrieving number of images' years
20:02:57,710 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
20:02:59,288 DEBUG [WebServer] Incoming connection from /192.168.1.68:61169
20:02:59,304 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from UPnP/1.0 DLNADOC/1.50:
20:02:59,507 DEBUG [ContentDirectory] Browse() called for profile Generic DLNA profile with parameters: objectID = 0, browseFlag = BrowseDirectChildren, filter = dc:title,av:mediaClass,dc:date,@childCount,res,upnp:class,res@resolution,upnp:album,upnp:genre,upnp:albumArtURI,upnp:albumArtURI@dlna:profileID,dc:creator,res@size,res@duration,res@bitrate,res@protocolInfo, startIndex = 0, count = 10, sortCriteria =
20:02:59,523 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message

[zip]

Ok, so I presume it was slow because the library was busy with updating/checking for updates. Would you say you have mostly audio/video/images and can you give me estimation how much of each you have?

Looks like the problem area is images: I have about 25,000. Now updating the library to include all of them, and browse that same folder again.
I had about 4000 music files when I first experimented, but browsing them was always reasonably quick and I've removed them from the library for now.

[zip]

Thanks, I'll try to optimize the code a bit to support library this big. Will go into 0.4.

http://bitbucket.org/xnejp03/serviio/is ... -for-speed

[zip]

Actually, can you trythis:

1) stop Serviio service
2) edit file library/derby.properties and add these lines:

  Code:

derby.storage.pageSize=8192
derby.storage.pageCacheSize=3000

3) start Serviio service and try browsing your huge library

Let me know if you see any improvements.

Well, this is bizarre. I reported that I cut my library down to one folder and a few files, and saw a dramatic increase in speed of browsing - as might be expected. Next, I restored my library to include everything it contained previously, with the intention of providing a log whilst browsing the full library. However, much to my surprise I find that I can now browse the full library, including folders, at a perfectly respectable speed - it's probably no slower than the cut-down library! The difference is dramatic: before I never managed to see any photos through the 'folders' route because the TV would always time out after several minutes of waiting. Now it's a fraction of a second before the folders and/or pictures start to show.

As far as I know, the _only_ thing that has changed along the way is the minor release (I'm now using 0.3.1 when I first reported the problems with 0.3). I have _not_ changed the cache settings.

BTW the server is still running at 100% cpu continuously. From the logs, a complete scan of the library happens about every 25 minutes.

[zip]

Yes, I put some optimization into 0.3.1. The 100% is weird though, is it the serviio task or ffmpeg? How much memory do you have and what's the CPU?

I am running on a PS3 and was directed to this thread on facebook. The earlier suggested fix seemed to work well for a brief period of time, but it was just a bandage. I turned on debug logs to try and figure out what is causing the slowdown.

  Code:

20:30:47,277 DEBUG [GenreDAOImpl] Reading a Genre (id = 5)
20:30:47,278 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 1420
20:30:47,369 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 1500
20:30:47,455 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 1420
20:30:47,552 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1502)
20:30:47,553 DEBUG [GenreDAOImpl] Reading a Genre (id = 5)
20:30:47,553 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 1501
20:30:47,640 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 1420
20:30:47,731 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 1501
20:30:47,822 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1422)
20:30:47,823 DEBUG [GenreDAOImpl] Reading a Genre (id = 5)
20:30:47,823 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 1421
20:30:47,915 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 1501
20:30:48,006 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 1421
20:30:48,097 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1503)
20:30:48,098 DEBUG [GenreDAOImpl] Reading a Genre (id = 5)
20:30:48,098 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 1502
20:30:48,193 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 1421
20:30:48,287 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 1502
20:30:48,384 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1423)
20:30:48,385 DEBUG [GenreDAOImpl] Reading a Genre (id = 5)
20:30:48,385 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 1422
20:30:48,480 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 1502
20:30:48,585 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 1422
20:30:48,682 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1504)
20:30:48,682 DEBUG [GenreDAOImpl] Reading a Genre (id = 5)
20:30:48,683 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 1503
20:30:48,769 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 1422
20:30:48,878 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 1503
20:30:48,957 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1424)
20:30:48,958 DEBUG [GenreDAOImpl] Reading a Genre (id = 5)
20:30:48,958 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 1423
20:30:49,063 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 1503
20:30:49,146 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 1423
20:30:49,255 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1505)
20:30:49,255 DEBUG [GenreDAOImpl] Reading a Genre (id = 5)
20:30:49,255 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 1504
20:30:49,339 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 1423
20:30:49,447 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 1504
20:30:49,521 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1425)
20:30:49,522 DEBUG [GenreDAOImpl] Reading a Genre (id = 5)
20:30:49,522 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 1424
20:30:49,636 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 1504
20:30:49,707 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 1424
20:30:49,817 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 1506)

This continues on infinitum despite me having none of the metadata boxes checked (except the one grayed one). Is 0.3.1 not properly ignoring my metadata settings? Alternatively, is there any way to turn off those Actor, producer or director searches? I only use folder browsing.

[zip]

I'll try to add some settings into 0.4 for this data not to be sent to the device.

I just rolled back to 0.3 to see the debug code:

  Code:

20:10:53,529 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,529 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 267
20:10:53,530 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 267
20:10:53,531 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 267
20:10:53,532 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 267)
20:10:53,532 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,533 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 305
20:10:53,534 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 305
20:10:53,535 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 305
20:10:53,536 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 305)
20:10:53,536 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,536 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 306
20:10:53,537 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 306
20:10:53,538 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 306
20:10:53,539 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 306)
20:10:53,540 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,540 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 307
20:10:53,541 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 307
20:10:53,542 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 307
20:10:53,543 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 307)
20:10:53,543 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,543 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 308
20:10:53,544 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 308
20:10:53,546 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 308
20:10:53,547 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 308)
20:10:53,547 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,548 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 309
20:10:53,549 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 309
20:10:53,550 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 309
20:10:53,551 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 309)
20:10:53,551 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,552 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 310
20:10:53,552 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 310
20:10:53,554 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 310
20:10:53,555 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 310)
20:10:53,555 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,555 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 311
20:10:53,556 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 311
20:10:53,557 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 311
20:10:53,558 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 311)
20:10:53,559 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,559 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 312
20:10:53,560 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 312
20:10:53,561 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 312
20:10:53,562 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 312)
20:10:53,562 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,562 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 313
20:10:53,563 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 313
20:10:53,564 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 313
20:10:53,565 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 313)
20:10:53,566 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,566 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 314
20:10:53,567 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 314
20:10:53,568 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 314
20:10:53,569 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 314)
20:10:53,569 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,569 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 315
20:10:53,570 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 315
20:10:53,571 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 315
20:10:53,572 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 315)
20:10:53,573 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,573 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 316
20:10:53,574 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 316
20:10:53,575 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 316
20:10:53,577 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 316)
20:10:53,578 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,578 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 317
20:10:53,579 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 317
20:10:53,580 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 317
20:10:53,581 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 317)
20:10:53,581 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,582 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 318
20:10:53,583 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 318
20:10:53,584 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 318
20:10:53,585 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 318)
20:10:53,585 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,585 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 338
20:10:53,586 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 338
20:10:53,587 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 338
20:10:53,588 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 338)
20:10:53,588 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,589 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 339
20:10:53,590 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 339
20:10:53,591 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 339
20:10:53,592 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 339)
20:10:53,592 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,592 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 340
20:10:53,593 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 340
20:10:53,594 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 340
20:10:53,596 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 340)
20:10:53,596 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
20:10:53,597 DEBUG [PersonDAOImpl] Retrieving list of persons with role ACTOR for MediaItem 341
20:10:53,598 DEBUG [PersonDAOImpl] Retrieving list of persons with role DIRECTOR for MediaItem 341
20:10:53,599 DEBUG [PersonDAOImpl] Retrieving list of persons with role PRODUCER for MediaItem 341
20:10:53,600 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 341)

This time, the same data is almost instantaneous.

[zip]

Did you uninstall 0.3.1 and installed 0.3 or just reinstalled 0.3.1 with 0.3? Also what browse category is this log from?

I installed 0.3 after uninstalling 0.3.1 on OSX.

This was from browsing Folders.