MediaBrower cannot replay LiveStreams

EDIT: See the viewtopic.php?f=5&t=7138#p51658 post in this thread for the summary of this bug.
When playing a live stream with mediabrowser set to orig quality, regardless of the original stream, the first play works correctly but the second play cannot find the original transcoded file, for example with either of these streams
The first play works fine but on the second play mediabrowser issues the following error message that the transcoded stream cannot be found.
The log shows the first play transcoded the file and that subsequent playbacks used the existing transcode without errors. There is no indication that Mediabrowser was unable to find the previously transcoded file.
I discovered this in attempting to play SOPCAST's http:\\127.0.0.1:8902 but it also happens with other http: streams as documented above. However it does not happen with other streams like rtmp,rtsp,or mmsh. It is similar to the problem we had during the beta where a repeat playback would not work until another file was played back.
Additional tests:
Set mediabrowser to play medium quality by default.
Repetitive playbacks in medium work fine, but the file is transcoded each time, unlike original which unsuccessfully tries to reuse previous transcoded file.
Switching to Original in the player just hangs on spinning wheel, and nothing shows in the log except the kill of the previous playback, then
Switching to low resolution on the player works fine.
When playing a live stream with mediabrowser set to orig quality, regardless of the original stream, the first play works correctly but the second play cannot find the original transcoded file, for example with either of these streams
- Code:
http://127.0.0.1:8902
Input #0, mpegts, from 'http://127.0.0.1:8902':
Duration: N/A, start: 36800.171189, bitrate: 96 kb/s
Program 1
Stream #0:0[0x56](eng): Audio: mp2 ([3][0][0][0] / 0x0003), 48000 Hz, mono,
s16, 96 kb/s
Stream #0:1[0x57]: Video: h264 (Constrained Baseline) ([27][0][0][0] / 0x001
B), yuv420p, 646x396 [SAR 128:117 DAR 20672:11583], 62 fps, 25 tbr, 90k tbn, 50
tbc
or
http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d
Input #0, mpegts, from 'http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e206
69fbdfb31493d':
Duration: N/A, start: 27534.794789, bitrate: 15096 kb/s
Program 256
Metadata:
service_name : ?Eurosport Radug
service_provider: ?GTSS
Stream #0:0[0x80]: Video: mpeg2video (Main) ([2][0][0][0] / 0x0002), yuv420p
, 704x576 [SAR 16:11 DAR 16:9], 15000 kb/s, 31.62 fps, 25 tbr, 90k tbn, 50 tbc
Stream #0:1[0x81]: Audio: mp2 ([4][0][0][0] / 0x0004), 48000 Hz, mono, s16,
96 kb/s
The first play works fine but on the second play mediabrowser issues the following error message that the transcoded stream cannot be found.
- Code:
Error: 200, Stream not found, NetStream.Play.StreamNotFound, clip: '[Clip] 'http://localhost:23424/cds/resource/1000000000800001/MEDIA_ITEM/FLV-0/ORIGINAL,flv_player?authToken=c3e6c87377fa434f8467c784d75da3db''
at org.flowplayer.view::Launcher/doHandleError()
at org.flowplayer.view::Launcher/onClipError()
at EventListener/notify()
at org.flowplayer.model::EventDispatcher/_dispatchEvent()
at org.flowplayer.model::EventDispatcher/http://flowplayer.org/core/internal::doDispatchErrorEvent()
at org.flowplayer.model::EventDispatcher/http://flowplayer.org/core/internal::doDispatchEvent()
at org.flowplayer.model::Clip/onClipEvent()
at EventListener/notify()
at org.flowplayer.model::EventDispatcher/_dispatchEvent()
at org.flowplayer.model::EventDispatcher/http://flowplayer.org/core/internal::doDispatchErrorEvent()
at org.flowplayer.model::ClipEventDispatcher/dispatchError()
at org.flowplayer.controller::NetStreamControllingStreamProvider/_onNetStatus()
The log shows the first play transcoded the file and that subsequent playbacks used the existing transcode without errors. There is no indication that Mediabrowser was unable to find the previously transcoded file.
- Code:
2012-08-20 09:24:32,301 DEBUG [CDSRetrieveMediaServerResource] Request for content delivery accepted
2012-08-20 09:24:32,301 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 09:24:32,301 DEBUG [ResourceDeliveryProcessor] Request for resource 1000000000800001 and type 'MEDIA_ITEM' received
2012-08-20 09:24:32,301 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000000800001 (online)
2012-08-20 09:24:32,302 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 09:24:32,303 DEBUG [VideoDeliveryEngine] Delivering item '1000000000800001' for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 09:24:32,303 DEBUG [VideoDeliveryEngine] Delivering file 'http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d' using transcoding
2012-08-20 09:24:32,303 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 09:24:32,304 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d
2012-08-20 09:24:32,304 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d -y -copyts -c:v flv -sameq -vf scale=1024:576,setsar=1 -r 24000/1001 -g 15 -c:a libmp3lame -b:a 96k -ar 44100 -ac 1 -map 0:0 -map 0:1 -sn -f flv pipe:
2012-08-20 09:24:41,305 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 09:24:41,305 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 09:24:41,305 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 09:24:41,305 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 50000000000
2012-08-20 09:24:41,306 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-08-20 09:24:55,203 DEBUG [CDSRetrieveMediaServerResource] Request for content delivery accepted
2012-08-20 09:24:55,203 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 09:24:55,204 DEBUG [ResourceDeliveryProcessor] Request for resource 1000000000800001 and type 'MEDIA_ITEM' received
2012-08-20 09:24:55,204 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000000800001 (online)
2012-08-20 09:24:55,204 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 09:24:55,204 DEBUG [VideoDeliveryEngine] Delivering item '1000000000800001' for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 09:24:55,205 DEBUG [VideoDeliveryEngine] Delivering file 'http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d' using transcoding
2012-08-20 09:24:55,205 DEBUG [AbstractTranscodingDeliveryEngine] A suitable transcoding job already exists, re-use it for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 09:24:55,205 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 09:24:55,205 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 09:24:55,205 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 09:24:55,205 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 50000000000
2012-08-20 09:24:55,205 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-08-20 09:24:55,303 DEBUG [CDSRetrieveMediaServerResource] Request for content delivery accepted
2012-08-20 09:24:55,303 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 09:24:55,304 DEBUG [ResourceDeliveryProcessor] Request for resource 1000000000800001 and type 'MEDIA_ITEM' received
2012-08-20 09:24:55,304 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000000800001 (online)
2012-08-20 09:24:55,304 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 09:24:55,304 DEBUG [VideoDeliveryEngine] Delivering item '1000000000800001' for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 09:24:55,305 DEBUG [VideoDeliveryEngine] Delivering file 'http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d' using transcoding
2012-08-20 09:24:55,305 DEBUG [AbstractTranscodingDeliveryEngine] A suitable transcoding job already exists, re-use it for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 09:24:56,305 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 09:24:56,305 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 09:24:56,305 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 09:24:56,305 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 50000000000
2012-08-20 09:24:56,305 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-08-20 09:24:56,404 DEBUG [CDSRetrieveMediaServerResource] Request for content delivery accepted
2012-08-20 09:24:56,404 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 09:24:56,404 DEBUG [ResourceDeliveryProcessor] Request for resource 1000000000800001 and type 'MEDIA_ITEM' received
2012-08-20 09:24:56,404 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000000800001 (online)
2012-08-20 09:24:56,404 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 09:24:56,405 DEBUG [VideoDeliveryEngine] Delivering item '1000000000800001' for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 09:24:56,405 DEBUG [VideoDeliveryEngine] Delivering file 'http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d' using transcoding
2012-08-20 09:24:56,405 DEBUG [AbstractTranscodingDeliveryEngine] A suitable transcoding job already exists, re-use it for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 09:24:56,405 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 09:24:56,405 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 09:24:56,406 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 09:24:56,406 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 50000000000
2012-08-20 09:24:56,406 DEBUG [ResourceDeliveryProcessor] Sending file back
I discovered this in attempting to play SOPCAST's http:\\127.0.0.1:8902 but it also happens with other http: streams as documented above. However it does not happen with other streams like rtmp,rtsp,or mmsh. It is similar to the problem we had during the beta where a repeat playback would not work until another file was played back.
Additional tests:
Set mediabrowser to play medium quality by default.
Repetitive playbacks in medium work fine, but the file is transcoded each time, unlike original which unsuccessfully tries to reuse previous transcoded file.
Switching to Original in the player just hangs on spinning wheel, and nothing shows in the log except the kill of the previous playback, then
Switching to low resolution on the player works fine.
- Code:
2012-08-20 10:59:05,200 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 10:59:05,201 DEBUG [ResourceDeliveryProcessor] Request for resource 1000000000800001 and type 'MEDIA_ITEM' received
2012-08-20 10:59:05,201 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000000800001 (online)
2012-08-20 10:59:05,201 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 10:59:05,203 DEBUG [VideoDeliveryEngine] Delivering item '1000000000800001' for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 10:59:05,203 DEBUG [VideoDeliveryEngine] Delivering file 'http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d' using transcoding
2012-08-20 10:59:05,204 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 10:59:05,205 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d
2012-08-20 10:59:05,205 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d -y -copyts -c:v flv -b:v 1000k -maxrate:v 1000k -bufsize:v 1000k -vf scale=854:480,setsar=1 -r 24000/1001 -g 15 -c:a libmp3lame -b:a 96k -ar 44100 -ac 1 -map 0:0 -map 0:1 -sn -f flv pipe:
2012-08-20 10:59:16,205 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 10:59:16,205 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 10:59:16,205 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 10:59:16,205 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 50000000000
2012-08-20 10:59:16,205 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-08-20 11:01:01,312 DEBUG [CDSRetrieveMediaServerResource] Request for content delivery accepted
2012-08-20 11:01:01,312 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 11:01:01,313 DEBUG [ResourceDeliveryProcessor] Request for resource 1000000000800001 and type 'MEDIA_ITEM' received
2012-08-20 11:01:01,313 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000000800001 (online)
2012-08-20 11:01:01,313 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:01:01,314 DEBUG [VideoDeliveryEngine] Delivering item '1000000000800001' for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 11:01:01,315 DEBUG [VideoDeliveryEngine] Delivering file 'http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d' using transcoding
2012-08-20 11:01:01,315 DEBUG [AbstractTranscodingDeliveryEngine] Stopping previous transcoding job of file 'transcoding-temp-1000000000800001-flv_player-MEDIUM.stf'
2012-08-20 11:01:01,315 DEBUG [ProcessExecutor] Stopping external process: Thread[Thread-121,5,main]
2012-08-20 11:01:01,316 DEBUG [ProcessUtils] Killing the Windows process: 17228
2012-08-20 11:01:01,335 DEBUG [TranscodingJobListener] Transcoding finished; successful: true
2012-08-20 11:01:01,336 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 11:01:01,337 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d
2012-08-20 11:01:01,338 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d -y -copyts -c:v flv -b:v 1000k -maxrate:v 1000k -bufsize:v 1000k -vf scale=854:480,setsar=1 -r 24000/1001 -g 15 -c:a libmp3lame -b:a 96k -ar 44100 -ac 1 -map 0:0 -map 0:1 -sn -f flv pipe:
2012-08-20 11:01:12,839 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 11:01:12,839 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 11:01:12,839 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 11:01:12,839 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 50000000000
2012-08-20 11:01:12,839 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-08-20 11:01:13,002 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.10:57538
2012-08-20 11:01:13,002 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:01:13,003 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:57538
2012-08-20 11:01:16,344 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:01:16,345 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:01:16,876 DEBUG [NonClosingPipedInputStream] Closing piped input stream and closing related feeder process
2012-08-20 11:01:17,615 WARN [PipedOutputBytesReader] Error reading bytes stream from external process: Stream closed
2012-08-20 11:01:18,145 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:55
2012-08-20 11:01:24,300 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-20 11:01:24,300 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-20 11:01:24,305 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 50)
2012-08-20 11:01:24,314 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 76)
2012-08-20 11:01:24,315 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 77)
2012-08-20 11:01:24,315 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:02:14,000 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:02:14,000 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:02:15,801 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:55
2012-08-20 11:02:19,115 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.10:57538
2012-08-20 11:02:19,115 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:02:19,116 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:57538
2012-08-20 11:02:24,317 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-20 11:02:24,317 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-20 11:02:24,324 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 50)
2012-08-20 11:02:24,341 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 76)
2012-08-20 11:02:24,342 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 77)
2012-08-20 11:02:24,342 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:03:08,068 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:MediaRenderer:1 from address /192.168.1.10:63950
2012-08-20 11:03:08,068 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:03:08,069 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:MediaServer:1 from address /192.168.1.10:63950
2012-08-20 11:03:08,069 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:03:08,069 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:63950
2012-08-20 11:03:09,393 DEBUG [WebServer] Incoming connection from /192.168.1.10:50685
2012-08-20 11:03:09,393 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:03:09,394 DEBUG [DeviceDescriptionRequestHandler] DeviceDescription request received for device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65 from 192.168.1.10 (headers = [Cache-Control: no-cache,Connection: Close,Pragma: no-cache,Accept: text/xml, application/xml,Host: 192.168.1.10:8895,User-Agent: Microsoft-Windows/6.1 UPnP/1.0 Windows-Media-Player-DMS/12.0.7600.16385 DLNADOC/1.50])
2012-08-20 11:03:09,394 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:03:09,394 DEBUG [RendererManager] Looking for a renderer profile for Http headers: [Cache-Control: no-cache,Connection: Close,Pragma: no-cache,Accept: text/xml, application/xml,Host: 192.168.1.10:8895,User-Agent: Microsoft-Windows/6.1 UPnP/1.0 Windows-Media-Player-DMS/12.0.7600.16385 DLNADOC/1.50]
2012-08-20 11:03:09,395 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:03:09,404 DEBUG [DeviceDescriptionRequestHandler] Sending DeviceDescription XML back using profile 'Generic DLNA profile'
2012-08-20 11:03:09,434 DEBUG [WebServer] Incoming connection from /192.168.1.10:50686
2012-08-20 11:03:09,434 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:03:09,435 DEBUG [UPnPIconRequestHandler] UPnP icon request received for icon smallPNG
2012-08-20 11:03:11,067 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:MediaRenderer:1 from address /192.168.1.10:63950
2012-08-20 11:03:11,067 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:03:11,068 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:MediaServer:1 from address /192.168.1.10:63950
2012-08-20 11:03:11,068 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:03:11,069 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:63950
2012-08-20 11:03:11,690 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:03:11,691 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:03:13,491 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:41
2012-08-20 11:03:14,067 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:MediaRenderer:1 from address /192.168.1.10:63950
2012-08-20 11:03:14,067 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:03:14,068 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:MediaServer:1 from address /192.168.1.10:63950
2012-08-20 11:03:14,068 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:03:14,069 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:63950
2012-08-20 11:03:24,344 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-20 11:03:24,344 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-20 11:03:24,346 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 50)
2012-08-20 11:03:24,365 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 76)
2012-08-20 11:03:24,365 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 77)
2012-08-20 11:03:24,366 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:03:25,227 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.10:57538
2012-08-20 11:03:25,227 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:03:25,228 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:57538
2012-08-20 11:03:55,171 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:03:55,172 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:03:56,972 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:57
2012-08-20 11:04:03,220 DEBUG [PlaylistDAOImpl] Reading all Playlists
2012-08-20 11:04:03,228 DEBUG [PlaylistMaintainerThread] Playlist ALL MUSIC FOR WIIMC+ has unresolved items, checking if they are in the library now
2012-08-20 11:04:03,228 DEBUG [PlaylistParser] Parsing playlist 'D:\My Music\- Playlists\ALL MUSIC FOR WIIMC+.m3u'
2012-08-20 11:04:03,228 DEBUG [PlaylistParser] Reading playlist from a local file
2012-08-20 11:04:03,230 DEBUG [PlaylistParser] Found a suitable playlist parser strategy: M3UParserStrategy
2012-08-20 11:04:03,401 DEBUG [PlaylistDAOImpl] Reading items for playlist 9
2012-08-20 11:04:03,424 DEBUG [PlaylistMaintainerThread] Found playlist item that has not been added yet: D:\My Music\Freddy Fender - Forever Gold (2000)\Freddy Fender - Forever Gold 01 - Wasted Days And Wasted Nights.mp3
2012-08-20 11:04:03,424 DEBUG [MediaItemDAOImpl] Looking up a media item for file path: D:\My Music\Freddy Fender - Forever Gold (2000)\Freddy Fender - Forever Gold 01 - Wasted Days And Wasted Nights.mp3, ignore case: true
2012-08-20 11:04:03,425 DEBUG [PlaylistMaintainerThread] Item 'D:\My Music\Freddy Fender - Forever Gold (2000)\Freddy Fender - Forever Gold 01 - Wasted Days And Wasted Nights.mp3' cannot be resolved to an entity in the Serviio library, will try again later
2012-08-20 11:04:17,069 DEBUG [WebServer] I/O error: Connection reset
2012-08-20 11:04:31,337 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.10:57538
2012-08-20 11:04:31,338 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:04:31,338 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:57538
2012-08-20 11:04:35,668 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:04:35,668 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:04:38,668 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:04:38,668 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:04:41,668 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:04:41,668 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:04:44,684 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:04:44,684 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:04:47,684 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:04:47,684 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:04:50,684 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:04:50,684 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:04:54,992 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:04:54,993 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:04:56,793 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:36
2012-08-20 11:05:24,385 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-20 11:05:24,385 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-20 11:05:24,387 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 50)
2012-08-20 11:05:24,396 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 76)
2012-08-20 11:05:24,397 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 77)
2012-08-20 11:05:24,397 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:05:33,289 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:05:33,290 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:05:34,671 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:05:34,671 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:05:35,090 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:50
2012-08-20 11:05:37,448 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.10:57538
2012-08-20 11:05:37,448 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:05:37,449 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:57538
2012-08-20 11:05:37,671 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:05:37,671 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:05:40,671 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:05:40,671 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:05:43,689 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:05:43,689 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:05:46,686 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:05:46,686 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:05:49,686 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:05:49,686 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:06:24,399 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-20 11:06:24,399 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-20 11:06:24,401 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 50)
2012-08-20 11:06:24,410 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 76)
2012-08-20 11:06:24,411 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 77)
2012-08-20 11:06:24,411 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:06:25,411 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:06:25,411 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:06:27,212 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:54
2012-08-20 11:06:43,561 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.10:57538
2012-08-20 11:06:43,561 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:06:43,562 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:57538
2012-08-20 11:07:21,701 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:07:21,702 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:07:23,502 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:58
2012-08-20 11:07:24,412 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-20 11:07:24,412 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-20 11:07:24,414 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 50)
2012-08-20 11:07:24,423 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 76)
2012-08-20 11:07:24,424 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 77)
2012-08-20 11:07:24,424 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:07:49,674 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.10:57538
2012-08-20 11:07:49,674 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:07:49,675 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:57538
2012-08-20 11:08:22,445 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:08:22,446 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:08:24,246 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:41
2012-08-20 11:08:24,426 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-20 11:08:24,426 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-20 11:08:24,430 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 50)
2012-08-20 11:08:24,446 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 76)
2012-08-20 11:08:24,447 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 77)
2012-08-20 11:08:24,448 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:08:55,791 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.10:57538
2012-08-20 11:08:55,792 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:08:55,792 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:57538
2012-08-20 11:09:02,742 DEBUG [NonClosingPipedInputStream] Closing piped input stream and closing related feeder process
2012-08-20 11:09:02,742 DEBUG [ProcessExecutor] Stopping external process: Thread[Thread-125,5,main]
2012-08-20 11:09:02,742 DEBUG [ProcessUtils] Killing the Windows process: 11024
2012-08-20 11:09:02,764 DEBUG [TranscodingJobListener] Transcoding finished; successful: true
2012-08-20 11:09:03,077 WARN [PipedOutputBytesReader] Error reading bytes stream from external process: Stream closed
2012-08-20 11:09:03,457 DEBUG [PlaylistDAOImpl] Reading all Playlists
2012-08-20 11:09:03,468 DEBUG [PlaylistMaintainerThread] Playlist ALL MUSIC FOR WIIMC+ has unresolved items, checking if they are in the library now
2012-08-20 11:09:03,469 DEBUG [PlaylistParser] Parsing playlist 'D:\My Music\- Playlists\ALL MUSIC FOR WIIMC+.m3u'
2012-08-20 11:09:03,469 DEBUG [PlaylistParser] Reading playlist from a local file
2012-08-20 11:09:03,471 DEBUG [PlaylistParser] Found a suitable playlist parser strategy: M3UParserStrategy
2012-08-20 11:09:03,503 DEBUG [PlaylistDAOImpl] Reading items for playlist 9
2012-08-20 11:09:03,520 DEBUG [PlaylistMaintainerThread] Found playlist item that has not been added yet: D:\My Music\Freddy Fender - Forever Gold (2000)\Freddy Fender - Forever Gold 01 - Wasted Days And Wasted Nights.mp3
2012-08-20 11:09:03,521 DEBUG [MediaItemDAOImpl] Looking up a media item for file path: D:\My Music\Freddy Fender - Forever Gold (2000)\Freddy Fender - Forever Gold 01 - Wasted Days And Wasted Nights.mp3, ignore case: true
2012-08-20 11:09:03,521 DEBUG [PlaylistMaintainerThread] Item 'D:\My Music\Freddy Fender - Forever Gold (2000)\Freddy Fender - Forever Gold 01 - Wasted Days And Wasted Nights.mp3' cannot be resolved to an entity in the Serviio library, will try again later
2012-08-20 11:09:05,948 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:09:05,949 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:09:07,749 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:41
2012-08-20 11:09:24,449 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-20 11:09:24,449 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-20 11:09:24,453 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 50)
2012-08-20 11:09:24,468 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 76)
2012-08-20 11:09:24,469 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 77)
2012-08-20 11:09:24,470 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:09:49,925 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:09:49,926 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:09:51,726 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:57
2012-08-20 11:10:01,910 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.10:57538
2012-08-20 11:10:01,911 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:10:01,911 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:57538
2012-08-20 11:10:24,472 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-20 11:10:24,472 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-20 11:10:24,476 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 50)
2012-08-20 11:10:24,492 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 76)
2012-08-20 11:10:24,492 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 77)
2012-08-20 11:10:24,493 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:10:46,827 DEBUG [CDSRetrieveMediaServerResource] Request for content delivery accepted
2012-08-20 11:10:46,827 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 11:10:46,828 DEBUG [ResourceDeliveryProcessor] Request for resource 1000000000800001 and type 'MEDIA_ITEM' received
2012-08-20 11:10:46,828 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000000800001 (online)
2012-08-20 11:10:46,828 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:10:46,829 DEBUG [VideoDeliveryEngine] Delivering item '1000000000800001' for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 11:10:46,830 DEBUG [VideoDeliveryEngine] Delivering file 'http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d' using transcoding
2012-08-20 11:10:46,830 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 11:10:46,831 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d
2012-08-20 11:10:46,831 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d -y -copyts -c:v flv -b:v 1000k -maxrate:v 1000k -bufsize:v 1000k -vf scale=854:480,setsar=1 -r 24000/1001 -g 15 -c:a libmp3lame -b:a 96k -ar 44100 -ac 1 -map 0:0 -map 0:1 -sn -f flv pipe:
2012-08-20 11:10:49,889 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:10:49,890 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:10:51,690 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:45
2012-08-20 11:10:57,831 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 11:10:57,831 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 11:10:57,831 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 11:10:57,831 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 50000000000
2012-08-20 11:10:57,831 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-08-20 11:11:08,025 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.10:57538
2012-08-20 11:11:08,025 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:11:08,026 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:57538
2012-08-20 11:11:24,493 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-20 11:11:24,493 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-20 11:11:24,497 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 50)
2012-08-20 11:11:24,513 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 76)
2012-08-20 11:11:24,514 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 77)
2012-08-20 11:11:24,515 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:11:37,021 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:11:37,022 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:11:38,822 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:38
2012-08-20 11:11:42,680 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:11:42,680 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:11:45,679 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:11:45,679 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:11:48,679 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:11:48,679 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:11:51,695 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:11:51,695 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:11:54,695 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:11:54,695 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:11:57,695 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:11:57,695 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:12:14,145 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.10:57538
2012-08-20 11:12:14,145 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:12:14,146 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:57538
2012-08-20 11:12:17,233 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:12:17,234 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:12:19,034 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:40
2012-08-20 11:12:24,515 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-20 11:12:24,515 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-20 11:12:24,519 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 50)
2012-08-20 11:12:24,535 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 76)
2012-08-20 11:12:24,536 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 77)
2012-08-20 11:12:24,536 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:12:42,705 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:12:42,705 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:12:45,705 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:12:45,705 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:12:48,705 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:12:48,705 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:12:51,731 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:12:51,731 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:12:54,731 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:12:54,731 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:12:57,731 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.1.10:63950
2012-08-20 11:12:57,731 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:13:00,020 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:13:00,021 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:13:01,822 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:54
2012-08-20 11:13:20,271 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.10:57538
2012-08-20 11:13:20,271 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:13:20,272 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:57538
2012-08-20 11:13:22,804 DEBUG [NonClosingPipedInputStream] Closing piped input stream and closing related feeder process
2012-08-20 11:13:22,804 DEBUG [ProcessExecutor] Stopping external process: Thread[Thread-131,5,main]
2012-08-20 11:13:22,804 DEBUG [ProcessUtils] Killing the Windows process: 10220
2012-08-20 11:13:22,828 DEBUG [TranscodingJobListener] Transcoding finished; successful: true
2012-08-20 11:13:22,985 WARN [PipedOutputBytesReader] Error reading bytes stream from external process: Stream closed
2012-08-20 11:13:24,538 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-20 11:13:24,538 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-20 11:13:24,542 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 50)
2012-08-20 11:13:24,563 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 76)
2012-08-20 11:13:24,564 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 77)
2012-08-20 11:13:24,565 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:13:56,709 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:13:56,710 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:13:58,510 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:38
2012-08-20 11:14:03,537 DEBUG [PlaylistDAOImpl] Reading all Playlists
2012-08-20 11:14:03,549 DEBUG [PlaylistMaintainerThread] Playlist ALL MUSIC FOR WIIMC+ has unresolved items, checking if they are in the library now
2012-08-20 11:14:03,549 DEBUG [PlaylistParser] Parsing playlist 'D:\My Music\- Playlists\ALL MUSIC FOR WIIMC+.m3u'
2012-08-20 11:14:03,549 DEBUG [PlaylistParser] Reading playlist from a local file
2012-08-20 11:14:03,552 DEBUG [PlaylistParser] Found a suitable playlist parser strategy: M3UParserStrategy
2012-08-20 11:14:03,731 DEBUG [PlaylistDAOImpl] Reading items for playlist 9
2012-08-20 11:14:03,744 DEBUG [PlaylistMaintainerThread] Found playlist item that has not been added yet: D:\My Music\Freddy Fender - Forever Gold (2000)\Freddy Fender - Forever Gold 01 - Wasted Days And Wasted Nights.mp3
2012-08-20 11:14:03,744 DEBUG [MediaItemDAOImpl] Looking up a media item for file path: D:\My Music\Freddy Fender - Forever Gold (2000)\Freddy Fender - Forever Gold 01 - Wasted Days And Wasted Nights.mp3, ignore case: true
2012-08-20 11:14:03,744 DEBUG [PlaylistMaintainerThread] Item 'D:\My Music\Freddy Fender - Forever Gold (2000)\Freddy Fender - Forever Gold 01 - Wasted Days And Wasted Nights.mp3' cannot be resolved to an entity in the Serviio library, will try again later
2012-08-20 11:14:24,565 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-08-20 11:14:24,565 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-08-20 11:14:24,568 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 50)
2012-08-20 11:14:24,583 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 76)
2012-08-20 11:14:24,584 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 77)
2012-08-20 11:14:24,585 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:14:26,392 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.1.10:57538
2012-08-20 11:14:26,392 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.1.10
2012-08-20 11:14:26,393 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.1.10:57538
2012-08-20 11:14:37,319 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface net4 (Realtek RTL8191SE Wireless LAN 802.11n PCI-E NIC) and address 192.168.1.10, timeout = 0
2012-08-20 11:14:37,319 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
2012-08-20 11:14:39,119 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:00:47
2012-08-20 11:14:56,322 DEBUG [CDSRetrieveMediaServerResource] Request for content delivery accepted
2012-08-20 11:14:56,326 DEBUG [ResourceDeliveryProcessor] Resource request accepted. Using client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 11:14:56,326 DEBUG [ResourceDeliveryProcessor] Request for resource 1000000000800001 and type 'MEDIA_ITEM' received
2012-08-20 11:14:56,326 DEBUG [MediaResourceRetrievalStrategy] Getting information about media item 1000000000800001 (online)
2012-08-20 11:14:56,327 DEBUG [OnlineRepositoryDAOImpl] Reading an OnlineRepository (id = 80)
2012-08-20 11:14:56,328 DEBUG [VideoDeliveryEngine] Delivering item '1000000000800001' for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 11:14:56,328 DEBUG [VideoDeliveryEngine] Delivering file 'http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d' using transcoding
2012-08-20 11:14:56,329 DEBUG [AbstractTranscodingDeliveryEngine] No suitable transcoding job exists yet, start one for client 'IPAddress=/127.0.0.1, Profile=Flash player'
2012-08-20 11:14:56,329 DEBUG [FFMPEGWrapper] Invoking FFmpeg to transcode video file: http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d
2012-08-20 11:14:56,330 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d -y -copyts -c:v flv -b:v 500k -maxrate:v 500k -bufsize:v 500k -vf scale=356:200,setsar=1 -r 24000/1001 -g 15 -c:a libmp3lame -b:a 96k -ar 44100 -ac 1 -map 0:0 -map 0:1 -sn -f flv pipe:
2012-08-20 11:15:04,331 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 11:15:04,331 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 11:15:04,331 DEBUG [VideoDeliveryEngine] Found Format profile for transcoded file http://194.28.91.43:8080/esp_russian-8b3f33d1a1e1ca1e20669fbdfb31493d: FLV
2012-08-20 11:15:04,331 DEBUG [ResourceDeliveryProcessor] Stream entity has length: 50000000000
2012-08-20 11:15:04,331 DEBUG [ResourceDeliveryProcessor] Sending file back
2012-08-20 11:15:04,622 DEBUG [CDSRetrieveMediaServerResource]