Project 7611 (0, 23, 259) - High TPF

[truder44]

Having problem with long frame times

Project: 7611 (Run 0, Clone 23, Gen 269)

Code: Select all

*********************** Log Started 2012-11-10T07:54:08Z ***********************
07:54:08:************************* Folding@home Client *************************
07:54:08:      Website: http://folding.stanford.edu/
07:54:08:    Copyright: (c) 2009-2012 Stanford University
07:54:08:       Author: Joseph Coffland <joseph@cauldrondevelopment.com>
07:54:08:         Args: --lifeline 1224 --command-port=36330
07:54:08:       Config: C:/ProgramData/FAHClient/config.xml
07:54:08:******************************** Build ********************************
07:54:08:      Version: 7.1.52
07:54:08:         Date: Mar 20 2012
07:54:08:         Time: 19:37:42
07:54:08:      SVN Rev: 3515
07:54:08:       Branch: fah/trunk/client
07:54:08:     Compiler: Intel(R) C++ MSVC 1500 mode 1200
07:54:08:      Options: /TP /nologo /EHa /Qdiag-disable:4297,4103,1786,279 /Ox -arch:SSE
07:54:08:               /QaxSSE2,SSE3,SSSE3,SSE4.1,SSE4.2 /Qopenmp /Qrestrict /MT
07:54:08:     Platform: win32 XP
07:54:08:         Bits: 32
07:54:08:         Mode: Release
07:54:08:******************************* System ********************************
07:54:08:          CPU: Intel(R) Core(TM) i7-3770K CPU @ 3.50GHz
07:54:08:       CPU ID: GenuineIntel Family 6 Model 58 Stepping 9
07:54:08:         CPUs: 8
07:54:08:       Memory: 31.71GiB
07:54:08:  Free Memory: 29.59GiB
07:54:08:      Threads: WINDOWS_THREADS
07:54:08:   On Battery: false
07:54:08:   UTC offset: 11
07:54:08:          PID: 1300
07:54:08:          CWD: C:/ProgramData/FAHClient
07:54:08:           OS: Windows 7 Ultimate
07:54:08:      OS Arch: AMD64
07:54:08:         GPUs: 0
07:54:08:         CUDA: Not detected
07:54:08:Win32 Service: false
07:54:08:***********************************************************************
07:54:08:<config>
07:54:08:  <service-description v='Folding@home Client'/>
07:54:08:  <service-restart v='true'/>
07:54:08:  <service-restart-delay v='5000'/>
07:54:08:
07:54:08:  <!-- Client Control -->
07:54:08:  <cycle-rate v='4'/>
07:54:08:  <cycles v='-1'/>
07:54:08:  <data-directory v='.'/>
07:54:08:  <disable-project-lookup v='false'/>
07:54:08:  <exec-directory v='C:\Program Files (x86)\FAHClient'/>
07:54:08:  <exit-when-done v='false'/>
07:54:08:  <threads v='4'/>
07:54:08:
07:54:08:  <!-- Configuration -->
07:54:08:  <config-rotate v='true'/>
07:54:08:  <config-rotate-dir v='configs'/>
07:54:08:  <config-rotate-max v='16'/>
07:54:08:
07:54:08:  <!-- Debugging -->
07:54:08:  <assignment-servers>
07:54:08:    assign3.stanford.edu:8080 assign4.stanford.edu:80
07:54:08:  </assignment-servers>
07:54:08:  <capture-directory v='capture'/>
07:54:08:  <capture-sockets v='false'/>
07:54:08:  <debug-sockets v='false'/>
07:54:08:  <exception-locations v='true'/>
07:54:08:  <gpu-assignment-servers>
07:54:08:    assign-GPU.stanford.edu:80 assign-GPU.stanford.edu:8080
07:54:08:  </gpu-assignment-servers>
07:54:08:  <stack-traces v='false'/>
07:54:08:
07:54:08:  <!-- Error Handling -->
07:54:08:  <max-slot-errors v='5'/>
07:54:08:  <max-unit-errors v='5'/>
07:54:08:
07:54:08:  <!-- FahCore Control -->
07:54:08:  <checkpoint v='15'/>
07:54:08:  <core-dir v='cores'/>
07:54:08:  <core-priority v='idle'/>
07:54:08:  <cpu-affinity v='false'/>
07:54:08:  <cpu-usage v='100'/>
07:54:08:  <no-assembly v='false'/>
07:54:08:
07:54:08:  <!-- Folding Slot Configuration -->
07:54:08:  <client-subtype v='STDCLI'/>
07:54:08:  <client-type v='normal'/>
07:54:08:  <cpu-species v='X86_PENTIUM_II'/>
07:54:08:  <cpu-type v='AMD64'/>
07:54:08:  <cpus v='-1'/>
07:54:08:  <cuda-index v='0'/>
07:54:08:  <gpu v='false'/>
07:54:08:  <gpu-usage v='100'/>
07:54:08:  <max-packet-size v='normal'/>
07:54:08:  <opencl-index v='0'/>
07:54:08:  <os-species v='UNKNOWN'/>
07:54:08:  <os-type v='WIN32'/>
07:54:08:  <project-key v='0'/>
07:54:08:  <smp v='true'/>
07:54:08:
07:54:08:  <!-- Logging -->
07:54:08:  <log v='log.txt'/>
07:54:08:  <log-color v='false'/>
07:54:08:  <log-crlf v='true'/>
07:54:08:  <log-date v='false'/>
07:54:08:  <log-date-periodically v='21600'/>
07:54:08:  <log-debug v='true'/>
07:54:08:  <log-domain v='false'/>
07:54:08:  <log-header v='true'/>
07:54:08:  <log-level v='true'/>
07:54:08:  <log-no-info-header v='true'/>
07:54:08:  <log-redirect v='false'/>
07:54:08:  <log-rotate v='true'/>
07:54:08:  <log-rotate-dir v='logs'/>
07:54:08:  <log-rotate-max v='16'/>
07:54:08:  <log-short-level v='false'/>
07:54:08:  <log-simple-domains v='true'/>
07:54:08:  <log-thread-id v='false'/>
07:54:08:  <log-thread-prefix v='true'/>
07:54:08:  <log-time v='true'/>
07:54:08:  <log-to-screen v='true'/>
07:54:08:  <log-truncate v='false'/>
07:54:08:  <verbosity v='4'/>
07:54:08:
07:54:08:  <!-- Network -->
07:54:08:  <proxy v=':8080'/>
07:54:08:  <proxy-enable v='false'/>
07:54:08:  <proxy-pass v=''/>
07:54:08:  <proxy-user v=''/>
07:54:08:
07:54:08:  <!-- Process Control -->
07:54:08:  <child v='false'/>
07:54:08:  <daemon v='false'/>
07:54:08:  <pid v='false'/>
07:54:08:  <pid-file v='Folding@home Client.pid'/>
07:54:08:  <respawn v='false'/>
07:54:08:  <service v='false'/>
07:54:08:
07:54:08:  <!-- Remote Command Server -->
07:54:08:  <command-address v='0.0.0.0'/>
07:54:08:  <command-allow v='127.0.0.1'/>
07:54:08:  <command-allow-no-pass v='127.0.0.1'/>
07:54:08:  <command-deny v='0.0.0.0/0'/>
07:54:08:  <command-deny-no-pass v='0.0.0.0/0'/>
07:54:08:  <command-port v='36330'/>
07:54:08:
07:54:08:  <!-- Slot Control -->
07:54:08:  <max-shutdown-wait v='60'/>
07:54:08:  <pause-on-battery v='false'/>
07:54:08:  <pause-on-start v='false'/>
07:54:08:
07:54:08:  <!-- User Information -->
07:54:08:  <machine-id v='0'/>
07:54:08:  <passkey v='********************************'/>
07:54:08:  <team v='3542'/>
07:54:08:  <user v='truder44'/>
07:54:08:
07:54:08:  <!-- Work Unit Control -->
07:54:08:  <dump-after-deadline v='true'/>
07:54:08:  <max-queue v='16'/>
07:54:08:  <max-units v='0'/>
07:54:08:  <next-unit-percentage v='99'/>
07:54:08:
07:54:08:  <!-- Folding Slots -->
07:54:08:  <slot id='0' type='SMP'/>
07:54:08:</config>
07:54:08:Trying to access database...
07:54:08:Successfully acquired database lock
07:54:08:Enabled folding slot 00: READY smp:8
07:54:08:WU00:FS00:Starting
07:54:08:WU00:FS00:Running FahCore: "C:\Program Files (x86)\FAHClient/FAHCoreWrapper.exe" C:/ProgramData/FAHClient/cores/www.stanford.edu/~pande/Win32/AMD64/Core_a4.fah/FahCore_a4.exe -dir 00 -suffix 01 -version 701 -lifeline 1300 -checkpoint 15 -np 8
07:54:08:WU00:FS00:Started FahCore on PID 2956
07:54:08:WU00:FS00:Core PID:2964
07:54:08:WU00:FS00:FahCore 0xa4 started
07:54:09:WU00:FS00:0xa4:
07:54:09:WU00:FS00:0xa4:*------------------------------*
07:54:09:WU00:FS00:0xa4:Folding@Home Gromacs GB Core
07:54:09:WU00:FS00:0xa4:Version 2.27 (Dec. 15, 2010)
07:54:09:WU00:FS00:0xa4:
07:54:09:WU00:FS00:0xa4:Preparing to commence simulation
07:54:09:WU00:FS00:0xa4:- Looking at optimizations...
07:54:09:WU00:FS00:0xa4:- Files status OK
07:54:09:WU00:FS00:0xa4:- Expanded 29851 -> 644556 (decompressed 2159.2 percent)
07:54:09:WU00:FS00:0xa4:Called DecompressByteArray: compressed_data_size=29851 data_size=644556, decompressed_data_size=644556 diff=0
07:54:09:WU00:FS00:0xa4:- Digital signature verified
07:54:09:WU00:FS00:0xa4:
07:54:09:WU00:FS00:0xa4:Project: 7611 (Run 0, Clone 23, Gen 269)
07:54:09:WU00:FS00:0xa4:
07:54:09:WU00:FS00:0xa4:Assembly optimizations on if available.
07:54:09:WU00:FS00:0xa4:Entering M.D.
07:54:12:Server connection id=1 on 0.0.0.0:36330 from 127.0.0.1
07:54:15:WU00:FS00:0xa4:Using Gromacs checkpoints
07:54:15:WU00:FS00:0xa4:Mapping NT from 8 to 8 
07:54:15:WU00:FS00:0xa4:Resuming from checkpoint
07:54:15:WU00:FS00:0xa4:Verified 00/wudata_01.log
07:54:15:WU00:FS00:0xa4:Verified 00/wudata_01.trr
07:54:15:WU00:FS00:0xa4:Verified 00/wudata_01.xtc
07:54:15:WU00:FS00:0xa4:Verified 00/wudata_01.edr
07:54:15:WU00:FS00:0xa4:Completed 115260 out of 2000000 steps  (5%)
08:03:39:WU00:FS00:0xa4:Completed 120000 out of 2000000 steps  (6%)
08:42:50:WU00:FS00:0xa4:Completed 140000 out of 2000000 steps  (7%)
09:21:52:WU00:FS00:0xa4:Completed 160000 out of 2000000 steps  (8%)
10:01:06:WU00:FS00:0xa4:Completed 180000 out of 2000000 steps  (9%)
10:40:15:WU00:FS00:0xa4:Completed 200000 out of 2000000 steps  (10%)
11:19:44:WU00:FS00:0xa4:Completed 220000 out of 2000000 steps  (11%)

Working on i7 3770K at 3.8Ghz dedicated folding box.
Core running at 99% and no other programs running.
Time per frame is over 39 minutes.
(Possible bad WU?)

[Joe_H]

Possibly. So far there are no results in the database for this WU. What is the normal TPF for 7611 WU's on your system? If you have done all of the checks to make sure nothing else is causing the high TPF for this WU, then you can be fairly sure it is bad if it is running significantly slower than other WU's from this project.

[truder44]

Possibly. So far there are no results in the database for this WU. What is the normal TPF for 7611 WU's on your system? If you have done all of the checks to make sure nothing else is causing the high TPF for this WU, then you can be fairly sure it is bad if it is running significantly slower than other WU's from this project.

Previous 7611 WU on the machine ran at about 6 minutes 25 seconds per frame. [7611 (Run 3, Clone 64, Gen 161)]
As the current WU is still running at 39 minutes 11 seconds per frame I am assuming bad WU and dumping it.

[P5-133XL]

TPF's vary widely and point values vary widely between projects. You can not compare just them directly and come to any reasonable conclusions. PPD's are much more comparable but even those can vary significantly. I think that if the p7611 gave you 50K and other projects are giving you 53K that those numbers are close enough to each other that I don't think you need to worry much about the high TPF for one project.

As a side question why are you using only two cores and why CPU=90 (which is only useful for uniprocessor cores)? on an i7-3770K? Those are very strange settings for an 4/8 core processor and I'm really very surprised you can get 50+K PPD using only two cores.

[Zagen30]

I'm seeing super-slow times on 7611/0/23/287.

Code: Select all

02:25:00:WU03:FS02:0xa4:Completed 580000 out of 2000000 steps  (29%)
03:00:24:WU03:FS02:0xa4:Completed 600000 out of 2000000 steps  (30%)
03:36:36:WU03:FS02:0xa4:Completed 620000 out of 2000000 steps  (31%)
04:12:26:WU03:FS02:0xa4:Completed 640000 out of 2000000 steps  (32%)
04:49:22:WU03:FS02:0xa4:Completed 660000 out of 2000000 steps  (33%)
05:25:01:WU03:FS02:0xa4:Completed 680000 out of 2000000 steps  (34%)
06:01:13:WU03:FS02:0xa4:Completed 700000 out of 2000000 steps  (35%)
06:38:17:WU03:FS02:0xa4:Completed 720000 out of 2000000 steps  (36%)
07:16:25:WU03:FS02:0xa4:Completed 740000 out of 2000000 steps  (37%)
******************************** Date: 04/01/13 ********************************
07:54:18:WU03:FS02:0xa4:Completed 760000 out of 2000000 steps  (38%)

That's a roughly 38 minute TPF on a 4.3 GHz 3770k that usually does 7611s at about 6 to 7 minutes TPF. Start to 29% was about the same frame times, but I rebooted my computer to clear out any lingering background tasks and the client started a new log file and I didn't feel like copying over individual lines from the old log. I can pretty much confirm it wasn't background tasks/GPU usage/any other common CPU-stealing thing. I will dump the WU right after this.

[gero1369]

I have the same issue with a 7611. I haven't had any unusual problems to speak of until now. Here is my info:

i7-930 @ 3.8 GHz
SMP(8)
P7611 (R4, C57, G154)
Completed: 14%
PPD: 229.77
TPF: 01:57:31
ETA: 7.00:26:26
WU Points: 1875.12
User: Gero1369 (11108)

I'll dump when I get home. Thanks for the thread

[Joe_H]

So far there are two reports in the database of successful completion of this WU and one failure. Since there is no system information connected with the entries that completed, there is no way of telling if they took an unusually long time for those systems. If you can be certain that no other process is taking compute resources away from processing this WU, and the TPF is much longer than you have seen for other 7611 WU's, it is probably bad and should be dumped. Thanks for the report.

[patonb]

My i7 950@4.0Ghz run at 67C grabbed a (0,38,288). with a tpf of 59:15.

I have run other generations as quick as 6:38

[Joe_H]

Sounds like another bad one, no reports yet in the database. Do also check the number of steps listed for the WU, normal for Project 7611 is 2,000,000. Most of the bad WU's have the correct number, but occasionally one does get through that has too many steps.

[patonb]

Thanks Joe, it is 2 million steps, I'll complete it in just over a day, so I let it run

[patonb]

Could a mod check if this (0,38,288) uploaded?

Weirdly, the v7 interface said the collection server was 0.0.0.0

I'm just intrested as to what one of these does on upload.

[compdewd]

Weirdly, the v7 interface said the collection server was 0.0.0.0

I'm just intrested as to what one of these does on upload.

See this post by bollix47: viewtopic.php?p=231841#p231841

[bollix47]

Hi patonb (team 12864),
Your WU (P7611 R0 C38 G288) was added to the stats database on 2013-01-16 14:10:39 for 2856.7 points of credit.

[patonb]

Thanks bollix, glad it went through after 3 days of crunching.

[bruce]

See another report here: Project: 7611 (Run 2, Clone 39, Gen 319) runs very slowly

Since tjlane knows the cause, you still need to be sure that you report the problem here so that a Mod can report it as a bad WU (avoiding others from having the same problem).

The WU (P7611,R2,C39,G319) has been reported as a bad WU. Note that the list of reported WUs are stopped daily at 8am pacific time.