Page 1 of 1
Project: 10504 (R312, C27, G0) slow
Posted: Wed Mar 10, 2010 11:57 pm
by heikosch
Hi,
this WU is computed extremly slow, only ~4000 PPD compared to 5900-6000 PPD of project 10502 and 10503 WUs.
Any ideas why?
8800 GTS 512 at 1835 MHz shader clock.
Heiko
Re: Project: 10504 (R312, C27, G0) slow
Posted: Thu Mar 11, 2010 10:24 am
by toTOW
Without the log file, we can't say many things ...
Re: Project: 10504 (R312, C27, G0) slow
Posted: Thu Mar 11, 2010 1:37 pm
by heikosch
Normally WUs compute much faster, with 3600 finished WUs I don´t remember a GPU-WU completing so slow.
I don´t know what do you expect to find in the log file but here it is:
Code: Select all
[19:49:02] - Preparing to get new work unit...
[19:49:02] + Attempting to get work packet
[19:49:02] - Will indicate memory of 4093 MB
[19:49:02] - Connecting to assignment server
[19:49:02] Connecting to http://assign-GPU.stanford.edu:8080/
[19:49:04] Posted data.
[19:49:04] Initial: 43AB; - Successful: assigned to (171.67.108.21).
[19:49:04] + News From Folding@Home: Welcome to Folding@Home
[19:49:04] Loaded queue successfully.
[19:49:04] Connecting to http://171.67.108.21:8080/
[19:49:05] Posted data.
[19:49:05] Initial: 0000; - Receiving payload (expected size: 59571)
[19:49:06] - Downloaded at ~58 kB/s
[19:49:06] - Averaged speed for that direction ~57 kB/s
[19:49:06] + Received work.
[19:49:06] Trying to send all finished work units
[19:49:06] + No unsent completed units remaining.
[19:49:06] + Closed connections
[19:49:06]
[19:49:06] + Processing work unit
[19:49:06] Core required: FahCore_11.exe
[19:49:06] Core found.
[19:49:06] Working on queue slot 03 [March 9 19:49:06 UTC]
[19:49:06] + Working ...
[19:49:06] - Calling '.\FahCore_11.exe -dir work/ -suffix 03 -priority 96 -checkpoint 6 -verbose -lifeline 4216 -version 623'
[19:49:06]
[19:49:06] *------------------------------*
[19:49:06] Folding@Home GPU Core
[19:49:06] Version 1.31 (Tue Sep 15 10:57:42 PDT 2009)
[19:49:06]
[19:49:06] Compiler : Microsoft (R) 32-bit C/C++ Optimizing Compiler Version 14.00.50727.762 for 80x86
[19:49:06] Build host: amoeba
[19:49:06] Board Type: Nvidia
[19:49:06] Core :
[19:49:06] Preparing to commence simulation
[19:49:06] - Looking at optimizations...
[19:49:06] DeleteFrameFiles: successfully deleted file=work/wudata_03.ckp
[19:49:06] - Created dyn
[19:49:06] - Files status OK
[19:49:06] - Expanded 59059 -> 336799 (decompressed 570.2 percent)
[19:49:06] Called DecompressByteArray: compressed_data_size=59059 data_size=336799, decompressed_data_size=336799 diff=0
[19:49:06] - Digital signature verified
[19:49:06]
[19:49:06] Project: 10504 (Run 241, Clone 25, Gen 0)
[19:49:06]
[19:49:06] Assembly optimizations on if available.
[19:49:06] Entering M.D.
[19:49:12] Tpr hash work/wudata_03.tpr: 971243681 3802342376 2885179172 2366776144 3969118846
[19:49:12]
[19:49:12] Calling fah_main args: 14 usage=100
[19:49:12]
[19:49:13] Working on Protein
[19:49:14] Client config found, loading data.
[19:49:14] Starting GUI Server
[19:50:43] Completed 1%
[19:52:11] Completed 2%
[19:53:39] Completed 3%
[19:55:08] Completed 4%
[19:56:36] Completed 5%
[19:58:04] Completed 6%
[19:59:33] Completed 7%
[20:01:01] Completed 8%
[20:02:30] Completed 9%
[20:03:58] Completed 10%
[20:05:26] Completed 11%
[20:06:54] Completed 12%
[20:08:23] Completed 13%
[20:09:51] Completed 14%
[20:11:20] Completed 15%
[20:12:48] Completed 16%
[20:14:17] Completed 17%
[20:15:45] Completed 18%
[20:17:13] Completed 19%
[20:18:42] Completed 20%
[20:20:11] Completed 21%
[20:21:40] Completed 22%
[20:23:08] Completed 23%
[20:24:37] Completed 24%
[20:26:05] Completed 25%
[20:27:32] Completed 26%
[20:28:59] Completed 27%
[20:30:26] Completed 28%
[20:31:54] Completed 29%
[20:33:24] Completed 30%
[20:34:57] Completed 31%
[20:36:31] Completed 32%
[20:38:04] Completed 33%
[20:39:38] Completed 34%
[20:41:11] Completed 35%
[20:42:45] Completed 36%
[20:44:19] Completed 37%
[20:45:53] Completed 38%
[20:47:27] Completed 39%
[20:49:01] Completed 40%
[20:50:35] Completed 41%
[20:52:10] Completed 42%
[20:53:43] Completed 43%
[20:55:17] Completed 44%
[20:56:47] Completed 45%
[20:58:17] Completed 46%
[20:59:44] Completed 47%
[21:01:12] Completed 48%
[21:02:39] Completed 49%
[21:04:06] Completed 50%
[21:05:36] Completed 51%
[21:07:05] Completed 52%
[21:08:34] Completed 53%
[21:10:05] Completed 54%
[21:11:33] Completed 55%
[21:13:03] Completed 56%
[21:14:32] Completed 57%
[21:16:03] Completed 58%
[21:17:30] Completed 59%
[21:18:57] Completed 60%
[21:20:24] Completed 61%
[21:21:52] Completed 62%
[21:23:28] Completed 63%
[21:25:08] Completed 64%
[21:26:44] Completed 65%
[21:28:11] Completed 66%
[21:29:38] Completed 67%
[21:31:05] Completed 68%
[21:32:32] Completed 69%
[21:33:58] Completed 70%
[21:35:26] Completed 71%
[21:36:55] Completed 72%
[21:38:23] Completed 73%
[21:39:53] Completed 74%
[21:41:23] Completed 75%
[21:42:53] Completed 76%
[21:44:22] Completed 77%
[21:45:51] Completed 78%
[21:47:19] Completed 79%
[21:48:47] Completed 80%
[21:50:15] Completed 81%
[21:51:11] - Autosending finished units... [March 9 21:51:11 UTC]
[21:51:11] Trying to send all finished work units
[21:51:11] + No unsent completed units remaining.
[21:51:11] - Autosend completed
[21:51:11] + Working...
[21:51:44] Completed 82%
[21:53:11] Completed 83%
[21:54:37] Completed 84%
[21:56:04] Completed 85%
[21:57:30] Completed 86%
[21:58:56] Completed 87%
[22:00:23] Completed 88%
[22:01:49] Completed 89%
[22:03:16] Completed 90%
[22:04:46] Completed 91%
[22:06:15] Completed 92%
[22:07:44] Completed 93%
[22:09:13] Completed 94%
[22:10:42] Completed 95%
[22:12:12] Completed 96%
[22:13:41] Completed 97%
[22:15:08] Completed 98%
[22:16:34] Completed 99%
[22:18:02] Completed 100%
[22:18:03] Successful run
[22:18:03] DynamicWrapper: Finished Work Unit: sleep=10000
[22:18:13] Reserved 108944 bytes for xtc file; Cosm status=0
[22:18:13] Allocated 108944 bytes for xtc file
[22:18:13] - Reading up to 108944 from "work/wudata_03.xtc": Read 108944
[22:18:13] Read 108944 bytes from xtc file; available packet space=786321520
[22:18:13] xtc file hash check passed.
[22:18:13] Reserved 21912 21912 786321520 bytes for arc file=<work/wudata_03.trr> Cosm status=0
[22:18:13] Allocated 21912 bytes for arc file
[22:18:13] - Reading up to 21912 from "work/wudata_03.trr": Read 21912
[22:18:13] Read 21912 bytes from arc file; available packet space=786299608
[22:18:13] trr file hash check passed.
[22:18:13] Allocated 560 bytes for edr file
[22:18:13] Read bedfile
[22:18:13] edr file hash check passed.
[22:18:13] Logfile not read.
[22:18:13] GuardedRun: success in DynamicWrapper
[22:18:13] GuardedRun: done
[22:18:13] Run: GuardedRun completed.
[22:18:17] + Opened results file
[22:18:17] - Writing 131928 bytes of core data to disk...
[22:18:18] Done: 131416 -> 130385 (compressed to 99.2 percent)
[22:18:18] ... Done.
[22:18:18] DeleteFrameFiles: successfully deleted file=work/wudata_03.ckp
[22:18:18] Shutting down core
[22:18:18]
[22:18:18] Folding@home Core Shutdown: FINISHED_UNIT
[22:18:20] CoreStatus = 64 (100)
[22:18:20] Unit 3 finished with 99 percent of time to deadline remaining.
[22:18:20] Updated performance fraction: 0.990767
[22:18:20] Sending work to server
[22:18:20] Project: 10504 (Run 241, Clone 25, Gen 0)
[22:18:20] - Read packet limit of 540015616... Set to 524286976.
[22:18:20] + Attempting to send results [March 9 22:18:20 UTC]
[22:18:20] - Reading file work/wuresults_03.dat from core
[22:18:20] (Read 130897 bytes from disk)
[22:18:20] Connecting to http://171.67.108.21:8080/
[22:18:24] Posted data.
[22:18:24] Initial: 0000; - Uploaded at ~32 kB/s
[22:18:24] - Averaged speed for that direction ~31 kB/s
[22:18:24] + Results successfully sent
[22:18:24] Thank you for your contribution to Folding@Home.
[22:18:24] + Number of Units Completed: 3596
[22:18:28] Trying to send all finished work units
[22:18:28] + No unsent completed units remaining.
Heiko
Re: Project: 10504 (R312, C27, G0) slow
Posted: Thu Mar 11, 2010 4:46 pm
by Flathead74
According to your Fahlog, your frame times vary a bit, perhaps 1:26 - 1:30, approximately.
That scores to a range of 5,897 to 5,635 PPD.
But you are showing the log for Project: 10504 (Run 241, Clone 25, Gen 0),
and not Project: 10504 (R312, C27, G0), so there may be a difference.
Re: Project: 10504 (R312, C27, G0) slow
Posted: Thu Mar 11, 2010 5:28 pm
by heikosch
Flathead74 wrote:According to your Fahlog, your frame times vary a bit, perhaps 1:26 - 1:30, approximately.
That scores to a range of 5,897 to 5,635 PPD.
But you are showing the log for Project: 10504 (Run 241, Clone 25, Gen 0),
and not Project: 10504 (R312, C27, G0), so there may be a difference.
Oops, wrong log, sorry. Here´s the correct log:
Code: Select all
[21:05:39] - Preparing to get new work unit...
[21:05:39] + Attempting to get work packet
[21:05:39] - Will indicate memory of 4093 MB
[21:05:39] - Connecting to assignment server
[21:05:39] Connecting to http://assign-GPU.stanford.edu:8080/
[21:05:41] Posted data.
[21:05:41] Initial: 43AB; - Successful: assigned to (171.67.108.21).
[21:05:41] + News From Folding@Home: Welcome to Folding@Home
[21:05:41] Loaded queue successfully.
[21:05:41] Connecting to http://171.67.108.21:8080/
[21:05:42] Posted data.
[21:05:42] Initial: 0000; - Receiving payload (expected size: 59553)
[21:05:44] - Downloaded at ~29 kB/s
[21:05:44] - Averaged speed for that direction ~43 kB/s
[21:05:44] + Received work.
[21:05:44] Trying to send all finished work units
[21:05:44] + No unsent completed units remaining.
[21:05:44] + Closed connections
[21:05:44]
[21:05:44] + Processing work unit
[21:05:44] Core required: FahCore_11.exe
[21:05:44] Core found.
[21:05:44] Working on queue slot 03 [March 10 21:05:44 UTC]
[21:05:44] + Working ...
[21:05:44] - Calling '.\FahCore_11.exe -dir work/ -suffix 03 -priority 96 -checkpoint 6 -verbose -lifeline 3260 -version 623'
[21:05:44]
[21:05:44] *------------------------------*
[21:05:44] Folding@Home GPU Core
[21:05:44] Version 1.31 (Tue Sep 15 10:57:42 PDT 2009)
[21:05:44]
[21:05:44] Compiler : Microsoft (R) 32-bit C/C++ Optimizing Compiler Version 14.00.50727.762 for 80x86
[21:05:44] Build host: amoeba
[21:05:44] Board Type: Nvidia
[21:05:44] Core :
[21:05:44] Preparing to commence simulation
[21:05:44] - Looking at optimizations...
[21:05:44] DeleteFrameFiles: successfully deleted file=work/wudata_03.ckp
[21:05:44] - Created dyn
[21:05:44] - Files status OK
[21:05:44] - Expanded 59041 -> 336799 (decompressed 570.4 percent)
[21:05:44] Called DecompressByteArray: compressed_data_size=59041 data_size=336799, decompressed_data_size=336799 diff=0
[21:05:44] - Digital signature verified
[21:05:44]
[21:05:44] Project: 10504 (Run 312, Clone 27, Gen 0)
[21:05:44]
[21:05:44] Assembly optimizations on if available.
[21:05:44] Entering M.D.
[21:05:50] Tpr hash work/wudata_03.tpr: 196728641 667893634 2784785032 2876247979 3462515767
[21:05:50]
[21:05:50] Calling fah_main args: 14 usage=100
[21:05:50]
[21:05:50] Working on Protein
[21:05:51] Client config found, loading data.
[21:05:51] Starting GUI Server
[21:07:33] Completed 1%
[21:09:24] Completed 2%
[21:11:13] Completed 3%
[21:13:01] Completed 4%
[21:14:50] Completed 5%
[21:16:36] Completed 6%
[21:18:20] Completed 7%
[21:20:08] Completed 8%
[21:21:53] Completed 9%
[21:23:41] Completed 10%
[21:25:23] Completed 11%
[21:27:01] Completed 12%
[21:28:48] Completed 13%
[21:30:42] Completed 14%
[21:32:33] Completed 15%
[21:34:20] Completed 16%
[21:36:04] Completed 17%
[21:37:49] Completed 18%
[21:39:36] Completed 19%
[21:41:18] Completed 20%
[21:43:04] Completed 21%
[21:44:49] Completed 22%
[21:46:32] Completed 23%
[21:48:15] Completed 24%
[21:50:02] Completed 25%
[21:51:58] Completed 26%
[21:53:44] Completed 27%
[21:55:28] Completed 28%
[21:57:15] Completed 29%
[21:59:04] Completed 30%
[22:00:46] Completed 31%
[22:02:25] Completed 32%
[22:04:09] Completed 33%
[22:05:53] Completed 34%
[22:07:48] Completed 35%
[22:09:35] Completed 36%
[22:11:19] Completed 37%
[22:13:15] Completed 38%
[22:15:05] Completed 39%
[22:16:52] Completed 40%
[22:18:33] Completed 41%
[22:20:26] Completed 42%
[22:22:14] Completed 43%
[22:24:05] Completed 44%
[22:26:04] Completed 45%
[22:28:09] Completed 46%
[22:30:10] Completed 47%
[22:32:15] Completed 48%
[22:34:32] Completed 49%
[22:36:42] Completed 50%
[22:38:48] Completed 51%
[22:40:49] Completed 52%
[22:42:46] Completed 53%
[22:44:58] Completed 54%
[22:46:59] Completed 55%
[22:49:07] Completed 56%
[22:51:07] Completed 57%
[22:52:59] Completed 58%
[22:54:52] Completed 59%
[22:56:43] Completed 60%
[22:58:43] Completed 61%
[23:00:57] Completed 62%
[23:03:08] Completed 63%
[23:05:03] Completed 64%
[23:07:03] Completed 65%
[23:09:13] Completed 66%
[23:11:13] Completed 67%
[23:13:12] Completed 68%
[23:15:23] Completed 69%
[23:17:42] Completed 70%
[23:20:05] Completed 71%
[23:22:25] Completed 72%
[23:24:16] Completed 73%
[23:26:19] Completed 74%
[23:28:34] Completed 75%
[23:30:44] Completed 76%
[23:33:01] Completed 77%
[23:35:12] Completed 78%
[23:37:11] Completed 79%
[23:39:28] Completed 80%
[23:41:47] Completed 81%
[23:43:50] Completed 82%
[23:45:29] Completed 83%
[23:47:44] Completed 84%
[23:49:51] Completed 85%
[23:52:10] Completed 86%
[23:54:01] Completed 87%
[23:56:08] Completed 88%
[23:58:25] Completed 89%
[00:00:40] Completed 90%
[00:02:55] Completed 91%
[00:05:10] Completed 92%
[00:07:16] Completed 93%
[00:09:26] Completed 94%
[00:11:41] Completed 95%
[00:13:52] Completed 96%
[00:15:51] Completed 97%
[00:17:43] Completed 98%
[00:19:48] Completed 99%
[00:22:14] Completed 100%
[00:22:14] Successful run
[00:22:14] DynamicWrapper: Finished Work Unit: sleep=10000
[00:22:24] Reserved 109000 bytes for xtc file; Cosm status=0
[00:22:24] Allocated 109000 bytes for xtc file
[00:22:24] - Reading up to 109000 from "work/wudata_03.xtc": Read 109000
[00:22:24] Read 109000 bytes from xtc file; available packet space=786321464
[00:22:24] xtc file hash check passed.
[00:22:24] Reserved 21912 21912 786321464 bytes for arc file=<work/wudata_03.trr> Cosm status=0
[00:22:24] Allocated 21912 bytes for arc file
[00:22:24] - Reading up to 21912 from "work/wudata_03.trr": Read 21912
[00:22:24] Read 21912 bytes from arc file; available packet space=786299552
[00:22:24] trr file hash check passed.
[00:22:24] Allocated 560 bytes for edr file
[00:22:24] Read bedfile
[00:22:24] edr file hash check passed.
[00:22:24] Logfile not read.
[00:22:24] GuardedRun: success in DynamicWrapper
[00:22:24] GuardedRun: done
[00:22:24] Run: GuardedRun completed.
[00:22:25] + Opened results file
[00:22:25] - Writing 131984 bytes of core data to disk...
[00:22:25] Done: 131472 -> 130446 (compressed to 99.2 percent)
[00:22:25] ... Done.
[00:22:25] DeleteFrameFiles: successfully deleted file=work/wudata_03.ckp
[00:22:25] Shutting down core
[00:22:25]
[00:22:25] Folding@home Core Shutdown: FINISHED_UNIT
[00:22:29] CoreStatus = 64 (100)
[00:22:29] Unit 3 finished with 99 percent of time to deadline remaining.
[00:22:29] Updated performance fraction: 0.985011
[00:22:29] Sending work to server
[00:22:29] Project: 10504 (Run 312, Clone 27, Gen 0)
[00:22:29] - Read packet limit of 540015616... Set to 524286976.
[00:22:29] + Attempting to send results [March 11 00:22:29 UTC]
[00:22:29] - Reading file work/wuresults_03.dat from core
[00:22:29] (Read 130958 bytes from disk)
[00:22:29] Connecting to http://171.67.108.21:8080/
[00:22:33] Posted data.
[00:22:33] Initial: 0000; - Uploaded at ~32 kB/s
[00:22:33] - Averaged speed for that direction ~33 kB/s
[00:22:33] + Results successfully sent
[00:22:33] Thank you for your contribution to Folding@Home.
[00:22:33] + Number of Units Completed: 3606
[00:22:37] Trying to send all finished work units
[00:22:37] + No unsent completed units remaining.
You see that the WU is computed much slower with 4312 PPD. But it seems that FahMon calculated the PPD value wrong. Originally the PPD calculation was set to L3F, but I don´t find 3 frames with ~2,6 min length to get the 3200 PPD value. Now I´ve changed the setting to "effective duration" (translation might be wrong, I use the german UI).
Heiko
Re: Project: 10504 (R312, C27, G0) slow
Posted: Thu Mar 11, 2010 5:53 pm
by Wrish
Well, work units within a project can have some variance. It looks like an intermittent thing, seeing as your other 10504 was just fine. Everyone gets these slow units some time or other.
I prefer the "All Frames" setting in FahMon/HFM, because Effective Rate averages the work unit time into the first few %, making PPD seem unusually low at the start. "All Frames" assumes that pause at the start is a one-time thing, which is true for a 24/7 folder.
Re: Project: 10504 (R312, C27, G0) slow
Posted: Thu Mar 11, 2010 6:28 pm
by heikosch
Currently a project 10504 WU is computed with ~4100 PPD (correct according to the log) but the "all frames" setting shows ~6000 PPD with FahMon. I don´t think that rest of the frames only need half of the time of the first frames. Probably FahMon uses the "average" PPD value but in this case the average value equals the minimum value and that is nonsense. On the other hand HFM.NET shows correct values with the all frames setting. Seems to be an error in the FahMon benchmark data.
Heiko
Re: Project: 10504 (R312, C27, G0) slow
Posted: Thu Mar 11, 2010 6:36 pm
by 7im
Fahman has several options for computing the PPD. Average, last 3 frames, etc. If the client or PC was off, the average will have dropped because the client wasn't folding. Last 3 frames is more accurate, assuming nothing else was running during the last 3 frames.
Re: Project: 10504 (R312, C27, G0) slow
Posted: Thu Mar 11, 2010 8:28 pm
by heikosch
@7im
I know, but the computer and client were running for days. Look into the log, there was no interruption.
L3F gave me the unexpected low 3200 PPD and all frames gives me the a high speed nonsense value of 6000 PPD for all 10504 projects. At least I understand that project 10504 WUs vary between 4000 to 6000 PPD on my GPU and the FahMon PPD display is wrong, probably because of invalid stored benchmark data.
Heiko
Re: Project: 10504 (R312, C27, G0) slow
Posted: Thu Mar 11, 2010 8:59 pm
by bruce
heikosch wrote:I know, but the computer and client were running for days. Look into the log, there was no interruption.
FAH may not have been shut down, but that's doesn't mean that there were no interruptions. We can only guess whether there were other tasks running on the computer that modified the frame times. [I'm not saying there's anything wrong -- On a non-dedicated PC, I have to guess about my own systems. Sometimes I find that some other task started up and ran for a while without my actually doing anything and sometimes I don't ever find an explanation.]
Re: Project: 10504 (R312, C27, G0) slow
Posted: Thu Mar 11, 2010 10:19 pm
by heikosch
@bruce
The WU computed yesterday between 9pm and 0:22am. There were no other tasks with high CPU load and no other GPU tasks running, so you can compare it to a dedicated server.
Heiko