[GE users] sge_qmaster and high cpu

John Tseng jtseng at montalvosystems.com
Fri Mar 23 22:56:20 GMT 2007


    [ The following text is in the "ISO-8859-1" character set. ]
    [ Your display is set for the "ISO-8859-10" character set.  ]
    [ Some special characters may be displayed incorrectly. ]

I'm trying to figure out why our sge_qmaster is at such a high cpu.
We've been running 6.0u8, and recently upgraded to 6.0u10 and it occurs 
in both versions.

I've attached the qmaster output as sge.txt.  This is the same as the 
qping output, but in the qmaster messages file.

The current documentation on qping is sparse.  Does anyone know how to 
interrupt the data?
The only data that seems interesting is that the "wait" times seem to be 
high for the MT threads, but I'm not sure what that means, I don't see 
any wait times when looking at 'top' data.

03/23/2007 15:45:29|qmaster|sge|P|MT(1): runs: 1.02r/s (execd 
(l:0.28,j:0.40,c:0.28,p:0.28,a:0.00)/s GDI 
(a:0.17,g:1.25,m:0.23,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.11/s) 
out: 0.68m/s APT: 0.7420s/m idle: 23.99% wait: 70.58% time: 17.57s

Thanks,
john

Details:

* We have set the following qmaster_params:
qmaster_params               ENABLE_FORCED_QDEL=true MAX_DYN_EC=1024 \
                             MONITOR_TIME=0:0:10 PROF_SIGNAL=1 
PROF_DELIVER=1 \
                             PROF_TEVENT=1  PROF_MESSAGE=1

* we heavily use "-sync y".


* Our sgemaster is running FC4
[root at sge 6.0]# uname -a
Linux sge 2.6.16-1.2111_FC4smp #1 SMP Sat May 20 20:16:16 EDT 2006 
x86_64 x86_64 x86_64 GNU/Linux
[root at sge 6.0]# cat /etc/issue
Fedora Core release 4 (Stentz)

*) We have about 800 nodes, with about 600-700 jobs running.



    [ Part 2: "Attached Text" ]

03/23/2007 15:45:01|qmaster|sge|P|PROF(1129163104): timed event thread profiling summary:
03/23/2007 15:45:01|qmaster|sge|P|PROF(1129163104): other          : wc =    484.980s, utime =    426.460s, stime =      8.620s, utilization =  90%
03/23/2007 15:45:01|qmaster|sge|P|PROF(1129163104): communication  : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:01|qmaster|sge|P|PROF(1129163104): packing        : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:01|qmaster|sge|P|PROF(1129163104): eventclient    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:01|qmaster|sge|P|PROF(1129163104): eventmaster    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:01|qmaster|sge|P|PROF(1129163104): mirror         : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:01|qmaster|sge|P|PROF(1129163104): spooling       : wc =      0.210s, utime =      0.220s, stime =      0.220s, utilization = 210%
03/23/2007 15:45:01|qmaster|sge|P|PROF(1129163104): spooling-io    : wc =      2.840s, utime =      2.780s, stime =      0.200s, utilization = 105%
03/23/2007 15:45:01|qmaster|sge|P|PROF(1129163104): spooling-script: wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:01|qmaster|sge|P|PROF(1129163104): gdi            : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:01|qmaster|sge|P|PROF(1129163104): gdi_request    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:01|qmaster|sge|P|PROF(1129163104): ht-resize      : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:01|qmaster|sge|P|PROF(1129163104): total          : wc =    488.030s, utime =    429.460s, stime =      9.040s, utilization =  90%
03/23/2007 15:45:02|qmaster|sge|P|MT(1): runs: 8.35r/s (execd (l:1.97,j:3.83,c:1.97,p:1.97,a:0.10)/s GDI (a:0.59,g:0.00,m:3.54,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.39/s) out: 5.11m/s APT: 0.0108s/m idle: 90.94% wait: 0.91% time: 10.17s
03/23/2007 15:45:03|qmaster|sge|P|MT(2): runs: 7.46r/s (execd (l:0.88,j:2.75,c:0.88,p:0.88,a:0.10)/s GDI (a:0.98,g:0.98,m:2.95,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.59/s) out: 6.87m/s APT: 0.0151s/m idle: 88.77% wait: 1.98% time: 10.18s
03/23/2007 15:45:05|qmaster|sge|P|TET: runs: 1.02r/s (pending: 9.00 executed: 0.82/s) out: 0.00m/s APT: 0.0144s/m idle: 98.53% wait: 0.00% time: 9.79s
03/23/2007 15:45:06|qmaster|sge|P|EDT: runs: 10.22r/s (clients: 14.00 mod: 0.40/s ack: 0.91/s blocked: 0.00 busy: 0.32 | events: 41.77/s added: 41.67/s skipt: 0.10/s) out: 0.81m/s APT: 0.0028s/m idle: 97.10% wait: 0.01% time: 9.89s
03/23/2007 15:45:12|qmaster|sge|P|MT(1): runs: 4.59r/s (execd (l:1.43,j:1.43,c:1.43,p:1.43,a:0.10)/s GDI (a:0.31,g:4.08,m:1.53,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.10/s) out: 2.96m/s APT: 0.0271s/m idle: 87.57% wait: 2.56% time: 9.80s
03/23/2007 15:45:13|qmaster|sge|P|MT(2): runs: 5.16r/s (execd (l:1.92,j:2.02,c:1.92,p:1.92,a:0.00)/s GDI (a:0.10,g:4.05,m:1.42,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.61/s) out: 2.83m/s APT: 0.0302s/m idle: 84.40% wait: 4.36% time: 9.88s
03/23/2007 15:45:15|qmaster|sge|P|TET: runs: 0.30r/s (pending: 9.00 executed: 0.20/s) out: 0.00m/s APT: 0.0160s/m idle: 99.52% wait: 0.00% time: 9.99s
03/23/2007 15:45:16|qmaster|sge|P|EDT: runs: 6.30r/s (clients: 14.00 mod: 0.20/s ack: 0.80/s blocked: 0.00 busy: 0.05 | events: 2233.38/s added: 2233.38/s skipt: 0.00/s) out: 0.90m/s APT: 0.0427s/m idle: 73.11% wait: 0.00% time: 10.00s
03/23/2007 15:45:26|qmaster|sge|P|EDT: runs: 1.20r/s (clients: 14.00 mod: 0.00/s ack: 0.10/s blocked: 0.00 busy: 0.00 | events: 0.10/s added: 0.10/s skipt: 0.00/s) out: 0.40m/s APT: 0.0234s/m idle: 97.19% wait: 0.00% time: 10.00s
03/23/2007 15:45:29|qmaster|sge|P|PROF(1160632672): message thread profiling summary:
03/23/2007 15:45:29|qmaster|sge|P|PROF(1160632672): other          : wc =    412.540s, utime =    420.880s, stime =      6.250s, utilization = 104%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1160632672): communication  : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:29|qmaster|sge|P|TET: runs: 0.34r/s (pending: 9.00 executed: 0.34/s) out: 0.00m/s APT: 1.7159s/m idle: 41.06% wait: 58.88% time: 14.56s
03/23/2007 15:45:29|qmaster|sge|P|PROF(1171122528): message thread profiling summary:
03/23/2007 15:45:29|qmaster|sge|P|PROF(1160632672): packing        : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1171122528): other          : wc =    414.600s, utime =    420.900s, stime =      6.500s, utilization = 103%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1160632672): eventclient    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1171122528): communication  : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1160632672): eventmaster    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1160632672): mirror         : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1171122528): packing        : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1160632672): spooling       : wc =      1.160s, utime =      0.970s, stime =      0.170s, utilization =  98%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1160632672): spooling-io    : wc =      4.030s, utime =      1.230s, stime =      1.000s, utilization =  55%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1171122528): eventclient    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1160632672): spooling-script: wc =      0.040s, utime =      0.010s, stime =      0.020s, utilization =  75%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1160632672): gdi            : wc =    101.360s, utime =     26.460s, stime =      2.720s, utilization =  29%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1171122528): eventmaster    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1160632672): gdi_request    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1160632672): ht-resize      : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1171122528): mirror         : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1160632672): total          : wc =    519.130s, utime =    449.550s, stime =     10.160s, utilization =  89%
03/23/2007 15:45:29|qmaster|sge|P|MT(1): runs: 1.02r/s (execd (l:0.28,j:0.40,c:0.28,p:0.28,a:0.00)/s GDI (a:0.17,g:1.25,m:0.23,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.11/s) out: 0.68m/s APT: 0.7420s/m idle: 23.99% wait: 70.58% time: 17.57s
03/23/2007 15:45:29|qmaster|sge|P|PROF(1171122528): spooling       : wc =      1.010s, utime =      1.030s, stime =      0.080s, utilization = 110%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1171122528): spooling-io    : wc =      2.770s, utime =      1.010s, stime =      0.740s, utilization =  63%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1171122528): spooling-script: wc =      0.050s, utime =      0.050s, stime =      0.010s, utilization = 120%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1171122528): gdi            : wc =    100.840s, utime =     26.620s, stime =      2.860s, utilization =  29%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1171122528): gdi_request    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1171122528): ht-resize      : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:29|qmaster|sge|P|PROF(1171122528): total          : wc =    519.270s, utime =    449.610s, stime =     10.190s, utilization =  89%
03/23/2007 15:45:29|qmaster|sge|P|MT(2): runs: 0.78r/s (execd (l:0.24,j:0.24,c:0.24,p:0.24,a:0.00)/s GDI (a:0.06,g:0.12,m:0.12,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.12/s) out: 0.42m/s APT: 0.9893s/m idle: 22.44% wait: 1.20% time: 16.58s
03/23/2007 15:45:36|qmaster|sge|P|EDT: runs: 1.20r/s (clients: 14.00 mod: 0.00/s ack: 0.50/s blocked: 0.00 busy: 0.67 | events: 35.31/s added: 35.11/s skipt: 0.20/s) out: 0.50m/s APT: 0.0712s/m idle: 91.46% wait: 0.00% time: 10.00s
03/23/2007 15:45:39|qmaster|sge|P|TET: runs: 0.85r/s (pending: 19.00 executed: 0.74/s) out: 0.00m/s APT: 0.0031s/m idle: 99.74% wait: 0.00% time: 9.42s
03/23/2007 15:45:41|qmaster|sge|P|MT(2): runs: 1.13r/s (execd (l:0.26,j:0.44,c:0.26,p:0.26,a:0.26)/s GDI (a:0.00,g:1.04,m:0.17,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.00/s) out: 0.70m/s APT: 0.8839s/m idle: 0.00% wait: 1.15% time: 11.49s
03/23/2007 15:45:41|qmaster|sge|P|MT(1): runs: 3.77r/s (execd (l:1.80,j:2.23,c:1.80,p:1.80,a:0.17)/s GDI (a:0.34,g:0.09,m:0.43,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.43/s) out: 2.91m/s APT: 0.2650s/m idle: 0.14% wait: 96.93% time: 11.67s
03/23/2007 15:45:46|qmaster|sge|P|EDT: runs: 1.30r/s (clients: 14.00 mod: 0.10/s ack: 0.70/s blocked: 0.00 busy: 0.46 | events: 23.71/s added: 23.61/s skipt: 0.10/s) out: 0.90m/s APT: 0.0501s/m idle: 93.49% wait: 0.00% time: 10.00s
03/23/2007 15:45:49|qmaster|sge|P|TET: runs: 0.30r/s (pending: 14.33 executed: 0.10/s) out: 0.00m/s APT: 0.8691s/m idle: 73.91% wait: 25.92% time: 10.00s
03/23/2007 15:45:51|qmaster|sge|P|PROF(1139652960): event master thread profiling summary:
03/23/2007 15:45:51|qmaster|sge|P|PROF(1139652960): other          : wc =    525.150s, utime =    449.930s, stime =      9.020s, utilization =  87%
03/23/2007 15:45:51|qmaster|sge|P|PROF(1139652960): communication  : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:51|qmaster|sge|P|PROF(1139652960): packing        : wc =     14.880s, utime =     21.230s, stime =      1.400s, utilization = 152%
03/23/2007 15:45:51|qmaster|sge|P|PROF(1139652960): eventclient    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:51|qmaster|sge|P|PROF(1139652960): eventmaster    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:51|qmaster|sge|P|PROF(1139652960): mirror         : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:51|qmaster|sge|P|PROF(1139652960): spooling       : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:51|qmaster|sge|P|PROF(1139652960): spooling-io    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:51|qmaster|sge|P|PROF(1139652960): spooling-script: wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:51|qmaster|sge|P|PROF(1139652960): gdi            : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:51|qmaster|sge|P|PROF(1139652960): gdi_request    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:51|qmaster|sge|P|PROF(1139652960): ht-resize      : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:45:51|qmaster|sge|P|PROF(1139652960): total          : wc =    540.030s, utime =    471.160s, stime =     10.420s, utilization =  89%
03/23/2007 15:45:56|qmaster|sge|P|EDT: runs: 1.20r/s (clients: 14.00 mod: 0.10/s ack: 0.60/s blocked: 0.00 busy: 0.00 | events: 14.20/s added: 14.10/s skipt: 0.10/s) out: 0.50m/s APT: 0.0421s/m idle: 94.94% wait: 0.00% time: 10.00s
03/23/2007 15:45:58|qmaster|sge|P|MT(1): runs: 2.86r/s (execd (l:1.09,j:1.37,c:1.09,p:1.09,a:0.40)/s GDI (a:0.11,g:0.46,m:0.11,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.29/s) out: 1.31m/s APT: 0.3460s/m idle: 1.16% wait: 68.48% time: 17.50s
03/23/2007 15:45:58|qmaster|sge|P|MT(2): runs: 3.43r/s (execd (l:0.96,j:2.08,c:0.96,p:0.96,a:0.06)/s GDI (a:0.11,g:0.34,m:0.39,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.45/s) out: 1.35m/s APT: 0.2907s/m idle: 0.20% wait: 20.53% time: 17.77s
03/23/2007 15:45:59|qmaster|sge|P|TET: runs: 0.50r/s (pending: 9.00 executed: 0.50/s) out: 0.00m/s APT: 0.0007s/m idle: 99.96% wait: 0.00% time: 9.99s
03/23/2007 15:46:02|qmaster|sge|P|PROF(1129163104): timed event thread profiling summary:
03/23/2007 15:46:02|qmaster|sge|P|PROF(1129163104): other          : wc =    546.630s, utime =    477.860s, stime =     10.080s, utilization =  89%
03/23/2007 15:46:02|qmaster|sge|P|PROF(1129163104): communication  : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:02|qmaster|sge|P|PROF(1129163104): packing        : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:02|qmaster|sge|P|PROF(1129163104): eventclient    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:02|qmaster|sge|P|PROF(1129163104): eventmaster    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:02|qmaster|sge|P|PROF(1129163104): mirror         : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:02|qmaster|sge|P|PROF(1129163104): spooling       : wc =      0.210s, utime =      0.220s, stime =      0.220s, utilization = 210%
03/23/2007 15:46:02|qmaster|sge|P|PROF(1129163104): spooling-io    : wc =      2.910s, utime =      2.780s, stime =      0.210s, utilization = 103%
03/23/2007 15:46:02|qmaster|sge|P|PROF(1129163104): spooling-script: wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:02|qmaster|sge|P|PROF(1129163104): gdi            : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:02|qmaster|sge|P|PROF(1129163104): gdi_request    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:02|qmaster|sge|P|PROF(1129163104): ht-resize      : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:02|qmaster|sge|P|PROF(1129163104): total          : wc =    549.750s, utime =    480.860s, stime =     10.510s, utilization =  89%
03/23/2007 15:46:06|qmaster|sge|P|EDT: runs: 1.50r/s (clients: 14.00 mod: 0.10/s ack: 0.90/s blocked: 0.00 busy: 0.33 | events: 434.81/s added: 434.81/s skipt: 0.00/s) out: 0.60m/s APT: 0.0764s/m idle: 88.53% wait: 0.00% time: 10.00s
03/23/2007 15:46:09|qmaster|sge|P|TET: runs: 0.90r/s (pending: 9.56 executed: 0.80/s) out: 0.00m/s APT: 0.2255s/m idle: 79.72% wait: 17.06% time: 10.00s
03/23/2007 15:46:15|qmaster|sge|P|MT(1): runs: 3.21r/s (execd (l:1.37,j:1.49,c:1.37,p:1.37,a:0.12)/s GDI (a:0.18,g:0.24,m:0.60,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.48/s) out: 1.31m/s APT: 0.3109s/m idle: 0.03% wait: 76.09% time: 16.80s
03/23/2007 15:46:15|qmaster|sge|P|MT(2): runs: 1.24r/s (execd (l:0.65,j:0.77,c:0.65,p:0.65,a:0.00)/s GDI (a:0.12,g:0.06,m:0.18,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.06/s) out: 0.59m/s APT: 0.8032s/m idle: 0.01% wait: 22.81% time: 16.87s
03/23/2007 15:46:16|qmaster|sge|P|EDT: runs: 1.12r/s (clients: 14.00 mod: 0.09/s ack: 0.75/s blocked: 0.00 busy: 0.92 | events: 413.60/s added: 413.60/s skipt: 0.00/s) out: 1.03m/s APT: 0.0870s/m idle: 90.24% wait: 0.00% time: 10.70s
03/23/2007 15:46:26|qmaster|sge|P|EDT: runs: 1.19r/s (clients: 14.00 mod: 0.00/s ack: 0.00/s blocked: 0.00 busy: 1.00 | events: 0.00/s added: 0.00/s skipt: 0.00/s) out: 0.32m/s APT: 0.0002s/m idle: 99.98% wait: 0.00% time: 9.27s
03/23/2007 15:46:28|qmaster|sge|P|MT(2): runs: 2.76r/s (execd (l:1.18,j:1.50,c:1.18,p:1.18,a:0.55)/s GDI (a:0.00,g:0.32,m:0.00,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.39/s) out: 0.95m/s APT: 0.3567s/m idle: 1.52% wait: 98.04% time: 12.68s
03/23/2007 15:46:28|qmaster|sge|P|TET: runs: 0.15r/s (pending: 9.67 executed: 0.10/s) out: 0.00m/s APT: 3.8503s/m idle: 40.96% wait: 58.94% time: 19.57s
03/23/2007 15:46:28|qmaster|sge|P|MT(1): runs: 3.75r/s (execd (l:2.37,j:2.60,c:2.37,p:2.37,a:0.00)/s GDI (a:0.15,g:0.15,m:0.46,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.23/s) out: 1.53m/s APT: 0.2657s/m idle: 0.38% wait: 0.33% time: 13.07s
03/23/2007 15:46:36|qmaster|sge|P|EDT: runs: 1.20r/s (clients: 14.00 mod: 0.10/s ack: 0.80/s blocked: 0.00 busy: 0.33 | events: 238.78/s added: 238.78/s skipt: 0.00/s) out: 0.60m/s APT: 0.0754s/m idle: 90.95% wait: 0.00% time: 10.00s
03/23/2007 15:46:41|qmaster|sge|P|PROF(1160632672): message thread profiling summary:
03/23/2007 15:46:41|qmaster|sge|P|TET: runs: 0.48r/s (pending: 10.00 executed: 0.40/s) out: 0.00m/s APT: 2.0340s/m idle: 2.59% wait: 96.62% time: 12.53s
03/23/2007 15:46:41|qmaster|sge|P|PROF(1160632672): other          : wc =    483.340s, utime =    493.470s, stime =      7.190s, utilization = 104%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1160632672): communication  : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1160632672): packing        : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1160632672): eventclient    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1160632672): eventmaster    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1160632672): mirror         : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1171122528): message thread profiling summary:
03/23/2007 15:46:41|qmaster|sge|P|PROF(1171122528): other          : wc =    484.560s, utime =    493.260s, stime =      7.310s, utilization = 103%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1171122528): communication  : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1171122528): packing        : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1171122528): eventclient    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1171122528): eventmaster    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1160632672): spooling       : wc =      1.360s, utime =      1.050s, stime =      0.220s, utilization =  93%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1160632672): spooling-io    : wc =      4.300s, utime =      1.330s, stime =      1.090s, utilization =  56%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1171122528): mirror         : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1160632672): spooling-script: wc =      0.040s, utime =      0.010s, stime =      0.020s, utilization =  75%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1160632672): gdi            : wc =    101.630s, utime =     26.840s, stime =      2.720s, utilization =  29%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1171122528): spooling       : wc =      1.180s, utime =      1.260s, stime =      0.160s, utilization = 120%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1160632672): gdi_request    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1160632672): ht-resize      : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1171122528): spooling-io    : wc =      3.950s, utime =      1.190s, stime =      0.930s, utilization =  54%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1160632672): total          : wc =    590.670s, utime =    522.700s, stime =     11.240s, utilization =  90%
03/23/2007 15:46:41|qmaster|sge|P|MT(1): runs: 0.24r/s (execd (l:0.16,j:0.16,c:0.16,p:0.16,a:0.08)/s GDI (a:0.00,g:0.00,m:0.00,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.00/s) out: 0.00m/s APT: 4.1271s/m idle: 0.00% wait: 98.91% time: 12.38s
03/23/2007 15:46:41|qmaster|sge|P|PROF(1171122528): spooling-script: wc =      0.050s, utime =      0.050s, stime =      0.010s, utilization = 120%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1171122528): gdi            : wc =    101.080s, utime =     27.000s, stime =      2.860s, utilization =  30%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1171122528): gdi_request    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1171122528): ht-resize      : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:41|qmaster|sge|P|PROF(1171122528): total          : wc =    590.820s, utime =    522.760s, stime =     11.270s, utilization =  90%
03/23/2007 15:46:41|qmaster|sge|P|MT(2): runs: 4.79r/s (execd (l:3.14,j:3.38,c:3.14,p:3.14,a:0.08)/s GDI (a:0.31,g:0.08,m:0.24,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.63/s) out: 1.18m/s APT: 0.2087s/m idle: 0.01% wait: 0.07% time: 12.73s
03/23/2007 15:46:46|qmaster|sge|P|EDT: runs: 1.30r/s (clients: 14.00 mod: 0.10/s ack: 0.90/s blocked: 0.00 busy: 0.08 | events: 235.49/s added: 235.49/s skipt: 0.00/s) out: 0.80m/s APT: 0.0655s/m idle: 91.48% wait: 0.00% time: 10.00s
03/23/2007 15:46:51|qmaster|sge|P|PROF(1139652960): event master thread profiling summary:
03/23/2007 15:46:51|qmaster|sge|P|PROF(1139652960): other          : wc =    584.020s, utime =    509.170s, stime =      9.760s, utilization =  89%
03/23/2007 15:46:51|qmaster|sge|P|PROF(1139652960): communication  : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:51|qmaster|sge|P|PROF(1139652960): packing        : wc =     16.020s, utime =     23.400s, stime =      1.460s, utilization = 155%
03/23/2007 15:46:51|qmaster|sge|P|PROF(1139652960): eventclient    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:51|qmaster|sge|P|PROF(1139652960): eventmaster    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:51|qmaster|sge|P|PROF(1139652960): mirror         : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:51|qmaster|sge|P|PROF(1139652960): spooling       : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:51|qmaster|sge|P|PROF(1139652960): spooling-io    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:51|qmaster|sge|P|PROF(1139652960): spooling-script: wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:51|qmaster|sge|P|PROF(1139652960): gdi            : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:51|qmaster|sge|P|PROF(1139652960): gdi_request    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:51|qmaster|sge|P|PROF(1139652960): ht-resize      : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:46:51|qmaster|sge|P|PROF(1139652960): total          : wc =    600.040s, utime =    532.570s, stime =     11.220s, utilization =  91%
03/23/2007 15:46:53|qmaster|sge|P|MT(2): runs: 0.33r/s (execd (l:0.08,j:0.08,c:0.08,p:0.08,a:0.00)/s GDI (a:0.00,g:0.00,m:0.08,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.08/s) out: 0.16m/s APT: 3.0395s/m idle: 0.97% wait: 0.25% time: 12.28s
03/23/2007 15:46:53|qmaster|sge|P|TET: runs: 0.64r/s (pending: 9.38 executed: 0.56/s) out: 0.00m/s APT: 1.3316s/m idle: 15.01% wait: 84.83% time: 12.53s
03/23/2007 15:46:53|qmaster|sge|P|MT(1): runs: 4.79r/s (execd (l:3.36,j:3.44,c:3.36,p:3.36,a:0.08)/s GDI (a:0.24,g:0.00,m:0.24,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.72/s) out: 0.80m/s APT: 0.2055s/m idle: 1.51% wait: 96.26% time: 12.52s
03/23/2007 15:46:56|qmaster|sge|P|EDT: runs: 1.30r/s (clients: 14.31 mod: 0.10/s ack: 0.60/s blocked: 0.00 busy: 0.08 | events: 424.96/s added: 424.96/s skipt: 0.00/s) out: 0.40m/s APT: 0.0614s/m idle: 92.02% wait: 0.00% time: 10.00s
03/23/2007 15:47:03|qmaster|sge|P|TET: runs: 0.53r/s (pending: 9.00 executed: 0.43/s) out: 0.00m/s APT: 0.0009s/m idle: 99.95% wait: 0.00% time: 9.35s
03/23/2007 15:47:03|qmaster|sge|P|PROF(1129163104): timed event thread profiling summary:
03/23/2007 15:47:03|qmaster|sge|P|PROF(1129163104): other          : wc =    606.670s, utime =    539.330s, stime =     10.830s, utilization =  91%
03/23/2007 15:47:03|qmaster|sge|P|PROF(1129163104): communication  : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:47:03|qmaster|sge|P|PROF(1129163104): packing        : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:47:03|qmaster|sge|P|PROF(1129163104): eventclient    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:47:03|qmaster|sge|P|PROF(1129163104): eventmaster    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:47:03|qmaster|sge|P|PROF(1129163104): mirror         : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:47:03|qmaster|sge|P|PROF(1129163104): spooling       : wc =      0.210s, utime =      0.220s, stime =      0.220s, utilization = 210%
03/23/2007 15:47:03|qmaster|sge|P|PROF(1129163104): spooling-io    : wc =      3.160s, utime =      2.990s, stime =      0.220s, utilization = 102%
03/23/2007 15:47:03|qmaster|sge|P|PROF(1129163104): spooling-script: wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:47:03|qmaster|sge|P|PROF(1129163104): gdi            : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:47:03|qmaster|sge|P|PROF(1129163104): gdi_request    : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:47:03|qmaster|sge|P|PROF(1129163104): ht-resize      : wc =      0.000s, utime =      0.000s, stime =      0.000s, utilization =   0%
03/23/2007 15:47:03|qmaster|sge|P|PROF(1129163104): total          : wc =    610.040s, utime =    542.540s, stime =     11.270s, utilization =  91%
03/23/2007 15:47:06|qmaster|sge|P|EDT: runs: 1.00r/s (clients: 15.00 mod: 0.00/s ack: 0.00/s blocked: 0.00 busy: 0.00 | events: 0.00/s added: 0.00/s skipt: 0.00/s) out: 0.50m/s APT: 0.0006s/m idle: 99.94% wait: 0.00% time: 10.00s
03/23/2007 15:47:06|qmaster|sge|P|MT(1): runs: 3.23r/s (execd (l:1.61,j:1.70,c:1.61,p:1.61,a:0.16)/s GDI (a:0.32,g:0.24,m:0.16,d:0.08,c:0.00,t:0.00,p:0.00)/s event-acks: 0.40/s) out: 1.21m/s APT: 0.3096s/m idle: 0.01% wait: 97.49% time: 12.38s
03/23/2007 15:47:06|qmaster|sge|P|MT(2): runs: 0.24r/s (execd (l:0.08,j:0.08,c:0.08,p:0.08,a:0.00)/s GDI (a:0.08,g:0.00,m:0.08,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.00/s) out: 0.16m/s APT: 4.1809s/m idle: 1.01% wait: 2.33% time: 12.67s
03/23/2007 15:47:16|qmaster|sge|P|EDT: runs: 1.30r/s (clients: 15.00 mod: 0.10/s ack: 0.80/s blocked: 0.00 busy: 0.08 | events: 226.01/s added: 225.81/s skipt: 0.20/s) out: 0.80m/s APT: 0.0614s/m idle: 92.01% wait: 0.00% time: 10.00s
03/23/2007 15:47:17|qmaster|sge|P|MT(2): runs: 0.61r/s (execd (l:0.26,j:0.26,c:0.26,p:0.26,a:0.00)/s GDI (a:0.09,g:0.09,m:0.09,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.09/s) out: 0.26m/s APT: 1.6287s/m idle: 1.16% wait: 98.26% time: 11.54s
03/23/2007 15:47:17|qmaster|sge|P|TET: runs: 0.27r/s (pending: 9.00 executed: 0.20/s) out: 0.00m/s APT: 2.4805s/m idle: 32.94% wait: 66.12% time: 14.80s
03/23/2007 15:47:17|qmaster|sge|P|MT(1): runs: 3.97r/s (execd (l:1.86,j:2.28,c:1.86,p:1.86,a:0.25)/s GDI (a:0.25,g:0.17,m:0.17,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.67/s) out: 1.43m/s APT: 0.2497s/m idle: 1.00% wait: 0.99% time: 11.85s
03/23/2007 15:47:26|qmaster|sge|P|EDT: runs: 1.30r/s (clients: 15.00 mod: 0.10/s ack: 0.90/s blocked: 0.00 busy: 0.08 | events: 425.72/s added: 425.72/s skipt: 0.00/s) out: 0.50m/s APT: 0.0699s/m idle: 90.91% wait: 0.00% time: 10.00s
03/23/2007 15:47:27|qmaster|sge|P|TET: runs: 0.65r/s (pending: 9.83 executed: 0.54/s) out: 0.00m/s APT: 0.0315s/m idle: 97.94% wait: 1.90% time: 9.19s
03/23/2007 15:47:28|qmaster|sge|P|MT(2): runs: 2.23r/s (execd (l:0.68,j:0.68,c:0.68,p:0.68,a:0.00)/s GDI (a:0.19,g:0.39,m:0.58,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.29/s) out: 1.26m/s APT: 0.4410s/m idle: 1.76% wait: 0.12% time: 10.33s
03/23/2007 15:47:28|qmaster|sge|P|MT(1): runs: 3.67r/s (execd (l:1.83,j:1.93,c:1.83,p:1.83,a:0.10)/s GDI (a:0.19,g:0.39,m:0.48,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.48/s) out: 1.35m/s APT: 0.2657s/m idle: 2.51% wait: 96.39% time: 10.36s
03/23/2007 15:47:36|qmaster|sge|P|EDT: runs: 1.50r/s (clients: 15.00 mod: 0.00/s ack: 0.40/s blocked: 0.00 busy: 0.67 | events: 223.31/s added: 223.31/s skipt: 0.00/s) out: 0.70m/s APT: 0.0265s/m idle: 96.03% wait: 0.00% time: 10.00s
03/23/2007 15:47:38|qmaster|sge|P|TET: runs: 0.61r/s (pending: 10.57 executed: 0.52/s) out: 0.00m/s APT: 0.9252s/m idle: 43.58% wait: 55.69% time: 11.48s
03/23/2007 15:47:38|qmaster|sge|P|MT(2): runs: 0.77r/s (execd (l:0.19,j:0.39,c:0.19,p:0.19,a:0.00)/s GDI (a:0.10,g:0.10,m:0.10,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.10/s) out: 0.67m/s APT: 1.2974s/m idle: 0.01% wait: 97.63% time: 10.38s
03/23/2007 15:47:38|qmaster|sge|P|MT(1): runs: 2.34r/s (execd (l:1.07,j:1.37,c:1.07,p:1.07,a:0.10)/s GDI (a:0.20,g:0.10,m:0.39,d:0.00,c:0.00,t:0.00,p:0.00)/s event-acks: 0.29/s) out: 1.07m/s APT: 0.4268s/m idle: 0.00% wait: 0.20% time: 10.24s



    [ Part 3: "Attached Text" ]

    [ The following text is in the "iso-8859-1" character set. ]
    [ Your display is set for the "ISO-8859-10" character set.  ]
    [ Some special characters may be displayed incorrectly. ]

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe at gridengine.sunsource.net
For additional commands, e-mail: users-help at gridengine.sunsource.net



More information about the gridengine-users mailing list