I'm glad to see the timestamps have returned.
Below are two excepts: one from your log and one from from my XP
system. I had d_source_v set on my system which is why there are
additional messages.
Socketwrapper is a very simple program which just has a thread per app.
which reads from the source and copies to the destination - no real
processing so delays are caused either waiting for a read or a write to
finish.
The interesting thing when comparing the logs is the time taken between
starting a read and starting the corresponding write on my system was
1.2 secs but on your system it was 23.9 secs.
Red for my log, blue for your log. Comparing key logs message
SW: 2007-04-05 20:34:11.328 MoveDataThreadProc for step 2 about to call
ReadFile.
SW: 2007-04-05 20:34:12.500 MoveDataThreadProc for step 2 about to
write data.
SW: 2007-04-07 12:00:19.057 MoveDataThreadProc for step 2 about to call
ReadFile.
SW: 2007-04-07 12:00:42.923 MoveDataThreadProc for step 2 about to
write data.
This indicates that socketwrapper is OK but something is delaying the
reading the file in socketwrapper or the implementation of
socketwrapper in Vista is provoking the delay.
My initial guess would be either network delays if the files are on a
server or security/file locking.
Are your files local or on a server ?
I am unfamiliar with Vista but it looks like something is delaying
access to the file to the socketwrapper program. Playing MP3 files do
not use socketwrapper but still files are read.
I'm not sure what to do - I can build a new version of socketwrapper
which produces more messsages so all the steps are logged with
associated timing.
You could check out if anybody else experience delays with Vista apps
using pipes and/or Named pipes.
Larger excerpt of logs.
Code:
--------------------
SW: 2007-04-07 12:00:19.057 MoveDataThreadProc for step 2 started.
SW: 2007-04-07 12:00:19.057 MoveDataThreadProc for step 2 about to call
ReadFile.
SW: 2007-04-07 12:00:19.088
Running as follows
SW: 2007-04-07 12:00:19.088 # =input== =output= ==type== etc
SW: 2007-04-07 12:00:19.103 0 00000003 00000114 PROCESS [0000012c]
"C:\Program
Files\slimserver652v20070407\server\Bin\MSWin32-x86-multi-thread\mov123.exe"
"F:\iTunes\iTunes Music\Grateful Dead\1978-07-08 Red Rocks\1-01 Bertha.m4a"
SW: 2007-04-07 12:00:19.103 1 00000110 0000011c PROCESS [00000134]
"C:\Program
Files\slimserver652v20070407\server\Bin\MSWin32-x86-multi-thread\flac.exe" -cs
--totally-silent --compression-level-0 --endian big --sign signed --channels 2
--bps 16 --sa
mple-rate 44100 -
SW: 2007-04-07 12:00:19.103 2 00000118 00000124 THREAD [00000128] 00000000
00373f98
SW: 2007-04-07 12:00:19.103
2007-04-07 12:00:19.1335 Pipeline reader connected
SW: 2007-04-07 12:00:42.923 MoveDataThreadProc for step 2 about to write data.
2007-04-07 12:00:43.1139 Got a track starting event
--------------------
Code:
--------------------
SW: 2007-04-05 20:34:11.328 MoveDataThreadProc for step 2 started.
SW: 2007-04-05 20:34:11.328 MoveDataThreadProc for step 2 about to call
ReadFile.
2007-04-05 20:34:11.3319 songTime: rate:1 -songtime:0 -startStream:0
2007-04-05 20:34:11.3332 songTime: rate:1 -songtime:0 -startStream:0
SW: 2007-04-05 20:34:11.328
Running as follows
SW: 2007-04-05 20:34:11.328 # =input== =output= ==type== etc
SW: 2007-04-05 20:34:11.343 0 00000003 0000003c PROCESS [00000094]
"C:\Program
Files\SlimServer65v20070405\server\Bin\MSWin32-x86-multi-thread\mov123.exe"
"C:\Documents and Settings\All Users\Documents\My Music\Sample Music\emerge.m4a"
SW: 2007-04-05 20:34:11.343 1 00000038 00000044 PROCESS [00000080]
"C:\Program
Files\SlimServer65v20070405\server\Bin\MSWin32-x86-multi-thread\flac.exe" -cs
--totally-silent --compression-level-0 --endian big --sign signed --channels 2
--bps 16 --sample-rate 44100 -
2007-04-05 20:34:11.3513 songTime: rate:1 -songtime:0 -startStream:0
SW: 2007-04-05 20:34:11.343 2 00000040 00000070 THREAD [0000007c] 00000000
00395730
2007-04-05 20:34:11.3539 songTime: rate:1 -songtime:0 -startStream:0
SW: 2007-04-05 20:34:11.343
2007-04-05 20:34:11.6376 Pipeline reader connected
2007-04-05 20:34:11.7338 would have blocked, will try again later
2007-04-05 20:34:11.7926 would have blocked, will try again later
2007-04-05 20:34:11.8454 would have blocked, will try again later
2007-04-05 20:34:11.8982 would have blocked, will try again later
2007-04-05 20:34:11.9510 would have blocked, will try again later
2007-04-05 20:34:12.0037 would have blocked, will try again later
2007-04-05 20:34:12.0564 would have blocked, will try again later
2007-04-05 20:34:12.1092 would have blocked, will try again later
2007-04-05 20:34:12.2470 would have blocked, will try again later
2007-04-05 20:34:12.2997 would have blocked, will try again later
2007-04-05 20:34:12.3296 songTime: rate:1 -songtime:0 -startStream:0
2007-04-05 20:34:12.3308 songTime: rate:1 -songtime:0 -startStream:0
2007-04-05 20:34:12.3518 would have blocked, will try again later
2007-04-05 20:34:12.4907 would have blocked, will try again later
SW: 2007-04-05 20:34:12.500 MoveDataThreadProc for step 2 about to write data.
2007-04-05 20:34:12.5432 Read 24576 bytes from source
--------------------
--
bpa
------------------------------------------------------------------------
bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806
View this thread: http://forums.slimdevices.com/showthread.php?t=34181
_______________________________________________
discuss mailing list
[email protected]
http://lists.slimdevices.com/lists/listinfo/discuss
