by abeloin » Thu Oct 27, 2011 8:32 pm
Just tried it with build 1450 and the issue is still not resolved.
Also, while trying different combinations, I stumble on a weird behavior: MM4 refuse to play any M4A or FLAC files hosted on Serviio. MM4 will try via in_wma.dll first, then in_wmp3.dll and give up after. I wasn't able to reproduce the issue with other renderer (Foobar2000, BubbleUpnp).
Code: Select all
Thu Oct 27 21:09:24.473 2011 (UTC - 4:00): TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 0, All: 44
Thu Oct 27 21:09:24.483 2011 (UTC - 4:00): Thread 'UpdateDriveLetters_Var' has started 9848
Thu Oct 27 21:09:24.484 2011 (UTC - 4:00): Thread registered, going to initialize 9848
Thu Oct 27 21:09:24.484 2011 (UTC - 4:00): Thread initialized 9848
Thu Oct 27 21:09:24.485 2011 (UTC - 4:00): CDPlayer.ini location: C:\Users\abeloin\AppData\Roaming\MediaMonkey\CDPlayer.ini
Thu Oct 27 21:09:24.485 2011 (UTC - 4:00): CDPlayer.ini location: C:\Users\abeloin\AppData\Roaming\MediaMonkey\CDPlayer.ini
Thu Oct 27 21:09:24.560 2011 (UTC - 4:00): CDPlayer.ini location: C:\Users\abeloin\AppData\Roaming\MediaMonkey\CDPlayer.ini
Thu Oct 27 21:09:24.636 2011 (UTC - 4:00): Going 'UpdateDriveLetters_Var'to make final callback 9848
Thu Oct 27 21:09:24.636 2011 (UTC - 4:00): Thread 'UpdateDriveLetters_Var'has finished 9848
Thu Oct 27 21:09:29.823 2011 (UTC - 4:00): Forms: Received WM_ACTIVATEAPP
Thu Oct 27 21:09:29.823 2011 (UTC - 4:00): Forms: Accepted WM_ACTIVATEAPP +
Thu Oct 27 21:09:29.823 2011 (UTC - 4:00): Forms: RestoreTopMost: Level: 1
Thu Oct 27 21:09:29.823 2011 (UTC - 4:00): Forms: RestoreTopMost: Starting
Thu Oct 27 21:09:29.824 2011 (UTC - 4:00): Winamp sim - ignoring.
Thu Oct 27 21:09:29.824 2011 (UTC - 4:00): Winamp simulation window received messsage 28
Thu Oct 27 21:09:29.824 2011 (UTC - 4:00): Winamp sim - ignoring.
Thu Oct 27 21:09:29.826 2011 (UTC - 4:00): MainForm: NC Activate +
Thu Oct 27 21:09:29.986 2011 (UTC - 4:00): Player: Adding 1 track(s)
Thu Oct 27 21:09:29.987 2011 (UTC - 4:00): Player: Added 1 track(s)
Thu Oct 27 21:09:29.987 2011 (UTC - 4:00): _Stop: started
Thu Oct 27 21:09:29.990 2011 (UTC - 4:00): PrepareDockedVideo: Begin
Thu Oct 27 21:09:29.990 2011 (UTC - 4:00): PrepareDockedVideo: Switching=false IsStartingPlayback=false WasManuallyChanged=false
Thu Oct 27 21:09:29.990 2011 (UTC - 4:00): PrepareDockedVideo: Reduced window or audio
Thu Oct 27 21:09:29.990 2011 (UTC - 4:00): PrepareDockedVideo: Audio
Thu Oct 27 21:09:29.990 2011 (UTC - 4:00): PrepareDockedVideo: End
Thu Oct 27 21:09:29.990 2011 (UTC - 4:00): _Stop: finished
Thu Oct 27 21:09:29.995 2011 (UTC - 4:00): Player: Setting current track: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:29.996 2011 (UTC - 4:00): PrepareDockedVideo: Begin
Thu Oct 27 21:09:29.996 2011 (UTC - 4:00): PrepareDockedVideo: Switching=false IsStartingPlayback=false WasManuallyChanged=false
Thu Oct 27 21:09:29.996 2011 (UTC - 4:00): PrepareDockedVideo: Reduced window or audio
Thu Oct 27 21:09:29.996 2011 (UTC - 4:00): PrepareDockedVideo: Audio
Thu Oct 27 21:09:29.997 2011 (UTC - 4:00): PrepareDockedVideo: End
Thu Oct 27 21:09:29.997 2011 (UTC - 4:00): Winamp simulation window received messsage 12
Thu Oct 27 21:09:29.997 2011 (UTC - 4:00): Winamp sim - message left to the default processing
Thu Oct 27 21:09:29.997 2011 (UTC - 4:00): Winamp sim - message processing finished
Thu Oct 27 21:09:29.998 2011 (UTC - 4:00): BQ: Starting a new task.
Thu Oct 27 21:09:29.998 2011 (UTC - 4:00): BQ: Starting a new thread.
Thu Oct 27 21:09:30.015 2011 (UTC - 4:00): TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 0, All: 44
Thu Oct 27 21:09:30.023 2011 (UTC - 4:00): Thread 'BackgroundQueue' has started 9652
Thu Oct 27 21:09:30.023 2011 (UTC - 4:00): Thread registered, going to initialize 9652
Thu Oct 27 21:09:30.024 2011 (UTC - 4:00): Thread initialized 9652
Thu Oct 27 21:09:30.024 2011 (UTC - 4:00): Player: UpdatePlaylistEntry() starting.
Thu Oct 27 21:09:30.024 2011 (UTC - 4:00): Player: UpdatePlaylistEntry() Test1.
Thu Oct 27 21:09:30.024 2011 (UTC - 4:00): Player: UpdatePlaylistEntry() is in DB.
Thu Oct 27 21:09:30.052 2011 (UTC - 4:00): TGenThread.Create: ThreadName: PlaybackStarter_Var , Running Threads: Internal: 1, All: 45
Thu Oct 27 21:09:30.066 2011 (UTC - 4:00): Thread 'PlaybackStarter_Var' has started 2836
Thu Oct 27 21:09:30.067 2011 (UTC - 4:00): Thread registered, going to initialize 2836
Thu Oct 27 21:09:30.067 2011 (UTC - 4:00): Thread initialized 2836
Thu Oct 27 21:09:30.068 2011 (UTC - 4:00): Player: _Play() procedure entering.
Thu Oct 27 21:09:30.086 2011 (UTC - 4:00): TGenThread.Create: ThreadName: PlayerEntriesUpdater_Var , Running Threads: Internal: 1, All: 46
Thu Oct 27 21:09:30.094 2011 (UTC - 4:00): Winamp simulation window received messsage 12
Thu Oct 27 21:09:30.094 2011 (UTC - 4:00): Winamp sim - message left to the default processing
Thu Oct 27 21:09:30.094 2011 (UTC - 4:00): Winamp sim - message processing finished
Thu Oct 27 21:09:30.095 2011 (UTC - 4:00): Thread 'PlayerEntriesUpdater_Var' has started 7084
Thu Oct 27 21:09:30.096 2011 (UTC - 4:00): Thread registered, going to initialize 7084
Thu Oct 27 21:09:30.096 2011 (UTC - 4:00): Thread initialized 7084
Thu Oct 27 21:09:30.098 2011 (UTC - 4:00): Player: W7 icon updated.
Thu Oct 27 21:09:30.099 2011 (UTC - 4:00): Player: Going to handle the current track.
Thu Oct 27 21:09:30.099 2011 (UTC - 4:00): Player: Updating playlist entry.
Thu Oct 27 21:09:30.099 2011 (UTC - 4:00): Player: Setting current track: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.099 2011 (UTC - 4:00): Player: Track entry prepared, going to start playback.
Thu Oct 27 21:09:30.099 2011 (UTC - 4:00): Player: Song is not cached, try to play the original file
Thu Oct 27 21:09:30.099 2011 (UTC - 4:00): Going to play file: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.099 2011 (UTC - 4:00): Plugin C:\Program Files (x86)\MediaMonkey\Plugins\in_wma.dll can play http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.100 2011 (UTC - 4:00): Going to start playback.
Thu Oct 27 21:09:30.100 2011 (UTC - 4:00): TWAInputPlugin.Play starting
Thu Oct 27 21:09:30.105 2011 (UTC - 4:00): Going 'PlayerEntriesUpdater_Var'to make final callback 7084
Thu Oct 27 21:09:30.105 2011 (UTC - 4:00): Thread 'PlayerEntriesUpdater_Var' is going to callback
Thu Oct 27 21:09:30.105 2011 (UTC - 4:00): Winamp sim - WM_USER message 603
Thu Oct 27 21:09:30.105 2011 (UTC - 4:00): Winamp sim - WM_USER message 603
Thu Oct 27 21:09:30.106 2011 (UTC - 4:00): Winamp sim - WM_USER message 603
Thu Oct 27 21:09:30.106 2011 (UTC - 4:00): Thread 'PlayerEntriesUpdater_Var'has finished 7084
Thu Oct 27 21:09:30.110 2011 (UTC - 4:00): Use of a debugger while executing Windows Digital Rights Management (WMDRM) code is not permitted. Aborting WMDRM initialization.
Thu Oct 27 21:09:30.129 2011 (UTC - 4:00): TGenThread.Create: ThreadName: IsSongAccessibleAsync , Running Threads: Internal: 2, All: 49
Thu Oct 27 21:09:30.139 2011 (UTC - 4:00): Thread 'IsSongAccessibleAsync' has started 4112
Thu Oct 27 21:09:30.139 2011 (UTC - 4:00): Thread registered, going to initialize 4112
Thu Oct 27 21:09:30.139 2011 (UTC - 4:00): Thread initialized 4112
Thu Oct 27 21:09:30.141 2011 (UTC - 4:00): Winamp sim - WM_USER message 9899
Thu Oct 27 21:09:30.204 2011 (UTC - 4:00): (25f8.b14): C++ EH exception - code e06d7363 (first chance)
Thu Oct 27 21:09:30.208 2011 (UTC - 4:00): (25f8.b14): C++ EH exception - code e06d7363 (first chance)
Thu Oct 27 21:09:30.209 2011 (UTC - 4:00): TWAInputPlugin.Play finishing
Thu Oct 27 21:09:30.209 2011 (UTC - 4:00): Plugin C:\Program Files (x86)\MediaMonkey\Plugins\in_wmp3.dll can play http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.209 2011 (UTC - 4:00): Going to start playback.
Thu Oct 27 21:09:30.209 2011 (UTC - 4:00): TWAInputPlugin.Play starting
Thu Oct 27 21:09:30.209 2011 (UTC - 4:00): INWMP3: Stop() started
Thu Oct 27 21:09:30.209 2011 (UTC - 4:00): INWMP3: Close() started
Thu Oct 27 21:09:30.209 2011 (UTC - 4:00): INWMP3: Close() 1
Thu Oct 27 21:09:30.210 2011 (UTC - 4:00): INWMP3: Close() 2
Thu Oct 27 21:09:30.210 2011 (UTC - 4:00): INWMP3: Close() 3
Thu Oct 27 21:09:30.210 2011 (UTC - 4:00): INWMP3: Close() finished
Thu Oct 27 21:09:30.211 2011 (UTC - 4:00): INWMP3: StopOutput() started
Thu Oct 27 21:09:30.211 2011 (UTC - 4:00): INWMP3: StopOutput() finished
Thu Oct 27 21:09:30.211 2011 (UTC - 4:00): INWMP3: Stop() finished
Thu Oct 27 21:09:30.211 2011 (UTC - 4:00): Winamp sim - WM_USER message 603
Thu Oct 27 21:09:30.245 2011 (UTC - 4:00): GetFileInfo: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.246 2011 (UTC - 4:00): Getting UPnP metadata for URL: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.246 2011 (UTC - 4:00): UPnP: Get servers
Thu Oct 27 21:09:30.246 2011 (UTC - 4:00): UPnP: Get servers
Thu Oct 27 21:09:30.246 2011 (UTC - 4:00): UPnP: Servers count: 4
Thu Oct 27 21:09:30.246 2011 (UTC - 4:00): UPnP: Server name: Serviio (core.lan), Server UUID: 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
Thu Oct 27 21:09:30.247 2011 (UTC - 4:00): UPnP: Server name: ABELOIN-7: abeloin:, Server UUID: 9d986978-fc5d-46be-8fa2-4381a8c4921c
Thu Oct 27 21:09:30.247 2011 (UTC - 4:00): UPnP: Server name: Asset UPnP: ABELOIN-7, Server UUID: c8ef8667-1e16-40c2-abcd-123456789abc
Thu Oct 27 21:09:30.247 2011 (UTC - 4:00): UPnP: Server name: foobar2000 Media Server (abeloin) [ABELOIN-7], Server UUID: 302cd9f6-5103-58e8-4d27-b4375133b011
Thu Oct 27 21:09:30.247 2011 (UTC - 4:00): UPnP: Set server
Thu Oct 27 21:09:30.248 2011 (UTC - 4:00): UPnP: Set server
Thu Oct 27 21:09:30.248 2011 (UTC - 4:00): UpNp: Current server name: Serviio (core.lan)
Thu Oct 27 21:09:30.248 2011 (UTC - 4:00): UPnP: Browse
Thu Oct 27 21:09:30.248 2011 (UTC - 4:00): UPnP: MM Controller: BrowseUpNp
Thu Oct 27 21:09:30.257 2011 (UTC - 4:00): INWMP3: Open()
Thu Oct 27 21:09:30.260 2011 (UTC - 4:00): INWMP3: StripID3Stream: Openning TStreamAccess
Thu Oct 27 21:09:30.261 2011 (UTC - 4:00): Locking file: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.261 2011 (UTC - 4:00): Locked file: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.440 2011 (UTC - 4:00): Going 'IsSongAccessibleAsync'to make final callback 4112
Thu Oct 27 21:09:30.440 2011 (UTC - 4:00): Thread 'IsSongAccessibleAsync'has finished 4112
Thu Oct 27 21:09:30.508 2011 (UTC - 4:00): TGenThread.Create: ThreadName: StartReadingHTTP_VAR , Running Threads: Internal: 2, All: 48
Thu Oct 27 21:09:30.517 2011 (UTC - 4:00): Thread 'StartReadingHTTP_VAR' has started 8800
Thu Oct 27 21:09:30.518 2011 (UTC - 4:00): Thread registered, going to initialize 8800
Thu Oct 27 21:09:30.518 2011 (UTC - 4:00): Thread initialized 8800
Thu Oct 27 21:09:30.565 2011 (UTC - 4:00): Unlocking file: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.565 2011 (UTC - 4:00): Unlocked file: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.566 2011 (UTC - 4:00): INWMP3: StripID3Stream: SetID3Offset().
Thu Oct 27 21:09:30.566 2011 (UTC - 4:00): INWMP3: StreamSeek 2 - 0
Thu Oct 27 21:09:30.566 2011 (UTC - 4:00): THTTPStream.CheckBuffer( RequestedPosition = 1, StartPosition = 0, buf.Size = 0, buf.Position = 0, SeekRequest = 1)
Thu Oct 27 21:09:30.567 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 1933312 bytes)
Thu Oct 27 21:09:30.568 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 1933312 bytes, buf.Position = 0)
Thu Oct 27 21:09:30.568 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 98304 bytes)
Thu Oct 27 21:09:30.569 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 98304 bytes, buf.Position = 0)
Thu Oct 27 21:09:30.569 2011 (UTC - 4:00): THTTPStream.Stop
Thu Oct 27 21:09:30.571 2011 (UTC - 4:00): Going 'StartReadingHTTP_VAR'to make final callback 8800
Thu Oct 27 21:09:30.572 2011 (UTC - 4:00): Thread 'StartReadingHTTP_VAR'has finished 8800
Thu Oct 27 21:09:30.720 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:30.721 2011 (UTC - 4:00): THTTPStream.CheckBuffer( RequestedPosition = 0, StartPosition = 6683765, buf.Size = 0, buf.Position = 0, SeekRequest = 1)
Thu Oct 27 21:09:30.721 2011 (UTC - 4:00): THTTPStream.CheckBuffer( Going to perform range request to position 0)
Thu Oct 27 21:09:30.722 2011 (UTC - 4:00): THTTPStream.Stop
Thu Oct 27 21:09:30.840 2011 (UTC - 4:00): TGenThread.Create: ThreadName: StartReadingHTTP_VAR , Running Threads: Internal: 2, All: 48
Thu Oct 27 21:09:30.851 2011 (UTC - 4:00): Thread 'StartReadingHTTP_VAR' has started 3936
Thu Oct 27 21:09:30.852 2011 (UTC - 4:00): Thread registered, going to initialize 3936
Thu Oct 27 21:09:30.852 2011 (UTC - 4:00): Thread initialized 3936
Thu Oct 27 21:09:30.898 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 360448 bytes)
Thu Oct 27 21:09:30.899 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 360448 bytes, buf.Position = 0)
Thu Oct 27 21:09:30.900 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:30.900 2011 (UTC - 4:00): INWMP3: StripID3Stream: Looking for data.
Thu Oct 27 21:09:30.901 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
...
Thu Oct 27 21:09:30.911 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:30.911 2011 (UTC - 4:00): THTTPStream.CheckBuffer( RequestedPosition = 385024, StartPosition = 0, buf.Size = 360448, buf.Position = 344064, SeekRequest = 0)
Thu Oct 27 21:09:30.912 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 327680 bytes)
Thu Oct 27 21:09:30.913 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 327680 bytes, buf.Position = 344064)
Thu Oct 27 21:09:30.913 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 98304 bytes)
Thu Oct 27 21:09:30.913 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 98304 bytes, buf.Position = 344064)
Thu Oct 27 21:09:30.914 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
...
Thu Oct 27 21:09:30.929 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:30.929 2011 (UTC - 4:00): THTTPStream.CheckBuffer( RequestedPosition = 802816, StartPosition = 0, buf.Size = 786432, buf.Position = 761856, SeekRequest = 0)
Thu Oct 27 21:09:30.930 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 557056 bytes)
Thu Oct 27 21:09:30.930 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 557056 bytes, buf.Position = 761856)
Thu Oct 27 21:09:30.931 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 65536 bytes)
Thu Oct 27 21:09:30.931 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 65536 bytes, buf.Position = 761856)
Thu Oct 27 21:09:30.931 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
...
Thu Oct 27 21:09:30.950 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:30.951 2011 (UTC - 4:00): THTTPStream.CheckBuffer( RequestedPosition = 1417216, StartPosition = 0, buf.Size = 1409024, buf.Position = 1376256, SeekRequest = 0)
Thu Oct 27 21:09:30.952 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 524288 bytes)
Thu Oct 27 21:09:30.995 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 524288 bytes, buf.Position = 1376256)
Thu Oct 27 21:09:30.997 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 4194304 bytes)
Thu Oct 27 21:09:31.000 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 4194304 bytes, buf.Position = 1376256)
Thu Oct 27 21:09:31.001 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
...
Thu Oct 27 21:09:31.011 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:31.011 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 556149 bytes)
Thu Oct 27 21:09:31.012 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 556149 bytes, buf.Position = 6127616)
Thu Oct 27 21:09:31.012 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:31.013 2011 (UTC - 4:00): Going 'StartReadingHTTP_VAR'to make final callback 3936
Thu Oct 27 21:09:31.013 2011 (UTC - 4:00): Thread 'StartReadingHTTP_VAR'has finished 3936
Thu Oct 27 21:09:31.015 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
...
Thu Oct 27 21:09:31.196 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:31.196 2011 (UTC - 4:00): THTTPStream.Stop
Thu Oct 27 21:09:31.297 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:31.297 2011 (UTC - 4:00): INWMP3: StripID3Stream: Open finished.
Thu Oct 27 21:09:31.298 2011 (UTC - 4:00): INWMP3: OnStatus 1.
Thu Oct 27 21:09:31.298 2011 (UTC - 4:00): INWMP3: Open() problem
Thu Oct 27 21:09:31.298 2011 (UTC - 4:00): INWMP3: Close() started
Thu Oct 27 21:09:31.298 2011 (UTC - 4:00): INWMP3: StopStream() started
Thu Oct 27 21:09:31.299 2011 (UTC - 4:00): INWMP3: StopStream() finished
Thu Oct 27 21:09:31.299 2011 (UTC - 4:00): INWMP3: Close() 1
Thu Oct 27 21:09:31.299 2011 (UTC - 4:00): INWMP3: Close() 2
Thu Oct 27 21:09:31.300 2011 (UTC - 4:00): INWMP3: Close() 3
Thu Oct 27 21:09:31.300 2011 (UTC - 4:00): INWMP3: Close() finished
Thu Oct 27 21:09:31.300 2011 (UTC - 4:00): INWMP3: Play() problem
Thu Oct 27 21:09:31.300 2011 (UTC - 4:00): INWMP3: Stop() started
Thu Oct 27 21:09:31.301 2011 (UTC - 4:00): INWMP3: Close() started
Thu Oct 27 21:09:31.301 2011 (UTC - 4:00): INWMP3: Close() 1
Thu Oct 27 21:09:31.301 2011 (UTC - 4:00): INWMP3: Close() 2
Thu Oct 27 21:09:31.301 2011 (UTC - 4:00): INWMP3: Close() 3
Thu Oct 27 21:09:31.302 2011 (UTC - 4:00): INWMP3: Close() finished
Thu Oct 27 21:09:31.302 2011 (UTC - 4:00): INWMP3: StopOutput() started
Thu Oct 27 21:09:31.302 2011 (UTC - 4:00): INWMP3: StopOutput() finished
Thu Oct 27 21:09:31.302 2011 (UTC - 4:00): INWMP3: Stop() finished
Thu Oct 27 21:09:31.302 2011 (UTC - 4:00): THTTPStream.Stop
Thu Oct 27 21:09:31.503 2011 (UTC - 4:00): TWAInputPlugin.Play finishing
Thu Oct 27 21:09:31.503 2011 (UTC - 4:00): Decoder: CreateDecoder() started
Thu Oct 27 21:09:31.504 2011 (UTC - 4:00): Player: There is a problem in playing this file, try the next one
Thu Oct 27 21:09:31.506 2011 (UTC - 4:00): Going 'PlaybackStarter_Var'to make final callback 2836
Thu Oct 27 21:09:31.507 2011 (UTC - 4:00): Winamp Playlist sim - WM_USER message 0
Thu Oct 27 21:09:31.507 2011 (UTC - 4:00): Winamp Playlist sim - message left to the default processing
Thu Oct 27 21:09:31.507 2011 (UTC - 4:00): Winamp Playlist sim - WM_USER message 1073741824
Thu Oct 27 21:09:31.508 2011 (UTC - 4:00): Winamp Playlist sim - message left to the default processing
Thu Oct 27 21:09:31.508 2011 (UTC - 4:00): Winamp sim - WM_USER message 603
Thu Oct 27 21:09:31.508 2011 (UTC - 4:00): Winamp sim - WM_USER message 603
Thu Oct 27 21:09:31.508 2011 (UTC - 4:00): Thread 'PlaybackStarter_Var'has finished 2836
Thu Oct 27 21:09:33.094 2011 (UTC - 4:00): Going 'BackgroundQueue'to make final callback 9652
Thu Oct 27 21:09:33.094 2011 (UTC - 4:00): Thread 'BackgroundQueue'has finished 9652
Thu Oct 27 21:09:35.746 2011 (UTC - 4:00): MainForm: NC Activate -
Thu Oct 27 21:09:35.747 2011 (UTC - 4:00): Forms: Received WM_ACTIVATEAPP
Thu Oct 27 21:09:35.747 2011 (UTC - 4:00): Forms: Accepted WM_ACTIVATEAPP -
Thu Oct 27 21:09:35.747 2011 (UTC - 4:00): Forms: NormalizeTopMosts: Level: 0
Thu Oct 27 21:09:35.748 2011 (UTC - 4:00): Forms: NormalizeTopMost: Starting
Thu Oct 27 21:09:35.748 2011 (UTC - 4:00): Winamp sim - ignoring.
Thu Oct 27 21:09:35.748 2011 (UTC - 4:00): Winamp simulation window received messsage 28
Thu Oct 27 21:09:35.749 2011 (UTC - 4:00): Winamp sim - ignoring.
Just tried it with build 1450 and the issue is still not resolved.
Also, while trying different combinations, I stumble on a weird behavior: MM4 refuse to play any M4A or FLAC files hosted on Serviio. MM4 will try via in_wma.dll first, then in_wmp3.dll and give up after. I wasn't able to reproduce the issue with other renderer (Foobar2000, BubbleUpnp).
[code]
Thu Oct 27 21:09:24.473 2011 (UTC - 4:00): TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 0, All: 44
Thu Oct 27 21:09:24.483 2011 (UTC - 4:00): Thread 'UpdateDriveLetters_Var' has started 9848
Thu Oct 27 21:09:24.484 2011 (UTC - 4:00): Thread registered, going to initialize 9848
Thu Oct 27 21:09:24.484 2011 (UTC - 4:00): Thread initialized 9848
Thu Oct 27 21:09:24.485 2011 (UTC - 4:00): CDPlayer.ini location: C:\Users\abeloin\AppData\Roaming\MediaMonkey\CDPlayer.ini
Thu Oct 27 21:09:24.485 2011 (UTC - 4:00): CDPlayer.ini location: C:\Users\abeloin\AppData\Roaming\MediaMonkey\CDPlayer.ini
Thu Oct 27 21:09:24.560 2011 (UTC - 4:00): CDPlayer.ini location: C:\Users\abeloin\AppData\Roaming\MediaMonkey\CDPlayer.ini
Thu Oct 27 21:09:24.636 2011 (UTC - 4:00): Going 'UpdateDriveLetters_Var'to make final callback 9848
Thu Oct 27 21:09:24.636 2011 (UTC - 4:00): Thread 'UpdateDriveLetters_Var'has finished 9848
Thu Oct 27 21:09:29.823 2011 (UTC - 4:00): Forms: Received WM_ACTIVATEAPP
Thu Oct 27 21:09:29.823 2011 (UTC - 4:00): Forms: Accepted WM_ACTIVATEAPP +
Thu Oct 27 21:09:29.823 2011 (UTC - 4:00): Forms: RestoreTopMost: Level: 1
Thu Oct 27 21:09:29.823 2011 (UTC - 4:00): Forms: RestoreTopMost: Starting
Thu Oct 27 21:09:29.824 2011 (UTC - 4:00): Winamp sim - ignoring.
Thu Oct 27 21:09:29.824 2011 (UTC - 4:00): Winamp simulation window received messsage 28
Thu Oct 27 21:09:29.824 2011 (UTC - 4:00): Winamp sim - ignoring.
Thu Oct 27 21:09:29.826 2011 (UTC - 4:00): MainForm: NC Activate +
Thu Oct 27 21:09:29.986 2011 (UTC - 4:00): Player: Adding 1 track(s)
Thu Oct 27 21:09:29.987 2011 (UTC - 4:00): Player: Added 1 track(s)
Thu Oct 27 21:09:29.987 2011 (UTC - 4:00): _Stop: started
Thu Oct 27 21:09:29.990 2011 (UTC - 4:00): PrepareDockedVideo: Begin
Thu Oct 27 21:09:29.990 2011 (UTC - 4:00): PrepareDockedVideo: Switching=false IsStartingPlayback=false WasManuallyChanged=false
Thu Oct 27 21:09:29.990 2011 (UTC - 4:00): PrepareDockedVideo: Reduced window or audio
Thu Oct 27 21:09:29.990 2011 (UTC - 4:00): PrepareDockedVideo: Audio
Thu Oct 27 21:09:29.990 2011 (UTC - 4:00): PrepareDockedVideo: End
Thu Oct 27 21:09:29.990 2011 (UTC - 4:00): _Stop: finished
Thu Oct 27 21:09:29.995 2011 (UTC - 4:00): Player: Setting current track: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:29.996 2011 (UTC - 4:00): PrepareDockedVideo: Begin
Thu Oct 27 21:09:29.996 2011 (UTC - 4:00): PrepareDockedVideo: Switching=false IsStartingPlayback=false WasManuallyChanged=false
Thu Oct 27 21:09:29.996 2011 (UTC - 4:00): PrepareDockedVideo: Reduced window or audio
Thu Oct 27 21:09:29.996 2011 (UTC - 4:00): PrepareDockedVideo: Audio
Thu Oct 27 21:09:29.997 2011 (UTC - 4:00): PrepareDockedVideo: End
Thu Oct 27 21:09:29.997 2011 (UTC - 4:00): Winamp simulation window received messsage 12
Thu Oct 27 21:09:29.997 2011 (UTC - 4:00): Winamp sim - message left to the default processing
Thu Oct 27 21:09:29.997 2011 (UTC - 4:00): Winamp sim - message processing finished
Thu Oct 27 21:09:29.998 2011 (UTC - 4:00): BQ: Starting a new task.
Thu Oct 27 21:09:29.998 2011 (UTC - 4:00): BQ: Starting a new thread.
Thu Oct 27 21:09:30.015 2011 (UTC - 4:00): TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 0, All: 44
Thu Oct 27 21:09:30.023 2011 (UTC - 4:00): Thread 'BackgroundQueue' has started 9652
Thu Oct 27 21:09:30.023 2011 (UTC - 4:00): Thread registered, going to initialize 9652
Thu Oct 27 21:09:30.024 2011 (UTC - 4:00): Thread initialized 9652
Thu Oct 27 21:09:30.024 2011 (UTC - 4:00): Player: UpdatePlaylistEntry() starting.
Thu Oct 27 21:09:30.024 2011 (UTC - 4:00): Player: UpdatePlaylistEntry() Test1.
Thu Oct 27 21:09:30.024 2011 (UTC - 4:00): Player: UpdatePlaylistEntry() is in DB.
Thu Oct 27 21:09:30.052 2011 (UTC - 4:00): TGenThread.Create: ThreadName: PlaybackStarter_Var , Running Threads: Internal: 1, All: 45
Thu Oct 27 21:09:30.066 2011 (UTC - 4:00): Thread 'PlaybackStarter_Var' has started 2836
Thu Oct 27 21:09:30.067 2011 (UTC - 4:00): Thread registered, going to initialize 2836
Thu Oct 27 21:09:30.067 2011 (UTC - 4:00): Thread initialized 2836
Thu Oct 27 21:09:30.068 2011 (UTC - 4:00): Player: _Play() procedure entering.
Thu Oct 27 21:09:30.086 2011 (UTC - 4:00): TGenThread.Create: ThreadName: PlayerEntriesUpdater_Var , Running Threads: Internal: 1, All: 46
Thu Oct 27 21:09:30.094 2011 (UTC - 4:00): Winamp simulation window received messsage 12
Thu Oct 27 21:09:30.094 2011 (UTC - 4:00): Winamp sim - message left to the default processing
Thu Oct 27 21:09:30.094 2011 (UTC - 4:00): Winamp sim - message processing finished
Thu Oct 27 21:09:30.095 2011 (UTC - 4:00): Thread 'PlayerEntriesUpdater_Var' has started 7084
Thu Oct 27 21:09:30.096 2011 (UTC - 4:00): Thread registered, going to initialize 7084
Thu Oct 27 21:09:30.096 2011 (UTC - 4:00): Thread initialized 7084
Thu Oct 27 21:09:30.098 2011 (UTC - 4:00): Player: W7 icon updated.
Thu Oct 27 21:09:30.099 2011 (UTC - 4:00): Player: Going to handle the current track.
Thu Oct 27 21:09:30.099 2011 (UTC - 4:00): Player: Updating playlist entry.
Thu Oct 27 21:09:30.099 2011 (UTC - 4:00): Player: Setting current track: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.099 2011 (UTC - 4:00): Player: Track entry prepared, going to start playback.
Thu Oct 27 21:09:30.099 2011 (UTC - 4:00): Player: Song is not cached, try to play the original file
Thu Oct 27 21:09:30.099 2011 (UTC - 4:00): Going to play file: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.099 2011 (UTC - 4:00): Plugin C:\Program Files (x86)\MediaMonkey\Plugins\in_wma.dll can play http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.100 2011 (UTC - 4:00): Going to start playback.
Thu Oct 27 21:09:30.100 2011 (UTC - 4:00): TWAInputPlugin.Play starting
Thu Oct 27 21:09:30.105 2011 (UTC - 4:00): Going 'PlayerEntriesUpdater_Var'to make final callback 7084
Thu Oct 27 21:09:30.105 2011 (UTC - 4:00): Thread 'PlayerEntriesUpdater_Var' is going to callback
Thu Oct 27 21:09:30.105 2011 (UTC - 4:00): Winamp sim - WM_USER message 603
Thu Oct 27 21:09:30.105 2011 (UTC - 4:00): Winamp sim - WM_USER message 603
Thu Oct 27 21:09:30.106 2011 (UTC - 4:00): Winamp sim - WM_USER message 603
Thu Oct 27 21:09:30.106 2011 (UTC - 4:00): Thread 'PlayerEntriesUpdater_Var'has finished 7084
Thu Oct 27 21:09:30.110 2011 (UTC - 4:00): Use of a debugger while executing Windows Digital Rights Management (WMDRM) code is not permitted. Aborting WMDRM initialization.
Thu Oct 27 21:09:30.129 2011 (UTC - 4:00): TGenThread.Create: ThreadName: IsSongAccessibleAsync , Running Threads: Internal: 2, All: 49
Thu Oct 27 21:09:30.139 2011 (UTC - 4:00): Thread 'IsSongAccessibleAsync' has started 4112
Thu Oct 27 21:09:30.139 2011 (UTC - 4:00): Thread registered, going to initialize 4112
Thu Oct 27 21:09:30.139 2011 (UTC - 4:00): Thread initialized 4112
Thu Oct 27 21:09:30.141 2011 (UTC - 4:00): Winamp sim - WM_USER message 9899
Thu Oct 27 21:09:30.204 2011 (UTC - 4:00): (25f8.b14): C++ EH exception - code e06d7363 (first chance)
Thu Oct 27 21:09:30.208 2011 (UTC - 4:00): (25f8.b14): C++ EH exception - code e06d7363 (first chance)
Thu Oct 27 21:09:30.209 2011 (UTC - 4:00): TWAInputPlugin.Play finishing
Thu Oct 27 21:09:30.209 2011 (UTC - 4:00): Plugin C:\Program Files (x86)\MediaMonkey\Plugins\in_wmp3.dll can play http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.209 2011 (UTC - 4:00): Going to start playback.
Thu Oct 27 21:09:30.209 2011 (UTC - 4:00): TWAInputPlugin.Play starting
Thu Oct 27 21:09:30.209 2011 (UTC - 4:00): INWMP3: Stop() started
Thu Oct 27 21:09:30.209 2011 (UTC - 4:00): INWMP3: Close() started
Thu Oct 27 21:09:30.209 2011 (UTC - 4:00): INWMP3: Close() 1
Thu Oct 27 21:09:30.210 2011 (UTC - 4:00): INWMP3: Close() 2
Thu Oct 27 21:09:30.210 2011 (UTC - 4:00): INWMP3: Close() 3
Thu Oct 27 21:09:30.210 2011 (UTC - 4:00): INWMP3: Close() finished
Thu Oct 27 21:09:30.211 2011 (UTC - 4:00): INWMP3: StopOutput() started
Thu Oct 27 21:09:30.211 2011 (UTC - 4:00): INWMP3: StopOutput() finished
Thu Oct 27 21:09:30.211 2011 (UTC - 4:00): INWMP3: Stop() finished
Thu Oct 27 21:09:30.211 2011 (UTC - 4:00): Winamp sim - WM_USER message 603
Thu Oct 27 21:09:30.245 2011 (UTC - 4:00): GetFileInfo: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.246 2011 (UTC - 4:00): Getting UPnP metadata for URL: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.246 2011 (UTC - 4:00): UPnP: Get servers
Thu Oct 27 21:09:30.246 2011 (UTC - 4:00): UPnP: Get servers
Thu Oct 27 21:09:30.246 2011 (UTC - 4:00): UPnP: Servers count: 4
Thu Oct 27 21:09:30.246 2011 (UTC - 4:00): UPnP: Server name: Serviio (core.lan), Server UUID: 8dee68fe-0370-3fc8-a5f5-ae4a1fb10a65
Thu Oct 27 21:09:30.247 2011 (UTC - 4:00): UPnP: Server name: ABELOIN-7: abeloin:, Server UUID: 9d986978-fc5d-46be-8fa2-4381a8c4921c
Thu Oct 27 21:09:30.247 2011 (UTC - 4:00): UPnP: Server name: Asset UPnP: ABELOIN-7, Server UUID: c8ef8667-1e16-40c2-abcd-123456789abc
Thu Oct 27 21:09:30.247 2011 (UTC - 4:00): UPnP: Server name: foobar2000 Media Server (abeloin) [ABELOIN-7], Server UUID: 302cd9f6-5103-58e8-4d27-b4375133b011
Thu Oct 27 21:09:30.247 2011 (UTC - 4:00): UPnP: Set server
Thu Oct 27 21:09:30.248 2011 (UTC - 4:00): UPnP: Set server
Thu Oct 27 21:09:30.248 2011 (UTC - 4:00): UpNp: Current server name: Serviio (core.lan)
Thu Oct 27 21:09:30.248 2011 (UTC - 4:00): UPnP: Browse
Thu Oct 27 21:09:30.248 2011 (UTC - 4:00): UPnP: MM Controller: BrowseUpNp
Thu Oct 27 21:09:30.257 2011 (UTC - 4:00): INWMP3: Open()
Thu Oct 27 21:09:30.260 2011 (UTC - 4:00): INWMP3: StripID3Stream: Openning TStreamAccess
Thu Oct 27 21:09:30.261 2011 (UTC - 4:00): Locking file: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.261 2011 (UTC - 4:00): Locked file: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.440 2011 (UTC - 4:00): Going 'IsSongAccessibleAsync'to make final callback 4112
Thu Oct 27 21:09:30.440 2011 (UTC - 4:00): Thread 'IsSongAccessibleAsync'has finished 4112
Thu Oct 27 21:09:30.508 2011 (UTC - 4:00): TGenThread.Create: ThreadName: StartReadingHTTP_VAR , Running Threads: Internal: 2, All: 48
Thu Oct 27 21:09:30.517 2011 (UTC - 4:00): Thread 'StartReadingHTTP_VAR' has started 8800
Thu Oct 27 21:09:30.518 2011 (UTC - 4:00): Thread registered, going to initialize 8800
Thu Oct 27 21:09:30.518 2011 (UTC - 4:00): Thread initialized 8800
Thu Oct 27 21:09:30.565 2011 (UTC - 4:00): Unlocking file: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.565 2011 (UTC - 4:00): Unlocked file: http://192.168.1.10:8895/resource/5070/MEDIA_ITEM/AAC_ISO_320$0
Thu Oct 27 21:09:30.566 2011 (UTC - 4:00): INWMP3: StripID3Stream: SetID3Offset().
Thu Oct 27 21:09:30.566 2011 (UTC - 4:00): INWMP3: StreamSeek 2 - 0
Thu Oct 27 21:09:30.566 2011 (UTC - 4:00): THTTPStream.CheckBuffer( RequestedPosition = 1, StartPosition = 0, buf.Size = 0, buf.Position = 0, SeekRequest = 1)
Thu Oct 27 21:09:30.567 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 1933312 bytes)
Thu Oct 27 21:09:30.568 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 1933312 bytes, buf.Position = 0)
Thu Oct 27 21:09:30.568 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 98304 bytes)
Thu Oct 27 21:09:30.569 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 98304 bytes, buf.Position = 0)
Thu Oct 27 21:09:30.569 2011 (UTC - 4:00): THTTPStream.Stop
Thu Oct 27 21:09:30.571 2011 (UTC - 4:00): Going 'StartReadingHTTP_VAR'to make final callback 8800
Thu Oct 27 21:09:30.572 2011 (UTC - 4:00): Thread 'StartReadingHTTP_VAR'has finished 8800
Thu Oct 27 21:09:30.720 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:30.721 2011 (UTC - 4:00): THTTPStream.CheckBuffer( RequestedPosition = 0, StartPosition = 6683765, buf.Size = 0, buf.Position = 0, SeekRequest = 1)
Thu Oct 27 21:09:30.721 2011 (UTC - 4:00): THTTPStream.CheckBuffer( Going to perform range request to position 0)
Thu Oct 27 21:09:30.722 2011 (UTC - 4:00): THTTPStream.Stop
Thu Oct 27 21:09:30.840 2011 (UTC - 4:00): TGenThread.Create: ThreadName: StartReadingHTTP_VAR , Running Threads: Internal: 2, All: 48
Thu Oct 27 21:09:30.851 2011 (UTC - 4:00): Thread 'StartReadingHTTP_VAR' has started 3936
Thu Oct 27 21:09:30.852 2011 (UTC - 4:00): Thread registered, going to initialize 3936
Thu Oct 27 21:09:30.852 2011 (UTC - 4:00): Thread initialized 3936
Thu Oct 27 21:09:30.898 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 360448 bytes)
Thu Oct 27 21:09:30.899 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 360448 bytes, buf.Position = 0)
Thu Oct 27 21:09:30.900 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:30.900 2011 (UTC - 4:00): INWMP3: StripID3Stream: Looking for data.
Thu Oct 27 21:09:30.901 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
...
Thu Oct 27 21:09:30.911 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:30.911 2011 (UTC - 4:00): THTTPStream.CheckBuffer( RequestedPosition = 385024, StartPosition = 0, buf.Size = 360448, buf.Position = 344064, SeekRequest = 0)
Thu Oct 27 21:09:30.912 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 327680 bytes)
Thu Oct 27 21:09:30.913 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 327680 bytes, buf.Position = 344064)
Thu Oct 27 21:09:30.913 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 98304 bytes)
Thu Oct 27 21:09:30.913 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 98304 bytes, buf.Position = 344064)
Thu Oct 27 21:09:30.914 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
...
Thu Oct 27 21:09:30.929 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:30.929 2011 (UTC - 4:00): THTTPStream.CheckBuffer( RequestedPosition = 802816, StartPosition = 0, buf.Size = 786432, buf.Position = 761856, SeekRequest = 0)
Thu Oct 27 21:09:30.930 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 557056 bytes)
Thu Oct 27 21:09:30.930 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 557056 bytes, buf.Position = 761856)
Thu Oct 27 21:09:30.931 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 65536 bytes)
Thu Oct 27 21:09:30.931 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 65536 bytes, buf.Position = 761856)
Thu Oct 27 21:09:30.931 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
...
Thu Oct 27 21:09:30.950 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:30.951 2011 (UTC - 4:00): THTTPStream.CheckBuffer( RequestedPosition = 1417216, StartPosition = 0, buf.Size = 1409024, buf.Position = 1376256, SeekRequest = 0)
Thu Oct 27 21:09:30.952 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 524288 bytes)
Thu Oct 27 21:09:30.995 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 524288 bytes, buf.Position = 1376256)
Thu Oct 27 21:09:30.997 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 4194304 bytes)
Thu Oct 27 21:09:31.000 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 4194304 bytes, buf.Position = 1376256)
Thu Oct 27 21:09:31.001 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
...
Thu Oct 27 21:09:31.011 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:31.011 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Going to write 556149 bytes)
Thu Oct 27 21:09:31.012 2011 (UTC - 4:00): THTTPStream.WriteToBuffer( Written 556149 bytes, buf.Position = 6127616)
Thu Oct 27 21:09:31.012 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:31.013 2011 (UTC - 4:00): Going 'StartReadingHTTP_VAR'to make final callback 3936
Thu Oct 27 21:09:31.013 2011 (UTC - 4:00): Thread 'StartReadingHTTP_VAR'has finished 3936
Thu Oct 27 21:09:31.015 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
...
Thu Oct 27 21:09:31.196 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:31.196 2011 (UTC - 4:00): THTTPStream.Stop
Thu Oct 27 21:09:31.297 2011 (UTC - 4:00): INWMP3: StreamSeek 0 - 0
Thu Oct 27 21:09:31.297 2011 (UTC - 4:00): INWMP3: StripID3Stream: Open finished.
Thu Oct 27 21:09:31.298 2011 (UTC - 4:00): INWMP3: OnStatus 1.
Thu Oct 27 21:09:31.298 2011 (UTC - 4:00): INWMP3: Open() problem
Thu Oct 27 21:09:31.298 2011 (UTC - 4:00): INWMP3: Close() started
Thu Oct 27 21:09:31.298 2011 (UTC - 4:00): INWMP3: StopStream() started
Thu Oct 27 21:09:31.299 2011 (UTC - 4:00): INWMP3: StopStream() finished
Thu Oct 27 21:09:31.299 2011 (UTC - 4:00): INWMP3: Close() 1
Thu Oct 27 21:09:31.299 2011 (UTC - 4:00): INWMP3: Close() 2
Thu Oct 27 21:09:31.300 2011 (UTC - 4:00): INWMP3: Close() 3
Thu Oct 27 21:09:31.300 2011 (UTC - 4:00): INWMP3: Close() finished
Thu Oct 27 21:09:31.300 2011 (UTC - 4:00): INWMP3: Play() problem
Thu Oct 27 21:09:31.300 2011 (UTC - 4:00): INWMP3: Stop() started
Thu Oct 27 21:09:31.301 2011 (UTC - 4:00): INWMP3: Close() started
Thu Oct 27 21:09:31.301 2011 (UTC - 4:00): INWMP3: Close() 1
Thu Oct 27 21:09:31.301 2011 (UTC - 4:00): INWMP3: Close() 2
Thu Oct 27 21:09:31.301 2011 (UTC - 4:00): INWMP3: Close() 3
Thu Oct 27 21:09:31.302 2011 (UTC - 4:00): INWMP3: Close() finished
Thu Oct 27 21:09:31.302 2011 (UTC - 4:00): INWMP3: StopOutput() started
Thu Oct 27 21:09:31.302 2011 (UTC - 4:00): INWMP3: StopOutput() finished
Thu Oct 27 21:09:31.302 2011 (UTC - 4:00): INWMP3: Stop() finished
Thu Oct 27 21:09:31.302 2011 (UTC - 4:00): THTTPStream.Stop
Thu Oct 27 21:09:31.503 2011 (UTC - 4:00): TWAInputPlugin.Play finishing
Thu Oct 27 21:09:31.503 2011 (UTC - 4:00): Decoder: CreateDecoder() started
Thu Oct 27 21:09:31.504 2011 (UTC - 4:00): Player: There is a problem in playing this file, try the next one
Thu Oct 27 21:09:31.506 2011 (UTC - 4:00): Going 'PlaybackStarter_Var'to make final callback 2836
Thu Oct 27 21:09:31.507 2011 (UTC - 4:00): Winamp Playlist sim - WM_USER message 0
Thu Oct 27 21:09:31.507 2011 (UTC - 4:00): Winamp Playlist sim - message left to the default processing
Thu Oct 27 21:09:31.507 2011 (UTC - 4:00): Winamp Playlist sim - WM_USER message 1073741824
Thu Oct 27 21:09:31.508 2011 (UTC - 4:00): Winamp Playlist sim - message left to the default processing
Thu Oct 27 21:09:31.508 2011 (UTC - 4:00): Winamp sim - WM_USER message 603
Thu Oct 27 21:09:31.508 2011 (UTC - 4:00): Winamp sim - WM_USER message 603
Thu Oct 27 21:09:31.508 2011 (UTC - 4:00): Thread 'PlaybackStarter_Var'has finished 2836
Thu Oct 27 21:09:33.094 2011 (UTC - 4:00): Going 'BackgroundQueue'to make final callback 9652
Thu Oct 27 21:09:33.094 2011 (UTC - 4:00): Thread 'BackgroundQueue'has finished 9652
Thu Oct 27 21:09:35.746 2011 (UTC - 4:00): MainForm: NC Activate -
Thu Oct 27 21:09:35.747 2011 (UTC - 4:00): Forms: Received WM_ACTIVATEAPP
Thu Oct 27 21:09:35.747 2011 (UTC - 4:00): Forms: Accepted WM_ACTIVATEAPP -
Thu Oct 27 21:09:35.747 2011 (UTC - 4:00): Forms: NormalizeTopMosts: Level: 0
Thu Oct 27 21:09:35.748 2011 (UTC - 4:00): Forms: NormalizeTopMost: Starting
Thu Oct 27 21:09:35.748 2011 (UTC - 4:00): Winamp sim - ignoring.
Thu Oct 27 21:09:35.748 2011 (UTC - 4:00): Winamp simulation window received messsage 28
Thu Oct 27 21:09:35.749 2011 (UTC - 4:00): Winamp sim - ignoring.
[/code]