Serviio

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

XBox intermittent audio file playback problems

https://forum.serviio.org/viewtopic.php?f=5&t=7134

Page 1 of 1

XBox intermittent audio file playback problems

PostPosted: Mon Aug 20, 2012 5:34 am
by grolschie
Hello,

Sometimes iTunes MPA files won't play on the Xbox. Here is an example:
  Code:
2012-08-20 17:22:13,796 DEBUG [AudioDeliveryEngine] Delivering file '01 Requiem for Evita.m4a' using transcoding
2012-08-20 17:22:13,796 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-20 17:22:13,812 DEBUG [MediaItemDAOImpl] Getting file of media item 2459
2012-08-20 17:22:13,812 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode audio file: D:\ITUNES\Music\Madonna\Evita\01 Requiem for Evita.m4a
2012-08-20 17:22:13,812 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\ITUNES\Music\Madonna\Evita\01 Requiem for Evita.m4a -y -b:a 192k -ac 2 -vn -f mp3 C:\WINDOWS\TEMP\Serviio\transcoding-temp-2459-3-ORIGINAL.stf
2012-08-20 17:22:14,468 DEBUG [FileBasedTranscodingDeliveryStrategy] Sending transcoding stream
2012-08-20 17:22:28,656 DEBUG [AudioDeliveryEngine] Found Format profile for transcoded file 01 Requiem for Evita.m4a: MP3
2012-08-20 17:22:28,656 DEBUG [MediaItemDAOImpl] Marking MediaItem (id = 2459) as read
2012-08-20 17:22:28,671 DEBUG [WebServer] Incoming connection from /192.168.100.10:22066
2012-08-20 17:22:28,671 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-20 17:22:28,687 DEBUG [ResourceTransportRequestHandler] GET /resource/2460/MEDIA_ITEM/MP3-0/ORIGINAL HTTP/1.1, headers = [User-Agent: Xenon,Connection: Keep-alive,Host: 192.168.100.1:8895,Content-Length: 3]]
2012-08-20 17:22:28,687 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-20 17:22:28,687 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-20 17:22:28,687 DEBUG [ResourceDeliveryProcessor] Request for resource 2460 and type 'MEDIA_ITEM' received
2012-08-20 17:22:28,687 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 2460 (local)
2012-08-20 17:22:28,687 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 2460)
2012-08-20 17:22:28,687 DEBUG [MusicTrackDAOImpl] Reading a MusicTrack (id = 2460)
2012-08-20 17:22:28,687 DEBUG [AudioDeliveryEngine] Delivering item '2460' for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-20 17:22:28,687 DEBUG [AudioDeliveryEngine] Delivering file '02 Oh What a Circus.m4a' using transcoding
2012-08-20 17:22:28,687 DEBUG [AbstractTranscodingDeliveryEngine] No other client uses transcoding job of file 'transcoding-temp-2459-3-ORIGINAL.stf', will stop the job
2012-08-20 17:22:28,687 DEBUG [AbstractTranscodingDeliveryEngine] Stopping previous transcoding job of file 'transcoding-temp-2459-3-ORIGINAL.stf'
2012-08-20 17:22:28,687 DEBUG [ProcessExecutor] Stopping external process: Thread[Thread-43,5,main]
2012-08-20 17:22:28,703 DEBUG [LocalContentCacheDecorator] Cleared cache (local_resetafterplay)
2012-08-20 17:22:28,703 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 900000000
2012-08-20 17:22:28,703 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-08-20 17:22:28,703 DEBUG [ResourceTransportRequestHandler] Creating entity with chunked transfer
2012-08-20 17:22:28,703 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: audio/mpeg,Date: Mon, 20 Aug 2012 05:22:28 GMT,Server: Windows XP, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Streaming]]
2012-08-20 17:22:28,703 DEBUG [WebServer] I/O error: Software caused connection abort: socket write error
2012-08-20 17:22:28,812 DEBUG [ProcessUtils] Killing the Windows process: 3348
2012-08-20 17:22:28,812 DEBUG [TranscodingJobListener] Transcoding finished; successful: true
2012-08-20 17:22:28,812 DEBUG [TranscodingJobListener] Deleted temp file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-2459-3-ORIGINAL.stf': true


The weird thing is in this attempt, "02 Oh What a Circus.m4a" played, but " 01 Requiem for Evita.m4a" didn't. I get a circle with a line through it on the Xbox. However, " 01 Requiem for Evita.m4a" plays when I try again.


Here is an example from the same album:
  Code:
2012-08-20 17:30:09,796 DEBUG [MediaItemDAOImpl] Getting file of media item 2460
2012-08-20 17:30:09,796 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode audio file: D:\ITUNES\Music\Madonna\Evita\02 Oh What a Circus.m4a
2012-08-20 17:30:09,796 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\ITUNES\Music\Madonna\Evita\02 Oh What a Circus.m4a -y -b:a 192k -ac 2 -vn -f mp3 C:\WINDOWS\TEMP\Serviio\transcoding-temp-2460-3-ORIGINAL.stf
2012-08-20 17:30:10,296 DEBUG [FileBasedTranscodingDeliveryStrategy] Sending transcoding stream
2012-08-20 17:30:10,296 DEBUG [AbstractTranscodingDeliveryEngine] No other client uses transcoding job of file 'transcoding-temp-2460-3-ORIGINAL.stf', will stop the job
2012-08-20 17:30:10,296 DEBUG [AbstractTranscodingDeliveryEngine] Stopping previous transcoding job of file 'transcoding-temp-2460-3-ORIGINAL.stf'
2012-08-20 17:30:10,296 DEBUG [ProcessExecutor] Stopping external process: Thread[Thread-96,5,main]
2012-08-20 17:30:10,296 DEBUG [ProcessUtils] Killing the Windows process: 1840
2012-08-20 17:30:10,296 DEBUG [TranscodingJobListener] Transcoding finished; successful: true
2012-08-20 17:30:10,296 DEBUG [AudioDeliveryEngine] Found Format profile for transcoded file 02 Oh What a Circus.m4a: MP3
2012-08-20 17:30:10,296 DEBUG [MediaItemDAOImpl] Marking MediaItem (id = 2460) as read
2012-08-20 17:30:10,296 DEBUG [LocalContentCacheDecorator] Cleared cache (local_resetafterplay)
2012-08-20 17:30:10,296 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 900000000
2012-08-20 17:30:10,296 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-08-20 17:30:10,296 DEBUG [ResourceTransportRequestHandler] Creating entity with chunked transfer
2012-08-20 17:30:10,296 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: audio/mpeg,Date: Mon, 20 Aug 2012 05:30:10 GMT,Server: Windows XP, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Streaming]]
2012-08-20 17:30:10,296 DEBUG [WebServer] I/O error: Software caused connection abort: socket write error
2012-08-20 17:30:10,312 DEBUG [TranscodingJobListener] Deleted temp file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-2460-3-ORIGINAL.stf': true
2012-08-20 17:30:10,312 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-20 17:30:10,312 DEBUG [MediaItemDAOImpl] Getting file of media item 2461
2012-08-20 17:30:10,312 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode audio file: D:\ITUNES\Music\Madonna\Evita\03 On This Night of a Thousand Stars.m4a
2012-08-20 17:30:10,312 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\ITUNES\Music\Madonna\Evita\03 On This Night of a Thousand Stars.m4a -y -b:a 192k -ac 2 -vn -f mp3 C:\WINDOWS\TEMP\Serviio\transcoding-temp-2461-3-ORIGINAL.stf
2012-08-20 17:30:11,015 DEBUG [FileBasedTranscodingDeliveryStrategy] Sending transcoding stream
2012-08-20 17:30:19,187 DEBUG [WebServer] Incoming connection from /192.168.100.10:58062
2012-08-20 17:30:19,187 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-20 17:30:19,187 DEBUG [ResourceTransportRequestHandler] GET /resource/2462/MEDIA_ITEM/MP3-0/ORIGINAL HTTP/1.1, headers = [User-Agent: Xenon,Connection: Keep-alive,Host: 192.168.100.1:8895,Content-Length: 3]]
2012-08-20 17:30:19,187 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-20 17:30:19,187 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-20 17:30:19,187 DEBUG [ResourceDeliveryProcessor] Request for resource 2462 and type 'MEDIA_ITEM' received
2012-08-20 17:30:19,187 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 2462 (local)
2012-08-20 17:30:19,187 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 2462)
2012-08-20 17:30:19,187 DEBUG [MusicTrackDAOImpl] Reading a MusicTrack (id = 2462)
2012-08-20 17:30:19,187 DEBUG [AudioDeliveryEngine] Delivering item '2462' for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'


In this example, both "02 Oh What a Circus.m4a" and "03 On This Night of a Thousand Stars.m4a" fail to play.

It is clearly intermittent. Maybe related to the problem I have with streaming video? The log doesn't really say alot. Maybe FFMPEG is tying up my CPU too much and the Xbox doesn't get what it needs in time?

I don't have as many problems with the Sony BDP-S370 and Serviio. The most reliable for me though seems to be the MediaBrowser webpage.

Re: XBox intermittent problems

PostPosted: Mon Aug 20, 2012 11:29 pm
by grolschie
More problems playing .m4a files, this time possible ffmpeg failure:
  Code:
2012-08-21 11:22:22,593 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-21 11:22:22,593 DEBUG [MediaItemDAOImpl] Getting file of media item 1434
2012-08-21 11:22:22,593 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode audio file: D:\ITUNES\Music\Michalis Hatzigiannis\7\01 ΕΜΕΙΣ ΟΙ ΔΥΟ ΣΑΝ ΕΝΑ.m4a
2012-08-21 11:22:22,593 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\ITUNES\Music\Michalis Hatzigiannis\7\01 ΕΜΕΙΣ ΟΙ ΔΥΟ ΣΑΝ ΕΝΑ.m4a -y -b:a 192k -ac 2 -vn -f mp3 C:\WINDOWS\TEMP\Serviio\transcoding-temp-1434-3-ORIGINAL.stf
2012-08-21 11:22:30,093 ERROR [ResourceTransportRequestHandler] Error while processing resource, sending back 500 error. Message: Transcoded file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-1434-3-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
java.io.IOException: Transcoded file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-1434-3-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
   at org.serviio.delivery.resource.transcode.FileBasedTranscodingDeliveryStrategy.createInputStream(FileBasedTranscodingDeliveryStrategy.java:45)
   at org.serviio.delivery.resource.transcode.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:125)
   at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:95)
   at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:117)
   at org.serviio.delivery.ResourceDeliveryProcessor.deliverContent(ResourceDeliveryProcessor.java:84)
   at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:79)
   at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:61)
   at org.apache.http.protocol.HttpService.doService(HttpService.java:293)
   at org.serviio.upnp.webserver.ServiioHttpService.doService(ServiioHttpService.java:58)
   at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:212)
   at org.serviio.upnp.webserver.WebServer$WorkerThread.run(WebServer.java:191)
2012-08-21 11:22:30,125 DEBUG [WebServer] Incoming connection from /192.168.100.10:56588
2012-08-21 11:22:30,125 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-21 11:22:30,125 DEBUG [ResourceTransportRequestHandler] GET /resource/1435/MEDIA_ITEM/MP3-0/ORIGINAL HTTP/1.1, headers = [User-Agent: Xenon,Connection: Keep-alive,Host: 192.168.100.1:8895,Content-Length: 3]]
2012-08-21 11:22:30,125 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-21 11:22:30,125 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-21 11:22:30,125 DEBUG [ResourceDeliveryProcessor] Request for resource 1435 and type 'MEDIA_ITEM' received
2012-08-21 11:22:30,125 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1435 (local)
2012-08-21 11:22:30,125 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 1435)
2012-08-21 11:22:30,125 DEBUG [MusicTrackDAOImpl] Reading a MusicTrack (id = 1435)
2012-08-21 11:22:30,125 DEBUG [AudioDeliveryEngine] Delivering item '1435' for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-21 11:22:30,125 DEBUG [AudioDeliveryEngine] Delivering file '02 Η ΑΓΑΠΗ ΠΟΥ ΜΕΝΕΙ.m4a' using transcoding
2012-08-21 11:22:30,125 DEBUG [AbstractTranscodingDeliveryEngine] No other client uses transcoding job of file 'transcoding-temp-1434-3-ORIGINAL.stf', will stop the job
2012-08-21 11:22:30,125 DEBUG [AbstractTranscodingDeliveryEngine] Stopping previous transcoding job of file 'transcoding-temp-1434-3-ORIGINAL.stf'
2012-08-21 11:22:30,125 DEBUG [TranscodingJobListener] Deleted temp file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-1434-3-ORIGINAL.stf': false
2012-08-21 11:22:30,125 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-21 11:22:30,125 DEBUG [MediaItemDAOImpl] Getting file of media item 1435
2012-08-21 11:22:30,125 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode audio file: D:\ITUNES\Music\Michalis Hatzigiannis\7\02 Η ΑΓΑΠΗ ΠΟΥ ΜΕΝΕΙ.m4a
2012-08-21 11:22:30,125 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\ITUNES\Music\Michalis Hatzigiannis\7\02 Η ΑΓΑΠΗ ΠΟΥ ΜΕΝΕΙ.m4a -y -b:a 192k -ac 2 -vn -f mp3 C:\WINDOWS\TEMP\Serviio\transcoding-temp-1435-3-ORIGINAL.stf
2012-08-21 11:22:37,625 ERROR [ResourceTransportRequestHandler] Error while processing resource, sending back 500 error. Message: Transcoded file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-1435-3-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
java.io.IOException: Transcoded file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-1435-3-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
   at org.serviio.delivery.resource.transcode.FileBasedTranscodingDeliveryStrategy.createInputStream(FileBasedTranscodingDeliveryStrategy.java:45)
   at org.serviio.delivery.resource.transcode.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:125)
   at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:95)
   at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:117)
   at org.serviio.delivery.ResourceDeliveryProcessor.deliverContent(ResourceDeliveryProcessor.java:84)
   at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:79)
   at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:61)
   at org.apache.http.protocol.HttpService.doService(HttpService.java:293)
   at org.serviio.upnp.webserver.ServiioHttpService.doService(ServiioHttpService.java:58)
   at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:212)
   at org.serviio.upnp.webserver.WebServer$WorkerThread.run(WebServer.java:191)

Re: XBox intermittent problems

PostPosted: Wed Aug 22, 2012 1:46 am
by grolschie
More from the log (too much to read? please read below then):
  Code:
2012-08-22 13:33:16,671 DEBUG [ResourceDeliveryProcessor] Request for resource 429 and type 'MEDIA_ITEM' received
2012-08-22 13:33:16,671 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 429 (local)
2012-08-22 13:33:16,671 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 429)
2012-08-22 13:33:16,671 DEBUG [MusicTrackDAOImpl] Reading a MusicTrack (id = 429)
2012-08-22 13:33:16,687 DEBUG [AudioDeliveryEngine] Delivering item '429' for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:33:16,687 DEBUG [AudioDeliveryEngine] Delivering file '02 To Diko Mou Paploma.m4a' using transcoding
2012-08-22 13:33:16,687 DEBUG [AbstractTranscodingDeliveryEngine] No other client uses transcoding job of file 'transcoding-temp-428-3-ORIGINAL.stf', will stop the job
2012-08-22 13:33:16,687 DEBUG [AbstractTranscodingDeliveryEngine] Stopping previous transcoding job of file 'transcoding-temp-428-3-ORIGINAL.stf'
2012-08-22 13:33:16,703 DEBUG [TranscodingJobListener] Deleted temp file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-428-3-ORIGINAL.stf': false
2012-08-22 13:33:16,703 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:33:16,703 DEBUG [MediaItemDAOImpl] Getting file of media item 429
2012-08-22 13:33:16,703 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode audio file: D:\ITUNES\Music\Compilations\Greek Bouzouki Nights - The Ultimate Col\02 To Diko Mou Paploma.m4a
2012-08-22 13:33:16,703 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\ITUNES\Music\Compilations\Greek Bouzouki Nights - The Ultimate Col\02 To Diko Mou Paploma.m4a -y -b:a 192k -ac 2 -vn -f mp3 C:\WINDOWS\TEMP\Serviio\transcoding-temp-429-3-ORIGINAL.stf
2012-08-22 13:33:24,203 ERROR [ResourceTransportRequestHandler] Error while processing resource, sending back 500 error. Message: Transcoded file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-429-3-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
java.io.IOException: Transcoded file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-429-3-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
   at org.serviio.delivery.resource.transcode.FileBasedTranscodingDeliveryStrategy.createInputStream(FileBasedTranscodingDeliveryStrategy.java:45)
   at org.serviio.delivery.resource.transcode.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:125)
   at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:95)
   at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:117)
   at org.serviio.delivery.ResourceDeliveryProcessor.deliverContent(ResourceDeliveryProcessor.java:84)
   at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:79)
   at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:61)
   at org.apache.http.protocol.HttpService.doService(HttpService.java:293)
   at org.serviio.upnp.webserver.ServiioHttpService.doService(ServiioHttpService.java:58)
   at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:212)
   at org.serviio.upnp.webserver.WebServer$WorkerThread.run(WebServer.java:191)
2012-08-22 13:33:24,218 DEBUG [WebServer] Incoming connection from /192.168.100.10:62719
2012-08-22 13:33:24,234 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:33:24,234 DEBUG [ResourceTransportRequestHandler] GET /resource/430/MEDIA_ITEM/MP3-0/ORIGINAL HTTP/1.1, headers = [User-Agent: Xenon,Connection: Keep-alive,Host: 192.168.100.1:8895,Content-Length: 3]]
2012-08-22 13:33:24,234 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:33:24,234 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:33:24,234 DEBUG [ResourceDeliveryProcessor] Request for resource 430 and type 'MEDIA_ITEM' received
2012-08-22 13:33:24,234 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 430 (local)
2012-08-22 13:33:24,234 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 430)
2012-08-22 13:33:24,234 DEBUG [MusicTrackDAOImpl] Reading a MusicTrack (id = 430)
2012-08-22 13:33:24,234 DEBUG [AudioDeliveryEngine] Delivering item '430' for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:33:24,234 DEBUG [AudioDeliveryEngine] Delivering file '03 Sinnefies.m4a' using transcoding
2012-08-22 13:33:24,234 DEBUG [AbstractTranscodingDeliveryEngine] No other client uses transcoding job of file 'transcoding-temp-429-3-ORIGINAL.stf', will stop the job
2012-08-22 13:33:24,234 DEBUG [AbstractTranscodingDeliveryEngine] Stopping previous transcoding job of file 'transcoding-temp-429-3-ORIGINAL.stf'
2012-08-22 13:33:24,234 DEBUG [TranscodingJobListener] Deleted temp file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-429-3-ORIGINAL.stf': false
2012-08-22 13:33:24,234 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:33:24,234 DEBUG [MediaItemDAOImpl] Getting file of media item 430
2012-08-22 13:33:24,234 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode audio file: D:\ITUNES\Music\Compilations\Greek Bouzouki Nights - The Ultimate Col\03 Sinnefies.m4a
2012-08-22 13:33:24,234 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\ITUNES\Music\Compilations\Greek Bouzouki Nights - The Ultimate Col\03 Sinnefies.m4a -y -b:a 192k -ac 2 -vn -f mp3 C:\WINDOWS\TEMP\Serviio\transcoding-temp-430-3-ORIGINAL.stf
2012-08-22 13:33:31,734 ERROR [ResourceTransportRequestHandler] Error while processing resource, sending back 500 error. Message: Transcoded file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-430-3-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
java.io.IOException: Transcoded file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-430-3-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
   at org.serviio.delivery.resource.transcode.FileBasedTranscodingDeliveryStrategy.createInputStream(FileBasedTranscodingDeliveryStrategy.java:45)
   at org.serviio.delivery.resource.transcode.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:125)
   at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:95)
   at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:117)
   at org.serviio.delivery.ResourceDeliveryProcessor.deliverContent(ResourceDeliveryProcessor.java:84)
   at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:79)
   at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:61)
   at org.apache.http.protocol.HttpService.doService(HttpService.java:293)
   at org.serviio.upnp.webserver.ServiioHttpService.doService(ServiioHttpService.java:58)
   at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:212)
   at org.serviio.upnp.webserver.WebServer$WorkerThread.run(WebServer.java:191)
2012-08-22 13:33:31,750 DEBUG [WebServer] Incoming connection from /192.168.100.10:37686
2012-08-22 13:33:31,765 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:33:31,765 DEBUG [ResourceTransportRequestHandler] GET /resource/431/MEDIA_ITEM/MP3-0/ORIGINAL HTTP/1.1, headers = [User-Agent: Xenon,Connection: Keep-alive,Host: 192.168.100.1:8895,Content-Length: 3]]
2012-08-22 13:33:31,765 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:33:31,765 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:33:31,765 DEBUG [ResourceDeliveryProcessor] Request for resource 431 and type 'MEDIA_ITEM' received
2012-08-22 13:33:31,765 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 431 (local)
2012-08-22 13:33:31,765 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 431)
2012-08-22 13:33:31,765 DEBUG [MusicTrackDAOImpl] Reading a MusicTrack (id = 431)
2012-08-22 13:33:31,765 DEBUG [AudioDeliveryEngine] Delivering item '431' for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:33:31,765 DEBUG [AudioDeliveryEngine] Delivering file '04 I Thalassa Tou Peiraia.m4a' using transcoding
2012-08-22 13:33:31,765 DEBUG [AbstractTranscodingDeliveryEngine] No other client uses transcoding job of file 'transcoding-temp-430-3-ORIGINAL.stf', will stop the job
2012-08-22 13:33:31,765 DEBUG [AbstractTranscodingDeliveryEngine] Stopping previous transcoding job of file 'transcoding-temp-430-3-ORIGINAL.stf'
2012-08-22 13:33:31,765 DEBUG [TranscodingJobListener] Deleted temp file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-430-3-ORIGINAL.stf': false
2012-08-22 13:33:31,765 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:33:31,765 DEBUG [MediaItemDAOImpl] Getting file of media item 431
2012-08-22 13:33:31,765 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode audio file: D:\ITUNES\Music\Compilations\Greek Bouzouki Nights - The Ultimate Col\04 I Thalassa Tou Peiraia.m4a
2012-08-22 13:33:31,765 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\ITUNES\Music\Compilations\Greek Bouzouki Nights - The Ultimate Col\04 I Thalassa Tou Peiraia.m4a -y -b:a 192k -ac 2 -vn -f mp3 C:\WINDOWS\TEMP\Serviio\transcoding-temp-431-3-ORIGINAL.stf
2012-08-22 13:33:39,265 ERROR [ResourceTransportRequestHandler] Error while processing resource, sending back 500 error. Message: Transcoded file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-431-3-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
java.io.IOException: Transcoded file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-431-3-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
   at org.serviio.delivery.resource.transcode.FileBasedTranscodingDeliveryStrategy.createInputStream(FileBasedTranscodingDeliveryStrategy.java:45)
   at org.serviio.delivery.resource.transcode.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:125)
   at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:95)
   at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:117)
   at org.serviio.delivery.ResourceDeliveryProcessor.deliverContent(ResourceDeliveryProcessor.java:84)
   at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:79)
   at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:61)
   at org.apache.http.protocol.HttpService.doService(HttpService.java:293)
   at org.serviio.upnp.webserver.ServiioHttpService.doService(ServiioHttpService.java:58)
   at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:212)
   at org.serviio.upnp.webserver.WebServer$WorkerThread.run(WebServer.java:191)
2012-08-22 13:33:39,296 DEBUG [WebServer] Incoming connection from /192.168.100.10:64704
2012-08-22 13:33:39,312 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:33:39,312 DEBUG [ResourceTransportRequestHandler] GET /resource/432/MEDIA_ITEM/MP3-0/ORIGINAL HTTP/1.1, headers = [User-Agent: Xenon,Connection: Keep-alive,Host: 192.168.100.1:8895,Content-Length: 3]]
2012-08-22 13:33:39,312 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:33:39,312 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:33:39,312 DEBUG [ResourceDeliveryProcessor] Request for resource 432 and type 'MEDIA_ITEM' received
2012-08-22 13:33:39,312 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 432 (local)
2012-08-22 13:33:39,312 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 432)
2012-08-22 13:33:39,312 DEBUG [MusicTrackDAOImpl] Reading a MusicTrack (id = 432)
2012-08-22 13:33:39,312 DEBUG [AudioDeliveryEngine] Delivering item '432' for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:33:39,312 DEBUG [AudioDeliveryEngine] Delivering file '05 Oi Glaroi.m4a' using transcoding
2012-08-22 13:33:39,328 DEBUG [AbstractTranscodingDeliveryEngine] No other client uses transcoding job of file 'transcoding-temp-431-3-ORIGINAL.stf', will stop the job
2012-08-22 13:33:39,328 DEBUG [AbstractTranscodingDeliveryEngine] Stopping previous transcoding job of file 'transcoding-temp-431-3-ORIGINAL.stf'
2012-08-22 13:33:39,328 DEBUG [TranscodingJobListener] Deleted temp file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-431-3-ORIGINAL.stf': false
2012-08-22 13:33:39,328 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:33:39,328 DEBUG [MediaItemDAOImpl] Getting file of media item 432
2012-08-22 13:33:39,328 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode audio file: D:\ITUNES\Music\Compilations\Greek Bouzouki Nights - The Ultimate Col\05 Oi Glaroi.m4a
2012-08-22 13:33:39,328 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\ITUNES\Music\Compilations\Greek Bouzouki Nights - The Ultimate Col\05 Oi Glaroi.m4a -y -b:a 192k -ac 2 -vn -f mp3 C:\WINDOWS\TEMP\Serviio\transcoding-temp-432-3-ORIGINAL.stf
2012-08-22 13:33:46,828 ERROR [ResourceTransportRequestHandler] Error while processing resource, sending back 500 error. Message: Transcoded file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-432-3-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
java.io.IOException: Transcoded file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-432-3-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
   at org.serviio.delivery.resource.transcode.FileBasedTranscodingDeliveryStrategy.createInputStream(FileBasedTranscodingDeliveryStrategy.java:45)
   at org.serviio.delivery.resource.transcode.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:125)
   at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:95)
   at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:117)
   at org.serviio.delivery.ResourceDeliveryProcessor.deliverContent(ResourceDeliveryProcessor.java:84)
   at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:79)
   at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:61)
   at org.apache.http.protocol.HttpService.doService(HttpService.java:293)
   at org.serviio.upnp.webserver.ServiioHttpService.doService(ServiioHttpService.java:58)
   at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:212)
   at org.serviio.upnp.webserver.WebServer$WorkerThread.run(WebServer.java:191)
2012-08-22 13:33:46,859 DEBUG [WebServer] Incoming connection from /192.168.100.10:45046
2012-08-22 13:33:46,875 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:33:46,875 DEBUG [ResourceTransportRequestHandler] GET /resource/433/MEDIA_ITEM/MP3-0/ORIGINAL HTTP/1.1, headers = [User-Agent: Xenon,Connection: Keep-alive,Host: 192.168.100.1:8895,Content-Length: 3]]
2012-08-22 13:33:46,875 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:33:46,875 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:33:46,875 DEBUG [ResourceDeliveryProcessor] Request for resource 433 and type 'MEDIA_ITEM' received
2012-08-22 13:33:46,875 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 433 (local)
2012-08-22 13:33:46,875 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 433)
2012-08-22 13:33:46,875 DEBUG [MusicTrackDAOImpl] Reading a MusicTrack (id = 433)
2012-08-22 13:33:46,875 DEBUG [AudioDeliveryEngine] Delivering item '433' for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:33:46,875 DEBUG [AudioDeliveryEngine] Delivering file '06 Anapse to Tsigaro.m4a' using transcoding
2012-08-22 13:33:46,875 DEBUG [AbstractTranscodingDeliveryEngine] No other client uses transcoding job of file 'transcoding-temp-432-3-ORIGINAL.stf', will stop the job
2012-08-22 13:33:46,875 DEBUG [AbstractTranscodingDeliveryEngine] Stopping previous transcoding job of file 'transcoding-temp-432-3-ORIGINAL.stf'
2012-08-22 13:33:46,875 DEBUG [ProcessExecutor] Stopping external process: Thread[Thread-175,5,main]
2012-08-22 13:33:47,953 DEBUG [ProcessUtils] Killing the Windows process: 1648
2012-08-22 13:33:47,953 DEBUG [TranscodingJobListener] Transcoding finished; successful: true
2012-08-22 13:33:48,890 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-22 13:33:48,890 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-22 13:33:48,890 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 1)
2012-08-22 13:33:48,906 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 2)
2012-08-22 13:33:48,906 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 3)
2012-08-22 13:33:48,906 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 4)
2012-08-22 13:33:48,906 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 5)
2012-08-22 13:33:48,906 DEBUG [OnlineLibraryManager] Online resource http://www.hahasport.com/c-1.html?estreams=9 expired, will reload it
2012-08-22 13:33:48,906 DEBUG [OnlineLibraryManager] Resource http://www.hahasport.com/c-1.html?estreams=9 not in cache yet, loading it
2012-08-22 13:33:48,921 DEBUG [WebResourceParser] Parsing web resource 'http://www.hahasport.com/c-1.html?estreams=9'
2012-08-22 13:33:48,953 DEBUG [FeedItemUrlExtractor] Playlist extractor:   - transmitted from WebResourceParser - playlistUrl: null
2012-08-22 13:33:48,953 DEBUG [WebResourceParser] Found matching url extractor (HaHaSport) for resource http://www.hahasport.com/c-1.html?estreams=9
2012-08-22 13:33:48,953 DEBUG [FeedItemUrlExtractor] HaHaSport: Starting parsing resource: http://www.hahasport.com/c-1.html?estreams=9
2012-08-22 13:33:49,406 DEBUG [TranscodingJobListener] Deleted temp file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-432-3-ORIGINAL.stf': false
2012-08-22 13:33:49,421 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:33:49,421 DEBUG [MediaItemDAOImpl] Getting file of media item 433
2012-08-22 13:33:49,421 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode audio file: D:\ITUNES\Music\Compilations\Greek Bouzouki Nights - The Ultimate Col\06 Anapse to Tsigaro.m4a
2012-08-22 13:33:49,421 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\ITUNES\Music\Compilations\Greek Bouzouki Nights - The Ultimate Col\06 Anapse to Tsigaro.m4a -y -b:a 192k -ac 2 -vn -f mp3 C:\WINDOWS\TEMP\Serviio\transcoding-temp-433-3-ORIGINAL.stf
2012-08-22 13:34:01,546 DEBUG [WebServer] Incoming connection from /192.168.100.10:24609
2012-08-22 13:34:01,578 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:34:01,578 DEBUG [ResourceTransportRequestHandler] GET /resource/434/MEDIA_ITEM/MP3-0/ORIGINAL HTTP/1.1, headers = [User-Agent: Xenon,Connection: Keep-alive,Host: 192.168.100.1:8895,Content-Length: 3]]
2012-08-22 13:34:07,062 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:34:07,078 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:34:07,078 DEBUG [ResourceDeliveryProcessor] Request for resource 434 and type 'MEDIA_ITEM' received
2012-08-22 13:34:07,078 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 434 (local)
2012-08-22 13:34:07,078 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 434)
2012-08-22 13:34:07,078 DEBUG [MusicTrackDAOImpl] Reading a MusicTrack (id = 434)
2012-08-22 13:34:07,078 DEBUG [AudioDeliveryEngine] Delivering item '434' for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:34:07,359 DEBUG [AudioDeliveryEngine] Delivering file '07 Kaiki Mou Ai Nikola.m4a' using transcoding
2012-08-22 13:34:07,359 DEBUG [AbstractTranscodingDeliveryEngine] No other client uses transcoding job of file 'transcoding-temp-433-3-ORIGINAL.stf', will stop the job
2012-08-22 13:34:07,359 DEBUG [AbstractTranscodingDeliveryEngine] Stopping previous transcoding job of file 'transcoding-temp-433-3-ORIGINAL.stf'
2012-08-22 13:34:07,359 DEBUG [ProcessExecutor] Stopping external process: Thread[Thread-187,5,main]
2012-08-22 13:34:07,359 DEBUG [ProcessUtils] Killing the Windows process: 2412
2012-08-22 13:34:07,359 DEBUG [TranscodingJobListener] Transcoding finished; successful: true
2012-08-22 13:34:01,578 DEBUG [FileBasedTranscodingDeliveryStrategy] Sending transcoding stream
2012-08-22 13:34:07,078 DEBUG [WebServer] Incoming connection from /192.168.100.10:19574
2012-08-22 13:34:07,359 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:34:07,359 DEBUG [ResourceTransportRequestHandler] GET /resource/435/MEDIA_ITEM/MP3-0/ORIGINAL HTTP/1.1, headers = [User-Agent: Xenon,Connection: Keep-alive,Host: 192.168.100.1:8895,Content-Length: 3]]
2012-08-22 13:34:07,359 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:34:07,359 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:34:07,359 DEBUG [ResourceDeliveryProcessor] Request for resource 435 and type 'MEDIA_ITEM' received
2012-08-22 13:34:07,359 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 435 (local)
2012-08-22 13:34:07,359 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 435)
2012-08-22 13:34:07,359 DEBUG [MusicTrackDAOImpl] Reading a MusicTrack (id = 435)
2012-08-22 13:34:07,359 DEBUG [AudioDeliveryEngine] Delivering item '435' for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:34:07,359 DEBUG [AudioDeliveryEngine] Delivering file '08 Magissa Thessaloniki.m4a' using transcoding
2012-08-22 13:34:07,578 DEBUG [PlaylistDAOImpl] Reading all Playlists
2012-08-22 13:34:08,609 DEBUG [AudioDeliveryEngine] Found Format profile for transcoded file 06 Anapse to Tsigaro.m4a: MP3
2012-08-22 13:34:08,640 DEBUG [MediaItemDAOImpl] Marking MediaItem (id = 433) as read
2012-08-22 13:34:08,750 DEBUG [PlaylistMaintainerThread] Playlist Classical has unresolved items, checking if they are in the library now
2012-08-22 13:34:08,765 DEBUG [PlaylistParser] Parsing playlist 'D:\ITUNES\Playlists\Classical.pls'
2012-08-22 13:34:08,796 DEBUG [PlaylistParser] Reading playlist from a local file
2012-08-22 13:34:08,875 DEBUG [LocalContentCacheDecorator] Cleared cache (local_resetafterplay)
2012-08-22 13:34:08,875 DEBUG [TranscodingJobListener] Deleted temp file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-433-3-ORIGINAL.stf': false
2012-08-22 13:34:08,890 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:34:08,906 DEBUG [MediaItemDAOImpl] Getting file of media item 434
2012-08-22 13:34:08,906 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode audio file: D:\ITUNES\Music\Compilations\Greek Bouzouki Nights - The Ultimate Col\07 Kaiki Mou Ai Nikola.m4a
2012-08-22 13:34:08,906 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 900000000
2012-08-22 13:34:08,937 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-08-22 13:34:08,937 DEBUG [ResourceTransportRequestHandler] Creating entity with chunked transfer
2012-08-22 13:34:08,953 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: audio/mpeg,Date: Wed, 22 Aug 2012 01:34:08 GMT,Server: Windows XP, UPnP/1.0 DLNADOC/1.50, Serviio/1.0.1,Cache-control: no-cache,transferMode.dlna.org: Streaming]]
2012-08-22 13:34:08,968 DEBUG [WebServer] I/O error: Software caused connection abort: socket write error
2012-08-22 13:34:08,921 DEBUG [PlaylistParser] Found a suitable playlist parser strategy: PlsParserStrategy
2012-08-22 13:34:08,921 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\ITUNES\Music\Compilations\Greek Bouzouki Nights - The Ultimate Col\07 Kaiki Mou Ai Nikola.m4a -y -b:a 192k -ac 2 -vn -f mp3 C:\WINDOWS\TEMP\Serviio\transcoding-temp-434-3-ORIGINAL.stf
2012-08-22 13:34:09,000 DEBUG [PlaylistDAOImpl] Reading items for playlist 2
2012-08-22 13:34:14,953 DEBUG [PlaylistMaintainerThread] Found playlist item that has not been added yet: D:\ITUNES\Music\Cologne Chamber Orchestra, Helmut Muller\24 Hours of Classical Music � The Perfec\268 The Nutcracker Suite, Op. 71a_ V.m4a
2012-08-22 13:34:15,000 DEBUG [MediaItemDAOImpl] Looking up a media item for file path: D:\ITUNES\Music\Cologne Chamber Orchestra, Helmut Muller\24 Hours of Classical Music � The Perfec\268 The Nutcracker Suite, Op. 71a_ V.m4a, ignore case: true
2012-08-22 13:34:15,000 DEBUG [PlaylistMaintainerThread] Item 'D:\ITUNES\Music\Cologne Chamber Orchestra, Helmut Muller\24 Hours of Classical Music � The Perfec\268 The Nutcracker Suite, Op. 71a_ V.m4a' cannot be resolved to an entity in the Serviio library, will try again later
2012-08-22 13:34:15,062 DEBUG [PlaylistMaintainerThread] Playlist Folk has unresolved items, checking if they are in the library now
2012-08-22 13:34:15,093 DEBUG [PlaylistParser] Parsing playlist 'D:\ITUNES\Playlists\Folk.pls'
2012-08-22 13:34:20,468 DEBUG [PlaylistParser] Reading playlist from a local file
2012-08-22 13:34:20,531 DEBUG [PlaylistParser] Found a suitable playlist parser strategy: PlsParserStrategy
2012-08-22 13:34:21,015 DEBUG [PlaylistDAOImpl] Reading items for playlist 3
2012-08-22 13:34:20,546 WARN  [FeedUpdaterThread] An error occured while scanning for online item information, will continue
java.io.IOException: Unexpected error while invoking plugin (HaHaSport): The operation took more than 30000 ms and has been cancelled.
   at org.serviio.library.online.WebResourceParser.parse(WebResourceParser.java:58)
   at org.serviio.library.online.OnlineLibraryManager.findResource(OnlineLibraryManager.java:171)
   at org.serviio.library.online.OnlineLibraryManager.findResourceInCacheOrParse(OnlineLibraryManager.java:186)
   at org.serviio.library.online.metadata.FeedUpdaterThread.getOnlineItems(FeedUpdaterThread.java:159)
   at org.serviio.library.online.metadata.FeedUpdaterThread.run(FeedUpdaterThread.java:96)
Caused by: java.lang.RuntimeException: The operation took more than 30000 ms and has been cancelled.
   at org.serviio.library.online.PluginExecutionProcessor.execute(PluginExecutionProcessor.java:64)
   at org.serviio.library.online.WebResourceUrlExtractor.parseWebResource(WebResourceUrlExtractor.java:29)
   at org.serviio.library.online.WebResourceParser.parse(WebResourceParser.java:56)
   ... 4 more
2012-08-22 13:34:20,546 DEBUG [WebServer] Incoming connection from /192.168.100.10:46541
2012-08-22 13:34:21,640 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:34:21,640 DEBUG [ResourceTransportRequestHandler] GET /resource/436/MEDIA_ITEM/MP3-0/ORIGINAL HTTP/1.1, headers = [User-Agent: Xenon,Connection: Keep-alive,Host: 192.168.100.1:8895,Content-Length: 3]]
2012-08-22 13:34:21,640 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:34:21,640 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:34:21,656 DEBUG [ResourceDeliveryProcessor] Request for resource 436 and type 'MEDIA_ITEM' received
2012-08-22 13:34:21,656 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 436 (local)
2012-08-22 13:34:21,671 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 436)
2012-08-22 13:34:21,671 DEBUG [MusicTrackDAOImpl] Reading a MusicTrack (id = 436)
2012-08-22 13:34:21,687 DEBUG [AudioDeliveryEngine] Delivering item '436' for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:34:21,687 DEBUG [AudioDeliveryEngine] Delivering file '09 Misirlou.m4a' using transcoding
2012-08-22 13:34:21,625 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 6)
2012-08-22 13:34:27,531 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 8)
2012-08-22 13:34:27,546 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 13)
2012-08-22 13:34:21,546 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface eth0 (Realtek RTL8139/810x Family Fast Ethernet NIC) and address 192.168.100.1, timeout = 0
2012-08-22 13:34:27,906 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device f4f1ff23-a781-34a5-8123-b670571bd9d1
2012-08-22 13:34:28,093 DEBUG [WebServer] Incoming connection from /192.168.100.10:59490
2012-08-22 13:34:28,093 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:34:28,109 DEBUG [ResourceTransportRequestHandler] GET /resource/437/MEDIA_ITEM/MP3-0/ORIGINAL HTTP/1.1, headers = [User-Agent: Xenon,Connection: Keep-alive,Host: 192.168.100.1:8895,Content-Length: 3]]
2012-08-22 13:34:28,109 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.100.10
2012-08-22 13:34:28,125 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:34:28,125 DEBUG [ResourceDeliveryProcessor] Request for resource 437 and type 'MEDIA_ITEM' received
2012-08-22 13:34:28,125 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 437 (local)
2012-08-22 13:34:28,140 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 437)
2012-08-22 13:34:28,140 DEBUG [MusicTrackDAOImpl] Reading a MusicTrack (id = 437)
2012-08-22 13:34:28,140 DEBUG [AudioDeliveryEngine] Delivering item '437' for client 'IPAddress=/192.168.100.10, Profile=Xbox 360'
2012-08-22 13:34:28,156 DEBUG [AudioDeliveryEngine] Delivering file '10 Oso Aksizeis Esi.m4a' using transcoding


This time it skipped the first 9 tracks on this album. They have circles with lines through them.

Here is one example from the above log that isolates the problem:
  Code:
2012-08-22 13:33:16,703 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\ITUNES\Music\Compilations\Greek Bouzouki Nights - The Ultimate Col\02 To Diko Mou Paploma.m4a -y -b:a 192k -ac 2 -vn -f mp3 C:\WINDOWS\TEMP\Serviio\transcoding-temp-429-3-ORIGINAL.stf
2012-08-22 13:33:24,203 ERROR [ResourceTransportRequestHandler] Error while processing resource, sending back 500 error. Message: Transcoded file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-429-3-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
java.io.IOException: Transcoded file 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-429-3-ORIGINAL.stf' cannot be found, FFmpeg execution probably failed
   at org.serviio.delivery.resource.transcode.FileBasedTranscodingDeliveryStrategy.createInputStream(FileBasedTranscodingDeliveryStrategy.java:45)
   at org.serviio.delivery.resource.transcode.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:125)
   at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:95)
   at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:117)
   at org.serviio.delivery.ResourceDeliveryProcessor.deliverContent(ResourceDeliveryProcessor.java:84)
   at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:79)
   at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:61)
   at org.apache.http.protocol.HttpService.doService(HttpService.java:293)
   at org.serviio.upnp.webserver.ServiioHttpService.doService(ServiioHttpService.java:58)
   at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:212)
   at org.serviio.upnp.webserver.WebServer$WorkerThread.run(WebServer.java:191)



Other interesting things from the above log:
  Code:
2012-08-22 13:34:34,218 DEBUG [WebServer] I/O error: Read error
...
2012-08-22 13:34:34,421 DEBUG [WebServer] I/O error: Software caused connection abort: socket write error
...
2012-08-22 13:34:34,937 DEBUG [WebServer] I/O error: Software caused connection abort: socket write error


These socket write errors I see when trying to stream internet video (please see other thread)

Re: XBox intermittent audio file playback problems

PostPosted: Mon Aug 27, 2012 10:07 pm
by zip
try to run this and post the error

  Code:
ffmpeg.exe -i "D:\ITUNES\Music\Compilations\Greek Bouzouki Nights - The Ultimate Col\02 To Diko Mou Paploma.m4a" -y -b:a 192k -ac 2 -vn -f mp3 C:\WINDOWS\TEMP\Serviio\transcoding-temp-429-3-ORIGINAL.stf

Re: XBox intermittent audio file playback problems

PostPosted: Mon Aug 27, 2012 10:11 pm
by grolschie
Thanks. No error. It's intermittant.

  Code:
C:\Program Files\Serviio\lib>ffmpeg.exe -i "D:\ITUNES\Music\Compilations\Greek B
ouzouki Nights - The Ultimate Col\02 To Diko Mou Paploma.m4a" -y -b:a 192k -ac 2
 -vn -f mp3 C:\WINDOWS\TEMP\Serviio\transcoding-temp-429-3-ORIGINAL.stf
ffmpeg version N-43594-gf0896a6 Copyright (c) 2000-2012 the FFmpeg developers
  built on Aug 15 2012 21:25:48 with gcc 4.7.1 (GCC)
  configuration: --enable-gpl --enable-version3 --disable-pthreads --enable-runt
ime-cpudetect --enable-avisynth --enable-bzlib --enable-frei0r --enable-libass -
-enable-libcelt --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-l
ibfreetype --enable-libgsm --enable-libmp3lame --enable-libnut --enable-libopenj
peg --enable-librtmp --enable-libschroedinger --enable-libspeex --enable-libtheo
ra --enable-libutvideo --enable-libvo-aacenc --enable-libvo-amrwbenc --enable-li
bvorbis --enable-libvpx --enable-libx264 --enable-libxavs --enable-libxvid --ena
ble-zlib
  libavutil      51. 69.100 / 51. 69.100
  libavcodec     54. 52.100 / 54. 52.100
  libavformat    54. 23.101 / 54. 23.101
  libavdevice    54.  2.100 / 54.  2.100
  libavfilter     3.  9.100 /  3.  9.100
  libswscale      2.  1.101 /  2.  1.101
  libswresample   0. 15.100 /  0. 15.100
  libpostproc    52.  0.100 / 52.  0.100
[mov,mp4,m4a,3gp,3g2,mj2 @ 023ed620] max_analyze_duration 5000000 reached at 501
5510
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from 'D:\ITUNES\Music\Compilations\Greek Bouz
ouki Nights - The Ultimate Col\02 To Diko Mou Paploma.m4a':
  Metadata:
    major_brand     : M4A
    minor_version   : 0
    compatible_brands: M4A mp42isom
    creation_time   : 2005-03-05 19:30:15
    title           : To Diko Mou Paploma
    artist          : Fr. Kavvadia & G. Bogdanos
    album_artist    : Various Artists
    album           : Greek Bouzouki Nights - The Ultimate Collection of Classic
 "Bouzouki" Greek Songs
    track           : 2/14
    disc            : 1/1
    gapless_playback: 0
    date            : 2007-05-15T07:00:00Z
    copyright       : Γäù 2007 Lyra
    media_type      : 1
    genre           : Greek
  Duration: 00:02:00.81, start: 0.000000, bitrate: 301 kb/s
    Stream #0:0(eng): Audio: aac (mp4a / 0x6134706D), 44100 Hz, stereo, s16, 263
 kb/s
    Metadata:
      creation_time   : 2005-03-05 19:30:15
    Stream #0:1: Video: mjpeg, yuvj444p, 600x600 [SAR 72:72 DAR 1:1], 90k tbr, 9
0k tbn, 90k tbc
Output #0, mp3, to 'C:\WINDOWS\TEMP\Serviio\transcoding-temp-429-3-ORIGINAL.stf'
:
  Metadata:
    major_brand     : M4A
    minor_version   : 0
    compatible_brands: M4A mp42isom
    TCON            : Greek
    TIT2            : To Diko Mou Paploma
    TPE1            : Fr. Kavvadia & G. Bogdanos
    TPE2            : Various Artists
    TALB            : Greek Bouzouki Nights - The Ultimate Collection of Classic
 "Bouzouki" Greek Songs
    TRCK            : 2/14
    TPOS            : 1/1
    gapless_playback: 0
    TDRL            : 2007-05-15T07:00:00Z
    TCOP            : Γäù 2007 Lyra
    media_type      : 1
    TSSE            : Lavf54.23.101
    Stream #0:0(eng): Audio: mp3, 44100 Hz, stereo, s16, 192 kb/s
    Metadata:
      creation_time   : 2005-03-05 19:30:15
Stream mapping:
  Stream #0:0 -> #0:0 (aac -> libmp3lame)
Press [q] to stop, [?] for help
size=    2833kB time=00:02:00.83 bitrate= 192.0kbits/s
video:0kB audio:2832kB subtitle:0 global headers:0kB muxing overhead 0.038143%


Basically, it's like for a moment Serviio becomes unavailable or something, and each track fails to play, one by one. Then it starts working, and whatever track it's up to, starts to play. I have tried a newer version of ffmpeg. And I am also running ProLasso to keep processes from hogging my single-core CPU. I suspect that when the error occurs, there maybe already an ffmpeg process running with online library updates, etc.
All times are UTC
Page 1 of 1
Powered by phpBB © 2000, 2002, 2005, 2007 phpBB Group
http://www.phpbb.com/